You are not logged in.

Pages: 1

#1 2019-06-22 22:15:26

Jim
Member
Registered: 2019-06-22
Posts: 9

2255 hangs in the middle of the print

Is there some more descriptive log perhaps, where I could see the reason?..

It just suddenly "hangs" during the print (configuration with the Raspberry Pi + RAMPS board).

First time it hang on the level 11 with LEDs on, curing this level indefinitely, and after switching on the LED there were no "Curing for X seconds" record appeared in the log, it just continued to be curing indefinitely after switching on the LEDs... The "Stop" buttons did not do anything, it still continued (but UI was still responsive)... I was forced to switch the printer off to stop it.

Next time it hang on the level 8, immediately after "Shutter close" record: the LEDs went off this time, but after that no new records in the log, and it hang in this state indefinitely... Stopping it did not work too, so I was forced to hard-reboot it again. But the UI itself was working, so it was not a printer process crash or full-freeze...

It worked OK on the same printer with previous versions I tried...
Just let me know if you want me to debug it on my end somehow.

Last edited by Jim (2019-06-22 23:03:39)

Offline

#2 2019-06-23 00:00:15

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

Ah, found a printer.log file with some more info than in the UI. Don't see the "attach file to the post" functionality here, so here is the part of a last log around the layer 8 (where it got stuck). I tried to use "Stop" and "Force stop" buttons with no effect, so perhaps the "Using this function during printering is forbidden" lines may be a result of it, but maybe some other reason...
BTW, it did not move the platform up/down between layers during printing in the "out of the box" installation of NanoDLP (despite the fact the "lift after print" values are stated in the profile), so I was forced to add the "before" and "after" GCODE manually to the profile, is this normal?..

