On Fri, Feb 12, 2016 at 09:52:22AM -0800, Jonathan Adams wrote: ... > > dtrace: 26719 dynamic variable drops with non-empty dirty list > > SYSCALL COUNT TIME(us) > > fdsync 3 322593 > > rename 4 112 > > stat 11 18 > > lwp_mutex_wakeup 15 78 > > mprotect 23 396 > > pollsys 58 2040311 > > lwp_sigmask 117 349 > > setcontext 117 454 > > lwp_park 320 8525843 > > lwp_mutex_timedlock 364 2030 > > yield 725 568670 > > write 6737 45526 > > open 27491 353860 > > fcntl 27506 54801 > > close 27529 54292 > > lwp_cond_signal 48837 152506 > > lwp_cond_wait 48891 616603479 > > lseek 58049 113307 > > send 72409 267314 > > read 126334 29247492 > > fstat 127719 254078 ... > > # date > > Wed Feb 29 22:40:17 EST 2012 > > # > > ? > > As you can see time of running su was 22:40:12 and the time at the > > exit point? was 22:40:17. That means the dtrace ran for about 5 > > seconds. However, if you sum up the micro seconds, you will see > > 658,607,509 us which is about 658 seconds. > > > > Isn't that strange for you? If you think I am mistaking somewhere, > > please let me know. Otherwise, I will explain with more details later. > > Given that there are calls to lwp_park() and lwp_* calls, this is clearly a > multi-threaded program. So it's easy to imagine that ~100 threads or more > could give you these results.
In addition, several of those system calls are all about waiting for a particular event to occur, and so the thread is asleep and other threads can be making forward progress; lwp_cond_wait(), lwp_park(), and pollsys() in particular. So even on a low-CPU count machine, you could have hundreds of threads sleeping. If you change the script to replace 'timestamp' with 'vtimestamp', that will only record the on-CPU time, which will be much lower, since all time sleeping won't be counted. Then, the maximum total would be (# CPUs * wall time elapsed). Cheers, - jonathan ------------------------------------------- dtrace-discuss Archives: https://www.listbox.com/member/archive/184261/=now RSS Feed: https://www.listbox.com/member/archive/rss/184261/25769126-e243886f Modify Your Subscription: https://www.listbox.com/member/?member_id=25769126&id_secret=25769126-8d47a7b2 Powered by Listbox: http://www.listbox.com
