FN created TS-1335:
----------------------
Summary: TS crashed when null_transform running as a request
transform
Key: TS-1335
URL: https://issues.apache.org/jira/browse/TS-1335
Project: Traffic Server
Issue Type: Bug
Components: HTTP, Plugins
Affects Versions: 3.2.0
Environment: CentOS 6.0
Reporter: FN
Priority: Blocker
I'm writing a request transform plugin based on null_transform. null_transform
is a response transform plugin, I replace all RESPONSE to REQUEST in
null_transform.c and return 1 in function transformable directly. When I loaded
this plugin to TS and try to upload some files, it works with small size files
but crash when file size > 1Mbytes.
Logs:
+++++++++ Incoming Request +++++++++
-- State Machine Id: 19
POST
http://192.168.5.18/trac/Test/attachment/wiki/WikiStart/?action=new&attachfilebutton=Attach+another+file
HTTP/1.1
Host: 192.168.5.18
User-Agent: Mozilla/5.0 (Windows NT 6.1; rv:5.0) Gecko/20100101 Firefox/5.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip, deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Proxy-Connection: keep-alive
Referer:
http://192.168.5.18/trac/Test/attachment/wiki/WikiStart/?action=new&attachfilebutton=Attach+another+file
Cookie: trac_form_token=93b8737c71ff0e373ffa8910;
trac_auth=d7abd26a050240f9d8c53dddb1df1b2e
Authorization: Basic dXNlcjoxMjM0NTY=
Content-Type: multipart/form-data;
boundary=---------------------------302451218714462
Content-Length: 3549051
[Jul 6 16:02:13.184] Server {0x40a04b70} DEBUG: (http_trans) Next action
DNS_LOOKUP; OSDNSLookup
[Jul 6 16:02:13.184] Server {0x40a04b70} DEBUG: (http) [19] State Transition:
HTTP_API_POST_REMAP -> DNS_LOOKUP
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_seq)
[HttpStateMachineGet::do_hostdb_lookup] Doing DNS Lookup
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans)
[HttpTransact::OSDNSLookup] This was attempt 1
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_seq)
[HttpTransact::OSDNSLookup] DNS Lookup successful
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans) [OSDNSLookup] DNS
lookup for O.S. successful IP: 192.168.5.18
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans) Next action
HttpTransact::HTTP_API_OS_DNS; HttpTransact::DecideCacheLookup
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http) [19] State Transition:
DNS_LOOKUP -> API_OS_DNS
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans)
[DecideCacheLookup] Will NOT do cache lookup.
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_seq) [DecideCacheLookup]
Will NOT do cache lookup
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans) Next action
HTTP_API_CACHE_LOOKUP_COMPLETE; LookupSkipOpenServer
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http) [19] State Transition:
API_OS_DNS -> API_CACHE_LOOKUP_COMPLETE
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans) request not
cacheable, so bypass parent
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans)
[ink_cluster_time] local: 1341604933, highest_delta: 0, cluster: 1341604933
[Jul 6 16:02:13.185] Server {0x40a04b70} DEBUG: (http_trans) [build_request]
request_sent_time: 1341604933
+++++++++ Proxy's Request +++++++++
-- State Machine Id: 19
POST
/trac/Test/attachment/wiki/WikiStart/?action=new&attachfilebutton=Attach+another+file
HTTP/1.1
Host: 192.168.5.18
User-Agent: Mozilla/5.0 (Windows NT 6.1; rv:5.0) Gecko/20100101 Firefox/5.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip, deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Referer:
http://192.168.5.18/trac/Test/attachment/wiki/WikiStart/?action=new&attachfilebutton=Attach+another+file
Cookie: trac_form_token=93b8737c71ff0e373ffa8910;
trac_auth=d7abd26a050240f9d8c53dddb1df1b2e
Authorization: Basic dXNlcjoxMjM0NTY=
Content-Type: multipart/form-data;
boundary=---------------------------302451218714462
Content-Length: 3549051
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http_trans) Next action next;
HttpTransact::HandleResponse
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http) [19] State Transition:
API_CACHE_LOOKUP_COMPLETE -> ORIGIN_SERVER_OPEN
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http_track) entered inside
do_http_server_open
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http) [19] open connection to
192.168.5.18: 192.168.5.18:80
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http_seq)
[HttpSM::do_http_server_open] Sending request to server
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http) calling
netProcessor.connect_re
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http) [19]
[HttpSM::main_handler, NET_EVENT_OPEN]
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http_track) entered inside
state_http_server_open
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http) [19]
[&HttpSM::state_http_server_open, NET_EVENT_OPEN]
[Jul 6 16:02:13.186] Server {0x40a04b70} DEBUG: (http_ss) [17] session born,
netvc 0x44c16f20
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_tunnel) [19] adding
producer 'user agent post'
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_tunnel) [19] adding
consumer 'post transform'
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_tunnel) tunnel_run
started, p_arg is provided
[Jul 6 16:02:13.187] Server {0x40159db0} DEBUG: (http_tunnel) [19]
consumer_handler [post transform VC_EVENT_WRITE_READY]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http) [19]
[HttpSM::main_handler, TRANSFORM_READ_READY]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http) [19]
[&HttpSM::state_request_wait_for_transform_read, TRANSFORM_READ_READY]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http) [19]
[&HttpSM::state_common_wait_for_transform_read, VC_EVENT_ERROR]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_cs) [3] session closed
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_cs) [3] session destroy
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_trans)
[HttpTransact::HandleApiErrorJump]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_trans) [WUTS code
generation] Hit/Miss: 49, Log: 51, Hier: 50, Status: 500
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_trans) Adding Server:
ATS/3.2.0
+++++++++ Proxy's Response 2 +++++++++
-- State Machine Id: 19
HTTP/1.1 500 INKApi Error
Date: Fri, 06 Jul 2012 20:02:13 GMT
Proxy-Connection: close
Server: ATS/3.2.0
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_trans) Next action
PROXY_INTERNAL_CACHE_NOOP; NULL
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http) [19] State Transition:
ORIGIN_SERVER_OPEN -> PROXY_INTERNAL_CACHE_NOOP
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_ss) [17] session closed
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_redirect)
[HttpSM::do_redirect]
[Jul 6 16:02:13.187] Server {0x40a04b70} DEBUG: (http_redirect)
[HttpTunnel::deallocate_postdata_copy_buffers]
NOTE: Traffic Server received Sig 11: Segmentation fault
/usr/local/bin/traffic_server - STACK TRACE:
[0x40000400]
/usr/local/bin/traffic_server(_ZN6HttpSM17handle_api_returnEv+0x2b5)[0x81689f5]
/usr/local/bin/traffic_server(_ZN6HttpSM17state_api_calloutEiPv+0x248)[0x8161fc8]
/usr/local/bin/traffic_server(_ZN6HttpSM14do_api_calloutEv+0x67)[0x816d167]
/usr/local/bin/traffic_server(_ZN6HttpSM14set_next_stateEv+0xeb)[0x816a42b]
/usr/local/bin/traffic_server(_ZN6HttpSM36state_common_wait_for_transform_readEP17HttpTransformInfoMS_FiiPvEiS2_+0x223)[0x81619f3]
/usr/local/bin/traffic_server(_ZN6HttpSM37state_request_wait_for_transform_readEiPv+0x83)[0x8164e03]
/usr/local/bin/traffic_server(_ZN6HttpSM12main_handlerEiPv+0xcf)[0x81671ff]
/usr/local/bin/traffic_server(_ZN17TransformTerminus12handle_eventEiPv+0x17a)[0x811c7da]
/usr/local/bin/traffic_server(_ZN7EThread13process_eventEP5Eventi+0xa2)[0x82caca2]
/usr/local/bin/traffic_server(_ZN7EThread7executeEv+0x57c)[0x82cb6cc]
/usr/local/bin/traffic_server[0x82c9c94]
/lib/libpthread.so.0[0x7c7a09]
/lib/libc.so.6(clone+0x5e)[0x70543e]
[Jul 6 16:02:13.951] Manager {0xb776f740} FATAL:
[LocalManager::pollMgmtProcessServer] Error in read (errno: 104)
[Jul 6 16:02:13.952] Manager {0xb776f740} FATAL: (last system error 104:
Connection reset by peer)
[Jul 6 16:02:13.952] Manager {0xb776f740} NOTE: [LocalManager::mgmtShutdown]
Executing shutdown request.
[Jul 6 16:02:13.952] Manager {0xb776f740} NOTE:
[LocalManager::processShutdown] Executing process shutdown request.
[Jul 6 16:02:13.952] Manager {0xb776f740} ERROR:
[LocalManager::sendMgmtMsgToProcesses] Error writing message
[Jul 6 16:02:13.952] Manager {0xb776f740} ERROR: (last system error 32:
Broken pipe)
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
