[linux] strace -o bestand programma

[Paul Slootman]

On Fri 04 Dec 2020, Daniel C. von Asmuth wrote:

> > >> > > > > Een manier om zoiets te onderzoeken is met het volgende commando:
> > >> > > > >
> > >> > > > >         strace -T -o trace.txt vlc

Ik zou er -f bijzetten, dan zie je ook alle threads en evt. geforkte
processen.

> clone(child_stack=0x7fbe9980bf30, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tid=[21305], tls=0x7fbe9980c700, child_tidptr=0x7fbe9980c9d0) = 21305 <0.000028>
> rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM CHLD], NULL, 8) = 0 <0.000004>
> futex(0x7fbe9c2840a0, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = 0 <25.521139>
> futex(0x560d7c737f98, FUTEX_WAKE_PRIVATE, 1) = 1 <0.000011>
> rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM], NULL, 8) = 0 <0.000022>
> rt_sigaction(SIGHUP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0 <0.000060>
> rt_sigtimedwait([HUP INT QUIT TERM], {si_signo=SIGINT, si_code=SI_KERNEL}, NULL, 8) = 2 (SIGINT) <152.944456>
> rt_sigaction(SIGINT, {sa_handler=SIG_IGN, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fbe9f8d2210}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0 <0.000037>
> rt_sigaction(SIGALRM, {sa_handler=0x560d7c67c980, sa_mask=[ALRM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7fbe9f8d2210}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0 <0.000104>
> rt_sigprocmask(SIG_UNBLOCK, [INT ALRM], NULL, 8) = 0 <0.000027>
> alarm(3)                                = 0 <0.000018>
> getpid()                                = 21299 <0.000016>
> tgkill(21299, 21299, SIGTERM)           = 0 <0.000019>
> 
> In bovenstaande zie je de enige twee system calls die veel tijd kostten. De laatste bijna
> 153 seconden - ik neem aan dat dat Harry's <Ctrl-C> was (gerekend vanaf het opstarten
> van het programma). Het programma stopt niet onmiddellijk, maar sluit daarna snel af.
> 
> Daarvoor gebeurt iets verdachts: een futex system call die de aanroepende thread
> ruim 25 seconden liet wachten. Het adres 0x7fbe9c2840a0 komt verder nergens in
> de trace voor, dus veel wijzer maakt dat ons niet. Het bevestigt in ieder geval

Hoogstewaarschijnlijk omdat een andere thread iets aan het doen is, wat
weten we nu niet. Daar worden zulke futex'en ook voor gebruikt: om
threads te synchroniseren.


Paul