[jira] [Updated] (TS-1054) TSFetchUrl takes an address but does the DNS lookup anyway

2011-12-15 Thread Leif Hedstrom (Updated) (JIRA) 

 [ 
https://issues.apache.org/jira/browse/TS-1054?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Leif Hedstrom updated TS-1054:
--

Fix Version/s: 3.1.2

> TSFetchUrl takes an address but does the DNS lookup anyway
> --
>
> Key: TS-1054
> URL: https://issues.apache.org/jira/browse/TS-1054
> Project: Traffic Server
>  Issue Type: Bug
>  Components: Performance
>Affects Versions: 3.0.2
>Reporter: James Peach
>Priority: Minor
> Fix For: 3.1.2
>
>
> TSFetchUrl() takes an IP address as one of its arguments, so the API client 
> has to resolve the hostname portion of any URL it wants to fetch. However 
> once you get into the HTTP state machine, the host gets resolved again. One 
> of these DNS queries is redundant for performance reasons. Additionally, the 
> plugin might have some special knowledge about which IP address to use that 
> the DNS resolver doesn't, in which case the result would be wrong.
> [Dec 14 20:36:29.414] Server {0x7fff7b5f9960} DIAG: (plugin) [1] http request 
> (90 of 90 bytes):
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> [Dec 14 20:36:29.415] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [init] FetchSM 
> initialized for request with headers
> --
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> --
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [httpConnect] 
> calling httpconnect write
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Created 
> PluginVCCore at 0x102872c00, active 0x102872c38, passive 0x102872e10
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (http_seq) 
> HttpAccept:mainEvent] accepted connection
> [Dec 14 20:36:29.425] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] session 
> born, netvc 0x102872e10
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] using 
> accept inactivity timeout [120 seconds]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] Starting 
> transaction 1 using sm [0]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for 0 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_write for 90 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Passive: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Active: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; act_on 90
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [fetch_handler] calling fetch_plugin
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [process_fetch_write] calling process write
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [HttpSM::main_handler, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] done parsing 
> client request header
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> reenable Read
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) START 
> HttpTransact::ModifyRequest
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) 
> [ink_cluster_time] local: 1323923789, highest_delta: 0, cluster: 1323923789
> [Dec 14 20:36:29.437] Server {0x7fff7b5f99

[jira] [Updated] (TS-1054) TSFetchUrl takes an address but does the DNS lookup anyway

2012-01-21 Thread Leif Hedstrom (Updated) (JIRA) 

 [ 
https://issues.apache.org/jira/browse/TS-1054?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Leif Hedstrom updated TS-1054:
--

Fix Version/s: (was: 3.1.2)
   3.1.3

Moving out to 3.1.3 for now.

> TSFetchUrl takes an address but does the DNS lookup anyway
> --
>
> Key: TS-1054
> URL: https://issues.apache.org/jira/browse/TS-1054
> Project: Traffic Server
>  Issue Type: Bug
>  Components: Performance
>Affects Versions: 3.0.2
>Reporter: James Peach
>Assignee: James Peach
>Priority: Minor
> Fix For: 3.1.3
>
>
> TSFetchUrl() takes an IP address as one of its arguments, so the API client 
> has to resolve the hostname portion of any URL it wants to fetch. However 
> once you get into the HTTP state machine, the host gets resolved again. One 
> of these DNS queries is redundant for performance reasons. Additionally, the 
> plugin might have some special knowledge about which IP address to use that 
> the DNS resolver doesn't, in which case the result would be wrong.
> [Dec 14 20:36:29.414] Server {0x7fff7b5f9960} DIAG: (plugin) [1] http request 
> (90 of 90 bytes):
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> [Dec 14 20:36:29.415] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [init] FetchSM 
> initialized for request with headers
> --
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> --
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [httpConnect] 
> calling httpconnect write
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Created 
> PluginVCCore at 0x102872c00, active 0x102872c38, passive 0x102872e10
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (http_seq) 
> HttpAccept:mainEvent] accepted connection
> [Dec 14 20:36:29.425] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] session 
> born, netvc 0x102872e10
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] using 
> accept inactivity timeout [120 seconds]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] Starting 
> transaction 1 using sm [0]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for 0 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_write for 90 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Passive: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Active: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; act_on 90
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [fetch_handler] calling fetch_plugin
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [process_fetch_write] calling process write
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [HttpSM::main_handler, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] done parsing 
> client request header
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> reenable Read
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) START 
> HttpTransact::ModifyRequest
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) 
> [ink_cl

[jira] [Updated] (TS-1054) TSFetchUrl takes an address but does the DNS lookup anyway

2012-04-04 Thread James Peach (Updated) (JIRA) 

 [ 
https://issues.apache.org/jira/browse/TS-1054?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

James Peach updated TS-1054:


Fix Version/s: (was: 3.1.4)
   3.3.0

I won't have time to investigate for 3.2. Move out to 3.3.

> TSFetchUrl takes an address but does the DNS lookup anyway
> --
>
> Key: TS-1054
> URL: https://issues.apache.org/jira/browse/TS-1054
> Project: Traffic Server
>  Issue Type: Bug
>  Components: Performance
>Affects Versions: 3.0.2
>Reporter: James Peach
>Assignee: James Peach
>Priority: Minor
> Fix For: 3.3.0
>
>
> TSFetchUrl() takes an IP address as one of its arguments, so the API client 
> has to resolve the hostname portion of any URL it wants to fetch. However 
> once you get into the HTTP state machine, the host gets resolved again. One 
> of these DNS queries is redundant for performance reasons. Additionally, the 
> plugin might have some special knowledge about which IP address to use that 
> the DNS resolver doesn't, in which case the result would be wrong.
> [Dec 14 20:36:29.414] Server {0x7fff7b5f9960} DIAG: (plugin) [1] http request 
> (90 of 90 bytes):
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> [Dec 14 20:36:29.415] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [init] FetchSM 
> initialized for request with headers
> --
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> --
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [httpConnect] 
> calling httpconnect write
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Created 
> PluginVCCore at 0x102872c00, active 0x102872c38, passive 0x102872e10
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (http_seq) 
> HttpAccept:mainEvent] accepted connection
> [Dec 14 20:36:29.425] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] session 
> born, netvc 0x102872e10
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] using 
> accept inactivity timeout [120 seconds]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] Starting 
> transaction 1 using sm [0]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for 0 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_write for 90 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Passive: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Active: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; act_on 90
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [fetch_handler] calling fetch_plugin
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [process_fetch_write] calling process write
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [HttpSM::main_handler, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] done parsing 
> client request header
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> reenable Read
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) START 
> HttpTransact::ModifyRequest
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBU

