You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@trafficserver.apache.org by "Kunal Gulati (JIRA)" <ji...@apache.org> on 2015/03/20 18:26:38 UTC
[jira] [Created] (TS-3460) Traffic Server doesn't count bytes
transferred correctly on SSL Sessions
Kunal Gulati created TS-3460:
--------------------------------
Summary: Traffic Server doesn't count bytes transferred correctly on SSL Sessions
Key: TS-3460
URL: https://issues.apache.org/jira/browse/TS-3460
Project: Traffic Server
Issue Type: Bug
Components: SSL
Reporter: Kunal Gulati
Following API return incorrect values for SSL sessions (In case client hasn't yet send a TCP FIN or it is long running SSL session[For eg messenger]
TSHttpTxnClientReqHdrBytesGet(txnp);
TSHttpTxnClientReqBodyBytesGet(txnp);
TSHttpTxnClientRespHdrBytesGet(txnp);
TSHttpTxnClientRespBodyBytesGet(txnp);
This issue is reproducible on ATS 4.2,4.3,5.2 and Tip of Tree
(Not sure how to add stack trace and wireshark captures)
Not working
Breakpoint 1, debug_print_session (txnp=0x7ffff0bad9f0) at ./tcpinfo.cc:243
243 in_bytes = TSHttpTxnClientReqHdrBytesGet(txnp);
(gdb) p in_bytes
$8 = 7440486
(gdb) backtrace
#0 debug_print_session (txnp=0x7ffff0bad9f0) at ./tcpinfo.cc:243
#1 0x00007ffff2ed6831 in tcp_info_hook (contp=0x1117990, event=TS_EVENT_HTTP_TXN_CLOSE, edata=0x7ffff0bad9f0) at ./tcpinfo.cc:274
#2 0x00000000004f3771 in INKContInternal::handle_event (this=0x1117990, event=60012, edata=0x7ffff0bad9f0) at InkAPI.cc:997
#3 0x00000000004ea812 in Continuation::handleEvent (this=0x1117990, event=60012, data=0x7ffff0bad9f0) at ../iocore/eventsystem/I_Continuation.h:146
#4 0x00000000004f4090 in APIHook::invoke (this=0x11189f0, event=60012, edata=0x7ffff0bad9f0) at InkAPI.cc:1216
#5 0x000000000056903e in HttpSM::state_api_callout (this=0x7ffff0bad9f0, event=0, data=0x0) at HttpSM.cc:1410
#6 0x000000000057559f in HttpSM::do_api_callout_internal (this=0x7ffff0bad9f0) at HttpSM.cc:4767
#7 0x0000000000581ebe in HttpSM::do_api_callout (this=0x7ffff0bad9f0) at HttpSM.cc:497
#8 0x000000000057abfc in HttpSM::kill_this (this=0x7ffff0bad9f0) at HttpSM.cc:6443
#9 0x000000000056ccc4 in HttpSM::main_handler (this=0x7ffff0bad9f0, event=2301, data=0x7ffff0baf5f8) at HttpSM.cc:2545
#10 0x00000000004ea812 in Continuation::handleEvent (this=0x7ffff0bad9f0, event=2301, data=0x7ffff0baf5f8) at ../iocore/eventsystem/I_Continuation.h:146
#11 0x00000000005b814c in HttpTunnel::main_handler (this=0x7ffff0baf5f8, event=105, data=0x7fffec015ed0) at HttpTunnel.cc:1504
#12 0x00000000004ea812 in Continuation::handleEvent (this=0x7ffff0baf5f8, event=105, data=0x7fffec015ed0) at ../iocore/eventsystem/I_Continuation.h:146
#13 0x00000000006cd798 in read_signal_and_update (event=105, vc=0x7fffec015dc0) at UnixNetVConnection.cc:138
#14 0x00000000006d0bd2 in UnixNetVConnection::mainEvent (this=0x7fffec015dc0, event=1, e=0x1097e20) at UnixNetVConnection.cc:1063
#15 0x00000000004ea812 in Continuation::handleEvent (this=0x7fffec015dc0, event=1, data=0x1097e20) at ../iocore/eventsystem/I_Continuation.h:146
#16 0x00000000006c7de9 in InactivityCop::check_inactivity (this=0x107ff10, event=2, e=0x1097e20) at UnixNet.cc:67
#17 0x00000000004ea812 in Continuation::handleEvent (this=0x107ff10, event=2, data=0x1097e20) at ../iocore/eventsystem/I_Continuation.h:146
#18 0x00000000006f01b3 in EThread::process_event (this=0x7ffff524c010, e=0x1097e20, calling_code=2) at UnixEThread.cc:145
#19 0x00000000006f058f in EThread::execute (this=0x7ffff524c010) at UnixEThread.cc:224
#20 0x0000000000512e16 in main (argv=0x7fffffffe718) at Main.cc:1659
(gdb) p in_bytes
$9 = 7440486
(gdb) n
244 in_bytes += TSHttpTxnClientReqBodyBytesGet(txnp);
(gdb) p in_bytes
$10 = 435
(gdb) n
245 out_bytes = TSHttpTxnClientRespHdrBytesGet(txnp);
(gdb) p in_bytes
$11 = 435
(gdb) n
246 out_bytes += TSHttpTxnClientRespBodyBytesGet(txnp);
(gdb) p out_bytes
$12 = 100
(gdb) n
247 total_out_bytes += out_bytes;
(gdb) p out_bytes
$13 = 25122
(gdb) n
248 total_in_bytes += in_bytes;
(gdb) p out_bytes
$14 = 25122
Breakpoint 1, debug_print_session (txnp=0x7ffff0bad9f0) at ./tcpinfo.cc:243
243 in_bytes = TSHttpTxnClientReqHdrBytesGet(txnp);
(gdb) backtrace
#0 debug_print_session (txnp=0x7ffff0bad9f0) at ./tcpinfo.cc:243
#1 0x00007ffff2ed6831 in tcp_info_hook (contp=0x1117990, event=TS_EVENT_HTTP_TXN_CLOSE, edata=0x7ffff0bad9f0) at ./tcpinfo.cc:274
#2 0x00000000004f3771 in INKContInternal::handle_event (this=0x1117990, event=60012, edata=0x7ffff0bad9f0) at InkAPI.cc:997
#3 0x00000000004ea812 in Continuation::handleEvent (this=0x1117990, event=60012, data=0x7ffff0bad9f0) at ../iocore/eventsystem/I_Continuation.h:146
#4 0x00000000004f4090 in APIHook::invoke (this=0x11189f0, event=60012, edata=0x7ffff0bad9f0) at InkAPI.cc:1216
#5 0x000000000056903e in HttpSM::state_api_callout (this=0x7ffff0bad9f0, event=0, data=0x0) at HttpSM.cc:1410
#6 0x000000000057559f in HttpSM::do_api_callout_internal (this=0x7ffff0bad9f0) at HttpSM.cc:4767
#7 0x0000000000581ebe in HttpSM::do_api_callout (this=0x7ffff0bad9f0) at HttpSM.cc:497
#8 0x000000000057abfc in HttpSM::kill_this (this=0x7ffff0bad9f0) at HttpSM.cc:6443
#9 0x000000000056ccc4 in HttpSM::main_handler (this=0x7ffff0bad9f0, event=2301, data=0x7ffff0baf5f8) at HttpSM.cc:2545
#10 0x00000000004ea812 in Continuation::handleEvent (this=0x7ffff0bad9f0, event=2301, data=0x7ffff0baf5f8) at ../iocore/eventsystem/I_Continuation.h:146
#11 0x00000000005b814c in HttpTunnel::main_handler (this=0x7ffff0baf5f8, event=104, data=0x7fffec016710) at HttpTunnel.cc:1504
#12 0x00000000004ea812 in Continuation::handleEvent (this=0x7ffff0baf5f8, event=104, data=0x7fffec016710) at ../iocore/eventsystem/I_Continuation.h:146
#13 0x00000000006cd798 in read_signal_and_update (event=104, vc=0x7fffec016600) at UnixNetVConnection.cc:138
#14 0x00000000006cd958 in read_signal_done (event=104, nh=0x7ffff524fc10, vc=0x7fffec016600) at UnixNetVConnection.cc:168
#15 0x00000000006cdfb2 in read_from_net (nh=0x7ffff524fc10, vc=0x7fffec016600, thread=0x7ffff524c010) at UnixNetVConnection.cc:291
#16 0x00000000006cff63 in UnixNetVConnection::net_read_io (this=0x7fffec016600, nh=0x7ffff524fc10, lthread=0x7ffff524c010) at UnixNetVConnection.cc:835
#17 0x00000000006c799a in NetHandler::mainNetEvent (this=0x7ffff524fc10, event=5, e=0x1097e80) at UnixNet.cc:384
#18 0x00000000004ea812 in Continuation::handleEvent (this=0x7ffff524fc10, event=5, data=0x1097e80) at ../iocore/eventsystem/I_Continuation.h:146
#19 0x00000000006f01b3 in EThread::process_event (this=0x7ffff524c010, e=0x1097e80, calling_code=5) at UnixEThread.cc:145
#20 0x00000000006f0768 in EThread::execute (this=0x7ffff524c010) at UnixEThread.cc:269
#21 0x0000000000512e16 in main (argv=0x7fffffffe718) at Main.cc:1659
(gdb) n
244 in_bytes += TSHttpTxnClientReqBodyBytesGet(txnp);
(gdb) n
245 out_bytes = TSHttpTxnClientRespHdrBytesGet(txnp);
(gdb) n
246 out_bytes += TSHttpTxnClientRespBodyBytesGet(txnp);
(gdb) n
247 total_out_bytes += out_bytes;
(gdb) p in_bytes
$1 = 657
(gdb) p out_bytes
$2 = 25300
(gdb) c
Continuing.
[Mar 20 17:02:42.116] Server {0x7ffff7fea780} DIAG: (tcpinfo) Latest Transaction Close Bytes: In 657 Out 25300 Total In 657 Out 25300
[Mar 20 17:02:42.116] Server {0x7ffff7fea780} DIAG: (tcpinfo) logging hook called for (txn_close) with log object 0x110e9a0
[Mar 20 17:02:42.116] Server {0x7ffff7fea780} DIAG: (tcpinfo) error getting the client socket fd
[Mar 20 17:02:42.116] Server {0x7ffff7fea780} DIAG: (tcpinfo) Finished calling log_tcp_info
Breakpoint 1, debug_print_session (txnp=0x7ffff0bad9f0) at ./tcpinfo.cc:243
243 in_bytes = TSHttpTxnClientReqHdrBytesGet(txnp);
(gdb) p in_bytes
$3 = 7440486
(gdb) n
244 in_bytes += TSHttpTxnClientReqBodyBytesGet(txnp);
(gdb) p in_bytes
$4 = 120
(gdb) n
245 out_bytes = TSHttpTxnClientRespHdrBytesGet(txnp);
(gdb) p in_bytes
$5 = 657
(gdb) n
246 out_bytes += TSHttpTxnClientRespBodyBytesGet(txnp);
(gdb) p out_bytes
$6 = 100
(gdb) n
247 total_out_bytes += out_bytes;
(gdb) p out_bytes
$7 = 25316
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)