Out of memory

[giafar]

Using release Debian-USBProxy.img or git trunk version if I proxy my printer all the memory is eaten by usb-mint. Have you ever observed something like this ?

kern.log

Jul 6 09:48:39 arm kernel: [ 461.900119] usb-mitm invoked oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0 Jul 6 09:48:39 arm kernel: [ 461.908256] usb-mitm cpuset=/ mems_allowed=0 Jul 6 09:48:39 arm kernel: [ 461.912769] CPU: 0 PID: 2307 Comm: usb-mitm Not tainted 3.12.0-bone8 #1 Jul 6 09:48:39 arm kernel: [ 461.919779] from Jul 6 09:48:39 arm kernel: [ 461.928773] from Jul 6 09:48:39 arm kernel: [ 461.937324] from Jul 6 09:48:39 arm kernel: [ 461.946704] from Jul 6 09:48:39 arm kernel: [ 461.956694] from Jul 6 09:48:39 arm kernel: [ 461.966314] from Jul 6 09:48:39 arm kernel: [ 461.976582] from Jul 6 09:48:39 arm kernel: [ 461.987024] from Jul 6 09:48:39 arm kernel: [ 461.996643] from Jul 6 09:48:39 arm kernel: [ 462.005807] from Jul 6 09:48:39 arm kernel: [ 462.014505] Exception stack(0xddbf7fb0 to 0xddbf7ff8) Jul 6 09:48:39 arm kernel: [ 462.019828] 7fa0: 00001009 00009c99 16ac5368 00000000 Jul 6 09:48:39 arm kernel: [ 462.028437] 7fc0: b6b9d258 00001009 b6b9d694 16ac4368 0000aca0 00001018 00001008 00000063 Jul 6 09:48:39 arm kernel: [ 462.037044] 7fe0: b6b9d290 b024dcf8 b6b0ff37 b6b104ea 00000030 ffffffff Jul 6 09:48:39 arm kernel: [ 462.044005] Mem-info: Jul 6 09:48:39 arm kernel: [ 462.046403] Normal per-cpu: Jul 6 09:48:39 arm kernel: [ 462.049336] CPU 0: hi: 186, btch: 31 usd: 132 Jul 6 09:48:39 arm kernel: [ 462.054391] active_anon:122966 inactive_anon:41 isolated_anon:0 Jul 6 09:48:39 arm kernel: [ 462.054391] active_file:6 inactive_file:12 isolated_file:0 Jul 6 09:48:39 arm kernel: [ 462.054391] unevictable:0 dirty:0 writeback:3 unstable:0 Jul 6 09:48:39 arm kernel: [ 462.054391] free:686 slab_reclaimable:516 slab_unreclaimable:1168 Jul 6 09:48:39 arm kernel: [ 462.054391] mapped:18 shmem:52 pagetables:406 bounce:0 Jul 6 09:48:39 arm kernel: [ 462.054391] free_cma:0 Jul 6 09:48:39 arm kernel: [ 462.086755] Normal free:2744kB min:2848kB low:3560kB high:4272kB active_anon:491864kB inactive_anon:164kB active_file:24kB inactive_file:48kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:523264kB managed:508188kB mlocked:0kB dirty:0kB writeback:12kB mapped:72kB shmem:208kB slab_reclaimable:2064kB slab_unreclaimable:4672kB kernel_stack:888kB pagetables:1624kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:1991 all_unreclaimable? yes Jul 6 09:48:39 arm kernel: [ 462.130493] lowmem_reserve[]: 0 0 0 Jul 6 09:48:39 arm kernel: [ 462.134193] Normal: 0_4kB 1_8kB (R) 1_16kB (R) 1_32kB (R) 0_64kB 1_128kB (R) 0_256kB 1_512kB (R) 0_1024kB 1_2048kB (R) 0_4096kB 0_8192kB = 2744kB Jul 6 09:48:39 arm kernel: [ 462.148045] 77 total pagecache pages Jul 6 09:48:39 arm kernel: [ 462.151818] 0 pages in swap cache Jul 6 09:48:39 arm kernel: [ 462.155311] Swap cache stats: add 0, delete 0, find 0/0 Jul 6 09:48:39 arm kernel: [ 462.160809] Free swap = 0kB Jul 6 09:48:39 arm kernel: [ 462.163843] Total swap = 0kB Jul 6 09:48:39 arm kernel: [ 462.184362] 131072 pages of RAM Jul 6 09:48:39 arm kernel: [ 462.187732] 1037 free pages Jul 6 09:48:39 arm kernel: [ 462.190685] 4025 reserved pages Jul 6 09:48:39 arm kernel: [ 462.193998] 1684 slab pages Jul 6 09:48:39 arm kernel: [ 462.196929] 263080 pages shared Jul 6 09:48:39 arm kernel: [ 462.200238] 0 pages swap cached Jul 6 09:48:39 arm kernel: [ 462.203549] [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name Jul 6 09:48:39 arm kernel: [ 462.211843] [ 383] 0 383 574 104 3 0 -1000 udevd Jul 6 09:48:39 arm kernel: [ 462.220221] [ 493] 0 493 573 103 3 0 -1000 udevd Jul 6 09:48:39 arm kernel: [ 462.228569] [ 494] 0 494 573 103 3 0 -1000 udevd Jul 6 09:48:39 arm kernel: [ 462.236907] [ 715] 0 715 328 17 3 0 0 logsave Jul 6 09:48:39 arm kernel: [ 462.245424] [ 1312] 0 1312 328 17 3 0 0 logsave Jul 6 09:48:39 arm kernel: [ 462.253941] [ 1654] 0 1654 1027 430 4 0 0 dhclient Jul 6 09:48:39 arm kernel: [ 462.262551] [ 1845] 0 1845 6876 125 6 0 0 rsyslogd Jul 6 09:48:39 arm kernel: [ 462.271159] [ 1903] 0 1903 839 41 4 0 0 cron Jul 6 09:48:39 arm kernel: [ 462.279402] [ 1964] 101 1964 647 57 4 0 0 dbus-daemon Jul 6 09:48:39 arm kernel: [ 462.288290] [ 2022] 102 2022 717 73 4 0 0 avahi-daemon Jul 6 09:48:39 arm kernel: [ 462.297264] [ 2023] 102 2023 691 56 4 0 0 avahi-daemon Jul 6 09:48:39 arm kernel: [ 462.306239] [ 2062] 0 2062 1298 106 4 0 -1000 sshd Jul 6 09:48:39 arm kernel: [ 462.314484] [ 2086] 0 2086 836 34 4 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.322818] [ 2087] 0 2087 836 34 4 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.331152] [ 2088] 0 2088 836 34 4 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.339487] [ 2089] 0 2089 836 34 4 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.347826] [ 2090] 0 2090 836 34 4 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.356162] [ 2091] 0 2091 836 34 4 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.364496] [ 2092] 0 2092 416 33 3 0 0 getty Jul 6 09:48:39 arm kernel: [ 462.372830] [ 2097] 0 2097 2074 157 6 0 0 sshd Jul 6 09:48:39 arm kernel: [ 462.381074] [ 2099] 1000 2099 2074 155 5 0 0 sshd Jul 6 09:48:39 arm kernel: [ 462.389319] [ 2100] 1000 2100 1030 87 4 0 0 bash Jul 6 09:48:39 arm kernel: [ 462.397562] [ 2108] 1000 2108 749 22 4 0 0 tail Jul 6 09:48:39 arm kernel: [ 462.405805] [ 2111] 0 2111 2074 157 6 0 0 sshd Jul 6 09:48:39 arm kernel: [ 462.414047] [ 2113] 1000 2113 2074 155 5 0 0 sshd Jul 6 09:48:39 arm kernel: [ 462.422290] [ 2114] 1000 2114 1030 87 4 0 0 bash Jul 6 09:48:39 arm kernel: [ 462.430536] [ 2119] 1000 2119 1049 86 5 0 0 top Jul 6 09:48:39 arm kernel: [ 462.438687] [ 2120] 0 2120 2074 157 6 0 0 sshd Jul 6 09:48:39 arm kernel: [ 462.446931] [ 2122] 1000 2122 2074 155 5 0 0 sshd Jul 6 09:48:39 arm kernel: [ 462.455175] [ 2123] 1000 2123 1030 88 4 0 0 bash Jul 6 09:48:39 arm kernel: [ 462.463418] [ 2285] 0 2285 1018 76 4 0 0 sudo Jul 6 09:48:39 arm kernel: [ 462.471662] [ 2286] 0 2286 987 63 4 0 0 su Jul 6 09:48:39 arm kernel: [ 462.479723] [ 2287] 0 2287 1032 90 4 0 0 bash Jul 6 09:48:39 arm kernel: [ 462.487965] [ 2289] 0 2289 173150 120448 265 0 0 usb-mitm Jul 6 09:48:39 arm kernel: [ 462.496569] Out of memory: Kill process 2289 (usb-mitm) score 920 or sacrifice child Jul 6 09:48:39 arm kernel: [ 462.504736] Killed process 2289 (usb-mitm) total-vm:692600kB, anon-rss:481744kB, file-rss:48kB Jul 6 09:48:39 arm kernel: [ 466.343579] gadgetfs: disconnected

