Problem with Octoprint

[inspire]

Problem?

First, My prints come out much better from SD card (exactly same gcode file) and idk why?
Second, most important, recently my printer stops printing, freezes on some random point, octopi freezes too, unfreeze when i pull out usb cable from ender...

What did you already try to solve it?

reflash printer, reinstall octopi

Have you tried running in safe mode?

no

Complete Logs

Full log in attachment (change the extension to .txt)
log.gcode (45.6 KB)
Part:
2021-02-03 17:42:40,994 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial connection"
2021-02-03 17:42:41,240 - octoprint.util.comm - INFO - Serial detection: Performing autodetection with 7 port/baudrate candidates: /dev/ttyUSB0@115200, /dev/ttyUSB0@250000, /dev/ttyUSB0@230400, /dev/ttyUSB0@57600, /dev/ttyUSB0@38400, /dev/ttyUSB0@19200, /dev/ttyUSB0@9600
2021-02-03 17:42:41,248 - octoprint.util.comm - INFO - Serial detection: Trying port /dev/ttyUSB0, baudrate 115200
2021-02-03 17:42:41,261 - octoprint.util.comm - INFO - Connecting to port /dev/ttyUSB0, baudrate 115200
2021-02-03 17:42:41,286 - octoprint.util.comm - INFO - Serial detection: Handshake attempt #1 with timeout 2.0s
2021-02-03 17:42:41,306 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-02-03 17:42:41,357 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial connection" to "Operational"
2021-02-03 17:42:41,408 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-02-03 17:42:42,188 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin 2.0.7.2 (Jan 25 2021"
2021-02-03 17:42:42,404 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2021-02-03 17:42:43,323 - octoprint.plugins.tracking - INFO - Sent tracking event printer_connected, payload: {u'printer_baudrate': 0, u'printer_port': None, u'firmware_name': u'Marlin 2.0.7.2 (Jan 25 2021'}
2021-02-03 17:42:45,478 - octoprint.plugins.DisplayLayerProgress - INFO - Limit of 500 reached and no M117 INDICATOR-Layer found
2021-02-03 17:42:45,486 - octoprint.plugins.DisplayLayerProgress - INFO - FilePreProcessor. Checking LayerExpressions.
2021-02-03 17:42:45,494 - octoprint.plugins.DisplayLayerProgress - INFO - FilePreProcessor. LayerExpression valid. Start processing...
2021-02-03 17:43:05,195 - octoprint.filemanager.analysis - INFO - Starting analysis of local:CE3PRO_test.gcode
2021-02-03 17:43:05,973 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile
2021-02-03 17:43:06,082 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile
2021-02-03 17:43:06,169 - octoprint.plugins.DisplayLayerProgress - INFO - Total height not found in MetaFile
2021-02-03 17:43:46,310 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile
2021-02-03 17:43:46,652 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile
2021-02-03 17:43:47,649 - octoprint.filemanager.analysis - INFO - Analysis of entry local:CE3PRO_test.gcode finished, needed 42.45s
2021-02-03 17:43:47,946 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile
2021-02-03 17:43:48,167 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile
2021-02-03 17:43:49,345 - octoprint.printer.standard.job - INFO - Print job selected - origin: local, path: CE3PRO_test.gcode, owner: _api, user: _api
2021-02-03 17:43:49,391 - octoprint.plugins.DisplayLayerProgress - INFO - File '/home/pi/.octoprint/uploads/CE3PRO_test.gcode' selected. Determining number of layers.
2021-02-03 17:43:49,524 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting"
2021-02-03 17:43:49,629 - octoprint.plugins.DisplayLayerProgress - INFO - Read total height from MetaFile
2021-02-03 17:43:49,652 - octoprint.printer.standard.job - INFO - Print job started - origin: local, path: CE3PRO_test.gcode, owner: _api, user: _api
2021-02-03 17:43:50,446 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2021-02-03 17:43:50,541 - octoprint.util.comm - INFO - Changing monitoring state from "Starting" to "Printing"
2021-02-03 17:43:52,900 - octoprint.util.comm - INFO - Printer seems to support the busy protocol, will adjust timeouts and set busy interval accordingly
2021-02-03 17:43:58,516 - octoprint.plugins.DisplayLayerProgress - INFO - Store layer count in MetaFile
2021-02-03 17:43:58,723 - octoprint.plugins.DisplayLayerProgress - INFO - File select-event processing done!'
2021-02-03 17:43:59,098 - octoprint.plugins.DisplayLayerProgress - INFO - Printing started. Detailed progress started.{u'origin': u'local', u'name': u'CE3PRO_test.gcode', u'user': u'_api', u'owner': u'_api', u'path': u'CE3PRO_test.gcode', u'size': 2215826L}
2021-02-03 17:43:59,779 - octoprint.plugins.tracking - INFO - Sent tracking event print_started, payload: {u'origin': u'local', u'file': 'd41210ec150a8ff6fb252898f06be2e31071873a'}
2021-02-03 17:44:53,409 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-02-03 17:45:34,732 - octoprint.util.comm - INFO - Telling the printer to set the busy interval to our "communicationBusy" timeout - 1s = 2s
2021-02-03 17:46:03,189 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 9984}
2021-02-03 17:49:14,045 - octoprint.util.comm - INFO - Ignoring resend request for line 265 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 17:53:14,788 - octoprint.util.comm - INFO - Ignoring resend request for line 647 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 17:56:23,916 - octoprint.util.comm - INFO - Ignoring resend request for line 1308 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 17:57:27,745 - octoprint.util.comm - INFO - Ignoring resend request for line 1402 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 17:59:53,423 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-02-03 18:01:03,266 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 10884}
2021-02-03 18:12:46,018 - octoprint.server.util.flask - INFO - Passively logging in user _api from ::ffff:192.168.0.100
2021-02-03 18:12:46,033 - octoprint.access.users - INFO - Logged in user: _api
2021-02-03 18:13:13,921 - octoprint.util.comm - INFO - Ignoring resend request for line 2874 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 18:14:53,438 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-02-03 18:16:03,583 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 11784}
2021-02-03 18:18:27,534 - octoprint.server.views - WARNING - Client requested cache refresh via cache-control headers but we are printing. Not invalidating caches due to resource limitation. Append ?_refresh=true to the URL if you absolutely require a refresh now
2021-02-03 18:26:43,484 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:192.168.0.100
2021-02-03 18:29:53,448 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-02-03 18:31:03,329 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 12684}
2021-02-03 18:31:10,170 - octoprint.util.comm - INFO - Ignoring resend request for line 5960 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 18:34:42,951 - octoprint.util.comm - INFO - Ignoring resend request for line 6706 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 18:36:36,140 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 7122, current line = 7123
| Last lines in terminal:
| Recv: ok
| Send: N7114 G3 X169.286 Y116.028 I-7.663 J6.119 E3618.7914127
| Recv: ok
| Send: N7115 G3 X168.962 Y120.378 I-9.71 J1.465 E3618.99616117
| Recv: ok
| Send: N7116 G3 X166.781 Y124.162 I-9.391 J-2.894 E3619.20123101
| Recv: ok
| Send: N7117 G3 X162.48 Y126.862 I-7.197 J-6.685 E3619.4403492
| Recv: ok
| Send: N7118 G3 X159.588 Y127.296 I-2.898 J-9.46 E3619.5769984
| Recv: ok
| Send: N7119 G1 X153.062 Y127.297 E3619.8809297
| Recv: ok
| Send: N7120 G2 X137.539 Y131.592 I0 J30.196 E3620.6399771
| Recv: ok
| Send: N7121 G1 X84.227 Y163.547 E3623.5342288
| Recv: T:209.37 /210.00 B:60.00 /60.00 @:83 B@:34
| Recv: ok
| Send: N7122 G1 X83.492 Y163.954 E3623.5733494
| Recv: Resend: 7122
2021-02-03 18:36:36,248 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 7123, current line = 7125
| Last lines in terminal:
| Recv: ok
| Send: N7118 G3 X159.588 Y127.296 I-2.898 J-9.46 E3619.5769984
| Recv: ok
| Send: N7119 G1 X153.062 Y127.297 E3619.8809297
| Recv: ok
| Send: N7120 G2 X137.539 Y131.592 I0 J30.196 E3620.6399771
| Recv: ok
| Send: N7121 G1 X84.227 Y163.547 E3623.5342288
| Recv: T:209.37 /210.00 B:60.00 /60.00 @:83 B@:34
| Recv: ok
| Send: N7122 G1 X83.492 Y163.954 E3623.5733494
| Recv: Resend: 7122
| Recv: ok
| Send: N7122 G1 X83.492 Y163.954 E3623.5733494
| Recv: ok
| Send: N7123 G0 F9750 X83.293 Y163.56268
| Recv: ok
| Send: N7124 G0 X83.029 Y163.6430
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 7122
| Recv: Resend: 7123
2021-02-03 18:44:53,469 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2021-02-03 18:46:03,440 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 13584}
2021-02-03 18:48:44,628 - octoprint.util.comm - INFO - Ignoring resend request for line 11272 == current line, we haven't sent that yet so the printer got N-1 twice from us, probably due to a timeout
2021-02-03 18:50:11,054 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 12253, current line = 12255
| Last lines in terminal:
| Recv: ok
| Send: N12247 G3 X159.574 Y126.897 I-2.77 J-9.085 E850.9040293
| Recv: ok
| Send: N12248 G1 X153.058 Y126.897 E851.20744111
| Recv: ok
| Send: N12249 G2 X137.337 Y131.247 I0.004 J30.595 E851.9761683
| Recv: T:209.37 /210.00 B:60.00 /60.00 @:81 B@:35
| Recv: ok
| Send: N12250 G1 X84.033 Y163.197 E854.8699995
| Recv: ok
| Send: N12251 G1 X83.302 Y163.602 E854.9089108
| Recv: ok
| Send: N12252 G0 F9750 X83.492 Y163.954123
| Recv: ok
| Send: N12253 G3 X77.843 Y165.296 I-5.594 J-10.981 E855.18178 F195012
| Recv: echo:Unknown command: "12253 G3 X77.843 Y165.296 I-5.594 J-10.981 E855.18178 F1950"
| Recv: ok
| Send: N12254 G3 X72.209 Y163.9 I0.055 J-12.28 E855.45453*127
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 12252
| Recv: Resend: 12253
2021-02-03 18:57:31,221 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 15091, current line = 15092

