On Fri, 25 Sep 2015, Daniel Stenberg wrote:
Hey Tatsuhiro,
Can you help me out with a look at this nghttpd server output that I get when
downloading a 8GB file from localhost (HTTPS).
It so looks like we have a window size related problem based solely on what
packages we see that that go out and come in.
The server sends out 4 DATA frames quickly, then it takes 5 milliseconds
before a WINDOW_UPDATE is received (adding 32K to stream 0) and then it takes
an additional about 39 milliseconds (I'm not sure what makes it take so long)
for a second WINDOW_UPDATE (on strean 1) and then a 3rd (stream 0, 32767
bytes) and a 4th update (stream 1, also 32767 bytes). The three latter ones
all within the same millisecond.
Then it loops and it sends another 4 DATA frames really fast and back to the
same window update dance.
See attachment for a snippet from the log. This problem is easily reproducable
for me.
Does it give you any ideas?
--
/ daniel.haxx.se
[id=18] [31191.788] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.788] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.788] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.788] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31191.793] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31191.832] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31191.832] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31191.832] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31191.832] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.832] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.832] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.832] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31191.837] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31191.876] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31191.876] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31191.876] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31191.876] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.876] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.876] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.876] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31191.881] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31191.920] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31191.920] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31191.920] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31191.920] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.920] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.920] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.920] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31191.925] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31191.964] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31191.964] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31191.964] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31191.964] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.964] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.964] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31191.964] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31191.969] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31192.008] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31192.008] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31192.008] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31192.008] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.008] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.008] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.008] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31192.013] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31192.052] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31192.052] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31192.052] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31192.052] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.052] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.052] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.052] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31192.057] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31192.096] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31192.096] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31192.096] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31192.096] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.096] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.096] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.096] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31192.101] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31192.140] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31192.140] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31192.140] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31192.140] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.140] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.140] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.140] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31192.145] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31192.184] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31192.184] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31192.184] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31192.184] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.184] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.184] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.184] send DATA frame <length=16383, flags=0x00, stream_id=1>
[id=18] [31192.189] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32768)
[id=18] [31192.228] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32768)
[id=18] [31192.228] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=0>
(window_size_increment=32767)
[id=18] [31192.228] recv WINDOW_UPDATE frame <length=4, flags=0x00, stream_id=1>
(window_size_increment=32767)
[id=18] [31192.228] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.228] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.228] send DATA frame <length=16384, flags=0x00, stream_id=1>
[id=18] [31192.228] send DATA frame <length=16383, flags=0x00, stream_id=1>-------------------------------------------------------------------
List admin: http://cool.haxx.se/list/listinfo/curl-library
Etiquette: http://curl.haxx.se/mail/etiquette.html
