Shino and Luke,
Thank you for helping me work through this. The tcplog mode in haproxy actually
doesn’t provide enough information because it doesn’t bother with paths or
query strings or anything http like. I am using the httplog mode as a result,
and the odd thing is that the error logged indicated the browser is actually
responsible for closing the connections. Usually these errors would be
generated when a user clicks stop or navigates away from a page. Per the
haproxy docs:
CH The client aborted while waiting for the server to start responding.
It might be the server taking too long to respond or the client
clicking the 'Stop' button too fast.
Here is the log data for a request made using the aws-sdk-js library.
```
Jan 14 09:46:59 localhost haproxy-gen1[400]: 10.100.88.52:62880
[14/Jan/2016:09:46:58.970] www-https~ www-backend/www-1 37/0/0/12/49 200 382 -
- ---- 1/1/0/0/0 0/0 "POST /three2016com-devopsdevel/Archive.zip?uploads
HTTP/1.1"
Jan 14 09:46:59 localhost haproxy-gen1[400]: 10.100.88.52:62885
[14/Jan/2016:09:46:59.918] www-https~ cors_opts/<NOSRV> 48/-1/-1/-1/48 503 399
- - SC-- 3/3/0/0/0 0/0 "OPTIONS
/three2016com-devopsdevel/Archive.zip?partNumber=2&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1"
Jan 14 09:47:00 localhost haproxy-gen1[400]: 10.100.88.52:62886
[14/Jan/2016:09:46:59.945] www-https~ cors_opts/<NOSRV> 57/-1/-1/-1/57 503 399
- - SC-- 2/2/0/0/0 0/0 "OPTIONS
/three2016com-devopsdevel/Archive.zip?partNumber=3&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1"
Jan 14 09:47:00 localhost haproxy-gen1[400]: 10.100.88.52:62887
[14/Jan/2016:09:46:59.960] www-https~ cors_opts/<NOSRV> 45/-1/-1/-1/45 503 399
- - SC-- 1/1/0/0/0 0/0 "OPTIONS
/three2016com-devopsdevel/Archive.zip?partNumber=4&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1"
Jan 14 09:47:12 localhost haproxy-gen1[400]: 10.100.88.52:62892
[14/Jan/2016:09:47:01.369] www-https~ www-backend/www-1 28/0/0/11442/11470 200
165 - - ---- 4/4/3/3/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?partNumber=2&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1”
Jan 14 09:47:12 localhost haproxy-gen1[400]: 10.100.88.52:62892
[14/Jan/2016:09:47:12.840] www-https~ cors_opts/<NOSRV> 70/-1/-1/-1/70 503 399
- - SC-- 3/3/0/0/0 0/0 "OPTIONS
/three2016com-devopsdevel/Archive.zip?uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1”
Jan 14 09:47:13 localhost haproxy-gen1[400]: 10.100.88.52:62888
[14/Jan/2016:09:46:59.965] www-https~ www-backend/www-1 41/0/0/-1/13182 -1 0 -
- CH-- 2/2/2/2/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?partNumber=1&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1"
Jan 14 09:47:13 localhost haproxy-gen1[400]: 10.100.88.52:62894
[14/Jan/2016:09:47:03.601] www-https~ www-backend/www-1 63/0/0/-1/9581 -1 0 - -
CH-- 1/1/1/1/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?partNumber=3&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1"
Jan 14 09:47:13 localhost haproxy-gen1[400]: 10.100.88.52:62897
[14/Jan/2016:09:47:04.981] www-https~ www-backend/www-1 118/0/0/-1/8268 -1 0 -
- CH-- 1/1/0/0/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?partNumber=4&uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1"
Jan 14 09:47:13 localhost haproxy-gen1[400]: 10.100.88.52:62899
[14/Jan/2016:09:47:13.429] www-https~ www-backend/www-1 40/0/0/22/62 204 126 -
- ---- 1/1/0/0/0 0/0 "DELETE
/three2016com-devopsdevel/Archive.zip?uploadId=xlC0aPjOQ96Mkn8asY62cw%3D%3D
HTTP/1.1”
```
The SC errors are expected on the OPTIONS requests as I have a separate backend
without any servers handling the preflights which I don’t think riak-cs will do
(if it will please enlighten me and I will update my config). The client is
actually receiving a 200 response with the CORS headers for OPTIONS requests.
There also appear to be a number of BADREQ errors in the log, but these appear
to be connections that that the browser initiated and then never used. No HTTP
requests are actually being made in those requests and I don’t appear to be
missing anything above (OPTIONS + PUT). As mentioned, the first PUT request is
successful, but subsequent requests appear to fail, or more accurately appear
to be closed by the client. When I use cyberduck for the same file I see the
following log entries:
```
Jan 14 10:01:36 localhost haproxy-gen1[400]: 10.100.88.52:63105
[14/Jan/2016:10:01:36.063] www-https~ www-backend/www-1 59/0/0/14/73 200 382 -
- ---- 1/1/0/0/0 0/0 "POST /three2016com-devopsdevel/Archive.zip?uploads
HTTP/1.1"
Jan 14 10:02:48 localhost haproxy-gen1[400]: 10.100.88.52:63105
[14/Jan/2016:10:01:36.136] www-https~ www-backend/www-1 70/0/1/72138/72209 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=3
HTTP/1.1"
Jan 14 10:02:53 localhost haproxy-gen1[400]: 10.100.88.52:63119
[14/Jan/2016:10:01:36.266] www-https~ www-backend/www-1 136/0/1/76606/76743 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=1
HTTP/1.1"
Jan 14 10:02:56 localhost haproxy-gen1[400]: 10.100.88.52:63117
[14/Jan/2016:10:01:36.266] www-https~ www-backend/www-1 90/0/1/79916/80007 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=10
HTTP/1.1"
Jan 14 10:02:57 localhost haproxy-gen1[400]: 10.100.88.52:63116
[14/Jan/2016:10:01:36.265] www-https~ www-backend/www-1 100/0/1/81618/81719 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=9
HTTP/1.1"
Jan 14 10:03:23 localhost haproxy-gen1[400]: 10.100.88.52:63118
[14/Jan/2016:10:01:36.266] www-https~ www-backend/www-1 130/0/0/107459/107589
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=2
HTTP/1.1"
Jan 14 10:03:28 localhost haproxy-gen1[400]: 10.100.88.52:63115
[14/Jan/2016:10:01:36.265] www-https~ www-backend/www-1 137/0/0/111934/112071
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=8
HTTP/1.1"
Jan 14 10:03:52 localhost haproxy-gen1[400]: 10.100.88.52:63113
[14/Jan/2016:10:01:36.245] www-https~ www-backend/www-1 112/0/0/136606/136718
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=5
HTTP/1.1"
Jan 14 10:04:05 localhost haproxy-gen1[400]: 10.100.88.52:63105
[14/Jan/2016:10:02:48.346] www-https~ www-backend/www-1 121/0/1/76853/76975 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=11
HTTP/1.1"
Jan 14 10:04:05 localhost haproxy-gen1[400]: 10.100.88.52:63120
[14/Jan/2016:10:01:36.266] www-https~ www-backend/www-1 99/0/1/149217/149317
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=4
HTTP/1.1"
Jan 14 10:04:08 localhost haproxy-gen1[400]: 10.100.88.52:63112
[14/Jan/2016:10:01:36.245] www-https~ www-backend/www-1 112/0/0/152150/152262
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=6
HTTP/1.1"
Jan 14 10:04:19 localhost haproxy-gen1[400]: 10.100.88.52:63114
[14/Jan/2016:10:01:36.261] www-https~ www-backend/www-1 104/0/1/160670/160775
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=7
HTTP/1.1"
Jan 14 10:04:34 localhost haproxy-gen1[400]: 10.100.88.52:63119
[14/Jan/2016:10:02:53.008] www-https~ www-backend/www-1 100/0/0/99129/99229 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=12
HTTP/1.1"
Jan 14 10:04:39 localhost haproxy-gen1[400]: 10.100.88.52:63116
[14/Jan/2016:10:02:57.985] www-https~ www-backend/www-1 181/0/0/99530/99711 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=14
HTTP/1.1"
Jan 14 10:04:41 localhost haproxy-gen1[400]: 10.100.88.52:63117
[14/Jan/2016:10:02:56.274] www-https~ www-backend/www-1 312/0/0/102647/102959
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=13
HTTP/1.1"
Jan 14 10:04:52 localhost haproxy-gen1[400]: 10.100.88.52:63113
[14/Jan/2016:10:03:52.963] www-https~ www-backend/www-1 203/0/0/57611/57814 200
190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=17
HTTP/1.1"
Jan 14 10:05:11 localhost haproxy-gen1[400]: 10.100.88.52:63118
[14/Jan/2016:10:03:23.856] www-https~ www-backend/www-1 109/0/0/105391/105500
200 190 - - ---- 10/10/9/9/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=15
HTTP/1.1"
Jan 14 10:05:28 localhost haproxy-gen1[400]: 10.100.88.52:63105
[14/Jan/2016:10:04:05.320] www-https~ www-backend/www-1 231/0/0/80927/81158 200
190 - - ---- 9/9/8/8/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=18
HTTP/1.1"
Jan 14 10:05:45 localhost haproxy-gen1[400]: 10.100.88.52:63114
[14/Jan/2016:10:04:19.199] www-https~ www-backend/www-1 89/0/0/86180/86269 200
190 - - ---- 8/8/7/7/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=21
HTTP/1.1"
Jan 14 10:05:46 localhost haproxy-gen1[400]: 10.100.88.52:63113
[14/Jan/2016:10:04:52.940] www-https~ www-backend/www-1 172/0/1/53672/53845 200
190 - - ---- 8/8/6/6/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=25
HTTP/1.1"
Jan 14 10:05:58 localhost haproxy-gen1[400]: 10.100.88.52:63120
[14/Jan/2016:10:04:05.583] www-https~ www-backend/www-1 233/0/1/110598/110832
200 190 - - ---- 6/6/5/5/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=19
HTTP/1.1"
Jan 14 10:05:59 localhost haproxy-gen1[400]: 10.100.88.52:63117
[14/Jan/2016:10:04:41.396] www-https~ www-backend/www-1 248/0/0/77581/77829 200
190 - - ---- 6/6/4/4/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=24
HTTP/1.1"
Jan 14 10:06:00 localhost haproxy-gen1[400]: 10.100.88.52:63119
[14/Jan/2016:10:04:34.402] www-https~ www-backend/www-1 197/0/0/85485/85682 200
190 - - ---- 6/6/3/3/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=22
HTTP/1.1"
Jan 14 10:06:00 localhost haproxy-gen1[400]: 10.100.88.52:63116
[14/Jan/2016:10:04:39.859] www-https~ www-backend/www-1 178/0/0/80650/80828 200
190 - - ---- 6/6/2/2/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=23
HTTP/1.1"
Jan 14 10:06:01 localhost haproxy-gen1[400]: 10.100.88.52:63115
[14/Jan/2016:10:03:28.336] www-https~ www-backend/www-1 75/0/0/150705/150780
200 190 - - ---- 6/6/1/1/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=16
HTTP/1.1"
Jan 14 10:06:06 localhost haproxy-gen1[400]: 10.100.88.52:63112
[14/Jan/2016:10:04:08.508] www-https~ www-backend/www-1 126/0/0/116172/116298
200 190 - - ---- 6/6/0/0/0 0/0 "PUT
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D&partNumber=20
HTTP/1.1"
Jan 14 10:06:07 localhost haproxy-gen1[400]: 10.100.88.52:63112
[14/Jan/2016:10:06:06.970] www-https~ www-backend/www-1 86/0/0/21/107 200 468 -
- ---- 6/6/0/0/0 0/0 "POST
/three2016com-devopsdevel/Archive.zip?uploadId=Ui6QDuCuSBqpbGGdf8SHig%3D%3D
HTTP/1.1"
```
Since this is not a browser client there is no preflight (OPTIONS) required.
There are no errors being logged at all, and the upload completes without
issue.
So far I have only tested this functionality in Chrome. I am going to try and
test Safari and FF now and I will let you know if there is any difference (or
not).
Thanks,
John Fanjoy
Systems Engineer
jfan...@inetu.net
On 1/14/16, 9:31 AM, "Shunichi Shinohara" <sh...@basho.com> wrote:
>Hi John,
>
>I tested Multipart Upload with aws-sdk-js with the patch you
>mentioned, against riak_cs (s2),
>upload finished without errors up to 1GB object. The environment is
>all local on my laptop,
>so latency is small. The script I used is in [1].
>
>As Luke mentioned, HAProxy would be the point to be investigated first.
>Or, if it's possible to get packet capture, by finding some wrong TCP
>packet, like
>RST or premature (from the point of HTTP) FIN, one can identify who
>closes TCP connection
>actively. In this case, packet should be captured on client box,
>HAProxy box and riak cs box.
>
>[1] https://gist.github.com/shino/ac7d56398557fb936899
>
>Thanks,
>Shino
>
>
>2016-01-14 8:51 GMT+09:00 Luke Bakken <lbak...@basho.com>:
>> Hi John,
>>
>> Thanks for the info. I'm very curious to see what's in the haproxy
>> logs with regard to TCP.
>> --
>> Luke Bakken
>> Engineer
>> lbak...@basho.com
>>
>>
>> On Wed, Jan 13, 2016 at 3:50 PM, John Fanjoy <jfan...@inetu.net> wrote:
>>> Luke,
>>>
>>> As a test I’ve already increased all timeouts to 5 minutes but the failure
>>> occurs within under 1 minute so it doesn’t appear to be timeout related. I
>>> change the logs to tcplog tomorrow and let you know if I find anything.
>>>
>>> Thanks
>>>
>>> John Fanjoy
>>> Systems Engineer
>>> jfan...@inetu.net
>>>
>>>
>>>
>>>
>>>
>>> On 1/13/16, 6:05 PM, "Luke Bakken" <lbak...@basho.com> wrote:
>>>
>>>>haproxy ships with some "short" default timeouts. If CyberDuck is able
>>>>to upload these files faster than aws-sdk, it may be doing so within
>>>>the default haproxy timeouts.
>>>>
>>>>You can also look at haproxy's log to see if you find any TCP
>>>>connections that it has closed.
>>>>--
>>>>Luke Bakken
>>>>Engineer
>>>>lbak...@basho.com
>>>>
>>>>
>>>>On Wed, Jan 13, 2016 at 3:02 PM, John Fanjoy <jfan...@inetu.net> wrote:
>>>>> Luke,
>>>>>
>>>>> I may be able to do that. The only problem is without haproxy I have no
>>>>> way to inject CORS headers which the browser requires, but I may be able
>>>>> to write up small nodejs app to get past that and see if it is somehow
>>>>> related to haproxy. The fact that these errors are not present when using
>>>>> Cyberduck which is also talking to haproxy leads me to believe that’s not
>>>>> the cause, but it’s definitely worth testing.
>>>>>
>>>>> --
>>>>> John Fanjoy
>>>>> Systems Engineer
>>>>> jfan...@inetu.net
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On 1/13/16, 5:55 PM, "Luke Bakken" <lbak...@basho.com> wrote:
>>>>>
>>>>>>John -
>>>>>>
>>>>>>The following error indicates that the connection was unexpectedly
>>>>>>closed by something outside of Riak while the chunk is uploading:
>>>>>>
>>>>>>{badmatch,{error,closed}}
>>>>>>
>>>>>>Is it possible to remove haproxy to test using the the aws-sdk?
>>>>>>
>>>>>>That is my first thought as to the cause of this issue, especially
>>>>>>since writing to S3 works with the same code.
>>>>>>
>>>>>>--
>>>>>>Luke Bakken
>>>>>>Engineer
>>>>>>lbak...@basho.com
>>>>>>
>>>>>>On Wed, Jan 13, 2016 at 2:46 PM, John Fanjoy <jfan...@inetu.net> wrote:
>>>>>>> Luke,
>>>>>>>
>>>>>>> Yes on both parts. To confirm cyberduck was using multi-part I actually
>>>>>>> tailed the console.log while it was uploading the file, and it uploaded
>>>>>>> the file in approx. 40 parts. Afterwards the parts were reassembled as
>>>>>>> you would expect. The AWS-SDK for javascript has an object called
>>>>>>> ManagedUpload which automatically switches to multi-part when the input
>>>>>>> is larger than the maxpartsize (default 5mb). I have confirmed that it
>>>>>>> is splitting the files up, but so far I’ve only ever seen one part get
>>>>>>> successfully uploaded before the others failed at which point it
>>>>>>> removes the upload (DELETE call) automatically. I also verified that
>>>>>>> the javascript I have in place does work with an actual AWS S3 bucket
>>>>>>> to rule out coding issues on my end and the same >400mb file was
>>>>>>> successfully uploaded to the bucket I created there without issue.
>>>>>>>
>>>>>>> A few things worth mentioning that I missed before. I am running
>>>>>>> riak-s2 behind haproxy. Haproxy is handling ssl and enabling CORS for
>>>>>>> browser based requests. I have tested smaller files (~4-5mb) and GET
>>>>>>> requests using the browser client and everything works with my current
>>>>>>> haproxy configuration, but the larger files are failing, usually after
>>>>>>> 1 part is successfully uploaded. I can also list bucket contents and
>>>>>>> delete existing contents. The only feature that is not working appears
>>>>>>> to be the multi-part uploads. We are running centOS 7 (kernel version
>>>>>>> 3.10.0-327.4.4.el7.x86_64). Please let me know if you have any further
>>>>>>> questions.
>>>>>>>
>>>>>>> --
>>>>>>> John Fanjoy
>>>>>>> Systems Engineer
>>>>>>> jfan...@inetu.net
>>
>> _______________________________________________
>> riak-users mailing list
>> riak-users@lists.basho.com
>> http://lists.basho.com/mailman/listinfo/riak-users_lists.basho.com
_______________________________________________
riak-users mailing list
riak-users@lists.basho.com
http://lists.basho.com/mailman/listinfo/riak-users_lists.basho.com
