Errors in Docker logs - can't see document images anymore

When things don't work as they should.
Post Reply
wesss
Posts: 6
Joined: Wed Feb 13, 2019 8:35 pm

Errors in Docker logs - can't see document images anymore

Post by wesss »

I'm running the docker setup, with postgresql 11 and redis 5.
It was working until a month or so ago (this isn't a high usage install, just personal).
I can't figure out how to fix this, so I need some help. Here is the error log output:

Code: Select all

mayan-edms-app |  -------------- [queues]
mayan-edms-app |                 .> common_periodic  exchange=common_periodic(direct) key=common_periodic
mayan-edms-app |                 .> document_states  exchange=document_states(direct) key=document_states
mayan-edms-app |                 .> mailing          exchange=mailing(direct) key=mailing
mayan-edms-app |                 .> ocr              exchange=ocr(direct) key=ocr
mayan-edms-app |                 .> parsing          exchange=parsing(direct) key=parsing
mayan-edms-app |                 .> statistics       exchange=statistics(direct) key=statistics
mayan-edms-app |                 .> tools            exchange=tools(direct) key=tools
mayan-edms-app |
mayan-edms-app | [2020-01-26 22:48:01,882: ERROR/ForkPoolWorker-1] Task mayan.apps.checkouts.tasks.task_check_expired_check_outs[b11e6836-958d-4f36-814c-da5b502333e2] rais$
d unexpected: OperationalError('could not receive data from server: Bad file descriptor\n')
mayan-edms-app | Traceback (most recent call last):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
mayan-edms-app |     return self.cursor.execute(sql, params)
mayan-edms-app | psycopg2.OperationalError: could not receive data from server: Bad file descriptor
mayan-edms-app |
mayan-edms-app |
mayan-edms-app | The above exception was the direct cause of the following exception:
mayan-edms-app |
mayan-edms-app | Traceback (most recent call last):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/app/trace.py", line 385, in trace_task
mayan-edms-app |     R = retval = fun(*args, **kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/app/trace.py", line 648, in __protected_call__
mayan-edms-app |     return self.run(*args, **kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/mayan/apps/checkouts/tasks.py", line 30, in task_check_expired_check_outs
mayan-edms-app |     DocumentCheckout.objects.check_in_expired_check_outs()
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/mayan/apps/checkouts/managers.py", line 80, in check_in_expired_check_outs
mayan-edms-app |     for document in self.expired_check_outs():
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/models/query.py", line 250, in __iter__
mayan-edms-app |     self._fetch_all()
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/models/query.py", line 1121, in _fetch_all
mayan-edms-app |     self._result_cache = list(self._iterable_class(self))
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/models/query.py", line 53, in __iter__
mayan-edms-app |     results = compiler.execute_sql(chunked_fetch=self.chunked_fetch)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 899, in execute_sql
mayan-edms-app |     raise original_exception
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/models/sql/compiler.py", line 889, in execute_sql
mayan-edms-app |     cursor.execute(sql, params)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
mayan-edms-app |     return self.cursor.execute(sql, params)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/utils.py", line 94, in __exit__
mayan-edms-app |     six.reraise(dj_exc_type, dj_exc_value, traceback)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/utils/six.py", line 685, in reraise
mayan-edms-app |     raise value.with_traceback(tb)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/db/backends/utils.py", line 64, in execute
mayan-edms-app |     return self.cursor.execute(sql, params)
mayan-edms-app | django.db.utils.OperationalError: could not receive data from server: Bad file descriptor
mayan-edms-app |
mayan-edms-app | mayan.apps.common.middleware.error_logging <39> [ERROR] "process_exception() line 18 Exception caught by request middleware; <WSGIRequest: GET '/api/docume
nts/392/versions/396/pages/2966/image/?width=800&height=&zoom=&rotation=&_hash=eb517d37b3e4c6b768a1f1afcd728ea054a4644733ec488daa11b1bae26b145d'>, The operation timed out."
mayan-edms-app | Traceback (most recent call last):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/backends/asynchronous.py", line 255, in _wait_for_pending
mayan-edms-app |     on_interval=on_interval):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/backends/asynchronous.py", line 54, in drain_events_until
mayan-edms-app |     raise socket.timeout()
mayan-edms-app | socket.timeout
mayan-edms-app |
mayan-edms-app | During handling of the above exception, another exception occurred:
mayan-edms-app |
mayan-edms-app | Traceback (most recent call last):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/core/handlers/base.py", line 185, in _get_response
mayan-edms-app |     response = wrapped_callback(request, *callback_args, **callback_kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/views/decorators/csrf.py", line 58, in wrapped_view
mayan-edms-app |     return view_func(*args, **kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/views/generic/base.py", line 68, in view
mayan-edms-app |     return self.dispatch(request, *args, **kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/rest_framework/views.py", line 494, in dispatch
mayan-edms-app |     response = self.handle_exception(exc)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/rest_framework/views.py", line 454, in handle_exception
mayan-edms-app |     self.raise_uncaught_exception(exc)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/rest_framework/views.py", line 491, in dispatch
mayan-edms-app |     response = handler(request, *args, **kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/rest_framework/generics.py", line 210, in get
mayan-edms-app |     return self.retrieve(request, *args, **kwargs)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/django/views/decorators/cache.py", line 43, in _cache_controlled
mayan-edms-app |     response = viewfunc(request, *args, **kw)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/mayan/apps/documents/api_views.py", line 221, in retrieve
mayan-edms-app |     cache_filename = task.get(timeout=DOCUMENT_IMAGE_TASK_TIMEOUT)
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/result.py", line 226, in get
mayan-edms-app |     on_message=on_message,
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/backends/asynchronous.py", line 188, in wait_for_pending
mayan-edms-app |     for _ in self._wait_for_pending(result, **kwargs):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/backends/asynchronous.py", line 259, in _wait_for_pending
mayan-edms-app |     raise TimeoutError('The operation timed out.')
mayan-edms-app | celery.exceptions.TimeoutError: The operation timed out.
mayan-edms-app | mayan.apps.common.middleware.error_logging <40> [ERROR] "process_exception() line 18 Exception caught by request middleware; <WSGIRequest: GET '/api/docume
nts/391/versions/395/pages/2965/image/?width=800&height=&zoom=&rotation=&_hash=eb517d37b3e4c6b768a1f1afcd728ea054a4644733ec488daa11b1bae26b145d'>, The operation timed out."
mayan-edms-app | Traceback (most recent call last):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/backends/asynchronous.py", line 255, in _wait_for_pending
mayan-edms-app |     on_interval=on_interval):
mayan-edms-app |   File "/opt/mayan-edms/lib/python3.7/site-packages/celery/backends/asynchronous.py", line 54, in drain_events_until
mayan-edms-app |     raise socket.timeout()
mayan-edms-app | socket.timeout
mayan-edms-app |
mayan-edms-app | During handling of the above exception, another exception occurred:
(and the errors continue)

Any idea what could be causing these Bad file descriptors?

Thanks for anything.

User avatar
rssfed23
Moderator
Moderator
Posts: 185
Joined: Mon Oct 14, 2019 1:18 pm
Location: United Kingdom
Contact:

Re: Errors in Docker logs - can't see document images anymore

Post by rssfed23 »

What version of Mayan are you running?

I ask, as it looks like Celery is using the async backend, and we switched to the sync backend in the 3.3 timeframe.

Can you post the environment variables you're using to launch mayan as well as the mayan container version?

There's 2 potential things for us to look at here here.
The first (and easiest) is to follow the section at https://docs.mayan-edms.com/parts/troub ... ts-already

Although that's not the same error message you're getting, I can see many other people reporting the same issue in Django and setting the CONN_MAX_AGE to 0 can fix it. I have a suspicion that your machine is running out of open file descriptors from leftover connections. If Mayan starts and runs for a little while before running into problems this may be the explanation. The DB basically cuts the connection of while the data is being transferred due to a lack of free connections/file descriptors.
So please ensure that the MAYAN_DATABASE_CONN_MAX_AGE is set to 0 in your docker-compose file or docker run command.

But we need your environment variables and any other configs, because I notice another thing in that log output as well:

The lines I'm most interested in (if you have one) is any custom supervisor configuration you've got (if any).
The line to start gunicorn should be

Code: Select all

command = /opt/mayan-edms/bin/gunicorn -w 5 mayan.wsgi --max-requests 1000 --max-requests-jitter 50 --worker-class sync --bind 0.0.0.0:8000 --timeout 120
whereas in the past we used a worker-class async.
I saw this issue once before when using async in the newer versions and had to change that line (the project default config updated it but I had it leftover from a manual setting). But if you've not deployed a custom configuration then it should have worked automatically.

Additionally, what folders have you got as volume mounts? Because keeping /etc/supervisor inside the container mounted to the local filesystem is one way our updated settings inside the docker container might not end up applied.
Please don't PM for general support; start a new thread with your issue instead.

wesss
Posts: 6
Joined: Wed Feb 13, 2019 8:35 pm

Re: Errors in Docker logs - can't see document images anymore

Post by wesss »

Thanks so much for your message. For some reason I didn't get a notification of your reply. I'll check those settings.
Running:
Mayan EDMS Version 3.3.10
Build number: v3.3.10_Fri Jan 31 01:42:59 2020 -0400

Alongside Redis5-alpine and postgres11-alpine docker images
I don't have any custom supervisor or anything else. Just the standard mayan docker image
Redis is used for broker and results:
MAYAN_CELERY_BROKER_URL: redis://results:6379/0
MAYAN_CELERY_RESULT_BACKEND: redis://results:6379/1

I didn't have "MAYAN_DATABASE_CONN_MAX_AGE: 0", so I added that. I'm still getting the same errors.

Something that comes to mind for me is that some db upgrade or other update between mayan-edms versions perhaps wasn't correctly applied, resulting in something missing in my database tables? I'm just shooting in the dark with that.

Key parts of docker-compose (personal info removed):

Code: Select all

  results:
    container_name: mayan-edms-results
    image: redis:5-alpine
    restart: unless-stopped
    environment:
      DATABASES: 2
      MAXMEMORY: 100mb
      MAXMEMORY-POLICY: allkeys-lru
      MAXCLIENTS: 500
      SAVE: ""
      TCP-BACKLOG: 256

  db:
    container_name: mayan-edms-db
    image: postgres:11-alpine
    restart: unless-stopped
    environment:
      POSTGRES_DB: 
      POSTGRES_PASSWORD: 
      POSTGRES_USER: 

  app:
    container_name: mayan-edms-app
    image: mayanedms/mayanedms:latest
    restart: unless-stopped
    depends_on:
      - db
      - results
    environment:
      MAYAN_CELERY_BROKER_URL: redis://results:6379/0
      MAYAN_CELERY_RESULT_BACKEND: redis://results:6379/1
      MAYAN_DATABASE_CONN_MAX_AGE: 0
      MAYAN_DATABASE_ENGINE: django.db.backends.postgresql
      MAYAN_DATABASE_HOST: db
      MAYAN_DATABASE_NAME: 
      MAYAN_DATABASE_PASSWORD: 
      MAYAN_DATABASE_USER: 
Much appreciated.

Post Reply