This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
Re: [ltt-dev] Re: Interoperability of LTTng and LTTV with SystemTAP (heavy usage)
- From: Mathieu Desnoyers <compudj at krystal dot dyndns dot org>
- To: ltt-dev at shafik dot org, systemtap at sources dot redhat dot com
- Date: Sat, 17 Dec 2005 15:00:26 -0500
- Subject: Re: [ltt-dev] Re: Interoperability of LTTng and LTTV with SystemTAP (heavy usage)
- References: <20051214022515.GA1488@Krystal> <20051216010459.GA11668@Krystal>
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