Missing size_rcv in certain cases

[tisba]

I'm still investigating what actually happens, but here is what I have observed so far.

• The test type was HTTP
• using traffic dump, we saw almost 100% error_no_http_status status codes: 1481819141.918814;<0.667.0>;1320;get;host.example.com;/path;error_no_http_status;0;57.704;-;;;. I guess this happened because the target system was quite overloaded.
• size_rcv reported in tsung.log was always 0 during the time we saw only error_no_http_status. It was okay before we saw the error_no_http_status responses.
• System monitoring and tsung's own os_mon reported traffic though: stats: {recvpackets,"os_mon@ip-172-31-8-102"} 1 4836.0 0.0 4836 205 1768.059190031152 321

See example stats dump from tsung.log:

# stats: dump at 1481819071
stats: users 2900 2900
stats: {recvpackets,"os_mon@HOSTNAME"} 1 4013.0 0.0 4648 180 1754.417445482866 321
stats: {sentpackets,"os_mon@HOSTNAME"} 1 4272.0 0.0 4941 171 1830.323987538942 321
stats: {cpu,"os_mon@HOSTNAME"} 1 5.8734177215189876 0.0 31.291591046581974 0.3001500750375188 2.5174925442795377 322
stats: {load,"os_mon@HOSTNAME"} 1 0.01953125 0.0 1.78125 0.0 0.0635432841614907 322
stats: {freemem,"os_mon@HOSTNAME"} 1 3176.27734375 0.0 3403.55859375 3176.27734375 3300.2474160520187 322
stats: {recvpackets,"os_mon@HOSTNAME"} 1 4836.0 0.0 4836 205 1768.059190031152 321
stats: {sentpackets,"os_mon@HOSTNAME"} 1 5102.0 0.0 5102 214 1849.031152647974 321
stats: {freemem,"os_mon@HOSTNAME"} 1 3179.26953125 0.0 3403.0546875 3179.26953125 3302.280922457298 322
stats: {cpu,"os_mon@HOSTNAME"} 1 8.9 0.0 30.066195276064388 0.3498250874562719 2.848366680014288 322
stats: {load,"os_mon@HOSTNAME"} 1 0.0 0.0 2.25 0.0 0.08161750389408108 321
stats: {freemem,"os_mon@HOSTNAME"} 1 3190.63671875 0.0 3400.6796875 3186.94921875 3308.8615410825537 321
stats: {freemem,"tsung_controller@ip-172-31-9-56"} 1 3408.203125 0.0 3431.88671875 3393.84765625 3413.069863645187 322
stats: {load,"os_mon@HOSTNAME"} 1 0.12109375 0.0 2.19921875 0.0 0.08688373447204961 322
stats: {load,"os_mon@HOSTNAME"} 1 0.01171875 0.0 2.1796875 0.0 0.0995608501552795 322
stats: {recvpackets,"os_mon@HOSTNAME"} 1 3879.0 0.0 4630 188 1748.8909657320871 321
stats: {sentpackets,"os_mon@HOSTNAME"} 1 4101.0 0.0 4924 183 1828.7538940809961 321
stats: {freemem,"os_mon@HOSTNAME"} 1 3181.49609375 0.0 3409.41015625 3178.62109375 3301.217391304348 322
stats: {recvpackets,"os_mon@HOSTNAME"} 1 3917.0 0.0 4731 190 1758.0093457943929 321
stats: {sentpackets,"os_mon@HOSTNAME"} 1 4188.0 0.0 4976 188 1837.1588785046729 321
stats: {cpu,"os_mon@HOSTNAME"} 1 4.090909090909091 0.0 29.58682679960722 0.15182186234817813 2.2957231138241165 322
stats: {load,"os_mon@HOSTNAME"} 1 0.26171875 0.0 2.23828125 0.0 0.09761985636645959 322
stats: {cpu,"os_mon@HOSTNAME"} 1 5.5193176116407425 0.0 31.417010230569552 0.15052684395383845 1.7959747674470707 322
stats: {freemem,"os_mon@HOSTNAME"} 1 3197.3984375 0.0 3417.9765625 3197.3984375 3313.274019798138 322
stats: {recvpackets,"os_mon@HOSTNAME"} 1 4144.0 0.0 4637 196 1752.7906249999992 320
stats: {sentpackets,"os_mon@HOSTNAME"} 1 4421.0 0.0 4854 183 1831.5968750000006 320
stats: {load,"tsung_controller@ip-172-31-9-56"} 1 0.0 0.0 2.6015625 0.0 0.06178425854037267 322
stats: {recvpackets,"tsung_controller@ip-172-31-9-56"} 1 2667.0 0.0 3524 748 1865.1682242990655 321
stats: {sentpackets,"tsung_controller@ip-172-31-9-56"} 1 2561.0 0.0 3613 763 1877.6760124610591 321
stats: {cpu,"os_mon@HOSTNAME"} 1 4.411764705882353 0.0 5.311077389984825 0.20030045067601399 1.8518106271593886 321
stats: {cpu,"tsung_controller@HOSTNAME"} 1 0.6555723651033787 0.0 34.39880900253963 0.15067805123053743 0.9073521586564877 322
stats: session 0 0 0 1657.4560546875 1657.4560546875 1657.4560546875 1
stats: users_count 0 2901
stats: finish_users_count 0 1
stats: request 1817 66.75524573150288 12.390001548417176 19198.837158203125 3.6708984375 2099.6608012568536 302822
stats: connect 1818 21.087016794941206 17.62213867947525 5060.239990234375 0.466796875 20.45062261225243 193370
stats: page 1772 68.4549103127645 15.751193798713032 29431.10498046875 3.6708984375 2160.542457233537 294290
stats: 200 0 99081
stats: size_rcv 0 116884028
stats: newphase 0 30
stats: error_json_unparsable 45 5512
stats: size_sent 1016224 169026041
stats: connected 1 5
stats: error_json_not_parsed 45 5512
stats: 204 0 694
stats: 201 0 11854
stats: 503 0 7953
stats: 404 0 334

size_rcv was exactly 0 and size_sent was non zero. That makes no sense for a ~20 minute period.

My suspicion is, that the size_rcv is not properly calculated (or maybe even skipped?) when error_no_http_status happened.

[tisba]

I just cannot wrap my head around, why exactly the HTTP status code could not be determined. As far as I can tell none is the default in the http#status record and for some reason ts_http_common:parse_status/2 was not called or did not update the value. Unfortunately I have not yet figured out, how to reliably reproduce that behavior.

For the reason size_rcv is not counted, I guess we have to look around ts_client:handle_data_msg. I think we do not call ts_mon:add with size_rcv in case we get too little data. Can you maybe help to trace this down, @nniclausse?