LTTng » LTTng-modules

(LTTng 2.8.0 lttng-tools a0f518a on Ubuntu 14.04.4, kernel 4.2.0-27-generic)
It seems one cannot create a channel buffer of size 4 GiB or greater (despite there being no mention of a maximum size in the documentation).

$ lttng create kaboom
Session kaboom created.
Traces will be written in /home/user/lttng-traces/kaboom-20160615-131455
$ lttng enable-channel syscalls -k --subbuf-size 0x2000000 --num-subbuf 128
Error: Channel syscalls: Kernel create channel failed (session kaboom)
Error: Command error

With extremely verbose debug, we get:

$ lttng create kaboom
Session kaboom created.
Traces will be written in /home/user/lttng-traces/kaboom-20160615-131455
$ lttng -vvv enable-channel syscalls -k --subbuf-size 0x2000000 --num-subbuf 128
DEBUG1 - 13:18:34.917959 [3076/3076]: Channel subbuf size set to 33554432 (in cmd_enable_channels() at commands/enable_channels.c:384)
DEBUG1 - 13:18:34.919094 [3076/3076]: Channel subbuf num set to 128 (in cmd_enable_channels() at commands/enable_channels.c:420)
DEBUG2 - 13:18:34.919416 [3076/3076]: Config file path found: /home/user (in _get_session_name() at utils.c:63)
DEBUG1 - 13:18:34.919570 [3076/3076]: Session name found: kaboom (in _get_session_name() at utils.c:64)
DEBUG1 - 13:18:34.919738 [3076/3076]: Enabling channel syscalls (in enable_channel() at commands/enable_channels.c:225)
DEBUG1 - 13:18:34.921301 [3076/3076]: LSM cmd type : 5 (in send_session_msg() at lttng-ctl.c:135)
Error: Channel syscalls: Kernel create channel failed (session kaboom)
Error: Command error
DEBUG1 - 13:18:35.309852 [3076/3076]: Clean exit (in clean_exit() at lttng.c:149)

and