[jira] [Updated] (TS-1054) TSFetchUrl takes an address but does the DNS lookup anyway

2014-09-04 Thread Leif Hedstrom (JIRA) 

 [ 
https://issues.apache.org/jira/browse/TS-1054?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Leif Hedstrom updated TS-1054:
--
Fix Version/s: (was: 5.2.0)

> TSFetchUrl takes an address but does the DNS lookup anyway
> --
>
> Key: TS-1054
> URL: https://issues.apache.org/jira/browse/TS-1054
> Project: Traffic Server
>  Issue Type: Bug
>  Components: Performance
>Affects Versions: 3.0.2
>Reporter: James Peach
>Assignee: James Peach
>Priority: Minor
>
> TSFetchUrl() takes an IP address as one of its arguments, so the API client 
> has to resolve the hostname portion of any URL it wants to fetch. However 
> once you get into the HTTP state machine, the host gets resolved again. One 
> of these DNS queries is redundant for performance reasons. Additionally, the 
> plugin might have some special knowledge about which IP address to use that 
> the DNS resolver doesn't, in which case the result would be wrong.
> [Dec 14 20:36:29.414] Server {0x7fff7b5f9960} DIAG: (plugin) [1] http request 
> (90 of 90 bytes):
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> [Dec 14 20:36:29.415] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [init] FetchSM 
> initialized for request with headers
> --
> GET http://www.iana.org//_css/2011.1/fonts/OpenSans-SemiBold.ttf HTTP/1.1
> accept: */*
> --
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (FetchSM) [httpConnect] 
> calling httpconnect write
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Created 
> PluginVCCore at 0x102872c00, active 0x102872c38, passive 0x102872e10
> [Dec 14 20:36:29.424] Server {0x7fff7b5f9960} DEBUG: (http_seq) 
> HttpAccept:mainEvent] accepted connection
> [Dec 14 20:36:29.425] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] session 
> born, netvc 0x102872e10
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] using 
> accept inactivity timeout [120 seconds]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (http_cs) [0] Starting 
> transaction 1 using sm [0]
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for 0 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_read for -1 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> do_io_write for 90 bytes
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Passive: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc_event) [0] Active: 
> Received event 1
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_read_side; act_on 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> closed? 0 shutdown? 0
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; act_on 90
> [Dec 14 20:36:29.436] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Active: 
> process_write_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [fetch_handler] calling fetch_plugin
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (FetchSM) 
> [process_fetch_write] calling process write
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; act_on 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> process_read_side; added 90
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [HttpSM::main_handler, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] 
> [&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http) [0] done parsing 
> client request header
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (pvc) [0] Passive: 
> reenable Read
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) START 
> HttpTransact::ModifyRequest
> [Dec 14 20:36:29.437] Server {0x7fff7b5f9960} DEBUG: (http_trans) 
> [ink_cluster_time] local: 1323923789, highest_delta: 0, cluster: 1323923789
> [Dec 14 20:36:29.437] Server {0x