Skip to content

Instantly share code, notes, and snippets.

@Antnee

Antnee/strace.txt

Last active November 19, 2019 16:43
Show Gist options
  • Save Antnee/21112d64467f1d09b11428321625f65e to your computer and use it in GitHub Desktop.
Save Antnee/21112d64467f1d09b11428321625f65e to your computer and use it in GitHub Desktop.
Download ZIP
Slow Xdebug 2.8.0 Strace
Raw
strace.txt
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
29.16 0.034135 2 20437 9 open
19.65 0.022995 1 20456 close
14.39 0.016840 1 25138 10055 access
8.61 0.010082 1 14542 poll
6.81 0.007972 1 5622 45 stat
4.65 0.005440 1 10127 17 lstat
4.26 0.004985 0 11774 write
4.08 0.004771 1 3333 getdents
3.90 0.004559 0 45619 read
2.54 0.002969 0 40045 fstat
0.75 0.000883 0 17450 lseek
0.46 0.000542 0 6414 sendto
0.40 0.000465 0 2562 munmap
0.15 0.000170 0 4290 getcwd
0.14 0.000164 0 2696 mmap
0.06 0.000070 1 127 mprotect
0.00 0.000000 0 302 brk
0.00 0.000000 0 80 rt_sigaction
0.00 0.000000 0 2 rt_sigprocmask
0.00 0.000000 0 23 13 ioctl
0.00 0.000000 0 4 pipe
0.00 0.000000 0 172 madvise
0.00 0.000000 0 883 getpid
0.00 0.000000 0 17 socket
0.00 0.000000 0 15 10 connect
0.00 0.000000 0 9425 recvfrom
0.00 0.000000 0 14 setsockopt
0.00 0.000000 0 7 getsockopt
0.00 0.000000 0 2 clone
0.00 0.000000 0 3 1 execve
0.00 0.000000 0 2 wait4
0.00 0.000000 0 86 uname
0.00 0.000000 0 27 fcntl
0.00 0.000000 0 2 chdir
0.00 0.000000 0 12 unlink
0.00 0.000000 0 5 readlink
0.00 0.000000 0 2 getrlimit
0.00 0.000000 0 1 sysinfo
0.00 0.000000 0 2 arch_prctl
0.00 0.000000 0 21 futex
0.00 0.000000 0 1 set_tid_address
0.00 0.000000 0 4 newfstatat
0.00 0.000000 0 1 set_robust_list
0.00 0.000000 0 5 sendmmsg
0.00 0.000000 0 1717 getrandom
------ ----------- ----------- --------- --------- ----------------
100.00 0.117042 243469 10150 total
@Antnee
Copy link
Author

Antnee commented Nov 19, 2019

Here's a quick example of the sort of thing that I'm getting from a strace -r -Tfe trace=open vendor/bin/phpunit --testdox --colors=always --coverage-html report command:

 ◓ running tests     0.971306 open("/var/www/html/tests/../spool/phpunit", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 9 <0.001046>
 ◑ running tests     0.557823 open("/var/www/html/vendor/phpunit/phpunit/src/Framework/MockObject/Matcher/ConsecutiveParameters.php", O_RDONLY) = 9 <0.000551>
     0.020636 open("/var/www/html/vendor/phpunit/phpunit/src/Framework/MockObject/Stub/ConsecutiveCalls.php", O_RDONLY) = 9 <0.000791>
     0.053992 open("/var/www/html/src/Foo.php", O_RDONLY) = 9 <0.000989>
     1.311633 open("/var/www/html/vendor/phpunit/phpunit/src/Framework/MockObject/Stub/ConsecutiveCalls.php", O_RDONLY) = 9 <0.001083>
     0.006750 open("/var/www/html/src/Foo.php", O_RDONLY) = 9 <0.001176>
     0.005525 open("/var/www/html/vendor/phpunit/phpunit/src/Framework/MockObject/Matcher/ConsecutiveParameters.php", O_RDONLY) = 9 <0.000333>
     0.009173 open("/var/www/html/src/Foo.php", O_RDONLY) = 9 <0.000794>
     0.003583 open("/var/www/html/src/Foo.php", O_RDONLY) = 9 <0.000782>
 ◒ running tests     0.085541 open("/var/www/html/src/Bar.php", O_RDONLY) = 9 <0.000818>

App filenames obfuscated

There are a lot of very slow opens, and they come from all over the app, not just in the vendor/ directory as displayed above; I have them all over the app, and there's no obvious pattern to it, either

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment