[
https://issues.apache.org/jira/browse/TS-871?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13491919#comment-13491919
]
Igor Galić commented on TS-871:
-------------------------------
I was unable to repro the issue Ben reported here, reason being: I went over
https:// while he went over http://
Here's what happens with an svn co:
{noformat}
igalic@tynix ~/src/asf % svn co
http://svn.apache.org/repos/asf/subversion/trunk subversion.snew
svn: E175002: Unable to connect to a repository at URL
'http://svn.apache.org/repos/asf/subversion/trunk'
svn: E175002: Server sent unexpected return value (504 Connection Timed Out) in
response to OPTIONS request for
'http://svn.apache.org/repos/asf/subversion/trunk'
1 igalic@tynix ~/src/asf %
{noformat}
On the traffic_server side we have:
{noformat}
[Nov 6 23:37:46.767] Server {0x7fc78400f840} DEBUG: (http_init)
proxy.config.http.redirection_enabled = 0
[Nov 6 23:37:46.767] Server {0x7fc78400f840} DEBUG: (http_init)
proxy.config.http.number_of_redirections = 1
[Nov 6 23:37:46.767] Server {0x7fc78400f840} DEBUG: (http_init)
proxy.config.http.post_copy_size = 2048
[Nov 6 23:37:46.769] Server {0x7fc78400f840} DEBUG: (http_aeua)
[HttpConfig::init_aeua_filter] - Config:
"/opt/ats-trunk/etc/trafficserver/ae_ua.config"
[Nov 6 23:37:46.769] Server {0x7fc78400f840} DEBUG: (http_aeua)
[HttpConfig::init_aeua_filter] - Opening config
"/opt/ats-trunk/etc/trafficserver/ae_ua.config"
[Nov 6 23:37:46.769] Server {0x7fc78400f840} DEBUG: (http_aeua)
[HttpConfig::init_aeua_filter] - Added 0 REGEXP filters
[Nov 6 23:37:46.769] Server {0x7fc78400f840} DEBUG: (http_aeua)
[init_http_aeua_filter] - Total loaded 0 REGEXP for Accept-Enconding/User-Agent
filtering
[Nov 6 23:37:46.769] Server {0x7fc78400f840} WARNING: connection throttle too
high, 30000 (throttle) + 192 (internal use) > 4096 (file descriptor limit),
using throttle of 3904
[Nov 6 23:37:46.770] Server {0x7fc78400f840} NOTE: cache clustering disabled
[Nov 6 23:37:46.782] Server {0x7fc78400f840} NOTE: cache clustering disabled
[Nov 6 23:37:46.796] Server {0x7fc78400f840} NOTE: logging initialized[11],
logging_mode = 3
[Nov 6 23:37:46.808] Server {0x7fc78400f840} NOTE: traffic server running
[Nov 6 23:37:46.877] Server {0x7fc78400f840} NOTE: cache enabled
[Nov 6 23:37:52.855] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpAccept:mainEvent 0x7fc774016600] accepted connection from
192.168.122.1:38202 transport type = 0
[Nov 6 23:37:52.856] Server {0x7fc78400f840} DEBUG: (http_cs) [0] session
born, netvc 0x7fc774016600
[Nov 6 23:37:52.873] Server {0x7fc78400f840} DEBUG: (http_cs) [0] using accept
inactivity timeout [120 seconds]
[Nov 6 23:37:52.873] Server {0x7fc78400f840} DEBUG: (http_cs) [0] Starting
transaction 1 using sm [0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_READ_READY]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [0] done parsing
client request header
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http_trans) START
HttpTransact::ModifyRequest
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241472, highest_delta: 0, cluster: 1352241472
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http_trans) END
HttpTransact::ModifyRequest
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
HTTP_API_READ_REQUEST_HDR; HttpTransact::StartRemapRequest
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: STATE_UNDEFINED -> API_READ_REQUEST_HDR
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http_trans) START
HttpTransact::StartRemapRequest
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http_trans) Before
Remapping:
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) HTTP_HEADER
0x7fc77a89f898: [T: 3, L: 48, OBJFLAGS: 0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [TYPE: REQ, V:
10001, URL: 0x7fc77a89fb18, METHOD: "OPTIONS", METHOD_LEN: 7, FIELDS:
0x7fc77a89f8c8]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) URL 0x7fc77a89fb18:
[T: 2, L: 128, OBJFLAGS: 0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 94,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) USER: "",
USER_LEN: 0,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) HOST:
"svn.apache.org", HOST_LEN: 14,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) PORT: "",
PORT_LEN: 0, PORT_NUM: 0
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) PATH:
"repos/asf/subversion/trunk", PATH_LEN: 26,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) QUERY: "",
QUERY_LEN: 0,
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) MIME_HEADER
0x7fc77a89f8c8: [T: 4, L: 592, OBJFLAGS: 0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http)
[PBITS: 0x0009000001044804, SLACC: 0xFFFFF5FFFFF49FF1FFFFFFFFFFF0F2FF,
HEADBLK: 0x7fc77a89f908, TAILBLK: 0x7fc77a89f908]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) FIELD_BLOCK
0x7fc77a89f908: [T: 5, L: 528, OBJFLAGS: 0]
[Nov 6 23:37:52.876] Server {0x7fc78400f840} DEBUG: (http) [FREETOP: 11,
NEXTBLK: (nil)]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 0
(0x7fc77a89f918), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "User-Agent",
N_LEN: 10, N_IDX: 64,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "SVN/1.7.7
neon/0.29.6", V_LEN: 21,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 35, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 1
(0x7fc77a89f938), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "Connection",
N_LEN: 10, N_IDX: 12,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "TE", V_LEN: 2,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 16, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 2
(0x7fc77a89f958), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "TE", N_LEN: 2,
N_IDX: 121,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "trailers",
V_LEN: 8,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 14, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 3
(0x7fc77a89f978), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "Host", N_LEN:
4, N_IDX: 30,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V:
"svn.apache.org", V_LEN: 14,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 22, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 4
(0x7fc77a89f998), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "Content-Type",
N_LEN: 12, N_IDX: 20,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "text/xml",
V_LEN: 8,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 24, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 5
(0x7fc77a89f9b8), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N:
"Accept-Encoding", N_LEN: 15, N_IDX: 1,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "gzip", V_LEN:
4,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89fa58, RAW: 1, RAWLEN: 23, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 6
(0x7fc77a89f9d8), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/depth";, V_LEN: 48,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89f9f8, RAW: 1, RAWLEN: 55, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 7
(0x7fc77a89f9f8), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/mergeinfo";, V_LEN: 52,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89fa18, RAW: 1, RAWLEN: 59, F: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 8
(0x7fc77a89fa18), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/log-revprops";, V_LEN: 55,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 62, F: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT # 9
(0x7fc77a89fa38), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N:
"Content-Length", N_LEN: 14, N_IDX: 16,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "104", V_LEN: 3,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 21, F: 1]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SLOT #10
(0x7fc77a89fa58), LIVE
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [N:
"Accept-Encoding", N_LEN: 15, N_IDX: 1,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) V: "gzip", V_LEN:
4,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 23, F: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans) END
HttpTransact::StartRemapRequest
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
HTTP_API_PRE_REMAP; HttpTransact::PerformRemap
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: API_READ_REQUEST_HDR -> HTTP_API_PRE_REMAP
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans) Inside
PerformRemap
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
HTTP_REMAP_REQUEST; HttpTransact::EndRemapRequest
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: HTTP_API_PRE_REMAP -> HTTP_REMAP_REQUEST
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_remap_request] Remapping request
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans) START
HttpTransact::EndRemapRequest
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans)
EndRemapRequest host is svn.apache.org
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http_trans) After
Remapping:
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) HTTP_HEADER
0x7fc77a89f898: [T: 3, L: 48, OBJFLAGS: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [TYPE: REQ, V:
10001, URL: 0x7fc77a89fb18, METHOD: "OPTIONS", METHOD_LEN: 7, FIELDS:
0x7fc77a89f8c8]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) URL 0x7fc77a89fb18:
[T: 2, L: 128, OBJFLAGS: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 94,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) USER: "",
USER_LEN: 0,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) HOST:
"svn.apache.org", HOST_LEN: 14,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) PORT: "",
PORT_LEN: 0, PORT_NUM: 0
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) PATH:
"repos/asf/subversion/trunk", PATH_LEN: 26,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) QUERY: "",
QUERY_LEN: 0,
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http) MIME_HEADER
0x7fc77a89f8c8: [T: 4, L: 592, OBJFLAGS: 0]
[Nov 6 23:37:52.877] Server {0x7fc78400f840} DEBUG: (http)
[PBITS: 0x0009000001044804, SLACC: 0xFFFFF5FFFFF49FF1FFFFFFFFFFF0F2FF,
HEADBLK: 0x7fc77a89f908, TAILBLK: 0x7fc77a89f908]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) FIELD_BLOCK
0x7fc77a89f908: [T: 5, L: 528, OBJFLAGS: 0]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [FREETOP: 11,
NEXTBLK: (nil)]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 0
(0x7fc77a89f918), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "User-Agent",
N_LEN: 10, N_IDX: 64,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "SVN/1.7.7
neon/0.29.6", V_LEN: 21,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 35, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 1
(0x7fc77a89f938), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "Connection",
N_LEN: 10, N_IDX: 12,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "TE", V_LEN: 2,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 16, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 2
(0x7fc77a89f958), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "TE", N_LEN: 2,
N_IDX: 121,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "trailers",
V_LEN: 8,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 14, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 3
(0x7fc77a89f978), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "Host", N_LEN:
4, N_IDX: 30,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V:
"svn.apache.org", V_LEN: 14,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 22, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 4
(0x7fc77a89f998), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "Content-Type",
N_LEN: 12, N_IDX: 20,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "text/xml",
V_LEN: 8,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 24, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 5
(0x7fc77a89f9b8), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N:
"Accept-Encoding", N_LEN: 15, N_IDX: 1,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "gzip", V_LEN:
4,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89fa58, RAW: 1, RAWLEN: 23, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 6
(0x7fc77a89f9d8), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/depth";, V_LEN: 48,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89f9f8, RAW: 1, RAWLEN: 55, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 7
(0x7fc77a89f9f8), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/mergeinfo";, V_LEN: 52,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89fa18, RAW: 1, RAWLEN: 59, F: 0]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 8
(0x7fc77a89fa18), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/log-revprops";, V_LEN: 55,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 62, F: 0]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT # 9
(0x7fc77a89fa38), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N:
"Content-Length", N_LEN: 14, N_IDX: 16,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "104", V_LEN: 3,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 21, F: 1]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) SLOT #10
(0x7fc77a89fa58), LIVE
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [N:
"Accept-Encoding", N_LEN: 15, N_IDX: 1,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) V: "gzip", V_LEN:
4,
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 23, F: 0]
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http_trans) END
HttpTransact::EndRemapRequest
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
HTTP_API_POST_REMAP; HttpTransact::HandleRequest
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: HTTP_REMAP_REQUEST -> HTTP_API_POST_REMAP
[Nov 6 23:37:52.878] Server {0x7fc78400f840} DEBUG: (http_trans) START
HttpTransact::HandleRequest
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http_trans)
[is_request_valid]no request header errors
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleRequest] request valid.
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) HTTP_HEADER
0x7fc77a89f898: [T: 3, L: 48, OBJFLAGS: 0]
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) [TYPE: REQ, V:
10001, URL: 0x7fc77a89fb18, METHOD: "OPTIONS", METHOD_LEN: 7, FIELDS:
0x7fc77a89f8c8]
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) URL 0x7fc77a89fb18:
[T: 2, L: 128, OBJFLAGS: 0]
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) [URLTYPE: 1,
SWKSIDX: 94,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) SCHEME: "http",
SCHEME_LEN: 4,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) USER: "",
USER_LEN: 0,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) PASSWORD: "",
PASSWORD_LEN: 0,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) HOST:
"svn.apache.org", HOST_LEN: 14,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) PORT: "",
PORT_LEN: 0, PORT_NUM: 0
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) PATH:
"repos/asf/subversion/trunk", PATH_LEN: 26,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) PARAMS: "",
PARAMS_LEN: 0,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) QUERY: "",
QUERY_LEN: 0,
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) FRAGMENT: "",
FRAGMENT_LEN: 0]
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http) MIME_HEADER
0x7fc77a89f8c8: [T: 4, L: 592, OBJFLAGS: 0]
[Nov 6 23:37:52.879] Server {0x7fc78400f840} DEBUG: (http)
[PBITS: 0x0009000001044804, SLACC: 0xFFFFF5FFFFF49FF1FFFFFFFFFFF0F2FF,
HEADBLK: 0x7fc77a89f908, TAILBLK: 0x7fc77a89f908]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [CBITS:
0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) FIELD_BLOCK
0x7fc77a89f908: [T: 5, L: 528, OBJFLAGS: 0]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [FREETOP: 11,
NEXTBLK: (nil)]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 0
(0x7fc77a89f918), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "User-Agent",
N_LEN: 10, N_IDX: 64,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V: "SVN/1.7.7
neon/0.29.6", V_LEN: 21,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 35, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 1
(0x7fc77a89f938), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "Connection",
N_LEN: 10, N_IDX: 12,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V: "TE", V_LEN: 2,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 16, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 2
(0x7fc77a89f958), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "TE", N_LEN: 2,
N_IDX: 121,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V: "trailers",
V_LEN: 8,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 14, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 3
(0x7fc77a89f978), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "Host", N_LEN:
4, N_IDX: 30,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V:
"svn.apache.org", V_LEN: 14,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 22, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 4
(0x7fc77a89f998), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "Content-Type",
N_LEN: 12, N_IDX: 20,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V: "text/xml",
V_LEN: 8,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 24, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 5
(0x7fc77a89f9b8), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N:
"Accept-Encoding", N_LEN: 15, N_IDX: 1,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V: "gzip", V_LEN:
4,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89fa58, RAW: 1, RAWLEN: 23, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 6
(0x7fc77a89f9d8), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/depth";, V_LEN: 48,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89f9f8, RAW: 1, RAWLEN: 55, F: 1]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 7
(0x7fc77a89f9f8), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/mergeinfo";, V_LEN: 52,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP:
0x7fc77a89fa18, RAW: 1, RAWLEN: 59, F: 0]
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) SLOT # 8
(0x7fc77a89fa18), LIVE
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) [N: "DAV", N_LEN:
3, N_IDX: -1,
[Nov 6 23:37:52.880] Server {0x7fc78400f840} DEBUG: (http) V:
"http://subversion.tigris.org/xmlns/dav/svn/log-revprops";, V_LEN: 55,
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 62, F: 0]
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) SLOT # 9
(0x7fc77a89fa38), LIVE
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) [N:
"Content-Length", N_LEN: 14, N_IDX: 16,
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) V: "104", V_LEN: 3,
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 21, F: 1]
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http)
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) SLOT #10
(0x7fc77a89fa58), LIVE
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) [N:
"Accept-Encoding", N_LEN: 15, N_IDX: 1,
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) V: "gzip", V_LEN:
4,
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) NEXTDUP: (nil),
RAW: 1, RAWLEN: 23, F: 0]
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http)
+++++++++ Incoming Request +++++++++
-- State Machine Id: 0
OPTIONS http://svn.apache.org/repos/asf/subversion/trunk HTTP/1.1
User-Agent: SVN/1.7.7 neon/0.29.6
Connection: TE
TE: trailers
Host: svn.apache.org
Content-Type: text/xml
Accept-Encoding: gzip
DAV: http://subversion.tigris.org/xmlns/dav/svn/depth
DAV: http://subversion.tigris.org/xmlns/dav/svn/mergeinfo
DAV: http://subversion.tigris.org/xmlns/dav/svn/log-revprops
Content-Length: 104
Accept-Encoding: gzip
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans)
[DecideCacheLookup] Will NOT do cache lookup.
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_seq)
[DecideCacheLookup] Will NOT do cache lookup
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
HTTP_API_CACHE_LOOKUP_COMPLETE; CallOSDNSLookup
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: HTTP_API_POST_REMAP -> API_CACHE_LOOKUP_COMPLETE
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
DNS_LOOKUP; OSDNSLookup
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: API_CACHE_LOOKUP_COMPLETE -> DNS_LOOKUP
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpStateMachineGet::do_hostdb_lookup] Doing DNS Lookup
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::OSDNSLookup] This was attempt 1
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::OSDNSLookup] DNS Lookup successful
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans) [OSDNSLookup]
DNS lookup for O.S. successful IP: 160.45.251.2
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
HttpTransact::HTTP_API_OS_DNS; LookupSkipOpenServer
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: DNS_LOOKUP -> API_OS_DNS
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans) request not
cacheable, so bypass parent
[Nov 6 23:37:52.881] Server {0x7fc78400f840} DEBUG: (http_trans) client_ip_set
= 0
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_trans) inserted
request header 'Client-ip: 192.168.122.1'
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_trans)
[add_client_ip_to_outgoing_request] Appended connecting client's
(192.168.122.1) to the X-Forwards header
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241472, highest_delta: 0, cluster: 1352241472
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_trans)
[build_request] request_sent_time: 1352241472
+++++++++ Proxy's Request +++++++++
-- State Machine Id: 0
OPTIONS /repos/asf/subversion/trunk HTTP/1.1
User-Agent: SVN/1.7.7 neon/0.29.6
Host: svn.apache.org
Content-Type: text/xml
Accept-Encoding: gzip
DAV: http://subversion.tigris.org/xmlns/dav/svn/depth
DAV: http://subversion.tigris.org/xmlns/dav/svn/mergeinfo
DAV: http://subversion.tigris.org/xmlns/dav/svn/log-revprops
Content-Length: 104
Accept-Encoding: gzip
Client-ip: 192.168.122.1
X-Forwarded-For: 192.168.122.1
Via: http/1.1 tynix[FE80000000000000B6749FFFFE9DDA61]
(ApacheTrafficServer/3.2.3 [uSc s f p eN:tMc i p s ])
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
next; HttpTransact::HandleResponse
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: API_OS_DNS -> ORIGIN_SERVER_OPEN
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside do_http_server_open
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http) [0] open connection
to svn.apache.org: 160.45.251.2:80
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Nov 6 23:37:52.885] Server {0x7fc78400f840} DEBUG: (http) calling
netProcessor.connect_re
[Nov 6 23:37:52.886] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Nov 6 23:37:52.886] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside state_http_server_open
[Nov 6 23:37:52.886] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Nov 6 23:37:52.886] Server {0x7fc78400f840} DEBUG: (http_ss) [0] session
born, netvc 0x7fc774015dc0
[Nov 6 23:37:52.917] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:37:52.917] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_server_response_header, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_ss) [0] session
closed
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::handle_server_setup_error, VC_EVENT_NONE]
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241503, highest_delta: 0, cluster: 1352241503
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1352241503
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 0
HTTP/0.9 0
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response not valid
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans) [1] failed to
connect [6] to 160.45.251.2
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans)
[retry_server_connection_not_open] attempts now: 2, max: 6
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] Error. Retrying...
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: ORIGIN_SERVER_OPEN -> ORIGIN_SERVER_OPEN
[Nov 6 23:38:23.722] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside do_http_server_open
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http) [0] open connection
to svn.apache.org: 160.45.251.2:80
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http) calling
netProcessor.connect_re
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside state_http_server_open
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Nov 6 23:38:23.723] Server {0x7fc78400f840} DEBUG: (http_ss) [1] session
born, netvc 0x7fc774015b00
[Nov 6 23:38:23.773] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:38:23.773] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_server_response_header, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_ss) [1] session
closed
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::handle_server_setup_error, VC_EVENT_NONE]
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241534, highest_delta: 0, cluster: 1352241534
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1352241534
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 0
HTTP/0.9 0
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response not valid
[Nov 6 23:38:54.658] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_trans) [2] failed to
connect [6] to 160.45.251.2
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_trans)
[retry_server_connection_not_open] attempts now: 3, max: 6
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] Error. Retrying...
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: ORIGIN_SERVER_OPEN -> ORIGIN_SERVER_OPEN
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside do_http_server_open
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http) [0] open connection
to svn.apache.org: 160.45.251.2:80
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http) calling
netProcessor.connect_re
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside state_http_server_open
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Nov 6 23:38:54.659] Server {0x7fc78400f840} DEBUG: (http_ss) [2] session
born, netvc 0x7fc774015dc0
[Nov 6 23:38:55.716] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:38:55.716] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_server_response_header, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http_ss) [2] session
closed
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::handle_server_setup_error, VC_EVENT_NONE]
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241566, highest_delta: 0, cluster: 1352241566
[Nov 6 23:39:26.618] Server {0x7fc78400f840} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1352241566
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 0
HTTP/0.9 0
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response not valid
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_trans) [3] failed to
connect [6] to 160.45.251.2
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_trans)
[retry_server_connection_not_open] attempts now: 4, max: 6
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] Error. Retrying...
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: ORIGIN_SERVER_OPEN -> ORIGIN_SERVER_OPEN
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside do_http_server_open
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http) [0] open connection
to svn.apache.org: 160.45.251.2:80
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http) calling
netProcessor.connect_re
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside state_http_server_open
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Nov 6 23:39:26.619] Server {0x7fc78400f840} DEBUG: (http_ss) [3] session
born, netvc 0x7fc774015b00
[Nov 6 23:39:26.671] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:39:26.671] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_server_response_header, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_ss) [3] session
closed
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::handle_server_setup_error, VC_EVENT_NONE]
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241597, highest_delta: 0, cluster: 1352241597
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1352241597
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 0
HTTP/0.9 0
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response not valid
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans) [4] failed to
connect [6] to 160.45.251.2
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans)
[retry_server_connection_not_open] attempts now: 5, max: 6
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] Error. Retrying...
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: ORIGIN_SERVER_OPEN -> ORIGIN_SERVER_OPEN
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside do_http_server_open
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http) [0] open connection
to svn.apache.org: 160.45.251.2:80
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Nov 6 23:39:57.584] Server {0x7fc78400f840} DEBUG: (http) calling
netProcessor.connect_re
[Nov 6 23:39:57.585] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Nov 6 23:39:57.585] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside state_http_server_open
[Nov 6 23:39:57.585] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Nov 6 23:39:57.585] Server {0x7fc78400f840} DEBUG: (http_ss) [4] session
born, netvc 0x7fc774015dc0
[Nov 6 23:39:58.146] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:39:58.146] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:28.540] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_server_response_header, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_ss) [4] session
closed
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::handle_server_setup_error, VC_EVENT_NONE]
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241628, highest_delta: 0, cluster: 1352241628
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1352241628
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 0
HTTP/0.9 0
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response not valid
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans) [5] failed to
connect [6] to 160.45.251.2
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans)
[retry_server_connection_not_open] attempts now: 6, max: 6
[Nov 6 23:40:28.541] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] Error. Retrying...
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: ORIGIN_SERVER_OPEN -> ORIGIN_SERVER_OPEN
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside do_http_server_open
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http) [0] open connection
to svn.apache.org: 160.45.251.2:80
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http) calling
netProcessor.connect_re
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http_track) entered
inside state_http_server_open
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Nov 6 23:40:28.542] Server {0x7fc78400f840} DEBUG: (http_ss) [5] session
born, netvc 0x7fc774015b00
[Nov 6 23:40:28.885] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:28.886] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_send_server_request_header, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::state_read_server_response_header, VC_EVENT_INACTIVITY_TIMEOUT]
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_ss) [5] session
closed
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::handle_server_setup_error, VC_EVENT_NONE]
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_trans)
[HttpTransact::HandleResponse]
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response received
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241659, highest_delta: 0, cluster: 1352241659
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_trans)
[HandleResponse] response_received_time: 1352241659
+++++++++ Incoming O.S. Response +++++++++
-- State Machine Id: 0
HTTP/0.9 0
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::HandleResponse] Response not valid
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] (hrfs)
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_response_from_server] Error. No more retries.
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_trans)
[handle_server_connection_not_open] (hscno)
[Nov 6 23:40:59.495] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpTransact::handle_server_connection_not_open]
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241659, highest_delta: 0, cluster: 1352241659
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http) [0] hostdb update
marking IP: 160.45.251.2:80 as down
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http) server info =
160.45.251.2:80
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http_trans) [WUTS code
generation] Hit/Miss: 49, Log: 112, Hier: 106, Status: 800
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http_trans) Adding
Server: ATS/3.2.3
+++++++++ Proxy's Response 2 +++++++++
-- State Machine Id: 0
HTTP/1.1 504 Connection Timed Out
Date: Tue, 06 Nov 2012 22:40:59 GMT
Connection: keep-alive
Via: http/1.1 tynix (ApacheTrafficServer/3.2.3 [uSc sEf p eT:tMc i p sF])
Server: ATS/3.2.3
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http) [0] State
Transition: ORIGIN_SERVER_OPEN -> PROXY_SEND_ERROR_CACHE_NOOP
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http_tunnel) [0] adding
producer 'internal msg'
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http_tunnel) [0] adding
consumer 'user agent'
[Nov 6 23:40:59.496] Server {0x7fc78400f840} DEBUG: (http_tunnel) tunnel_run
started, p_arg is NULL
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_cs)
tcp_init_cwnd_set 0
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_cs) desired TCP
congestion window is 0
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_tunnel) [0]
consumer_handler [user agent VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::tunnel_handler_ua, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_cs) [0] session
released by sm [0]
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_cs) [0] data already
in buffer, starting new transaction
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_cs) [0] using accept
inactivity timeout [120 seconds]
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http_cs) [0] Starting
transaction 2 using sm [1]
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http) [1]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Nov 6 23:40:59.497] Server {0x7fc78400f840} DEBUG: (http) [0]
[HttpSM::main_handler, HTTP_TUNNEL_EVENT_DONE]
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http) [0]
[&HttpSM::tunnel_handler, HTTP_TUNNEL_EVENT_DONE]
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpStateMachineGet::update_stats] Logging transaction
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http_trans) Adding new
large stat block
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http) [0] dellocating sm
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http) [1]
[HttpSM::main_handler, VC_EVENT_EOS]
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http) [1]
[&HttpSM::state_read_client_request_header, VC_EVENT_EOS]
[Nov 6 23:40:59.498] Server {0x7fc78400f840} DEBUG: (http) [1] error parsing
client request header
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_trans)
[BadRequest]parser marked request bad
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_trans)
[ink_cluster_time] local: 1352241659, highest_delta: 0, cluster: 1352241659
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_trans) [WUTS code
generation] Hit/Miss: 98, Log: 118, Hier: 49, Status: 806
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_trans) Adding
Server: ATS/3.2.3
+++++++++ Proxy's Response 2 +++++++++
-- State Machine Id: 1
HTTP/1.1 400 Invalid HTTP Request
Date: Tue, 06 Nov 2012 22:40:59 GMT
Connection: close
Via: http/1.1 tynix (ApacheTrafficServer/3.2.3 [uEc s f p eH:t c i p s ])
Server: ATS/3.2.3
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_trans) Next action
PROXY_SEND_ERROR_CACHE_NOOP; NULL
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http) [1] State
Transition: STATE_UNDEFINED -> PROXY_SEND_ERROR_CACHE_NOOP
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_tunnel) [1] adding
producer 'internal msg'
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_tunnel) [1] adding
consumer 'user agent'
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_tunnel) tunnel_run
started, p_arg is NULL
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_cs)
tcp_init_cwnd_set 1
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_tunnel) [1]
consumer_handler [user agent VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http) [1]
[&HttpSM::tunnel_handler_ua, VC_EVENT_WRITE_COMPLETE]
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_cs) [0] session
closed
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_cs) [0] session
destroy
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http) [1]
[HttpSM::main_handler, HTTP_TUNNEL_EVENT_DONE]
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http) [1]
[&HttpSM::tunnel_handler, HTTP_TUNNEL_EVENT_DONE]
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http_seq)
[HttpStateMachineGet::update_stats] Logging transaction
[Nov 6 23:40:59.499] Server {0x7fc78400f840} DEBUG: (http) [1] dellocating sm
{noformat}
A number of things can be observed:
The OPTIONS body is discarded, while the {{Content-Length}} is kept in tact.
That seems rather odd behaviour to begin with.
Next, the svn.apache.org server almost immediately answers with a {{400}}, but
we don't pass that on to the client.
Instead we loop a number of times, then send the client a {{504}}. This
behaviour, again, seems rather weird.
> Subversion (1.7) with serf fails with ATS in forward and reverse proxy mode
> ---------------------------------------------------------------------------
>
> Key: TS-871
> URL: https://issues.apache.org/jira/browse/TS-871
> Project: Traffic Server
> Issue Type: Bug
> Components: HTTP
> Affects Versions: 3.0.0
> Reporter: Igor Galić
> Assignee: Leif Hedstrom
> Fix For: 3.3.1
>
> Attachments: ats_Thttp.debug.notime.txt, ats_Thttp.debug.txt,
> revats_Thttp.debug.notime.txt, revats_Thttp.debug.txt, serf_proxy.cap,
> serf_revproxy.cap, stats.diff, TS-871.diff
>
>
> When accessing a remote subversion repository via http or https with svn 1.7,
> it will currently timeout:
> {noformat}
> igalic@tynix ~/src/asf % svn co
> http://svn.apache.org/repos/asf/trafficserver/plugins/stats_over_http/
> svn: E020014: Unable to connect to a repository at URL
> 'http://svn.apache.org/repos/asf/trafficserver/plugins/stats_over_http'
> svn: E020014: Unspecified error message: 504 Connection Timed Out
> 1 igalic@tynix ~/src/asf %
> {noformat}
> I have started traffic_server -Thttp and captured the output, which I'm
> attaching.
> There's also a capture from the network.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
