You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "FN (JIRA)" <ji...@apache.org> on 2012/07/06 22:11:34 UTC
[jira] [Updated] (TS-1335) TS crashed when null_transform running
as a request transform
[ https://issues.apache.org/jira/browse/TS-1335?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
FN updated TS-1335:
-------------------
Attachment: post_success.txt
post_crash.txt
Here is full logs for post success and crash.
> 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
> Attachments: post_crash.txt, post_success.txt
>
>
> 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