Re: LTTng very heavy system usage scenario

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

Well, I finally managed to finish my brand new LTTng+LTTV implementation. This
third usage scenario has been made with it.

I tried something that always turns out to make tracers dead : a loopback ping
flood (ping -f 127.0.0.1). Here are the results :-)

Mathieu


Usage scenario 3

Very heavy system usage (ping flood on the loopback pseudo interface)

Tests made on a 3Ghz pentium 4, with hyperthreading enabled.

Trace taken with LTTng 0.5.0

No event has been lost while tracing.

(units are in seconds)

Trace duration : 12.785209485
Total cpu time available (approximately : it's hyperthreading...) : 25.57s
Trace size : 176M

Trace data rate : 13.76MB/s

idle cpu time : 7.297325362s (sum of the two HT cpus)
System load : (25.57-7.297325362)/25.57 = 71.5%


lttd cpu time (process 4773 in the trace)

usermode : 3.613249328
traps : none
irqs :
21 (3com 3c940 10/100/1000Base-T) : 0.094693456
0 (timer) : 0.015632051
19 (USB and IDE) : 0.000242789
system calls :
unknown (beginning of trace) : 0.000024347
175 (rt_sigprocmask) : 0.352830699
3 (read) : 0.697699884
142 (newselect) : 2.055746440
4 (write) : 1.522248853
54 (ioctl) : 0.000014157

Total cpu time accountable to process :
usermode + traps + system calls
8.241813708


ratio of time for write / cpu time used :
45.10%

ratio of time for write / cpu time available (doesn't mean much with HT) :
32.23%


Overall information on the trace

event count 9588836

Event rate : 749994 events per second

detail per event type (38 event types)

Statistic for  'event_types' :

state_dump_facility_load :  10
exit :  3
wait :  17
free :  3
fork :  3
schedchange :  42076
syscall_entry :  2297497
write :  427383
wakeup :  37268
soft_irq_entry :  309692
softirq :  25105
soft_irq_exit :  309692
read :  166746
syscall_exit :  2297497
expired :  258
irq_exit :  170318
packet_in :  259254
irq_entry :  170318
tasklet_entry :  62
tasklet_exit :  62
packet_out :  408715
trap_exit :  2448
call :  386428
recvmsg :  258803
close :  93
trap_entry :  2448
select :  1406394
buf_wait_start :  19
page_alloc :  478581
buf_wait_end :  19
create :  8
sendmsg :  127608
poll :  3449
ioctl :  443
open :  79
set_itimer :  11
page_free :  3
exec :  4
seek :  19



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