Issue #264: [doc] IOError: request data read error on git push due to mod_wsgi
| Reported by: | freakrob |
| State: | new |
| Created on: | 2017-01-25 06:34 |
| Updated on: | 2018-05-18 20:07 |
Description
I recently updated my instance of kallithea from 0.3.1 to 0.3.2 and followed the new installation instructions regarding VirtualHost entries and mod_wsgi that resulted from issue #203
However, I recently noticed that some git pushes would hang on the user side and about five minutes later kallithea would completely crash.
Checking the logs, I found:
[Mon Jan 16 15:07:53.637099 2017] [wsgi:error] [pid 7213:tid 140207274170112] 2017-01-16 15:07:53.636 INFO [kallithea.lib.auth_modules.auth_ldap] user USERA authenticated correctly [Mon Jan 16 15:07:53.833657 2017] [wsgi:error] [pid 7213:tid 140207274170112] 2017-01-16 15:07:53.833 INFO [kallithea.lib.base] Access for IP:MY_IP allowed [Mon Jan 16 15:07:53.962835 2017] [wsgi:error] [pid 7213:tid 140207274170112] 2017-01-16 15:07:53.962 INFO [kallithea.lib.middleware.simplegit] push action on Git repo "REPO" by "USERA" from MY_IP [Mon Jan 16 15:07:55.279728 2017] [wsgi:error] [pid 7213:tid 140206053259008] Exception in thread Thread-4876: [Mon Jan 16 15:07:55.279767 2017] [wsgi:error] [pid 7213:tid 140206053259008] Traceback (most recent call last): [Mon Jan 16 15:07:55.279771 2017] [wsgi:error] [pid 7213:tid 140206053259008] File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner [Mon Jan 16 15:07:55.279773 2017] [wsgi:error] [pid 7213:tid 140206053259008] self.run() [Mon Jan 16 15:07:55.279776 2017] [wsgi:error] [pid 7213:tid 140206053259008] File "/srv/kallithea-0.3.2/kallithea/lib/vcs/subprocessio.py", line 66, in run [Mon Jan 16 15:07:55.279779 2017] [wsgi:error] [pid 7213:tid 140206053259008] b = s.read(4096) [Mon Jan 16 15:07:55.279781 2017] [wsgi:error] [pid 7213:tid 140206053259008] IOError: request data read error [Mon Jan 16 15:07:55.279786 2017] [wsgi:error] [pid 7213:tid 140206053259008] [Mon Jan 16 15:12:55.379509 2017] [wsgi:error] [pid 7215:tid 140207143753472] [client MY_IP:49182] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:16:00.026787 2017] [wsgi:error] [pid 7215:tid 140207177324288] [client OTHER_IP:48696] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:16:04.860132 2017] [wsgi:error] [pid 7215:tid 140207017862912] [client OTHER_IP:48697] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:17:59.984598 2017] [wsgi:error] [pid 7214:tid 140207059826432] [client OTHER_IP:48698] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:18:04.913305 2017] [wsgi:error] [pid 7215:tid 140207051433728] [client OTHER_IP:48699] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:18:59.934258 2017] [wsgi:error] [pid 7215:tid 140207043041024] [client OTHER_IP:48700] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:21:00.591058 2017] [wsgi:error] [pid 7215:tid 140207068219136] [client OTHER_IP:48701] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:21:04.961031 2017] [wsgi:error] [pid 7215:tid 140207126968064] [client OTHER_IP:48702] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi [Mon Jan 16 15:24:04.962009 2017] [wsgi:error] [pid 7214:tid 140207026255616] [client OTHER_IP:48703] Timeout when reading response headers from daemon process 'kallithea': /srv/kallithea/dispatch.wsgi
This log shows USER_A pushing into REPO from MY_IP. After about 5 minutes of hanging, USER_A checked the web page, which didn't load. Then he tried a few more times from another device OTHER_IP. The 5 minute gap was pretty consistent and is probably a 300sec timeout somehwere.
At first it only affected a single repository, so I left this issue alone. However, it now had crept up to the point of affecting a majority of the repos I use daily.
Yesterday I went bug hunting and found out that the recent change from embedded to daemon mode of kallithea caused this. Prior to version 4.4.0 of mod_wsgi, chunked requests -- which git performs when large pushes are made -- were broken in daemon mode but worked fine in embedded mode. Of course I only found this after spending ~6h and reading obscure mailing list posts from 2013.
It would be really nice if the documentation could be updated to reflect that version 4.4.0 and up of mod_wsgi is needed in order to run in daemon mode as suggested by the installation instruction.
Attachments
Comments
Comment by Mads Kiilerich, on 2017-01-25 11:18
Failure like this has often seemed to be related to http://stackoverflow.com/questions/10790232/hanging-at-post-git-receive-pack-chunked ... or at least "solved" by the same workaround. The problem could perhaps also be explained by your repository or pushes getting over a certain size.
A documentation patch would be awesome!
Comment by Thomas De Schampheleire, on 2018-05-18 20:07