Re: Interoperability of LTTng and LTTV with SystemTAP (heavy usage)

[Mathieu Desnoyers <compudj at krystal dot dyndns dot org>]

Hi,

Here is, as promised, the rest of the heavy usage scenario requested. It has
been kindly generated by Autodesk partners.

You will find these results much more interesting than the previous ones.

I would be interested to know if SystemTAP can handle an average load of 58K
events per second.

Heavy usage scenario : Trace from Autodesk, 64 bits x86_64, 4 CPUs

621 MB trace. Duration : 9m10s.


Units are in seconds

total :
wall time : 546.479691385 (9m10s)

total cpu time available :
4*546.479691385 = 2185.918765540

total idle time (sum for 4 cpus): 1135.045529154
(time spent in process 0 in "unknown" syscall)

Total cpu time used :
2185.918765540 - 1135.045529154 = 1050.873236386
System load : 1050.873236386/2185.918765540 = 48.07%


lttd :
(note : in the trace, lttd is : pid 11413)

overall cpu time in system call : 3.141004863
  note : in this trace, usermode time is accounted as system call time due
  to a bug in instrumentation of system calls. Autodesk has been informed of
  the problem. Instrumentation set provided by Autodesk is available there :
  http://ltt.polymtl.ca/ > Third party contributions.
overall cpu time in traps : 0.00223371


Time used by lttd :

Percentage of wall time :
3.143238573/2185.918765540 * 100% = 0.144%
Percentage of cpu time :
3.143238573/1050.873236386 *100% = 0.299%


overall event count (for the whole 9m10s on the 4 CPUs)

events count : 31946639

detail per event type

Statistic for  'event_types' :

state_dump_facility_load :  11
wait :  17759
free :  3017
exit :  3017
fork :  3014
soft_irq_entry :  2964643
softirq :  2188180
soft_irq_exit :  2964643
tasklet_entry :  523479
tasklet_exit :  523479
expired :  1061734
wakeup :  1711432
schedchange :  2620332
syscall_entry :  5198 (should be more than that)
write :  322312
read :  614706
syscall_exit :  5180 (should be more than that)
trap_entry :  3799122
trap_exit :  3799122
open :  139309
close :  166203
irq_exit :  886808
packet_in :  145148
packet_out :  122118
page_alloc :  387151
page_free :  3536
irq_entry :  886808
sendmsg :  138882
select :  4715579
recvmsg :  27091
ioctl :  272526
set_itimer :  13725
buf_wait_end :  1485
buf_wait_start :  1484
poll :  811642
seek :  84544
call :  2
shm_create :  1
create :  1567
signal :  7707
exec :  2725
page_wait_end :  109
page_wait_start :  109


Event rate :

over wall time :
31946639/546.479691385 = 58459 events/s

over combined available cpu time :
31946639/2185.918765540 = 14614 events/s


Mathieu Desnoyers


Key fingerprint:     8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68 
OpenPGP public key:              http://krystal.dyndns.org:8080/key/compudj.gpg