You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "Richard Hesse (JIRA)" <ji...@apache.org> on 2013/05/21 06:49:18 UTC
[jira] [Commented] (TS-1756) Crash report: kill_tunnel
[ https://issues.apache.org/jira/browse/TS-1756?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13662678#comment-13662678 ]
Richard Hesse commented on TS-1756:
-----------------------------------
I'm seeing this, too. Similar OS CentOS 5.6 with updates (basically 5.9).
{quote}
/usr/local/bin/traffic_server - STACK TRACE:
/lib64/libpthread.so.0[0x378480eca0]
/usr/local/bin/traffic_server(_ZN10HttpTunnel15chain_abort_allEP18HttpTunnelProducer+0xaa)[0x56dd5a]
/usr/local/bin/traffic_server(_ZN10HttpTunnel11kill_tunnelEv+0x22)[0x571702]
/usr/local/bin/traffic_server(_ZN6HttpSM28state_watch_for_client_abortEiPv+0x11a)[0x52890a]
/usr/local/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0xdc)[0x530a3c]
/usr/local/bin/traffic_server[0x694897]
/usr/local/bin/traffic_server(_ZN10NetHandler12mainNetEventEiP5Event+0x479)[0x689ed9]
/usr/local/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0x22f)[0x6b993f]
/usr/local/bin/traffic_server(_ZN7EThread7executeEv+0x5bc)[0x6ba24c]
/usr/local/bin/traffic_server[0x6b8d8e]
/lib64/libpthread.so.0[0x378480683d]
/lib64/libc.so.6(clone+0x6d)[0x37840d4fad]
{quote}
> Crash report: kill_tunnel
> -------------------------
>
> Key: TS-1756
> URL: https://issues.apache.org/jira/browse/TS-1756
> Project: Traffic Server
> Issue Type: Bug
> Components: Clustering, Core, HTTP
> Affects Versions: 3.2.4
> Reporter: helaku
> Fix For: 3.3.3
>
>
> centos 5.9 x64 ts3.2.4 debug log
> {code}
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http) [3466] State Transition: API_CACHE_LOOKUP_COMPLETE -> SERVE_FROM_CACHE
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http) [3466] perform_cache_write_action CACHE_DO_SERVE
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http_redirect) [HttpSM::do_redirect]
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http_redirect) [HttpTunnel::deallocate_postdata_copy_buffers]
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http_tunnel) [3466] adding producer 'cache read'
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http_tunnel) [3466] adding consumer 'user agent'
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http_tunnel) tunnel_run started, p_arg is NULL
> [Mar 19 14:55:40.687] Server {0x4286a940} DEBUG: (http_cs) tcp_init_cwnd_set 1
> [Mar 19 14:55:40.687] Server {0x42769940} DEBUG: (http_tunnel) [3466] consumer_handler [user agent VC_EVENT_WRITE_READY]
> [Mar 19 14:55:40.687] Server {0x42769940} DEBUG: (http_tunnel) [3466] consumer_handler [user agent VC_EVENT_WRITE_READY]
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) [SelectFromAlternates] # alternates = 1
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) [SelectFromAlternates] 1 alternates for this cached doc
> [alts] There are 1 alternates for this request header.
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Exact match for ACCEPT CHARSET
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Exact match for ACCEPT ENCODING
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) [calculate_quality_accept_language_match]: response hdr does not have content-language.
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) CalcQualityOfMatch: Accept match = 1
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) CalcQualityOfMatch: Accept match = 1
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Content-Type and Accept 1.000000
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) CalcQualityOfMatch: AcceptCharset match = 1.001
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) CalcQualityOfMatch: AcceptCharset match = 1.001
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Content-Type and Accept-Charset 1.001000
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) CalcQualityOfMatch: AcceptEncoding match = 1.001
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) CalcQualityOfMatch: AcceptEncoding match = 1.001
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Content-Encoding and Accept-Encoding 1.001000
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) CalcQualityOfMatch: AcceptLanguage match = 1
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) CalcQualityOfMatch: AcceptLanguage match = 1
> [Mar 19 14:55:40.691] Server {0x42466940} DEBUG: (http) [2021] [HttpSM::main_handler, VC_EVENT_EOS]
> [Mar 19 14:55:40.691] Server {0x42466940} DEBUG: (http) [2021] [&HttpSM::state_watch_for_client_abort, VC_EVENT_EOS]
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Content-Language and Accept-Language 1.000000
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) Mult's Quality Factor: 1.002001
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_alternate) ----------End of Alternate----------
> NOTE: Traffic Server received Sig 11: Segmentation fault
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) type = 'image', subtype = 'jpeg'/usr/local/trafficserver-3.2.4/bin/traffic_server - STACK TRACE:
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) Using default image vary headers
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) CalcQualityOfMatch: CalcVariability says variability = 0
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) CalcQualityOfMatch: CalcVariability says variability = 0
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_match) CalcQualityOfMatch: Returning final Q = 1.002
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) CalcQualityOfMatch: Returning final Q = 1.002
> [alts] ---- alternate #1 (Q = 1.002) has these request/response hdrs:
> GET http://117.7.92.116/line_head/3/220x165/50e7cac997a17.jpg HTTP/1.1
> Accept: */*
> Referer: http://www.xg.com.cn/
> Accept-Language: zh-CN
> User-Agent: Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; WOW64; Trident/5.0; qihu theworld)
> Accept-Encoding: gzip
> Host: img2a.xg-img.com.cn
> Client-ip: 113.132.246.226
> X-Forwarded-For: 113.132.246.226
> HTTP/1.1 200 OK
> Server: nginx
> Date: Tue, 19 Mar 2013 06:43:05 GMT
> Content-Type: image/jpeg
> Connection: keep-alive
> Last-Modified: Sat, 05 Jan 2013 06:40:09 GMT
> Accept-Ranges: bytes
> Content-Length: 18391
> Cache-Control: max-age=315360000
> Expires: Thu, 16 Mar 2023 13:00:18 GMT
> Age: 63767
> Via: http/1.1 zats-xeq-117792109 (zcache [cRs f ])
> Z-CACHE: Z-NCACHE-shangdi117792107
> [Mar 19 14:55:40.691] Server {0x45294940} DEBUG: (http_seq) [SelectFromAlternates] Chosen alternate # 0
> [alts] and the winner is alternate number 1
> /lib64/libpthread.so.0[0x34c860ebe0]
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN10HttpTunnel15chain_abort_allEP18HttpTunnelProducer+0x71)[0x552bdf]
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN10HttpTunnel11kill_tunnelEv+0x30)[0x5538b4]
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN6HttpSM28state_watch_for_client_abortEiPv+0x140)[0x513d7c]
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_cache) [3467] [&HttpCacheSM::state_cache_open_read, CACHE_EVENT_OPEN_READ]
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http) [3467] [HttpSM::main_handler, CACHE_EVENT_OPEN_READ]
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http) [3467] [&HttpSM::state_cache_open_read, CACHE_EVENT_OPEN_READ]
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http) [3467] cache_open_read - CACHE_EVENT_OPEN_READ
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_trans) [HttpTransact::HandleCacheOpenRead]
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_trans) CacheOpenRead -- hit
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_trans) Next action HTTP_API_READ_CACHE_HDR; HandleCacheOpenReadHitFreshness
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0x6e)[0x51e8a4]
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http) [3467] State Transition: CACHE_LOOKUP -> API_READ_CACHE_HDR
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_seq) [HttpTransact::HandleCacheOpenReadHitFreshness] Hit in cache
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_trans) [HandleCacheOpenReadHitFreshness] request_sent_time : 136367587
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_trans) [HandleCacheOpenReadHitFreshness] response_received_time : 136367587
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_match) calculate_document_freshness_limit --- max_age set, freshness_limit = 315360000
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_match) calculate_document_freshness_limit --- final freshness_limit = 31536000
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] age_value: 20667
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] date_value: 136367587
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] response_time: 136367587
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] now: 1363676140
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] now (fixed): 1363676140
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] apparent_age: 0
> [Mar 19 14:55:40.692] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] corrected_received_age: 20667/usr/local/trafficserver-3.2.4/bin/traffic_server[0x65657d]
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN10NetHandler12mainNetEventEiP5Event+0x472)[0x64c252]
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0x23a)[0x675490]
> /usr/local/trafficserver-3.2.4/bin/traffic_server(_ZN7EThread7executeEv+0x5c9)[0x675d7]
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] response_delay: 0
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] corrected_initial_age: 20667
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] resident_time: 261
> /usr/local/trafficserver-3.2.4/bin/traffic_server[0x674a40]
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_age) [calculate_document_age] current_age: 20928
> /lib64/libpthread.so.0[0x34c860677d]
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_match) [what_is_document_freshness] fresh_limit: 31536000 current_age: 20928
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_match) [..._document_freshness] initial age limit: 31536000
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_match) document_freshness --- current_age = 20928
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_match) document_freshness --- age_limit = 31536000
> /lib64/libc.so.6(clone+0x6d)[0x34c7ad33ed]
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_match) document_freshness --- fresh_limit = 31536000
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_seq) document_freshness --- current_age = 20928
> [Mar 19 14:55:40.693] Server {0x42365940} DEBUG: (http_seq) document_freshness --- age_limit = 31536000[Mar 19 14:55:40.789] Manager {0x2b95758b5b90} ERROR: [LocalManager::pollMgmtProcessServer] Server Process terminated due to Sig 11: Segmentation fault
> [Mar 19 14:55:40.789] Manager {0x2b95758b5b90} ERROR: (last system error 2: No such file or directory)
> [Mar 19 14:55:40.70] Manager {0x2b95758b5b90} ERROR: [Alarms::signalAlarm] Server Process was reset
> [Mar 19 14:55:40.70] Manager {0x2b95758b5b90} ERROR: (last system error 2: No such file or directory)
> [Mar 19 14:55:41.72] Manager {0x2b95758b5b90} NOTE: [LocalManager::startProxy] Launching ts process
> [TrafficServer] using root directory '/usr/local/trafficserver-3.2.4'
> [Mar 19 14:55:41.800] Manager {0x2b95758b5b90} NOTE: [LocalManager::pollMgmtProcessServer] New process connecting fd '13'
> [Mar 19 14:55:41.800] Manager {0x2b95758b5b90} NOTE: [Alarms::signalAlarm] Server Process born
> [Mar 19 14:55:42.811] {0x2b7028e7fc20} STATUS: opened /usr/local/trafficserver-3.2.4/var/log/trafficserver/diags.log
> [Mar 19 14:55:42.811] {0x2b7028e7fc20} NOTE: updated diags config
> [Mar 19 14:55:42.813] Server {0x2b7028e7fc20} DEBUG: (http_init) proxy.config.http.redirection_enabled = 0
> [Mar 19 14:55:42.813] Server {0x2b7028e7fc20} DEBUG: (http_init) proxy.config.http.number_of_redirections = 1
> [Mar 19 14:55:42.813] Server {0x2b7028e7fc20} DEBUG: (http_init) proxy.config.http.post_copy_size = 2048
> [Mar 19 14:55:42.816] Server {0x2b7028e7fc20} DEBUG: (http_aeua) [HttpConfig::init_aeua_filter] - Config: "/usr/local/trafficserver-3.2.4/etc/trafficserver/ae_ua.config"
> [Mar 19 14:55:42.816] Server {0x2b7028e7fc20} DEBUG: (http_aeua) [HttpConfig::init_aeua_filter] - Opening config "/usr/local/trafficserver-3.2.4/etc/trafficserver/ae_ua.config"
> [Mar 19 14:55:42.816] Server {0x2b7028e7fc20} DEBUG: (http_aeua) [HttpConfig::init_aeua_filter] - Added 0 REGEXP filters
> [Mar 19 14:55:42.816] Server {0x2b7028e7fc20} DEBUG: (http_aeua) [init_http_aeua_filter] - Total loaded 0 REGEXP for Accept-Enconding/User-Agent filtering
> [Mar 19 14:55:42.818] Server {0x2b7028e7fc20} NOTE: cache clustering enabled
> [Mar 19 14:55:42.821] Server {0x2b7028e7fc20} DEBUG: (dns) ink_dns_init: called with init_called = 0
> [Mar 19 14:55:42.829] Server {0x407fb940} NOTE: updated diags config
> {code}
--
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