Re: [ltt-dev] Re: Interoperability of LTTng and LTTV with SystemTAP (heavy usage)

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

Time used for probe sites in heavy usage scenario (scenario 2) :

31946639 events * 220ns = 7.02s

Probe time / used cpu time
7.02/1050.873236386*100% = 0.67%

Probe time / available cpu time
7.02/2185.918765540*100% = 0.32%


Mathieu

* Mathieu Desnoyers (compudj@krystal.dyndns.org) wrote:
> 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
> _______________________________________________
> ltt-dev mailing list
> ltt-dev@listserv.shafik.org
> http://www.listserv.shafik.org/listserv/listinfo/ltt-dev
> 
OpenPGP public key:              http://krystal.dyndns.org:8080/key/compudj.gpg
Key fingerprint:     8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68