Trace Format

Trace Format zhang Tue, 04/28/2020 - 15:00

Upon request, a MonetDB server will produce an event stream with performance profiling information.

The event stream consists of individual text lines with comma-separated values and decorative tuple format square brackets (‘[’ and ‘]’). The field types are fixed. The bulk of the event records are recordings made at the “start” and “done” state of a MAL instruction call. The last column “stmt” contains the actual call and its arguments. It aids in the analysis to understand why some instructions are taking a lot of time. The prelude of the event record contains:

  Field Description Example
1 event An event counter 38
2 time The wall-clock time in microseconds "13:11:16.710180",
3 pc Name of the query execution plan name; followed by the program counter in the execution plan (denoted in the square brackets ‘[‘ and ‘]’) indicating the position of the MAL instruction in its defining block; and finally a unique call identifier to distinguish recursion. "user.s5_1[14]12",
4 thread Id of the worker thread processing this MAL instruction. 3
5 state The instruction status ("start" or "done") *. The "wait" event signals that a worker thread has stumbled upon an empty instruction queue, e.g. all remaining MAL instructions are blocked by an instruction to produce an intermediate result. "done",
6 usec The estimated (at "start") or actual execution time (at "done") for the MAL instruction, measured in microseconds 207,
7 rssMB Memory Resident Set Size (RSS), i.e., the portion of memory occupied by a process that is held in main memory, in MB. 54
8 tmpspace Estimated cumulative query plan footprint, in MB. For a query, the maximal value of “tmpspace” gives a fairly good estimation of the memory consumption of this query. 0,
9 inblock The number of disk blocks read ** 0,
10 outblock The number of disk blocks written ** 0,
11 majflt The number of major page faults 0,
12 nswap The number of swaps 0,
13 switch The number of context switches 0,
14 stmt The MAL statement being executed, with argument statistics "sql.exportResult(X_21=\"104d2\":streams,X_16=4:int);”


* In addition, the “state” field denotes two special events. The “wait” event is received when the worker threads cannot find an eligible MAL instruction and have to wait for other worker threads to deliver results. The “ping” event provides a synopsis of the CPU processing loads.

** Please be aware that these values reflect system wide activities, thus they include not only MonetDB activities. Additionally, these I/O counts do not reflect the actual amount of data read/written from/to the hardware drives, as this information is generally not available to all users of a Linux system.