[ 
https://issues.apache.org/jira/browse/TS-4162?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15123313#comment-15123313
 ] 

ASF GitHub Bot commented on TS-4162:
------------------------------------

Github user masaori335 commented on a diff in the pull request:

    https://github.com/apache/trafficserver/pull/444#discussion_r51245359
  
    --- Diff: mgmt/RecordsConfig.cc ---
    @@ -1995,6 +1995,8 @@ static const RecordElement RecordsConfig[] =
       ,
       {RECT_CONFIG, "proxy.config.http2.no_activity_timeout_in", RECD_INT, 
"115", RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL}
       ,
    +  {RECT_CONFIG, "proxy.config.http2.active_timeout_in", RECD_INT, "900", 
RECU_DYNAMIC, RR_NULL, RECC_STR, "^[0-9]+$", RECA_NULL}
    --- End diff --
    
    I'm not sure how log is suitable for default value. I chose `900` to make 
it same as `proxy.config.http.transaction_active_timeout_in`.
    Any suggestions?



> Http2ClientSession close connection by INACTIVITY_TIMEOUT event, even if the 
> connection is still active
> -------------------------------------------------------------------------------------------------------
>
>                 Key: TS-4162
>                 URL: https://issues.apache.org/jira/browse/TS-4162
>             Project: Traffic Server
>          Issue Type: Bug
>          Components: HTTP/2
>            Reporter: Masaori Koshiba
>            Assignee: Masaori Koshiba
>             Fix For: 6.2.0
>
>
> h3. Summary
> In my investigation, {{Http2ClientSession}} close connection by 
> {{VC_EVENT_INACTIVITY_TIMEOUT}} event.
> TS should keep "active" connection until {{VC_EVENT_ACTIVITY_TIMEOUT}} event 
> is issued.
> h3. Investigation Details
> 1. Add debug logs to clarify what event is issued in Http2ClientSession.cc 
> {code}
> diff --git a/proxy/http2/Http2ClientSession.cc 
> b/proxy/http2/Http2ClientSession.cc
> index ccad11f..b1a5a26 100644
> --- a/proxy/http2/Http2ClientSession.cc
> +++ b/proxy/http2/Http2ClientSession.cc
> @@ -241,7 +241,13 @@ Http2ClientSession::main_event_handler(int event, void 
> *edata)
>    }
>    case VC_EVENT_ACTIVE_TIMEOUT:
> +    DebugHttp2Ssn0("VC_EVENT_ACTIVITY_TIMEOUT");
> +    this->do_io_close();
> +    return 0;
> +
>    case VC_EVENT_INACTIVITY_TIMEOUT:
> +    DebugHttp2Ssn0("VC_EVENT_INACTIVITY_TIMEOUT");
> +    this->do_io_close();
> +    return 0;
> {code}
> - Enable HTTP/2 with default HTTP/2 settings
> - Enable debug and set debug tag 'http2_cs'
> - Disable cache
> 2. Start origin server with netcat and remap every request to it. 
> 3. Do HTTP/2 request on h2i to TS
> Below is debug logs. 
> {noformat}
> [Jan 29 14:56:35.723] Server {0x700000ba2000} DEBUG: 
> <Http2SessionAccept.cc:52 (accept)> (http2_seq) [HttpSessionAccept2:mainEvent 
> 0x7fc4f424fc80] accepted connection from 127.0.0.1:56466 transport type = 4
> [Jan 29 14:56:35.724] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:127 (new_connection)> (http2_cs) [0] session born, 
> netvc 0x7fc4f424fc80
> [Jan 29 14:56:35.724] Server {0x700000ba2000} DEBUG: 
> <Http2ConnectionState.cc:1136 (send_window_update_frame)> (http2_cs) [0] Send 
> WINDOW_UPDATE frame.
> [Jan 29 14:56:35.724] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:285 (state_read_connection_preface)> (http2_cs) [0] 
> [&Http2ClientSession::state_read_connection_preface, VC_EVENT_READ_READY]
> [Jan 29 14:56:35.724] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:285 (state_read_connection_preface)> (http2_cs) [0] 
> [&Http2ClientSession::state_read_connection_preface, VC_EVENT_READ_READY]
> [Jan 29 14:56:35.724] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:301 (state_read_connection_preface)> (http2_cs) [0] 
> received connection preface
> [Jan 29 14:56:51.205] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:329 (state_start_frame_read)> (http2_cs) [0] 
> [&Http2ClientSession::state_start_frame_read, VC_EVENT_READ_READY]
> [Jan 29 14:56:51.205] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:336 (state_start_frame_read)> (http2_cs) [0] receiving 
> frame header
> [Jan 29 14:56:51.205] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:346 (state_start_frame_read)> (http2_cs) [0] frame 
> header length=7, type=1, flags=0x5, streamid=1
> [Jan 29 14:56:51.205] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:404 (state_complete_frame_read)> (http2_cs) [0] 
> [&Http2ClientSession::state_complete_frame_read, VC_EVENT_READ_READY]
> [Jan 29 14:56:51.205] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:412 (state_complete_frame_read)> (http2_cs) [0] 
> completed frame read, 7 bytes available
> [Jan 29 14:56:51.551] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:249 (main_event_handler)> (http2_cs) [0] 
> VC_EVENT_INACTIVITY_TIMEOUT
> [Jan 29 14:56:51.551] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:203 (do_io_close)> (http2_cs) [0] session closed
> [Jan 29 14:56:51.552] Server {0x700000ba2000} DEBUG: 
> <Http2ClientSession.cc:72 (destroy)> (http2_cs) [0] session destroy
> {noformat}
> 300ms after TS requests to origin server, {{VC_EVENT_INACTIVITY_TIMEOUT}} is 
> happen immediately and Http2ClientSession close the connection.
> It looks like origin server needs return first byte of headers in 300ms. In 
> some cases like origin server is slow or faraway, this could be problem.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to