Corey Cossentino created TS-2147:
------------------------------------
Summary: rfc5861 plugin causes a segfault
Key: TS-2147
URL: https://issues.apache.org/jira/browse/TS-2147
Project: Traffic Server
Issue Type: Bug
Components: Plugins
Reporter: Corey Cossentino
When using the rfc5861 plugin, the server will segfault when a cache lookup is
stale.
To reproduce: using the Node.js test server provided with the plugin, make a
request, then make a second request for the same URL after at least five
seconds.
[TrafficServer] using root directory '/usr/local'
[Aug 22 17:04:55.334] Server {0x7f01dfe617e0} DIAG: (rfc5861) Plugin
registration succeeded.
[Aug 22 17:04:55.334] Server {0x7f01dfe617e0} DIAG: (rfc5861) Plugin Init
Complete.
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
rfc5861_plugin
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Event:
TS_EVENT_HTTP_READ_REQUEST_HDR
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) External Request
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
create_request_info
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
create_request_info
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) state after
TSmalloc: 0x2ab4ae0
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) before
TSHttpTxnReenable
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
rfc5861_plugin
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Event:
TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) state after arg
get: 0x2ab4ae0
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Not Stale!
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
free_request_info
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Free effective URL
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Release Http
Header
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Destroy Buffer
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Free Client Addr
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Free Request Info
[Aug 22 17:04:57.443] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
free_request_info
[Aug 22 17:04:57.444] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE Event Handler End
[Aug 22 17:04:57.444] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
rfc5861_plugin
[Aug 22 17:04:57.444] Server {0x7f01dfe617e0} DIAG: (rfc5861) after
TSHttpTxnReenable
[Aug 22 17:04:57.444] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TS_EVENT_HTTP_READ_REQUEST_HDR Event Handler End
[Aug 22 17:04:57.444] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Event:
TS_EVENT_HTTP_READ_REQUEST_HDR
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) External Request
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
create_request_info
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
create_request_info
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) state after
TSmalloc: 0x2ae5b20
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) before
TSHttpTxnReenable
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Event:
TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) state after arg
get: 0x2ae5b20
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) CacheLookupStatus
is STALE
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Inside
get_cached_header_info
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Found a date
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Found
cache-control
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Found max-age
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Found
stale-while-revalidate
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Found
stale-on-error
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
get_cached_header_info
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Looks like we can
return fresh info and validate in the background
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) set state as async
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TSHttpTxnCacheLookupStatusSet()
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) TSContCreate()
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) TSContDataSet()
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) state: 0x2ae5b20
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TSHttpTxnReenable()
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Entering
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Event:
TS_EVENT_HTTP_SEND_RESPONSE_HDR
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) set warning header
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TS_EVENT_HTTP_SEND_RESPONSE_HDR Event Handler End
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TS_EVENT_HTTP_CACHE_LOOKUP_COMPLETE Event Handler End
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) after
TSHttpTxnReenable
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861)
TS_EVENT_HTTP_READ_REQUEST_HDR Event Handler End
[Aug 22 17:05:03.971] Server {0x7f01dfe617e0} DIAG: (rfc5861) Leaving
rfc5861_plugin
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Entering
fetch_resource
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) state: 0x2ae5b20
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Lets do the lookup
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Locking URL
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Set Connection:
close
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Creating
Connection hdr
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Create Buffers
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) HdrPrint()
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) TSHttpConnect()
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) TSVConnRead()
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) TSVConnWrite()
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Leaving
fetch_resource
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Entering
consume_resource
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Write Complete
[Aug 22 17:05:03.971] Server {0x7f01d2cab700} DIAG: (rfc5861) Leaving
consume_resource
[Aug 22 17:05:03.972] Server {0x7f01d2cab700} DIAG: (rfc5861) Entering
rfc5861_plugin
[Aug 22 17:05:03.972] Server {0x7f01d2cab700} DIAG: (rfc5861) Event:
TS_EVENT_HTTP_READ_REQUEST_HDR
[Aug 22 17:05:03.972] Server {0x7f01d2cab700} DIAG: (rfc5861) Internal Request
[Aug 22 17:05:03.972] Server {0x7f01d2cab700} DIAG: (rfc5861) after
TSHttpTxnHookAdd
[Aug 22 17:05:03.972] Server {0x7f01d2cab700} DIAG: (rfc5861) before
TSHttpTxnReenable
NOTE: Traffic Server received Sig 11: Segmentation fault
traffic_server - STACK TRACE:
/lib64/libpthread.so.0(+0xf500)[0x7f01ddddf500]
traffic_server(_Z16_acquire_sessionP13SessionBucketPK8sockaddrR7INK_MD5P6HttpSM+0x46)[0x518b56]
traffic_server(_ZN18HttpSessionManager15acquire_sessionEP12ContinuationPK8sockaddrPKcP17HttpClientSessionP6HttpSM+0x37c)[0x519b2c]
traffic_server(_ZN6HttpSM19do_http_server_openEb+0x490)[0x52ba90]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x4e4)[0x533bb4]
traffic_server(_ZN6HttpSM22state_cache_open_writeEiPv+0x143)[0x526993]
traffic_server(_ZN6HttpSM12main_handlerEiPv+0xd8)[0x52fe28]
traffic_server(_ZN11HttpCacheSM22state_cache_open_writeEiPv+0xfa)[0x50a0ba]
traffic_server(_ZN7CacheVC8callcontEi+0x53)[0x5ed853]
traffic_server(_ZN7CacheVC18openWriteStartDoneEiP5Event+0x5c3)[0x660383]
traffic_server(_ZN5Cache10open_writeEP12ContinuationP7INK_MD5P8HTTPInfolS3_13CacheFragTypePci+0x72e)[0x65fd1e]
traffic_server(_ZN14CacheProcessor10open_writeEP12ContinuationiP3URLbP7HTTPHdrP8HTTPInfol13CacheFragType+0xb5)[0x6336e5]
traffic_server(_ZN11HttpCacheSM10open_writeEP3URLP7HTTPHdrP8HTTPInfolbb+0xa0)[0x50a420]
traffic_server(_ZN6HttpSM23do_cache_prepare_actionEP11HttpCacheSMP8HTTPInfobb+0x10e)[0x51b85e]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x6bc)[0x533d8c]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x3ba)[0x532a2a]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x2b0)[0x52a940]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1f2)[0x5338c2]
traffic_server(_ZN6HttpSM16do_hostdb_lookupEv+0x282)[0x51c6e2]
traffic_server(_ZN6HttpSM14set_next_stateEv+0xbad)[0x53427d]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x3ba)[0x532a2a]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x2b0)[0x52a940]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1f2)[0x5338c2]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x3ba)[0x532a2a]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x2b0)[0x52a940]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1f2)[0x5338c2]
traffic_server(_ZN6HttpSM21state_cache_open_readEiPv+0xfe)[0x52cdfe]
traffic_server(_ZN6HttpSM12main_handlerEiPv+0xd8)[0x52fe28]
traffic_server(_ZN11HttpCacheSM21state_cache_open_readEiPv+0x1b2)[0x50a7d2]
traffic_server(_ZN7CacheVC8callcontEi+0x53)[0x5ed853]
traffic_server(_ZN7CacheVC17openReadStartHeadEiP5Event+0x8c5)[0x656a85]
traffic_server(_ZN5Cache9open_readEP12ContinuationP7INK_MD5P7HTTPHdrP21CacheLookupHttpConfig13CacheFragTypePci+0x383)[0x6535e3]
traffic_server(_ZN14CacheProcessor9open_readEP12ContinuationP3URLbP7HTTPHdrP21CacheLookupHttpConfigl13CacheFragType+0xad)[0x63102d]
traffic_server(_ZN11HttpCacheSM9open_readEP3URLP7HTTPHdrP21CacheLookupHttpConfigl+0x94)[0x50a224]
traffic_server(_ZN6HttpSM24do_cache_lookup_and_readEv+0xf3)[0x51bb63]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x722)[0x533df2]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x3ba)[0x532a2a]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x2b0)[0x52a940]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1f2)[0x5338c2]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1e2)[0x5338b2]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x3ba)[0x532a2a]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x2b0)[0x52a940]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1f2)[0x5338c2]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x3ba)[0x532a2a]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x2b0)[0x52a940]
traffic_server(_ZN6HttpSM18state_api_callbackEiPv+0x8b)[0x53001b]
traffic_server(TSHttpTxnReenable+0x404)[0x4b86e4]
/usr/local/libexec/trafficserver/rfc5861.so(+0x2f91)[0x7f01d823af91]
traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x114)[0x52a7a4]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x1f2)[0x5338c2]
traffic_server(_ZN6HttpSM32state_read_client_request_headerEiPv+0x289)[0x529559]
traffic_server(_ZN6HttpSM12main_handlerEiPv+0xd8)[0x52fe28]
traffic_server(_ZN8PluginVC17process_read_sideEb+0x375)[0x4cffa5]
traffic_server(_ZN8PluginVC18process_write_sideEb+0x57a)[0x4d08fa]
traffic_server(_ZN8PluginVC12main_handlerEiPv+0x372)[0x4d2122]
traffic_server(_ZN7EThread13process_eventEP5Eventi+0x8f)[0x6a38ef]
traffic_server(_ZN7EThread7executeEv+0x63b)[0x6a446b]
traffic_server[0x6a278a]
/lib64/libpthread.so.0(+0x7851)[0x7f01dddd7851]
/lib64/libc.so.6(clone+0x6d)[0x7f01dd17090d]
--
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
