Seemly randomly raises Z to full height and goes to far corner and just extrudes

What is the problem?

When printing with octoprint, seemly randomly it raises Z to full height and goes to far corner and just extrudes.

What did you already try to solve it?

My apologizes but I do not know how to attempt to solve this. The problem never happens when printing directly from sd card. This issue has happened three times. I have been able to print about a dozen prints without issue using octoprint.

Terminal output

Recv:  T:17.38 /0.00 B:22.42 /0.00 @:0 B@:0
Recv:  T:17.54 /0.00 B:22.62 /0.00 @:0 B@:0
Unexpected error while reading serial port, please consult octoprint.log for details: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831
Please see https://faq.octoprint.org/serialerror for possible reasons of this.
Changing monitoring state from "Operational" to "Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831)"
Connection closed, closing down monitor

octoprint.log

2021-03-04 13:21:12,257 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 13:36:12,259 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 13:51:12,270 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 13:55:59,124 - octoprint.server.util.flask - INFO - Passively logging in user hendr1x from ::ffff:192.168.1.213
2021-03-04 13:55:59,125 - octoprint.access.users - INFO - Logged in user: hendr1x
2021-03-04 13:55:59,241 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.1.213
2021-03-04 13:56:00,462 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.213
2021-03-04 13:56:00,527 - octoprint.server.util.flask - INFO - Passively logging in user hendr1x from ::ffff:192.168.1.213
2021-03-04 13:56:00,527 - octoprint.access.users - INFO - Logged in user: hendr1x
2021-03-04 13:56:00,680 - octoprint.plugins.softwareupdate - INFO - Fetching check overlays from https://plugins.octoprint.org/update_check_overlay.json
2021-03-04 13:56:02,649 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2021-03-04 13:56:03,092 - octoprint.server.util.sockjs - INFO - User hendr1x logged in on the socket from client ::ffff:192.168.1.213
2021-03-04 13:56:11,546 - octoprint.util.comm - INFO - Starting job on behalf of user hendr1x
2021-03-04 13:56:11,561 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2021-03-04 13:56:11,575 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: Teckin_Light_Holder_-_Ender_5.gcode, owner: hendr1x, user: hendr1x
2021-03-04 13:56:11,626 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-03-04 13:56:11,636 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2021-03-04 14:06:12,272 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 14:21:12,272 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 14:26:04,483 - octoprint.util.comm - INFO - Finished in 1792.937 s.
2021-03-04 14:26:04,484 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Finishing"
2021-03-04 14:26:04,500 - octoprint.printer.standard.job - INFO - Print job done - origin: local, path: Teckin_Light_Holder_-_Ender_5.gcode, owner: hendr1x
2021-03-04 14:26:04,616 - octoprint.util.comm - INFO - Changing monitoring state from "Finishing" to "Operational"
2021-03-04 14:36:12,274 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 14:51:12,275 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 15:06:12,276 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 15:21:12,278 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-03-04 15:22:40,279 - octoprint.util.comm - ERROR - Unexpected error while reading from serial port
Traceback (most recent call last):
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 3831, in _readline
    ret = self._serial.readline()
  File "/home/pi/oprint/lib/python3.7/site-packages/octoprint/util/comm.py", line 6455, in readline
    c = self.read(1)
  File "/home/pi/oprint/lib/python3.7/site-packages/serial/serialposix.py", line 596, in read
    'device reports readiness to read but returned no data '
serial.serialutil.SerialException: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2021-03-04 15:22:40,287 - octoprint.util.comm - ERROR - Please see https://faq.octoprint.org/serialerror for possible reasons of this.
2021-03-04 15:22:40,291 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline (Error: SerialException: 'device reports readiness to read but returned no data (device disconnected or multiple access on port?)' @ comm.py:_readline:3831)"
2021-03-04 15:22:40,311 - octoprint.plugins.action_command_notification - INFO - Notifications cleared

Did it happen right after you saw this message in the terminal or did you turn the printer off when it happened?

