Consistent Communication Timeout

What is the problem?
Consistently Octopi will allow me to print for 40-50mins with no failure. RPi temp would be around 58-60C. 20mins into the next print, printer will stall.

What did you already try to solve it?

  1. Tried two (2) RPis 3 B

  2. Tried three (3) different power supplies. Links below:

First one because I have this lying around. Description says each USB port provides 2.4A

Second, bought this adapter that's rated at 3A. Tested on a RPi 3 using Retroarch and lightning bolt didn't show

Still tried isolating if it's a power issue, I tried a third power adapter bought from Microcenter.
https://www.microcenter.com/product/465196/51v-3a-power-supply-for-raspberry-pi-zero,-zero-w,-2---3-with-built-in-4ft-micro-usb-cable

All power supplies will produce the same behavior described above.

  1. Thinking it could be due to overheating, I added a heat sink to the RPi. Checked several logs and didn't find any text that says "overheating" or "throttled"

  2. Updated the RPi firmware doing the following commands:
    sudo rpi-update
    sudo apt-get update
    sudo apt-get upgrade

  3. Increased the timeout settings as described in this post:
    https://discourse.octoprint.org/t/i-see-a-lot-of-communication-timeout-messages-in-the-log/218

Before I give up, I thought maybe asking the community first. I kinda liked already the convenience that Octoprint provides but with numerous failed prints and trying out several solutions, still no luck.

Additional information about your setup (OctoPrint version, OctoPi version, printer, firmware, octoprint.log , serial.log or output on terminal tab, ...)

OctoPrint version: 1.3.10
OctoPi version: 0.15.1
Printer: Ultimaker 2+
Printer Firmware: Tinker 17.10.1
Pi: Raspberry Pi 3B
Camera: Raspberry Pi Camera Module

OctoPrint Log (last few lines before failure):

2018-12-15 01:16:57,700 - Send: N28837 G1 X116.258 Y55.227 E313.05349*80
2018-12-15 01:16:57,715 - Recv: ok
2018-12-15 01:16:57,718 - Send: N28838 G1 X120.028 Y57.405 E313.12516*81
2018-12-15 01:17:27,738 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2018-12-15 01:17:27,746 - Send: N28839 M105*47
2018-12-15 01:17:27,756 - Recv: Error:Line Number is not Last Line Number+1, Last Line: 28837
2018-12-15 01:17:27,758 - Recv: Resend: 28838
2018-12-15 01:17:27,765 - Recv: ok
2018-12-15 01:17:27,768 - Send: N28838 G1 X120.028 Y57.405 E313.12516*81
2018-12-15 01:17:27,777 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,780 - Recv: ok
2018-12-15 01:17:27,783 - Send: N28839 M105*47
2018-12-15 01:17:27,793 - Recv: ok T:42.6 /0.0 B:60.3 /60.0 B@:0 @:0
2018-12-15 01:17:27,802 - Send: N28840 M105*33
2018-12-15 01:17:27,809 - Recv: ok T:42.6 /0.0 B:60.3 /60.0 B@:0 @:0
2018-12-15 01:17:27,814 - Send: N28841 G1 X120.119 Y57.467 E313.12697*82
2018-12-15 01:17:27,830 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,831 - Recv: ok
2018-12-15 01:17:27,836 - Send: N28842 G1 X120.313 Y57.635 E313.13119*92
2018-12-15 01:17:27,846 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,850 - Recv: ok
2018-12-15 01:17:27,855 - Send: N28843 G1 X120.49 Y57.848 E313.13575*107
2018-12-15 01:17:27,862 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,866 - Recv: ok
2018-12-15 01:17:27,870 - Send: N28844 G1 X120.582 Y57.996 E313.13862*87
2018-12-15 01:17:27,879 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,882 - Recv: ok
2018-12-15 01:17:27,887 - Send: N28845 G1 X120.65 Y58.141 E313.14126*105
2018-12-15 01:17:27,895 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,899 - Recv: ok
2018-12-15 01:17:27,905 - Send: N28846 G1 X120.707 Y58.3 E313.14404*91
2018-12-15 01:17:27,916 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,918 - Recv: ok
2018-12-15 01:17:27,923 - Send: N28847 G1 X120.74 Y58.416 E313.14602*109
2018-12-15 01:17:27,932 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,936 - Recv: ok
2018-12-15 01:17:27,941 - Send: N28848 G1 X120.765 Y58.554 E313.14833*94
2018-12-15 01:17:27,948 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,952 - Recv: ok
2018-12-15 01:17:27,956 - Send: N28849 G1 X120.775 Y58.667 E313.1502*102
2018-12-15 01:17:27,969 - Recv: ok
2018-12-15 01:17:27,973 - Send: N28850 G1 X120.78 Y60.752 E313.18451*103
2018-12-15 01:17:27,982 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:27,986 - Recv: ok
2018-12-15 01:17:27,992 - Send: N28851 G1 X120.776 Y64.874 E313.25236*89
2018-12-15 01:17:28,006 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:28,009 - Recv: ok
2018-12-15 01:17:28,015 - Send: N28852 G1 X120.747 Y65.167 E313.2572*96
2018-12-15 01:17:28,022 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:28,026 - Recv: ok
2018-12-15 01:17:28,031 - Send: N28853 G1 X120.715 Y65.303 E313.2595*111
2018-12-15 01:17:28,039 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:28,043 - Recv: ok
2018-12-15 01:17:28,048 - Send: N28854 G1 X120.667 Y65.445 E313.26197*89
2018-12-15 01:17:28,058 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:28,060 - Recv: ok
2018-12-15 01:17:28,066 - Send: N28855 G1 X120.606 Y65.577 E313.26436*81
2018-12-15 01:17:28,075 - Recv: echo: cold extrusion prevented
2018-12-15 01:17:28,080 - Recv: ok
2018-12-15 01:17:28,086 - Send: N28856 G1 X120.518 Y65.729 E313.26726*85
2018-12-15 01:17:28,100 - Recv: ok
2018-12-15 01:17:28,105 - Send: N28857 G1 X120.425 Y65.861 E313.26991*90
2018-12-15 01:17:28,121 - Recv: echo: coldok
2018-12-15 01:17:58,150 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2018-12-15 01:17:58,163 - Send: N28858 M105*40
2018-12-15 01:18:28,192 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2018-12-15 01:18:28,205 - Send: N28859 M105*41
2018-12-15 01:18:28,214 - Recv: ok T:39.3 /0.0 B:59.9 /60.0 B@:127 @:0
2018-12-15 01:18:28,223 - Send: N28860 M105*35
2018-12-15 01:18:28,230 - Recv: ok T:39.3 /0.0 B:59.9 /60.0 B@:127 @:0
2018-12-15 01:18:28,238 - Send: N28861 M104 S210*99
2018-12-15 01:18:28,245 - Recv: ok
2018-12-15 01:18:28,250 - Send: N28862 G1 X120.049 Y66.301 E313.27944*85
2018-12-15 01:18:28,258 - Recv: echo: cold extrusion prevented
2018-12-15 01:18:28,261 - Recv: ok
2018-12-15 01:18:28,266 - Send: N28863 G1 X119.874 Y66.54 E313.28432*104
2018-12-15 01:18:28,275 - Recv: echo: cold extrusion prevented
2018-12-15 01:18:28,279 - Recv: ok
2018-12-15 01:18:28,284 - Send: N28864 G1 X119.722 Y66.778 E313.28896*88
2018-12-15 01:18:32,396 - Changing monitoring state from "Printing" to "Cancelling"
2018-12-15 01:18:32,418 - Send: N28865 M108*43
2018-12-15 01:18:58,301 - Communication timeout while printing, trying to trigger response from printer. Configure long running commands or increase communication timeout if that happens regularly on specific commands or long moves.
2018-12-15 01:18:58,302 - Send: N28866 M105*37
2018-12-15 01:18:58,315 - Recv: Error:Line Num
2018-12-15 01:18:58,317 - Changing monitoring state from "Cancelling" to "Error: Line Num"
2018-12-15 01:18:58,325 - Changing monitoring state from "Error: Line Num" to "Offline (Error: Line Num)"
2018-12-15 01:18:58,331 - Connection closed, closing down monitor

