ERPNext Bench start Not Working

Adarsh_B · December 1, 2023, 3:20pm

15:17:25 system | redis_socketio.1 started (pid=17624)
15:17:25 system | redis_cache.1 started (pid=17621)
15:17:25 redis_socketio.1 | 17630:C 01 Dec 2023 15:17:25.706 # Fatal error, can’t open config file ‘config/redis_socketio.conf’: No such file or directory
15:17:25 system | redis_socketio.1 stopped (rc=1)
15:17:25 system | redis_queue.1 started (pid=17627)
15:17:25 redis_queue.1 | 17634:C 01 Dec 2023 15:17:25.709 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
15:17:25 redis_queue.1 | 17634:C 01 Dec 2023 15:17:25.709 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=17634, just started
15:17:25 redis_queue.1 | 17634:C 01 Dec 2023 15:17:25.709 # Configuration loaded
15:17:25 redis_queue.1 | 17634:M 01 Dec 2023 15:17:25.710 * Increased maximum number of open files to 10032 (it was originally set to 1024).
15:17:25 redis_queue.1 | 17634:M 01 Dec 2023 15:17:25.710 # Could not create server TCP listening socket 127.0.0.1:11000: bind: Address already in use
15:17:25 system | redis_queue.1 stopped (rc=1)
15:17:25 system | worker_short.1 started (pid=17637)
15:17:25 system | watch.1 started (pid=17638)
15:17:25 redis_cache.1 | 17635:C 01 Dec 2023 15:17:25.717 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
15:17:25 redis_cache.1 | 17635:C 01 Dec 2023 15:17:25.721 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=17635, just started
15:17:25 redis_cache.1 | 17635:C 01 Dec 2023 15:17:25.722 # Configuration loaded
15:17:25 redis_cache.1 | 17635:M 01 Dec 2023 15:17:25.722 * Increased maximum number of open files to 10032 (it was originally set to 1024).
15:17:25 redis_cache.1 | 17635:M 01 Dec 2023 15:17:25.723 # Could not create server TCP listening socket 127.0.0.1:13000: bind: Address already in use
15:17:25 system | redis_cache.1 stopped (rc=1)
15:17:25 system | schedule.1 started (pid=17639)
15:17:25 system | socketio.1 started (pid=17646)
15:17:25 system | web.1 started (pid=17640)
15:17:25 system | worker_default.1 started (pid=17644)
15:17:25 system | worker_long.1 started (pid=17641)
15:17:25 system | sending SIGTERM to web.1 (pid 17640)
15:17:25 system | sending SIGTERM to socketio.1 (pid 17646)
15:17:25 system | sending SIGTERM to watch.1 (pid 17638)
15:17:25 system | sending SIGTERM to schedule.1 (pid 17639)
15:17:25 system | sending SIGTERM to worker_short.1 (pid 17637)
15:17:25 system | sending SIGTERM to worker_long.1 (pid 17641)
15:17:25 system | sending SIGTERM to worker_default.1 (pid 17644)
15:17:25 system | worker_long.1 stopped (rc=-15)
15:17:25 system | worker_short.1 stopped (rc=-15)
15:17:25 system | worker_default.1 stopped (rc=-15)
15:17:25 system | schedule.1 stopped (rc=-15)
15:17:25 system | web.1 stopped (rc=-15)
15:17:25 system | watch.1 stopped (rc=-15)
15:17:25 system | socketio.1 stopped (rc=-15)

I get this every time I bench start

Adarsh_B · December 1, 2023, 4:07pm

Can someone send screenshot
Command:
cd frappe-bench
cd config
ls

Also,
sudo nano redis_socketio.conf

corentin · December 1, 2023, 4:36pm

Is your bench already running somewhere? Maybe some process crashed but was not restarted. Maybe some zombie processes are listening on those ports.

If possible, just restart your computer or the server. This is not an amazing solution but it will surely work.

Adarsh_B · December 1, 2023, 5:22pm

Restarted. But it is not solving the issue

avc · December 1, 2023, 5:34pm

Hi @Adarsh_B:

Is your site running?
Tried to access to localhost:8000?

Adarsh_B · December 1, 2023, 5:36pm

ip:8000 site not found

avc · December 1, 2023, 7:29pm

Try

sudo lsof -n -i :13000 | grep LISTEN

and

sudo lsof -n -i :8000 | grep LISTEN

This will show which processes are listening these ports.

Adarsh_B · December 2, 2023, 4:10am

I have changed the ports of socketio & webserver. But one process is still creating an issue.
Command:node PID:23023
This one. Even if I kill the service or change the socketio port, the socketio port gets used automatically by this service & the error arises again.

rp21 · December 2, 2023, 7:59am

The problem here is the TCP listening socket on 127.0.0.1:11000 and 127.0.0.1:13000 is already in use, probably because there is a previous bench process that you started but weren’t closed properly, based on my experience.

As avc suggested, try running

sudo lsof -n -i :11000 | grep LISTEN
sudo lsof -n -i :13000 | grep LISTEN

and kill the processes using port 11000 and 13000.

If it doesn’t work, it probably because the processes are automatically restarted whenever it’s killed. Either temporarily stop the automatic restarting process or reboot the server/machine. The easy way is to just reboot the server/machine as it gives you a fresh state again.

