You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "David Carlin (JIRA)" <ji...@apache.org> on 2012/09/06 20:33:09 UTC
[jira] [Commented] (TS-1330) Logging related segfault in 3.2.0
[ https://issues.apache.org/jira/browse/TS-1330?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13449909#comment-13449909 ]
David Carlin commented on TS-1330:
----------------------------------
This time I got a core dump!
Here is stack trace from traffic.out - looks same/similar as those above:
[Sep 6 18:00:00.008] Server {0x2ba8bbf7a700} STATUS: The logfile /home/y/logs/trafficserver/error.log was rolled to /home/y/logs/trafficserver/error.log_l12.ycs.a4e.yahoo.com.20120906.15h59m55s-20120906.18h00m00s.old.
[Sep 6 18:00:00.008] Server {0x2ba8bbf7a700} STATUS: The logfile /home/y/logs/trafficserver/squid.blog was rolled to /home/y/logs/trafficserver/squid.blog_l12.ycs.a4e.yahoo.com.20120906.16h00m00s-20120906.18h00m00s.old.
[Sep 6 18:00:52.595] Server {0x2ba894b0a700} NOTE: Traffic Server is skipping the current log entry for squid.blog because its size (26344) exceeds the maximum payload space in a log buffer
[Sep 6 18:02:00.938] Server {0x2ba894c0b700} NOTE: Traffic Server is skipping the current log entry for squid.blog because its size (26336) exceeds the maximum payload space in a log buffer
[Sep 6 18:06:13.471] Server {0x2ba895211700} NOTE: Traffic Server is skipping the current log entry for squid.blog because its size (26496) exceeds the maximum payload space in a log buffer
NOTE: Traffic Server received Sig 11: Segmentation fault
/home/y/bin/traffic_server - STACK TRACE:
/lib64/libpthread.so.0[0x359c60f490]
/home/y/bin/traffic_server(_ZN9LogBuffer14checkout_writeEPmm+0x153)[0x58e083]
/home/y/bin/traffic_server(_ZN9LogObject15_checkout_writeEPmm+0xa8)[0x5a64c8]
/home/y/bin/traffic_server(_ZN9LogObject3logEP9LogAccessPc+0x2f0)[0x5a7e30]
/home/y/bin/traffic_server(_ZN3Log6accessEP9LogAccess+0x146)[0x58f506]
/home/y/bin/traffic_server(_ZN6HttpSM12update_statsEv+0x630)[0x526c50]
/home/y/bin/traffic_server(_ZN6HttpSM9kill_thisEv+0x928)[0x52b548]
/home/y/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0x198)[0x52b868]
/home/y/bin/traffic_server(_ZN10HttpTunnel12main_handlerEiPv+0xde)[0x56c3ee]
/home/y/bin/traffic_server[0x673871]
/home/y/bin/traffic_server(_Z15write_to_net_ioP10NetHandlerP18UnixNetVConnectionP7EThread+0x847)[0x6756e7]
/home/y/bin/traffic_server(_ZN10NetHandler12mainNetEventEiP5Event+0x286)[0x66e076]
/home/y/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0xb4)[0x696ce4]
/home/y/bin/traffic_server(_ZN7EThread7executeEv+0x4c3)[0x697673]
/home/y/bin/traffic_server[0x695cb2]
/lib64/libpthread.so.0[0x359c6077e1]
/lib64/libc.so.6(clone+0x6d)[0x359c2e577d]
Backtrace:
#0 LogBuffer::checkout_write (this=<value optimized out>, write_offset=0x2ba894c0a888, write_size=<value optimized out>) at LogBuffer.cc:289
#1 0x00000000005a64c8 in LogObject::_checkout_write (this=0x346e580, write_offset=0x2ba894c0a888, bytes_needed=488) at LogObject.cc:424
#2 0x00000000005a7e30 in LogObject::log (this=0x346e580, lad=0x2ba894c0aa70, text_entry=0x0) at LogObject.cc:579
#3 0x000000000058f506 in log (lad=0x2ba894c0aa70) at LogObject.h:395
#4 Log::access (lad=0x2ba894c0aa70) at Log.cc:1117
#5 0x0000000000526c50 in HttpSM::update_stats (this=0x2baa37537430) at HttpSM.cc:6340
#6 0x000000000052b548 in HttpSM::kill_this (this=0x2baa37537430) at HttpSM.cc:6301
#7 0x000000000052b868 in HttpSM::main_handler (this=0x2baa37537430, event=2301, data=0x2baa37538fa0) at HttpSM.cc:2460
#8 0x000000000056c3ee in handleEvent (this=0x2baa37538fa0, event=<value optimized out>, data=<value optimized out>)
at ../../iocore/eventsystem/I_Continuation.h:146
#9 HttpTunnel::main_handler (this=0x2baa37538fa0, event=<value optimized out>, data=<value optimized out>) at HttpTunnel.cc:1479
#10 0x0000000000673871 in handleEvent (event=<value optimized out>, nh=0x2ba8940031e8, vc=0x2ba94c2edd40) at ../../iocore/eventsystem/I_Continuation.h:146
#11 write_signal_and_update (event=<value optimized out>, nh=0x2ba8940031e8, vc=0x2ba94c2edd40) at UnixNetVConnection.cc:153
#12 write_signal_done (event=<value optimized out>, nh=0x2ba8940031e8, vc=0x2ba94c2edd40) at UnixNetVConnection.cc:180
#13 0x00000000006756e7 in write_to_net_io (nh=0x2ba8940031e8, vc=0x2ba94c2edd40, thread=<value optimized out>) at UnixNetVConnection.cc:479
#14 0x000000000066e076 in NetHandler::mainNetEvent (this=0x2ba8940031e8, event=<value optimized out>, e=<value optimized out>) at UnixNet.cc:397
#15 0x0000000000696ce4 in handleEvent (this=0x2ba894000010, e=0x3165680, calling_code=5) at I_Continuation.h:146
#16 EThread::process_event (this=0x2ba894000010, e=0x3165680, calling_code=5) at UnixEThread.cc:142
#17 0x0000000000697673 in EThread::execute (this=0x2ba894000010) at UnixEThread.cc:264
#18 0x0000000000695cb2 in spawn_thread_internal (a=0x30fb350) at Thread.cc:88
#19 0x000000359c6077e1 in start_thread () from /lib64/libpthread.so.0
#20 0x000000359c2e577d in clone () from /lib64/libc.so.6
> Logging related segfault in 3.2.0
> ---------------------------------
>
> Key: TS-1330
> URL: https://issues.apache.org/jira/browse/TS-1330
> Project: Traffic Server
> Issue Type: Bug
> Components: Logging
> Affects Versions: 3.2.0
> Environment: ATS 3.2.0 on RHEL 6.2 64-bit
> Reporter: David Carlin
> Fix For: 3.3.1
>
>
> I observed the following crash once on one of our ATS boxes - possibly related to TS-1240
> Jul 2 13:56:56 l2 traffic_server[25853]: {0x2b0a391e1700} ERROR: [SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_SYSCALL, underlying IO error: Connection reset by peer
> Jul 2 13:59:56 l2 kernel: [ET_NET 1][25855]: segfault at c ip 000000000058e083 sp 00002b0a2982b740 error 6
> Jul 2 13:59:56 l2 kernel: [ET_NET 3][25857]: segfault at 84 ip 000000000058e083 sp 00002b0a29a31740 error 6 in traffic_server[400000+340000]
> Jul 2 13:59:56 l2 kernel: in traffic_server[400000+340000]
> Jul 2 14:02:59 l2 traffic_cop[25901]: (test) read timeout [180000 ]
> Jul 2 14:02:59 l2 traffic_cop[25901]: server heartbeat failed [1]
> Jul 2 14:03:08 l2 traffic_manager[25826]: {0x7f3f088607e0} FATAL: [LocalManager::pollMgmtProcessServer] Error in read (errno: 104)
> Jul 2 14:03:09 l2 traffic_manager[25826]: {0x7f3f088607e0} FATAL: (last system error 104: Connection reset by peer)
> Jul 2 14:03:09 l2 traffic_cop[25901]: cannot find traffic_server [1]
> Jul 2 14:03:09 l2 traffic_manager[25826]: {0x7f3f088607e0} ERROR: [LocalManager::sendMgmtMsgToProcesses] Error writing message
> Jul 2 14:03:09 l2 traffic_manager[25826]: {0x7f3f088607e0} ERROR: (last system error 32: Broken pipe)
> Jul 2 14:03:12 l2 traffic_cop[25901]: cop received child status signal [25826 35584]
> Jul 2 14:03:12 l2 traffic_cop[25901]: traffic_manager not running, making sure traffic_server is dead
> Jul 2 14:03:12 l2 traffic_cop[25901]: spawning traffic_manager
> Jul 2 14:03:13 l2 traffic_manager[18267]: NOTE: --- Manager Starting ---
> Jul 2 14:03:13 l2 traffic_manager[18267]: NOTE: Manager Version: Apache Traffic Server - traffic_manager - 3.2.0 - (build # 52518 on Jun 25 2012 at 18:22:12)
> Jul 2 14:03:13 l2 traffic_manager[18267]: {0x7fe63de3f7e0} STATUS: opened /home/y/logs/trafficserver/manager.log
> Jul 2 14:03:15 l2 traffic_server[18322]: NOTE: --- Server Starting ---
> Jul 2 14:03:15 l2 traffic_server[18322]: NOTE: Server Version: Apache Traffic Server - traffic_server - 3.2.0 - (build # 52518 on Jun 25 2012 at 18:22:31)
> Jul 2 14:03:15 l2 traffic_server[18322]: {0x2b77573ab860} STATUS: opened /home/y/logs/trafficserver/diags.log
> Jul 2 14:03:15 l2 traffic_server[18322]: {0x2b77573ab860} ERROR: Cannot insert duplicate!
> Jul 2 14:03:22 l2 traffic_cop[25901]: server heartbeat succeeded
> [Jul 2 13:56:56.304] Server {0x2b0a391e1700} ERROR: [SSL_NetVConnection::ssl_read_from_net] SSL_ERROR_SYSCALL, underlying IO error: Connection reset by peer
> NOTE: Traffic Server received Sig 11: Segmentation fault
> NOTE: Traffic Server received Sig 11: Segmentation fault
> /home/y/bin/traffic_server - STACK TRACE:
> /home/y/bin/traffic_server - STACK TRACE:
> /lib64/libpthread.so.0[0x3b54e0f4a0]
> /lib64/libpthread.so.0[0x3b54e0f4a0]
> /home/y/bin/traffic_server(_ZN9LogBuffer14checkout_writeEPmm+0x153)[0x58e083]
> /home/y/bin/traffic_server(_ZN9LogObject15_checkout_writeEPmm+0xa8)[0x5a64c8]
> /home/y/bin/traffic_server(_ZN9LogObject3logEP9LogAccessPc+0x2f0)[0x5a7e30]
> /home/y/bin/traffic_server(_ZN9LogBuffer14checkout_writeEPmm+0x153)[0x58e083]
> /home/y/bin/traffic_server(_ZN9LogObject15_checkout_writeEPmm+0xa8)[0x5a64c8]
> /home/y/bin/traffic_server(_ZN9LogObject3logEP9LogAccessPc+0x2f0)[0x5a7e30]
> /home/y/bin/traffic_server(_ZN3Log6accessEP9LogAccess+0x146)[0x58f506]
> /home/y/bin/traffic_server(_ZN6HttpSM12update_statsEv+0x630)[0x526c50]
> /home/y/bin/traffic_server(_ZN3Log6accessEP9LogAccess+0x146)[0x58f506]
> /home/y/bin/traffic_server(_ZN6HttpSM9kill_thisEv+0x928)[0x52b548]
> /home/y/bin/traffic_server(_ZN6HttpSM12update_statsEv+0x630)[0x526c50]
> /home/y/bin/traffic_server(_ZN6HttpSM9kill_thisEv+0x928)[0x52b548]
> /home/y/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0x198)[0x52b868]
> /home/y/bin/traffic_server(_ZN10HttpTunnel12main_handlerEiPv+0xde)[0x56c3ee]
> /home/y/bin/traffic_server[0x6736a1]
> /home/y/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0x198)[0x52b868]
> /home/y/bin/traffic_server(_Z15write_to_net_ioP10NetHandlerP18UnixNetVConnectionP7EThread+0x847)[0x675517]
> /home/y/bin/traffic_server[0x672f81]
> /home/y/bin/traffic_server(_ZN10NetHandler12mainNetEventEiP5Event+0x286)[0x66df96]
> /home/y/bin/traffic_server[0x676ad5]
> /home/y/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0xb4)[0x696b14]
> /home/y/bin/traffic_server(_ZN10NetHandler12mainNetEventEiP5Event+0x1f2)[0x66df02]
> /home/y/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0xb4)[0x696b14]
> /home/y/bin/traffic_server(_ZN7EThread7executeEv+0x4c3)[0x6974a3]
> /home/y/bin/traffic_server[0x695ae2]
> /lib64/libpthread.so.0[0x3b54e077f1]
> /lib64/libc.so.6(clone+0x6d)[0x3b54ae5ccd]
> /home/y/bin/traffic_server(_ZN7EThread7executeEv+0x4c3)[0x6974a3]
> /home/y/bin/traffic_server[0x695ae2]
> /lib64/libpthread.so.0[0x3b54e077f1]
> /lib64/libc.so.6(clone+0x6d)[0x3b54ae5ccd]
> [Jul 2 14:03:08.684] Manager {0x7f3f088607e0} FATAL: [LocalManager::pollMgmtProcessServer] Error in read (errno: 104)
> [Jul 2 14:03:09.213] Manager {0x7f3f088607e0} FATAL: (last system error 104: Connection reset by peer)
> [Jul 2 14:03:09.213] Manager {0x7f3f088607e0} NOTE: [LocalManager::mgmtShutdown] Executing shutdown request.
> [Jul 2 14:03:09.213] Manager {0x7f3f088607e0} NOTE: [LocalManager::processShutdown] Executing process shutdown request.
> [Jul 2 14:03:09.496] Manager {0x7f3f088607e0} ERROR: [LocalManager::sendMgmtMsgToProcesses] Error writing message
> [Jul 2 14:03:09.496] Manager {0x7f3f088607e0} ERROR: (last system error 32: Broken pipe)
> [example_alarm_bin.sh] sent alarm: l2.ycs.uls.yahoo.com [Mon Jul 2 14:03:09 2012] The TS-TM connection is broken for some reason. Either restart TS and TM or correct this error for TM to display TS statistics correctly
--
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