OctoPrint.log

2018-04-19 21:07:57,068 - octoprint.server - INFO - --- Log roll over detected ---------------------------------------------------
2018-04-19 21:07:57,069 - octoprint.server - INFO - OctoPrint 1.3.8
2018-04-19 21:07:57,071 - octoprint.plugin.core - INFO - 12 plugin(s) registered with the system:
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/announcements
|  Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/corewizard
|  CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/cura
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/discovery
|  Firmware Updater (1.0.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_firmwareupdater
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  OctoPi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/octopi_support
|  OctoRant (1.2.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_octorant
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/pluginmanager
|  Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/printer_safety_check
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/softwareupdate
|  Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/virtual_printer
2018-04-19 21:07:57,091 - octoprint.environment - INFO - Detected environment is Python 2.7.9 under Linux (linux2). Details:
|  hardware:
|    cores: 4
|    freq: 1200.0
|    ram: 901685248
|  os:
|    id: linux
|    platform: linux2
|  plugins:
|    octopi_support:
|      model: 3B
|      revision: a02082
|      version: 0.14.0
|  python:
|    pip: 9.0.3
|    version: 2.7.9
|    virtualenv: /home/pi/oprint
2018-04-19 21:07:57,092 - octoprint.server - INFO - ------------------------------------------------------------------------------
2018-04-19 21:07:57,059 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 21:17:56,516 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:18:26,840 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:18:57,856 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:19:28,529 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:19:58,889 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:20:29,922 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:20:29,998 - octoprint.util.comm - INFO - Finished in 792.100 s.
2018-04-19 21:20:30,049 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-19 21:21:47,652 - octoprint.filemanager.analysis - INFO - Starting analysis of local:75mm_x_0.25mm_Cylinder.gcode
2018-04-19 21:21:47,655 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/75mm_x_0.25mm_Cylinder.gcode
2018-04-19 21:21:49,435 - octoprint.filemanager.analysis - INFO - Analysis of entry local:75mm_x_0.25mm_Cylinder.gcode finished, needed 1.78s
2018-04-19 21:22:57,109 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 21:25:02,157 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing"
2018-04-19 21:25:02,176 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-19 21:36:40,155 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:37:11,122 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:37:41,193 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:37:57,136 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 21:38:12,205 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:38:43,130 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:39:13,237 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 21:39:15,296 - octoprint.util.comm - INFO - Finished in 853.140 s.
2018-04-19 21:39:15,343 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-19 21:39:15,677 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1120, current line = 1124
| Last lines in terminal:
| Recv:  T:95.93 /0.00 B:50.05 /45.00 @:0 B@:0
| Recv:  T:95.93 /0.00 B:50.05 /45.00 @:0 B@:0 W:?
| 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.
| Send: N1119 M105*31
| Recv:  T:95.56 /0.00 B:50.01 /45.00 @:0 B@:0 W:0
| Recv:  T:95.20 /0.00 B:49.94 /45.00 @:0 B@:0
| Recv:  T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0 W:0
| Recv: ok N1112 P15 B0
| Send: N1120 M140 S45*102
| Recv: ok N1113 P14 B0
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Send: N1121 M84*44
| Send: N1122 G90*32
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Send: N1123 M117 Print complete*77
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Changing monitoring state from "Printing" to "Operational"
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Recv: Resend: 1120
2018-04-19 21:39:15,776 - octoprint.util.comm - INFO - Ignoring resend request for line 1120, that still originates from lines we sent before we got the first resend request
2018-04-19 21:39:15,818 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1120, current line = 1124
| Last lines in terminal:
| Send: N1122 G90*32
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Send: N1123 M117 Print complete*77
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Changing monitoring state from "Printing" to "Operational"
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Recv: Resend: 1120
| Recv: ok N1118 P14 B2
| Send: N1120 M140 S45*102
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Send: N1121 M84*44
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Send: N1122 G90*32
| Recv: Resend: 1120
| Recv: ok N1116 P14 B4
| Send: N1123 M117 Print complete*77
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Recv: Resend: 1120
2018-04-19 21:39:15,880 - octoprint.util.comm - INFO - Got a resend request from the printer: requested line = 1124, current line = 1124
| Last lines in terminal:
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Recv: Resend: 1120
| Recv: ok N1118 P14 B2
| Send: N1120 M140 S45*102
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Recv: ok T:95.13 /0.00 B:49.92 /45.00 @:0 B@:0
| Send: N1121 M84*44
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Send: N1122 G90*32
| Recv: Resend: 1120
| Recv: ok N1116 P14 B4
| Send: N1123 M117 Print complete*77
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1119
| Recv: Resend: 1120
| Recv: ok N1116 P14 B4
| Send: N1120 M140 S45*102
| Recv: ok N1120 P14 B3
| Send: N1121 M84*44
| Recv: Error:Line Number is not Last Line Number+1, Last Line: 1123
| Recv: Resend: 1124
2018-04-19 21:41:42,910 - octoprint.filemanager.analysis - INFO - Starting analysis of local:xyzCalibration_cube.gcode
2018-04-19 21:41:42,913 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/xyzCalibration_cube.gcode
2018-04-19 21:41:45,778 - octoprint.filemanager.analysis - INFO - Analysis of entry local:xyzCalibration_cube.gcode finished, needed 2.87s
2018-04-19 21:42:06,877 - octoprint.server.util.sockjs - INFO - Client connection closed: 2604:5500:c143:7c00:6447:70ab:9ce:5144
2018-04-19 21:42:06,920 - octoprint.server.util.sockjs - INFO - New connection from client: 2604:5500:c143:7c00:6447:70ab:9ce:5144
2018-04-19 21:42:31,075 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing"
2018-04-19 21:42:31,089 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-19 21:52:57,137 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 22:07:57,138 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 22:11:35,226 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 22:12:06,045 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 22:12:36,255 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 22:13:07,286 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 22:13:38,102 - octoprint.util.comm - INFO - Communication timeout while printing, trying to trigger response from printer.
2018-04-19 22:14:07,445 - octoprint.util.comm - INFO - Finished in 1896.371 s.
2018-04-19 22:14:07,508 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-19 22:19:36,741 - octoprint.filemanager.analysis - INFO - Starting analysis of local:20mm_cube_outline_only.gcode
2018-04-19 22:19:36,743 - octoprint.filemanager.analysis - INFO - Invoking analysis command: /home/pi/oprint/bin/python -m octoprint analysis gcode --speed-x=6000 --speed-y=6000 --max-t=10 --throttle=0.0 --throttle-lines=100 /home/pi/.octoprint/uploads/20mm_cube_outline_only.gcode
2018-04-19 22:19:38,544 - octoprint.filemanager.analysis - INFO - Analysis of entry local:20mm_cube_outline_only.gcode finished, needed 1.80s
2018-04-19 22:19:39,901 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing"
2018-04-19 22:19:39,921 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-19 22:22:57,140 - octoprint.server.heartbeat - INFO - Server heartbeat <3