Hi there,
Can someone please take a look and see if you can help me figure out what is
wrong for following URL redirect?
I am expecting the source URL is redirected to:
http://www.comcastwholesale.com/services/linear-hd
But I am seeing:
http://www.comcastwholesale.com/solutions-industry/mvpds
Following is the data I collected from my test.
=== ATS:
Apache Traffic Server - traffic_line - 5.3.0 - (build # 062210 on Jun 22 2015
at 10:11:19)
=== Configuration in remap.config (One line)
map http://comcastmediacenter.com http://comcastmediacenter.com
@plugin=/usr/lib64/trafficserver/plugins/regex_remap.so
@pparam=/etc/trafficserver/regexmap/comcastmediacenter.com.reg
=== Configuration in /etc/trafficserver/regexmap/comcastmediacenter.com.reg —
one line only again
^/cmc-hits/channel-detail.aspx?channel=2017
http://www.comcastwholesale.com/services/linear-hd @status=301
=== Test output:
[root@ncst-urlrw03 trafficserver]# curl -vvvvv -sIH "HOST:
comcastmediacenter.com"
http://localhost/cmc-hits/channel-detail.aspx?channel=2017
* About to connect() to localhost port 80 (#0)
* Trying ::1... Connection refused
* Trying 127.0.0.1... connected
* Connected to localhost (127.0.0.1) port 80 (#0)
> HEAD /cmc-hits/channel-detail.aspx?channel=2017 HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1
> Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Accept: */*
> HOST: comcastmediacenter.com
>
< HTTP/1.1 301 Redirect
HTTP/1.1 301 Redirect
< Date: Thu, 09 Jun 2016 18:48:00 GMT
Date: Thu, 09 Jun 2016 18:48:00 GMT
< Server: ATS/5.3.0
Server: ATS/5.3.0
< Cache-Control: no-store
Cache-Control: no-store
< Content-Type: text/html; charset=utf-8
Content-Type: text/html; charset=utf-8
< Content-Language: en
Content-Language: en
< Location: http://www.comcastwholesale.com/solutions-industry/mvpds
Location: http://www.comcastwholesale.com/solutions-industry/mvpds
< Content-Length: 214
Content-Length: 214
< Age: 0
Age: 0
< Connection: keep-alive
Connection: keep-alive
<
* Connection #0 to host localhost left intact
* Closing connection #0
=== Debug output: (From fresh ats restart)
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http_tunnel) [0]
consumer_handler [user agent VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http) [0]
[&HttpSM::tunnel_handler_ua, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http_cs) [0] session
closed
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http_cs) [0] session
destroy
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http) [0]
[HttpSM::main_handler, HTTP_TUNNEL_EVENT_DONE]
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http) [0]
[&HttpSM::tunnel_handler, HTTP_TUNNEL_EVENT_DONE]
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http_seq) Skipping cop
heartbeat logging & stats due to config
[Jun 9 19:00:24.762] Server {0x2b634fc3b700} DEBUG: (http) [0] deallocating sm
[Jun 9 19:00:33.611] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpSessionAccept:mainEvent 0x2b635c016600] accepted connection from
127.0.0.1:30063 transport type = 1
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_cs) [1] session
born, netvc 0x2b635c016600
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_cs) [1] Starting
transaction 1 using sm [1]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1]
[HttpSM::main_handler, VC_EVENT_READ_READY]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1] done parsing
client request header
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) START
HttpTransact::ModifyRequest
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498833, highest_delta: 0, cluster: 1465498833
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) END
HttpTransact::ModifyRequest
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) Checking if
transaction wants to upgrade
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_API_READ_REQUEST_HDR; HttpTransact::StartRemapRequest
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_UNDEFINED -> SM_ACTION_API_READ_REQUEST_HDR
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1] calling plugin
on hook TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x2625d40
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_api_callback, HTTP_API_CONTINUE]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_api_callout, HTTP_API_CONTINUE]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) START
HttpTransact::StartRemapRequest
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) Before
Remapping:
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) HTTP_HEADER
0x2b6358945898: [T: 3, L: 48, OBJFLAGS: 0]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [TYPE: REQ, V:
10001, URL: 0x2b6358945b18, METHOD: "HEAD", METHOD_LEN: 4, FIELDS:
0x2b63589458c8]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) URL 0x2b6358945b18:
[T: 2, L: 112, OBJFLAGS: 0]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 99,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) USER: "",
USER_LEN: 0,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) HOST: "",
HOST_LEN: 0,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) PORT: "",
PORT_LEN: 0, PORT_NUM: 0
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) PATH:
"cmc-hits/channel-detail.aspx", PATH_LEN: 28,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) QUERY:
"channel=2017", QUERY_LEN: 12,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) MIME_HEADER
0x2b63589458c8: [T: 4, L: 592, OBJFLAGS: 0]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http)
[PBITS: 0x0008000001000001, SLACC: 0xFFFFFFF1FFFFFFFFFFFFFFFFFFF0FFFF,
HEADBLK: 0x2b6358945908, TAILBLK: 0x2b6358945908]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) FIELD_BLOCK
0x2b6358945908: [T: 5, L: 528, OBJFLAGS: 0]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [FREETOP: 3,
NEXTBLK: (nil)]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 0
(0x2b6358945918), LIVE
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [N: "User-Agent",
N_LEN: 10, N_IDX: 64,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) V: "curl/7.19.7
(x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3
libidn/1.18 libssh2/1.4.2", V_LEN: 110,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 124, F: 1]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 1
(0x2b6358945938), LIVE
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [N: "Accept",
N_LEN: 6, N_IDX: 4,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) V: "*/*", V_LEN: 3,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 13, F: 1]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 2
(0x2b6358945958), LIVE
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [N: "HOST", N_LEN:
4, N_IDX: 30,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) V:
"comcastmediacenter.com", V_LEN: 22,
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 30, F: 1]
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) END
HttpTransact::StartRemapRequest
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_API_PRE_REMAP; HttpTransact::PerformRemap
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_API_READ_REQUEST_HDR -> SM_ACTION_API_PRE_REMAP
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) Inside
PerformRemap
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_REMAP_REQUEST; HttpTransact::EndRemapRequest
[Jun 9 19:00:33.612] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_API_PRE_REMAP -> SM_ACTION_REMAP_REQUEST
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpSM::do_remap_request] Remapping request
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans) START
HttpTransact::EndRemapRequest
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans)
EndRemapRequest host is comcastmediacenter.com
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans) After
Remapping:
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) HTTP_HEADER
0x2b6358945898: [T: 3, L: 48, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [TYPE: REQ, V:
10001, URL: 0x2b6358945b18, METHOD: "HEAD", METHOD_LEN: 4, FIELDS:
0x2b63589458c8]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) URL 0x2b6358945b18:
[T: 2, L: 112, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 99,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) USER: "",
USER_LEN: 0,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) HOST:
"comcastmediacenter.com", HOST_LEN: 22,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PORT: "",
PORT_LEN: 0, PORT_NUM: 0
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PATH:
"cmc-hits/channel-detail.aspx", PATH_LEN: 28,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) QUERY:
"channel=2017", QUERY_LEN: 12,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) MIME_HEADER
0x2b63589458c8: [T: 4, L: 592, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[PBITS: 0x0008000001000001, SLACC: 0xFFFFFFF1FFFFFFFFFFFFFFFFFFF0FFFF,
HEADBLK: 0x2b6358945908, TAILBLK: 0x2b6358945908]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) FIELD_BLOCK
0x2b6358945908: [T: 5, L: 528, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [FREETOP: 3,
NEXTBLK: (nil)]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 0
(0x2b6358945918), LIVE
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [N: "User-Agent",
N_LEN: 10, N_IDX: 64,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) V: "curl/7.19.7
(x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3
libidn/1.18 libssh2/1.4.2", V_LEN: 110,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 124, F: 1]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 1
(0x2b6358945938), LIVE
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [N: "Accept",
N_LEN: 6, N_IDX: 4,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) V: "*/*", V_LEN: 3,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 13, F: 1]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 2
(0x2b6358945958), LIVE
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [N: "HOST", N_LEN:
4, N_IDX: 30,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) V:
"comcastmediacenter.com", V_LEN: 22,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 0, RAWLEN: 30, F: 1]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans) END
HttpTransact::EndRemapRequest
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_API_POST_REMAP; HttpTransact::HandleRequest
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_REMAP_REQUEST -> SM_ACTION_API_POST_REMAP
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans) START
HttpTransact::HandleRequest
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans)
[init_stat_vars_from_req] set req cont length to 0
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_trans)
[is_request_valid]no request header errors
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpTransact::HandleRequest] request valid.
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) HTTP_HEADER
0x2b6358945898: [T: 3, L: 48, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [TYPE: REQ, V:
10001, URL: 0x2b6358945b18, METHOD: "HEAD", METHOD_LEN: 4, FIELDS:
0x2b63589458c8]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) URL 0x2b6358945b18:
[T: 2, L: 112, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 99,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) USER: "",
USER_LEN: 0,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) HOST:
"comcastmediacenter.com", HOST_LEN: 22,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PORT: "",
PORT_LEN: 0, PORT_NUM: 0
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PATH:
"cmc-hits/channel-detail.aspx", PATH_LEN: 28,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) QUERY:
"channel=2017", QUERY_LEN: 12,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) MIME_HEADER
0x2b63589458c8: [T: 4, L: 592, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[PBITS: 0x0008000001000001, SLACC: 0xFFFFFFF1FFFFFFFFFFFFFFFFFFF0FFFF,
HEADBLK: 0x2b6358945908, TAILBLK: 0x2b6358945908]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) FIELD_BLOCK
0x2b6358945908: [T: 5, L: 528, OBJFLAGS: 0]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [FREETOP: 3,
NEXTBLK: (nil)]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 0
(0x2b6358945918), LIVE
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [N: "User-Agent",
N_LEN: 10, N_IDX: 64,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) V: "curl/7.19.7
(x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3
libidn/1.18 libssh2/1.4.2", V_LEN: 110,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 124, F: 1]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 1
(0x2b6358945938), LIVE
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [N: "Accept",
N_LEN: 6, N_IDX: 4,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) V: "*/*", V_LEN: 3,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 13, F: 1]
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http)
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) SLOT # 2
(0x2b6358945958), LIVE
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) [N: "HOST", N_LEN:
4, N_IDX: 30,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) V:
"comcastmediacenter.com", V_LEN: 22,
[Jun 9 19:00:33.613] Server {0x2b634ff3e700} DEBUG: (http) NEXTDUP: (nil),
RAW: 0, RAWLEN: 30, F: 1]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http)
+++++++++ Incoming Request +++++++++
-- State Machine Id: 1
HEAD http://comcastmediacenter.com/cmc-hits/channel-detail.aspx?channel=2017
HTTP/1.1
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1
Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
Accept: */*
HOST: comcastmediacenter.com
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[DecideCacheLookup] Will do cache lookup.
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_seq)
[DecideCacheLookup] Will do cache lookup
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_CACHE_LOOKUP; __null
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_API_POST_REMAP -> SM_ACTION_CACHE_LOOKUP
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpSM::do_cache_lookup_and_read] [1] Issuing cache lookup for URL
http://comcastmediacenter.com/cmc-hits/channel-detail.aspx?channel=2017
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_cache) [1]
[&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1]
[HttpSM::main_handler, CACHE_EVENT_OPEN_READ_FAILED]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_cache_open_read, CACHE_EVENT_OPEN_READ_FAILED]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1] cache_open_read
- CACHE_EVENT_OPEN_READ_FAILED
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http)
[state_cache_open_read] open read failed.
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[HttpTransact::HandleCacheOpenRead]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) CacheOpenRead
-- miss
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_DNS_LOOKUP; OSDNSLookup
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_CACHE_LOOKUP -> SM_ACTION_DNS_LOOKUP
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpSM::do_hostdb_lookup] Doing DNS Lookup
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (dns) received query
comcastmediacenter.com type = 1, timeout = 0
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498833, highest_delta: 0, cluster: 1465498833
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[HttpTransact::OSDNSLookup] This was attempt 1
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpTransact::OSDNSLookup] DNS Lookup successful
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) [OSDNSLookup]
DNS lookup for O.S. successful IP: 69.252.80.75
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) Next action
SM_ACTION_API_OS_DNS; HandleCacheOpenReadMiss
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_DNS_LOOKUP -> SM_ACTION_API_OS_DNS
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[HandleCacheOpenReadMiss] --- MISS
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpTransact::HandleCacheOpenReadMiss] Miss in cache
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) client_ip_set
= 0
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans) inserted
request header 'Client-ip: 127.0.0.1'
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[add_client_ip_to_outgoing_request] Appended connecting client's (127.0.0.1) to
the X-Forwards header
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[build_request] removing host name from url
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[build_request] request not like cacheable and conditional headers not removed
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498833, highest_delta: 0, cluster: 1465498833
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_trans)
[build_request] request_sent_time: 1465498833
+++++++++ Proxy's Request +++++++++
-- State Machine Id: 1
HEAD /cmc-hits/channel-detail.aspx?channel=2017 HTTP/1.1
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1
Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
Accept: */*
HOST: comcastmediacenter.com
Client-ip: 127.0.0.1
X-Forwarded-For: 127.0.0.1
Via: http/1.1 urlrwtest[45FCFB23] (ApacheTrafficServer/5.3.0)
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_API_OS_DNS -> SM_ACTION_ORIGIN_SERVER_OPEN
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_track) entered
inside do_http_server_open ][IPv4]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1] open connection
to comcastmediacenter.com: 69.252.80.75:80
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) calling
netProcessor.connect_re
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_track) entered
inside state_http_server_open
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Jun 9 19:00:33.614] Server {0x2b634ff3e700} DEBUG: (http_ss) [1] session
born, netvc 0x2b635c016080
+++++++++ Proxy's Request after hooks +++++++++
-- State Machine Id: 1
[Jun 9 19:00:33.614] Server {0x2b6347855bc0} DEBUG: (dns) enqueing query
comcastmediacenter.com
HEAD /cmc-hits/channel-detail.aspx?channel=2017 HTTP/1.1
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1
Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
Accept: */*
HOST: comcastmediacenter.com
Client-ip: 127.0.0.1
X-Forwarded-For: 127.0.0.1
Via: http/1.1 urlrwtest[45FCFB23] (ApacheTrafficServer/5.3.0)
[Jun 9 19:00:33.614] Server {0x2b6347855bc0} DEBUG: (dns) adding first to
collapsing queue
[Jun 9 19:00:33.614] Server {0x2b6347855bc0} DEBUG: (dns) send query (qtype=1)
for comcastmediacenter.com to fd 132
[Jun 9 19:00:33.615] Server {0x2b6347855bc0} DEBUG: (dns) sent qname =
comcastmediacenter.com, id = 1678, nameserver = 1
[Jun 9 19:00:33.615] Server {0x2b6347855bc0} DEBUG: (dns) sent_one:
failover_number for resolver 1 is 1
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http) [1]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http) [1]
[HttpSM::main_handler, VC_EVENT_READ_READY]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::state_read_server_response_header, VC_EVENT_READ_READY]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_seq) Done parsing
server response header
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498833, highest_delta: 0, cluster: 1465498833
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1465498833
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 1
HTTP/1.1 301 Redirect
Date: Thu, 09 Jun 2016 19:00:33 GMT
Connection: close
Server: ATS/4.0.1
Cache-Control: no-store
Content-Type: text/html; charset=utf-8
Content-Language: en
Location: http://www.comcastwholesale.com/solutions-industry/mvpds
Content-Length: 214
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[is_response_valid] No errors in response
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response valid
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans) [hrfs]
connection alive
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[handle_forward_server_connection_open] (hfsco)
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpTransact::handle_server_connection_open]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http) server info =
69.252.80.75:80
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans) [hfsco] cache
action: CACHE_DO_NO_ACTION
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[handle_no_cache_operation_on_forward_server_response] (hncoofsr)
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_seq)
[handle_no_cache_operation_on_forward_server_response]
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans) [hncoofsr]
server sent back something other than 100,304,200
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] age_value: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] date_value: 1465498833
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] response_time: 1465498833
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] now: 1465498833
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] now (fixed): 1465498833
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] apparent_age: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] corrected_received_age: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] response_delay: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] corrected_initial_age: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] resident_time: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_age)
[calculate_document_age] current_age: 0
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans)
[handle_content_length_header] RESPONSE cont len in hdr is 214
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans) [Squid code
generation] Hit/Miss: 1, Log: 3, Hier: 2
[Jun 9 19:00:33.615] Server {0x2b634ff3e700} DEBUG: (http_trans) Adding
Server: ATS/5.3.0
+++++++++ Base Header for Building Response +++++++++
-- State Machine Id: 1
HTTP/1.1 301 Redirect
Date: Thu, 09 Jun 2016 19:00:33 GMT
Connection: close
Server: ATS/4.0.1
Cache-Control: no-store
Content-Type: text/html; charset=utf-8
Content-Language: en
Location: http://www.comcastwholesale.com/solutions-industry/mvpds
Content-Length: 214
+++++++++ Proxy's Response 2 +++++++++
-- State Machine Id: 1
HTTP/1.1 301 Redirect
Date: Thu, 09 Jun 2016 19:00:33 GMT
Server: ATS/5.3.0
Cache-Control: no-store
Content-Type: text/html; charset=utf-8
Content-Language: en
Location: http://www.comcastwholesale.com/solutions-industry/mvpds
Content-Length: 214
Age: 0
Connection: keep-alive
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1] State
Transition: SM_ACTION_ORIGIN_SERVER_OPEN -> SM_ACTION_SERVER_READ
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_redirect)
is_redirect_required 0
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_redirect)
[HttpSM::do_redirect]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) Setup Server
Transfer
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_tunnel) [1] adding
producer 'http server'
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_tunnel) [1] adding
consumer 'user agent'
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1]
perform_cache_write_action CACHE_DO_NO_ACTION
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_tunnel) tunnel_run
started, p_arg is provided
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs)
tcp_init_cwnd_set 0
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs) desired TCP
congestion window is 0
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_tunnel) [1]
[tunnel_run] producer already done
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_tunnel) [1]
producer_handler [http server HTTP_TUNNEL_EVENT_PRECOMPLETE]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_redirect)
[HttpTunnel::producer_handler] enable_redirection: [0 0 0] event: 2302
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::tunnel_handler_server, HTTP_TUNNEL_EVENT_PRECOMPLETE]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_ss) [1] session
closing, netvc 0x2b635c016080
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_tunnel) [1]
consumer_handler [user agent VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::tunnel_handler_ua, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs) [1] session
released by sm [1]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs)
tcp_init_cwnd_set 1
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs) [1] initiating
io for next header
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1]
[HttpSM::main_handler, HTTP_TUNNEL_EVENT_DONE]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1]
[&HttpSM::tunnel_handler, HTTP_TUNNEL_EVENT_DONE]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_seq)
[HttpSM::update_stats] Logging transaction
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http) [1] deallocating sm
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs) [1]
[&HttpClientSession::state_keep_alive, VC_EVENT_EOS]
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs) [1] session
closed
[Jun 9 19:00:33.616] Server {0x2b634ff3e700} DEBUG: (http_cs) [1] session
destroy
[Jun 9 19:00:33.627] Server {0x2b6347855bc0} DEBUG: (dns) received packet size
= 56
[Jun 9 19:00:33.627] Server {0x2b6347855bc0} DEBUG: (dns) round-robin:
nameserver 1 DNS response code = 0
[Jun 9 19:00:33.627] Server {0x2b6347855bc0} DEBUG: (dns) received A name =
comcastmediacenter.com
[Jun 9 19:00:33.627] Server {0x2b6347855bc0} DEBUG: (dns) SUCCESS result for
comcastmediacenter.com = 69.252.80.75 retry 0
[Jun 9 19:00:33.627] Server {0x2b634ff3e700} DEBUG: (dns) called back
continuation for comcastmediacenter.com
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpSessionAccept:mainEvent 0x2b635c016600] accepted connection from
127.0.0.1:63171 transport type = 0
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_cs) [2] session
born, netvc 0x2b635c016600
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_cs) [2] Starting
transaction 1 using sm [2]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [2]
[HttpSM::main_handler, VC_EVENT_READ_READY]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [2] done parsing
client request header
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) START
HttpTransact::ModifyRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498834, highest_delta: 0, cluster: 1465498834
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) END
HttpTransact::ModifyRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) Checking if
transaction wants to upgrade
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_API_READ_REQUEST_HDR; HttpTransact::StartRemapRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_UNDEFINED -> SM_ACTION_API_READ_REQUEST_HDR
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) START
HttpTransact::StartRemapRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) Before
Remapping:
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) HTTP_HEADER
0x2b6358943898: [T: 3, L: 48, OBJFLAGS: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [TYPE: REQ, V:
10000, URL: 0x2b6358943b18, METHOD: "GET", METHOD_LEN: 3, FIELDS:
0x2b63589438c8]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) URL 0x2b6358943b18:
[T: 2, L: 112, OBJFLAGS: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 99,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) USER: "",
USER_LEN: 0,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) HOST:
"127.0.0.1", HOST_LEN: 9,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) PORT: "8083",
PORT_LEN: 4, PORT_NUM: 8083
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) PATH:
"synthetic.txt", PATH_LEN: 13,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) QUERY: "",
QUERY_LEN: 0,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) MIME_HEADER
0x2b63589438c8: [T: 4, L: 592, OBJFLAGS: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http)
[PBITS: 0x0000000001000000, SLACC: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF,
HEADBLK: 0x2b6358943908, TAILBLK: 0x2b6358943908]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) FIELD_BLOCK
0x2b6358943908: [T: 5, L: 528, OBJFLAGS: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [FREETOP: 1,
NEXTBLK: (nil)]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) SLOT # 0
(0x2b6358943918), LIVE
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [N: "Host", N_LEN:
4, N_IDX: 30,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) V:
"127.0.0.1:8083", V_LEN: 14,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) NEXTDUP: (nil),
RAW: 0, RAWLEN: 18, F: 1]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http)
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) END
HttpTransact::StartRemapRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_API_PRE_REMAP; HttpTransact::PerformRemap
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_API_READ_REQUEST_HDR -> SM_ACTION_API_PRE_REMAP
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) Inside
PerformRemap
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_REMAP_REQUEST; HttpTransact::EndRemapRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_API_PRE_REMAP -> SM_ACTION_REMAP_REQUEST
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpSM::do_remap_request] Remapping request
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) START
HttpTransact::EndRemapRequest
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans)
EndRemapRequest host is 127.0.0.1
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http_trans) After
Remapping:
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) HTTP_HEADER
0x2b6358943898: [T: 3, L: 48, OBJFLAGS: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [TYPE: REQ, V:
10000, URL: 0x2b6358943b18, METHOD: "GET", METHOD_LEN: 3, FIELDS:
0x2b63589438c8]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) URL 0x2b6358943b18:
[T: 2, L: 112, OBJFLAGS: 0]
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 99,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) USER: "",
USER_LEN: 0,
[Jun 9 19:00:34.763] Server {0x2b635003f700} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) HOST:
"127.0.0.1", HOST_LEN: 9,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PORT: "8083",
PORT_LEN: 4, PORT_NUM: 8083
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PATH:
"synthetic.txt", PATH_LEN: 13,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) QUERY: "",
QUERY_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) MIME_HEADER
0x2b63589438c8: [T: 4, L: 592, OBJFLAGS: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http)
[PBITS: 0x0000000001000000, SLACC: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF,
HEADBLK: 0x2b6358943908, TAILBLK: 0x2b6358943908]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) FIELD_BLOCK
0x2b6358943908: [T: 5, L: 528, OBJFLAGS: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [FREETOP: 1,
NEXTBLK: (nil)]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) SLOT # 0
(0x2b6358943918), LIVE
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [N: "Host", N_LEN:
4, N_IDX: 30,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) V:
"127.0.0.1:8083", V_LEN: 14,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) NEXTDUP: (nil),
RAW: 0, RAWLEN: 18, F: 1]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http)
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) END
HttpTransact::EndRemapRequest
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_API_POST_REMAP; HttpTransact::HandleRequest
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_REMAP_REQUEST -> SM_ACTION_API_POST_REMAP
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) START
HttpTransact::HandleRequest
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[init_stat_vars_from_req] set req cont length to 0
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[is_request_valid]no request header errors
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpTransact::HandleRequest] request valid.
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) HTTP_HEADER
0x2b6358943898: [T: 3, L: 48, OBJFLAGS: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [TYPE: REQ, V:
10000, URL: 0x2b6358943b18, METHOD: "GET", METHOD_LEN: 3, FIELDS:
0x2b63589438c8]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) URL 0x2b6358943b18:
[T: 2, L: 112, OBJFLAGS: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 99,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) USER: "",
USER_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) HOST:
"127.0.0.1", HOST_LEN: 9,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PORT: "8083",
PORT_LEN: 4, PORT_NUM: 8083
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PATH:
"synthetic.txt", PATH_LEN: 13,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) QUERY: "",
QUERY_LEN: 0,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) MIME_HEADER
0x2b63589438c8: [T: 4, L: 592, OBJFLAGS: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http)
[PBITS: 0x0000000001000000, SLACC: 0xFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF,
HEADBLK: 0x2b6358943908, TAILBLK: 0x2b6358943908]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) FIELD_BLOCK
0x2b6358943908: [T: 5, L: 528, OBJFLAGS: 0]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [FREETOP: 1,
NEXTBLK: (nil)]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) SLOT # 0
(0x2b6358943918), LIVE
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [N: "Host", N_LEN:
4, N_IDX: 30,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) V:
"127.0.0.1:8083", V_LEN: 14,
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) NEXTDUP: (nil),
RAW: 0, RAWLEN: 18, F: 1]
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http)
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[DecideCacheLookup] Will NOT do cache lookup.
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_seq)
[DecideCacheLookup] Will NOT do cache lookup
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_API_CACHE_LOOKUP_COMPLETE; CallOSDNSLookup
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_API_POST_REMAP -> SM_ACTION_API_CACHE_LOOKUP_COMPLETE
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_DNS_LOOKUP; OSDNSLookup
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_API_CACHE_LOOKUP_COMPLETE -> SM_ACTION_DNS_LOOKUP
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (dns)
[HttpTransact::HandleRequest] Skipping DNS lookup for 127.0.0.1 because it's
loopback
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[HttpTransact::OSDNSLookup] This was attempt 1
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpTransact::OSDNSLookup] DNS Lookup successful
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) [OSDNSLookup]
DNS lookup for O.S. successful IP: 127.0.0.1
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) Next action
SM_ACTION_API_OS_DNS; LookupSkipOpenServer
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_DNS_LOOKUP -> SM_ACTION_API_OS_DNS
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) client_ip_set
= 0
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) inserted
request header 'Client-ip: 127.0.0.1'
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[add_client_ip_to_outgoing_request] Appended connecting client's (127.0.0.1) to
the X-Forwards header
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[build_request] removing host name from url
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[build_request] request like cacheable and conditional headers removed
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498834, highest_delta: 0, cluster: 1465498834
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans)
[build_request] request_sent_time: 1465498834
[Jun 9 19:00:34.764] Server {0x2b635003f700} DEBUG: (http_trans) Next action
next; HttpTransact::HandleResponse
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_API_OS_DNS -> SM_ACTION_ORIGIN_SERVER_OPEN
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_track) entered
inside do_http_server_open ][IPv4]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2] open connection
to 127.0.0.1: 127.0.0.1:8083
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) calling
netProcessor.connect_re
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_track) entered
inside state_http_server_open
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_ss) [2] session
born, netvc 0x2b635c015dc0
+++++++++ Proxy's Request after hooks +++++++++
-- State Machine Id: 2
GET /synthetic.txt HTTP/1.1
Host: 127.0.0.1:8083
Client-ip: 127.0.0.1
X-Forwarded-For: 127.0.0.1
Via: http/1.0 urlrwtest[45FCFB23] (ApacheTrafficServer/5.3.0)
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2]
[HttpSM::main_handler, VC_EVENT_READ_READY]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::state_read_server_response_header, VC_EVENT_READ_READY]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_seq) Done parsing
server response header
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[ink_cluster_time] local: 1465498834, highest_delta: 0, cluster: 1465498834
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1465498834
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[is_response_valid] No errors in response
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response valid
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans) [hrfs]
connection alive
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[handle_forward_server_connection_open] (hfsco)
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_seq)
[HttpTransact::handle_server_connection_open]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http) server info =
127.0.0.1:8083
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans) [hfsco] cache
action: CACHE_DO_NO_ACTION
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans)
[handle_no_cache_operation_on_forward_server_response] (hncoofsr)
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_seq)
[handle_no_cache_operation_on_forward_server_response]
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans) [hncoofsr]
server sent back 200
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_trans) [hncoofsr]
next action will be OS_READ_CACHE_NOOP
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] age_value: 0
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] date_value: 1465498834
[Jun 9 19:00:34.765] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] response_time: 1465498834
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] now: 1465498834
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] now (fixed): 1465498834
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] apparent_age: 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] corrected_received_age: 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] response_delay: 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] corrected_initial_age: 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] resident_time: 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_age)
[calculate_document_age] current_age: 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_trans)
[handle_content_length_header] RESPONSE cont len in hdr is 1620
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_trans) [Squid code
generation] Hit/Miss: 1, Log: 3, Hier: 2
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_trans) Adding
Server: ATS/5.3.0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2] State
Transition: SM_ACTION_ORIGIN_SERVER_OPEN -> SM_ACTION_SERVER_READ
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_redirect)
is_redirect_required 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) Setup Server
Transfer
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_tunnel) [2] adding
producer 'http server'
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_tunnel) [2] adding
consumer 'user agent'
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2]
perform_cache_write_action CACHE_DO_NO_ACTION
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_tunnel) tunnel_run
started, p_arg is provided
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_cs)
tcp_init_cwnd_set 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_cs) desired TCP
congestion window is 0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_tunnel) [2]
[tunnel_run] producer already done
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_tunnel) [2]
producer_handler [http server HTTP_TUNNEL_EVENT_PRECOMPLETE]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_redirect)
[HttpTunnel::producer_handler] enable_redirection: [0 0 0] event: 2302
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::tunnel_handler_server, HTTP_TUNNEL_EVENT_PRECOMPLETE]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_ss) [2] session
closing, netvc 0x2b635c015dc0
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_tunnel) [2]
consumer_handler [user agent VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::tunnel_handler_ua, VC_EVENT_WRITE_COMPLETE]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_cs) [2] session
closed
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_cs) [2] session
destroy
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2]
[HttpSM::main_handler, HTTP_TUNNEL_EVENT_DONE]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2]
[&HttpSM::tunnel_handler, HTTP_TUNNEL_EVENT_DONE]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http_seq) Skipping cop
heartbeat logging & stats due to config
[Jun 9 19:00:34.766] Server {0x2b635003f700} DEBUG: (http) [2] deallocating sm
Thank you very much!
Hong Ye
