[Solved] "File upload disconnected"

Hello
I’m using ERPNext Production version 10.

I’ve done various database imports through the import tool. However, this does not work only for the Doctype “Item Group”.

Our team assumes this might be because the SocketIO port could be closed/not forwarded.

What do you guys think about this? SocketIO runs by default on port 9000 and has not been changed since we installed ERPNext. If this is a problem, how do we open/forward the port?

regards
Val

You can check its status with

sudo systemctl status supervisor

If it isn’t running, you can manually start/restart it with

sudo systemctl restart supervisor

or

supervisorctl restart all

supervisor is active and running. A restart doesn’t help, unfortunatly. Also I’d like to mention again that other file imports do work (such as customer or item) but this specific one refuses.

regards
Val

What does your /etc/hosts file contain?

cat /etc/hosts

127.0.0.1	localhost
127.0.1.1	ubuntu

# The following lines are desirable for IPv6 capable hosts
::1     localhost ip6-localhost ip6-loopback
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters

That looks OK. This is often suggested… (though I personally am not a fan as it can cause high memory usage)

echo fs.inotify.max_user_watches=524288 | sudo tee -a /etc/sysctl.conf && sudo sysctl -p
cd ~/frappe-bench
bench restart

Seems like you’ve hit something here.
Bench restart throws out the following.

INFO:bench.utils:sudo supervisorctl restart frappe-bench-workers: frappe-bench-web:
frappe-bench-workers:frappe-bench-frappe-schedule: stopped
frappe-bench-workers:frappe-bench-frappe-default-worker-0: stopped
frappe-bench-workers:frappe-bench-frappe-long-worker-0: stopped
frappe-bench-workers:frappe-bench-frappe-short-worker-0: stopped
frappe-bench-web:frappe-bench-frappe-web: stopped
frappe-bench-workers:frappe-bench-frappe-schedule: started
frappe-bench-workers:frappe-bench-frappe-default-worker-0: started
frappe-bench-workers:frappe-bench-frappe-long-worker-0: started
frappe-bench-workers:frappe-bench-frappe-short-worker-0: started
frappe-bench-web:frappe-bench-frappe-web: started
frappe-bench-web:frappe-bench-node-socketio: ERROR (spawn error)

Like you said at the start, the socketio process isn’t happy. What does this give you

netstat -tnlp | grep -i listen

Yup. When I checked it, nothing seemed odd, but now we can be certain.

(Not all processes could be identified, non-owned process info
     will not be shown, you would have to be root to see it all.)
    tcp        0      0 127.0.0.1:6379          0.0.0.0:*               LISTEN      -               
    tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      -               
    tcp        0      0 0.0.0.0:53              0.0.0.0:*               LISTEN      -               
    tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      -               
    tcp        0      0 0.0.0.0:25              0.0.0.0:*               LISTEN      -               
    tcp        0      0 127.0.0.1:8000          0.0.0.0:*               LISTEN      7177/python     
    tcp6       0      0 :::3306                 :::*                    LISTEN      -               
    tcp6       0      0 :::53                   :::*                    LISTEN      -               
    tcp6       0      0 :::22                   :::*                    LISTEN      -               
    tcp6       0      0 :::25                   :::*                    LISTEN      -

edit: Output as root:

tcp        0      0 127.0.0.1:6379          0.0.0.0:*               LISTEN      1168/redis-server 1
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      1489/nginx -g daemo
tcp        0      0 0.0.0.0:53              0.0.0.0:*               LISTEN      845/dnsmasq     
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      1456/sshd       
tcp        0      0 0.0.0.0:25              0.0.0.0:*               LISTEN      2369/master     
tcp        0      0 127.0.0.1:8000          0.0.0.0:*               LISTEN      7177/python     
tcp6       0      0 :::3306                 :::*                    LISTEN      1451/mysqld     
tcp6       0      0 :::53                   :::*                    LISTEN      845/dnsmasq     
tcp6       0      0 :::22                   :::*                    LISTEN      1456/sshd       
tcp6       0      0 :::25                   :::*                    LISTEN      2369/master

There should be something like so…

tcp        0      0 127.0.0.1:13000         0.0.0.0:*               LISTEN      -                   
tcp        0      0 127.0.0.1:11000         0.0.0.0:*               LISTEN      -                   
tcp        0      0 127.0.0.1:8000          0.0.0.0:*               LISTEN      -                   
tcp        0      0 127.0.0.1:12000         0.0.0.0:*               LISTEN      -                   
tcp        0      0 127.0.0.1:9000          0.0.0.0:*               LISTEN      -                   

So your processes are not all loading. Have you checked the log files for other errors?