Additional information about your setup

Ender 3 Pro V4.2.2 with Marlin 2.0.7.2

Octopi (latest) on Raspberry 1 B+ overlocked to 1ghz,
OS running from USB drive
webcam (old, slow, low quality)
Plugins:
Dashboard (1.17.0)
DisplayLayerProgress Plugin (1.25.3) only for send to printer screen progress %, left time
PrintTimeGenius Plugin (2.2.7)
Themeify (1.2.2)

Slicer: latest Cura with ArcWelds

[Ewald_Ikemann]

Hello @inspire !

Please do not rename the octoprint.log to something else. (A log is a log, not a gcode file)

@inspire

log.gcode (45.6 KB)

This seems to be an excerpt too. Please send full logs.

@inspire

Have you tried running in safe mode?

no

Why not? It could help if it is a plugin.

From the lots of resend request you may check the USB connection from the Pi to the printer.

[b-morgan]

Creality hardware is notoriously bad at serial (USB) communication. It is very sensitive to the quality of the USB cable, EMI interference, power, and ground issues. Most often, cutting the 5V wire or taping the 5V pin (at the RPi end) in the USB cable is required.

No amount of reflashing and reinstalling is going to fix the problem. You have to solve the hardware communications issue first. Lots of topics in this forum on how to do that.