$ sudo -- lttng-sessiond -vvv
DEBUG1 - 13:14:42.945592 [2968/2968]: Resetting run_as worker signal handlers to default (in reset_sighandler() at runas.c:537)
DEBUG1 - 13:14:42.945868 [2968/2968]: run_as signal handler set for SIGTERM and SIGINT (in set_worker_sighandlers() at runas.c:594)
DEBUG1 - 13:14:42.946041 [2967/2967]: Health check time delta in seconds set to 20 (in health_init() at health.c:73)
DEBUG1 - 13:14:42.946282 [2967/2967]: epoll set max size is 3361075 (in compat_epoll_set_max_size() at compat-epoll.c:287)
DEBUG3 - 13:14:42.946501 [2967/2967]: Creating LTTng run directory: /var/run/lttng (in create_lttng_rundir() at main.c:5312)
DEBUG2 - 13:14:42.946671 [2967/2967]: Kernel consumer err path: /var/run/lttng/kconsumerd/error (in main() at main.c:5757)
DEBUG2 - 13:14:42.946783 [2967/2967]: Kernel consumer cmd path: /var/run/lttng/kconsumerd/command (in main() at main.c:5759)
DEBUG1 - 13:14:42.946927 [2967/2967]: Client socket path /var/run/lttng/client-lttng-sessiond (in main() at main.c:5839)
DEBUG1 - 13:14:42.947041 [2967/2967]: Application socket path /var/run/lttng/lttng-ust-sock-6 (in main() at main.c:5840)
DEBUG1 - 13:14:42.947146 [2967/2967]: Application wait path /lttng-ust-wait-6 (in main() at main.c:5841)
DEBUG1 - 13:14:42.947248 [2967/2967]: LTTng run directory path: /var/run/lttng (in main() at main.c:5842)
DEBUG2 - 13:14:42.947382 [2967/2967]: UST consumer 32 bits err path: /var/run/lttng/ustconsumerd32/error (in main() at main.c:5861)
DEBUG2 - 13:14:42.947489 [2967/2967]: UST consumer 32 bits cmd path: /var/run/lttng/ustconsumerd32/command (in main() at main.c:5863)
DEBUG2 - 13:14:42.947609 [2967/2967]: UST consumer 64 bits err path: /var/run/lttng/ustconsumerd64/error (in main() at main.c:5882)
DEBUG2 - 13:14:42.947716 [2967/2967]: UST consumer 64 bits cmd path: /var/run/lttng/ustconsumerd64/command (in main() at main.c:5884)
DEBUG3 - 13:14:42.947937 [2967/2967]: Created hashtable size 4 at 0x1608c70 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG3 - 13:14:42.952400 [2967/2967]: Created hashtable size 4 at 0x1609010 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG3 - 13:14:42.952510 [2967/2967]: Created hashtable size 4 at 0x16093d0 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG3 - 13:14:42.952609 [2967/2967]: Created hashtable size 4 at 0x1609790 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG2 - 13:14:42.952761 [2967/2967]: Creating consumer directory: /var/run/lttng/kconsumerd (in set_consumer_sockets() at main.c:5354)
DEBUG1 - 13:14:42.957480 [2967/2969]: [ht-thread] startup. (in thread_ht_cleanup() at ht-cleanup.c:36)
DEBUG3 - 13:14:42.957678 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG1 - 13:14:43.190550 [2967/2967]: Modprobe successfully lttng-ring-buffer-client-discard (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.243951 [2967/2967]: Modprobe successfully lttng-ring-buffer-client-overwrite (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.377058 [2967/2967]: Modprobe successfully lttng-ring-buffer-metadata-client (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.445182 [2967/2967]: Modprobe successfully lttng-ring-buffer-client-mmap-discard (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.486175 [2967/2967]: Modprobe successfully lttng-ring-buffer-client-mmap-overwrite (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.526426 [2967/2967]: Modprobe successfully lttng-ring-buffer-metadata-mmap-client (in modprobe_lttng() at modprobe.c:339)
DEBUG2 - 13:14:43.527659 [2967/2967]: Kernel tracer version validated (2.8, ABI 2.1) (in kernel_validate_version() at kernel.c:862)
DEBUG1 - 13:14:43.561689 [2967/2967]: Modprobe successfully lttng-probe-asoc (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.696578 [2967/2967]: Modprobe successfully lttng-probe-block (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.732233 [2967/2967]: Unable to load optional module lttng-probe-btrfs; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.806716 [2967/2967]: Modprobe successfully lttng-probe-compaction (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.835569 [2967/2967]: Unable to load optional module lttng-probe-ext3; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.862612 [2967/2967]: Unable to load optional module lttng-probe-ext4; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.103581 [2967/2967]: Modprobe successfully lttng-probe-gpio (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.109536 [2967/2967]: Modprobe successfully lttng-probe-irq (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.111794 [2967/2967]: Unable to load optional module lttng-probe-jbd; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.116738 [2967/2967]: Modprobe successfully lttng-probe-jbd2 (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.127610 [2967/2967]: Modprobe successfully lttng-probe-kmem (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.132034 [2967/2967]: Modprobe successfully lttng-probe-kvm (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.134196 [2967/2967]: Unable to load optional module lttng-probe-kvm-x86; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.136218 [2967/2967]: Unable to load optional module lttng-probe-kvm-x86-mmu; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.138274 [2967/2967]: Unable to load optional module lttng-probe-lock; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.142556 [2967/2967]: Modprobe successfully lttng-probe-module (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.146637 [2967/2967]: Modprobe successfully lttng-probe-napi (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.150652 [2967/2967]: Modprobe successfully lttng-probe-net (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.158937 [2967/2967]: Modprobe successfully lttng-probe-power (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.162872 [2967/2967]: Modprobe successfully lttng-probe-printk (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.166630 [2967/2967]: Modprobe successfully lttng-probe-random (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.170340 [2967/2967]: Modprobe successfully lttng-probe-rcu (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.172048 [2967/2967]: Unable to load optional module lttng-probe-regmap; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.175730 [2967/2967]: Modprobe successfully lttng-probe-regulator (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.177441 [2967/2967]: Unable to load optional module lttng-probe-rpm; continuing (in modprobe_lttng() at modprobe.c:335)
DEBUG1 - 13:14:43.181036 [2967/2967]: Modprobe successfully lttng-probe-sched (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.188557 [2967/2967]: Modprobe successfully lttng-probe-scsi (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.191854 [2967/2967]: Modprobe successfully lttng-probe-signal (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.195327 [2967/2967]: Modprobe successfully lttng-probe-skb (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.198640 [2967/2967]: Modprobe successfully lttng-probe-sock (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.201922 [2967/2967]: Modprobe successfully lttng-probe-statedump (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.205226 [2967/2967]: Modprobe successfully lttng-probe-sunrpc (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.208456 [2967/2967]: Modprobe successfully lttng-probe-timer (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.211589 [2967/2967]: Modprobe successfully lttng-probe-udp (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.218138 [2967/2967]: Modprobe successfully lttng-probe-vmscan (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.221173 [2967/2967]: Modprobe successfully lttng-probe-v4l2 (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.224456 [2967/2967]: Modprobe successfully lttng-probe-workqueue (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.227592 [2967/2967]: Modprobe successfully lttng-probe-writeback (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.230654 [2967/2967]: Modprobe successfully lttng-probe-x86-irq-vectors (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.233822 [2967/2967]: Modprobe successfully lttng-probe-x86-exceptions (in modprobe_lttng() at modprobe.c:339)
DEBUG1 - 13:14:43.233903 [2967/2967]: Kernel tracer fd 13 (in init_kernel_tracer() at main.c:2768)
DEBUG3 - 13:14:43.233964 [2967/2967]: Syscall init system call table (in syscall_init_table() at syscall.c:50)
DEBUG1 - 13:14:43.234400 [2967/2967]: Reallocating syscall table from 256 to 512 entries (in syscall_init_table() at syscall.c:95)
DEBUG1 - 13:14:43.234830 [2967/2967]: Reallocating syscall table from 512 to 1024 entries (in syscall_init_table() at syscall.c:95)
DEBUG2 - 13:14:43.235127 [2967/2967]: Creating consumer directory: /var/run/lttng/ustconsumerd64 (in set_consumer_sockets() at main.c:5354)
DEBUG2 - 13:14:43.235279 [2967/2967]: Creating consumer directory: /var/run/lttng/ustconsumerd32 (in set_consumer_sockets() at main.c:5354)
DEBUG3 - 13:14:43.235446 [2967/2967]: Session daemon client socket 16 and application socket 17 created (in init_daemon_socket() at main.c:5220)
DEBUG1 - 13:14:43.235550 [2967/2967]: All permissions are set (in set_permissions() at main.c:5300)
DEBUG3 - 13:14:43.235638 [2967/2967]: Created hashtable size 4 at 0x160c850 of type 2 (in lttng_ht_new() at hashtable.c:145)
DEBUG3 - 13:14:43.235699 [2967/2967]: Global buffer per UID registry initialized (in buffer_reg_init_uid_registry() at buffer-registry.c:99)
DEBUG3 - 13:14:43.235758 [2967/2967]: Created hashtable size 4 at 0x160cc10 of type 2 (in lttng_ht_new() at hashtable.c:145)
DEBUG3 - 13:14:43.235815 [2967/2967]: Global buffer per PID registry initialized (in buffer_reg_init_pid_registry() at buffer-registry.c:228)
DEBUG1 - 13:14:43.235876 [2967/2967]: Command subsystem initialized (in cmd_init() at cmd.c:3990)
DEBUG1 - 13:14:43.235965 [2967/2967]: Pid 2967 written in file /var/run/lttng/lttng-sessiond.pid (in utils_create_pid_file() at utils.c:507)
DEBUG1 - 13:14:43.236066 [2967/2967]: Pid 5345 written in file /var/run/lttng/agent.port (in utils_create_pid_file() at utils.c:507)
DEBUG1 - 13:14:43.236161 [2967/2967]: TCP inet operation timeout set to 216 sec (in lttcomm_inet_init() at inet.c:548)
DEBUG1 - 13:14:43.237742 [2967/3069]: [agent-thread] Manage agent application registration. (in agent_thread_manage_registration() at agent-thread.c:236)
DEBUG3 - 13:14:43.237873 [2967/3069]: URI string: tcp://localhost (in uri_parse() at uri.c:324)
DEBUG2 - 13:14:43.238171 [2967/3069]: IP address resolved to 127.0.0.1 (in set_ip_address() at uri.c:165)
DEBUG3 - 13:14:43.238257 [2967/3069]: URI dtype: 1, proto: 1, host: localhost, subdir: , ctrl: 0, data: 0 (in uri_parse() at uri.c:538)
DEBUG1 - 13:14:43.238377 [2967/3069]: [agent-thread] Listening on TCP port 5345 and socket 25 (in init_tcp_socket() at agent-thread.c:119)
DEBUG3 - 13:14:43.238447 [2967/3069]: [agent-thread] Manage agent polling (in agent_thread_manage_registration() at agent-thread.c:263)
DEBUG1 - 13:14:43.238223 [2967/3067]: [thread] Manage application started (in thread_manage_apps() at main.c:1603)
DEBUG1 - 13:14:43.238594 [2967/3067]: Apps thread polling (in thread_manage_apps() at main.c:1633)
DEBUG1 - 13:14:43.237809 [2967/3071]: [load-session-thread] Load session (in thread_load_session() at load-session-thread.c:91)
DEBUG1 - 13:14:43.238218 [2967/3068]: [ust-thread] Manage application notify command (in ust_thread_manage_notify() at ust-thread.c:40)
DEBUG3 - 13:14:43.238819 [2967/3068]: [ust-thread] Manage notify polling (in ust_thread_manage_notify() at ust-thread.c:69)
DEBUG1 - 13:14:43.237803 [2967/3070]: [thread] Thread manage kernel started (in thread_manage_kernel() at main.c:1100)
DEBUG1 - 13:14:43.238892 [2967/3070]: Updating kernel poll set (in update_kernel_poll() at main.c:935)
DEBUG1 - 13:14:43.238903 [2967/3070]: Thread kernel polling (in thread_manage_kernel() at main.c:1145)
DEBUG1 - 13:14:43.238913 [2967/3066]: [thread] Manage application registration started (in thread_registration_apps() at main.c:2155)
DEBUG1 - 13:14:43.238936 [2967/3066]: Notifying applications of session daemon state: 1 (in notify_ust_apps() at main.c:851)
DEBUG1 - 13:14:43.238998 [2967/3066]: Got the wait shm fd 30 (in get_wait_shm() at shm.c:115)
DEBUG1 - 13:14:43.239019 [2967/3066]: Futex wait update active 1 (in futex_wait_update() at futex.c:66)
DEBUG1 - 13:14:43.239029 [2967/3066]: Accepting application registration (in thread_registration_apps() at main.c:2192)
DEBUG1 - 13:14:43.239039 [2967/3065]: [thread] Dispatch UST command started (in thread_dispatch_ust_registration() at main.c:1915)
DEBUG1 - 13:14:43.239053 [2967/3065]: Futex n to 1 prepare done (in futex_nto1_prepare() at futex.c:78)
DEBUG1 - 13:14:43.239060 [2967/3065]: Woken up but nothing in the UST command queue (in thread_dispatch_ust_registration() at main.c:1938)
DEBUG1 - 13:14:43.239071 [2967/3064]: [thread] Manage client started (in thread_manage_clients() at main.c:4390)
DEBUG1 - 13:14:43.240396 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)
DEBUG1 - 13:14:43.240426 [2967/3063]: [thread] Manage health check started (in thread_manage_health() at main.c:4194)
DEBUG1 - 13:14:43.240510 [2967/3063]: Health check ready (in thread_manage_health() at main.c:4259)
DEBUG1 - 13:14:55.925759 [2967/3064]: Wait for client response (in thread_manage_clients() at main.c:4489)
DEBUG1 - 13:14:55.925882 [2967/3064]: Receiving data from client ... (in thread_manage_clients() at main.c:4534)
DEBUG1 - 13:14:55.926259 [2967/3064]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4538)
DEBUG1 - 13:14:55.926293 [2967/3064]: Clean command context structure (in clean_command_ctx() at main.c:831)
DEBUG1 - 13:14:55.926324 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)
DEBUG1 - 13:14:55.926468 [2967/3064]: Wait for client response (in thread_manage_clients() at main.c:4489)
DEBUG1 - 13:14:55.926499 [2967/3064]: Receiving data from client ... (in thread_manage_clients() at main.c:4534)
DEBUG1 - 13:14:55.926589 [2967/3064]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4538)
DEBUG1 - 13:14:55.926613 [2967/3064]: Clean command context structure (in clean_command_ctx() at main.c:831)
DEBUG1 - 13:14:55.926622 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)
DEBUG1 - 13:14:55.926977 [2967/3064]: Wait for client response (in thread_manage_clients() at main.c:4489)
DEBUG1 - 13:14:55.927010 [2967/3064]: Receiving data from client ... (in thread_manage_clients() at main.c:4534)
DEBUG1 - 13:14:55.927109 [2967/3064]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4538)
DEBUG1 - 13:14:55.927133 [2967/3064]: Clean command context structure (in clean_command_ctx() at main.c:831)
DEBUG1 - 13:14:55.927142 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)
DEBUG1 - 13:14:55.927249 [2967/3064]: Wait for client response (in thread_manage_clients() at main.c:4489)
DEBUG1 - 13:14:55.927277 [2967/3064]: Receiving data from client ... (in thread_manage_clients() at main.c:4534)
DEBUG1 - 13:14:55.927431 [2967/3064]: Processing client command 8 (in process_client_msg() at main.c:3020)
DEBUG1 - 13:14:55.927475 [2967/3064]: Waiting for 1 URIs from client ... (in process_client_msg() at main.c:3795)
DEBUG2 - 13:14:55.927576 [2967/3064]: Trying to find session by name kaboom (in session_find_by_name() at session.c:276)
DEBUG3 - 13:14:55.927640 [2967/3064]: Created hashtable size 4 at 0x7fac9c006f00 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG1 - 13:14:55.927656 [2967/3064]: Allocating ltt_sessions_ht_by_id (in ltt_sessions_ht_alloc() at session.c:153)
DEBUG3 - 13:14:55.927664 [2967/3064]: Created hashtable size 4 at 0x7fac9c0072c0 of type 2 (in lttng_ht_new() at hashtable.c:145)
DEBUG1 - 13:14:55.927694 [2967/3064]: Tracing session kaboom created with ID 0 by UID 1000 GID 1000 (in session_create() at session.c:420)
DEBUG2 - 13:14:55.927704 [2967/3064]: Trying to find session by name kaboom (in session_find_by_name() at session.c:276)
DEBUG3 - 13:14:55.927742 [2967/3064]: Created hashtable size 4 at 0x7fac9c00c6f0 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG2 - 13:14:55.927752 [2967/3064]: Setting trace directory path from URI to /home/user/lttng-traces/kaboom-20160615-131455 (in add_uri_to_consumer() at cmd.c:761)
DEBUG1 - 13:14:55.927775 [2967/3064]: Sending response (size: 20, retcode: Success (10)) (in thread_manage_clients() at main.c:4584)
DEBUG1 - 13:14:55.927802 [2967/3064]: Clean command context structure (in clean_command_ctx() at main.c:831)
DEBUG1 - 13:14:55.927811 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)
DEBUG1 - 13:18:34.920814 [2967/3064]: Wait for client response (in thread_manage_clients() at main.c:4489)
DEBUG1 - 13:18:34.920900 [2967/3064]: Receiving data from client ... (in thread_manage_clients() at main.c:4534)
DEBUG1 - 13:18:34.921018 [2967/3064]: Nothing recv() from client... continuing (in thread_manage_clients() at main.c:4538)
DEBUG1 - 13:18:34.921045 [2967/3064]: Clean command context structure (in clean_command_ctx() at main.c:831)
DEBUG1 - 13:18:34.921058 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)
DEBUG1 - 13:18:34.921178 [2967/3064]: Wait for client response (in thread_manage_clients() at main.c:4489)
DEBUG1 - 13:18:34.921208 [2967/3064]: Receiving data from client ... (in thread_manage_clients() at main.c:4534)
DEBUG1 - 13:18:34.921520 [2967/3064]: Processing client command 5 (in process_client_msg() at main.c:3020)
DEBUG1 - 13:18:34.921546 [2967/3064]: Getting session kaboom by name (in process_client_msg() at main.c:3108)
DEBUG2 - 13:18:34.921556 [2967/3064]: Trying to find session by name kaboom (in session_find_by_name() at session.c:276)
DEBUG1 - 13:18:34.921567 [2967/3064]: Creating kernel session (in create_kernel_session() at main.c:2936)
DEBUG3 - 13:18:34.921620 [2967/3064]: Created hashtable size 4 at 0x7fac9c003d30 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG1 - 13:18:34.921704 [2967/3064]: Kernel session created (fd: 34) (in kernel_create_session() at kernel.c:112)
DEBUG3 - 13:18:34.921715 [2967/3064]: Copying tracing session consumer output in kernel session (in copy_session_consumer() at main.c:2818)
DEBUG3 - 13:18:34.921784 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 13:18:34.921818 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 13:18:34.921840 [2967/3064]: Created hashtable size 4 at 0x7fac9c003d30 of type 1 (in lttng_ht_new() at hashtable.c:145)
DEBUG3 - 13:18:34.921863 [2967/3064]: Copy session consumer subdir /kernel (in copy_session_consumer() at main.c:2856)
DEBUG3 - 13:18:34.921872 [2967/3064]: mkdir() recursive /home/user/lttng-traces/kaboom-20160615-131455 with mode 504 for uid 1000 and gid 1000 (in run_as_mkdir_recursive() at runas.c:470)
DEBUG1 - 13:18:34.921898 [2967/3064]: Using run_as worker (in run_as() at runas.c:451)
DEBUG1 - 13:18:34.922390 [2967/3064]: Spawning consumerd (in spawn_consumerd() at main.c:2525)
DEBUG2 - 13:18:34.923048 [2967/3064]: Consumer pid 3077 (in start_consumerd() at main.c:2710)
DEBUG2 - 13:18:34.923092 [2967/3064]: Spawning consumer control thread (in start_consumerd() at main.c:2713)
DEBUG1 - 13:18:34.924905 [2967/3078]: [thread] Manage consumer started (in thread_manage_consumer() at main.c:1274)
DEBUG3 - 13:18:34.925992 [3077/3077]: Looking for a kernel consumer at these locations: (in spawn_consumerd() at main.c:2547)
DEBUG3 - 13:18:34.926182 [3077/3077]:     1) /usr/local/lib/lttng/libexec/lttng-consumerd (in spawn_consumerd() at main.c:2548)
DEBUG3 - 13:18:34.926422 [3077/3077]:     2) /usr/local/lib/lttng/libexec/lttng-consumerd (in spawn_consumerd() at main.c:2549)
DEBUG3 - 13:18:34.926642 [3077/3077]:     3)  (in spawn_consumerd() at main.c:2550)
DEBUG3 - 13:18:34.926934 [3077/3077]: Found location #1 (in spawn_consumerd() at main.c:2552)
DEBUG1 - 13:18:34.927062 [3077/3077]: Using kernel consumer at: /usr/local/lib/lttng/libexec/lttng-consumerd (in spawn_consumerd() at main.c:2565)
DEBUG2 - 13:18:34.929522 [2967/3078]: Receiving code from consumer err_sock (in thread_manage_consumer() at main.c:1372)
DEBUG1 - 13:18:35.304874 [2967/3078]: Consumer command socket ready (fd: 37 (in thread_manage_consumer() at main.c:1406)
DEBUG1 - 13:18:35.305616 [2967/3078]: Consumer metadata socket ready (fd: 38) (in thread_manage_consumer() at main.c:1408)
DEBUG3 - 13:18:35.306534 [2967/3064]: Consumer socket created (fd: 37) and added to output (in consumer_create_socket() at consumer.c:301)
DEBUG1 - 13:18:35.306688 [2967/3064]: Setting relayd for session kaboom (in cmd_setup_relayd() at cmd.c:1010)
DEBUG1 - 13:18:35.306858 [2967/3064]: Enabling channel syscalls for session kaboom (in cmd_enable_channel() at cmd.c:1313)
DEBUG1 - 13:18:35.306929 [2967/3064]: Trying to find channel syscalls (in trace_kernel_get_channel_by_name() at trace-kernel.c:48)
DEBUG3 - 13:18:35.307022 [2967/3064]: Kernel create channel syscalls with attr: 0, 33554432, 128, 0, 200000, -1, 0 (in kernel_create_channel() at kernel.c:146)
PERROR - 13:18:35.307893 [2967/3064]: ioctl kernel create channel: Invalid argument (in kernel_create_channel() at kernel.c:151)
DEBUG1 - 13:18:35.308179 [2967/3064]: Sending response (size: 20, retcode: Kernel create channel failed (38)) (in thread_manage_clients() at main.c:4584)
DEBUG1 - 13:18:35.322580 [2967/3064]: Clean command context structure (in clean_command_ctx() at main.c:831)
DEBUG1 - 13:18:35.322844 [2967/3064]: Accepting client command ... (in thread_manage_clients() at main.c:4437)

The key messages are the last few ones:

DEBUG3 - 13:18:35.307022 [2967/3064]: Kernel create channel syscalls with attr: 0, 33554432, 128, 0, 200000, -1, 0 (in kernel_create_channel() at kernel.c:146)
PERROR - 13:18:35.307893 [2967/3064]: ioctl kernel create channel: Invalid argument (in kernel_create_channel() at kernel.c:151)
DEBUG1 - 13:18:35.308179 [2967/3064]: Sending response (size: 20, retcode: Kernel create channel failed (38)) (in thread_manage_clients() at main.c:4584)

Even curiouser, if I destroy the session and try re-creating it, lttng eventually hangs:

$ lttng -vvv enable-channel syscalls -k --subbuf-size 0x80000000 --num-subbuf 2
DEBUG1 - 14:23:39.698770 [3131/3131]: Channel subbuf size set to 2147483648 (in cmd_enable_channels() at commands/enable_channels.c:384)
DEBUG1 - 14:23:39.699627 [3131/3131]: Channel subbuf num set to 2 (in cmd_enable_channels() at commands/enable_channels.c:420)
DEBUG2 - 14:23:39.699943 [3131/3131]: Config file path found: /home/user (in _get_session_name() at utils.c:63)
DEBUG1 - 14:23:39.700111 [3131/3131]: Session name found: kaboom (in _get_session_name() at utils.c:64)
DEBUG1 - 14:23:39.700298 [3131/3131]: Enabling channel syscalls (in enable_channel() at commands/enable_channels.c:225)
DEBUG1 - 14:23:39.701926 [3131/3131]: LSM cmd type : 5 (in send_session_msg() at lttng-ctl.c:135)

and, on the lttng-sessiond side:

[...]
DEBUG1 - 14:23:39.702945 [2967/3064]: Enabling channel syscalls for session kaboom (in cmd_enable_channel() at cmd.c:1313)
DEBUG1 - 14:23:39.702953 [2967/3064]: Trying to find channel syscalls (in trace_kernel_get_channel_by_name() at trace-kernel.c:48)
DEBUG3 - 14:23:39.702964 [2967/3064]: Kernel create channel syscalls with attr: 0, 2147483648, 2, 0, 200000, -1, 0 (in kernel_create_channel() at kernel.c:146)

At which point I ctrl+c out of lttng and sudo kill the session daemon, which is incompletely successful:

DEBUG1 - 14:28:22.591460 [2967/2967]: SIGTERM caught (in sighandler() at main.c:5423)
DEBUG1 - 14:28:22.591505 [2967/2967]: Terminating all threads (in stop_threads() at main.c:510)
DEBUG1 - 14:28:22.591566 [2967/2967]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:123)
DEBUG1 - 14:28:22.591590 [2967/3070]: Thread kernel return from poll on 2 fds (in thread_manage_kernel() at main.c:1152)
DEBUG1 - 14:28:22.591638 [2967/3070]: Kernel thread dying (in thread_manage_kernel() at main.c:1236)
DEBUG1 - 14:28:22.592584 [2967/3078]: consumer thread cleanup completed (in thread_manage_consumer() at main.c:1585)
DEBUG1 - 14:28:22.592676 [2967/3063]: Health check thread dying (in thread_manage_health() at main.c:4363)
DEBUG1 - 14:28:22.592766 [2967/3066]: Notifying applications of session daemon state: 0 (in notify_ust_apps() at main.c:851)
DEBUG1 - 14:28:22.592833 [2967/3066]: Got the wait shm fd 11 (in get_wait_shm() at shm.c:115)
DEBUG1 - 14:28:22.592858 [2967/3066]: Futex wait update active 0 (in futex_wait_update() at futex.c:66)
DEBUG1 - 14:28:22.592895 [2967/3066]: UST Registration thread cleanup complete (in thread_registration_apps() at main.c:2355)
DEBUG3 - 14:28:22.596531 [2967/3068]: [ust-thread] Manage notify return from poll on 2 fds (in ust_thread_manage_notify() at ust-thread.c:76)
DEBUG1 - 14:28:22.596578 [2967/3068]: Application notify communication apps thread cleanup complete (in ust_thread_manage_notify() at ust-thread.c:187)
DEBUG1 - 14:28:22.596631 [2967/3067]: Apps thread return from poll on 2 fds (in thread_manage_apps() at main.c:1640)
DEBUG1 - 14:28:22.596663 [2967/3067]: Application communication apps thread cleanup complete (in thread_manage_apps() at main.c:1748)
DEBUG3 - 14:28:22.597129 [2967/3069]: [agent-thread] Manage agent return from poll on 2 fds (in agent_thread_manage_registration() at agent-thread.c:269)
DEBUG3 - 14:28:22.598047 [2967/3069]: [agent-thread] 1 fd ready (in agent_thread_manage_registration() at agent-thread.c:280)
DEBUG3 - 14:28:22.598079 [2967/3069]: [agent-thread] Destroy TCP socket on port 5345 (in destroy_tcp_socket() at agent-thread.c:137)
DEBUG1 - 14:28:22.598111 [2967/3069]: [agent-thread] is cleaning up and stopping. (in agent_thread_manage_registration() at agent-thread.c:357)
DEBUG1 - 14:28:22.597163 [2967/3065]: Futex n to 1 wait done (in futex_nto1_wait() at futex.c:106)
DEBUG1 - 14:28:22.598178 [2967/3065]: Dispatch thread dying (in thread_dispatch_ust_registration() at main.c:2132)
DEBUG1 - 14:28:22.599154 [2967/2967]: Cleanup sessiond (in sessiond_cleanup() at main.c:624)
DEBUG1 - 14:28:22.599331 [2967/2967]: Removing sessiond and consumerd content of directory /var/run/lttng (in sessiond_cleanup() at main.c:643)
DEBUG1 - 14:28:22.599441 [2967/2967]: Removing /var/run/lttng/lttng-sessiond.pid (in sessiond_cleanup() at main.c:649)
DEBUG1 - 14:28:22.599484 [2967/2967]: Removing /var/run/lttng/agent.port (in sessiond_cleanup() at main.c:654)
DEBUG1 - 14:28:22.599584 [2967/2967]: Removing /var/run/lttng/kconsumerd/error (in sessiond_cleanup() at main.c:661)
DEBUG1 - 14:28:22.599673 [2967/2967]: Removing directory /var/run/lttng/kconsumerd (in sessiond_cleanup() at main.c:667)
DEBUG1 - 14:28:22.599711 [2967/2967]: Removing /var/run/lttng/ustconsumerd32/error (in sessiond_cleanup() at main.c:674)
DEBUG1 - 14:28:22.599799 [2967/2967]: Removing directory /var/run/lttng/ustconsumerd32 (in sessiond_cleanup() at main.c:680)
DEBUG1 - 14:28:22.599822 [2967/2967]: Removing /var/run/lttng/ustconsumerd64/error (in sessiond_cleanup() at main.c:687)
DEBUG1 - 14:28:22.599903 [2967/2967]: Removing directory /var/run/lttng/ustconsumerd64 (in sessiond_cleanup() at main.c:693)
DEBUG1 - 14:28:22.599926 [2967/2967]: Cleaning up all sessions (in sessiond_cleanup() at main.c:696)
DEBUG1 - 14:28:22.599944 [2967/2967]: Tearing down kernel session (in kernel_destroy_session() at kernel.c:916)
DEBUG1 - 14:28:22.600017 [2967/2967]: [trace] Closing session fd 34 (in trace_kernel_destroy_session() at trace-kernel.c:546)
DEBUG1 - 14:28:22.600073 [2967/2967]: Destroying session kaboom (in session_destroy() at session.c:331)
DEBUG1 - 14:28:22.600182 [2967/2967]: Empty ltt_sessions_ht_by_id, destroying it (in del_session_ht() at session.c:240)
DEBUG1 - 14:28:22.600271 [2967/2967]: Waiting for complete teardown of consumerd (PID: 3077) (in wait_consumer() at main.c:603)
DEBUG1 - 14:28:22.600477 [2967/2967]: Cleaning up all agent apps (in sessiond_cleanup() at main.c:713)
DEBUG1 - 14:28:22.600589 [2967/2967]: Closing all UST sockets (in sessiond_cleanup() at main.c:716)
DEBUG2 - 14:28:22.600671 [2967/2967]: UST app cleaning registered apps hash table (in ust_app_clean_list() at ust-app.c:3815)
DEBUG3 - 14:28:22.607513 [2967/2967]: Buffer registry destroy all registry (in buffer_reg_destroy_registries() at buffer-registry.c:753)
DEBUG2 - 14:28:22.607543 [2967/2967]: Closing kernel fd (in sessiond_cleanup() at main.c:721)
DEBUG1 - 14:28:22.607573 [2967/2967]: Unloading kernel modules (in sessiond_cleanup() at main.c:728)
DEBUG3 - 14:28:22.600158 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608106 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608135 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608161 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608178 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608198 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608214 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608235 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608251 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608284 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608301 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608316 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608329 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608344 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608357 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608396 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG3 - 14:28:22.608416 [2967/2969]: [ht-thread] Returning from poll on 2 fds. (in thread_ht_cleanup() at ht-cleanup.c:73)
DEBUG3 - 14:28:22.608432 [2967/2969]: [ht-thread] Polling. (in thread_ht_cleanup() at ht-cleanup.c:66)
DEBUG1 - 14:28:44.910953 [2967/2967]: SIGTERM caught (in sighandler() at main.c:5423)
DEBUG1 - 14:28:44.910996 [2967/2967]: Terminating all threads (in stop_threads() at main.c:510)
PERROR - 14:28:44.911016 [2967/2967]: write poll pipe: Bad file descriptor (in notify_thread_pipe() at utils.c:44)
Error: write error on thread quit pipe
DEBUG1 - 14:28:44.911055 [2967/2967]: Futex n to 1 wake done (in futex_nto1_wake() at futex.c:123)

The lttng-sessiond daemon (and its lttng-runas) are still hanging around, and I must restart the (virtual) machine.