[dominicgs]

I haven't seen this before. Are you using a BeagleBone Black and the Debian image from the GitHub release?

What commandline options were you using with usb-mitm?

[giafar]

Hi dominic. I have used both the debian image and the git hub release with the same issue. I just run usb-mitm without any option; it seems the leak is in the relayer thread. The printer is a multifunctional one with 4 interfaces.

[giafar]

I have used, for the git hub release, libusb 1.0.19 and boost_1_55_0

[dominicgs]

Thanks for the information. What makes you think the leak is in the relayer thread, do you have any debug output that could help us to track it down?

How long does this problem take to occur? i.e. is it leaking memory very quickly, or over a long period of time?

[kfatehi]

Hi I am having the same issue (out of memory when trying to print something through the proxy).

I made a video, viewable here: https://www.youtube.com/watch?v=xJTm8Ey9HvY

How long does this problem take to occur? i.e. is it leaking memory very quickly, or over a long period of time?

As soon as I start usb-mitm, it begins gradually leaking memory.

Do you have any debug output that could help us to track it down?

Please advise how I can gather this. Currently I just have kern.log output:

Dec 21 04:36:17 arm kernel: [ 1329.786989] Out of memory: Kill process 2314 (usb-mitm) score 924 or sacrifice child
Dec 21 04:36:17 arm kernel: [ 1329.795144] Killed process 2314 (usb-mitm) total-vm:544524kB, anon-rss:484072kB, file-rss:124kB
Dec 21 04:36:17 arm kernel: [ 1330.036033] gadgetfs: disconnected

