Issue solved, cause unknown
In contrast to socket.io, redis was also not working
frappe-user@ubuntu-erp:~/frappe-bench$ supervisorctl status
frappe-bench-redis:frappe-bench-redis-cache FATAL Exited too quickly (process log may have details)
frappe-bench-redis:frappe-bench-redis-queue FATAL Exited too quickly (process log may have details)
frappe-bench-web:frappe-bench-frappe-web RUNNING pid 1675110, uptime 0:00:01
frappe-bench-web:frappe-bench-node-socketio BACKOFF Exited too quickly (process log may have details)
frappe-bench-workers:frappe-bench-frappe-long-worker-0 RUNNING pid 1439880, uptime 16:19:48
frappe-bench-workers:frappe-bench-frappe-schedule RUNNING pid 1439878, uptime 16:19:48
frappe-bench-workers:frappe-bench-frappe-short-worker-0 RUNNING pid 1439879, uptime 16:19:48
Checked out each of their logs
less ~/frappe-bench/logs/redis-cache.log
less ~/frappe-bench/logs/redis-queue.log
less ~/frappe-bench/logs/node-socketio.log
Last two were for especial significance for resolving the issue for redis-cache
1440115:C 29 May 2024 22:19:51.660 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=1440115, just started
1440115:C 29 May 2024 22:19:51.660 # Configuration loaded
1440115:M 29 May 2024 22:19:51.661 * Increased maximum number of open files to 10032 (it was originally set to 1024).
1440115:M 29 May 2024 22:19:51.661 # Could not create server TCP listening socket 127.0.0.1:13000: bind: Address already in use
1440139:C 29 May 2024 22:20:01.059 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
Something similar was for the case of redis-queue and socket.io , found out each of there ports.
Like in this case it is port 13000
sudo lsof -i :13000
listed all the processes on port 13000
Used the following kill command to switch off all the current running redis process
sudo kill -9 <PID>
redis-ser 32054 frappe-user 6u IPv4 197500 0t0 TCP localhost:13000 (LISTEN)
redis-ser 32054 frappe-user 7u IPv4 197573 0t0 TCP localhost:13000->localhost:44670 (ESTABLISHED)
redis-ser 32054 frappe-user 8u IPv4 197575 0t0 TCP localhost:13000->localhost:44686 (ESTABLISHED)
redis-ser 32054 frappe-user 9u IPv4 197586 0t0 TCP localhost:13000->localhost:44700 (ESTABLISHED)
redis-ser 32054 frappe-user 10u IPv4 197590 0t0 TCP localhost:13000->localhost:44716 (ESTABLISHED)
redis-ser 32054 frappe-user 11u IPv4 15095695 0t0 TCP localhost:13000->localhost:43352 (ESTABLISHED)
redis-ser 32054 frappe-user 12u IPv4 200049 0t0 TCP localhost:13000->localhost:60924 (ESTABLISHED)
redis-ser 32054 frappe-user 13u IPv4 200052 0t0 TCP localhost:13000->localhost:60940 (ESTABLISHED)
redis-ser 32054 frappe-user 14u IPv4 199561 0t0 TCP localhost:13000->localhost:60956 (ESTABLISHED)
redis-ser 32054 frappe-user 15u IPv4 15810021 0t0 TCP localhost:13000->localhost:43550 (ESTABLISHED)
redis-ser 32054 frappe-user 16u IPv4 15814004 0t0 TCP localhost:13000->localhost:55960 (ESTABLISHED)
redis-ser 32054 frappe-user 17u IPv4 16248351 0t0 TCP localhost:13000->localhost:34014 (ESTABLISHED)
redis-ser 32054 frappe-user 18u IPv4 15096763 0t0 TCP localhost:13000->localhost:45800 (ESTABLISHED)
redis-ser 32054 frappe-user 19u IPv4 15098274 0t0 TCP localhost:13000->localhost:45816 (ESTABLISHED)
redis-ser 32054 frappe-user 20u IPv4 15728964 0t0 TCP localhost:13000->localhost:32828 (ESTABLISHED)
redis-ser 32054 frappe-user 21u IPv4 15735257 0t0 TCP localhost:13000->localhost:56048 (ESTABLISHED)
redis-ser 32054 frappe-user 22u IPv4 15735263 0t0 TCP localhost:13000->localhost:56054 (ESTABLISHED)
redis-ser 32054 frappe-user 23u IPv4 16248353 0t0 TCP localhost:13000->localhost:34020 (ESTABLISHED)
redis-ser 32054 frappe-user 24u IPv4 16248356 0t0 TCP localhost:13000->localhost:34034 (ESTABLISHED)
These are the ones already related to redis. However, there were other python stale connections with status
CLOSE_WAIT
For example,
python 1439878 frappe-user 3u IPv4 16249297 0t0 TCP localhost:34014->localhost:13000 (CLOSE_WAIT)
Similarly killed them.
Rinse and repeated the process for all three and the bench had automatically restarted the services correctly. Which was expected from the logs shared above
frappe-bench-redis:frappe-bench-redis-cache RUNNING pid 1687630, uptime 4:55:06
frappe-bench-redis:frappe-bench-redis-queue RUNNING pid 1687631, uptime 4:55:06
frappe-bench-web:frappe-bench-frappe-web RUNNING pid 1702630, uptime 0:21:25
frappe-bench-web:frappe-bench-node-socketio RUNNING pid 1702631, uptime 0:21:25
frappe-bench-workers:frappe-bench-frappe-long-worker-0 RUNNING pid 1702646, uptime 0:21:23
frappe-bench-workers:frappe-bench-frappe-schedule RUNNING pid 1702644, uptime 0:21:23
frappe-bench-workers:frappe-bench-frappe-short-worker-0 RUNNING pid 1702645, uptime 0:21:23
It took some more tinkering than this, but this is a distilled version one may use to resolve issue at their end.
Also frappe team and other contributors have built a impeccable architecture, easy to navigate it. Well done guys.
Not to mention, bench restart also works flawlessly now.
$ supervisorctl restart frappe-bench-web:
frappe-bench-web:frappe-bench-node-socketio: stopped
frappe-bench-web:frappe-bench-frappe-web: stopped
frappe-bench-web:frappe-bench-frappe-web: started
frappe-bench-web:frappe-bench-node-socketio: started
$ supervisorctl restart frappe-bench-workers:
frappe-bench-workers:frappe-bench-frappe-schedule: stopped
frappe-bench-workers:frappe-bench-frappe-short-worker-0: stopped
frappe-bench-workers:frappe-bench-frappe-long-worker-0: stopped
frappe-bench-workers:frappe-bench-frappe-schedule: started
frappe-bench-workers:frappe-bench-frappe-short-worker-0: started
frappe-bench-workers:frappe-bench-frappe-long-worker-0: started
INFO: A newer version of bench is available: 5.22.3 → 5.22.6