Please upload a full octoprint.log - there is more stuff in it than just the error part :slight_smile: (for example which plugins you're using)

Thanks for your help. Here is entire log.

octoprint.log (10.7 KB)

In this situation I did not kill the power. I came back into the room after an hour and the "print" had completed.

I don't see anything wrong in the log.
It's hard to fix something that happens randomly.
What happens if you print the same gcode again after it failed? does it work the next time?

Yeah it works fine after a restart.

Well I guess it's a firmware glitch :man_shrugging:
maybe somebody else got an idea

A long time ago I had a similar issue with a firmware that did floating point calculations in an interrupt handler. That took so long that the serial communication got interrupted, and also led to timing issues in the stepper routines. The result was sudden move to the min or max on one axes paired with a flood of resend requests. I fixed it by removing the expensive calculations from the interrupt handler.

Hello foosel, can you provide any information on how I might look for such calculations? I'm not really clear if this is a setting in the firmware or something my slicer (cura) would be producing? Thank you.

It would be an implementation detail in the firmware, but there's no guarantee if that is really the issue here. Just an additional data point really, since it sounded so familiar

Currently, this is a theoretical conversation. We haven't been told what make and model printer, what version (and type) of firmware, etc.

@hendr1x wants to know where to look for such calculations and the generic answer would be in the firmware sources which may or may not be easily obtained. Not much else we can add unless we get more information.

I have an ender 5 running an SKR Mini E3 v2 board utilizing marlin 2.0.7.2

I would happy to do run any tests you would like, I've been printing with octoprint all day with no issue but with no changes either. If I am pretty much the only person having this issue then I'm fine ruling out octoprint as the culprit..however I never had this issue running directly from the SD card. This might be nothing but in my research I found that the SKR Mini E3 v2 board can have issues when running more then 256 kb firmware however today I tried compiling with less then 256 and could not get it to work (region `rom' overflowed error). Thanks for any help you can provide.

Scratch that...just did it again

The major difference between printing from the SD card and printing over USB (using OctoPrint) is the serial communications. Creality controller boards have a (bad) reputation for flaky serial implementation highly susceptible to EMI, RFI, grounding issues, etc.

I believe the BigTreeTech (SKR) boards have a better reputation but the major source of the EMI, the rest of the Creality hardware, is still the same.

The major debugging aid we have on this forum is the log files, and in this case, the serial.log captured when the error occurs (which in this case means enabled all the time). This log will help determine if OctoPrint is (or is not) involved in the failure. At this time, I believe we are leaning towards OctoPrint is innocent.

It appears that you have access to the firmware sources and the expertise to compile it. I don't know what facilities are available in Marlin for capturing debugging information, but that is most likely where you will have the best chance of discovering the source of this behavior.

The Marlin folks have forums and a Discord server and that is where the Marlin expertise hangs out.

Thank you for your thorough response. I had it happen again after my last post (last night).

At that time I noticed a low voltage alert. I'm not sure if it was present prior (if that shows up in the logs). Is it possible that could be causing my issue? My apologizes if it was occurring prior and I did not report it. I am new to this and didn't know to look for it.

I also had more information in my log this time octoprint (1).log (273.2 KB) which I have attached.

Lastly, in regards to RF interference. I don't know much about this subject. A quick google search did not give me any easy to find information. Is it possible to add shielding (or other fixes)? Last night, I actually ordered a 24v to 5v converter which I assume will generate even more noise, I'm assuming I should return it and get a standard plug adapter.

Thank you very much for your help.

Also, can I ask if there is a way to avoid this issue all together by using octoprint and using an sdcard?

Insufficient power to the RPi can cause all manner of abnormal behavior so I'd fix that first. Putting tape or otherwise preventing the USB 5V from providing power to the printer may also be needed. You do, however, want to keep the grounds connected together. A shielded USB cable with ferite beads is also recommended grounding the shield at both ends can help with the EMI / RFI as well.

It is possible to add additional shielding. Where and how much is difficult to say. The USB suggestions above would be my first priority.

I leave my RPi powered up all the time. It costs almost nothing and the convenience of having it available without powering up the printer is, IMO, worth it. This necessitates using a separate, proper, power supply (i.e. not a charger) and not a buck converter.

My printer is plugged into a smart plug which I can control from my always on RPi.

I do use a buck converter (24v -> 12v) which provides power to an RPi hat. The hat controls up to 4 PWM fans which I have installed to provide additional part cooling. I wrote a plugin which allows those fans to mirror the part cooling fan on the extruder (which is controlled by M106 commands in the gcode).

Thank you very much for your support. I am going to isolate my electronics better. The PI and the control board are going to separated to their own separate enclosures and I bought some copper tape that is suppose to help with RFI / EMI...I figured it was worth a try. I am going to make sure the power supply is providing ample power and upgrade the USB cable that I am using to have ferite (and wrap with copper tape).

Hopefully this sorts it out. Take care.