You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@trafficserver.apache.org by Esmq <es...@163.com> on 2013/04/11 12:14:04 UTC
plz someone explain those confusing log ?
i found those log in my access log and dont' known what it mean...
am i under attack ?! for i see ts coredump for many times when these log appear
my logformat is: <Format = "%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<cquuc> %<caun> %<phr>/%<pqsn> %<psct>"/>
and i using trafficserver-3.2.0
##############################################
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
49.196 7022907777621061481 *Not IP address [0]* ERROR_UNKNOWN(1365674599)/652835814623 0 #003 #002 3 INVALID_CODE(200)/?017 GET
1954047348.196 721555296875 *Not IP address [0]* ERROR_UNKNOWN(0)/000 46 ?鍲 GET INVALID_CODE(8155789378232546408)/pp.n.test.com/include/js/common.js?qQu -
795766633.196 824634530385 *Not IP address [0]* ERROR_UNKNOWN(2)/000 51 ?s#010 GET INVALID_CODE(7002867873625699432)/pp.n.test.com/get_cdkey/wh_officialsite_cdkey_20121016.html -
##############################################
Re:Re:Re:Re: plz someone explain those confusing log ?
Posted by Esmq <es...@163.com>.
now i confirm that ts is crash REALLY for LOGGING.
when i set ***proxy.config.log.logging_enabled*** to 0 for some of my servers (no logging at all),
ts running well, no crash happend, and at the mean time, these servers that setting logging on crashed for several times.
i believed that come special requests (probably not http standard request), cause the LOGGING to fail and finally crash the ts~
i just dont't known what these suspected requests look like, and how to baned those requests.
thanks
At 2013-04-11 20:48:14,Esmq <es...@163.com> wrote:
it seems that ts crash always related to logging, as mention at https://issues.apache.org/jira/browse/TS-1330
and some special request reproduct the crash easily
At 2013-04-11 19:27:39,Esmq <es...@163.com> wrote:
hi, ym
following is the log found in traffic.out
########################################################################################################################################
[Apr 10 22:36:45.190] Server {0x44faab90} NOTE: Traffic Server is skipping the current log entry because its size exceeds the maximum line (entry) size for an ascii l
og buffer
[Apr 10 22:49:44.566] Server {0x44faab90} NOTE: Traffic Server is skipping the current log entry because its size exceeds the maximum line (entry) size for an ascii l
og buffer
NOTE: Traffic Server received Sig 11: Segmentation fault
/usr/local/trafficserver-3.2.0/bin/traffic_server - STACK TRACE:
[0x4001c400]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN17LogBufferIterator4nextEv+0x2a)[0x81d180a]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7LogFile22write_ascii_logbuffer3EP15LogBufferHeaderPc+0xec)[0x81e220c]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7LogFile5writeEP9LogBuffer+0x93)[0x81e4083]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN16LogBufferManager13flush_buffersEP13LogBufferSink+0xbe)[0x81ec2ee]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN16LogObjectManager13flush_buffersEv+0x2c)[0x81eca8c]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN3Log17flush_thread_mainEPv+0x54)[0x81d4264]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN24LoggingFlushContinuation9mainEventEiPv+0xd)[0x81d690d]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7EThread7executeEv+0xcee)[0x82e277e]
/usr/local/trafficserver-3.2.0/bin/traffic_server[0x82df894]
/lib/i686/cmov/libpthread.so.0[0x4005f4c0]
/lib/i686/cmov/libc.so.6(clone+0x5e)[0x4056b84e]
[Apr 10 22:51:42.687] Manager {0xb71946c0} FATAL: [LocalManager::pollMgmtProcessServer] Error in read (errno: 104)
[Apr 10 22:51:42.758] Manager {0xb71946c0} FATAL: (last system error 104: Connection reset by peer)
[Apr 10 22:51:42.758] Manager {0xb71946c0} NOTE: [LocalManager::mgmtShutdown] Executing shutdown request.
[Apr 10 22:51:42.758] Manager {0xb71946c0} NOTE: [LocalManager::processShutdown] Executing process shutdown request.
[Apr 10 22:51:42.764] Manager {0xb71946c0} ERROR: [LocalManager::sendMgmtMsgToProcesses] Error writing message
[Apr 10 22:51:42.764] Manager {0xb71946c0} ERROR: (last system error 32: Broken pipe)
[E. Mgmt] log ==> [TrafficManager] using root directory '/usr/local/trafficserver-3.2.0/'
[Apr 10 22:51:43.094] {0xb713a6c0} STATUS: opened /usr/local/trafficserver-3.2.0/var/log/trafficserver/manager.log
[Apr 10 22:51:43.145] {0xb713a6c0} NOTE: updated diags config
[Apr 10 22:51:43.188] Manager {0xb713a6c0} NOTE: [ClusterCom::ClusterCom] Node running on OS: 'Linux' Release: '2.6.26-2-686'
[Apr 10 22:51:43.429] Manager {0xb713a6c0} NOTE: [LocalManager::listenForProxy] Listening on port: 80
[Apr 10 22:51:43.429] Manager {0xb713a6c0} NOTE: [TrafficManager] Setup complete
[Apr 10 22:51:44.536] Manager {0xb713a6c0} NOTE: [LocalManager::startProxy] Launching ts process
[TrafficServer] using root directory '/usr/local/trafficserver-3.2.0/'
[Apr 10 22:51:44.556] Manager {0xb713a6c0} NOTE: [LocalManager::pollMgmtProcessServer] New process connecting fd '9'
[Apr 10 22:51:44.557] Manager {0xb713a6c0} NOTE: [Alarms::signalAlarm] Server Process born
[Apr 10 22:51:45.586] {0x405e7140} STATUS: opened /usr/local/trafficserver-3.2.0/var/log/trafficserver/diags.log
[Apr 10 22:51:45.593] {0x405e7140} NOTE: updated diags config
[Apr 10 22:51:45.625] Server {0x405e7140} NOTE: cache clustering disabled
[Apr 10 22:51:45.713] Server {0x405e7140} NOTE: cache clustering disabled
[Apr 10 22:51:45.753] Server {0x405e7140} NOTE: logging initialized[15], logging_mode = 3
[Apr 10 22:51:46.156] Server {0x405e7140} NOTE: traffic server running
[Apr 10 22:51:46.547] Server {0x4103ab90} NOTE: cache enabled
At 2013-04-11 19:17:26,"Yongming Zhao" <mi...@gmail.com> wrote:
well, can you show us some of the core stack trace log? and all the crash should go directly to Jira, it worth a look, don't even worry about if it is duplicated, we REALLY care all of the crashes.
thanks
在 2013-4-11，下午6:14，Esmq <es...@163.com> 写道：
i found those log in my access log and dont' known what it mean...
am i under attack ?! for i see ts coredump for many times when these log appear
my logformat is: <Format = "%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<cquuc> %<caun> %<phr>/%<pqsn> %<psct>"/>
and i using trafficserver-3.2.0
##############################################
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
49.196 7022907777621061481 *Not IP address [0]* ERROR_UNKNOWN(1365674599)/652835814623 0 #003 #002 3 INVALID_CODE(200)/?017 GET
1954047348.196 721555296875 *Not IP address [0]* ERROR_UNKNOWN(0)/000 46 ?鍲 GET INVALID_CODE(8155789378232546408)/pp.n.test.com/include/js/common.js?qQu -
795766633.196 824634530385 *Not IP address [0]* ERROR_UNKNOWN(2)/000 51 ?s#010 GET INVALID_CODE(7002867873625699432)/pp.n.test.com/get_cdkey/wh_officialsite_cdkey_20121016.html -
##############################################
Re:Re:Re: plz someone explain those confusing log ?
Posted by Esmq <es...@163.com>.
it seems that ts crash always related to logging, as mention at https://issues.apache.org/jira/browse/TS-1330
and some special request reproduct the crash easily
At 2013-04-11 19:27:39,Esmq <es...@163.com> wrote:
hi, ym
following is the log found in traffic.out
########################################################################################################################################
[Apr 10 22:36:45.190] Server {0x44faab90} NOTE: Traffic Server is skipping the current log entry because its size exceeds the maximum line (entry) size for an ascii l
og buffer
[Apr 10 22:49:44.566] Server {0x44faab90} NOTE: Traffic Server is skipping the current log entry because its size exceeds the maximum line (entry) size for an ascii l
og buffer
NOTE: Traffic Server received Sig 11: Segmentation fault
/usr/local/trafficserver-3.2.0/bin/traffic_server - STACK TRACE:
[0x4001c400]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN17LogBufferIterator4nextEv+0x2a)[0x81d180a]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7LogFile22write_ascii_logbuffer3EP15LogBufferHeaderPc+0xec)[0x81e220c]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7LogFile5writeEP9LogBuffer+0x93)[0x81e4083]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN16LogBufferManager13flush_buffersEP13LogBufferSink+0xbe)[0x81ec2ee]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN16LogObjectManager13flush_buffersEv+0x2c)[0x81eca8c]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN3Log17flush_thread_mainEPv+0x54)[0x81d4264]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN24LoggingFlushContinuation9mainEventEiPv+0xd)[0x81d690d]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7EThread7executeEv+0xcee)[0x82e277e]
/usr/local/trafficserver-3.2.0/bin/traffic_server[0x82df894]
/lib/i686/cmov/libpthread.so.0[0x4005f4c0]
/lib/i686/cmov/libc.so.6(clone+0x5e)[0x4056b84e]
[Apr 10 22:51:42.687] Manager {0xb71946c0} FATAL: [LocalManager::pollMgmtProcessServer] Error in read (errno: 104)
[Apr 10 22:51:42.758] Manager {0xb71946c0} FATAL: (last system error 104: Connection reset by peer)
[Apr 10 22:51:42.758] Manager {0xb71946c0} NOTE: [LocalManager::mgmtShutdown] Executing shutdown request.
[Apr 10 22:51:42.758] Manager {0xb71946c0} NOTE: [LocalManager::processShutdown] Executing process shutdown request.
[Apr 10 22:51:42.764] Manager {0xb71946c0} ERROR: [LocalManager::sendMgmtMsgToProcesses] Error writing message
[Apr 10 22:51:42.764] Manager {0xb71946c0} ERROR: (last system error 32: Broken pipe)
[E. Mgmt] log ==> [TrafficManager] using root directory '/usr/local/trafficserver-3.2.0/'
[Apr 10 22:51:43.094] {0xb713a6c0} STATUS: opened /usr/local/trafficserver-3.2.0/var/log/trafficserver/manager.log
[Apr 10 22:51:43.145] {0xb713a6c0} NOTE: updated diags config
[Apr 10 22:51:43.188] Manager {0xb713a6c0} NOTE: [ClusterCom::ClusterCom] Node running on OS: 'Linux' Release: '2.6.26-2-686'
[Apr 10 22:51:43.429] Manager {0xb713a6c0} NOTE: [LocalManager::listenForProxy] Listening on port: 80
[Apr 10 22:51:43.429] Manager {0xb713a6c0} NOTE: [TrafficManager] Setup complete
[Apr 10 22:51:44.536] Manager {0xb713a6c0} NOTE: [LocalManager::startProxy] Launching ts process
[TrafficServer] using root directory '/usr/local/trafficserver-3.2.0/'
[Apr 10 22:51:44.556] Manager {0xb713a6c0} NOTE: [LocalManager::pollMgmtProcessServer] New process connecting fd '9'
[Apr 10 22:51:44.557] Manager {0xb713a6c0} NOTE: [Alarms::signalAlarm] Server Process born
[Apr 10 22:51:45.586] {0x405e7140} STATUS: opened /usr/local/trafficserver-3.2.0/var/log/trafficserver/diags.log
[Apr 10 22:51:45.593] {0x405e7140} NOTE: updated diags config
[Apr 10 22:51:45.625] Server {0x405e7140} NOTE: cache clustering disabled
[Apr 10 22:51:45.713] Server {0x405e7140} NOTE: cache clustering disabled
[Apr 10 22:51:45.753] Server {0x405e7140} NOTE: logging initialized[15], logging_mode = 3
[Apr 10 22:51:46.156] Server {0x405e7140} NOTE: traffic server running
[Apr 10 22:51:46.547] Server {0x4103ab90} NOTE: cache enabled
At 2013-04-11 19:17:26,"Yongming Zhao" <mi...@gmail.com> wrote:
well, can you show us some of the core stack trace log? and all the crash should go directly to Jira, it worth a look, don't even worry about if it is duplicated, we REALLY care all of the crashes.
thanks
在 2013-4-11，下午6:14，Esmq <es...@163.com> 写道：
i found those log in my access log and dont' known what it mean...
am i under attack ?! for i see ts coredump for many times when these log appear
my logformat is: <Format = "%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<cquuc> %<caun> %<phr>/%<pqsn> %<psct>"/>
and i using trafficserver-3.2.0
##############################################
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
49.196 7022907777621061481 *Not IP address [0]* ERROR_UNKNOWN(1365674599)/652835814623 0 #003 #002 3 INVALID_CODE(200)/?017 GET
1954047348.196 721555296875 *Not IP address [0]* ERROR_UNKNOWN(0)/000 46 ?鍲 GET INVALID_CODE(8155789378232546408)/pp.n.test.com/include/js/common.js?qQu -
795766633.196 824634530385 *Not IP address [0]* ERROR_UNKNOWN(2)/000 51 ?s#010 GET INVALID_CODE(7002867873625699432)/pp.n.test.com/get_cdkey/wh_officialsite_cdkey_20121016.html -
##############################################
Re:Re: plz someone explain those confusing log ?
Posted by Esmq <es...@163.com>.
hi, ym
following is the log found in traffic.out
########################################################################################################################################
[Apr 10 22:36:45.190] Server {0x44faab90} NOTE: Traffic Server is skipping the current log entry because its size exceeds the maximum line (entry) size for an ascii l
og buffer
[Apr 10 22:49:44.566] Server {0x44faab90} NOTE: Traffic Server is skipping the current log entry because its size exceeds the maximum line (entry) size for an ascii l
og buffer
NOTE: Traffic Server received Sig 11: Segmentation fault
/usr/local/trafficserver-3.2.0/bin/traffic_server - STACK TRACE:
[0x4001c400]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN17LogBufferIterator4nextEv+0x2a)[0x81d180a]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7LogFile22write_ascii_logbuffer3EP15LogBufferHeaderPc+0xec)[0x81e220c]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7LogFile5writeEP9LogBuffer+0x93)[0x81e4083]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN16LogBufferManager13flush_buffersEP13LogBufferSink+0xbe)[0x81ec2ee]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN16LogObjectManager13flush_buffersEv+0x2c)[0x81eca8c]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN3Log17flush_thread_mainEPv+0x54)[0x81d4264]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN24LoggingFlushContinuation9mainEventEiPv+0xd)[0x81d690d]
/usr/local/trafficserver-3.2.0/bin/traffic_server(_ZN7EThread7executeEv+0xcee)[0x82e277e]
/usr/local/trafficserver-3.2.0/bin/traffic_server[0x82df894]
/lib/i686/cmov/libpthread.so.0[0x4005f4c0]
/lib/i686/cmov/libc.so.6(clone+0x5e)[0x4056b84e]
[Apr 10 22:51:42.687] Manager {0xb71946c0} FATAL: [LocalManager::pollMgmtProcessServer] Error in read (errno: 104)
[Apr 10 22:51:42.758] Manager {0xb71946c0} FATAL: (last system error 104: Connection reset by peer)
[Apr 10 22:51:42.758] Manager {0xb71946c0} NOTE: [LocalManager::mgmtShutdown] Executing shutdown request.
[Apr 10 22:51:42.758] Manager {0xb71946c0} NOTE: [LocalManager::processShutdown] Executing process shutdown request.
[Apr 10 22:51:42.764] Manager {0xb71946c0} ERROR: [LocalManager::sendMgmtMsgToProcesses] Error writing message
[Apr 10 22:51:42.764] Manager {0xb71946c0} ERROR: (last system error 32: Broken pipe)
[E. Mgmt] log ==> [TrafficManager] using root directory '/usr/local/trafficserver-3.2.0/'
[Apr 10 22:51:43.094] {0xb713a6c0} STATUS: opened /usr/local/trafficserver-3.2.0/var/log/trafficserver/manager.log
[Apr 10 22:51:43.145] {0xb713a6c0} NOTE: updated diags config
[Apr 10 22:51:43.188] Manager {0xb713a6c0} NOTE: [ClusterCom::ClusterCom] Node running on OS: 'Linux' Release: '2.6.26-2-686'
[Apr 10 22:51:43.429] Manager {0xb713a6c0} NOTE: [LocalManager::listenForProxy] Listening on port: 80
[Apr 10 22:51:43.429] Manager {0xb713a6c0} NOTE: [TrafficManager] Setup complete
[Apr 10 22:51:44.536] Manager {0xb713a6c0} NOTE: [LocalManager::startProxy] Launching ts process
[TrafficServer] using root directory '/usr/local/trafficserver-3.2.0/'
[Apr 10 22:51:44.556] Manager {0xb713a6c0} NOTE: [LocalManager::pollMgmtProcessServer] New process connecting fd '9'
[Apr 10 22:51:44.557] Manager {0xb713a6c0} NOTE: [Alarms::signalAlarm] Server Process born
[Apr 10 22:51:45.586] {0x405e7140} STATUS: opened /usr/local/trafficserver-3.2.0/var/log/trafficserver/diags.log
[Apr 10 22:51:45.593] {0x405e7140} NOTE: updated diags config
[Apr 10 22:51:45.625] Server {0x405e7140} NOTE: cache clustering disabled
[Apr 10 22:51:45.713] Server {0x405e7140} NOTE: cache clustering disabled
[Apr 10 22:51:45.753] Server {0x405e7140} NOTE: logging initialized[15], logging_mode = 3
[Apr 10 22:51:46.156] Server {0x405e7140} NOTE: traffic server running
[Apr 10 22:51:46.547] Server {0x4103ab90} NOTE: cache enabled
At 2013-04-11 19:17:26,"Yongming Zhao" <mi...@gmail.com> wrote:
well, can you show us some of the core stack trace log? and all the crash should go directly to Jira, it worth a look, don't even worry about if it is duplicated, we REALLY care all of the crashes.
thanks
在 2013-4-11，下午6:14，Esmq <es...@163.com> 写道：
i found those log in my access log and dont' known what it mean...
am i under attack ?! for i see ts coredump for many times when these log appear
my logformat is: <Format = "%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<cquuc> %<caun> %<phr>/%<pqsn> %<psct>"/>
and i using trafficserver-3.2.0
##############################################
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
49.196 7022907777621061481 *Not IP address [0]* ERROR_UNKNOWN(1365674599)/652835814623 0 #003 #002 3 INVALID_CODE(200)/?017 GET
1954047348.196 721555296875 *Not IP address [0]* ERROR_UNKNOWN(0)/000 46 ?鍲 GET INVALID_CODE(8155789378232546408)/pp.n.test.com/include/js/common.js?qQu -
795766633.196 824634530385 *Not IP address [0]* ERROR_UNKNOWN(2)/000 51 ?s#010 GET INVALID_CODE(7002867873625699432)/pp.n.test.com/get_cdkey/wh_officialsite_cdkey_20121016.html -
##############################################
Re: plz someone explain those confusing log ?
Posted by Yongming Zhao <mi...@gmail.com>.
well, can you show us some of the core stack trace log? and all the crash should go directly to Jira, it worth a look, don't even worry about if it is duplicated, we REALLY care all of the crashes.
thanks
在 2013-4-11，下午6:14，Esmq <es...@163.com> 写道：
> i found those log in my access log and dont' known what it mean...
>
> am i under attack ?! for i see ts coredump for many times when these log appear
>
> my logformat is: <Format = "%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<cquuc> %<caun> %<phr>/%<pqsn> %<psct>"/>
>
> and i using trafficserver-3.2.0
>
> ##############################################
> 0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
> 0.000 0 *Not IP address [0]* ERROR_UNKNOWN(0)/000 0 INVALID_CODE(0)/
> 49.196 7022907777621061481 *Not IP address [0]* ERROR_UNKNOWN(1365674599)/652835814623 0 #003 #002 3 INVALID_CODE(200)/?017 GET
> 1954047348.196 721555296875 *Not IP address [0]* ERROR_UNKNOWN(0)/000 46 ?鍲 GET INVALID_CODE(8155789378232546408)/pp.n.test.com/include/js/common.js?qQu -
> 795766633.196 824634530385 *Not IP address [0]* ERROR_UNKNOWN(2)/000 51 ?s#010 GET INVALID_CODE(7002867873625699432)/pp.n.test.com/get_cdkey/wh_officialsite_cdkey_20121016.html -
> ##############################################
>
>