[
https://issues.apache.org/jira/browse/TS-3487?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14486114#comment-14486114
]
Bryan Call edited comment on TS-3487 at 4/8/15 9:41 PM:
--------------------------------------------------------
Here is a debug of a long lived GET request where the origin sends a few bytes
every 10 seconds. The inactivity timeout is cleared because it is a GET and
then reset to the default because there is none set by inactivity cop. When
data gets sent from the origin through the proxy, write_disable is called it
again clears inactivity for the client and then the default get set again by
inactivity cop.
Debug output:
{code}
[Apr 8 14:27:54.670] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <UnixConnection.cc:410
(remove_from_keep_alive_lru)> (socket)
UnixNetVConnection::remove_from_keep_alive_lru NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=120000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:341 (set_active_timeout)> (socket) Set active
timeout=900000000000, NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=30000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:375 (cancel_inactivity_timeout)> (socket) Cancel
inactive timeout for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <UnixConnection.cc:364
(apply_options)> (socket) ::open: setsockopt() TCP_NODELAY on socket
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=5000000000, for NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:341 (set_active_timeout)> (socket) Set active
timeout=0, NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <P_UnixNet.h:402
(read_disable)> (socket) read_disable updating inactivity_at 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 5000000000,
NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 5000000000,
NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=25000000000, for NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=30000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 30000000000,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG: <P_UnixNet.h:423
(write_disable)> (socket) write_disable updating inactivity_at 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:55.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528475055227000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:55.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:90
(check_inactivity)> (inactivity_cop) vc: 0x7fbe7b8b3d40 inactivity timeout not
set, setting a default of 86400
[Apr 8 14:27:55.055] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=86400000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:56.053] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528476053850000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:56.053] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528476053850000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:27:57.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528477055982000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:57.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528477055982000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:27:58.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528478059062000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:58.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528478059062000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:27:59.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528479056493000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:59.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528479056493000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:00.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528480059704000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:00.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528480059704000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:01.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528481058265000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:01.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528481058265000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:02.060] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528482060738000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:02.060] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528482060738000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:03.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528483055991000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:03.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528483055991000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:04.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528484051031000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:04.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528484051031000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:05.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528485056102000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:05.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528485056102000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:06.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528486055305000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:06.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528486055305000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:07.052] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528487052662000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:07.052] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528487052662000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:08.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528488051771000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:08.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528488051771000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:09.050] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528489050845000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:09.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528489050845000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:10.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528490051790000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:10.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528490051790000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:11.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528491058664000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:11.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528491058664000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:12.063] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528492063347000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:12.063] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528492063347000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:13.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528493065027000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:13.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528493065027000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:14.069] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528494069261000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:14.069] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528494069261000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:14.673] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 25000000000,
NetVC=0x7fbe7b8b3a80
[Apr 8 14:28:14.674] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 86400000000000,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:28:14.674] Server {0x7fff73072300} DEBUG: <P_UnixNet.h:423
(write_disable)> (socket) write_disable updating inactivity_at 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:28:15.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528495065372000 timeout at: 1428528519 timeout in: 25
[Apr 8 14:28:15.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:90
(check_inactivity)> (inactivity_cop) vc: 0x7fbe7b8b3d40 inactivity timeout not
set, setting a default of 86400
[Apr 8 14:28:15.065] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=86400000000000, for NetVC=0x7fbe7b8b3d40
{code}
was (Author: bcall):
Here is a debug of a long lived GET request where the origin send a few bytes
every 10 seconds. The inactivity timeout is cleared because it is a GET and
then reset to the default because there is none set by inactivity cop. When
data gets sent from the origin through the proxy when write_disable is called
it again clears inactivity for the client and then the default get set again by
inactivity cop.
Debug output:
{code}
[Apr 8 14:27:54.670] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <UnixConnection.cc:410
(remove_from_keep_alive_lru)> (socket)
UnixNetVConnection::remove_from_keep_alive_lru NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=120000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:341 (set_active_timeout)> (socket) Set active
timeout=900000000000, NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=30000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:375 (cancel_inactivity_timeout)> (socket) Cancel
inactive timeout for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <UnixConnection.cc:364
(apply_options)> (socket) ::open: setsockopt() TCP_NODELAY on socket
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=5000000000, for NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:341 (set_active_timeout)> (socket) Set active
timeout=0, NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <P_UnixNet.h:402
(read_disable)> (socket) read_disable updating inactivity_at 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.671] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 5000000000,
NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 5000000000,
NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=25000000000, for NetVC=0x7fbe7b8b3a80
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=30000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 30000000000,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:54.673] Server {0x7fff73072300} DEBUG: <P_UnixNet.h:423
(write_disable)> (socket) write_disable updating inactivity_at 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:55.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528475055227000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:55.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:90
(check_inactivity)> (inactivity_cop) vc: 0x7fbe7b8b3d40 inactivity timeout not
set, setting a default of 86400
[Apr 8 14:27:55.055] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=86400000000000, for NetVC=0x7fbe7b8b3d40
[Apr 8 14:27:56.053] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528476053850000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:56.053] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528476053850000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:27:57.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528477055982000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:57.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528477055982000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:27:58.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528478059062000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:58.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528478059062000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:27:59.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528479056493000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:27:59.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528479056493000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:00.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528480059704000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:00.059] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528480059704000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:01.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528481058265000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:01.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528481058265000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:02.060] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528482060738000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:02.060] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528482060738000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:03.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528483055991000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:03.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528483055991000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:04.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528484051031000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:04.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528484051031000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:05.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528485056102000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:05.056] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528485056102000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:06.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528486055305000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:06.055] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528486055305000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:07.052] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528487052662000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:07.052] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528487052662000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:08.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528488051771000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:08.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528488051771000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:09.050] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528489050845000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:09.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528489050845000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:10.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528490051790000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:10.051] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528490051790000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:11.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528491058664000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:11.058] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528491058664000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:12.063] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528492063347000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:12.063] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528492063347000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:13.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528493065027000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:13.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528493065027000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:14.069] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528494069261000 timeout at: 1428528499 timeout in: 25
[Apr 8 14:28:14.069] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3d40 now:
1428528494069261000 timeout at: 1428614875 timeout in: 86400
[Apr 8 14:28:14.673] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 25000000000,
NetVC=0x7fbe7b8b3a80
[Apr 8 14:28:14.674] Server {0x7fff73072300} DEBUG: <UnixNetVConnection.cc:70
(net_activity)> (socket) net_activity updating inactivity 86400000000000,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:28:14.674] Server {0x7fff73072300} DEBUG: <P_UnixNet.h:423
(write_disable)> (socket) write_disable updating inactivity_at 0,
NetVC=0x7fbe7b8b3d40
[Apr 8 14:28:15.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:95
(check_inactivity)> (inactivity_cop_verbose) vc: 0x7fbe7b8b3a80 now:
1428528495065372000 timeout at: 1428528519 timeout in: 25
[Apr 8 14:28:15.065] Server {0x7fff73072300} DEBUG: <UnixNet.cc:90
(check_inactivity)> (inactivity_cop) vc: 0x7fbe7b8b3d40 inactivity timeout not
set, setting a default of 86400
[Apr 8 14:28:15.065] Server {0x7fff73072300} DEBUG:
<P_UnixNetVConnection.h:311 (set_inactivity_timeout)> (socket) Set inactive
timeout=86400000000000, for NetVC=0x7fbe7b8b3d40
{code}
> cannot override proxy.config.http.transaction_no_activity_timeout_in per
> remap rule for POST methold
> ----------------------------------------------------------------------------------------------------
>
> Key: TS-3487
> URL: https://issues.apache.org/jira/browse/TS-3487
> Project: Traffic Server
> Issue Type: Bug
> Components: HTTP
> Affects Versions: 5.2.1
> Reporter: Feifei Cai
> Assignee: Bryan Call
> Labels: review
> Fix For: 6.0.0
>
> Attachments: TS-3487.diff
>
>
> The configuration and test are as follows:
> remap.config:
> {noformat}
> map /test1 http://httpbin.org
> map /test2 http://httpbin.org @plugin=conf_remap.so
> @pparam=proxy.config.http.transaction_no_activity_timeout_in=15
> {noformat}
> records.config:
> {noformat}
> CONFIG proxy.config.http.transaction_no_activity_timeout_in INT 5
> CONFIG proxy.config.diags.debug.enabled INT 1
> CONFIG proxy.config.diags.debug.tags STRING
> http_cs|http_ss|inactivity.*|socket
> {noformat}
> {code:title=test.py}
> import time
> import logging
> import socket
> log = logging.getLogger(__name__)
> logging.basicConfig(level=logging.INFO)
> import SocketServer
> url1 = 'POST /test1/post HTTP/1.1\r\n'
> url2 = 'POST /test2/post HTTP/1.1\r\n'
> header1 = 'Host: 127.0.0.1\r\n'
> # last header need additional '\r\n'
> header2 = 'Content-Length: 10\r\n\r\n'
> body1 = '12345'
> body2 = '67890'
> def get_socket():
> s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
> s.connect(('127.0.0.1', 8080))
> return s
> def test_global_config():
> s = get_socket()
> log.info('start test global config...')
> try:
> # before remap
> s.send(url1)
> time.sleep(2) # < global config
> s.send(header1)
> time.sleep(3) # < global config
> s.send(header2)
> # after remap
> time.sleep(2) # < global config
> s.send(body1)
> time.sleep(4) # < global config
> s.send(body2)
> log.info('test global config: pass!')
> except IOError:
> log.info('test global config: fail!')
> response = s.recv(4096)
> print response
> def test_per_remap_config():
> s = get_socket()
> log.info('start test per remap config...')
> try:
> # before remap
> s.send(url2)
> time.sleep(2) # < global config
> s.send(header1)
> time.sleep(3) # < global config
> s.send(header2)
> # after remap
> time.sleep(11) # < per remap config
> s.send(body1)
> time.sleep(13) # < per remap config
> s.send(body2)
> log.info('test per remap config: pass!')
> except IOError:
> log.info('test per remap config: fail!')
> response = s.recv(4096)
> print response
> if __name__ == '__main__':
> test_global_config()
> test_per_remap_config()
> {code}
> {{test_global_config()}} would pass, but {{test_per_remap_config()}} fails.
> {{proxy.config.http.transaction_no_activity_timeout_in}} in per remap rule
> does not works.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
