OpenWrt/LEDE Project

  • Status Unconfirmed
  • Percent Complete
    0%
  • Task Type Bug Report
  • Category Base system
  • Assigned To No-one
  • Operating System All
  • Severity Low
  • Priority Very Low
  • Reported Version Trunk
  • Due in Version Undecided
  • Due Date Undecided
  • Private
Attached to Project: OpenWrt/LEDE Project
Opened by Ron Brash - 07.02.2017

FS#479 - Softethervpn results in ReAlloc error after vpnbridge is executed

On a mostly vanilla Atmel at91sam9g20-ek with 32MB of RAM, we are seeing a couple of errors using the current package software version + patches.

Overall, it may be the cross compilation process, overlay or something else entirely.

1. If the vpnbridge is already started, a NAND-WAIT stacktrace results if the binary is executed to instantiate a second instance.

root@lede:/usr/libexec/softethervpn# /usr/bin/env LANG=en_US.UTF-8 vpncmd
[  241.880000] 
[  241.880000] =================================
[  241.880000] [ INFO: inconsistent lock state ]
[  241.880000] 4.4.36 #0 Not tainted
[  241.880000] ---------------------------------
[  241.880000] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
[  241.880000] kswapd0/155 [HC0[0]:SC0[0]:HE1:SE1] takes:
[  241.880000]  (&f->sem){+.+.?.}, at: [<c012949c>] jffs2_do_clear_inode+0x28/0x114
[  241.880000] {RECLAIM_FS-ON-W} state was registered at:
[  241.880000]   [<c005047c>] lockdep_trace_alloc+0xf8/0x118
[  241.880000]   [<c00b5610>] kmem_cache_alloc+0x28/0x144
[  241.880000]   [<c01261d8>] jffs2_alloc_inode_cache+0x1c/0x28
[  241.880000]   [<c01293a4>] jffs2_do_read_inode+0x13c/0x20c
[  241.880000]   [<c012fe58>] jffs2_iget+0x74/0x324
[  241.880000]   [<c0130830>] jffs2_do_fill_super+0x190/0x274
[  241.880000]   [<c0130e98>] jffs2_fill_super+0xf4/0x144
[  241.880000]   [<c01d1528>] mount_mtd_aux+0x80/0x10c
[  241.880000]   [<c01d1630>] mount_mtd_nr+0x7c/0x94
[  241.880000]   [<c01d17f8>] mount_mtd+0x1b0/0x210
[  241.880000]   [<c01309d4>] jffs2_mount+0x1c/0x28
[  241.880000]   [<c00bbbe4>] mount_fs+0x1c/0xac
[  241.880000]   [<c00d6418>] vfs_kern_mount+0x5c/0x12c
[  241.880000]   [<c00d9e68>] do_mount+0xa04/0xbc8
[  241.880000]   [<c00da270>] SyS_mount+0x7c/0xa8
[  241.880000]   [<c0009660>] ret_fast_syscall+0x0/0x1c
[  241.880000] irq event stamp: 45867
[  241.880000] hardirqs last  enabled at (45867): [<c001508c>] _raw_spin_unlock_irq+0x2c/0x6c
[  241.880000] hardirqs last disabled at (45866): [<c0014e88>] _raw_spin_lock_irq+0x28/0x70
[  241.880000] softirqs last  enabled at (45450): [<c0024088>] __do_softirq+0x208/0x2a4
[  241.880000] softirqs last disabled at (45431): [<c0024488>] irq_exit+0xa4/0xec
[  241.880000] 
[  241.880000] other info that might help us debug this:
[  241.880000]  Possible unsafe locking scenario:
[  241.880000] 
[  241.880000]        CPU0
[  241.880000]        ----
[  241.880000]   lock(&f->sem);
[  241.880000]   <Interrupt>
[  241.880000]     lock(&f->sem);
[  241.880000] 
[  241.880000]  *** DEADLOCK ***
[  241.880000] 
[  241.880000] 2 locks held by kswapd0/155:
[  241.880000]  #0:  (shrinker_rwsem){++++..}, at: [<c0090034>] shrink_slab.part.1.constprop.7+0x30/0x230
[  241.880000]  #1:  (&type->s_umount_key#32){.+.+..}, at: [<c00bb3ec>] trylock_super+0x1c/0x60
[  241.880000] 
[  241.880000] stack backtrace:
[  241.880000] CPU: 0 PID: 155 Comm: kswapd0 Not tainted 4.4.36 #0
[  241.880000] Hardware name: Atmel AT91SAM9
[  241.880000] Backtrace: 
[  241.880000] [<c0019798>] (dump_backtrace) from [<c0019994>] (show_stack+0x18/0x1c)
[  241.880000]  r7:0000000a r6:c38af4c0 r5:c38af0c0 r4:c068f314
[  241.880000] [<c001997c>] (show_stack) from [<c016fdd8>] (dump_stack+0x20/0x28)
[  241.880000] [<c016fdb8>] (dump_stack) from [<c004d144>] (print_usage_bug.part.11+0x228/0x290)
[  241.880000] [<c004cf1c>] (print_usage_bug.part.11) from [<c004d5b0>] (mark_lock+0x404/0x63c)
[  241.880000]  r8:c004c558 r7:c38af0c0 r6:c38af4c0 r5:00000008 r4:0000000a
[  241.880000] [<c004d1ac>] (mark_lock) from [<c004e638>] (__lock_acquire+0x97c/0x198c)
[  241.880000]  r10:c38af0c0 r9:c0667044 r8:c38af4c0 r7:00000001 r6:00000002 r5:c3675704
[  241.880000]  r4:0000025d r3:00000004
[  241.880000] [<c004dcbc>] (__lock_acquire) from [<c004fdcc>] (lock_acquire+0x7c/0x9c)
[  241.880000]  r10:00000042 r9:c334c4c4 r8:c38af0c0 r7:c0ccdd8c r6:00000001 r5:60000013
[  241.880000]  r4:00000000
[  241.880000] [<c004fd50>] (lock_acquire) from [<c0011580>] (mutex_lock_nested+0x50/0x39c)
[  241.880000]  r6:c334d000 r5:c334d000 r4:c36756d0
[  241.880000] [<c0011530>] (mutex_lock_nested) from [<c012949c>] (jffs2_do_clear_inode+0x28/0x114)
[  241.880000]  r10:00000042 r9:c334c4c4 r8:c334c000 r7:00000058 r6:c334d000 r5:c334d000
[  241.880000]  r4:c36756d0
[  241.880000] [<c0129474>] (jffs2_do_clear_inode) from [<c012fde0>] (jffs2_evict_inode+0x34/0x38)
[  241.880000]  r7:00000058 r6:c044ba88 r5:c334d000 r4:c3675730
[  241.880000] [<c012fdac>] (jffs2_evict_inode) from [<c00d1a7c>] (evict+0xac/0x164)
[  241.880000]  r5:c367580c r4:c3675730
[  241.880000] [<c00d19d0>] (evict) from [<c00d1b6c>] (dispose_list+0x38/0x44)
[  241.880000]  r7:00000058 r6:00000063 r5:00000006 r4:c392dd58
[  241.880000] [<c00d1b34>] (dispose_list) from [<c00d2e1c>] (prune_icache_sb+0x4c/0x5c)
[  241.880000]  r5:00000006 r4:c392dd58
[  241.880000] [<c00d2dd0>] (prune_icache_sb) from [<c00bb570>] (super_cache_scan+0x140/0x184)
[  241.880000]  r5:00000000 r4:c392ddd8
[  241.880000] [<c00bb430>] (super_cache_scan) from [<c00901b0>] (shrink_slab.part.1.constprop.7+0x1ac/0x230)
[  241.880000]  r10:00000601 r9:00000000 r8:00000000 r7:00000400 r6:00000062 r5:c334c4c4
[  241.880000]  r4:000000a5
[  241.880000] [<c0090004>] (shrink_slab.part.1.constprop.7) from [<c0092318>] (shrink_zone+0x5f0/0x640)
[  241.880000]  r10:00000004 r9:00000117 r8:c04da918 r7:00000000 r6:00000000 r5:c392ded4
[  241.880000]  r4:c04da6fc
[  241.880000] [<c0091d28>] (shrink_zone) from [<c0092c8c>] (kswapd+0x4ac/0x668)
[  241.880000]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c04da6fc
[  241.880000]  r4:c04da6fc
[  241.880000] [<c00927e0>] (kswapd) from [<c003d1b4>] (kthread+0xe4/0xfc)
[  241.880000]  r10:00000000 r9:00000000 r8:00000000 r7:c00927e0 r6:c04da6fc r5:00000000
[  241.880000]  r4:c3950780
[  241.880000] [<c003d0d0>] (kthread) from [<c00096ec>] (ret_from_fork+0x14/0x28)
[  241.880000]  r7:00000000 r6:00000000 r5:c003d0d0 r4:c3950780

