[lttng-dev] Instrumenting a module?

[lttng-dev] Instrumenting a module?

[Thibault, Daniel]

   I'm trying to find out the recipe for instrumenting a kernel module with some custom LTTng tracepoints.  Oddly, writing the LTTng tracepoint provider kernel module turned out not too bad (the READMEs help), but I have seen no documentation of the process of instrumenting a module.

   Here is a simple module and its Makefile.  The module works as expected, adding events to the dmesg kernel log buffer upon being loaded and unloaded.

######
hello.c
######

#include <linux/module.h>  // included for all kernel modules
#include <linux/kernel.h>  // included for KERN_INFO
#include <linux/init.h>    // included for __init and __exit macros

//Module meta-data
MODULE_LICENSE("GPL");
MODULE_AUTHOR("Your name here");
MODULE_DESCRIPTION("A simple module");

//Module initialization
static int __init hello_init(void)
{
   printk(KERN_INFO "Hello!\n");
   return 0;
   // Any other return value means the module couldn't be loaded.
}

//Module finalization
static void __exit hello_cleanup(void)
{
   printk(KERN_INFO "Cleaning up hello module.\n");
}

//Identify the initialization and finalization handlers
module_init(hello_init);
module_exit(hello_cleanup);

######
Makefile
######

obj-m += hello.o

all:
	@echo "~~~~~~Copying hello.h to linux-headers:"
	gksudo cp hello.h /usr/src/linux-headers-3.2.0-53/include/trace/events/hello.h
	@echo "~~~~~~Copying hello.h to lttng-modules/instrumentation/events/lttng-module:"
	sudo cp hello-module.h /usr/src/lttng-modules-2.3.0/instrumentation/events/lttng-module/hello.h
	@echo "~~~~~~Copying lttng-probe-hello.c to lttng-modules/probes:"
	sudo cp lttng-probe-hello.c /usr/src/lttng-modules-2.3.0/probes/lttng-probe-hello.c
	@echo "~~~~~~Making hello.ko:"
	make -C /lib/modules/$(shell uname -r)/build M=$(PWD) modules

clean:
	make -C /lib/modules/$(shell uname -r)/build M=$(PWD) clean

hello.h defines the tracepoints for my custom LTTng module (lttng-probe-hello).  hello-module.h is hello.h "translated" for the lttng-module directory.  lttng-probe-hello was added to the probes Makefile.  lttng-modules makes and installs it just fine, and once I manually insmod lttng-probe-hello.ko, LTTng reports the new kernel tracepoints in 'lttng list -k'.

I instrument hello.c by adding:

######
hello.c
######

#include <linux/module.h>  // included for all kernel modules
#include <linux/kernel.h>  // included for KERN_INFO
#include <linux/init.h>    // included for __init and __exit macros
#include <trace/events/hello.h>

...

