[
https://issues.apache.org/jira/browse/TS-1756?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13606264#comment-13606264
]
helaku commented on TS-1756:
----------------------------
croe dump info
#0 0x0000000000552bdf in HttpTunnel::chain_abort_all (this=0x2aaab58e5e00,
p=0x2aaab58e5ff8) at HttpTunnel.cc:1306
#1 0x00000000005538b4 in HttpTunnel::kill_tunnel (this=0x2aaab58e5e00) at
HttpTunnel.cc:490
#2 0x0000000000513d7c in HttpSM::state_watch_for_client_abort
(this=0x2aaab58e4290, event=104, data=<value optimized out>) at HttpSM.cc:876
#3 0x000000000051e8a4 in HttpSM::main_handler (this=0x2aaab58e4290, event=104,
data=0xe885388) at HttpSM.cc:2447
#4 0x000000000065657d in read_from_net (nh=0x2aaaaae2f1e8, vc=0xe885280,
thread=0x2aaaaae2c010) at ../../iocore/eventsystem/I_Continuation.h:146
#5 0x000000000064c252 in NetHandler::mainNetEvent (this=0x2aaaaae2f1e8,
event=<value optimized out>, e=0x2aaaabd3b01c) at UnixNet.cc:372
#6 0x0000000000675490 in EThread::process_event (this=0x2aaaaae2c010,
e=0xdba8860, calling_code=5) at I_Continuation.h:146
#7 0x0000000000675d79 in EThread::execute (this=0x2aaaaae2c010) at
UnixEThread.cc:264
#8 0x00000000004b5f6b in main (argc=<value optimized out>, argv=<value
optimized out>) at Main.cc:1822
> 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.2
>
>
> 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
