search

Doodle3D / print3d

The application that runs on a Doodle3D WiFi box that communicates with printers.
www.doodle3d.com
GNU General Public License v2.0
13 stars 4 forks source link

Print3D crash #21

Closed peteruithoven closed 8 years ago

peteruithoven commented 9 years ago

@casperlamboo is currently running print3d from his laptop, controlled through his own Node.js API. Even then it suddenly stopped streaming. More debugging todo.

peteruithoven commented 8 years ago

This also happens when sending a bigger print, from the Doodle3D client (after increasing the max points amount and the number of lines per post). It looks like print3D stops working, In the /tmp/wifibox.log we see for example: 

12-21 15:20:54 (debug)     Response:error (error comunicating with server ((null)))

/tmp/print3d-ttyACM0.log: 

21-12 15:20:50  [MLD] append(): added 1008 bytes of gcode (1 chunks) in 3 ms
21-12 15:20:50  [CDH] received append gcode command with argument length 983
21-12 15:20:50  [MLD] append(): added 983 bytes of gcode (1 chunks) in 14 ms
Killed

logread: 

Mon Dec 21 15:19:45 2015 daemon.warn dnsmasq-dhcp[975]: no address range available for DHCP request via wlan0
Mon Dec 21 15:19:48 2015 daemon.warn dnsmasq-dhcp[975]: no address range available for DHCP request via wlan0
Mon Dec 21 15:20:16 2015 daemon.warn dnsmasq-dhcp[975]: no address range available for DHCP request via wlan0
Mon Dec 21 15:20:18 2015 daemon.warn dnsmasq-dhcp[975]: no address range available for DHCP request via wlan0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.260000] wpa_supplicant invoked oom-killer: gfp_mask=0x201da, order=0, oom_score_adj=0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.260000] CPU: 0 PID: 903 Comm: wpa_supplicant Not tainted 3.10.49 #4
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.270000] Stack : 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.270000]     00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.270000]     00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.270000]     00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.270000]     00000000 00000000 00000000 00000000 00000000 00000000 00000000 80f23b20
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.270000]     ...
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.300000] Call Trace:[<80203010>] 0x80203010
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.310000] [<80203010>] 0x80203010
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.310000] [<80255454>] 0x80255454
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.320000] [<802056e8>] 0x802056e8
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.320000] [<801a2d70>] 0x801a2d70
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.320000] [<801a3e70>] 0x801a3e70
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.330000] [<80081b44>] 0x80081b44
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.330000] [<8015ec70>] 0x8015ec70
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.330000] [<80120140>] 0x80120140
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.340000] [<8008a100>] 0x8008a100
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.340000] [<800e5b38>] 0x800e5b38
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.340000] [<80138ff0>] 0x80138ff0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.350000] [<80138dd0>] 0x80138dd0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.350000] [<8026332c>] 0x8026332c
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.350000] [<801041b8>] 0x801041b8
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.360000] [<801c2014>] 0x801c2014
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.360000] [<8007953c>] 0x8007953c
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.360000] [<80067ed0>] 0x80067ed0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.370000] [<8006fcb0>] 0x8006fcb0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.370000] [<80060820>] 0x80060820
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.370000] 
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.380000] Mem-Info:
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.380000] Normal per-cpu:
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.380000] CPU    0: hi:    0, btch:   1 usd:   0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.390000] active_anon:4233 inactive_anon:79 isolated_anon:0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.390000]  active_file:40 inactive_file:92 isolated_file:0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.390000]  unevictable:0 dirty:0 writeback:0 unstable:0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.390000]  free:162 slab_reclaimable:256 slab_unreclaimable:907
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.390000]  mapped:1 shmem:432 pagetables:103 bounce:0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.390000]  free_cma:0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.420000] Normal free:648kB min:680kB low:848kB high:1020kB active_anon:16932kB inactive_anon:316kB active_file:160kB inactive_file:368kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:32768kB managed:29172kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:1728kB slab_reclaimable:1024kB slab_unreclaimable:3628kB kernel_stack:376kB pagetables:412kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:572 all_unreclaimable? yMon Dec 21 15:20:54 2015 kern.warn kernel: [  612.460000] lowmem_reserve[]: 0 0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.460000] Normal: 0*4kB 1*8kB (R) 0*16kB 0*32kB 2*64kB (R) 0*128kB 0*256kB 1*512kB (R) 0*1024kB 0*2048kB 0*4096kB = 648kB
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.470000] 568 total pagecache pages
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.480000] 0 pages in swap cache
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.480000] Swap cache stats: add 0, delete 0, find 0/0
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.480000] Free swap  = 0kB
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.490000] Total swap = 0kB
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.490000] 8192 pages RAM
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.490000] 837 pages reserved
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.500000] 264080 pages shared
Mon Dec 21 15:20:54 2015 kern.warn kernel: [  612.500000] 6771 pages non-shared
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.500000] [ pid ]   uid  tgid total_vm      rss nr_ptes swapents oom_score_adj name
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.510000] [  371]     0   371      179       15       4        0             0 ubusd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.520000] [  372]     0   372      152       12       3        0             0 askfirst
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.530000] [  628]     0   628      230       48       4        0             0 logd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.530000] [  661]     0   661      345       53       4        0             0 netifd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.540000] [  715]     0   715      247       18       4        0             0 dropbear
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.550000] [  752]     0   752      583      143       4        0             0 uhttpd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.560000] [  903]     0   903      327       27       4        0             0 wpa_supplicant
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.570000] [  934]     0   934      287       16       3        0             0 udhcpc
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.570000] [  975] 65534   975      189       23       3        0             0 dnsmasq
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.580000] [ 1114]     0  1114      286       14       5        0             0 signin.sh
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.590000] [ 1116]     0  1116      285       12       3        0             0 sleep
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.600000] [ 1136]     0  1136      288       17       4        0             0 ntpd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.610000] [ 1184]     0  1184      286       14       4        0             0 print3d-manager
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.620000] [ 1194]     0  1194      285       13       3        0             0 inotifyd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.620000] [ 1210]     0  1210      287       15       4        0             0 print3d-runner.
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.630000] [ 1220]     0  1220     2613     2317       7        0             0 print3d
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.640000] [ 1261]     0  1261      264       37       4        0             0 dropbear
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.650000] [ 1271]     0  1271      289       18       3        0             0 ash
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.660000] [ 1282]     0  1282      287       16       4        0             0 tail
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.660000] [ 1310]     0  1310      264       37       4        0             0 dropbear
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.670000] [ 1335]     0  1335      289       18       4        0             0 ash
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.680000] [ 1370]     0  1370      287       15       4        0             0 tail
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.690000] [ 3538]     0  3538     1185      728       5        0             0 uhttpd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.700000] [ 3553]     0  3553      602      145       4        0             0 uhttpd
Mon Dec 21 15:20:54 2015 kern.info kernel: [  612.700000] [ 3556]     0  3556      532      141       4        0             0 uhttpd
Mon Dec 21 15:20:54 2015 kern.err kernel: [  612.710000] Out of memory: Kill process 1220 (print3d) score 306 or sacrifice child
Mon Dec 21 15:20:54 2015 kern.err kernel: [  612.720000] Killed process 1220 (print3d) total-vm:10452kB, anon-rss:9268kB, file-rss:0kB

With two prints, looking at the last successful d3dapi/info/status request the last buffered_lines amount was:

peteruithoven commented 8 years ago

To limit the logging we've made doodle3d-firmware and print3d log far less by default. https://github.com/Doodle3D/doodle3d-firmware/commit/f51e63e06a536000f6566d170cac794970708618 https://github.com/Doodle3D/print3d/commit/0280dd5c36eec7bf5a7cf3872c1b09df388a20fc This should at least prevent the type of crashed mentioned above.

olijf commented 8 years ago

Can this issue be closed? Seems fixed in https://github.com/Doodle3D/print3d/commit/0280dd5c36eec7bf5a7cf3872c1b09df388a20fc although @casperlamboo test points out that there might be a different problem....

peteruithoven commented 8 years ago

It is a different issue, because that commit (which makes it log less) fixes the issue that it runs out of memory. Since Casper tried this from his laptop this is a different issue. I'd say let's focus on running print3d on the WiFi-Box, let's close this when the tests Jeroen is performing finish without issues. I'll put it under the 0.10.10 milestone.

peteruithoven commented 8 years ago

For the release of the 0.10.10 we've done lot's of tests. I'm closing this issue for now.