2. If the vpnbridge is instantiated only once, and the vpn client is to be executed, a realloc error occurs:

 /usr/bin/env LANG=en_US.UTF-8 ./vpnclient 
Fatal Error: InternalReAlloc: error: realloc() failed.


Aborted

This is on 4.4.36 LEDE trunk with a FS that looks like:

Filesystem                Size      Used Available Use% Mounted on
/dev/root                 7.4M      7.4M         0 100% /rom
tmpfs                    25.3M      2.7M     22.6M  11% /tmp
tmpfs                    25.3M     44.0K     25.2M   0% /tmp/root
tmpfs                   512.0K         0    512.0K   0% /dev
/dev/mtdblock2           50.0M      2.2M     47.8M   4% /overlay
overlayfs:/overlay       50.0M      2.2M     47.8M   4% /

Any assistance would be helpful.


Admin
Jo-Philipp Wich commented on 07.02.2017 19:00

It looks to me as if you're running out of ram.

Ron Brash commented on 07.02.2017 19:17

Agreed, however, top says there is 21MB free before executing the vpnbridge, and 18MB before the vpnclient.

Admin
Jo-Philipp Wich commented on 07.02.2017 20:11

And during the execution? Maybe there's also endian issues in softethervpn, causing it to allocate huge amounts of memory?

Ron Brash commented on 08.02.2017 14:46

I will investigate the execution, but you are correct - the memory consumption is what is causing this issue. I have removed portions of the applications such that I only need the vpncmd and vpnbridge applications; the device doesn't crash.

I also had to play with the sysctrl var for min_free_kbyres (lowered it to 2048, and have been experimenting with 1024) and this also is increasing system stability.

I may have to work with the gentlemen who provided the package softether to LEDE/Openwrt to help make it more modular to reduce the run-time size. He was only testing on MIPs.

Loading...

Available keyboard shortcuts

Tasklist

Task Details

Task Editing