They weren’t loaded because I wasn’t running the bench while executing netstat and grep.
Having started the bench, I opened a second terminal and the output is as following:

tcp        0      0 127.0.0.1:6379          0.0.0.0:*               LISTEN      1168/redis-server 1
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      1489/nginx -g daemo
tcp        0      0 0.0.0.0:53              0.0.0.0:*               LISTEN      845/dnsmasq     
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      1456/sshd       
tcp        0      0 127.0.0.1:11000         0.0.0.0:*               LISTEN      28994/redis-server 
tcp        0      0 0.0.0.0:25              0.0.0.0:*               LISTEN      2369/master     
tcp        0      0 0.0.0.0:8000            0.0.0.0:*               LISTEN      29003/python    
tcp        0      0 127.0.0.1:12000         0.0.0.0:*               LISTEN      28977/redis-server 
tcp        0      0 127.0.0.1:13000         0.0.0.0:*               LISTEN      28997/redis-server 
tcp6       0      0 :::3306                 :::*                    LISTEN      1451/mysqld     
tcp6       0      0 :::53                   :::*                    LISTEN      845/dnsmasq     
tcp6       0      0 :::22                   :::*                    LISTEN      1456/sshd       
tcp6       0      0 :::25                   :::*                    LISTEN      2369/master     
tcp6       0      0 :::6787                 :::*                    LISTEN      29105/node      
tcp6       0      0 :::9000                 :::*                    LISTEN      29000/node

Can you show the socketio log file?

tail --lines=40 logs/redis-socketio*.log

Also, which version of node/npm do you have

node -v && npm -v

v8.15.1
6.4.1

However, those seem outdated now that I’m seeing the numbers. Actually, I’m surprised we are using npm, since I was under the assumption that Yarn is the packet manager for erpnext.

Also about this:

This is the result:

==> logs/redis-socketio.error.log <==

