This example demonstrates the insertion of a user event into the event stream. Here's the source, usr_event_simple.c:
/*
* $QNXLicenseC:
* Copyright 2007, QNX Software Systems. All Rights Reserved.
*
* You must obtain a written license from and pay applicable license fees to QNX
* Software Systems before you may reproduce, modify or distribute this software,
* or any work that includes all or part of this software. Free development
* licenses are available for evaluation and non-commercial purposes. For more
* information visit http://licensing.qnx.com or email licensing@qnx.com.
*
* This file may contain contributions from others. Please review this entire
* file for other proprietary rights or license notices, as well as the QNX
* Development Suite License Guide at http://licensing.qnx.com/license-guide/
* for other information.
* $
*/
#ifdef __USAGE
%C - instrumentation example
%C - example that illustrates the very basic use of
the TraceEvent() kernel call and the instrumentation
module with tracelogger in a daemon mode.
All classes and their events are included and monitored.
Additionally, four user-generated simple events and
one string event are intercepted.
In order to use this example, start the tracelogger
in the daemon mode as:
tracelogger -n iter_number -d1
with iter_number = your choice of 1 through 10
After you start the example, tracelogger
will log the specified number of iterations and then
terminate. There are no messages printed upon successful
completion of the example. You can view the intercepted
events with the traceprinter utility. The intercepted
user events (class USREVENT) have event IDs
(EVENT) equal to: 111, 222, 333, 444 and 555.
See accompanied documentation and comments within
the sample source code for more explanations.
#endif
#include <sys/trace.h>
#include <unistd.h>
#include "instrex.h"
int main(int argc, char **argv)
{
/*
* Just in case, turn off all filters, since we
* don't know their present state - go to the
* known state of the filters.
*/
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_DELALLCLASSES));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_CLRCLASSPID, _NTO_TRACE_KERCALL));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_CLRCLASSTID, _NTO_TRACE_KERCALL));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_CLRCLASSPID, _NTO_TRACE_THREAD));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_CLRCLASSTID, _NTO_TRACE_THREAD));
/*
* Set fast emitting mode for all classes and
* their events.
*/
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_SETALLCLASSESFAST));
/*
* Intercept all event classes
*/
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_ADDALLCLASSES));
/*
* Start tracing process
*
* During the tracing process, the tracelogger (which
* is being executed in a daemon mode) will log all events.
* You can specify the number of iterations (i.e., the
* number of kernel buffers logged) when you start tracelogger.
*/
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_START));
/*
* Insert four user-defined simple events and one string
* event into the event stream. The user events have
* arbitrary event IDs: 111, 222, 333, 444, and 555
* (possible values are in the range 0...1023).
* The user events with ID=(111, ..., 444) are simple events
* that have two numbers attached: ({1,11}, ..., {4,44}).
* The user string event (ID 555) includes the string,
* "Hello world".
*/
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_INSERTSUSEREVENT, 111, 1, 11));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_INSERTSUSEREVENT, 222, 2, 22));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_INSERTSUSEREVENT, 333, 3, 33));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_INSERTSUSEREVENT, 444, 4, 44));
TRACE_EVENT(argv[0], TraceEvent(_NTO_TRACE_INSERTUSRSTREVENT,555, "Hello world" ));
/*
* The main() of this execution flow returns.
* However, the main() function of the tracelogger
* will return after registering the specified number
* of events.
*/
return (0);
}
Compile it, and then run tracelogger in one window:
tracelogger -d1 -n 3 -f usr_event_simple.kev
and run the compiled program in another:
./usr_event_simple
The trace data is in usr_event_simple.kev; to examine it, type:
traceprinter -f usr_event_simple.kev | less
The output from traceprinter will look something like this:
TRACEPRINTER version 1.02
TRACEPARSER LIBRARY version 1.02
-- HEADER FILE INFORMATION --
TRACE_FILE_NAME:: usr_event_simple.kev
TRACE_DATE:: Wed Jun 24 10:59:34 2009
TRACE_VER_MAJOR:: 1
TRACE_VER_MINOR:: 01
TRACE_LITTLE_ENDIAN:: TRUE
TRACE_ENCODING:: 16 byte events
TRACE_BOOT_DATE:: Tue Jun 23 11:47:46 2009
TRACE_CYCLES_PER_SEC:: 736629000
TRACE_CPU_NUM:: 1
TRACE_SYSNAME:: QNX
TRACE_NODENAME:: localhost
TRACE_SYS_RELEASE:: 6.4.1
TRACE_SYS_VERSION:: 2009/05/20-17:35:56EDT
TRACE_MACHINE:: x86pc
TRACE_SYSPAGE_LEN:: 2264
TRACE_TRACELOGGER_ARGS:: tracelogger -d1 -n 3 -f usr_event_simple.kev
-- KERNEL EVENTS --
t:0x254620e4 CPU:00 CONTROL: BUFFER sequence = 54, num_events = 714
...
t:0x25496c81 CPU:00 PROCESS :PROCCREATE_NAME
ppid:426022
pid:1810480
name:./usr_event_simple
t:0x2549701a CPU:00 THREAD :THCREATE pid:1810480 tid:1
t:0x25497112 CPU:00 THREAD :THRUNNING pid:1810480 tid:1
t:0x2549793a CPU:00 KER_EXIT:TRACE_EVENT/01 ret_val:0x00000000 empty:0x00000000
t:0x25497f48 CPU:00 USREVENT:EVENT:111, d0:0x00000001 d1:0x0000000b
t:0x254982c5 CPU:00 USREVENT:EVENT:222, d0:0x00000002 d1:0x00000016
t:0x25498638 CPU:00 USREVENT:EVENT:333, d0:0x00000003 d1:0x00000021
t:0x25498996 CPU:00 USREVENT:EVENT:444, d0:0x00000004 d1:0x0000002c
t:0x25499451 CPU:00 USREVENT:EVENT:555 STR:"Hello world"
t:0x2549bde5 CPU:00 KER_CALL:THREAD_DESTROY/47 tid:-1 status_p:0
t:0x2549d0d6 CPU:00 KER_EXIT:THREAD_DESTROY/47 ret_val:0x00000030 empty:0x00000000
t:0x2549d8ae CPU:00 KER_CALL:THREAD_DESTROYALL/48 empty:0x00000000 empty:0x00000000
...
Inserting your own events lets you flag events or bracket groups of events to isolate them for study. It's also useful for inserting internal, customized information into the event stream.