Bench is not starting when use bench start

Bench is not starting when run command “bench start”

Error Comes :-

Traceback (most recent call last):
File “/usr/local/bin/bench”, line 11, in
load_entry_point(‘bench’, ‘console_scripts’, ‘bench’)()
File “/opt/erpnext/bench-repo/bench/cli.py”, line 40, in cli
bench_command()
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 722, in call
return self.main(*args, **kwargs)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 697, in main
rv = self.invoke(ctx)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 1063, in invoke
Command.invoke(self, ctx)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 895, in invoke
return ctx.invoke(self.callback, **ctx.params)
File “/usr/local/lib/python2.7/dist-packages/click/core.py”, line 535, in invoke
return callback(*args, **kwargs)
File “/opt/erpnext/bench-repo/bench/commands/init.py”, line 31, in bench_command
setup_logging(bench_path=bench_path)
File “/opt/erpnext/bench-repo/bench/utils.py”, line 300, in setup_logging
hdlr = logging.FileHandler(log_file)
File “/usr/lib/python2.7/logging/init.py”, line 913, in init
StreamHandler.init(self, self._open())
File “/usr/lib/python2.7/logging/init.py”, line 943, in _open
stream = open(self.baseFilename, self.mode)
IOError: [Errno 13] Permission denied: ‘/opt/erpnext/erpnext/logs/bench.log’

Your bench is installed in /opt hence your user will have issues.

Try this :

I show this msg

frappe@jmv-erp:~/frappe-bench$ bench start
19:16:29 system | redis_socketio.1 started (pid=17444)
19:16:30 redis_socketio.1 | 17451:M 29 Dec 19:16:30.000 * Increased maximum number of open files to 10032 (it was originally set to 1024).
19:16:30 redis_socketio.1 | 17451:M 29 Dec 19:16:30.000 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
19:16:30 system | redis_socketio.1 stopped (rc=1)
19:16:30 system | watch.1 started (pid=17448)
19:16:30 system | redis_queue.1 started (pid=17455)
19:16:30 system | web.1 started (pid=17454)
19:16:30 system | worker_long.1 started (pid=17446)
19:16:30 system | socketio.1 started (pid=17465)
19:16:30 redis_queue.1 | 17463:M 29 Dec 19:16:30.004 * Increased maximum number of open files to 10032 (it was originally set to 1024).
19:16:30 redis_queue.1 | 17463:M 29 Dec 19:16:30.004 # Creating Server TCP listening socket 127.0.0.1:11000: bind: Address already in use
19:16:30 system | redis_queue.1 stopped (rc=1)
19:16:30 system | redis_cache.1 started (pid=17468)
19:16:30 system | worker_default.1 started (pid=17459)
19:16:30 redis_cache.1 | 17473:M 29 Dec 19:16:30.007 * Increased maximum number of open files to 10032 (it was originally set to 1024).
19:16:30 redis_cache.1 | 17473:M 29 Dec 19:16:30.007 # Creating Server TCP listening socket 127.0.0.1:13000: bind: Address already in use
19:16:30 system | redis_cache.1 stopped (rc=1)
19:16:30 system | worker_short.1 started (pid=17462)
19:16:30 system | schedule.1 started (pid=17458)
19:16:30 system | sending SIGTERM to worker_long.1 (pid 17446)
19:16:30 system | sending SIGTERM to watch.1 (pid 17448)
19:16:30 system | sending SIGTERM to web.1 (pid 17454)
19:16:30 system | sending SIGTERM to schedule.1 (pid 17458)
19:16:30 system | sending SIGTERM to worker_default.1 (pid 17459)
19:16:30 system | sending SIGTERM to socketio.1 (pid 17465)
19:16:30 system | sending SIGTERM to worker_short.1 (pid 17462)
19:16:30 system | schedule.1 stopped (rc=-15)
19:16:30 system | worker_long.1 stopped (rc=-15)
19:16:30 system | socketio.1 stopped (rc=-15)
19:16:30 system | web.1 stopped (rc=-15)
19:16:30 system | worker_short.1 stopped (rc=-15)
19:16:30 system | watch.1 stopped (rc=-15)
19:16:30 system | worker_default.1 stopped (rc=-15)

This is the problem.

Hello,
I too have problem with “Bench Start”. I have copied the log below. Can someone help me on this.
I have installed this on a fresh server.

