Pierre Belzile
2012-01-27 02:06:55 UTC
Hi,
I build an HTTP 1.1 client and servers starting from the example in
HTTP3. I added a timer in the server to close a connection inactive for
60 seconds. My code stopped working after upgrading to 1.48: It seems
that some connections just don't die. Here is the tcpdump and some
comments. Reverted to 1.47 and working fine. I should
add for completeness that in 1.47, we're linking with non thread safe
boost libraries and switched to thread safe ones in 1.48 but I can't see
how that impacts asio.
As anyone encountered a similar issue?
Thanks,
Pierre
-----
This sequence shows that the client (za11) attempts to close a connection
established from port 45508 to port 18085, acknowledged by
the server (daffy), and ack-ack by the client.
A minute later, the server sends a reset for port 45511. That's the
server closing the socket
because of no activity. But socket should have been closed already.
Also that seems to "unlock" the client that now sends another
transaction. Why was
the client locked given that it had ack-ack the FIN?
19:34:33.020597 IP za11.idilia.net.45508 > daffy.idilia.net.18085: Flags
[F.], seq 453, ack 2027, win 69, options [nop,nop,TS val 525744130 ecr
18797391], length 0
0x0000: 4500 0034 cbd7 4000 4006 eaef c0a8 016f ***@.@......o
0x0010: c0a8 013d b1c4 46a5 9509 fdf1 36b8 5502 ...=..F.....6.U.
0x0020: 8011 0045 af94 0000 0101 080a 1f56 3802 ...E.........V8.
0x0030: 011e d34f ...O
19:34:33.020725 IP daffy.idilia.net.18085 > za11.idilia.net.45508: Flags
[F.], seq 2027, ack 454, win 54, options [nop,nop,TS val 18797391 ecr
525744130], length 0
0x0000: 4500 0034 9e57 4000 4006 1870 c0a8 013d ***@.@..p...=
0x0010: c0a8 016f 46a5 b1c4 36b8 5502 9509 fdf2 ...oF...6.U.....
0x0020: 8011 0036 afa2 0000 0101 080a 011e d34f ...6...........O
0x0030: 1f56 3802 .V8.
19:34:33.020820 IP za11.idilia.net.45508 > daffy.idilia.net.18085: Flags
[.], ack 2028, win 69, options [nop,nop,TS val 525744131 ecr 18797391],
length 0
0x0000: 4500 0034 cbd8 4000 4006 eaee c0a8 016f ***@.@......o
0x0010: c0a8 013d b1c4 46a5 9509 fdf2 36b8 5503 ...=..F.....6.U.
0x0020: 8010 0045 af92 0000 0101 080a 1f56 3803 ...E.........V8.
0x0030: 011e d34f ...O
19:35:33.034112 IP daffy.idilia.net.18085 > za11.idilia.net.45511: Flags
[R.], seq 3153132260, ack 2716375525, win 54, options [nop,nop,TS val
18857405 ecr 525744143], length 0
0x0000: 4500 0034 29b9 4000 4006 8d0e c0a8 013d E..4)***@.@......=
0x0010: c0a8 016f 46a5 b1c7 bbf0 fae4 a1e8 99e5 ...oF...........
0x0020: 8014 0036 f133 0000 0101 080a 011f bdbd ...6.3..........
0x0030: 1f56 380f .V8.
19:35:33.035527 IP za11.idilia.net.45512 > daffy.idilia.net.18085: Flags
[S], seq 4169269143, win 5840, options [mss 1460,sackOK,TS val 525804145
ecr 0,nop,wscale 7], length 0
0x0000: 4500 003c dde6 4000 4006 d8d8 c0a8 016f E..<***@.@......o
0x0010: c0a8 013d b1c8 46a5 f881 ff97 0000 0000 ...=..F.........
0x0020: a002 16d0 7ae3 0000 0204 05b4 0402 080a ....z...........
0x0030: 1f57 2271 0000 0000 0103 0307 .W"q........
I tried to compile to whole program with BOOST_ASIO_ENABLE_HANDLER_TRACKING
but that seems to prevent the client from sending any data at all:
asio|1327626817.367757|0*1|***@0xe648770.dispatch
@asio|1327626817.367962|>1|
@asio|1327626817.370260|1*2|***@0xe174680.async_connect
@asio|1327626817.370443|<1|
We see the async_connect after resolving endpoints sync. But no traffic
captured by tcpdump. And server just waits.
I build an HTTP 1.1 client and servers starting from the example in
HTTP3. I added a timer in the server to close a connection inactive for
60 seconds. My code stopped working after upgrading to 1.48: It seems
that some connections just don't die. Here is the tcpdump and some
comments. Reverted to 1.47 and working fine. I should
add for completeness that in 1.47, we're linking with non thread safe
boost libraries and switched to thread safe ones in 1.48 but I can't see
how that impacts asio.
As anyone encountered a similar issue?
Thanks,
Pierre
-----
This sequence shows that the client (za11) attempts to close a connection
established from port 45508 to port 18085, acknowledged by
the server (daffy), and ack-ack by the client.
A minute later, the server sends a reset for port 45511. That's the
server closing the socket
because of no activity. But socket should have been closed already.
Also that seems to "unlock" the client that now sends another
transaction. Why was
the client locked given that it had ack-ack the FIN?
19:34:33.020597 IP za11.idilia.net.45508 > daffy.idilia.net.18085: Flags
[F.], seq 453, ack 2027, win 69, options [nop,nop,TS val 525744130 ecr
18797391], length 0
0x0000: 4500 0034 cbd7 4000 4006 eaef c0a8 016f ***@.@......o
0x0010: c0a8 013d b1c4 46a5 9509 fdf1 36b8 5502 ...=..F.....6.U.
0x0020: 8011 0045 af94 0000 0101 080a 1f56 3802 ...E.........V8.
0x0030: 011e d34f ...O
19:34:33.020725 IP daffy.idilia.net.18085 > za11.idilia.net.45508: Flags
[F.], seq 2027, ack 454, win 54, options [nop,nop,TS val 18797391 ecr
525744130], length 0
0x0000: 4500 0034 9e57 4000 4006 1870 c0a8 013d ***@.@..p...=
0x0010: c0a8 016f 46a5 b1c4 36b8 5502 9509 fdf2 ...oF...6.U.....
0x0020: 8011 0036 afa2 0000 0101 080a 011e d34f ...6...........O
0x0030: 1f56 3802 .V8.
19:34:33.020820 IP za11.idilia.net.45508 > daffy.idilia.net.18085: Flags
[.], ack 2028, win 69, options [nop,nop,TS val 525744131 ecr 18797391],
length 0
0x0000: 4500 0034 cbd8 4000 4006 eaee c0a8 016f ***@.@......o
0x0010: c0a8 013d b1c4 46a5 9509 fdf2 36b8 5503 ...=..F.....6.U.
0x0020: 8010 0045 af92 0000 0101 080a 1f56 3803 ...E.........V8.
0x0030: 011e d34f ...O
19:35:33.034112 IP daffy.idilia.net.18085 > za11.idilia.net.45511: Flags
[R.], seq 3153132260, ack 2716375525, win 54, options [nop,nop,TS val
18857405 ecr 525744143], length 0
0x0000: 4500 0034 29b9 4000 4006 8d0e c0a8 013d E..4)***@.@......=
0x0010: c0a8 016f 46a5 b1c7 bbf0 fae4 a1e8 99e5 ...oF...........
0x0020: 8014 0036 f133 0000 0101 080a 011f bdbd ...6.3..........
0x0030: 1f56 380f .V8.
19:35:33.035527 IP za11.idilia.net.45512 > daffy.idilia.net.18085: Flags
[S], seq 4169269143, win 5840, options [mss 1460,sackOK,TS val 525804145
ecr 0,nop,wscale 7], length 0
0x0000: 4500 003c dde6 4000 4006 d8d8 c0a8 016f E..<***@.@......o
0x0010: c0a8 013d b1c8 46a5 f881 ff97 0000 0000 ...=..F.........
0x0020: a002 16d0 7ae3 0000 0204 05b4 0402 080a ....z...........
0x0030: 1f57 2271 0000 0000 0103 0307 .W"q........
I tried to compile to whole program with BOOST_ASIO_ENABLE_HANDLER_TRACKING
but that seems to prevent the client from sending any data at all:
asio|1327626817.367757|0*1|***@0xe648770.dispatch
@asio|1327626817.367962|>1|
@asio|1327626817.370260|1*2|***@0xe174680.async_connect
@asio|1327626817.370443|<1|
We see the async_connect after resolving endpoints sync. But no traffic
captured by tcpdump. And server just waits.