Bug #472
closedLttng-modules : Vmalloc fail
100%
Description
Hello, i try to use lttng 2.1 on beagleboard-xm, i use last stable buildroot version to create a rootfs with lttng-tools and lttng-modules but when i try to load lttng-tracer i have the following ouptup:
[root@beagleboard-xm ~]# modprobe lttng-tracer
[ 1229.656768] vmap allocation for size 16068608 failed: use vmalloc=<size> to increase size.
[ 1229.665618] vmalloc: allocation failure: 16064293 bytes
[ 1229.671234] modprobe: page allocation failure: order:0, mode:0xd0
[ 1229.677703] [<c001aea4>] (unwind_backtrace+0x0/0x178) from [<c06f6ee8>] (dump_stack+0x20/0x24)
[ 1229.686889] [<c06f6ee8>] (dump_stack+0x20/0x24) from [<c01495dc>] (warn_alloc_failed+0x1bc/0x1f4)
[ 1229.696289] [<c01495dc>] (warn_alloc_failed+0x1bc/0x1f4) from [<c018dd50>] (_vmalloc_node_range+0x2cc/0x2fc)
[ 1229.706756] [<c018dd50>] (_vmalloc_node_range+0x2cc/0x2fc) from [<c001867c>] (module_alloc+0x44/0x54)
[ 1229.716613] [<c001867c>] (module_alloc+0x44/0x54) from [<c00c55a0>] (module_alloc_update_bounds+0x1c/0xd0)
[ 1229.726837] [<c00c55a0>] (module_alloc_update_bounds+0x1c/0xd0) from [<c00c6078>] (layout_and_allocate+0xa08/0xca8)
[ 1229.737854] [<c00c6078>] (layout_and_allocate+0xa08/0xca8) from [<c00c6744>] (load_module+0x80/0x149c)
[ 1229.747711] [<c00c6744>] (load_module+0x80/0x149c) from [<c00c7bdc>] (sys_init_module+0x7c/0x250)
[ 1229.757110] [<c00c7bdc>] (sys_init_module+0x7c/0x250) from [<c0011700>] (ret_fast_syscall+0x0/0x48)
[ 1229.766693] Mem-info:
[ 1229.769073] Normal per-cpu:
[ 1229.772094] CPU 0: hi: 186, btch: 31 usd: 27
[ 1229.777191] active_anon:4185 inactive_anon:7 isolated_anon:0
[ 1229.777191] active_file:4468 inactive_file:651 isolated_file:0
[ 1229.777191] unevictable:0 dirty:2 writeback:0 unstable:0
[ 1229.777191] free:106136 slab_reclaimable:685 slab_unreclaimable:681
[ 1229.777191] mapped:463 shmem:12 pagetables:46 bounce:0
[ 1229.777191] free_cma:4029
[ 1229.809906] Normal free:424544kB min:2824kB low:3528kB high:4236kB active_anon:16740kB inactive_anon:28kB active_file:17872kB inactive_file:2604kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:500224kB mlocked:0kB dirty:8kB writeback:0kB mapped:1852kB shmem:48kB slab_reclaimable:2740kB slab_unreclaimable:2724kB kernel_stack:408kB pagetables:184kB unstable:0kB bounce:0kB free_cma:16116kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[ 1229.852294] lowmem_reserve[]: 0 0 0
[ 1229.855957] Normal: 14*4kB 1*8kB 2*16kB 2*32kB 3*64kB 2*128kB 2*256kB 1*512kB 3*1024kB 1*2048kB 102*4096kB = 424544kB
[ 1229.867553] 5130 total pagecache pages
[ 1229.871490] 0 pages in swap cache
[ 1229.875061] Swap cache stats: add 0, delete 0, find 0/0
[ 1229.880493] Free swap = 0kB
[ 1229.883636] Total swap = 0kB
[ 1229.913787] 131072 pages of RAM
[ 1229.917083] 106350 free pages
[ 1229.920318] 9763 reserved pages
[ 1229.923736] 1244 slab pages
[ 1229.926666] 1304 pages shared
[ 1229.929901] 0 pages swap cached
modprobe: can't load module lttng-tracer (extra/lttng-tracer.ko): Cannot allocate memory
But if it look memory available, i have sufficient memory :
[root@beagleboard-xm ~]# cat /proc/meminfo
MemTotal: 485236 kB
MemFree: 455792 kB
Buffers: 740 kB
Cached: 19792 kB
SwapCached: 0 kB
Active: 18752 kB
Inactive: 2640 kB
Active(anon): 880 kB
Inactive(anon): 28 kB
Active(file): 17872 kB
Inactive(file): 2612 kB
Unevictable: 0 kB
Mlocked: 0 kB
HighTotal: 0 kB
HighFree: 0 kB
LowTotal: 485236 kB
LowFree: 455792 kB
SwapTotal: 0 kB
SwapFree: 0 kB
Dirty: 8 kB
Writeback: 0 kB
AnonPages: 872 kB
Mapped: 1832 kB
Shmem: 52 kB
Slab: 5476 kB
SReclaimable: 2752 kB
SUnreclaim: 2724 kB
KernelStack: 408 kB
PageTables: 152 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 242616 kB
Committed_AS: 51564 kB
VmallocTotal: 499712 kB
VmallocUsed: 23808 kB
VmallocChunk: 381772 kB
And i have no problem to load other lttng modules:
lsmod
Module Size Used by Tainted: G
lttng_types 1275 0
lttng_kretprobes 4370 0
lttng_kprobes 2916 0
lttng_ftrace 3651 0
lttng_statedump 6390 0
lttng_lib_ring_buffer 65640 0
How can i fix this ?
Files
Updated by Mathieu Desnoyers over 11 years ago
[...]
[root@beagleboard-xm ~]# modprobe lttng-tracer
[ 1229.656768] vmap allocation for size 16068608 failed: use vmalloc=<size> to increase size.
[ 1229.665618] vmalloc: allocation failure: 16064293 bytes
[...]
But if it look memory available, i have sufficient memory :
I'm afraid you don't.
[root@beagleboard-xm ~]# cat /proc/meminfo
MemTotal: 485236 kB
MemFree: 455792 kB
[...]
VmallocTotal: 499712 kB
VmallocUsed: 23808 kB
VmallocChunk: 381772 kB
You only have about 455MB of memory, but you try to allocate 16GB.
Thanks,
Mathieu
--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
Updated by Mathieu Desnoyers over 11 years ago
- Status changed from New to Invalid
Updated by Yannick Brosseau over 11 years ago
But it seems that LTTng try by himself of allocating 16GB
Updated by tangi colin over 11 years ago
I try lttng-modules 2.1 and 2.0 with last buildroot toolchain and last linaro-toolchain and i have the same result. Lttng try be itself to allocating 16GB. How i can fix it ? Can i set parameter to fix lttng-modules allocation ?
I a attach below my kernel config.
Updated by Mathieu Desnoyers over 11 years ago
please attach a log of all "lttng" commands issued since lttng-sessiond startup. (please restart your lttng-sessiond for a clean state).
Thanks,
Mathieu
Updated by Mathieu Desnoyers over 11 years ago
- File fix-arm-syscall.patch fix-arm-syscall.patch added
- Status changed from Invalid to Confirmed
- Assignee set to Mathieu Desnoyers
Please try with the following patch applied. For reference, please see:
http://lists.lttng.org/pipermail/lttng-dev/2013-March/019855.html
Updated by tangi colin over 11 years ago
I try fix-arm-syscall.patch but it don't change anything.
Below, i post lttng-sessiond log:
[root@(none) ~]# lttng-sessiond -vvv
DEBUG3: Creating LTTng run directory: /var/run/lttng [in create_lttng_rundir() at main.c:3692]
DEBUG2: Kernel consumer err path: /var/run/lttng/kconsumerd/error [in main() at main.c:3940]
DEBUG2: Kernel consumer cmd path: /var/run/lttng/kconsumerd/command [in main() at main.c:3942]
DEBUG1: Client socket path /var/run/lttng/client-lttng-sessiond [in main() at main.c:3995]
DEBUG1: Application socket path /var/run/lttng/apps-lttng-sessiond [in main() at main.c:3996]
DEBUG1: LTTng run directory path: /var/run/lttng [in main() at main.c:3997]
DEBUG2: UST consumer 32 bits err path: /var/run/lttng/ustconsumerd32/error [in main() at main.c:4006]
DEBUG2: UST consumer 32 bits cmd path: /var/run/lttng/ustconsumerd32/command [in main() at main.c:4008]
DEBUG2: UST consumer 64 bits err path: /var/run/lttng/ustconsumerd64/error [in main() at main.c:4017]
DEBUG2: UST consumer 64 bits cmd path: /var/run/lttng/ustconsumerd64/command [in main() at main.c:4019]
DEBUG3: Created hashtable size 4 at 0x1e12080 of type 1 [in lttng_ht_new() at hashtable.c:96]
DEBUG3: Created hashtable size 4 at 0x1e121b0 of type 1 [in lttng_ht_new() at hashtable.c:96]
DEBUG2: Creating consumer directory: /var/run/lttng/kconsumerd [in set_consumer_sockets() at main.c:3734]
[ 239.998504] vmap allocation for size 16224256 failed: use vmalloc=<size> to increase size.
[ 240.007507] vmalloc: allocation failure: 16219598 bytes
[ 240.013092] modprobe: page allocation failure: order:0, mode:0xd0
[ 240.019500] [<c001ae80>] (unwind_backtrace+0x0/0x178) from [<c071f8b0>] (dump_stack+0x20/0x24)
[ 240.028564] [<c071f8b0>] (dump_stack+0x20/0x24) from [<c01530c4>] (warn_alloc_failed+0x1bc/0x1f4)
[ 240.037933] [<c01530c4>] (warn_alloc_failed+0x1bc/0x1f4) from [<c0198414>] (_vmalloc_node_range+0x2cc/0x2fc)
[ 240.048400] [<c0198414>] (_vmalloc_node_range+0x2cc/0x2fc) from [<c0018660>] (module_alloc+0x44/0x54)
[ 240.058227] [<c0018660>] (module_alloc+0x44/0x54) from [<c00cc940>] (module_alloc_update_bounds+0x1c/0xd4)
[ 240.068389] [<c00cc940>] (module_alloc_update_bounds+0x1c/0xd4) from [<c00cd41c>] (layout_and_allocate+0xa08/0xca8)
[ 240.079345] [<c00cd41c>] (layout_and_allocate+0xa08/0xca8) from [<c00cdae8>] (load_module+0x80/0x14d0)
[ 240.089172] [<c00cdae8>] (load_module+0x80/0x14d0) from [<c00cefb4>] (sys_init_module+0x7c/0x254)
[ 240.098541] [<c00cefb4>] (sys_init_module+0x7c/0x254) from [<c00116c0>] (ret_fast_syscall+0x0/0x48)
[ 240.108032] Mem-info:
[ 240.110412] Normal per-cpu:
[ 240.113342] CPU 0: hi: 186, btch: 31 usd: 58
[ 240.118438] active_anon:4958 inactive_anon:5 isolated_anon:0
[ 240.118438] active_file:686 inactive_file:7047 isolated_file:0
[ 240.118438] unevictable:0 dirty:2 writeback:0 unstable:0
[ 240.118438] free:66905 slab_reclaimable:1121 slab_unreclaimable:878
[ 240.118438] mapped:475 shmem:9 pagetables:46 bounce:0
[ 240.118438] free_cma:4029
[ 240.151000] Normal free:267620kB min:2824kB low:3528kB high:4236kB active_anon:19832kB inactive_anon:20kB active_file:2744kB inactive_fil
e:28188kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:500224kB mlocked:0kB dirty:8kB writeback:0kB mapped:1900kB shmem:36k
B slab_reclaimable:4484kB slab_unreclaimable:3512kB kernel_stack:384kB pagetables:184kB unstable:0kB bounce:0kB free_cma:16116kB writeback_t
mp:0kB pages_scanned:0 all_unreclaimable? no
[ 240.193298] lowmem_reserve[]: 0 0 0
[ 240.196990] Normal: 3*4kB 1*8kB 3*16kB 3*32kB 3*64kB 2*128kB 1*256kB 3*512kB 3*1024kB 4*2048kB 62*4096kB = 267620kB
[ 240.208221] 7741 total pagecache pages
[ 240.212127] 0 pages in swap cache
[ 240.215637] Swap cache stats: add 0, delete 0, find 0/0
[ 240.221160] Free swap = 0kB
[ 240.224212] Total swap = 0kB
[ 240.251220] 131072 pages of RAM
[ 240.254608] 67150 free pages
[ 240.257751] 44022 reserved pages
[ 240.261138] 1350 slab pages
[ 240.264129] 1943 pages shared
[ 240.267242] 0 pages swap cached
modprobe: can't load module lttng-tracer (extra/lttng-tracer.ko): Cannot allocate memory
Error: Unable to load module lttng-tracer
DEBUG1: Failed to open /proc/lttng [in init_kernel_tracer() at main.c:1962]
DEBUG1: Modprobe removal successful lttng-tracer [in modprobe_remove_lttng_control() at modprobe.c:100]
Warning: No kernel tracer available
DEBUG2: Creating consumer directory: /var/run/lttng/ustconsumerd64 [in set_consumer_sockets() at main.c:3734]
DEBUG2: Creating consumer directory: /var/run/lttng/ustconsumerd32 [in set_consumer_sockets() at main.c:3734]
DEBUG1: Signal handler set for SIGTERM, SIGPIPE and SIGINT [in set_signal_handler() at main.c:3826]
DEBUG3: Session daemon client socket 8 and application socket 9 created [in init_daemon_socket() at main.c:3596]
Warning: No tracing group detected
DEBUG1: epoll set max size is 122809 [in compat_epoll_set_max_size() at compat-epoll.c:270]
DEBUG1: Command subsystem initialized [in cmd_init() at cmd.c:2423]
DEBUG1: [thread] Dispatch UST command started [in thread_dispatch_ust_registration() at main.c:1300]
DEBUG1: Futex n to 1 prepare done [in futex_nto1_prepare() at futex.c:75]
DEBUG1: Woken up but nothing in the UST command queue [in thread_dispatch_ust_registration() at main.c:1310]
DEBUG1: [thread] Manage application registration started [in thread_registration_apps() at main.c:1378]
DEBUG1: [thread] Manage client started [in thread_manage_clients() at main.c:3147]
DEBUG1: [thread] Manage health check started [in thread_manage_health() at main.c:2953]
DEBUG1: [thread] Thread manage kernel started [in thread_manage_kernel() at main.c:692]
DEBUG1: [thread] Manage application started [in thread_manage_apps() at main.c:1107]
DEBUG1: Accepting client command ... [in thread_manage_clients() at main.c:3191]
DEBUG1: Updating kernel poll set [in update_kernel_poll() at main.c:557]
DEBUG1: Health check ready [in thread_manage_health() at main.c:2992]
DEBUG1: Notifying applications of session daemon state: 1 [in notify_ust_apps() at main.c:496]
DEBUG1: Apps thread polling on 2 fds [in thread_manage_apps() at main.c:1135]
DEBUG1: Thread kernel polling on 2 fds [in thread_manage_kernel() at main.c:735]
DEBUG1: Got the wait shm fd 15 [in get_wait_shm() at shm.c:117]
DEBUG1: Futex wait update active 1 [in futex_wait_update() at futex.c:63]
DEBUG1: Accepting application registration [in thread_registration_apps() at main.c:1413]
Updated by Mats Liljegren over 11 years ago
I have the same issue using kernel 3.8.6 on PandaBoard. I tried using vmalloc=400M, but that didn't help.
I do not understand the error above (mine is quite similar), it tries to allocate 16MB, the largest available chunk is ~181MB (VmallocChunk). Why can't it allocate this? Have I missed something? Could it be that it has already allocated memory when this error happened, and this memory was free before looking at /proc/meminfo?
Regards
Mats
Updated by Mathieu Desnoyers over 11 years ago
- Status changed from Confirmed to Resolved
- % Done changed from 0 to 100
Applied in changeset 11fa478f18241fedee86f7dc7820a91c629c9e7e.