[TS-1411] Seg fault when using %<cquuc>

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 3.2.0
• Fix Version/s: 5.0.0
• Component/s: Logging
• Labels: Crash

Environment

RHEL 6.2 x86_64

• Assignee: Bryan Call
• Reporter: David Carlin
• Created: 17/Aug/12 19:24
• Updated: 18/Dec/14 05:11
• Resolved: 20/May/14 23:27

Description

I've been experiencing some segfaults during log rotation. The sequence of events is this.. log rotation occurs, then I get hundreds of dropping log buffer error msgs, then the segfault.

This started occurring when I lengthened the default log format to include the unmapped URL and the user agent string:

%<cqtq> %<ttms> %<chi> %<crc>/%<pssc> %<psql> %<cqhm> %<cquc> %<caun> %<phr>/%<pqsn> %<psct> %<xid> %<cquuc> \"%<

{User-Agent}

cqh>\"

In terms of frequency, we have a number of boxes and I probably see one of these crashed per day since the above change. Logs are rotated every 2 hours.

I've had other log related segfaults, reported in TS-1330 - these new ones seem to have a different cause.

[Aug 14 21:07:20.002] Server

{0x2ae3a8887700} STATUS: The rolled logfile, /home/y/logs/trafficserver/error.log_l30.ycs.a4e.yahoo.com.20120814.17h59m50s-20120814.20h00m00s.old, was auto-deleted; 3148252 bytes were reclaimed.
[Aug 14 21:07:42.859] Server {0x2ae3a8887700}

STATUS: The rolled logfile, /home/y/logs/trafficserver/squid.blog_l30.ycs.a4e.yahoo.com.20120814.18h00m00s-20120814.20h00m00s.old, was auto-deleted; 14735520048 bytes were reclaimed.
[Aug 14 21:07:42.865] Server

{0x2ae3a8887700} WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.865] Server {0x2ae3a8887700}

WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.865] Server

{0x2ae3a8887700} WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.865] Server {0x2ae3a8887700}

WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.865] Server

{0x2ae3a8887700} WARNING: Dropping log buffer, can't keep up.
[...]
[Aug 14 21:07:42.876] Server {0x2ae3a8887700}

WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.876] Server

{0x2ae3a8887700} WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.876] Server {0x2ae3a8887700}

WARNING: Dropping log buffer, can't keep up.
[Aug 14 21:07:42.876] Server

{0x2ae3a8887700}

WARNING: Dropping log buffer, can't keep up.
NOTE: Traffic Server received Sig 11: Segmentation fault
/home/y/bin/traffic_server - STACK TRACE:
/lib64/libpthread.so.0[0x383f00f500]
/home/y/bin/traffic_server(LogAccess::marshal_mem(char*, char const*, int, int)+0x48)[0x58a118]
/home/y/bin/traffic_server(LogAccessHttp::marshal_client_req_url_canon(char*)+0x20)[0x58c3f0]
/home/y/bin/traffic_server(LogFieldList::marshal(LogAccess*, char*)+0x32)[0x59d5a2]
/home/y/bin/traffic_server(LogObject::log(LogAccess*, char*)+0x399)[0x5a7ed9]
/home/y/bin/traffic_server(Log::access(LogAccess*)+0x146)[0x58f506]
/home/y/bin/traffic_server(HttpSM::update_stats()+0x630)[0x526c50]
/home/y/bin/traffic_server(HttpSM::kill_this()+0x928)[0x52b548]
/home/y/bin/traffic_server(HttpSM::main_handler(int, void*)+0x198)[0x52b868]
/home/y/bin/traffic_server(HttpTunnel::main_handler(int, void*)+0xde)[0x56c3ee]
/home/y/bin/traffic_server[0x673871]
/home/y/bin/traffic_server(write_to_net_io(NetHandler*, UnixNetVConnection*, EThread*)+0x847)[0x6756e7]
/home/y/bin/traffic_server(NetHandler::mainNetEvent(int, Event*)+0x286)[0x66e076]
/home/y/bin/traffic_server(EThread::process_event(Event*, int)+0xb4)[0x696ce4]
/home/y/bin/traffic_server(EThread::execute()+0x4c3)[0x697673]
/home/y/bin/traffic_server[0x695cb2]
/lib64/libpthread.so.0[0x383f007851]

Issue Links

• relates to: TS-2837 Dangling pointer in URLImpl which may cause core dump