JosiahWI opened a new issue, #11552:
URL: https://github.com/apache/trafficserver/issues/11552

   ## Default Process
   ```
   [DEBUG]: Configured logging at level DEBUG
   [INFO]: Loading replay data from 
"/tmp/sandbox/proxy_protocol/pp-out-client-4/proxy_protocol_out.replay.yaml".
       [INFO]: Replay file parsing took: 0 milliseconds.
   [INFO]: Parsed 1 transaction in 1 session.
   [DEBUG]: Poll timeout set to 5000ms.
   [DEBUG]: Initialize TLS
       [DEBUG]: Writing TLS secrets to: 
/tmp/sandbox/proxy_protocol/pp-out-client-4/tls_secrets.txt
     [DEBUG]: Finished TLSSession::init
   [DEBUG]: Initialize H2
     [DEBUG]: Finished H2Session::init
   [DEBUG]: Initialize H3
       [DEBUG]: QUIC log files will be written to 
/tmp/sandbox/proxy_protocol/pp-out-client-4/qlog_directory
     [DEBUG]: Finished H3Session::init
   [DEBUG]: Client initialization complete.
   [DEBUG]: Starting session 
"/tmp/sandbox/proxy_protocol/pp-out-client-4/proxy_protocol_out.replay.yaml":24 
protocol=https.
   [DEBUG]: Connecting via TLS.
       [DEBUG]: Proxy TLS verification result: 18 (not X509_V_OK).
   [ERROR]: SSL_read timed out waiting to TLS content after 5000 milliseconds 
milliseconds.
           [DEBUG]: Sent the following HTTP/1 request headers for key 1:
   GET /get/request HTTP/1.1
   uuid: 1
   host: pp.origin.com
   
         [DEBUG]: Reading response header.
         [ERROR]: Failed to find a well-formed, completed HTTP response: 
PARSE_INCOMPLETE
       [ERROR]: Failed HTTP/1 transaction with key: 1
   [INFO]: 1 transaction in 1 session (reuse 1) in 5018 milliseconds (0.0 / 
millisecond).
   ```
   
   ## ATS
   ```
   +++++++++ Proxy's Request +++++++++
   -- State Machine Id: 0
   GET /get/request HTTP/1.1
   uuid: 1
   host: backend.pp.origin.com:61990
   Client-ip: 127.0.0.1
   X-Forwarded-For: 127.0.0.1
   Via: https/1.1 traffic_server[1c94b2e8-4158-4da2-9cf5-cf165e58480b] 
(ApacheTrafficServer/10.1.0)
   
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpTransact.cc:2220 
(LookupSkipOpenServer)> (http_trans) Next action next; 
HttpTransact::HandleResponse
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:7787 
(call_transact_and_set_next_state)> (http) [0] State Transition: 
SM_ACTION_API_CACHE_LOOKUP_COMPLETE -> SM_ACTION_ORIGIN_SERVER_OPEN
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpTransact.h:969 
(set_connect_fail)> (http) Setting upstream connection failure 0 to 5
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5267 
(do_http_server_open)> (http_track) [0] entered inside do_http_server_open 
][ipv4]
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5294 
(do_http_server_open)> (http) [0] open connection to backend.pp.origin.com: 
127.0.0.1:61990
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5297 
(do_http_server_open)> (http_seq) [0] Sending request to server
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpTransact.cc:6555 
(will_this_request_self_loop)> (http_transact) [0] max_proxy_cycles = 0
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpTransact.cc:6561 
(will_this_request_self_loop)> (http_transact) [0] dst_port = 61990 local_port 
= 61994
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpTransact.cc:6614 
(will_this_request_self_loop)> (http_transact) [0] count = 0 <= 
max_proxy_cycles = 0 : allowing loop
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5372 
(do_http_server_open)> (http_ss) [0] Try to acquire_session for 
backend.pp.origin.com
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSessionManager.cc:453 
(_acquire_session)> (http_ss) [acquire session] thread pool search failed
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5455 
(do_http_server_open)> (http_ss) [0] Check for existing connect request
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5603 
(do_http_server_open)> (http_ss) [0] Queue multiplexed request
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpTransact.h:969 
(set_connect_fail)> (http) Setting upstream connection failure 5 to 5
   [Jul 15 19:06:40.365] [ET_NET 0] DIAG: <HttpSM.cc:5624 
(do_http_server_open)> (http) [0] calling sslNetProcessor.connect_re
   [Jul 15 19:06:40.366] [ET_NET 0] DIAG: <ConnectingEntry.cc:47 
(state_http_server_open)> (http_connect) entered inside 
ConnectingEntry::state_http_server_open
   [Jul 15 19:06:40.366] [ET_NET 0] DIAG: <ConnectingEntry.cc:55 
(state_http_server_open)> (http_connect) ConnectingEntrysetting handler for 
connection handshake
   [Jul 15 19:06:40.369] [ET_NET 0] DIAG: <HttpSM.cc:153 
(do_outbound_proxy_protocol)> (proxyprotocol) vc_in had no Proxy Protocol. 
Manufacturing from the vc_in socket.
   [Jul 15 19:06:40.369] [ET_NET 0] DIAG: <ProxyProtocol.cc:361 
(proxy_protocol_v1_build)> (proxyprotocol_v1) Proxy Protocol v1: PROXY TCP4 
127.0.0.1 127.0.0.1 46294 61994
   [Jul 15 19:06:45.302] [ET_NET 0] DIAG: <HttpSM.cc:2608 (main_handler)> 
(http) [0] EVENT_ERROR/TS_EVENT_ERROR/VC_EVENT_ERROR, 3
   [Jul 15 19:06:45.303] [ET_NET 0] DIAG: <HttpSM.cc:831 
(state_watch_for_client_abort)> (http) [0] 
[&HttpSM::state_watch_for_client_abort, 
EVENT_ERROR/TS_EVENT_ERROR/VC_EVENT_ERROR]
   [Jul 15 19:06:45.303] [ET_NET 0] DIAG: <HttpSM.cc:8727 (clear)> 
(http_redirect) [PostDataBuffers::clear]
   [Jul 15 19:06:45.303] [ET_NET 0] DIAG: <Http1ClientSession.cc:272 
(do_io_close)> (http_cs) [0] session closed
   [Jul 15 19:06:45.304] [ET_NET 0] DIAG: <HttpSM.cc:7491 (kill_this)> 
(http_seq) [0] Logging transaction
   [Jul 15 19:06:45.304] [ET_NET 0] DIAG: <Http1ClientSession.cc:83 (destroy)> 
(http_cs) [0] session destroy
   [Jul 15 19:06:45.304] [ET_NET 0] DIAG: <HttpSM.cc:7540 (kill_this)> (http) 
[0] deallocating sm
   ```
   
   ## Origin
   ```
   [DEBUG]: Configured logging at level DEBUG
       [DEBUG]: Writing TLS secrets to: 
/tmp/sandbox/proxy_protocol/pp-out-server-4/tls_secrets.txt
     [DEBUG]: Finished TLSSession::init
     [DEBUG]: Finished H2Session::init
       [INFO]: Replay file parsing took: 0 milliseconds.
   [INFO]: Ready with 1 transaction.
     [INFO]: Listening for HTTP/1.x at: 127.0.0.1:61989
     [INFO]: Listening for HTTPS (HTTP/2 or HTTP/1.x) at: 127.0.0.1:61990
   [DEBUG]: Checking for proxy protocol header.
     [DEBUG]: Peeking at the socketdata to check PROXY header
   [DEBUG]: Accepted a TLS connection with an SNI of: backend.pp.origin.com.
     [DEBUG]: Poll called on a TLS session closed by the peer.
   [DEBUG]: Checking for proxy protocol header.
     [DEBUG]: Peeking at the socketdata to check PROXY header
     [DEBUG]: Attempting to parse PROXY header
     [DEBUG]: Got 44 of pp bytes. consuming it from socket.
     [INFO]: Received PROXY header v1:
   PROXY TCP4 127.0.0.1 127.0.0.1 46294 61994
     [DEBUG]: Finished accept using TLSSession
     [DEBUG]: Negotiated ALPN: none, HTTP/2 is not negotiated. Assuming HTTP/1
   [DEBUG]: Handling SIGINT: shutting down and exiting with a 0 response code 
because no errors have been seen.
   ```
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: [email protected]

For queries about this service, please contact Infrastructure at:
[email protected]

Reply via email to