Here is collected some notes about for optimal tool usage. Document is work in progress and will updated over time.
Instrumenting the systems
From coarse to fine grained
Generally, when using analysis tooling, you already have an idea where to search. Based on this, it is usually required quite small amount of instrumentation of code (that generates log file for analysis).
To save work, instrumenting first “high level” and once understanding after measurements, more detailed analysis can take place. The benefit of this kind of thinking is that:
- You see overall problem form high level and from that you can plan next debugging step.
- If you are lucky, you already understand the problem after step 1.
- The less instrumentation, the less performance overhead to actual system being measured.
TimeToPig uses keyboard together with mouse for fast usage. You actually need to know only 2 keyboard commands:
E-key ("e") sort and Zoom all ("g") command. There are bunch of other buttons for filtering, math and sorting but these 2 will cover 80% of typical use cases.
If looking picture below and position "E sort position", user have pressed e-key. When e-key was pressed, TimeToPic will sort all channels in order of appearance starting from mouse position. Now user can easily see what is happening, what kind sequences there are etc.
The other sort keys are ('s' and 'w') that sort by event duration and by name.
If looking picture below, there are code instrumentation in 2 levels: function level and inside for-loop.
This would work ok generally since code initializes something in system before entering active mode where performance lags would hurt.
If looking code and then considering possible instrumentation, you will see that:
- InitObjects() function does one thing and actually you are not interested initialization of single node.
- Most likely when seeing InitObjects() on timeline without seeing inside (loop) information is enough for debugging. --> You can drop for-loop instrumentation.
If object count to be initialized is huge (lets say millions), most likely logging overhead per node initialization becomes major explaining factor. --> You are actually measuring logging overhead of system.
Too much data!
Sometimes your picture might become messy when you have bot values and event in view. You can easily clean up by using filter "!abs"
Adding thread id and object instance to trace name
Since TimeToPic is general purpose visualizer, it does not understand threads and object instances. On some cases it would be extremely useful to add such information to channel names like below. Then you see concurrent operations and filtering by thread id is possible.
Conversion or modification existing logging
Since TimeToPic reads file, it really does not care who is creating analysis file. If changing existing existing logging system is not option, user can easily create conversion script that converts log A to for suitable format.