OctoPrint-FlashForge
OctoPrint-FlashForge copied to clipboard
Mrnt
0.2.4 can't process simplify3d gcode file when printing from SD Card
Hi, I used Upload to SD card, then printed from that - I get these kinds of messages in the log 2020-09-25 14:43:37,492 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): dropping command 2020-09-25 14:43:37,493 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:G1, cmd:G1 X1.482 Y-9.400 E1.5032
The extruder sounds like it's grinding or skipping steps or something. I also see this: 2020-09-25 16:23:46,385 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:46,387 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,389 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:46,391 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:46,392 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:46,394 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:46,395 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:46,398 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,400 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,402 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:46,403 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:47,364 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:47,364 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:47,366 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:47,367 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:47,376 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:47,377 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,380 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:47,382 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:47,383 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:47,384 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:47,384 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:47,386 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,387 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,388 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:47,388 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:48,359 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M105, cmd:M105 2020-09-25 16:23:48,360 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:48,363 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:48,364 - octoprint.plugins.flashforge - DEBUG - write() M105 2020-09-25 16:23:48,367 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:48,369 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:48,374 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M105 Received. | T0:28 /0 B:0/0 | ok | 2020-09-25 16:23:48,374 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M105 Received. 2020-09-25 16:23:48,376 - octoprint.plugins.flashforge - DEBUG - buffering: T0:28 /0 B:0/0 2020-09-25 16:23:48,377 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:48,380 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,383 - octoprint.util.comm - INFO - Externally triggered heatup detected 2020-09-25 16:23:48,395 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,397 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,399 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:48,400 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:48,401 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:48,411 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:48,412 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,414 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:48,417 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:48,418 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:48,420 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:48,421 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:48,423 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,426 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,429 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:48,430 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:49,371 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:49,373 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:49,376 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:49,378 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:49,386 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:49,388 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,389 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:49,392 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:49,393 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:49,394 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:49,396 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:49,402 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,408 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,411 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:49,413 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:50,375 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:50,376 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:50,378 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:50,380 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:23:50,389 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: READY | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:23:50,390 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,392 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:50,395 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:23:50,396 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:23:50,398 - octoprint.plugins.flashforge - DEBUG - buffering: Not SD printing 2020-09-25 16:23:50,399 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:23:50,402 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,404 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,407 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:23:50,407 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:23:51,378 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:23:51,379 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:23:51,382 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:23:51,387 - octoprint.plugins.flashforge - DEBUG - write() M119
I use Simplify 3D to slice, and the gcode files directly out of that always work if I load them via a usb flash drive at the unit directly.
If you upload to the address card using “Upload to SD” the file should go straight to the SD card and you should just see printing progress type messages in the log which looks like what you have. The plugin does not parse the uploaded file and alter it. It is a bit of a red flag that it says the total bytes it is/was printing is 1000. If you look further back in the log you should see the actual upload happening with progress in %. Make sure that got to 100%. There will be an M29 command at the end of the upload which should get a non error response.
If you can upload a fresh OctoPrint.log captured during an SD upload that doesn’t print it would be helpful.
I should note, the printer never actually does anything - the hot end doesn't heat up, nothing. Just sits there. The display shows what appears to be a print job, but ... just sits.
mo' log 2020-09-25 16:21:33,996 - octoprint.plugins.flashforge - DEBUG - writeraw() called by thread FlashForge.SD_Uploader 2020-09-25 16:21:33,997 - octoprint.plugins.flashforge - DEBUG - Sent: 99.00% 248832/250896 2020-09-25 16:21:33,998 - octoprint.plugins.flashforge - DEBUG - writeraw() called by thread FlashForge.SD_Uploader 2020-09-25 16:21:33,999 - octoprint.plugins.flashforge - DEBUG - Sent: 99.00% 249856/250896 2020-09-25 16:21:34,001 - octoprint.plugins.flashforge - DEBUG - writeraw() called by thread FlashForge.SD_Uploader 2020-09-25 16:21:34,002 - octoprint.plugins.flashforge - DEBUG - Sent: 99.00% 250880/250896 2020-09-25 16:21:34,003 - octoprint.plugins.flashforge - DEBUG - writeraw() called by thread FlashForge.SD_Uploader 2020-09-25 16:21:34,004 - octoprint.plugins.flashforge - DEBUG - Sent: 100.00% 250896/250896 2020-09-25 16:21:34,005 - octoprint.plugins.flashforge - DEBUG - sendcommand() M29 2020-09-25 16:21:34,006 - octoprint.plugins.flashforge - DEBUG - writeraw() called by thread FlashForge.SD_Uploader 2020-09-25 16:21:34,007 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: FlashForge.SD_Uploader, timeout: 10000 2020-09-25 16:21:34,052 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M29 Received. | Done saving file. | ok | 2020-09-25 16:21:34,052 - octoprint.plugins.flashforge - DEBUG - sendcommand() got an ok 2020-09-25 16:21:34,054 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,062 - octoprint.plugins.flashforge - DEBUG - enable_keep_alive(True) 2020-09-25 16:21:34,063 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M23, cmd:M23 0:/user/finder_gcode/xyzCalibration_cube.gcode 2020-09-25 16:21:34,063 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:34,064 - octoprint.util.comm - INFO - Externally triggered heatup detected 2020-09-25 16:21:34,068 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,069 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,070 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:34,071 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:34,072 - octoprint.plugins.flashforge - DEBUG - write() M23 0:/user/finder_gcode/xyzCalibration_cube.gcode M119 2020-09-25 16:21:34,092 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M23 Received. | File opened: /data/xyzCalibration_cube.gcode Size: 0 | File selected | ok | 2020-09-25 16:21:34,092 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M23 Received. 2020-09-25 16:21:34,093 - octoprint.plugins.flashforge - DEBUG - buffering: File opened: /data/xyzCalibration_cube.gcode Size: 0 2020-09-25 16:21:34,094 - octoprint.plugins.flashforge - DEBUG - buffering: File selected 2020-09-25 16:21:34,095 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:34,096 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,101 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,103 - octoprint.printer.standard.job - INFO - Print job selected - origin: sdcard, path: 0:/user/finder_gcode/xyzCalibration_cube.gcode , owner: None, user: None 2020-09-25 16:21:34,109 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,110 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,111 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:34,179 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,180 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,182 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,183 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,185 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,187 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,189 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,190 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,192 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,193 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,196 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,197 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,271 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,272 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,274 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,276 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,278 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,279 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,281 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,283 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,285 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,286 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,288 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,290 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:34,851 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:34,852 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:34,854 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:34,854 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:34,863 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:34,863 - octoprint.plugins.flashforge - DEBUG - state changed from 1 to 3 2020-09-25 16:21:34,864 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,865 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:34,873 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:34,874 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:34,874 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:34,875 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:34,877 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,878 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,880 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:34,880 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:35,034 - octoprint.filemanager.analysis - INFO - Analysis of entry local:finder_gcode/xyzCalibration_cube.gcode finished, needed 1.90s 2020-09-25 16:21:35,096 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,098 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,100 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,102 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,104 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,110 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,112 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,113 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,115 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,116 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,118 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,119 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,122 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,123 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,125 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,126 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,128 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,129 - octoprint.plugins.flashforge - DEBUG - get_extension_tree() 2020-09-25 16:21:35,853 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:35,854 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:35,855 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:35,858 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:35,867 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:35,868 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:35,868 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:35,878 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:35,878 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:35,879 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:35,879 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:35,880 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:35,882 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:35,883 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:35,883 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:36,856 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:36,857 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:36,860 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:36,862 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:36,877 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:36,879 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:36,881 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:36,882 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:36,884 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:36,886 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:36,887 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:36,890 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:36,892 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:36,895 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:36,896 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:37,860 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:37,861 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:37,864 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:37,865 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:37,877 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:37,879 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:37,887 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:37,891 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:37,891 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:37,894 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:37,895 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:37,898 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:37,900 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:37,903 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:37,903 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:38,251 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M105, cmd:M105 2020-09-25 16:21:38,252 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:38,256 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:38,257 - octoprint.plugins.flashforge - DEBUG - write() M105 2020-09-25 16:21:38,263 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M105 Received. | T0:28 /0 B:0/0 | ok | 2020-09-25 16:21:38,264 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M105 Received. 2020-09-25 16:21:38,266 - octoprint.plugins.flashforge - DEBUG - buffering: T0:28 /0 B:0/0 2020-09-25 16:21:38,267 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:38,270 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,272 - octoprint.util.comm - INFO - Externally triggered heatup detected 2020-09-25 16:21:38,276 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,279 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,280 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:38,864 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:38,865 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:38,868 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:38,869 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:38,881 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:38,883 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,884 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:38,891 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:38,892 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:38,894 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:38,903 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:38,906 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,908 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,911 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:38,912 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:39,868 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:39,868 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:39,872 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:39,873 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:39,886 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:39,888 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:39,889 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:39,892 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:39,893 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:39,894 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:39,896 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:39,899 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:39,901 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:39,903 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:39,905 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:40,872 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:40,872 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:40,876 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:40,877 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:40,888 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:40,890 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:40,891 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:40,893 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:40,894 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:40,896 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:40,897 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:40,899 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:40,902 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:40,905 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:40,906 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:41,308 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Starting print from SD" 2020-09-25 16:21:41,315 - octoprint.printer.standard.job - INFO - Print job started - origin: sdcard, path: 0:/user/finder_gcode/xyzCalibration_cube.gcode , owner: mw, user: mw 2020-09-25 16:21:41,332 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M23, cmd:M23 0:/user/finder_gcode/xyzCalibration_cube.gcode 2020-09-25 16:21:41,333 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:41,334 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): dropping command 2020-09-25 16:21:41,875 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:41,875 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:41,877 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:41,878 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:41,887 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:41,887 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:41,888 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:41,892 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:41,893 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:41,894 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:41,895 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:41,896 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:41,897 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:41,899 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M24, cmd:M24 2020-09-25 16:21:41,900 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:41,900 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:41,901 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:41,902 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:41,903 - octoprint.plugins.flashforge - DEBUG - write() M24 2020-09-25 16:21:41,917 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M24 Received. | ok | 2020-09-25 16:21:41,918 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M24 Received. 2020-09-25 16:21:41,918 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:41,919 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:41,921 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:41,921 - octoprint.util.comm - INFO - Changing monitoring state from "Starting print from SD" to "Printing from SD" 2020-09-25 16:21:41,922 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:42,877 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:42,878 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:42,882 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:42,883 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:42,894 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:42,896 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:42,897 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:42,904 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:42,908 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:42,909 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:42,911 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:42,914 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:42,917 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:42,919 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:42,920 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:43,255 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M105, cmd:M105 2020-09-25 16:21:43,256 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:43,260 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:43,260 - octoprint.plugins.flashforge - DEBUG - write() M105 2020-09-25 16:21:43,269 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M105 Received. | T0:28 /0 B:0/0 | ok | 2020-09-25 16:21:43,270 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M105 Received. 2020-09-25 16:21:43,271 - octoprint.plugins.flashforge - DEBUG - buffering: T0:28 /0 B:0/0 2020-09-25 16:21:43,272 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:43,276 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,277 - octoprint.util.comm - INFO - Externally triggered heatup detected 2020-09-25 16:21:43,282 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,284 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,286 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:43,883 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:43,883 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:43,887 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:43,888 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:43,898 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:43,899 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,900 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:43,903 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:43,904 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:43,906 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:43,907 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:43,910 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,912 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,922 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:43,923 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:44,887 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:44,888 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:44,891 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:44,892 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:44,905 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:44,907 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:44,908 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:44,911 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:44,912 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:44,914 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:44,915 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:44,917 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:44,920 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:44,923 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:44,924 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:45,890 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:45,891 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:45,894 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:45,896 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:45,910 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:45,912 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:45,913 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:45,915 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:45,917 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:45,918 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:45,919 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:45,922 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:45,924 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:45,927 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:45,928 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:46,894 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:46,895 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:46,898 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:46,899 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:46,909 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:46,911 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:46,920 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:46,922 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:46,924 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:46,925 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:46,927 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:46,930 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:46,932 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:46,935 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:46,936 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:47,897 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:47,898 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:47,902 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:47,903 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:47,912 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:47,914 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:47,915 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:47,918 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:47,919 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:47,921 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:47,922 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:47,924 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:47,935 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:47,937 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:47,938 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:48,259 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M105, cmd:M105 2020-09-25 16:21:48,260 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:48,263 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:48,264 - octoprint.plugins.flashforge - DEBUG - write() M105 2020-09-25 16:21:48,271 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M105 Received. | T0:28 /0 B:0/0 | ok | 2020-09-25 16:21:48,272 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M105 Received. 2020-09-25 16:21:48,274 - octoprint.plugins.flashforge - DEBUG - buffering: T0:28 /0 B:0/0 2020-09-25 16:21:48,275 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:48,278 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,280 - octoprint.util.comm - INFO - Externally triggered heatup detected 2020-09-25 16:21:48,284 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,287 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,288 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:48,901 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:48,902 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:48,905 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:48,906 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:48,917 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:48,918 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,919 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:48,925 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:48,926 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:48,928 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:48,929 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:48,932 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,934 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,936 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:48,938 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:49,904 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:49,905 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:49,909 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:49,910 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:49,927 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:0 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:49,929 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:49,930 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:49,932 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:49,933 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:49,935 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:49,936 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:49,939 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:49,941 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:49,943 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:49,944 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:50,908 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:50,909 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:50,912 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:50,914 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:50,923 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:1 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:50,925 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:50,933 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:50,936 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:50,937 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:50,939 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000 2020-09-25 16:21:50,940 - octoprint.plugins.flashforge - DEBUG - buffering: ok 2020-09-25 16:21:50,943 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:50,945 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:50,948 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:50,949 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:51,911 - octoprint.plugins.flashforge - DEBUG - rewrite_gcode(): gcode:M27, cmd:M27 2020-09-25 16:21:51,912 - octoprint.plugins.flashforge - DEBUG - is_sd_printing() 2020-09-25 16:21:51,916 - octoprint.plugins.flashforge - DEBUG - write() called by thread comm.sending_thread 2020-09-25 16:21:51,916 - octoprint.plugins.flashforge - DEBUG - write() M119 ~M27 2020-09-25 16:21:51,927 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M119 Received. | Endstop: X-max:0 Y-max:0 Z-max:1 | MachineStatus: BUILDING_FROM_SD | MoveMode: READY | Status: S:1 L:0 J:0 F:0 | ok | 2020-09-25 16:21:51,929 - octoprint.plugins.flashforge - DEBUG - readline() called by thread comm._monitor 2020-09-25 16:21:51,930 - octoprint.plugins.flashforge - DEBUG - readraw() called by thread: comm._monitor, timeout: 2000 2020-09-25 16:21:51,932 - octoprint.plugins.flashforge - DEBUG - readraw() returns: CMD M27 Received. | SD printing byte 0/1000 | ok | 2020-09-25 16:21:51,933 - octoprint.plugins.flashforge - DEBUG - buffering: CMD M27 Received. 2020-09-25 16:21:51,935 - octoprint.plugins.flashforge - DEBUG - buffering: SD printing byte 0/1000
This might be a silly question, but is this the internal SD card? The finder has two usb ports, so I can only assume that this SD card is internal to the unit...
Yes there's an sd card embedded on the control board of most of these printers so when you connect using FlashPrint and upload a file it goes onto that internal SD card. On the display on the printer you can print files off the internal SD card or select the USB drive (if you have one plugged in).
xyzCalibration_cube.gcode.txt octoprint (10).log
here are files from this morning. log file is freshly new and shows the same behavior.
Great, thanks for that. The file upload appears to be successful and the printer responds correctly to the M29 command which makes it look like it saved the file:
readraw() returns: CMD M29 Received. | Done saving file. | ok |
However clearly something is not quite right because when the printer is asked to print the file using the M23 command, it responds with:
readraw() returns: CMD M23 Received. | File opened: /data/xyzCalibration_cube.gcode Size: 0 | File selected | ok |
whereas my printer (not a Finder v2) responds with:
readraw() returns: CMD M23 Received. | File opened: 0:/user/xyzCalibration_cube.gcode Size: 250896 | File selected | ok |
Which makes me think that the file was in fact not transferred properly or not saved properly on the SD card. It could of course also be a firmware difference unfortunately.
Have you added any plugins besides the FlashForge one?
Looking again at the log it appears you have several plugins installed. Perhaps try disabling all of the ones you added except the FlashForge one and then try uploading to SD again. Depending on the function of the plugin, some plugins will manipulate the file before it is uploaded to the SD card (I believe DisplayLayer does this) so it would be good to eliminate any of them as a possible cause.
The FF memory is certainly not full. however, it does not show the 'xyz.gcode' file at all. I do have a number of plugins installed. I will report back.
as an aside, if I try to stream the gcode to the finder directly, the printer responds, but makes horrible grinding noises and grossly over-extrudes.
seems to be working, although not sure which plugin it might be having issues with. I think the one that presents a 'preheat' button might be it, but that's total conjecture.
I was able to do one print, but after I cancelled it, it didn't seem to work again. Power cycling, and trying again
edit: I tried with the xyz.gcode, then tried with one that had a much longer filename (And that did not seem to work, going to try with a shorter name)
Ok, strange - xyz.gcode prints, but xy.gcode (a tile holder, much larger file) does not. I tried re-slicing the same model with what I thought were the same factory settings in S3D, and it .. doesn't seem to work. I do see the xyz.gcode on the onboard flash now. So this is weird. Let me play with it a little bit and see if I can get something repeatable for you to chew on. Thanks for working with me!
not sure if this matters, but the port on the connection seems to be changing - when it connected before, it said 1:3, then 1:7 now 1:8...
I think I figured it out - if the file is in a folder in octoprint, it doesn't load correctly. If I "Upload to SD" from the root, it works. If I try from a folder (in this case, "finder_test", it does not work. I think before I was changing directories unwittingly: i.e. This print never worked: 2020-09-27 19:42:29,160 - octoprint.plugins.flashforge - INFO - Starting SDCard upload from finder_gcode/tiles3.gcode to finder_gcode/tiles3.gcode
this print did work: 2020-09-27 21:05:02,298 - octoprint.plugins.flashforge - INFO - Starting SDCard upload from tiles3.gcode to tiles3.gcode
...likely because there is no folder on the SD card called "finder_gcode" ?
...also, it seems that if you get the file to the printer, then the folder doesn't matter - although it is not clear if it transfers in a new file, or just uses the existing file. Anyway, I think I understand the problem. I went and deleted the xyz.gcode from the printer directly, and tried to load from the finder_tests folder in octoprint, and it did not print, as expected. what's interesting is that the printer display indicates that it has a job, and has the right name - but just never goes anywhere. It does 'home', but then that's it.
in short: if the file does not exist on the SD card, I have to Upload to SD from the root of octoprint. If the file name already exists, it appears to not matter what folder in octoprint I 'upload to SD' card, although I am not sure if it actually does file transfer or it just thinks it does - and runs whatever it has that has the same file name (old file).
my most recent log if it is helpful. this does not have a faulty load, but a successful one.
Oh yes the file path is totally screwed up. On my printers the upload path should always be /user/ eg /user/xyzCalibration.gcode. It looks like the Finder 2 is expecting the upload paths to be /data/ eg /data/xyzCalibration.gcode. I don't quite understand yet how we ended up with subfolders in the path name eg /user/finder_gcode/xyzCalibration_cube.gcode.
Not sure whether it is relevant - but what web browser are you using for the 'Upload to SD'?
not sure if this matters, but the port on the connection seems to be changing - when it connected before, it said 1:3, then 1:7 now 1:8... image
This will happen if you reboot the printer which you sometimes have to do if the connection isn't closed properly - eg for some reason the plugin did not get all of the response from the printer before the connection was closed. It reconnects on the Pi/computer and ends up taking a new port number (I'm guessing the USB stack is not sure if the previous port is still in use).
I think I will do a special version for you to try, but please tell me how you are able to get a subfolder name into the filename when using 'Upload to SD' because I cannot reproduce it using Safari, Chrome or Firefox (I don't have access to a Window box right now).
Shoot, I'm sorry - I should have shown those steps. I'm just making a folder in Octoprint here in the GUI - just hitting 'create folder', and that is where the finder_gcode comes from... and what I mean when I say 'root' vs in the folder. (see next comment).