Adarsh_B · December 3, 2023, 8:43am

08:39:37 system | redis_cache.1 started (pid=1841)
08:39:37 system | redis_socketio.1 started (pid=1845)
08:39:37 system | schedule.1 started (pid=1849)
08:39:37 redis_socketio.1 | 1851:C 03 Dec 2023 08:39:37.433 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
08:39:37 redis_socketio.1 | 1851:C 03 Dec 2023 08:39:37.434 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=1851, just started
08:39:37 redis_socketio.1 | 1851:C 03 Dec 2023 08:39:37.434 # Configuration loaded
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.434 * Increased maximum number of open files to 10032 (it was originally set to 1024).
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.435 * Running mode=standalone, port=10003.
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.435 # Server initialized
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.435 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add ‘vm.overcommit_memory = 1’ to /etc/sysctl.conf and then reboot or run the command ‘sysctl vm.overcommit_memory=1’ for this to take effect.
08:39:37 system | redis_queue.1 started (pid=1854)
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.457 * Ready to accept connections
08:39:37 system | socketio.1 started (pid=1863)
08:39:37 redis_queue.1 | 1858:C 03 Dec 2023 08:39:37.538 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
08:39:37 redis_queue.1 | 1858:C 03 Dec 2023 08:39:37.538 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=1858, just started
08:39:37 redis_queue.1 | 1858:C 03 Dec 2023 08:39:37.538 # Configuration loaded
08:39:37 redis_queue.1 | 1858:M 03 Dec 2023 08:39:37.539 * Increased maximum number of open files to 10032 (it was originally set to 1024).
08:39:37 redis_queue.1 | 1858:M 03 Dec 2023 08:39:37.539 # Could not create server TCP listening socket 127.0.0.1:10002: bind: Address already in use
08:39:37 system | redis_queue.1 stopped (rc=1)
08:39:37 redis_cache.1 | 1847:C 03 Dec 2023 08:39:37.554 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
08:39:37 redis_cache.1 | 1847:C 03 Dec 2023 08:39:37.554 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=1847, just started
08:39:37 redis_cache.1 | 1847:C 03 Dec 2023 08:39:37.554 # Configuration loaded
08:39:37 redis_cache.1 | 1847:M 03 Dec 2023 08:39:37.554 * Increased maximum number of open files to 10032 (it was originally set to 1024).
08:39:37 redis_cache.1 | 1847:M 03 Dec 2023 08:39:37.555 # Could not create server TCP listening socket 127.0.0.1:10001: bind: Address already in use
08:39:37 system | watch.1 started (pid=1861)
08:39:37 system | redis_cache.1 stopped (rc=1)
08:39:37 system | worker_short.1 started (pid=1874)
08:39:37 system | web.1 started (pid=1879)
08:39:37 system | worker_long.1 started (pid=1883)
08:39:37 system | worker_default.1 started (pid=1882)
08:39:37 system | sending SIGTERM to redis_socketio.1 (pid 1845)
08:39:37 system | sending SIGTERM to web.1 (pid 1879)
08:39:37 system | sending SIGTERM to socketio.1 (pid 1863)
08:39:37 system | sending SIGTERM to watch.1 (pid 1861)
08:39:37 system | sending SIGTERM to schedule.1 (pid 1849)
08:39:37 system | sending SIGTERM to worker_short.1 (pid 1874)
08:39:37 system | sending SIGTERM to worker_long.1 (pid 1883)
08:39:37 system | sending SIGTERM to worker_default.1 (pid 1882)
08:39:37 redis_socketio.1 | 1851:signal-handler (1701592777) Received SIGTERM scheduling shutdown…
08:39:37 system | web.1 stopped (rc=-15)
08:39:37 system | worker_long.1 stopped (rc=-15)
08:39:37 system | watch.1 stopped (rc=-15)
08:39:37 system | worker_default.1 stopped (rc=-15)
08:39:37 system | worker_short.1 stopped (rc=-15)
08:39:37 system | socketio.1 stopped (rc=-15)
08:39:37 system | schedule.1 stopped (rc=-15)
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.757 # User requested shutdown…
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.757 * Removing the pid file.
08:39:37 redis_socketio.1 | 1851:M 03 Dec 2023 08:39:37.757 # Redis is now ready to exit, bye bye…
08:39:37 system | redis_socketio.1 stopped (rc=-15)

I rebooted VPS. But that didn’t work. Restarted the system. Then changed the port for socketio & webserver.

Also tried bench restart which showed the following error:
ERROR: sudo supervisorctl restart frappe-bench-workers: frappe-bench-web:

avc · December 3, 2023, 10:55am

Hi @Adarsh_B:

I don’t know about your environment, but seems you are in production mode ( used bench setup production ). In this scenario, you don’t need to start the bench … because the system runs all the services automatically, and ports are in use.

Try
supervisorctl status

Hope this helps.

trentmu · December 6, 2023, 1:48am

@avc is correct

ganureddy · December 6, 2023, 3:21am

Try this command

sudo fuser -k 13000/tcp

sudo fuser -k 10001/tcp

bench start