[doc] IOError: request data read error on git push due to mod_wsgi

Issue #264 new
freakrob created an issue

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.

Comments (2)

  1. Log in to comment