Project

General

Profile

Actions
Copy link

Bug #16393

closed

keepproxy timeout on lugli

Added by Ward Vandewege almost 4 years ago. Updated almost 4 years ago.

Status:
Resolved
Priority:
Normal
Assigned To:
Ward Vandewege
Category:
Keep
Target version:
2020-05-06 Sprint
Story points:
-
Release:
Arvados 2.0.3
Release relationship:
Auto

Description

Keepproxy on lugli seems to be suffering from a timeout error if it can't write an entire block's worth to keepstore within 15s:

May 01 18:44:39 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:39Z" level=info msg=request RequestID=req-35oyym3mwx6bb8qwm7sk remoteAddr="127.0.0.1:35746" reqBytes=67108864 reqForwardedFor=207.172.223.247 reqHost=keep.lugli.arvadosapi.com reqMethod=PUT reqPath=abc3977c2c709626b57927dc7388a9fc reqQuery=
May 01 18:44:39 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:39Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Begin upload abc3977c2c709626b57927dc7388a9fc to http://keep0.lugli.arvadosapi.com:25107" 
May 01 18:44:39 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:39Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Replicas remaining to write: 2 active uploads: 1" 
May 01 18:44:54 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:54Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Upload failed http://keep0.lugli.arvadosapi.com:25107/abc3977c2c709626b57927dc7388a9fc error: Put http://keep0.lugli.arvadosapi.com:25107/abc3977c2c709626b57927dc7388a9fc: net/http: request canceled (Client.Timeout exceeded while awaiting headers)" 
May 01 18:44:54 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:54Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Replicas remaining to write: 2 active uploads: 0" 
May 01 18:44:54 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:54Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Begin upload abc3977c2c709626b57927dc7388a9fc to http://keep0.lugli.arvadosapi.com:25107" 
May 01 18:44:54 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:44:54Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Replicas remaining to write: 2 active uploads: 1" 
May 01 18:45:09 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:09Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Upload failed http://keep0.lugli.arvadosapi.com:25107/abc3977c2c709626b57927dc7388a9fc error: Put http://keep0.lugli.arvadosapi.com:25107/abc3977c2c709626b57927dc7388a9fc: net/http: request canceled (Client.Timeout exceeded while awaiting headers)" 
May 01 18:45:09 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:09Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Replicas remaining to write: 2 active uploads: 0" 
May 01 18:45:09 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:09Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Begin upload abc3977c2c709626b57927dc7388a9fc to http://keep0.lugli.arvadosapi.com:25107" 
May 01 18:45:09 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:09Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Replicas remaining to write: 2 active uploads: 1" 
May 01 18:45:12 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:12Z" level=info msg="DEBUG: [req-35oyym3mwx6bb8qwm7sk] Upload http://keep0.lugli.arvadosapi.com:25107/abc3977c2c709626b57927dc7388a9fc success" 
May 01 18:45:12 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:12Z" level=info msg="207.172.223.247,127.0.0.1:35746 PUT /abc3977c2c709626b57927dc7388a9fc 200 67108864 2 2 abc3977c2c709626b57927dc7388a9fc+67108864+A5a1c5246763239c3a5d474cdcadba9850dff2b6e@5ebee338 <nil>" 
May 01 18:45:12 ip-10-255-0-201 keepproxy[2367]: time="2020-05-01T18:45:12Z" level=info msg=response RequestID=req-35oyym3mwx6bb8qwm7sk remoteAddr="127.0.0.1:35746" reqBytes=67108864 reqForwardedFor=207.172.223.247 reqHost=keep.lugli.arvadosapi.com reqMethod=PUT reqPath=abc3977c2c709626b57927dc7388a9fc reqQuery= respBytes=92 respStatus=OK respStatusCode=200 timeToStatus=33.241195 timeTotal=33.241230 timeWriteBody=0.000035

The third attempt works, it is much faster than the first 2.

Why does it start out so slow?

Actions
Copy link

Also available in: Atom PDF