Major Description
When the incoming requests map to the default remap rule like below, the unmapped url path, hostname etc are not initialized correctly in the Logging module and result in crashes, if custom logging is enabled on those fields.
*map / http://abc.com*
(gdb) bt #0 0x0000003b72a8992b in memcpy () from /lib64/libc.so.6 #1 0x0000000000648c7e in LogAccess::marshal_mem (dest=0x2b94041d6e60 "/", source=0x2b93e8046869 "/", actual_len=-2, padded_len=0) at LogAccess.cc:829 #2 0x000000000064b4a3 in LogAccessHttp::marshal_client_req_unmapped_url_path (this=0x2b92b8806750, buf=0x2b94041d6e60 "/") at LogAccessHttp.cc:452 #3 0x0000000000658e4b in LogField::marshal (this=0x2cf3660, lad=0x2b92b8806750, buf=0x2b94041d6e60 "/") at LogField.cc:302 #4 0x000000000065991d in LogFieldList::marshal (this=0x2cf2690, lad=0x2b92b8806750, buf=0x2b94041d6e00 "2nsfor5aiq80k") at LogField.cc:602 #5 0x0000000000667510 in LogObject::log (this=0x2cf25c0, lad=0x2b92b8806750, text_entry=0x0) at LogObject.cc:640 #6 0x0000000000669ad8 in LogObjectManager::log (this=0x2cdd2f8, lad=0x2b92b8806750) at LogObject.cc:1354 #7 0x0000000000645836 in Log::access (lad=0x2b92b8806750) at Log.cc:1145 #8 0x00000000005df896 in HttpSM::update_stats (this=0x2b93b4daad90) at HttpSM.cc:6643 #9 0x00000000005df549 in HttpSM::kill_this (this=0x2b93b4daad90) at HttpSM.cc:6604 #10 0x00000000005d1e95 in HttpSM::main_handler (this=0x2b93b4daad90, event=2301, data=0x2b93b4dab9b8) at HttpSM.cc:2540 #11 0x00000000004f6c68 in Continuation::handleEvent (this=0x2b93b4daad90, event=2301, data=0x2b93b4dab9b8) at ../iocore/eventsystem/I_Continuation.h:146 #12 0x000000000061ac93 in HttpTunnel::main_handler (this=0x2b93b4dab9b8, event=103, data=0x2b93d42db4a8) at HttpTunnel.cc:1537 #13 0x00000000004f6c68 in Continuation::handleEvent (this=0x2b93b4dab9b8, event=103, data=0x2b93d42db4a8) at ../iocore/eventsystem/I_Continuation.h:146 #14 0x00000000007388f0 in write_signal_and_update (event=103, vc=0x2b93d42db330) at UnixNetVConnection.cc:171 #15 0x00000000007389ee in write_signal_done (event=103, nh=0x2b92b23b0cb0, vc=0x2b93d42db330) at UnixNetVConnection.cc:198 #16 0x0000000000739901 in write_to_net_io (nh=0x2b92b23b0cb0, vc=0x2b93d42db330, thread=0x2b92b23ad010) at UnixNetVConnection.cc:508 #17 0x00000000007391c7 in write_to_net (nh=0x2b92b23b0cb0, vc=0x2b93d42db330, thread=0x2b92b23ad010) at UnixNetVConnection.cc:370 #18 0x00000000007324de in NetHandler::mainNetEvent (this=0x2b92b23b0cb0, event=5, e=0x29d7db0) at UnixNet.cc:531 #19 0x00000000004f6c68 in Continuation::handleEvent (this=0x2b92b23b0cb0, event=5, data=0x29d7db0) at ../iocore/eventsystem/I_Continuation.h:146 #20 0x0000000000759412 in EThread::process_event (this=0x2b92b23ad010, e=0x29d7db0, calling_code=5) at UnixEThread.cc:145 #21 0x000000000075991c in EThread::execute (this=0x2b92b23ad010) at UnixEThread.cc:269 #22 0x0000000000758990 in spawn_thread_internal (a=0x28a6de0) at Thread.cc:88 #23 0x00002b92b0e499d1 in start_thread () from /lib64/libpthread.so.0 #24 0x0000003b72ae88fd in clone () from /lib64/libc.so.6 (gdb) up #1 0x0000000000648c7e in LogAccess::marshal_mem (dest=0x2b94041d6e60 "/", source=0x2b93e8046869 "/", actual_len=-2, padded_len=0) at LogAccess.cc:829 829 LogAccess.cc: No such file or directory. (gdb) up #2 0x000000000064b4a3 in LogAccessHttp::marshal_client_req_unmapped_url_path (this=0x2b92b8806750, buf=0x2b94041d6e60 "/") at LogAccessHttp.cc:452 452 LogAccessHttp.cc: No such file or directory.
Some gdb info:
(gdb) p m_client_req_unmapped_url_path_len $1 = -2 (gdb) p m_client_req_unmapped_url_path_str $2 = 0x2b93e8046869 "/" (gdb) p *m_client_req_unmapped_url_path_str $3 = 47 '/' (gdb) p m_client_req_unmapped_url_host_len $4 = 34 (gdb) p buf $5 = 0x2b94041d6e60 "/" (gdb) p m_client_req_unmapped_url_host_str $6 = 0x2b93e8046847 "%5B14:11:32%20UTC%202015%20--%3E" (gdb) p m_client_request $7 = (HTTPHdr *) 0x2b93b4dab098 (gdb) p *m_client_request $8 = {<MIMEHdr> = {<HdrHeapSDKHandle> = {m_heap = 0x2b93e00a1c20}, m_mime = 0x2b93e00a1cd8}, m_http = 0x2b93e00a1ca8, m_url_cached = {<HdrHeapSDKHandle> = {m_heap = 0x2b93e00a1c20}, m_url_impl = 0x2b93e00a1f28}, m_host_mime = 0x0, m_host_length = 28, m_port = 80, m_target_cached = true, m_target_in_url = true, m_port_in_header = false, static USE_HDR_HEAP_MAGIC = 0x1} (gdb) p m_client_request.m_url_impl There is no member or method named m_url_impl. (gdb) p m_client_request.m_url_cached.m_url_impl $9 = (URLImpl *) 0x2b93e00a1f28 (gdb) p *m_client_request.m_url_cached.m_url_impl $10 = {<HdrHeapObjImpl> = {m_type = 2, m_length = 112, m_obj_flags = 0}, m_len_scheme = 4, m_len_user = 0, m_len_password = 0, m_len_host = 28, m_len_port = 0, m_len_path = 0, m_len_params = 0, m_len_query = 0, m_len_fragment = 0, m_len_printed_string = 36, m_ptr_scheme = 0x2b94841cf74a "httpY-RID2nsfor5aiq80khttp://abc.com/", m_ptr_user = 0x0, m_ptr_password = 0x0, m_ptr_host = 0x2b94841cf72e "abc.comhttpXXXXXXXXXXXXXkhttp://abc.com/", m_ptr_port = 0x0, m_ptr_path = 0x0, m_ptr_params = 0x0, m_ptr_query = 0x0, m_ptr_fragment = 0x0, m_ptr_printed_string = 0x2b94841cf760 "http://abc.com/", m_scheme_wks_idx = 97, m_port = 0, m_url_type = 1 '\001', m_type_code = 0 '\000', m_clean = 1} (gdb) p m_client_request.m_http $11 = (HTTPHdrImpl *) 0x2b93e00a1ca8 (gdb) p *m_client_request.m_http $12 = {<HdrHeapObjImpl> = {m_type = 3, m_length = 48, m_obj_flags = 0}, m_polarity = HTTP_TYPE_REQUEST, m_version = 9, u = {req = {m_url_impl = 0x2b93e00a1f28, m_ptr_method = 0x2b93f822e7ec "14 14:11:32 UTC 2015 -->\n", m_len_method = 2, m_method_wks_idx = -1}, resp = {m_ptr_reason = 0x2b93e00a1f28 "\002p", m_len_reason = 59372, m_status = -2014}}, m_fields_impl = 0x2b93e00a1cd8} (gdb) p *m_client_request.m_http.u.req.m_ptr_method $13 = 49 '1' (gdb) p m_client_request.m_http.u.req.m_ptr_method $14 = 0x2b93f822e7ec "14 14:11:32 UTC 2015 -->\n" (gdb) p m_client_req_url_str $15 = 0x2b93e8046819 "http://abc.com/" (gdb) p m_client_req_url_canon_str $16 = 0x2b93e8046819 "http://abc.com/" (gdb) p m_client_req_url_len $17 = 36 (gdb) p m_client_req_unmapped_url_canon_str $18 = 0x2b93e8046840 "http://%5B14:11:32%20UTC%202015%20--%3E" (gdb) p m_client_req_unmapped_url_host_str $19 = 0x2b93e8046847 "%5B14:11:32%20UTC%202015%20--%3E" (gdb) p m_client_req_url_path_str $20 = 0x0 (gdb) p m_client_req_url_path_len $21 = 0
Below patch should address this:
diff --git a/proxy/logging/LogAccessHttp.cc b/proxy/logging/LogAccessHttp.cc index 573c1f4..e0edffd 100644 --- a/proxy/logging/LogAccessHttp.cc +++ b/proxy/logging/LogAccessHttp.cc @@ -419,7 +419,7 @@ LogAccessHttp::marshal_client_req_unmapped_url_canon(char *buf) int len = INK_MIN_ALIGN; validate_unmapped_url(); - if (0 == m_client_req_unmapped_url_canon_len) { + if (0 >= m_client_req_unmapped_url_canon_len) { // If the unmapped URL isn't populated, we'll fall back to the original // client URL. This helps for example server intercepts to continue to // log the requests, even when there is no remap rule for it. @@ -445,7 +445,7 @@ LogAccessHttp::marshal_client_req_unmapped_url_path(char *buf) validate_unmapped_url(); validate_unmapped_url_path(); - if (0 == m_client_req_unmapped_url_path_len) { + if (0 >= m_client_req_unmapped_url_path_len) { len = marshal_client_req_url_path(buf); } else { len = round_strlen(m_client_req_unmapped_url_path_len + 1); // +1 for eos