Hey Guys,
Looks like I have triggered some infinite loop when use ts_lua with ts.fetch
lua script, do the fetch after a hook function, logs shows it doesn’t take
cliaddr , but I don’t think that matters.
function control_request()
local ct = {
header = ts.client_request.get_headers(),
method = 'GET',
cliaddr = '10.12.17.57:33333'
}
local url = string.format('http://%s', '10.12.17.58' )
ts.debug(url)
local res = ts.fetch(url, ct)
ts.debug(res)
if res.status == 200 then
ts.debug("lua yes")
else
ts.debug('lua no')
end
return 0
end
function do_global_read_request()
ts.hook(TS_LUA_HOOK_READ_REQUEST_HDR, control_request)
return 0
end
running a single query to trigger it
[root@Di-Dev wrk]# curl -kv http://10.12.17.58 -x http://10.12.17.57:8080
* About to connect() to proxy 10.12.17.57 port 8080 (#0)
* Trying 10.12.17.57... connected
* Connected to 10.12.17.57 (10.12.17.57) port 8080 (#0)
> GET http://10.12.17.58/ HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.21
> Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: 10.12.17.58
> Accept: */*
> Proxy-Connection: Keep-Alive
>
debug log has been enabled for ts_lua
here’s the output for the traffic.out, and shows it keeps running inside the
lua script, but never come back, also doesn’t seem it trying to connect any url
based on the netstat and tcpdump.
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:7085
(call_transact_and_set_next_state)> (http) [10235] State Transition:
SM_ACTION_UNDEFINED -> SM_ACTION_API_READ_REQUEST_HDR
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1448
(state_api_callout)> (http) [10235] calling plugin on hook
TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x180afe0
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DIAG: (ts_lua)
[globalHookHandler] req_id: 10233
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DIAG: (ts_lua)
[globalHookHandler] has txn hook -> adding txn close hook handler to release
resources
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1332
(state_api_callback)> (http) [10235] [&HttpSM::state_api_callback,
HTTP_API_CONTINUE]
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1372
(state_api_callout)> (http) [10235] [&HttpSM::state_api_callout,
HTTP_API_CONTINUE]
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1448
(state_api_callout)> (http) [10235] calling plugin on hook
TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x2aaae364a180
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DIAG: (ts_lua) http://10.12.17.58
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSessionAccept.cc:60
(accept)> (http_seq) [HttpSessionAccept:mainEvent 0x2aaae3689148] accepted
connection from 127.0.0.1:33333 transport type = 0
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <Http1ClientSession.cc:170
(new_connection)> (http_cs) [10236] session born, netvc 0x2aaae3689148
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG:
<ProxyClientTransaction.cc:46 (new_transaction)> (http_txn) [0] Starting
transaction 1 using sm [10236]
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:2641
(main_handler)> (http) [10236] [HttpSM::main_handler, VC_EVENT_READ_READY]
[Dec 21 15:34:41.070] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:619
(state_read_client_request_header)> (http) [10236]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:2641
(main_handler)> (http) [10236] [HttpSM::main_handler, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:619
(state_read_client_request_header)> (http) [10236]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:769
(state_read_client_request_header)> (http) [10236] done parsing client request
header
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1112
(ModifyRequest)> (http_trans) START HttpTransact::ModifyRequest
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:8386
(ink_cluster_time)> (http_trans) [ink_cluster_time] local: 1482363281,
highest_delta: 0, cluster: 1482363281
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1203
(ModifyRequest)> (http_trans) END HttpTransact::ModifyRequest
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1205
(ModifyRequest)> (http_trans) Checking if transaction wants to upgrade
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1212
(ModifyRequest)> (http_trans) Next action SM_ACTION_API_READ_REQUEST_HDR;
HttpTransact::StartRemapRequest
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:7085
(call_transact_and_set_next_state)> (http) [10236] State Transition:
SM_ACTION_UNDEFINED -> SM_ACTION_API_READ_REQUEST_HDR
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1448
(state_api_callout)> (http) [10236] calling plugin on hook
TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x180afe0
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DIAG: (ts_lua)
[globalHookHandler] req_id: 10234
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DIAG: (ts_lua)
[globalHookHandler] has txn hook -> adding txn close hook handler to release
resources
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1332
(state_api_callback)> (http) [10236] [&HttpSM::state_api_callback,
HTTP_API_CONTINUE]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1372
(state_api_callout)> (http) [10236] [&HttpSM::state_api_callout,
HTTP_API_CONTINUE]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1448
(state_api_callout)> (http) [10236] calling plugin on hook
TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x2aaae364a140
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DIAG: (ts_lua) http://10.12.17.58
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSessionAccept.cc:60
(accept)> (http_seq) [HttpSessionAccept:mainEvent 0x2aaae3689778] accepted
connection from 127.0.0.1:33333 transport type = 0
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <Http1ClientSession.cc:170
(new_connection)> (http_cs) [10237] session born, netvc 0x2aaae3689778
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG:
<ProxyClientTransaction.cc:46 (new_transaction)> (http_txn) [0] Starting
transaction 1 using sm [10237]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:2641
(main_handler)> (http) [10237] [HttpSM::main_handler, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:619
(state_read_client_request_header)> (http) [10237]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:2641
(main_handler)> (http) [10237] [HttpSM::main_handler, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:619
(state_read_client_request_header)> (http) [10237]
[&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:769
(state_read_client_request_header)> (http) [10237] done parsing client request
header
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1112
(ModifyRequest)> (http_trans) START HttpTransact::ModifyRequest
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:8386
(ink_cluster_time)> (http_trans) [ink_cluster_time] local: 1482363281,
highest_delta: 0, cluster: 1482363281
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1203
(ModifyRequest)> (http_trans) END HttpTransact::ModifyRequest
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1205
(ModifyRequest)> (http_trans) Checking if transaction wants to upgrade
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpTransact.cc:1212
(ModifyRequest)> (http_trans) Next action SM_ACTION_API_READ_REQUEST_HDR;
HttpTransact::StartRemapRequest
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:7085
(call_transact_and_set_next_state)> (http) [10237] State Transition:
SM_ACTION_UNDEFINED -> SM_ACTION_API_READ_REQUEST_HDR
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1448
(state_api_callout)> (http) [10237] calling plugin on hook
TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x180afe0
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DIAG: (ts_lua)
[globalHookHandler] req_id: 10235
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DIAG: (ts_lua)
[globalHookHandler] has txn hook -> adding txn close hook handler to release
resources
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1332
(state_api_callback)> (http) [10237] [&HttpSM::state_api_callback,
HTTP_API_CONTINUE]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1372
(state_api_callout)> (http) [10237] [&HttpSM::state_api_callout,
HTTP_API_CONTINUE]
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DEBUG: <HttpSM.cc:1448
(state_api_callout)> (http) [10237] calling plugin on hook
TS_HTTP_READ_REQUEST_HDR_HOOK at hook 0x2aaae364a100
[Dec 21 15:34:41.071] Server {0x2aaab5312700} DIAG: (ts_lua) http://10.12.17.58
Thanks,
Di Li
