CMEM and C6Run

kuyniu iyniuyn said:

Its strange that our executable works when we run it a few times and then eventually stops working

I agree, it is strange, since CMEM contains auto-cleanup code that frees buffers that were allocated by the application but not explicitly freed by the application.  This happens when the /dev/cmem device is closed (either explicitly, or as part of auto-closing all open files that's inherent in Linux processes).

kuyniu iyniuyn said:

I will note that /proc/cmem is empty - I don't know if this is an issue.

/proc/cmem displays only pool-based buffers.  You haven't shown your CMEM module insertion command (insmod or modprobe), but if it doesn't contain any "pools=..." parameter then you will get no output from "% cat /proc/cmem".

kuyniu iyniuyn said:

We're wondering if a memory leak in our code can cause the heap memory to eventually run out?

As I stated above, CMEM buffers that aren't explicitly freed by a process should get auto-freed when that process exits, so I would expect that no leak would occur between subsequent runs of your application.

There might be some useful cmemk.ko debug output available to help diagnose this problem.  Can you rebuild cmemk.ko in "debug" mode (with "% make debug" in the cmem/src/module directory)?  If so, run your application intil the problem occurs, then run "% dmesg" to get CMEM debug output, and reply here with that.

Regards,

- Rob

Hi Rob,

I rebuilt the module with debug statements enabled and then ran our tests. Re-running the tests multiple times eventually shows an error. After running dmesg, this is the output:

Out of memory: kill process 17279 (dropbear) score 81 or a child
Killed process 17280 (sh) vsz:3040kB, anon-rss:88kB, file-rss:4kB
CMEMK Debug: open: called.
CMEMK Debug: GETVERSION ioctl received, returning 0x3000100.
CMEMK Debug: ALLOCHEAPCACHED ioctl received on heap pool for block 0
CMEMK Debug: get_phys: block_virtoff[0] translated kernel 0xc3000000 to 0xc2000000
CMEMK Debug: ALLOCHEAPCACHED: allocated 0x2000000 size buffer at 0xc2000000 (phys address)
CMEMK Debug: mmap: vma->vm_start = 0x40188000
CMEMK Debug: mmap: vma->vm_pgoff = 0xc2000
CMEMK Debug: mmap: vma->vm_end = 0x42188000
CMEMK Debug: mmap: size = 0x2000000
CMEMK Debug: mmap: calling set_cached(c1e5faa8) ...
CMEMK Debug: GETPHYS ioctl received.
CMEMK Debug: get_phys: find_vma translated user 0x40188000 to 0xc2000000
CMEMK Debug: GETPHYS: returning 0xc2000000
CMEMK Debug: CACHEWB ioctl received.
CMEMK Debug: CACHEWB: cleaned user virtual 0x40189080->0x401ffbd0
sh invoked oom-killer: gfp_mask=0xd0, order=2, oom_adj=0
Backtrace:
[<c002f518>] (dump_backtrace+0x0/0x110) from [<c002fa0c>] (dump_stack+0x18/0x1c)
r6:00000002 r5:c1c96960 r4:000000d0
[<c002f9f4>] (dump_stack+0x0/0x1c) from [<c0074178>] (dump_header+0x6c/0x160)
[<c007410c>] (dump_header+0x0/0x160) from [<c00742b0>] (oom_kill_process+0x44/0xdc)
[<c007426c>] (oom_kill_process+0x0/0xdc) from [<c00747b8>] (__out_of_memory+0x180/0x1a4)
r7:c1dd6000 r6:00000112 r5:c1c96960 r4:c03df728
[<c0074638>] (__out_of_memory+0x0/0x1a4) from [<c0074888>] (out_of_memory+0xac/0xf4)
[<c00747dc>] (out_of_memory+0x0/0xf4) from [<c00773bc>] (__alloc_pages_nodemask+0x46c/0x56c)
r6:00000002 r5:000000d0 r4:00000000
[<c0076f50>] (__alloc_pages_nodemask+0x0/0x56c) from [<c00774d4>] (__get_free_pages+0x18/0x44)
[<c00774bc>] (__get_free_pages+0x0/0x44) from [<c0032220>] (get_pgd_slow+0x20/0xdc)
[<c0032200>] (get_pgd_slow+0x0/0xdc) from [<c003c3b8>] (mm_init+0x94/0xd0)
r8:01200011 r7:c1e05a80 r6:c1dd6000 r5:00000000 r4:c1e05a80
[<c003c324>] (mm_init+0x0/0xd0) from [<c003c688>] (dup_mm+0x68/0x4b8)
r5:c1c972c0 r4:00000000
[<c003c620>] (dup_mm+0x0/0x4b8) from [<c003d25c>] (copy_process+0x738/0xd88)
[<c003cb24>] (copy_process+0x0/0xd88) from [<c003dae8>] (do_fork+0x16c/0x2d4)
[<c003d97c>] (do_fork+0x0/0x2d4) from [<c002ee2c>] (sys_clone+0x34/0x3c)
[<c002edf8>] (sys_clone+0x0/0x3c) from [<c002bee0>] (ret_fast_syscall+0x0/0x28)
Mem-info:
DMA per-cpu:
CPU 0: hi: 0, btch: 1 usd: 0
active_anon:106 inactive_anon:156 isolated_anon:0
active_file:0 inactive_file:14 isolated_file:0
unevictable:0 dirty:0 writeback:2 unstable:0
free:2776 slab_reclaimable:69 slab_unreclaimable:372
mapped:0 shmem:5 pagetables:51 bounce:0
DMA free:11104kB min:720kB low:900kB high:1080kB active_anon:424kB inactive_anon:624kB active_file:0kB inactive_file:56kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:32512kB mlocked:0kB dirty:0kB writeback:8kB mapped:0kB shmem:20kB slab_reclaimable:276kB slab_unreclaimable:1488kB kernel_stack:280kB pagetables:204kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
lowmem_reserve[]: 0 0 0
DMA: 2608*4kB 62*8kB 7*16kB 2*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 11104kB
19 total pagecache pages
0 pages in swap cache
Swap cache stats: add 0, delete 0, find 0/0
Free swap = 0kB
Total swap = 0kB
8192 pages of RAM
2841 free pages
1100 reserved pages
323 slab pages
14 pages shared
0 pages swap cached
Out of memory: kill process 17461 (sys_test_oar_c6) score 274 or a child
Killed process 17461 (sys_test_oar_c6) vsz:35164kB, anon-rss:104kB, file-rss:0kB
CMEMK Debug: close: called.
CMEMK Debug: close: all references closed, force freeing all busy buffers.
CMEMK Debug: Forcing free on pool 0
CMEMK Debug: busy entry(s) found
CMEMK Debug: Removing file c1f1d180 from user list of buffer 0xc2000000...
CMEMK Debug: Warning: Freeing 'busy' buffer from heap at 0xc2000000
CMEMK Debug: close: returning
sh invoked oom-killer: gfp_mask=0xd0, order=2, oom_adj=0

It seems the kernel is invoking oom killer after some memory operations happen on the cache. Any ideas?

Thanks.