[inspire]

@b-morgan

Creality hardware is notoriously bad at serial (USB) communication. It is very sensitive to the quality of the USB cable, EMI interference, power, and ground issues. Most often, cutting the 5V wire or taping the 5V pin (at the RPi end) in the USB cable is required.

Done, nothing change...
Its brand new cable.

Safe mode don't help too.

I bought another one but don't test it yet.

[b-morgan]

The USB cable should be shielded with ferrite cores at both ends and usually as short as possible (around 3ft). Make sure it is a data cable as many USB cables with a micro USB connector are charge only.

While the Creality controller boards are sensitive to EMI, the rest of the Creality printer hardware is an above normal EMI generator. Changing the location of the RPi relative to the rest of the printer can make a difference.

[inspire]

@b-morgan

The USB cable should be shielded with ferrite cores

Ordered next with ferrites

@b-morgan

While the Creality controller boards are sensitive to EMI, the rest of the Creality printer hardware is an above normal EMI generator. Changing the location of the RPi relative to the rest of the printer can make a difference.

My Pi always was 1m from printer, as far as the cable allowed.
From SD, prints looks fine and printer is behaving normally, so i think it's not printer fault.

[foosel]

Also check out

My Creality Ender3 runs into a lot of communication issues

A lot of resend requests or a high resend ratio in OctoPrint can be quite a problem when trying to reliably print. For Creality Ender3s - apart from the usual suspects - this can apparently also be caused by the LCD cable, as user @flrnwgnr reported. To quote: [...] The day before i printed a drawer and pushed the cable for the LCD just behind it - like this: [Cabling before] And that was the problem! After i re-arranged the cable according to the picture below (as I had it before and as …

[inspire]

idk what's going on, next cable and exactly the same... logs very similar

maybe my Pi is too slow?

[inspire]

it didn't change anything

[b-morgan]

@inspire

maybe my Pi is too slow?

Did I read it right? You are using a RPi 1? I think you've gotten your money's worth out of that one and you should seriously consider an RPi 3B, 3B+, or 4B (you don't need more that 2GB of memory).

There is, of course, the possibility that your Creality printer with a Creality controller board is never going to communicate reliably over a USB connection. You might search this forum for BTT or BigTreeTech as their controller board appears to be working better for a lot of folks.

[inspire]

@b-morgan

You are using a RPi 1?

Yes, but i think memory is not a problem here(I've never seen more than 60-65% of usage), while CPU usage most of the time is 70-100%

Maybe i'll try to print directly from pc, I have never tried it.