drbdump

drbdump is a tcpdump-like tool for the dRuby protocol. It allows you to inspect the message and analyze the messages sent between your DRb-using processes.

This presentation was given at dRuby Hiroba 2013

Transcript

1. drbdump Eric Hodel - drbrain@segment7.net Sunday, June 2, 13
2. Links • Gem: gem install drbdump https://rubygems.org/gems/drbdump • Source: https://github.com/drbrain/drbdump Sunday, June 2, 13
3. drbdump • Like tcpdump • Understands messages • Tracks Marshal allocations • Tracks latency Sunday, June 2, 13
4. Problems • Out-of-order TCP • mDNS • resolv.rb, partial patch • No filtering • IPv6 (bug) Sunday, June 2, 13
5. Running • Basic drbdump • Summary of 10,000 messages drbdump -q -n -c 10000 • Listen only on loopback drbdump -i lo0 Sunday, June 2, 13
6. Demo $ cd $(dirname $(gem which drbdump))/.. $ ruby example/... Sunday, June 2, 13
7. dRuby Protocol • Peer to Peer • Message → Result • 1 to ∞ messages per connection • TCP, UNIX, SSL, etc. • drbdump is TCP-only Sunday, June 2, 13
8. Message Chunk • Chunk size • 32-bit little-endian integer • Marshal stream "\x00\x00\x00\x03\x04\x08T" Sunday, June 2, 13
9. Message Send • Receiver • nil or object id • Method name • Argument count • Arguments • Block or nil Sunday, June 2, 13
10. Message Result • Message status • true → success • false → exception • Result or Exception Sunday, June 2, 13
11. drbdump loop Get packet Add to stream Find first chunk Load Error Ignore stream Determine type Update statistics Display packet Sunday, June 2, 13
12. Message-send Output 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
13. Timestamp 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
14. Source 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
15. Message-send 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
16. Receiver 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
17. Method Name 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
18. Arguments 17:34:49.546074 "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) Sunday, June 2, 13
19. Debug with irb …⋯ ⇒ ("druby://10.101.28.77:60913", 70180390657240). respond_to?(:update, false) ^C $ irb -r drb >> DRb.start_service >> DRb::DRbObject.new_with( "druby://10.101.28.77:60913", 70180390657240) Sunday, June 2, 13
20. Message-result Output 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
21. Timestamp 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
22. Destination 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
23. Message-result 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
24. Source 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
25. Status 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
26. Result Object 17:34:49.546531 "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" success: true Sunday, June 2, 13
27. Exception Result 17:34:49.563440 "druby://10.101.28.77:60929" ⤂ "druby://10.101.28.77:60920" exception: #<LocalJumpError: break from proc-closure> Sunday, June 2, 13
28. Exception 17:34:49.563440 "druby://10.101.28.77:60929" ⤂ "druby://10.101.28.77:60920" exception: #<LocalJumpError: break from proc-closure> Sunday, June 2, 13
29. Exception Object 17:34:49.563440 "druby://10.101.28.77:60929" ⤂ "druby://10.101.28.77:60920" exception: #<LocalJumpError: break from proc-closure> Sunday, June 2, 13
30. Easy to Match "druby://10.101.28.77:60919" ⇒ ("druby://10.101.28.77:60913" "druby://10.101.28.77:60919" ⾨ "druby://10.101.28.77:60913" "druby://10.101.28.77:60929" ⇒ ("druby://10.101.28.77:60920" "druby://10.101.28.77:60929" ⤂ "druby://10.101.28.77:60920" Sunday, June 2, 13
31. Statistics Output • Basic statistics • Packets, messages, results • Message statistics • Allocations, latency • Peer statistics • Latency Sunday, June 2, 13
32. Basic Statistics 1508 total packets captured 0 Rinda packets captured 56 DRb packets captured 30 messages sent 26 results received 2 exceptions raised Sunday, June 2, 13
33. Message Statistics Messages sent min, avg, max, stddev: call (1 args) 10 sent; 3.0, 6.2, 19.0, 6.7 allocations; 0.285, 1.479, 7.258, 2.171 ms Sunday, June 2, 13
34. Peer Statistics Peers min, avg, max, stddev: 6 messages: "druby://10.101.28.77:60928" to "druby://10.101.28.77:60910"; 0.623, 1.632, 4.877, 1.618 ms Sunday, June 2, 13
35. Peer Statistics Peers min, avg, max, stddev: [...] 4 single-message peers 0.307, 0.791, 1.568, 0.547 ms Sunday, June 2, 13
36. capp • libpcap wrapper • GVL-friendly • MIT license • Simple interface Sunday, June 2, 13
37. capp capp = Capp.live capp.filter = '...' Thread.new do capp.loop do |packet| @queue.enq packet end @queue << nil # no more packets end Sunday, June 2, 13
38. capp Thread.new do while packet = @queue.deq do process packet end end Sunday, June 2, 13
39. capp Thread process packet Queue packet = queue.deq Thread capp_loop() acquire GVL queue.enq packet Sunday, June 2, 13
40. capp Thread Thread process packet Queue Queue acquire GVL capp_loop() queue.enq packet packet = queue.deq Thread capp_loop() acquire GVL queue.enq packet Sunday, June 2, 13
41. capp Capp.open 'lo0' Capp.open 'capture.pcap' Capp.devices # devices and addresses Capp.drop_privileges # for safety capp.stop # end capture Sunday, June 2, 13
42. marshal-structure • Marshal parser • Tracks allocations Sunday, June 2, 13
43. marshal-structure s = Marshal::Structure.new \ Marshal.dump %w[a b] s.count_allocations #=> 4 s.load #=> ["a", "b"] Sunday, June 2, 13
44. marshal-structure s = Marshal::Structure.new \ Marshal.dump %w[a b] s.count_allocations #=> 4 s.load #=> ["a", "b"] Hidden Encoding instance variable Sunday, June 2, 13
45. token_stream s.token_stream.to_a #=> [ :array, 2, :instance_variables, :string, "a", 1, :symbol, "E", :true, :instance_variables, :string, "b", 1, :symbol_link, 0, :true] Sunday, June 2, 13
46. structure s.structure #=> [ :array, 0, 2, [:instance_variables, [:string, 1, "a"], 1, [:symbol, 0, "E"], :true], [:instance_variables, [:string, 2, "b"], 1, [:symbol_link, 0], :true]] Sunday, June 2, 13
47. structure s.structure #=> [ :array, 0, 2, [:instance_variables, [:string, 1, "a"], 1, [:symbol, 0, "E"], :true], [:instance_variables, [:string, 2, "b"], 1, [:symbol_link, 0], :true]] Reference ID Sunday, June 2, 13
48. structure s.structure #=> [ :array, 0, 2, [:instance_variables, [:string, 1, "a"], 1, [:symbol, 0, "E"], :true], [:instance_variables, [:string, 2, "b"], 1, [:symbol_link, 0], :true]] Reference ID Sunday, June 2, 13
49. structure s.structure #=> [ :array, 0, 2, [:instance_variables, [:string, 1, "a"], 1, [:symbol, 0, "E"], :true], [:instance_variables, [:string, 2, "b"], 1, [:symbol_link, 0], :true]] Reference ID Sunday, June 2, 13
50. structure s.structure #=> [ :array, 0, 2, [:instance_variables, [:string, 1, "a"], 1, [:symbol, 0, "E"], :true], [:instance_variables, [:string, 2, "b"], 1, [:symbol_link, 0], :true]] Reference ID Reference Use Sunday, June 2, 13
51. token_stream s.token_stream.to_a #=> [ :array, 2, :instance_variables, :string, "a", 1, :symbol, "E", :true, :instance_variables, :string, "b", 1, :symbol_link, 0, :true] Sunday, June 2, 13
52. structure s.structure #=> [ :array, 0, 2, [:instance_variables, [:string, 1, "a"], 1, [:symbol, 0, "E"], :true], [:instance_variables, [:string, 2, "b"], 1, [:symbol_link, 0], :true]] Sunday, June 2, 13
53. Questions? gem install drbdump Sunday, June 2, 13