Apache/mod_wsgi log object is not associated with a file descriptor

[gongomgra]

Description of the issue

Hello, team. We are facing an issue trying to install and configure ERPNext in a Debian 12 virtual-machine using bench 5.22.3. Although the ERPNext site gets generated, the website is not available with internal server error through Apache/mod_wsgi. WSGI log shows OSError: Apache/mod_wsgi log object is not associated with a file descriptor. Seems related to recent changes in __init__.py.

As a test, we implemented the change below and it seems to work. However, we saw this as a hot fix suggestion somewhere else, so we created this ticket for further help. Can you help us to understand what's the issue and how to fix it?

old: faulthandler.register(signal.SIGUSR1, file=sys.stderr)
new: faulthandler.register(signal.SIGUSR1, file=sys.__stderr__)

Context information (for bug reports)

Output of bench version

$ bench --version
5.22.3

Steps to reproduce the issue

1. Install ERPNext app using bench 5.22.3

$ bench new-site --db-name "ERPNEXT_DATABASE_NAME" --db-type "mariadb" --db-host "ERPNEXT_DATABASE_HOST" --db-port "ERPNEXT_DATABASE_PORT_NUMBER" --mariadb-root-username "ERPNEXT_DATABASE_ADMIN_USER" --mariadb-root-password "ERPNEXT_DATABASE_ADMIN_PASSWORD" erpnext
$ bench --site "erpnext" install-app erpnext
Installing frappe...
Updating DocTypes for frappe        : [========================================] 100%
Updating Dashboard for frappe
erpnext: SystemSettings.enable_scheduler is UNSET
*** Scheduler is disabled ***

Installing erpnext...
Updating DocTypes for erpnext       : [========================================] 100%
Updating customizations for Address
Updating customizations for Contact
Updating Dashboard for erpnext

2. Set host_name to http://localhost in site_config.json
3. Configure Apache/mod_wsgi
4. Visit website
5. Internal server error is shown (see stacktrace below for WSGI logs)

Observed result

Internal server error plus OSError: Apache/mod_wsgi log object is not associated with a file descriptor in logs.

Expected result

Login page.

Stacktrace / full error message

[Wed May 01 11:38:11.566673 2024] [wsgi:error] [pid 2010:tid 139701143983808] [remote 127.0.0.1:50960]   File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 1329, in get_doc
mod_wsgi (pid=2010): Exception occurred processing WSGI script '/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py'.
Traceback (most recent call last):
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/serve.py", line 19, in get_response
    endpoint, renderer_instance = path_resolver.resolve()
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/path_resolver.py", line 38, in resolve
    resolve_redirect(self.path, request.query_string)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/path_resolver.py", line 118, in resolve_redirect
    redirects += frappe.get_all("Website Route Redirect", ["source", "target"], order_by=None)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 2050, in get_all
    return get_list(doctype, *args, **kwargs)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 2025, in get_list
    return frappe.model.db_query.DatabaseQuery(doctype).execute(*args, **kwargs)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/model/db_query.py", line 167, in execute
    if is_virtual_doctype(self.doctype):
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/utils/caching.py", line 123, in site_cache_wrapper
    return func(*args, **kwargs)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/model/utils/__init__.py", line 132, in is_virtual_doctype
    if frappe.db.has_column("DocType", "is_virtual"):
  File "/opt/bitnami/erpnext/frappe-bench/env/lib/python3.10/site-packages/werkzeug/local.py", line 311, in __get__
    obj = instance._get_current_object()
  File "/opt/bitnami/erpnext/frappe-bench/env/lib/python3.10/site-packages/werkzeug/local.py", line 490, in _get_current_object
    raise RuntimeError(unbound_message) from None
RuntimeError: object is not bound

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 74, in application
    app(environ, start_response),
  File "/opt/bitnami/erpnext/frappe-bench/env/lib/python3.10/site-packages/werkzeug/wrappers/request.py", line 189, in application
    resp = f(*args[:-2] + (request,))
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 128, in application
    response = handle_exception(e)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 391, in handle_exception
    response = get_response("message", http_status_code=http_status_code)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/serve.py", line 28, in get_response
    response = ErrorPage(exception=e).render()
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/page_renderers/template_page.py", line 84, in render
    html = self.get_html()
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/utils.py", line 523, in cache_html_decorator
    html = func(*args, **kwargs)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/page_renderers/template_page.py", line 92, in get_html
    self.init_context()
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/page_renderers/error_page.py", line 14, in init_context
    super().init_context()
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/page_renderers/base_template_page.py", line 15, in init_context
    self.context.update(get_website_settings())
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/website/doctype/website_settings/website_settings.py", line 174, in get_website_settings
    settings: "WebsiteSettings" = frappe.get_cached_doc("Website Settings")
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 1203, in get_cached_doc
    doc = get_doc(*args, **kwargs)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 1329, in get_doc
    doc = frappe.model.document.get_doc(*args, **kwargs)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 83, in get_doc
    controller = get_controller(doctype)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/model/base_document.py", line 70, in get_controller
    site_controllers[doctype] = import_controller(doctype)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/model/base_document.py", line 95, in import_controller
    module = load_doctype_module(doctype, module_name)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/modules/utils.py", line 244, in load_doctype_module
    app = get_module_app(module)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/modules/utils.py", line 267, in get_module_app
    app = frappe.local.module_app.get(scrub(module))
AttributeError: 'NoneType' object has no attribute 'get'

mod_wsgi (pid=2010): Exception occurred processing WSGI script '/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py'.
Traceback (most recent call last):
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 95, in application
    init_request(request)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 168, in init_request
    frappe.init(site=site, sites_path=_sites_path, force=True)
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 311, in init
    _register_fault_handler()
  File "/opt/bitnami/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 2527, in _register_fault_handler
    faulthandler.register(signal.SIGUSR1, file=sys.stderr)
OSError: Apache/mod_wsgi log object is not associated with a file descriptor.

Additional information

Debian 12.

While looking for other issues affected with the same error message, we found a hot fix suggested here. We tested to update the line 2527 mentioned in the error message to the one below. After that, I was able to generate another site and get to the login page, pass the wizard, and get access to my ERPNext site.

According to Python's docs it contains the original value of stderr at the start of the program.

faulthandler.register(signal.SIGUSR1, file=sys.__stderr__)

[ankush]

@Mutantpenguin can you verify if this change is fine for your usage too 👀

don't want to break it again while fixing this.

[ankush]

@gongomgra you might wanna migrate to nginx + gunicorn setup.

We don't test compatibility with Apache/mod_wsgi at all. (maybe we historically supported this? idk)

[gongomgra]

Hi @ankush,

Thanks for letting us know. We will create an internal task to migrate to the recommended setup. In the meantime, we will keep an eye on the solution of this issue.

[Mutantpenguin]

Thanks @ankush for thinking of me!

If the current safeguard if isinstance(sys.stderr, io.TextIOWrapper): stays in place we don't have any problems with the proposed solution.

[gongomgra]

Hi @ankush,

I see a new Frappe version have been released recently, but the solution for this issue seems not to be included yet. Do you have any news on this? Thanks!