octoprint (2).log (252.2 KB)

serial (6).log (2.9 MB)

The good news is, your Pi indeed is not undervoltaged or overheating from the looks of your log. The bad news is that your printer still simply stops responding.

There's also this:

2018-12-15 01:18:28,250 - Send: N28862 G1 X120.049 Y66.301 E313.27944*85
2018-12-15 01:18:28,258 - Recv: echo: cold extrusion prevented
2018-12-15 01:18:28,261 - Recv: ok

and this where the cold extrusion message and the ok get garbled together:

2018-12-15 01:17:28,105 - Send: N28857 G1 X120.425 Y65.861 E313.26991*90
2018-12-15 01:17:28,121 - Recv: echo: coldok

You should first of all figure out why your firmware suddenly starts to trigger cold extrusion warnings. From your serial.log your printer's heaters still look like they are at temperature just before the first of such warnings arises, so this is really weird.

Secondly you should swap the cable between your pi and the printer to see if that fixes the mangled communication.

From the looks of it, I'd say it's rather a firmware/printer communication issue than something up with the Pi to be honest.

Thanks for your time looking at my issue @foosel. Really appreciate it.

Initially, I thought the "cold extrusion prevented" has something to do with my printers heater but when I'm printing from SD card (not using Octoprint), I can print several parts without encountering the cold extrusion.

I'll follow your advice and swap the USB cable connecting the RPi and the printer. I'll come back with my observations. Thanks again!

After 3 RPis (two 3 Bs, one 3 B+), 3 power supplies, 2 Sandisk Extreme SD cards, 2 USB cables, a heatsink & fan, and countless days of hair pulling, I think I may have finally resolved my issue.

I decided to isolate the issue one last time and decided to go underneath my UM2+ and change the motherboard. Afterwards, I was able to print 2+ hours straight without any serial communication issues! Good thing I had a spare motherboard lying around and was able to troubleshoot the issue.

Now I'm actually enjoying printing via Octoprint and not just printing knick knack parts for testing purposes. Thanks for all the work you've done @foosel for this wonderful software (Octoprint)!

It might not be the motherboard itself. It could be that you effectively just changed the firmware by doing that. (The other one could be good.)

Actually, forgot to mention that I've switched to stock firmware and back to Tinker firmware on the faulty motherboard and still no dice. While in the good motherboard, just one flash with the Tinker firmware and everything was good.

Next, I'd suggest checking the jumpers on the "bad" motherboard. I have a different controller board than yours but mine has a jumper which determines whether or not the board will sink 5V power on the serial line. That should be set to OFF if yours has one like that.

Mine faulty board looks like this...

It's got bunch of jumpers but nothing attached to any one of them.

The Safety 1 and Safety 2 jumpers (bottom left) are connected though both on this faulty board and the good board.

I think you're right that it may have to do with the board's serial communication coz I can print hours with no issue if I'm printing through the built-in SD card and firmware. But if I print through OctoPrint/RPi, that's when I experience serial communication timeouts.

The ones which could have something to do with this would, in theory, be close to both the input power and to the Type B USB connection.

And yet, the jumpers somewhere on the board do configure the step sizes. Neither the documentation nor the reprap page mentions anything about them.