helaku created TS-1756:
--------------------------
Summary: TS cluster Segmentation fault
Key: TS-1756
URL: https://issues.apache.org/jira/browse/TS-1756
Project: Traffic Server
Issue Type: Bug
Reporter: helaku
ts debug log
[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
--
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
