[TS-2044] Logging client run into "LOG_COLL_FLOW_DENY" status infinitely

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 3.3.5
• Component/s: Logging
• Assignee: James Peach
• Reporter: Yunkai Zhang
• Created: 18/Jul/13 07:24
• Updated: 09/Aug/13 14:34
• Resolved: 22/Jul/13 16:58

Description

Logging client run into "LOG_COLL_FLOW_DENY" status infinitely in our product enviroment, let's see the following debug info:

[Jul 17 16:35:50.832] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.854] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.854] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.866] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.866] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.881] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.881] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.892] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.893] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.909] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.909] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.929] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.929] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.951] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.951] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.958] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.958] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.965] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.965] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.979] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.979] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.986] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.986] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:50.992] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:50.992] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:51.000] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:51.000] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
[Jul 17 16:35:51.010] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send
[Jul 17 16:35:51.010] Server {0x2b6ee0208700} DEBUG: (log-coll) [0]client::send - m_flow = DENY; rejecting
...

Here was some gdb output:

Breakpoint 1, LogCollationClientSM::send (this=0x2b704c002d10, log_buffer=0x2b704c002c10) at LogCollationClientSM.cc:157
157     {
(gdb) p *this
$6 = {<LogCollationBase> = {<No data fields>}, <Continuation> = {<force_VFPT_to_top> = {_vptr.force_VFPT_to_top = 0x6e2650},
    handler = (int (Continuation::*)(Continuation *, int,
    void *)) 0x5bb4e0 <LogCollationClientSM::client_handler(int, void*)>, mutex = {m_ptr = 0x2b7050000000},
    link = {<SLink<Continuation>> = {next = 0x0}, prev = 0x0}}, m_client_state = LogCollationClientSM::LOG_COLL_CLIENT_IDLE,
  m_host_vc = 0x2b71a2533320, m_host_vio = 0x2b71a2533490, m_auth_buffer = 0x2b6f10b7c000, m_auth_reader = 0x2b6f10b7c018,
  m_send_buffer = 0x2b6f10b7fde0, m_send_reader = 0x2b6f10b7fdf8, m_pending_action = 0x0, m_pending_event = 0x0,
  m_abort_vio = 0x2b71a2533428, m_abort_buffer = 0x2b6f10b7fed0, m_buffer_send_list = 0x2b704c002e30,
  m_buffer_in_iocore = 0x0, m_flow = LogCollationClientSM::LOG_COLL_FLOW_DENY, m_log_host = 0x17806e0, static ID = 1,
  m_id = 0}
(gdb) detach
Detaching from program: /usr/bin/traffic_server, process 6644