DTrace: printf debugging for seventh-level wizards

Transcript

1. @sartak
   DTRACE
   printf debugging for seventh-level wizards
   12೥1݄14೔౔༵೔
   

   View Slide

2. ME ME ME ME ME ME ME
   Shawn M Moore
   @sartak
   I’m Bawstin’
   Moose-lover
   Infinity Interactive
   12೥1݄14೔౔༵೔
   

   View Slide

3. What’s my computer doing right now?
   Q:
   A: Find out with DTrace
   12೥1݄14೔౔༵೔
   

   View Slide

4. iotop
   $ iotop
   dtrace: failed to initialize dtrace:
   DTrace requires additional privileges
   You may already have DTrace
   and not even know it.
   12೥1݄14೔౔༵೔
   

   View Slide

5. Solaris & OS X (complete)
   Linux (partial)
   Profiler
   (Different and deeper than NYTProf)
   Debugger
   Kernel module
   “You don’t port DTrace to an OS,
   you port an OS to DTrace”
   DTRACE
   12೥1݄14೔౔༵೔
   

   View Slide

6. SAFE!
   ɾNo unwanted side effects
   ɾVery low overhead
   ɾDo it in production!
   12೥1݄14೔౔༵೔
   

   View Slide

7. σϞ
   pidpersec
   iotop
   execsnoop
   opensnoop
   dtruss
   plockstat
   iosnoop
   Global (high level)
   The metal (low level)
   12೥1݄14೔౔༵೔
   

   View Slide

8. σϞ
   pidpersec
   iotop
   execsnoop
   opensnoop
   dtruss
   plockstat
   iosnoop
   Global (high level)
   The metal (low level)
   12೥1݄14೔౔༵೔
   

   View Slide

9. PROGRAMMABILITY
   dtrace -n '
   syscall::open:entry
   /strstr(copyinstr(arg0), "corpus") != NULL/ {
   printf("%s %s",execname,copyinstr(arg0));
   }'
   Show processes that open a file whose name
   includes “corpus”
   12೥1݄14೔౔༵೔
   

   View Slide

10. PROGRAMMABILITY
    dtrace -n '
    syscall::open:entry
    /strstr(copyinstr(arg0), "corpus") != NULL/ {
    printf("%s %s",execname,copyinstr(arg0));
    }'
    Show processes that open a file whose name
    includes “corpus”
    Event(Probe Description)
    12೥1݄14೔౔༵೔
    

    View Slide

11. PROGRAMMABILITY
    dtrace -n '
    syscall::open:entry
    /strstr(copyinstr(arg0), "corpus") != NULL/ {
    printf("%s %s",execname,copyinstr(arg0));
    }'
    Show processes that open a file whose name
    includes “corpus”
    Predicate
    12೥1݄14೔౔༵೔
    

    View Slide

12. PROGRAMMABILITY
    dtrace -n '
    syscall::open:entry
    /strstr(copyinstr(arg0), "corpus") != NULL/ {
    printf("%s %s",execname,copyinstr(arg0));
    }'
    Show processes that open a file whose name
    includes “corpus”
    Action
    12೥1݄14೔౔༵೔
    

    View Slide

13. PROGRAMMABILITY
    dtrace -n '
    syscall::open:entry
    /strstr(copyinstr(arg0), "corpus") != NULL/ {
    printf("%s %s",execname,copyinstr(arg0));
    }'
    Show processes that open a file whose name
    includes “corpus”
    12೥1݄14೔౔༵೔
    

    View Slide

14. DTrace instrumentation points
    ɾKernel function calls/returns (syscalls too)
    ɾPerl function calls/returns
    ɾSQL execution
    ɾthreads
    ɾsignals
    ɾmany more
    PROBES
    12೥1݄14೔౔༵೔
    

    View Slide

15. THE COOL DEMO
    HEY, FORGETFUL!
    DEMO THE GPG THING
    12೥1݄14೔౔༵೔
    

    View Slide

16. PROFILER
    Devel::NYTProf
    kicks
    ass
    12೥1݄14೔౔༵೔
    

    View Slide

17. PROFILER
    But
    there’s
    more
    than
    one
    way
    to
    do
    it
    12೥1݄14೔౔༵೔
    

    View Slide

18. PROFILER
    DEMO:
    syscalls
    intuit_method
    12೥1݄14೔౔༵೔
    

    View Slide