lsusb -v yields https://gist.github.com/keyvanfatehi/3ff62303c1996d9e176a

[dominicgs]

@keyvanfatehi I'm sorry that I didn't respond when you raised this, it was an unfortunate time of year to come across a bug in the project.

I don't have a specific fix for this, but there have been a lot of changes recently to fix these sorts of issues. If you're still interested in using USBProxy, would you be able to try again?

[corkz]

I can confirm this memory leak still exists when using usb-mitm with a printer. Memory gets filled fast, just a couple of minutes. Check link for log info.

https://gist.github.com/corkz/1aea74e06b6bb6c741f6

[dominicgs]

@corkz can you confirm software versions for me?

Usbproxy git revision? Kernel? Are you using the provided OS image?

[corkz]

Compiled last night from a fresh git clone of master.

Kernel 3.19.3 Not running on beaglebone, so definitely not running provided OS image. I do have a few beaglebone blacks, and various allwinner, i.mx, odroid etc. devices.

This was done on an i.mx for reference. If necessary, I can use the supplied image for beaglebone and run on that.

[corkz]

I've been digging around in the source a bit, definitely a problem with the RelayReader for IN endpoints. I have disabled them while keeping the OUT endpoint functional, and the printer will print, without memory exploding. Not actually a solution, just narrowing the scope of starting place for the hunt. Also of note, is CPU use is insanely high, as in 50 - 100%. I think it's constantly reading from the bulk ep IN('s) and just bloating itself to death. Will continue to delve further as there are other bugs to explore with other multifunctional printers as well that do not enumerate properly.

[palesius]

Sorry to resurrect this ancient thread but I was curious if you ever tried running USBProxy on an odroid? On Jun 28, 2015 4:09 AM, "corkz" notifications@github.com wrote:

I've been digging around in the source a bit, definitely a problem with the RelayReader for IN endpoints. I have disabled them while keeping the OUT endpoint functional, and the printer will print, without memory exploding. Not actually a solution, just narrowing the scope of starting place for the hunt. Also of note, is CPU use is insanely high, as in 50 - 100%. I think it's constantly reading from the bulk ep IN('s) and just bloating itself to death. Will continue to delve further as there are other bugs to explore with other multifunctional printers as well that do not enumerate properly.

— Reply to this email directly or view it on GitHub https://github.com/dominicgs/USBProxy/issues/6#issuecomment-116220916.

[dominicgs]

I have one on my desk which I have booted once. That's as far as I've got with running USBProxy on odroid.

[straithe]

I'm going to close this as there hasn't been a response from the original poster in a while, but please re-open this issue or open a new one if this issue is experienced again.