Project

General

Profile

Actions

Bug #472

closed

Lttng-modules : Vmalloc fail

Added by tangi colin over 11 years ago. Updated over 11 years ago.

Status:
Resolved
Priority:
Normal
Target version:
-
Start date:
03/12/2013
Due date:
% Done:

100%

Estimated time:

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

.config (60.7 KB) .config tangi colin, 03/22/2013 08:48 AM
fix-arm-syscall.patch (2.17 KB) fix-arm-syscall.patch fix arm syscall instrumentation Mathieu Desnoyers, 03/23/2013 12:07 PM
Actions #1

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

Actions #2

Updated by Mathieu Desnoyers over 11 years ago

  • Status changed from New to Invalid
Actions #3

Updated by Yannick Brosseau over 11 years ago

But it seems that LTTng try by himself of allocating 16GB

Actions #4

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.

Actions #5

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

Actions #6

Updated by Mathieu Desnoyers over 11 years ago

Please try with the following patch applied. For reference, please see:

http://lists.lttng.org/pipermail/lttng-dev/2013-March/019855.html

Actions #7

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]

Actions #8

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

Actions #9

Updated by Mathieu Desnoyers over 11 years ago

  • Status changed from Confirmed to Resolved
  • % Done changed from 0 to 100
Actions

Also available in: Atom PDF