19. XCode’s profiler uses DTrace
    12೥1݄14೔౔༵೔
    

    View Slide

20. 12೥1݄14೔౔༵೔
    

    View Slide

21. TRANSLATION
    “I am comfortable being
    ignorant and helpless”
    12೥1݄14೔౔༵೔
    

    View Slide

22. DEBUGGER
    Request Tracker (e.g. rt.cpan.org)
    was failing tests on mod_perl.
    On only my computer.
    Probably because of all the Japanese.
    12೥1݄14೔౔༵೔
    

    View Slide

23. DEBUGGER
    Failed test
    'gpg: error reading key: ެ։伴͕ݟ͔ͭΓ·ͤΜ'
    doesn't match '(?-xism:public key not found)'
    12೥1݄14೔౔༵೔
    

    View Slide

24. DEBUGGER
    ެ։伴͕ݟ͔ͭΓ·ͤΜ
    isn’t part of RT’s Japanese i18n
    12೥1݄14೔౔༵೔
    

    View Slide

25. DEBUGGER
    ެ։伴͕ݟ͔ͭΓ·ͤΜ
    possibly from GPG’s i18n?
    12೥1݄14೔౔༵೔
    

    View Slide

26. DEBUGGER
    gpg-2.0.18 $ ack -a ެ։伴͕ݟ͔ͭΓ·ͤΜ
    gpg-2.0.18 $
    12೥1݄14೔౔༵೔
    

    View Slide

27. DEBUGGER
    gpg-2.0.18 $ echo "ެ։伴͕ݟ͔ͭΓ·ͤΜ" |
    iconv -f UTF-8 -t EUCJP | xargs ack -ao |
    iconv -f EUCJP -t UTF-8
    Binary file po/ja.gmo matches
    po/ja.po:2965:ެ։伴͕ݟ͔ͭΓ·ͤΜ
    po/ja.po:6525:ެ։伴͕ݟ͔ͭΓ·ͤΜ
    po/ja.po:8311:ެ։伴͕ݟ͔ͭΓ·ͤΜ
    gpg-2.0.18 $
    12೥1݄14೔౔༵೔
    

    View Slide

28. DEBUGGER
    probably a mis-set $LANG, $LC_ALL?
    12೥1݄14೔౔༵೔
    

    View Slide

29. DEBUGGER
    Ͱ΋
    LC_ALL=en gpg
    LC_ALL=ja gpg
    LC_ALL= gpg
    opensnoop
    12೥1݄14೔౔༵೔
    

    View Slide

30. DEBUGGER
    Without DTrace,
    woulda had to add
    print statements
    to GPG itself
    12೥1݄14೔౔༵೔
    

    View Slide

31. DEBUGGER
    then compiled it
    12೥1݄14೔౔༵೔
    

    View Slide

32. DEBUGGER
    then installed it
    12೥1݄14೔౔༵೔
    

    View Slide

33. DEBUGGER
    then repeated a couple of times
    because I’m a
    “throw everything til something sticks”
    kinda guy
    12೥1݄14೔౔༵೔
    

    View Slide

34. DEBUGGER
    then cleaned up after all that hot mess
    12೥1݄14೔౔༵೔
    

    View Slide

35. DEBUGGER
    DTrace is great for
    debugging interactions
    between programs
    12೥1݄14೔౔༵೔
    

    View Slide

36. DEBUGGER
    DTrace is great for
    debugging interactions
    between
    YOUR BEAUTIFUL CODE
    and
    THE IDIOTS
    12೥1݄14೔౔༵೔
    

    View Slide

37. Perl
    ɾ5.10.0+: sub-entry, sub-return
    ɾ5.15.1+: phase-change (${^GLOBAL_PHASE})
    ɹ
    ɾFuture?: string eval, etc.
    perldoc perldtrace
    12೥1݄14೔౔༵೔
    

    View Slide

38. Perl
    ɾ5.10.0Ҏ߱: sub-entry, sub-return
    ɾ5.15.1Ҏ߱: phase-change
    ɹ
    ɾকདྷʁ: string eval౳
    My first Perl patch!
    Was simple!
    perldtrace
    12೥1݄14೔౔༵೔
    

    View Slide

39. QUESTIONS?
    ೔ຊޠͰ΋̤̠Ͱ͢ʂ
    slides: http://twitter.com/sartak
    12೥1݄14೔౔༵೔
    

    View Slide