JSCamp 2016: Tracing and instrumentation in Node.js

The code use in this deck can be found here: https://github.com/watson/talks/tree/master/2016/06%20JSCamp/example-app

This talk is a head first dive into the next-gen core tracing API’s being developed under the Node.js Tracing Working Group. We’ll learn about the upcoming AsyncWrap API and how this can be used to build your own high level instrumentation logic in production.

Transcript

1. Thomas Watson @wa7son github.com/watson
2. @wa7son
3. @wa7son
4. @wa7son
5. @wa7son
6. @wa7son
7. github.com/watson/talks @wa7son
8. in production Instrumenting Node.js @wa7son
9. HTTP Request lifetime BOOM! Traces Transaction Incoming Request Response @wa7son
10. Normal solutions • Use a global or singleton object to store context • Pass a context object around between function calls • ??? @wa7son
11. @wa7son nodejsreactions.tumblr.com The Event Loop
12. The Event Loop Node.js process Synchronous code @wa7son
13. The Event Loop Node.js process @wa7son
14. Goals • Track HTTP request as transactions • Instrument I/O • Instrument potential CPU expensive operations • Associate exceptions with transactions • Don’t manually pass context around in the app • Plug’n’play • Almost no overhead @wa7son
15. Problems • Multiple HTTP requests active at the same time • Not possible to associate exceptions with origin HTTP request • No API to pass context across the async boundary @wa7son
16. Solution 1. Record context when a callback is queued on the event loop 2. Restore context when the callback is de- queued from the event loop global.currentTransaction global.currentTransaction = new Transaction(req) @wa7son
17. @wa7son
18. Patch the core • Patch Module._load • Patch the HTTP server to access new requests • Patch every async operation • timers • process.nextTick • Promise (native) • libuv @wa7son
19. github.com / watson / require-in-the-middle @wa7son
20. AsyncWrap https://github.com/nodejs/tracing-wg @wa7son
21. @wa7son
22. @wa7son
23. @wa7son
24. @wa7son
25. @wa7son
26. user: before async_wrap: init user: after async_wrap: pre user: done async_wrap: post async_wrap: destroy @wa7son
27. @wa7son
28. FATAL ERROR: node::AsyncWrap::AsyncWrap init hook threw @wa7son
29. @wa7son
30. @wa7son
31. user: before async_wrap: init user: after async_wrap: pre user: done async_wrap: post async_wrap: destroy @wa7son
32. @wa7son
33. > var asyncWrap = process.binding('async_wrap') undefined > asyncWrap.Providers { NONE: 0, CRYPTO: 1, FSEVENTWRAP: 2, FSREQWRAP: 3, GETADDRINFOREQWRAP: 4, GETNAMEINFOREQWRAP: 5, HTTPPARSER: 6, JSSTREAM: 7, PIPEWRAP: 8, PIPECONNECTWRAP: 9, PROCESSWRAP: 10, QUERYWRAP: 11, SHUTDOWNWRAP: 12, SIGNALWRAP: 13, STATWATCHER: 14, TCPWRAP: 15, TCPCONNECTWRAP: 16, TIMERWRAP: 17, TLSWRAP: 18, TTYWRAP: 19, UDPWRAP: 20, UDPSENDWRAP: 21, WRITEWRAP: 22, ZLIB: 23 } @wa7son
34. @wa7son
35. Handle Objects Node Core Userland libuv V8 JavaScript C / C++ @wa7son
36. Handle Objects net.connect @wa7son Handle objects
37. Handle Objects net.connect req === this socket === this @wa7son
38. Timers @wa7son
39. Timers user: before #1 async_wrap: init user: after #1 user: before #2 user: after #2 @wa7son
40. Timers user: before #1 async_wrap: init user: after #1 user: before #2 user: after #2 async_wrap: pre user: done #1 user: done #2 async_wrap: post async_wrap: destroy @wa7son
41. @wa7son
42. @wa7son
43. Show some real code @wa7son
44. Show some real code @wa7son github.com/watson/talks
45. AsyncWrap Gotchas • Handle creation time • console.log • process.nextTick • Timers • Promises • Multiple AsyncWrap’s @wa7son
46. @wa7son Callback queues in user-land
47. @wa7son ES6 Modules
48. @wa7son https://github.com/nodejs/tracing-wg
49. @wa7son https://github.com/nodejs/tracing-wg/tree/master/docs/AsyncWrap
50. @wa7son https://github.com/nodejs/tracing-wg/issues/29
51. Slides & Code github.com/watson/talks @wa7son
52. Mulțumiri! @wa7son github.com/watson