Octoprint: Print aborts immediately after start

[christianh17]

What were you doing?

Yesterday I updated octoprint to the newest version (1.3.2) and today tried to print. The first print went without any problems but since then I always get an error (Serial Communication lost).
Till the update everything worked without any problems.
Edit 20170326 11:17: I just restarted octoprint and now it works. Perhaps it is a problem with the second print? I'll try and give an update.

What did you expect to happen and what happened instead?

It's obvious, I wanted to print but I got an error.

Branch & Commit or Version of OctoPrint

OctoPrint 1.3.2 (master branch)

Operating System running OctoPrint

OctoPi. But I am not sure how to determine the version. /proc/version shows: Linux version 4.4.34+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #930 Wed Nov 23 15:12:30 GMT 2016
and /etc/os-release:
PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)"
NAME="Raspbian GNU/Linux"
VERSION_ID="8"
VERSION="8 (jessie)"
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"

Printer model & used firmware incl. version

Prusa I3 Chinese clone, Firmware: Marlin rcbugfix from about march, 15th.

Browser and Version of Browser, Operating System running Browser

Firefox 52

Link to octoprint.log

[On gist.github.com or pastebin.com. ALWAYS INCLUDE and never truncate.]

Link to contents of terminal tab or serial.log

https://gist.github.com/christianh17/424e29841a61177619a15d1715f4eb4d and
https://gist.github.com/christianh17/b0829520f38bb3bca0a9cd0c6b6d1858
first one: Serial.log and second one: terminal

Link to contents of Javascript console in the browser

n/a

Screenshot(s) or video(s) showing the problem:

n/a

I have read the FAQ.

[foosel]

It appears to be hiccuping hard while reading from your GCODE file here:

2017-03-26 08:50:11,422 - octoprint.util.comm - ERROR - Exception while processing line
Traceback (most recent call last):
  File "/home/pi/oprint/local/lib/python2.7/site-packages/OctoPrint-1.3.2-py2.7.egg/octoprint/util/comm.py", line 2679, in getNext
    line = self._handle.readline()
  File "/home/pi/oprint/lib/python2.7/codecs.py", line 672, in readline
    return self.reader.readline(size)
  File "/home/pi/oprint/lib/python2.7/codecs.py", line 527, in readline
    data = self.read(readsize, firstline=True)
  File "/home/pi/oprint/lib/python2.7/codecs.py", line 486, in read
    self.charbuffer += newchars
TypeError: unsupported operand type(s) for +=: 'NoneType' and 'unicode'

That looks like a race condition that was already fixed on the maintenance branch. If that is indeed the same issue (the stack trace looks very much like it), that problem should be fixed in 1.3.3

To quote a6c4f8ba3b49f5364c133034c2b666589e65eed7:

When the sending of the first line of a file to print is still taking place while an "ok" from the firmware comes in, it's possible that two threads will try to access the file handle in parallel. That can lead to trouble within Python's codecs module.

[christianh17]

Hi! Thanks a lot. In the meantime I tried to reproduce the error but of course it did not happen again. I will wait for the next update. If it happens only while the print starts nothing serious will hapen and I can wait. Regards, Christian

[foosel]

As far as I understand the issue (it's been impossible to reproduce intentionally so far, and I only even noticed it because @Booli ran into it and reported it on IRC) it should only be possible to happen on start of a print, because that's the only point in time where concurrent access to the file handle should be possible. But take that with a grain of salt because I haven't been able to reproduce it so I'm only going on code understanding here. In any case, it's a very rare problem - otherwise we'd probably seen this way earlier too, that code has been in there for a while. If it turns out to show up way more frequently I'll see into increasing prio to push out 1.3.3, but right now I'd not consider this a high prio issue that needs immediate hotfixing (with associated release overhead).

[bolsoncerrado]

Just had the same or similar error right now, few seconds after upload completed (if it makes any sense):

"Send: M105
Recv: ok T:16.9 /0.0 B:16.2 /0.0 T0:16.9 /0.0 @:0 B@:0
Send: M105
Changing monitoring state from 'Operational' to 'Printing'
Recv: ok T:16.9 /0.0 B:16.2 /0.0 T0:16.9 /0.0 @:0 B@:0
Send: N0 M110 N0125
Recv: ok
Send: N1 G9017
Recv: ok
See octoprint.log for details
Changing monitoring state from 'Printing' to 'Error: TypeError: 'unsupported operand type(s) for +=: 'NoneType' and 'unicode'' @ comm.py:startPrint:780'
Changing monitoring state from 'Error: TypeError: 'unsupported operand type(s) for +=: 'NoneType' and 'unicode'' @ comm.py:startPrint:780' to 'Offline: TypeError: 'unsupported operand type(s) for +=: 'NoneType' and 'unicode'' @ comm.py:startPrint:780'
Connection closed, closing down monitor"

Perhaps something to do with the parser/stabilizer for the Gcode analysis?

Anyhow if this is fixed in 1.3.3, let it happen :P

[foosel]

1.3.3 was just released.