Hi,
I am using VirtualHere for some time, to connect my Sharp printer to my Windows10 pc via a RaspberryPi Model B+ running Raspbian OS with Jessie release.
I don't know when it started, but I began getting white pages and disaligned printings when printing via VirtualHere (If I connect the USB cable I don't have problems). So I updated the VirtualHere server and client, but it did not help. Sometimes it prints OK, but most of the time it does not. I usually print pdf files.
This weekend I formated my SD card, reinstalled the raspbian (now with the new Strech release), and VirtualHere server and clients, but the problem persists.
In var/log/syslog I get the folowing entries when the printing doesn't come right
Dec 4 20:29:47 motionpi kernel: [81064.674298] warn_alloc: 8 callbacks suppressed
Dec 4 20:29:47 motionpi kernel: [81064.674310] vhusbdarm: page allocation failure: order:4, mode:0x24040c0(GFP_KERNEL|__GFP_COMP)
Dec 4 20:29:47 motionpi kernel: [81064.674361] CPU: 0 PID: 1379 Comm: vhusbdarm Not tainted 4.9.59+ #1047
Dec 4 20:29:47 motionpi kernel: [81064.674367] Hardware name: BCM2835
Dec 4 20:29:47 motionpi kernel: [81064.674431] [] (unwind_backtrace) from [] (show_stack+0x20/0x24)
Dec 4 20:29:47 motionpi kernel: [81064.674461] [] (show_stack) from [] (dump_stack+0x20/0x28)
Dec 4 20:29:47 motionpi kernel: [81064.674498] [] (dump_stack) from [] (warn_alloc+0xf8/0x120)
Dec 4 20:29:47 motionpi kernel: [81064.674523] [] (warn_alloc) from [] (__alloc_pages_nodemask+0x3f8/0xda0)
Dec 4 20:29:47 motionpi kernel: [81064.674551] [] (__alloc_pages_nodemask) from [] (kmalloc_order+0x28/0x78)
Dec 4 20:29:47 motionpi kernel: [81064.674573] [] (kmalloc_order) from [] (kmalloc_order_trace+0x2c/0x90)
Dec 4 20:29:47 motionpi kernel: [81064.674606] [] (kmalloc_order_trace) from [] (__kmalloc+0x194/0x1f8)
Dec 4 20:29:47 motionpi kernel: [81064.674641] [] (__kmalloc) from [] (proc_do_submiturb+0xd9c/0xf08)
Dec 4 20:29:47 motionpi kernel: [81064.674662] [] (proc_do_submiturb) from [] (usbdev_ioctl+0x7cc/0x1a3c)
Dec 4 20:29:47 motionpi kernel: [81064.674688] [] (usbdev_ioctl) from [] (do_vfs_ioctl+0x9c/0x7d4)
Dec 4 20:29:47 motionpi kernel: [81064.674710] [] (do_vfs_ioctl) from [] (SyS_ioctl+0x44/0x6c)
Dec 4 20:29:47 motionpi kernel: [81064.674732] [] (SyS_ioctl) from [] (ret_fast_syscall+0x0/0x1c)
Dec 4 20:29:47 motionpi kernel: [81064.674738] Mem-Info:
Dec 4 20:29:47 motionpi kernel: [81064.674766] active_anon:2636 inactive_anon:4325 isolated_anon:0
Dec 4 20:29:47 motionpi kernel: [81064.674766] active_file:43452 inactive_file:43463 isolated_file:0
Dec 4 20:29:47 motionpi kernel: [81064.674766] unevictable:0 dirty:0 writeback:0 unstable:0
Dec 4 20:29:47 motionpi kernel: [81064.674766] slab_reclaimable:2856 slab_unreclaimable:3381
Dec 4 20:29:47 motionpi kernel: [81064.674766] mapped:4889 shmem:272 pagetables:199 bounce:0
Dec 4 20:29:47 motionpi kernel: [81064.674766] free:8749 free_pcp:0 free_cma:14
Dec 4 20:29:47 motionpi kernel: [81064.674788] Node 0 active_anon:10544kB inactive_anon:17300kB active_file:173808kB inactive_file:173852kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:19556kB dirty:0kB writeback:0kB shmem:1088kB writeback_tmp:0kB unstable:0kB pages_scanned:0 all_unreclaimable? no
Dec 4 20:29:47 motionpi kernel: [81064.674819] Normal free:34996kB min:16384kB low:20480kB high:24576kB active_anon:10544kB inactive_anon:17300kB active_file:173808kB inactive_file:173852kB unevictable:0kB writepending:0kB present:458752kB managed:444536kB mlocked:0kB slab_reclaimable:11424kB slab_unreclaimable:13524kB kernel_stack:1200kB pagetables:796kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:56kB
Dec 4 20:29:47 motionpi kernel: lowmem_reserve[]: 0 0
Dec 4 20:29:47 motionpi kernel: [81064.674836] Normal: 1207*4kB (UMEC) 3253*8kB (UME) 257*16kB (U) 1*32kB (M) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 34996kB
Dec 4 20:29:47 motionpi kernel: 87566 total pagecache pages
Dec 4 20:29:47 motionpi kernel: [81064.674909] 379 pages in swap cache
Dec 4 20:29:47 motionpi kernel: [81064.674916] Swap cache stats: add 3618, delete 3239, find 1412/1945
Dec 4 20:29:47 motionpi kernel: [81064.674920] Free swap = 94540kB
Dec 4 20:29:47 motionpi kernel: [81064.674924] Total swap = 102396kB
Dec 4 20:29:47 motionpi kernel: [81064.674929] 114688 pages RAM
Dec 4 20:29:47 motionpi kernel: [81064.674932] 0 pages HighMem/MovableOnly
Dec 4 20:29:47 motionpi kernel: [81064.674936] 3554 pages reserved
Dec 4 20:29:47 motionpi kernel: [81064.674940] 2048 pages cma reserved
Dec 4 20:29:47 motionpi kernel: [81064.696892] vhusbdarm: page allocation failure: order:4, mode:0x24040c0(GFP_KERNEL|__GFP_COMP)
Dec 4 20:29:47 motionpi kernel: [81064.696957] CPU: 0 PID: 1379 Comm: vhusbdarm Not tainted 4.9.59+ #1047
Dec 4 20:29:47 motionpi kernel: [81064.696963] Hardware name: BCM2835
Dec 4 20:29:47 motionpi kernel: [81064.697028] [] (unwind_backtrace) from [] (show_stack+0x20/0x24)
Dec 4 20:29:47 motionpi kernel: [81064.697054] [] (show_stack) from [] (dump_stack+0x20/0x28)
Dec 4 20:29:47 motionpi kernel: [81064.697094] [] (dump_stack) from [] (warn_alloc+0xf8/0x120)
Dec 4 20:29:47 motionpi kernel: [81064.697118] [] (warn_alloc) from [] (__alloc_pages_nodemask+0x3f8/0xda0)
Dec 4 20:29:47 motionpi kernel: [81064.697146] [] (__alloc_pages_nodemask) from [] (kmalloc_order+0x28/0x78)
Dec 4 20:29:47 motionpi kernel: [81064.697166] [] (kmalloc_order) from [] (kmalloc_order_trace+0x2c/0x90)
Dec 4 20:29:47 motionpi kernel: [81064.697201] [] (kmalloc_order_trace) from [] (__kmalloc+0x194/0x1f8)
Dec 4 20:29:47 motionpi kernel: [81064.697237] [] (__kmalloc) from [] (proc_do_submiturb+0xd9c/0xf08)
Dec 4 20:29:47 motionpi kernel: [81064.697258] [] (proc_do_submiturb) from [] (usbdev_ioctl+0x7cc/0x1a3c)
Dec 4 20:29:47 motionpi kernel: [81064.697284] [] (usbdev_ioctl) from [] (do_vfs_ioctl+0x9c/0x7d4)
Dec 4 20:29:47 motionpi kernel: [81064.697304] [] (do_vfs_ioctl) from [] (SyS_ioctl+0x44/0x6c)
Dec 4 20:29:47 motionpi kernel: [81064.697330] [] (SyS_ioctl) from [] (ret_fast_syscall+0x0/0x1c)
Dec 4 20:29:47 motionpi kernel: [81064.697337] Mem-Info:
Dec 4 20:29:47 motionpi kernel: [81064.697365] active_anon:2637 inactive_anon:4325 isolated_anon:0
Dec 4 20:29:47 motionpi kernel: [81064.697365] active_file:43432 inactive_file:43446 isolated_file:0
Dec 4 20:29:47 motionpi kernel: [81064.697365] unevictable:0 dirty:6 writeback:0 unstable:0
Dec 4 20:29:47 motionpi kernel: [81064.697365] slab_reclaimable:2856 slab_unreclaimable:3381
Dec 4 20:29:47 motionpi kernel: [81064.697365] mapped:4890 shmem:273 pagetables:199 bounce:0
Dec 4 20:29:47 motionpi kernel: [81064.697365] free:8787 free_pcp:0 free_cma:14
Dec 4 20:29:47 motionpi kernel: [81064.697388] Node 0 active_anon:10548kB inactive_anon:17300kB active_file:173728kB inactive_file:173784kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:19560kB dirty:24kB writeback:0kB shmem:1092kB writeback_tmp:0kB unstable:0kB pages_scanned:0 all_unreclaimable? no
Dec 4 20:29:47 motionpi kernel: [81064.697418] Normal free:35148kB min:16384kB low:20480kB high:24576kB active_anon:10548kB inactive_anon:17300kB active_file:173728kB inactive_file:173784kB unevictable:0kB writepending:24kB present:458752kB managed:444536kB mlocked:0kB slab_reclaimable:11424kB slab_unreclaimable:13524kB kernel_stack:1200kB pagetables:796kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:56kB
Dec 4 20:29:47 motionpi kernel: lowmem_reserve[]: 0 0
Dec 4 20:29:47 motionpi kernel: [81064.697435] Normal: 1215*4kB (UMEC) 3262*8kB (UME) 260*16kB (U) 1*32kB (U) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 35148kB
Dec 4 20:29:47 motionpi kernel: 87529 total pagecache pages
Dec 4 20:29:47 motionpi kernel: [81064.697511] 378 pages in swap cache
Dec 4 20:29:47 motionpi kernel: [81064.697518] Swap cache stats: add 3618, delete 3240, find 1413/1946
Dec 4 20:29:47 motionpi kernel: [81064.697522] Free swap = 94544kB
Dec 4 20:29:47 motionpi kernel: [81064.697526] Total swap = 102396kB
Dec 4 20:29:47 motionpi kernel: [81064.697531] 114688 pages RAM
Dec 4 20:29:47 motionpi kernel: [81064.697535] 0 pages HighMem/MovableOnly
Dec 4 20:29:47 motionpi kernel: [81064.697539] 3554 pages reserved
Dec 4 20:29:47 motionpi kernel: [81064.697543] 2048 pages cma reserved
Dec 4 20:29:47 motionpi kernel: [81064.729403] vhusbdarm: page allocation failure: order:4, mode:0x24040c0(GFP_KERNEL|__GFP_COMP)
Dec 4 20:29:47 motionpi kernel: [81064.729466] CPU: 0 PID: 1379 Comm: vhusbdarm Not tainted 4.9.59+ #1047
Dec 4 20:29:47 motionpi kernel: [81064.729473] Hardware name: BCM2835
Dec 4 20:29:47 motionpi kernel: [81064.729536] [] (unwind_backtrace) from [] (show_stack+0x20/0x24)
Dec 4 20:29:47 motionpi kernel: [81064.729563] [] (show_stack) from [] (dump_stack+0x20/0x28)
Dec 4 20:29:47 motionpi kernel: [81064.729602] [] (dump_stack) from [] (warn_alloc+0xf8/0x120)
Dec 4 20:29:47 motionpi kernel: [81064.729626] [] (warn_alloc) from [] (__alloc_pages_nodemask+0x3f8/0xda0)
Dec 4 20:29:47 motionpi kernel: [81064.729655] [] (__alloc_pages_nodemask) from [] (kmalloc_order+0x28/0x78)
Dec 4 20:29:47 motionpi kernel: [81064.729674] [] (kmalloc_order) from [] (kmalloc_order_trace+0x2c/0x90)
Dec 4 20:29:47 motionpi kernel: [81064.729709] [] (kmalloc_order_trace) from [] (__kmalloc+0x194/0x1f8)
Dec 4 20:29:47 motionpi kernel: [81064.729746] [] (__kmalloc) from [] (proc_do_submiturb+0xd9c/0xf08)
Dec 4 20:29:47 motionpi kernel: [81064.729769] [] (proc_do_submiturb) from [] (usbdev_ioctl+0x7cc/0x1a3c)
Dec 4 20:29:47 motionpi kernel: [81064.729796] [] (usbdev_ioctl) from [] (do_vfs_ioctl+0x9c/0x7d4)
Dec 4 20:29:47 motionpi kernel: [81064.729815] [] (do_vfs_ioctl) from [] (SyS_ioctl+0x44/0x6c)
Dec 4 20:29:47 motionpi kernel: [81064.729840] [] (SyS_ioctl) from [] (ret_fast_syscall+0x0/0x1c)
Dec 4 20:29:47 motionpi kernel: [81064.729846] Mem-Info:
Dec 4 20:29:47 motionpi kernel: [81064.729874] active_anon:2637 inactive_anon:4325 isolated_anon:0
Dec 4 20:29:47 motionpi kernel: [81064.729874] active_file:43412 inactive_file:43429 isolated_file:0
Dec 4 20:29:47 motionpi kernel: [81064.729874] unevictable:0 dirty:9 writeback:0 unstable:0
Dec 4 20:29:47 motionpi kernel: [81064.729874] slab_reclaimable:2856 slab_unreclaimable:3381
Dec 4 20:29:47 motionpi kernel: [81064.729874] mapped:4892 shmem:275 pagetables:199 bounce:0
Dec 4 20:29:47 motionpi kernel: [81064.729874] free:8824 free_pcp:0 free_cma:14
Dec 4 20:29:47 motionpi kernel: [81064.729896] Node 0 active_anon:10548kB inactive_anon:17300kB active_file:173648kB inactive_file:173716kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:19568kB dirty:36kB writeback:0kB shmem:1100kB writeback_tmp:0kB unstable:0kB pages_scanned:0 all_unreclaimable? no
Dec 4 20:29:47 motionpi kernel: [81064.729926] Normal free:35296kB min:16384kB low:20480kB high:24576kB active_anon:10548kB inactive_anon:17300kB active_file:173648kB inactive_file:173716kB unevictable:0kB writepending:36kB present:458752kB managed:444536kB mlocked:0kB slab_reclaimable:11424kB slab_unreclaimable:13524kB kernel_stack:1200kB pagetables:796kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:56kB
Dec 4 20:29:47 motionpi kernel: lowmem_reserve[]: 0 0
Dec 4 20:29:47 motionpi kernel: [81064.729945] Normal: 1212*4kB (UMEC) 3282*8kB (UME) 260*16kB (U) 1*32kB (E) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 35296kB
Dec 4 20:29:47 motionpi kernel: 87492 total pagecache pages
Dec 4 20:29:47 motionpi kernel: [81064.730019] 376 pages in swap cache
Dec 4 20:29:47 motionpi kernel: [81064.730026] Swap cache stats: add 3618, delete 3242, find 1415/1948
Dec 4 20:29:47 motionpi kernel: [81064.730030] Free swap = 94552kB
Dec 4 20:29:47 motionpi kernel: [81064.730034] Total swap = 102396kB
Dec 4 20:29:47 motionpi kernel: [81064.730039] 114688 pages RAM
Dec 4 20:29:47 motionpi kernel: [81064.730043] 0 pages HighMem/MovableOnly
Dec 4 20:29:47 motionpi kernel: [81064.730047] 3554 pages reserved
Dec 4 20:29:47 motionpi kernel: [81064.730051] 2048 pages cma reserved
Dec 4 20:29:47 motionpi kernel: [81064.747476] vhusbdarm: page allocation failure: order:4, mode:0x24040c0(GFP_KERNEL|__GFP_COMP)
Dec 4 20:29:47 motionpi kernel: [81064.747538] CPU: 0 PID: 1379 Comm: vhusbdarm Not tainted 4.9.59+ #1047
Dec 4 20:29:47 motionpi kernel: [81064.747545] Hardware name: BCM2835
Dec 4 20:29:47 motionpi kernel: [81064.747612] [] (unwind_backtrace) from [] (show_stack+0x20/0x24)
Dec 4 20:29:47 motionpi kernel: [81064.747640] [] (show_stack) from [] (dump_stack+0x20/0x28)
Dec 4 20:29:47 motionpi kernel: [81064.747676] [] (dump_stack) from [] (warn_alloc+0xf8/0x120)
Dec 4 20:29:47 motionpi kernel: [81064.747705] [] (warn_alloc) from [] (__alloc_pages_nodemask+0x3f8/0xda0)
Dec 4 20:29:47 motionpi kernel: [81064.747735] [] (__alloc_pages_nodemask) from [] (kmalloc_order+0x28/0x78)
Dec 4 20:29:47 motionpi kernel: [81064.747755] [] (kmalloc_order) from [] (kmalloc_order_trace+0x2c/0x90)
Dec 4 20:29:47 motionpi kernel: [81064.747786] [] (kmalloc_order_trace) from [] (__kmalloc+0x194/0x1f8)
Dec 4 20:29:47 motionpi kernel: [81064.747823] [] (__kmalloc) from [] (proc_do_submiturb+0xd9c/0xf08)
Dec 4 20:29:47 motionpi kernel: [81064.747845] [] (proc_do_submiturb) from [] (usbdev_ioctl+0x7cc/0x1a3c)
Dec 4 20:29:47 motionpi kernel: [81064.747871] [] (usbdev_ioctl) from [] (do_vfs_ioctl+0x9c/0x7d4)
Dec 4 20:29:47 motionpi kernel: [81064.747888] [] (do_vfs_ioctl) from [] (SyS_ioctl+0x44/0x6c)
Dec 4 20:29:47 motionpi kernel: [81064.747909] [] (SyS_ioctl) from [] (ret_fast_syscall+0x0/0x1c)
Dec 4 20:29:47 motionpi kernel: [81064.747914] Mem-Info:
Dec 4 20:29:47 motionpi kernel: [81064.747941] active_anon:2637 inactive_anon:4333 isolated_anon:0
Dec 4 20:29:47 motionpi kernel: [81064.747941] active_file:43402 inactive_file:43402 isolated_file:0
Dec 4 20:29:47 motionpi kernel: [81064.747941] unevictable:0 dirty:12 writeback:0 unstable:0
Dec 4 20:29:47 motionpi kernel: [81064.747941] slab_reclaimable:2856 slab_unreclaimable:3381
Dec 4 20:29:47 motionpi kernel: [81064.747941] mapped:4892 shmem:275 pagetables:199 bounce:0
Dec 4 20:29:47 motionpi kernel: [81064.747941] free:8855 free_pcp:0 free_cma:14
Dec 4 20:29:47 motionpi kernel: [81064.747966] Node 0 active_anon:10548kB inactive_anon:17332kB active_file:173608kB inactive_file:173608kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:19568kB dirty:48kB writeback:0kB shmem:1100kB writeback_tmp:0kB unstable:0kB pages_scanned:0 all_unreclaimable? no
Dec 4 20:29:47 motionpi kernel: [81064.747997] Normal free:35420kB min:16384kB low:20480kB high:24576kB active_anon:10548kB inactive_anon:17332kB active_file:173608kB inactive_file:173608kB unevictable:0kB writepending:48kB present:458752kB managed:444536kB mlocked:0kB slab_reclaimable:11424kB slab_unreclaimable:13524kB kernel_stack:1200kB pagetables:796kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:56kB
Dec 4 20:29:47 motionpi kernel: lowmem_reserve[]: 0 0
Dec 4 20:29:47 motionpi kernel: [81064.748143] Normal: 1201*4kB (UMEC) 3303*8kB (UME) 260*16kB (U) 1*32kB (U) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 35420kB
Dec 4 20:29:47 motionpi kernel: 87463 total pagecache pages
Dec 4 20:29:47 motionpi kernel: [81064.748222] 384 pages in swap cache
Dec 4 20:29:47 motionpi kernel: [81064.748229] Swap cache stats: add 3626, delete 3242, find 1415/1949
Dec 4 20:29:47 motionpi kernel: [81064.748233] Free swap = 94552kB
Dec 4 20:29:47 motionpi kernel: [81064.748237] Total swap = 102396kB
Dec 4 20:29:47 motionpi kernel: [81064.748242] 114688 pages RAM
Dec 4 20:29:47 motionpi kernel: [81064.748246] 0 pages HighMem/MovableOnly
Dec 4 20:29:47 motionpi kernel: [81064.748250] 3554 pages reserved
Dec 4 20:29:47 motionpi kernel: [81064.748254] 2048 pages cma reserved
Dec 4 20:29:47 motionpi kernel: [81064.791018] usb 1-1.2: Process 1379 (vhusbdarm) called USBDEVFS_RESETEP for active endpoint 0x05
Dec 4 20:29:47 motionpi kernel: [81064.802057] usb 1-1.2: Process 1379 (vhusbdarm) called USBDEVFS_CLEAR_HALT for active endpoint 0x05
Dec 4 20:29:47 motionpi kernel: [81064.803617] usb 1-1.2: Process 1379 (vhusbdarm) called USBDEVFS_RESETEP for active endpoint 0x05
Can you please advise?
Thank you.
.
Thats the first time ive ever seen this error. It shows that basically the raspbian kernel cannot allocate memory to hold the usb transfer. Your server does appear to have memory but it might be too fragmented. see here https://www.raspberrypi.org/forums/viewtopic.php?f=28&t=178150 try the turbo setting for the smsc
Hi Michael,
Hi Michael,
Thank you for your reply.
I forgot to mention that in my tests I noticed that the first couple of pages after a reboot printed correctly, but then stopped.
So, I read the post that you suggested and the posts inside it.
The thing i tried first was to remove the swap file, but it did not work so I added the "smsc95xx.turbo_mode=N" and still no progress.
I then started reducing gradually the vm.min_free_kbytes from 16384 until 1536, which apparently works. I am not sure I understand what this does, but I'll keep this value and continue checking.
Thank you for your support!