==> logs/redis-socketio.log <==
      _.-``    `.  `_.  ''-._           Redis 3.0.6 (00000000/0) 64 bit
  .-`` .-```.  ```\/    _.,_ ''-._                                   
 (    '      ,       .-`  | `,    )     Running in standalone mode
 |`-._`-...-` __...-.``-._|'` _.-'|     Port: 12000
 |    `-._   `._    /     _.-'    |     PID: 2018
  `-._    `-._  `-./  _.-'    _.-'                                   
 |`-._`-._    `-.__.-'    _.-'_.-'|                                  
 |    `-._`-._        _.-'_.-'    |           http://redis.io        
  `-._    `-._`-.__.-'_.-'    _.-'                                   
 |`-._`-._    `-.__.-'    _.-'_.-'|                                  
 |    `-._`-._        _.-'_.-'    |                                  
  `-._    `-._`-.__.-'_.-'    _.-'                                   
      `-._    `-.__.-'    _.-'                                       
          `-._        _.-'                                           
              `-.__.-'                                               

2018:M 23 Apr 09:27:11.852 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
2018:M 23 Apr 09:27:11.852 # Server started, Redis version 3.0.6
2018:M 23 Apr 09:27:11.852 # 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.
2018:M 23 Apr 09:27:11.852 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
2018:M 23 Apr 09:27:11.864 * The server is now ready to accept connections on port 12000
2018:signal-handler (1556004498) Received SIGTERM scheduling shutdown...
2018:M 23 Apr 09:28:18.987 # User requested shutdown...
2018:M 23 Apr 09:28:18.987 # Redis is now ready to exit, bye bye...
5042:M 23 Apr 11:10:28.900 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
5042:M 23 Apr 11:10:28.914 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
5042:M 23 Apr 11:10:28.914 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
5042:M 23 Apr 11:10:28.914 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
5082:M 23 Apr 11:10:30.496 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
5082:M 23 Apr 11:10:30.498 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
5082:M 23 Apr 11:10:30.499 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
5082:M 23 Apr 11:10:30.499 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
5129:M 23 Apr 11:10:32.523 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
5129:M 23 Apr 11:10:32.523 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
5129:M 23 Apr 11:10:32.523 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
5129:M 23 Apr 11:10:32.523 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
5150:M 23 Apr 11:10:35.547 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
5150:M 23 Apr 11:10:35.554 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
5150:M 23 Apr 11:10:35.555 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
5150:M 23 Apr 11:10:35.555 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use

Holy cow! How did I not see this? Yeah, apparently redis said bye at one point. Too much stuff going on.

I’m sure if you fix that piece, you’ll be OK.
Limits can be set both in the current session and/or system-wide setting

ulimit -Sn 100000 # This will only work if hard limit is big enough.
sysctl -w fs.file-max=100000

There is a test tool for redis here - https://redis.io/docs/management/optimization/benchmarks/

Thanks for the amount of help you’ve given me so far. Unfortunatly, nothing seems to help.
I went through the following steps:

ulimit -Sn 100000 # This will only work if hard limit is big enough.
sysctl -w fs.file-max=100000

After that, I followed this guide, and also did this.

Then I went through your suggested steps again.
echo fs.inotify.max_user_watches=524288 | sudo tee -a /etc/sysctl.conf && sudo sysctl -p
output:

fs.inotify.max_user_watches=524288
fs.inotify.max_user_watches = 524288
fs.inotify.max_user_watches = 524288
fs.inotify.max_user_watches = 524288
vm.overcommit_memory = 1
fs.inotify.max_user_watches = 524288

then netstat -tnlp | grep -i listen
output:

(Not all processes could be identified, non-owned process info
 will not be shown, you would have to be root to see it all.)
tcp        0      0 127.0.0.1:6379          0.0.0.0:*               LISTEN      -               
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      -               
tcp        0      0 0.0.0.0:53              0.0.0.0:*               LISTEN      -               
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      -               
tcp        0      0 127.0.0.1:11000         0.0.0.0:*               LISTEN      14842/redis-server 
tcp        0      0 0.0.0.0:25              0.0.0.0:*               LISTEN      -               
tcp        0      0 0.0.0.0:8000            0.0.0.0:*               LISTEN      14840/python    
tcp        0      0 127.0.0.1:12000         0.0.0.0:*               LISTEN      14825/redis-server 
tcp        0      0 127.0.0.1:13000         0.0.0.0:*               LISTEN      14845/redis-server 
tcp6       0      0 :::3306                 :::*                    LISTEN      -               
tcp6       0      0 :::53                   :::*                    LISTEN      -               
tcp6       0      0 :::22                   :::*                    LISTEN      -               
tcp6       0      0 :::25                   :::*                    LISTEN      -               
tcp6       0      0 :::6787                 :::*                    LISTEN      14945/node      
tcp6       0      0 :::9000                 :::*                    LISTEN      14833/node    

then tail --lines=40 logs/redis-socketio*.log
output:

[Only showing the latest error output]
15452:M 23 Apr 15:27:30.324 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
15452:M 23 Apr 15:27:30.324 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
15452:M 23 Apr 15:27:30.324 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
15452:M 23 Apr 15:27:30.324 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
15492:M 23 Apr 15:27:32.052 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
15492:M 23 Apr 15:27:32.056 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
15492:M 23 Apr 15:27:32.056 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
15492:M 23 Apr 15:27:32.057 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
15535:M 23 Apr 15:27:34.083 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
15535:M 23 Apr 15:27:34.105 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
15535:M 23 Apr 15:27:34.108 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
15535:M 23 Apr 15:27:34.108 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use
15554:M 23 Apr 15:27:37.144 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
15554:M 23 Apr 15:27:37.145 # Redis can't set maximum open files to 10032 because of OS error: Operation not permitted.
15554:M 23 Apr 15:27:37.145 # Current maximum open files is 4096. maxclients has been reduced to 4064 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
15554:M 23 Apr 15:27:37.145 # Creating Server TCP listening socket 127.0.0.1:12000: bind: Address already in use

Even though your solution, and lots of others would’ve made sense, it did not work.

After making the changes to your system, you might need to restart the supervisor and bench subsystems

cd ~frappe-bench
sudo supervisorctl restart all
bench restart

The fact that it reports the port in use already, implies that another process has already been attempted

I’m sorry, but I think I’m mixing the order of commands. When the bench is currently turned off, this works.
However, after that, I can’t use bench start anymore.
When starting the bench, he tells me that the ports are already in use and shuts down.
So usually I would just sudo supervisorcts stop all and bench start after this.

Once the bench is running, I open another tab. Then I can sudo supervisorctl restart all
but that throws errors, just as bench restart.

Anyway, going forward, I decided to try the import again and although I got the error again, the file was actually saved this time. So I guess my problem is kind of solved…?

In any case, thank you for your time

Regards,
Val

EDIT: Visual Bug! The file is not actually uploaded, so the same error persists…

Please close this thread.
Apparently my whole installation is a mess. It seems like a mix of Developer and Production bench and I will do a complete reinstallation.

I once again thank Trentmu for his time for a problem which was clearly on my end.

FYI both environments (production and development) can run from the same directory for eg /home/frappe/frappe-bench

But of course one must be shut down before the other can be started.

So if the ‘bench start’ process dies with ‘bind: Address already in use’, that typically means a process from the production remains running and must be shutdown with say ‘sudo supervisorctl stop all’