Thanks for the report. There is something not working as it should. I will have a look at it.

The latest MirrorManager release introduced a bug which lead to wrongly calculating the rsync timeout: https://github.com/fedora-infra/mirrormanager2/pull/244

It was always 1 second, so most rsync crawls aborted.

The other error 'BASE URL [] does not exist' does not happen any more. I see it in the log of other mirrors, but I think it might have been something temporary.

Closing this now. Please re-open if you see something similar.

Hi Adrian,

I think the issue is still there. For example in the crawl log of this morning (2018-03-15 05:51:35,817 - INFO - Worker '461eb1d' starting on host <Host(455 - fr2.rpmfind.net)>), I see that the rsync command on fedora-linux has been discarded, presumably because the preliminary "HEAD /linux/fedora/linux/" http request didn't reach me. I have traces of other categories being successfully crawled at matching timestamps (one http HEAD request in the access_log for epel, and one in the ssl_access_log for fedora-secondary, I don't know if this difference is significant)

I made some tests with a local mm2 instance, and I could trigger this broken pipe error in conn.request(), when check_head() is not protected by the try/except handling code (occurring when the second category is crawled):

~~~~
Traceback (most recent call last):
File "./mm2_crawler", line 1514, in worker
rc = per_host(session, host.id, options, config)
File "./mm2_crawler", line 1318, in per_host
exists = check_for_base_dir(hoststate, host_category_urls)
File "./mm2_crawler", line 1137, in check_for_base_dir
exists = check_head(hoststate, u, None, False, True)
File "./mm2_crawler", line 623, in check_head
'User-Agent':'mirrormanager-crawler/0.1 (+https://github.com/fedora-infra/mirrormanager2/)'})
File "/usr/lib64/python2.7/httplib.py", line 1042, in request
self._send_request(method, url, body, headers)
File "/usr/lib64/python2.7/httplib.py", line 1082, in _send_request
self.endheaders(body)
File "/usr/lib64/python2.7/httplib.py", line 1038, in endheaders
self._send_output(message_body)
File "/usr/lib64/python2.7/httplib.py", line 882, in _send_output
self.send(msg)
File "/usr/lib64/python2.7/httplib.py", line 858, in send
self.sock.sendall(data)
File "/usr/lib64/python2.7/socket.py", line 228, in meth
return getattr(self._sock,name)(*args)
error: [Errno 32] Broken pipe
~~~~

In my tiny test environment, putting conn.request() inside the try/except statement that already protects conn.getresponse() seems to be sufficient to get rid of these errors.

Cool, thanks for debugging this! I still do not understand it and therefore I am not really happy just surrounding it with a try/except block without understanding it.

Can you share a bit more about your test setup, I would really like to understand it better. Are you using http or https as URLs? Could you provide a test case for the test suite?

I setup a local mm2 server, created the database, setup just the minimal category stuff (fedora linux, epel, and fedora secondary), and created the same host (fr2.rpmfind.net) than on the production server (with both http and https URLs, but maybe the order is different). What I observe is:

• if two conn.request() on the same netloc/scheme are done in less than the default keep-alive interval (5 seconds), it works.

• if a second conn.request() happens after the keep-alive interval, but while the socket is still in CLOSE_WAIT state (lsof), then conn.request() works but conn.getresponse() returns an empty reply, and the exception handler retries after closing the connection. So this case works too since the connection is closed and opened again.

• if a second conn.request() happens after the socket CLOSE_WAIT timer has expired (for example after 40 seconds in my case), I get the broken pipe error in conn.request(), that is not handled.

These three situations can be triggered, by commenting the try/except statement that protects check_head(), and by duplicating the code that does the conn.request(), conn.getresponse() and conn.end_request() calls, separating the two sets by an arbitrary sleep delay.

I think this is also coherent with the crawler log:

• fedora-secondary URL is tested first using https scheme: it works
• epel url is tested some minutes later using http scheme: it works too because the port is different.
• fedora-linux url fails both in http and https, because it tries to reuse the two previous sockets, that don't exist anymore (keep-alive + CLOSE_WAIT delay)

Thanks for your help. I think I do understand the problem now.

MirrorManager does not really know when the crawled mirror closes the keep-alive connection. Therefore there is the retry code path in the try/except block. In combination with HTTPS it seems that the exception happens earlier and therefore the connection setup needs to be moved in the try block.

I will open a github PR with a fix for this.

https://github.com/fedora-infra/mirrormanager2/pull/245