Bench start SIGTERM

Install / Update
1

Hi all,

I have an erpnext instance that used to run perfectly on ubuntu 20.04 and it stopped working by itself without any modifications, I have read all the threads I could find to no avail and my system has been down for weeks now!

If anyone can help it is much appreciated!

/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
22:51:59 system | redis_cache.1 started (pid=94814)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
22:51:59 system | redis_socketio.1 started (pid=94816)
22:51:59 redis_socketio.1 | 94824:C 05 Sep 2022 22:51:59.969 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
22:51:59 redis_socketio.1 | 94824:C 05 Sep 2022 22:51:59.969 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=94824, just started
22:51:59 redis_socketio.1 | 94824:C 05 Sep 2022 22:51:59.969 # Configuration loaded
22:51:59 redis_socketio.1 | 94824:M 05 Sep 2022 22:51:59.971 * Increased maximum number of open files to 10032 (it was originally set to 1024).
22:51:59 redis_socketio.1 | 94824:M 05 Sep 2022 22:51:59.972 * Running mode=standalone, port=12000.
22:51:59 redis_socketio.1 | 94824:M 05 Sep 2022 22:51:59.972 # Server initialized
22:51:59 redis_socketio.1 | 94824:M 05 Sep 2022 22:51:59.972 * Ready to accept connections
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
22:51:59 redis_cache.1 | 94820:C 05 Sep 2022 22:51:59.980 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
22:51:59 redis_cache.1 | 94820:C 05 Sep 2022 22:51:59.980 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=94820, just started
22:51:59 redis_cache.1 | 94820:C 05 Sep 2022 22:51:59.980 # Configuration loaded
22:51:59 redis_cache.1 | 94820:M 05 Sep 2022 22:51:59.982 * Increased maximum number of open files to 10032 (it was originally set to 1024).
22:51:59 system | redis_queue.1 started (pid=94818)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn’t supported in binary mode, the default buffer size will be used
self.stdout = io.open(c2pread, ‘rb’, bufsize)
22:51:59 redis_cache.1 | 94820:M 05 Sep 2022 22:51:59.986 * Running mode=standalone, port=13000.
22:51:59 redis_cache.1 | 94820:M 05 Sep 2022 22:51:59.986 # Server initialized
22:51:59 redis_cache.1 | 94820:M 05 Sep 2022 22:51:59.987 * Ready to accept connections
22:51:59 system | web.1 started (pid=94827)
22:51:59 system | schedule.1 started (pid=94834)
22:51:59 redis_queue.1 | 94830:C 05 Sep 2022 22:51:59.995 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
22:51:59 system | socketio.1 started (pid=94825)
22:51:59 redis_queue.1 | 94830:C 05 Sep 2022 22:51:59.995 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=94830, just started
22:51:59 redis_queue.1 | 94830:C 05 Sep 2022 22:51:59.995 # Configuration loaded
22:51:59 redis_queue.1 | 94830:M 05 Sep 2022 22:51:59.999 * Increased maximum number of open files to 10032 (it was originally set to 1024).
22:52:00 redis_queue.1 | 94830:M 05 Sep 2022 22:52:00.000 * Running mode=standalone, port=11000.
22:52:00 redis_queue.1 | 94830:M 05 Sep 2022 22:52:00.000 # Server initialized
22:52:00 redis_queue.1 | 94830:M 05 Sep 2022 22:52:00.001 * Ready to accept connections
22:52:00 system | worker_short.1 started (pid=94840)
22:52:00 worker_short.1 | /bin/sh: 1: cannot create logs/worker.log: Permission denied
22:52:00 system | worker_short.1 stopped (rc=2)
22:52:00 system | worker_long.1 started (pid=94838)
22:51:59 worker_long.1 | /bin/sh: 1: cannot create logs/worker.log: Permission denied
22:52:00 system | worker_long.1 stopped (rc=2)
22:52:00 system | watch.1 started (pid=94848)
22:52:00 system | worker_default.1 started (pid=94846)
22:52:00 system | sending SIGTERM to redis_cache.1 (pid 94814)
22:52:00 system | sending SIGTERM to redis_socketio.1 (pid 94816)
22:52:00 system | sending SIGTERM to redis_queue.1 (pid 94818)
22:52:00 system | sending SIGTERM to web.1 (pid 94827)
22:52:00 system | sending SIGTERM to socketio.1 (pid 94825)
22:52:00 system | sending SIGTERM to watch.1 (pid 94848)
22:52:00 system | sending SIGTERM to schedule.1 (pid 94834)
22:52:00 system | sending SIGTERM to worker_default.1 (pid 94846)
22:52:00 redis_queue.1 | 94830:signal-handler (1662432720) Received SIGTERM scheduling shutdown…
22:52:00 redis_cache.1 | 94820:signal-handler (1662432720) Received SIGTERM scheduling shutdown…
22:52:00 redis_socketio.1 | 94824:signal-handler (1662432720) Received SIGTERM scheduling shutdown…
22:52:00 worker_default.1 | /bin/sh: 1: cannot create logs/worker.log: Permission denied
22:52:00 system | schedule.1 stopped (rc=-15)
22:52:00 system | worker_default.1 stopped (rc=2)
22:52:00 system | socketio.1 stopped (rc=-15)
22:52:00 system | web.1 stopped (rc=-15)
22:52:00 system | watch.1 stopped (rc=-15)
22:52:00 redis_socketio.1 | 94824:M 05 Sep 2022 22:52:00.074 # User requested shutdown…
22:52:00 redis_socketio.1 | 94824:M 05 Sep 2022 22:52:00.074 * Removing the pid file.
22:52:00 redis_socketio.1 | 94824:M 05 Sep 2022 22:52:00.074 # Redis is now ready to exit, bye bye…
22:52:00 system | redis_socketio.1 stopped (rc=-15)
22:52:00 redis_cache.1 | 94820:M 05 Sep 2022 22:52:00.087 # User requested shutdown…
22:52:00 redis_cache.1 | 94820:M 05 Sep 2022 22:52:00.088 * Removing the pid file.
22:52:00 redis_cache.1 | 94820:M 05 Sep 2022 22:52:00.088 # Redis is now ready to exit, bye bye…
22:52:00 system | redis_cache.1 stopped (rc=-15)
22:52:00 redis_queue.1 | 94830:M 05 Sep 2022 22:52:00.102 # User requested shutdown…
22:52:00 redis_queue.1 | 94830:M 05 Sep 2022 22:52:00.102 * Removing the pid file.
22:52:00 redis_queue.1 | 94830:M 05 Sep 2022 22:52:00.102 # Redis is now ready to exit, bye bye…
22:52:00 system | redis_queue.1 stopped (rc=-15)