2019/06/22 21:10:19.105973 {"Layer":"4","module":"Gcode","level":"Notice","msg":"Position change 3.5 to 3.7"}
2019/06/22 21:10:19.106284 {"Layer":"4","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:19.183169 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:10:19.183494 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:19.210850 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:10:19.211281 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:21.242206 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:10:23.243489 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:10:24.427159 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:10:24.427431 {"Layer":"5","module":"Gcode","level":"Notice","msg":"Position set to 0.25"}
2019/06/22 21:10:24.427811 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:24.502368 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:10:24.502684 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:24.552430 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:10:24.552734 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:24.639660 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:10:24.728583 {"Layer":"5","module":"Image","level":"Warning","msg":"Display layer public/plates/1/5.png"}
{"time":"2019-06-22T21:10:46.973347001Z","level":"ERROR","prefix":"echo","file":"echo.go","line":"580","message":"code=404, message=Not Found"}
2019/06/22 21:11:08.966829 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:12.037341 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:11:14.036172 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:11:15.296211 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:11:15.296775 {"Layer":"5","module":"Gcode","level":"Notice","msg":"Position change 3.5 to 3.75"}
2019/06/22 21:11:15.296776 {"Layer":"5","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:15.373924 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:11:15.374380 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:15.401300 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:11:15.401615 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:17.432791 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:11:19.432905 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:11:20.616640 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:11:20.617010 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:20.617426 {"Layer":"6","module":"Gcode","level":"Notice","msg":"Position set to 0.3"}
2019/06/22 21:11:20.693173 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:11:20.693463 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:20.743146 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:11:20.743440 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:20.834148 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:11:20.922904 {"Layer":"6","module":"Image","level":"Warning","msg":"Display layer public/plates/1/6.png"}
2019/06/22 21:12:04.176391 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:07.246971 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:12:09.246774 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:12:10.507317 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:12:10.507813 {"Layer":"6","module":"Gcode","level":"Notice","msg":"Position change 3.5 to 3.8"}
2019/06/22 21:12:10.508138 {"Layer":"6","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:10.584827 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:12:10.585205 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:10.612190 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:12:10.612473 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:12.644777 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:12:14.645220 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:12:15.828911 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:12:15.829265 {"Layer":"7","module":"Gcode","level":"Notice","msg":"Position set to 0.35"}
2019/06/22 21:12:15.829320 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:15.904138 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:12:15.904442 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:15.954089 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:12:15.954411 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:16.042565 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:12:16.130413 {"Layer":"7","module":"Image","level":"Warning","msg":"Display layer public/plates/1/7.png"}
2019/06/22 21:12:58.387314 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:01.456603 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:13:03.456714 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:13:04.715403 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:13:04.715781 {"Layer":"7","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:04.716630 {"Layer":"7","module":"Gcode","level":"Notice","msg":"Position change 3.5 to 3.85"}
2019/06/22 21:13:04.794407 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:13:04.794922 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:04.820567 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:13:04.820837 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:06.852192 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:13:08.850935 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/22 21:13:10.035953 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/22 21:13:10.036376 {"Layer":"8","module":"Gcode","level":"Notice","msg":"Position set to 0.4"}
2019/06/22 21:13:10.038111 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:10.112622 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:13:10.113075 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:10.161467 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/22 21:13:10.161876 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:10.249722 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/22 21:13:10.338412 {"Layer":"8","module":"Image","level":"Warning","msg":"Display layer public/plates/1/8.png"}
2019/06/22 21:13:51.595547 {"Layer":"8","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
{"time":"2019-06-22T21:14:35.782535627Z","level":"ERROR","prefix":"echo","file":"echo.go","line":"580","message":"code=404, message=Not Found"}
{"time":"2019-06-22T21:14:43.747139397Z","level":"ERROR","prefix":"echo","file":"echo.go","line":"580","message":"code=404, message=Not Found"}
{"time":"2019-06-22T21:15:34.28993371Z","level":"ERROR","prefix":"echo","file":"echo.go","line":"580","message":"code=404, message=Not Found"}
2019/06/22 21:16:06.377037 {"Layer":"8","module":"Access Control","level":"Warning","msg":"Using this function during printering is forbidden"}
2019/06/22 21:16:14.374581 {"Layer":"8","module":"Access Control","level":"Warning","msg":"Using this function during printering is forbidden"}
printer: imageLayer.c:255: destroyImageLayer: Assertion `result == 0' failed.
SIGABRT: abort
PC=0x76cb345c m=2 sigcode=4294967290

goroutine 0 [idle]:
runtime: unknown pc 0x76cb345c
stack: frame={sp:0x6699c760, fp:0x0} stack=[0x6619d224,0x6699ce24)
6699c6e0:  00000000  00000000  00000000  00000000
6699c6f0:  00000000  00000000  00000000  00000000
6699c700:  00000000  00000000  00000000  00000000
6699c710:  76f742d0  6699c788  76c8a110  000001ea
6699c720:  6699c78c  76f5a624  00000001  76c8daf4
6699c730:  000001ea  76c94804  76f742d0  6699c78c
6699c740:  6699c788  76dc4078  6699d460  00000001
6699c750:  6699c874  6699c7e0  00000006  76cb33e0
6699c760: <00004000  00000000  76f80cf0  6699c7f8
6699c770:  76f81888  76f6d2bc  76f81000  00000000
6699c780:  76f75318  0000000f  00000000  00000000
6699c790:  00000000  3de00ec7  76f74488  00000000
6699c7a0:  6699c7f8  6699c800  6699c86c  76c99141
6699c7b0:  6699c854  76f5abfc  6699c800  76f81abc
6699c7c0:  00000009  76f75730  00000005  00000000
6699c7d0:  00000001  76f742d0  00000000  76dc3000
runtime: unknown pc 0x76cb345c
stack: frame={sp:0x6699c760, fp:0x0} stack=[0x6619d224,0x6699ce24)
6699c6e0:  00000000  00000000  00000000  00000000
6699c6f0:  00000000  00000000  00000000  00000000
6699c700:  00000000  00000000  00000000  00000000
6699c710:  76f742d0  6699c788  76c8a110  000001ea
6699c720:  6699c78c  76f5a624  00000001  76c8daf4
6699c730:  000001ea  76c94804  76f742d0  6699c78c
6699c740:  6699c788  76dc4078  6699d460  00000001
6699c750:  6699c874  6699c7e0  00000006  76cb33e0
6699c760: <00004000  00000000  76f80cf0  6699c7f8
6699c770:  76f81888  76f6d2bc  76f81000  00000000
6699c780:  76f75318  0000000f  00000000  00000000
6699c790:  00000000  3de00ec7  76f74488  00000000
6699c7a0:  6699c7f8  6699c800  6699c86c  76c99141
6699c7b0:  6699c854  76f5abfc  6699c800  76f81abc
6699c7c0:  00000009  76f75730  00000005  00000000
6699c7d0:  00000001  76f742d0  00000000  76dc3000

goroutine 1 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0x65162e4c, 0x72, 0x0)
    /usr/local/go/src/runtime/netpoll.go:182 +0x48
internal/poll.(*pollDesc).wait(0x107c834, 0x72, 0x0, 0x0, 0x5cda6c)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x80
internal/poll.(*pollDesc).waitRead(...)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0x107c820, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/internal/poll/fd_unix.go:384 +0x1b0
net.(*netFD).accept(0x107c820, 0x2e1abc7a, 0x0, 0x5d0e9a3b)
    /usr/local/go/src/net/fd_unix.go:238 +0x20
net.(*TCPListener).accept(0x1011678, 0x613e5c9a, 0x180, 0xee1abc7a)
    /usr/local/go/src/net/tcpsock_posix.go:139 +0x20
net.(*TCPListener).AcceptTCP(0x1011678, 0x1, 0x13da0, 0x28fab8)
    /usr/local/go/src/net/tcpsock.go:247 +0x40
github.com/labstack/echo.tcpKeepAliveListener.Accept(0x1011678, 0xe9a3b00, 0x49290, 0x294334, 0x1161e58)
    /home/pi/go/src/github.com/labstack/echo/echo.go:713 +0x1c
net/http.(*Server).Serve(0x108c580, 0x6a7658, 0x1011680, 0x0, 0x0)
    /usr/local/go/src/net/http/server.go:2859 +0x1e4
github.com/labstack/echo.(*Echo).StartServer(0x114c540, 0x108c580, 0x1, 0x5ebcd4)
    /home/pi/go/src/github.com/labstack/echo/echo.go:646 +0x2d4
projects/printer/app/web.Init(0x0)
    /home/pi/go/src/projects/printer/app/web/routes.go:38 +0x29c
main.main()
    /home/pi/printer/app/main.go:98 +0x424

goroutine 5 [chan receive, 29 minutes]:
projects/printer/app/move.(*speedStruct).calc(0xa598a0, 0x1052140)
    /home/pi/go/src/projects/printer/app/move/speed.go:94 +0x3c
created by projects/printer/app/move.init.1
    /home/pi/go/src/projects/printer/app/move/speed.go:31 +0x60

goroutine 8 [chan receive]:
projects/printer/app/machine.(*StatusStruct).FindIP(0xa59a78)
    /home/pi/go/src/projects/printer/app/machine/status.go:98 +0x5c
created by projects/printer/app/machine.(*StatusStruct).Load
    /home/pi/go/src/projects/printer/app/machine/status.go:74 +0x80

goroutine 35 [sleep]:
runtime.goparkunlock(...)
    /usr/local/go/src/runtime/proc.go:307
time.Sleep(0x77359400, 0x0)
    /usr/local/go/src/runtime/time.go:105 +0x15c
projects/printer/app/vendor/company/nanodlp-nextion/nextion.(*Configuration).TryConnect(0x1180000, 0x101bce0, 0xc)
    /home/pi/go/src/projects/printer/app/vendor/company/nanodlp-nextion/nextion/serial.go:107 +0x44
created by projects/printer/app/vendor/company/nanodlp-nextion/nextion.(*Configuration).Run
    /home/pi/go/src/projects/printer/app/vendor/company/nanodlp-nextion/nextion/nextion.go:7 +0xa4

goroutine 114 [chan receive]:
projects/printer/app/dash.UpdateControlPanel()
    /home/pi/go/src/projects/printer/app/dash/dashboard.go:33 +0x60
created by main.afterIP
    /home/pi/printer/app/main.go:127 +0x104

goroutine 19 [sleep]:
runtime.goparkunlock(...)
    /usr/local/go/src/runtime/proc.go:307
time.Sleep(0x540be400, 0x2)
    /usr/local/go/src/runtime/time.go:105 +0x15c
projects/printer/app/wifi.wifiStatus()
    /home/pi/go/src/projects/printer/app/wifi/wireless.go:44 +0xcc
created by projects/printer/app/wifi.ARMInit
    /home/pi/go/src/projects/printer/app/wifi/wireless.go:29 +0xd0

goroutine 14 [chan receive]:
projects/printer/app/hw/monitor.FreeMem()
    /home/pi/go/src/projects/printer/app/hw/monitor/memfree.go:11 +0x5c
created by main.main
    /home/pi/printer/app/main.go:74 +0x29c

goroutine 15 [syscall, 4 minutes]:
syscall.Syscall6(0x8e, 0x7, 0x10645780, 0x0, 0x10645800, 0x0, 0x0, 0x1, 0x0, 0x30)
    /usr/local/go/src/syscall/asm_linux_arm.s:45 +0x8
syscall.Select(0x7, 0x10645780, 0x0, 0x10645800, 0x0, 0x1, 0x138b8, 0x13aa4)
    /usr/local/go/src/syscall/zsyscall_linux_arm.go:1440 +0x6c
github.com/creack/goselect.sysSelect(...)
    /home/pi/go/src/github.com/creack/goselect/select_linux.go:8
github.com/creack/goselect.Select(0x7, 0x10645780, 0x0, 0x10645800, 0xffffffff, 0xffffffff, 0x0, 0x1)
    /home/pi/go/src/github.com/creack/goselect/select.go:16 +0x78
go.bug.st/serial.v1/unixutils.Select(0x115ee98, 0x0, 0x115ee98, 0xffffffff, 0xffffffff, 0x1d818, 0x65173948, 0x0)
    /home/pi/go/src/go.bug.st/serial.v1/unixutils/select.go:99 +0x80
go.bug.st/serial%2ev1.(*unixPort).Read(0x107a600, 0x31e192f, 0x1, 0x1, 0x0, 0x0, 0x0)
    /home/pi/go/src/go.bug.st/serial.v1/serial_unix.go:63 +0x104
projects/printer/app/hw/shield.(*Conf).Read(0xa595c8, 0x31e192f, 0x1, 0x1, 0x1, 0x0, 0x459984)
    /home/pi/go/src/projects/printer/app/hw/shield/shield.go:88 +0x1cc
projects/printer/app/hw.SlaveRead(...)
    /home/pi/go/src/projects/printer/app/hw/hardware.go:43
projects/printer/app/gcode.(*termStruct).readLine(0xa594d8, 0x31e192c, 0x3, 0x8)
    /home/pi/go/src/projects/printer/app/gcode/term.go:54 +0xb0
projects/printer/app/gcode.(*termStruct).Reader(0xa594d8)
    /home/pi/go/src/projects/printer/app/gcode/term.go:41 +0xbc
created by main.main
    /home/pi/printer/app/main.go:75 +0x2b8

goroutine 16 [chan receive]:
projects/printer/app/slicer.(*MonitorStruct).Watch(0xa59578)
    /home/pi/go/src/projects/printer/app/slicer/slicer.go:101 +0x78
created by main.main
    /home/pi/printer/app/main.go:76 +0x2d8

goroutine 51 [sleep]:
runtime.goparkunlock(...)
    /usr/local/go/src/runtime/proc.go:307
time.Sleep(0xa13b8600, 0x1)
    /usr/local/go/src/runtime/time.go:105 +0x15c
projects/printer/app/hw/monitor.Monitor()
    /home/pi/go/src/projects/printer/app/hw/monitor/monitor_linux.go:35 +0x40
created by main.main
    /home/pi/printer/app/main.go:82 +0x43c

goroutine 32 [IO wait]:
internal/poll.runtime_pollWait(0x65162b34, 0x72, 0x0)
    /usr/local/go/src/runtime/netpoll.go:182 +0x48
internal/poll.(*pollDesc).wait(0x12df644, 0x72, 0x400, 0x400, 0x0)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x80
internal/poll.(*pollDesc).waitRead(...)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).ReadFrom(0x12df630, 0x115bb44, 0x400, 0x400, 0x0, 0x0, 0x0, 0x0, 0x0)
    /usr/local/go/src/internal/poll/fd_unix.go:219 +0x16c
net.(*netFD).readFrom(0x12df630, 0x115bb44, 0x400, 0x400, 0x221, 0x6a3e00, 0x12b3601, 0x0, 0x4)
    /usr/local/go/src/net/fd_unix.go:208 +0x38
net.(*UDPConn).readFrom(0x1326058, 0x115bb44, 0x400, 0x400, 0x221, 0x59c4d, 0x21a, 0x1d5)
    /usr/local/go/src/net/udpsock_posix.go:47 +0x38
net.(*UDPConn).ReadFromUDP(0x1326058, 0x115bb44, 0x400, 0x400, 0xffffffff, 0x221, 0x0, 0x0)
    /usr/local/go/src/net/udpsock.go:109 +0x44
projects/printer/app/ssdp.Server(0x5ebcd4, 0x2, 0x108ad67, 0x8, 0x699b18, 0x4)
    /home/pi/go/src/projects/printer/app/ssdp/ssdp.go:58 +0x1b8
created by main.afterIP
    /home/pi/printer/app/main.go:125 +0xac

goroutine 36 [syscall, 4 minutes]:
syscall.Syscall6(0x8e, 0xc, 0x10645000, 0x0, 0x10645080, 0x0, 0x0, 0x43901, 0x0, 0x21)
    /usr/local/go/src/syscall/asm_linux_arm.s:45 +0x8
syscall.Select(0xc, 0x10645000, 0x0, 0x10645080, 0x0, 0x1d818, 0x65165028, 0x7f)
    /usr/local/go/src/syscall/zsyscall_linux_arm.go:1440 +0x6c
github.com/creack/goselect.sysSelect(...)
    /home/pi/go/src/github.com/creack/goselect/select_linux.go:8
github.com/creack/goselect.Select(0xc, 0x10645000, 0x0, 0x10645080, 0xffffffff, 0xffffffff, 0x0, 0x1)
    /home/pi/go/src/github.com/creack/goselect/select.go:16 +0x78
go.bug.st/serial.v1/unixutils.Select(0x1138ee0, 0x0, 0x1138ee0, 0xffffffff, 0xffffffff, 0x1487030, 0x10, 0x10)
    /home/pi/go/src/go.bug.st/serial.v1/unixutils/select.go:99 +0x80
go.bug.st/serial%2ev1.(*unixPort).Read(0x10ea1e0, 0x11540a0, 0x1, 0x1, 0x0, 0x0, 0x0)
    /home/pi/go/src/go.bug.st/serial.v1/serial_unix.go:63 +0x104
projects/printer/app/vendor/company/nanodlp-nextion/nextion.(*Configuration).readSerialPort(0x1180000)
    /home/pi/go/src/projects/printer/app/vendor/company/nanodlp-nextion/nextion/serial.go:41 +0x80
created by projects/printer/app/vendor/company/nanodlp-nextion/nextion.(*Configuration).Run
    /home/pi/go/src/projects/printer/app/vendor/company/nanodlp-nextion/nextion/nextion.go:16 +0x1a4

goroutine 37 [sleep]:
runtime.goparkunlock(...)
    /usr/local/go/src/runtime/proc.go:307
time.Sleep(0x3b9aca00, 0x0)
    /usr/local/go/src/runtime/time.go:105 +0x15c
projects/printer/app/hmi.printLoop()
    /home/pi/go/src/projects/printer/app/hmi/print.go:49 +0x9c0
projects/printer/app/hmi.updateLoop()
    /home/pi/go/src/projects/printer/app/hmi/engine.go:331 +0x184
created by projects/printer/app/hmi.startup
    /home/pi/go/src/projects/printer/app/hmi/hmi.go:71 +0x24

goroutine 2667 [IO wait]:
internal/poll.runtime_pollWait(0x65162dc8, 0x72, 0xffffffff)
    /usr/local/go/src/runtime/netpoll.go:182 +0x48
internal/poll.(*pollDesc).wait(0x1208924, 0x72, 0x1000, 0x1000, 0xffffffff)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x80
internal/poll.(*pollDesc).waitRead(...)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0x1208910, 0x1211000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/local/go/src/internal/poll/fd_unix.go:169 +0x184
net.(*netFD).Read(0x1208910, 0x1211000, 0x1000, 0x1000, 0x28b5a4, 0x14fcd44, 0xffffffff)
    /usr/local/go/src/net/fd_unix.go:202 +0x38
net.(*conn).Read(0x10ef7f8, 0x1211000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/net.go:177 +0x5c
net/http.(*connReader).Read(0x14fcd40, 0x1211000, 0x1000, 0x1000, 0x0, 0x96f20f65, 0xbf3bc51d)
    /usr/local/go/src/net/http/server.go:787 +0x168
bufio.(*Reader).fill(0x10eb320)
    /usr/local/go/src/bufio/bufio.go:100 +0x114
bufio.(*Reader).Peek(0x10eb320, 0x4, 0xbf3bc51d, 0x8997f122, 0x220, 0xa59718, 0x0)
    /usr/local/go/src/bufio/bufio.go:138 +0x38
net/http.(*conn).serve(0x1318300, 0x6a8478, 0x14fcd20)
    /usr/local/go/src/net/http/server.go:1903 +0x960
created by net/http.(*Server).Serve
    /usr/local/go/src/net/http/server.go:2884 +0x298

goroutine 2665 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0x65162f54, 0x72, 0xffffffff)
    /usr/local/go/src/runtime/netpoll.go:182 +0x48
internal/poll.(*pollDesc).wait(0x12087e4, 0x72, 0x1000, 0x1000, 0xffffffff)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:87 +0x80
internal/poll.(*pollDesc).waitRead(...)
    /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0x12087d0, 0x1373000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/local/go/src/internal/poll/fd_unix.go:169 +0x184
net.(*netFD).Read(0x12087d0, 0x1373000, 0x1000, 0x1000, 0x28b5a4, 0x14fdd24, 0xffffffff)
    /usr/local/go/src/net/fd_unix.go:202 +0x38
net.(*conn).Read(0x10ef7e8, 0x1373000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /usr/local/go/src/net/net.go:177 +0x5c
net/http.(*connReader).Read(0x14fdd20, 0x1373000, 0x1000, 0x1000, 0x0, 0x973c6860, 0xbf3bc519)
    /usr/local/go/src/net/http/server.go:787 +0x168
bufio.(*Reader).fill(0x10eb3e0)
    /usr/local/go/src/bufio/bufio.go:100 +0x114
bufio.(*Reader).Peek(0x10eb3e0, 0x4, 0xbf3bc519, 0xd035a9e8, 0x21c, 0xa59718, 0x0)
    /usr/local/go/src/bufio/bufio.go:138 +0x38
net/http.(*conn).serve(0x1318240, 0x6a8478, 0x14fdca0)
    /usr/local/go/src/net/http/server.go:1903 +0x960
created by net/http.(*Server).Serve
    /usr/local/go/src/net/http/server.go:2884 +0x298

goroutine 1426 [syscall, 4 minutes]:
projects/printer/app/viewer/manx._Cfunc_destroy_image()
    _cgo_gotypes.go:71 +0x30
projects/printer/app/viewer/manx.ClearImage()
    /home/pi/go/src/projects/printer/app/viewer/manx/manx_rpi.go:35 +0x20
projects/printer/app/hw.ShowBlank()
    /home/pi/go/src/projects/printer/app/hw/hardware.go:136 +0x118
projects/printer/app/print.printLayer(0x8, 0xb1d91c0, 0x9)
    /home/pi/go/src/projects/printer/app/print/printing.go:297 +0x484
projects/printer/app/print.Start(0x1, 0x1)
    /home/pi/go/src/projects/printer/app/print/printing.go:150 +0x34c
created by projects/printer/app/web.printerStart
    /home/pi/go/src/projects/printer/app/web/web.go:840 +0x118

trap    0x0
error   0x0
oldmask 0x4000
r0      0x0
r1      0x6699c760
r2      0x0
r3      0x8
r4      0x0
r5      0x6699c760
r6      0x6699d460
r7      0xaf
r8      0x6699c874
r9      0xff
r10     0x1000540
fp      0xa252f4
ip      0x20
sp      0x6699c760
lr      0xffffffff
pc      0x76cb345c
cpsr    0x10
fault   0x0
2019/06/22 21:04:19.368807 {"Layer":"0","module":"Hardware","level":"Notice","msg":"Initializing build # 2255 - generic"}
2019/06/22 21:04:19.406573 {"Layer":"0","module":"Terminal","level":"Notice","msg":"Terminal Reader Activated"}
...
...

Last edited by Jim (2019-06-23 00:01:59)

Offline

#3 2019-06-23 03:50:59

Yianni-VJ
Member
Registered: 2016-05-24
Posts: 95

Re: 2255 hangs in the middle of the print

I also experienced a crash mid print.

Offline

#4 2019-06-23 04:49:38

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

I see in the log I've posted here that the printer process is crashed by the assertion in imageLayer.c somewhere around the time when the [[Delay 0.5]] command I have in my "before layer" and "after layer" gcodes is executed...
So I've just removed the [[Delay 0.5]] from both "before" and "after" - and so far so good, it is printing right now the layer 35, fingers crossed so far haven't crashed...
So there is definitely some nasty crash bug asserted on the line 255 of the imageLayer.c...

Offline

#5 2019-06-23 04:54:23

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

Oops, I wrote too early... It just crashed immediately after I posted my previous message - exactly at the layer 35. wink
So, the [[Delay 0.5]] was nothing to do with this crash bug - it still crashes inside imageLayer.c...

Offline

#6 2019-06-23 09:04:34

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

Just tried to

sudo apt update && sudo apt upgrade

and started the printing again.
Right now it is printing the layer 61, and so far is still alive... wink

Will let you know how it ends up. If everything will be OK - then it might be the bug somewhere in the system GPU-related code which could have been fixed by the Pi system update/upgrade...

Offline

#7 2019-06-23 09:28:31

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

Nope.
It did the same crash at the layer 101. But this time there is no crash stacktrace in the log, it just silently died with the LED matrix switched ON (and without the next "Curing for X seconds" record in the UI log). So I did a hard-reset again, 'cause it doesn't react to any "Stop" buttons when this happens.

2019/06/23 09:17:06.503697 {"Layer":"99","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:06.504521 {"Layer":"99","module":"Gcode","level":"Notice","msg":"Position change 3.5 to 8.45"}
2019/06/23 09:17:06.582137 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:06.582562 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:06.608246 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:06.608528 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:08.638538 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/23 09:17:10.638517 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/23 09:17:11.822212 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/23 09:17:11.822557 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:11.823590 {"Layer":"100","module":"Gcode","level":"Notice","msg":"Position set to 5"}
2019/06/23 09:17:11.898719 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:11.899166 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:11.924534 {"Layer":"100","module":"Image","level":"Warning","msg":"Display layer public/plates/1/100.png"}
2019/06/23 09:17:11.951776 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:11.952252 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:11.952531 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:20.203239 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:22.777827 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/23 09:17:24.778096 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/23 09:17:26.037979 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/23 09:17:26.038658 {"Layer":"100","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:26.039169 {"Layer":"100","module":"Gcode","level":"Notice","msg":"Position change 3.5 to 8.5"}
2019/06/23 09:17:26.116875 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:26.117231 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:26.144274 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:26.144657 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:28.175498 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/23 09:17:30.175915 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:busy: processing↵"}
2019/06/23 09:17:31.361123 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: Z_move_comp↵"}
2019/06/23 09:17:31.361678 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:31.362198 {"Layer":"101","module":"Gcode","level":"Notice","msg":"Position set to 5.05"}
2019/06/23 09:17:31.437475 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:31.437871 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:31.467162 {"Layer":"101","module":"Image","level":"Warning","msg":"Display layer public/plates/1/101.png"}
2019/06/23 09:17:31.491577 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: echo:Unknown command: ''↵"}
2019/06/23 09:17:31.492016 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:31.492343 {"Layer":"101","module":"Terminal","level":"Notice","msg":"Received Data From Controller: ok↵"}
2019/06/23 09:17:09.227049 {"Layer":"0","module":"Hardware","level":"Notice","msg":"Initializing build # 2255 - generic"}
2019/06/23 09:17:09.271840 {"Layer":"0","module":"Terminal","level":"Notice","msg":"Terminal Reader Activated"}
...
...

So I can't use it in this state - it's not possible to leave it printing without sitting and watching it all the time...

Offline

#8 2019-06-24 10:12:30

Shahin
Administrator
Registered: 2016-02-17
Posts: 3,541

Re: 2255 hangs in the middle of the print

Maybe two issues are mixed. One is fixed with the firmware upgrade.
I guess the second issue is power related. Check if you are supplying stable power to pi.

Offline

#9 2019-06-24 10:56:27

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

Thank you for the advise!

The power supply is OK: it has twice the needed power (including UV), and it worked absolutely OK before...
But I agree that it looks like some hardware issue too: such random failures at different times often end up to be some GPU or CPU overheat... So, I've already ran one more test today - I've lowered the pixel frequency of the screen, and 267 layers printed without any problems and no freezes. I stopped it because it's late here (NZ), I'm going to bed already - don't want it to print unattended so far...
But tomorrow I'll run the full test: if it will not have any freezes, then it most likely was some kind of overheat or other hardware issue that looks like got resolved by lowering the frequency.
I'll let here know tomorrow if that solved the issue.

Offline

#10 2019-06-25 22:24:22

Jim
Member
Registered: 2019-06-22
Posts: 9

Re: 2255 hangs in the middle of the print

The full test went without any hiccups.

So, it was definitely some mixed issue, thank you Shahin.
The first issue (GPU code crash) had been fixed by the system update/upgrade.
The second issue has been fixed by lowering the screen pixel rate (hdmi_timings setting in /boot/config.txt).

So guys, if you experience freezes mid of the print - update/upgrade the system, and if that doesn't help, the stuck screen (GPU) hardware might be the reason of freezes - try to lower the pixel-rate, or ask the screen supplier for the exact hdmi_timings for that particular screen...

Offline

Pages: 1

Board footer

Powered by FluxBB