static int __init hello_init(void)
{
   trace_hello_init("Hello!");
   printk(KERN_INFO "Hello!\n");
...

static void __exit hello_cleanup(void)
{
   trace_hello_exit("Bye!");
   printk(KERN_INFO "Cleaning up hello module.\n");
...

I get a couple of warnings when I make the instrumented hello module:

WARNING: "__tracepoint_hello_exit" [/home/daniel/module/hello.ko] undefined!
WARNING: "__tracepoint_hello_init" [/home/daniel/module/hello.ko] undefined!

And hello.ko refuses to insmod as a consequence:

$ sudo insmod hello.ko
insmod: error inserting 'hello.ko': -1 Unknown symbol in module

Assuming I got the LTTng tracepoint provider kernel module right, what am I doing wrong with the instrumented module?  I suspect a missing define flag.
 
Daniel U. Thibault
Protection des syst?mes et contremesures (PSC) | Systems Protection & Countermeasures (SPC)
Cyber s?curit? pour les missions essentielles (CME) | Mission Critical Cyber Security (MCCS)
R & D pour la d?fense Canada - Valcartier (RDDC Valcartier) | Defence R&D Canada - Valcartier (DRDC Valcartier)
2459 route de la Bravoure
Qu?bec QC? G3J 1X5
CANADA
Vox?: (418) 844-4000 x4245
Fax?: (418) 844-4538
NAC?: 918V QSDJ <http://www.travelgis.com/map.asp?addr=918V%20QSDJ>
Gouvernement du Canada?| Government of Canada
<http://www.valcartier.drdc-rddc.gc.ca/>

[lttng-dev] Instrumenting a module?

[Thibault, Daniel]

   Update.  I finally figured it out: in the mainline, in the special case of dynamic arrays (and hence strings), you cannot use '__entry->fieldname' but must instead write 'memcpy(__get_dynamic_array(fieldname)...' (or ' __assign_str(fieldname, arg)') because there is no direct struct member created.  Problem solved!

Daniel U. Thibault
Protection des syst?mes et contremesures (PSC) | Systems Protection & Countermeasures (SPC)
Cyber s?curit? pour les missions essentielles (CME) | Mission Critical Cyber Security (MCCS)
R & D pour la d?fense Canada - Valcartier (RDDC Valcartier) | Defence R&D Canada - Valcartier (DRDC Valcartier)
2459 route de la Bravoure
Qu?bec QC  G3J 1X5
CANADA
Vox : (418) 844-4000 x4245
Fax : (418) 844-4538
NAC : 918V QSDJ <http://www.travelgis.com/map.asp?addr=918V%20QSDJ>
Gouvernement du Canada | Government of Canada
<http://www.valcartier.drdc-rddc.gc.ca/>

[lttng-dev] Instrumenting a module?

[Thibault, Daniel]

   Further update.  So far I can make plain payload fields and static array payload fields.  But I can't make dynamic array fields (same problem as with strings, I'm sure, since a string is just a dynamic array of char).

   The tracepoint:

TRACE_EVENT(hello_exit,
   TP_PROTO(int * intarr, unsigned short len),
   TP_ARGS(intarr, len),
   TP_STRUCT__entry(
      __dynamic_array(int, anarray, len)
   ),
   TP_fast_assign(
      memcpy(__entry->anarray, intarr, len*sizeof(int));
   ),
   TP_printk(
      "%s", "printk says bye"
   )
);

   The TP_fast_assign of the lttng-module version uses:
tp_memcpy(anarray, intarr, len*sizeof(int))

   The make of the module calling trace_hello_exit() says:

make -C /lib/modules/3.2.0-53-virtual/build M=/home/daniel/Documents/mymodule modules
make[1]: entrant dans le r?pertoire ? /usr/src/linux-headers-3.2.0-53-virtual ?
  CC [M]  /home/daniel/Documents/mymodule/hello.o
In file included from include/trace/ftrace.h:567:0,
                 from include/trace/define_trace.h:86,
                 from include/trace/events/hello.h:130,
                 from /home/daniel/Documents/mymodule/hello.c:5:
include/trace/events/hello.h: In function 'ftrace_raw_event_hello_exit':
include/trace/events/hello.h:87:1: erreur: 'struct ftrace_raw_hello_exit' has no member named 'anarray'
In file included from include/trace/ftrace.h:774:0,
                 from include/trace/define_trace.h:86,
                 from include/trace/events/hello.h:130,
                 from /home/daniel/Documents/mymodule/hello.c:5:
include/trace/events/hello.h: In function 'perf_trace_hello_exit':
include/trace/events/hello.h:87:1: erreur: 'struct ftrace_raw_hello_exit' has no member named 'anarray'
make[2]: *** [/home/daniel/Documents/mymodule/hello.o] Erreur 1
make[1]: *** [_module_/home/daniel/Documents/mymodule] Erreur 2
make[1]: quittant le r?pertoire ? /usr/src/linux-headers-3.2.0-53-virtual ?
make: *** [all] Erreur 2

   Why was perf dragged into this?  The __string attempt only had an ftrace failure.

   Please help untangle this.

Daniel U. Thibault
Protection des syst?mes et contremesures (PSC) | Systems Protection & Countermeasures (SPC)
Cyber s?curit? pour les missions essentielles (CME) | Mission Critical Cyber Security (MCCS)
R & D pour la d?fense Canada - Valcartier (RDDC Valcartier) | Defence R&D Canada - Valcartier (DRDC Valcartier)
2459 route de la Bravoure
Qu?bec QC  G3J 1X5
CANADA
Vox : (418) 844-4000 x4245
Fax : (418) 844-4538
NAC : 918V QSDJ <http://www.travelgis.com/map.asp?addr=918V%20QSDJ>
Gouvernement du Canada | Government of Canada
<http://www.valcartier.drdc-rddc.gc.ca/>

[lttng-dev] Instrumenting a module?

[Thibault, Daniel]

----------------------------------------------------------------------
> Date: Mon, 10 Feb 2014 17:10:37 +0000
> From: "Thibault, Daniel" <Daniel.Thibault@drdc-rddc.gc.ca>
>
>    I'm trying to find out the recipe for instrumenting a kernel module with some custom LTTng tracepoints.
>  Oddly, writing the LTTng tracepoint provider kernel module turned out not too bad (the READMEs help),
> but I have seen no documentation of the process of instrumenting a module.

   Update.  Looking at the instrumented kernel compilation units and define_trace.h, I've come to think I must #define CREATE_TRACE_POINTS just before #include <trace/events/hello.h> in the instrumented module.  What I find bizarre, though, is that this works for an integer payload field (instrumented module and LTTng tracepoint provider kernel module compile, tracing the new kernel events works as expected) but fails miserably with a string payload field.  Looking at other kernel tracepoints that have string payload fields, I just don't see what I'm doing wrong.

   The integer tracepoint:

TRACE_EVENT(hello_init,
   TP_PROTO(int anint),
   TP_ARGS(anint),
   TP_STRUCT__entry(
      __field(int, aninteger)
   ),
   TP_fast_assign(
      __entry->aninteger = anint;
   ),
   TP_printk(
      "hello=%d", __entry->aninteger
   )
);

   The string tracepoint:

TRACE_EVENT(hello_init,
   TP_PROTO(const char * astring),
   TP_ARGS(astring),
   TP_STRUCT__entry(
      __string(hello_string, astring)
   ),
   TP_fast_assign(
      __assign_str(hello_string, astring);
   ),
   TP_printk(
      "hello=%s", __entry->hello_string
   )
);

   This time the make says:

make -C /lib/modules/3.2.0-53-virtual/build M=/home/daniel/Documents/mymodule modules
make[1]: entrant dans le r?pertoire ? /usr/src/linux-headers-3.2.0-53-virtual ?
  CC [M]  /home/daniel/Documents/mymodule/hello.o
In file included from include/trace/ftrace.h:296:0,
                 from include/trace/define_trace.h:86,
                 from include/trace/events/hello.h:110,
                 from /home/daniel/Documents/mymodule/hello.c:5:
include/trace/events/hello.h: In function 'ftrace_raw_output_hello_init':
include/trace/events/hello.h:57:1: erreur: 'struct ftrace_raw_hello_init' has no member named 'hello_string'
make[2]: *** [/home/daniel/Documents/mymodule/hello.o] Erreur 1
make[1]: *** [_module_/home/daniel/Documents/mymodule] Erreur 2
make[1]: quittant le r?pertoire ? /usr/src/linux-headers-3.2.0-53-virtual ?
make: *** [all] Erreur 2

Daniel U. Thibault
Protection des syst?mes et contremesures (PSC) | Systems Protection & Countermeasures (SPC)
Cyber s?curit? pour les missions essentielles (CME) | Mission Critical Cyber Security (MCCS)
R & D pour la d?fense Canada - Valcartier (RDDC Valcartier) | Defence R&D Canada - Valcartier (DRDC Valcartier)
2459 route de la Bravoure
Qu?bec QC  G3J 1X5
CANADA
Vox : (418) 844-4000 x4245
Fax : (418) 844-4538
NAC : 918V QSDJ <http://www.travelgis.com/map.asp?addr=918V%20QSDJ>
Gouvernement du Canada | Government of Canada
<http://www.valcartier.drdc-rddc.gc.ca/>