shyampras@SatsolERP:~/bench/frappe-bench$ bench start
08:31:29 system | watch.1 started (pid=2787)
08:31:29 system | redis_socketio.1 started (pid=2793)
08:31:29 redis_socketio.1 | 2805:M 15 Aug 08:31:29.832 * Increased maximum number of open files to 10032 (it was originally set to 1024).
08:31:29 redis_socketio.1 | 2805:M 15 Aug 08:31:29.832 # Warning: 32 bit instance detected but no memory limit set. Setting 3 GB maxmemory limit with ‘noeviction’ policy now.
08:31:29 redis_socketio.1 | .
08:31:29 redis_socketio.1 | .-__ ''-._ 08:31:29 redis_socketio.1 | _.- .. ‘’-._ Redis 3.0.6 (00000000/0) 32 bit
08:31:29 redis_socketio.1 | .-.-```. ```\/ _.,_ ''-._ 08:31:29 redis_socketio.1 | ( ' , .-` | `, ) Running in standalone mode 08:31:29 redis_socketio.1 | |`-._`-...-` __...-.-.|’_.-'| Port: 12000 08:31:29 redis_socketio.1 | |-. ._ / _.-' | PID: 2805 08:31:29 redis_socketio.1 |-._ -._-./ .-’ .-’
08:31:29 redis_socketio.1 | |-._-.
-.__.-' _.-'_.-'| 08:31:29 system | worker_long.1 started (pid=2799) 08:31:29 redis_socketio.1 | |-.
-._ _.-'_.-' | http://redis.io 08:31:29 redis_socketio.1 |-._ -._-..-’.-’ .-’
08:31:29 redis_socketio.1 | |-._-.
-.__.-' _.-'_.-'| 08:31:29 redis_socketio.1 | |-.
-._ _.-'_.-' | 08:31:29 redis_socketio.1 |-._ -._-.
.-’.-’ .-’
08:31:29 redis_socketio.1 | -._-..-’ _.-’
08:31:29 redis_socketio.1 | -._ _.-' 08:31:29 redis_socketio.1 |-.
.-’
08:31:29 redis_socketio.1 |
08:31:29 redis_socketio.1 | 2805:M 15 Aug 08:31:29.832 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
08:31:29 redis_socketio.1 | 2805:M 15 Aug 08:31:29.832 # Server started, Redis version 3.0.6
08:31:29 redis_socketio.1 | 2805:M 15 Aug 08:31:29.832 * The server is now ready to accept connections on port 12000
08:31:29 system | web.1 started (pid=2802)
08:31:29 system | schedule.1 started (pid=2798)
08:31:29 system | redis_cache.1 started (pid=2807)
08:31:29 redis_cache.1 | 2817:M 15 Aug 08:31:29.851 * Increased maximum number of open files to 10032 (it was originally set to 1024).
08:31:29 system | worker_default.1 started (pid=2816)
08:31:29 system | socketio.1 started (pid=2794)
08:31:29 system | redis_queue.1 started (pid=2808)
08:31:29 redis_queue.1 | 2828:M 15 Aug 08:31:29.855 * Increased maximum number of open files to 10032 (it was originally set to 1024).
08:31:29 redis_queue.1 | 2828:M 15 Aug 08:31:29.856 # Warning: 32 bit instance detected but no memory limit set. Setting 3 GB maxmemory limit with ‘noeviction’ policy now.
08:31:29 redis_queue.1 | .
08:31:29 redis_queue.1 | .-__ ''-._ 08:31:29 redis_queue.1 | _.- .. ‘’-.
Redis 3.0.6 (00000000/0) 32 bit
08:31:29 redis_queue.1 | .-.-```. ```\/ _.,_ ''-._ 08:31:29 redis_queue.1 | ( ' , .-` | `, ) Running in standalone mode 08:31:29 redis_queue.1 | |`-._`-...-` __...-.-.
|’_.-'| Port: 11000 08:31:29 redis_queue.1 | |-._ ._ / _.-' | PID: 2828 08:31:29 redis_queue.1 |-._ -._-./ .-’ .-’
08:31:29 redis_queue.1 | |-._-.
-.__.-' _.-'_.-'| 08:31:29 redis_queue.1 | |-.
-._ _.-'_.-' | http://redis.io 08:31:29 redis_queue.1 |-._ -._-..-’.-’ .-’
08:31:29 redis_queue.1 | |-._-.
-.__.-' _.-'_.-'| 08:31:29 redis_queue.1 | |-.
-._ _.-'_.-' | 08:31:29 redis_queue.1 |-._ -._-.
.-’.-’ .-’
08:31:29 redis_queue.1 | -._-..-’ _.-’
08:31:29 redis_queue.1 | -._ _.-' 08:31:29 redis_queue.1 |-.
.-’
08:31:29 redis_queue.1 |
08:31:29 system | worker_short.1 started (pid=2804)
08:31:29 redis_queue.1 | 2828:M 15 Aug 08:31:29.861 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
08:31:29 redis_queue.1 | 2828:M 15 Aug 08:31:29.861 # Server started, Redis version 3.0.6
08:31:29 redis_queue.1 | 2828:M 15 Aug 08:31:29.861 * The server is now ready to accept connections on port 11000
08:31:29 redis_cache.1 | .
08:31:29 redis_cache.1 | .-__ ''-._ 08:31:29 redis_cache.1 | _.- .. ‘’-.
Redis 3.0.6 (00000000/0) 32 bit
08:31:29 redis_cache.1 | .-.-```. ```\/ _.,_ ''-._ 08:31:29 redis_cache.1 | ( ' , .-` | `, ) Running in standalone mode 08:31:29 redis_cache.1 | |`-._`-...-` __...-.-.
|’_.-'| Port: 13000 08:31:29 redis_cache.1 | |-._ ._ / _.-' | PID: 2817 08:31:29 redis_cache.1 |-._ -._-./ .-’ .-’
08:31:29 redis_cache.1 | |-._-.
-.__.-' _.-'_.-'| 08:31:29 redis_cache.1 | |-.
-._ _.-'_.-' | http://redis.io 08:31:29 redis_cache.1 |-._ -._-..-’.-’ .-’
08:31:29 redis_cache.1 | |-._-.
-.__.-' _.-'_.-'| 08:31:29 redis_cache.1 | |-.
-._ _.-'_.-' | 08:31:29 redis_cache.1 |-._ -._-.
.-’_.-’ _.-’
08:31:29 redis_cache.1 | -._-..-’ _.-’
08:31:29 redis_cache.1 | -._ _.-' 08:31:29 redis_cache.1 |-.
.-’
08:31:29 redis_cache.1 |
08:31:29 redis_cache.1 | 2817:M 15 Aug 08:31:29.865 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
08:31:29 redis_cache.1 | 2817:M 15 Aug 08:31:29.865 # Server started, Redis version 3.0.6
08:31:29 redis_cache.1 | 2817:M 15 Aug 08:31:29.865 * The server is now ready to accept connections on port 13000
08:31:30 socketio.1 | listening on *: 9000
08:31:33 worker_default.1 | Traceback (most recent call last):
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 484, in connect
08:31:33 worker_default.1 | sock = self._connect()
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 541, in _connect
08:31:33 worker_default.1 | raise err
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 529, in _connect
08:31:33 worker_default.1 | sock.connect(socket_address)
08:31:33 worker_default.1 | ConnectionRefusedError: [Errno 111] Connection refused
08:31:33 worker_default.1 |
08:31:33 worker_default.1 | During handling of the above exception, another exception occurred:
08:31:33 worker_default.1 |
08:31:33 worker_default.1 | Traceback (most recent call last):
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/client.py”, line 667, in execute_command
08:31:33 worker_default.1 | connection.send_command(*args)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 610, in send_command
08:31:33 worker_default.1 | self.send_packed_command(self.pack_command(*args))
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 585, in send_packed_command
08:31:33 worker_default.1 | self.connect()
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 489, in connect
08:31:33 worker_default.1 | raise ConnectionError(self._error_message(e))
08:31:33 worker_default.1 | redis.exceptions.ConnectionError: Error 111 connecting to localhost:11000. Connection refused.
08:31:33 worker_default.1 |
08:31:33 worker_default.1 | During handling of the above exception, another exception occurred:
08:31:33 worker_default.1 |
08:31:33 worker_default.1 | Traceback (most recent call last):
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 484, in connect
08:31:33 worker_default.1 | sock = self._connect()
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 541, in _connect
08:31:33 worker_default.1 | raise err
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 529, in _connect
08:31:33 worker_default.1 | sock.connect(socket_address)
08:31:33 worker_default.1 | ConnectionRefusedError: [Errno 111] Connection refused
08:31:33 worker_default.1 |
08:31:33 worker_default.1 | During handling of the above exception, another exception occurred:
08:31:33 worker_default.1 |
08:31:33 worker_default.1 | Traceback (most recent call last):
08:31:33 worker_default.1 | File “/usr/lib/python3.5/runpy.py”, line 184, in _run_module_as_main
08:31:33 worker_default.1 | “main”, mod_spec)
08:31:33 worker_default.1 | File “/usr/lib/python3.5/runpy.py”, line 85, in _run_code
08:31:33 worker_default.1 | exec(code, run_globals)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/apps/frappe/frappe/utils/bench_helper.py”, line 97, in
08:31:33 worker_default.1 | main()
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/apps/frappe/frappe/utils/bench_helper.py”, line 18, in main
08:31:33 worker_default.1 | click.Group(commands=commands)(prog_name=‘bench’)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/click/core.py”, line 764, in call
08:31:33 worker_default.1 | return self.main(*args, **kwargs)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/click/core.py”, line 717, in main
08:31:33 worker_default.1 | rv = self.invoke(ctx)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/click/core.py”, line 1137, in invoke
08:31:33 worker_default.1 | return _process_result(sub_ctx.command.invoke(sub_ctx))
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/click/core.py”, line 1137, in invoke
08:31:33 worker_default.1 | return _process_result(sub_ctx.command.invoke(sub_ctx))
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/click/core.py”, line 956, in invoke
08:31:33 worker_default.1 | return ctx.invoke(self.callback, **ctx.params)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/click/core.py”, line 555, in invoke
08:31:33 worker_default.1 | return callback(*args, **kwargs)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/apps/frappe/frappe/commands/scheduler.py”, line 158, in start_worker
08:31:33 worker_default.1 | start_worker(queue, quiet = quiet)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/apps/frappe/frappe/utils/background_jobs.py”, line 150, in start_worker
08:31:33 worker_default.1 | Worker(queues, name=get_worker_name(queue)).work(logging_level = logging_level)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/rq/worker.py”, line 466, in work
08:31:33 worker_default.1 | self.register_birth()
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/rq/worker.py”, line 273, in register_birth
08:31:33 worker_default.1 | if self.connection.exists(self.key) and
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/client.py”, line 951, in exists
08:31:33 worker_default.1 | return self.execute_command(‘EXISTS’, name)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/client.py”, line 673, in execute_command
08:31:33 worker_default.1 | connection.send_command(*args)
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 610, in send_command
08:31:33 worker_default.1 | self.send_packed_command(self.pack_command(*args))
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 585, in send_packed_command
08:31:33 worker_default.1 | self.connect()
08:31:33 worker_default.1 | File “/home/shyampras/bench/frappe-bench/env/lib/python3.5/site-packages/redis/connection.py”, line 489, in connect
08:31:33 worker_default.1 | raise ConnectionError(self._error_message(e))
08:31:33 worker_default.1 | redis.exceptions.ConnectionError: Error 111 connecting to localhost:11000. Connection refused.
08:31:33 system | worker_default.1 stopped (rc=1)
08:31:33 system | sending SIGTERM to watch.1 (pid 2787)
08:31:33 system | sending SIGTERM to socketio.1 (pid 2794)
08:31:33 system | sending SIGTERM to schedule.1 (pid 2798)
08:31:33 system | sending SIGTERM to redis_socketio.1 (pid 2793)
08:31:33 system | sending SIGTERM to worker_long.1 (pid 2799)
08:31:33 system | sending SIGTERM to worker_short.1 (pid 2804)
08:31:33 system | sending SIGTERM to redis_queue.1 (pid 2808)
08:31:33 system | sending SIGTERM to web.1 (pid 2802)
08:31:33 system | sending SIGTERM to redis_cache.1 (pid 2807)
08:31:33 redis_socketio.1 | 2805:signal-handler (1565838093) Received SIGTERM scheduling shutdown…
08:31:33 redis_queue.1 | 2828:signal-handler (1565838093) Received SIGTERM scheduling shutdown…
08:31:33 redis_cache.1 | 2817:signal-handler (1565838093) Received SIGTERM scheduling shutdown…
08:31:33 system | worker_long.1 stopped (rc=-15)
08:31:33 system | socketio.1 stopped (rc=-15)
08:31:33 system | schedule.1 stopped (rc=-15)
08:31:33 system | web.1 stopped (rc=-15)
08:31:33 redis_socketio.1 | 2805:M 15 Aug 08:31:33.643 # User requested shutdown…
08:31:33 redis_socketio.1 | 2805:M 15 Aug 08:31:33.643 # Redis is now ready to exit, bye bye…
08:31:33 system | watch.1 stopped (rc=-15)
08:31:33 system | redis_socketio.1 stopped (rc=-15)
08:31:33 system | worker_short.1 stopped (rc=-15)
08:31:33 redis_queue.1 | 2828:M 15 Aug 08:31:33.663 # User requested shutdown…
08:31:33 redis_queue.1 | 2828:M 15 Aug 08:31:33.663 # Redis is now ready to exit, bye bye…
08:31:33 system | redis_queue.1 stopped (rc=-15)
08:31:33 redis_cache.1 | 2817:M 15 Aug 08:31:33.669 # User requested shutdown…
08:31:33 redis_cache.1 | 2817:M 15 Aug 08:31:33.669 # Redis is now ready to exit, bye bye…
08:31:33 system | redis_cache.1 stopped (rc=-15)

This is the problem -

A search on that will get you pointers to try like this

Hello Clarkej, Thanks for the pointers. I tried bench start in separate terminal but encountered same error!

if i am trying sudo supervisorctl stop all , it says supervisorctl cmd not found.

please help me resolve.
Thank u so much in advance. I appreciate it.

Did you run the command bench setup supervisorctl then try again

1 Like