2

Hey,

I can see a lot of

22:52:00 worker_default.1 | /bin/sh: 1: cannot create logs/worker.log: Permission denied

in the stack trace.

Probably need to get appropriate permissions for creating file in that directory (?)

3

yes, I did notice that could you lead me on a path to achieve this? I have solved a few of the problems that I could see from the stack but I do not know how to solve this error!

thanks!

4

I managed to fix this permission error:

22:52:00 worker_default.1 | /bin/sh: 1: cannot create logs/worker.log: Permission denied

Deleting all the worker logs in /frappe-bench/logs solves it.

I am now left with this stack with a couple of errors with ports already in use. I am trying a bunch of solutions from other posts and will update on this. If anyone has input on this it is greatly appreciated. Thanks

/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
/usr/lib/python3.8/subprocess.py:848: RuntimeWarning: line buffering (buffering=1) isn't supported in binary mode, the default buffer size will be used
  self.stdout = io.open(c2pread, 'rb', bufsize)
14:53:40 system           | redis_cache.1 started (pid=3301)
14:53:40 system           | socketio.1 started (pid=3303)
14:53:40 system           | redis_queue.1 started (pid=3302)
14:53:40 system           | schedule.1 started (pid=3304)
14:53:40 system           | worker_default.1 started (pid=3306)
14:53:40 system           | watch.1 started (pid=3310)
14:53:40 system           | web.1 started (pid=3305)
14:53:40 system           | worker_long.1 started (pid=3307)
14:53:40 system           | worker_short.1 started (pid=3309)
14:53:40 system           | redis_socketio.1 started (pid=3308)
14:53:40 redis_cache.1    | 3313:C 21 Sep 2022 14:53:40.045 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
14:53:40 redis_cache.1    | 3313:C 21 Sep 2022 14:53:40.045 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=3313, just started
14:53:40 redis_cache.1    | 3313:C 21 Sep 2022 14:53:40.045 # Configuration loaded
14:53:40 redis_cache.1    | 3313:M 21 Sep 2022 14:53:40.046 * Increased maximum number of open files to 10032 (it was originally set to 1024).
14:53:40 redis_queue.1    | 3318:C 21 Sep 2022 14:53:40.044 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
14:53:40 redis_queue.1    | 3318:C 21 Sep 2022 14:53:40.045 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=3318, just started
14:53:40 redis_queue.1    | 3318:C 21 Sep 2022 14:53:40.045 # Configuration loaded
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.045 * Increased maximum number of open files to 10032 (it was originally set to 1024).
14:53:40 redis_socketio.1 | 3327:C 21 Sep 2022 14:53:40.048 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
14:53:40 redis_socketio.1 | 3327:C 21 Sep 2022 14:53:40.048 # Redis version=5.0.7, bits=64, commit=00000000, modified=0, pid=3327, just started
14:53:40 redis_socketio.1 | 3327:C 21 Sep 2022 14:53:40.048 # Configuration loaded
14:53:40 redis_cache.1    | 3313:M 21 Sep 2022 14:53:40.049 # Could not create server TCP listening socket 127.0.0.1:13000: bind: Address already in use
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.049 * Increased maximum number of open files to 10032 (it was originally set to 1024).
14:53:40 system           | redis_cache.1 stopped (rc=1)
14:53:40 system           | sending SIGTERM to redis_socketio.1 (pid 3308)
14:53:40 system           | sending SIGTERM to redis_queue.1 (pid 3302)
14:53:40 system           | sending SIGTERM to web.1 (pid 3305)
14:53:40 system           | sending SIGTERM to socketio.1 (pid 3303)
14:53:40 system           | sending SIGTERM to watch.1 (pid 3310)
14:53:40 system           | sending SIGTERM to schedule.1 (pid 3304)
14:53:40 system           | sending SIGTERM to worker_short.1 (pid 3309)
14:53:40 system           | sending SIGTERM to worker_long.1 (pid 3307)
14:53:40 system           | sending SIGTERM to worker_default.1 (pid 3306)
14:53:40 system           | socketio.1 stopped (rc=-15)
14:53:40 system           | watch.1 stopped (rc=-15)
14:53:40 system           | worker_short.1 stopped (rc=-15)
14:53:40 system           | worker_default.1 stopped (rc=-15)
14:53:40 system           | worker_long.1 stopped (rc=-15)
14:53:40 system           | web.1 stopped (rc=-15)
14:53:40 system           | schedule.1 stopped (rc=-15)
14:53:40 redis_queue.1    | 3318:signal-handler (1663786420) Received SIGTERM scheduling shutdown...
14:53:40 redis_socketio.1 | 3327:signal-handler (1663786420) Received SIGTERM scheduling shutdown...
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.066 * Running mode=standalone, port=12000.
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.066 * Running mode=standalone, port=11000.
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.066 # Server initialized
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.066 # Server initialized
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.066 * Ready to accept connections
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.066 # User requested shutdown...
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.066 * Removing the pid file.
14:53:40 redis_socketio.1 | 3327:M 21 Sep 2022 14:53:40.066 # Redis is now ready to exit, bye bye...
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.066 * Ready to accept connections
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.066 # User requested shutdown...
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.066 * Removing the pid file.
14:53:40 redis_queue.1    | 3318:M 21 Sep 2022 14:53:40.066 # Redis is now ready to exit, bye bye...
14:53:40 system           | redis_socketio.1 stopped (rc=-15)
14:53:40 system           | redis_queue.1 stopped (rc=-15)
5

This topic was automatically closed 180 days after the last reply. New replies are no longer allowed.