WORKING

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
2018-04-19 22:37:57,141 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 22:46:10,300 - octoprint.util.comm - INFO - Finished in 1590.399 s.
2018-04-19 22:46:10,326 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-19 22:52:57,142 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 22:54:42,120 - octoprint.server.util.sockjs - INFO - Client connection closed: 2604:5500:c143:7c00:6447:70ab:9ce:5144
2018-04-19 22:57:39,309 - octoprint.filemanager.analysis - INFO - Starting analysis of local:xyzCalibration_cube_p60_ew.gcode
2018-04-19 22:57:39,311 - 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_p60_ew.gcode
2018-04-19 22:57:41,991 - octoprint.filemanager.analysis - INFO - Analysis of entry local:xyzCalibration_cube_p60_ew.gcode finished, needed 2.68s
2018-04-19 22:57:41,996 - octoprint.server.util.sockjs - INFO - New connection from client: 2604:5500:c143:7c00:6447:70ab:9ce:5144
2018-04-19 22:58:44,182 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing"
2018-04-19 22:58:44,211 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-19 23:07:57,144 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 23:22:57,145 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 23:29:27,434 - octoprint.util.comm - INFO - Finished in 1843.253 s.
2018-04-19 23:29:27,460 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-19 23:37:57,147 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-19 23:52:57,148 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 00:00:29,163 - octoprint.util.comm - INFO - No response from printer after 3 consecutive communication timeouts, considering it dead.
2018-04-20 00:00:29,174 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Offline (Error: Too many consecutive timeouts, printer still connected and alive?)"
2018-04-20 00:03:14,423 - octoprint.server.util.sockjs - INFO - Client connection closed: 2604:5500:c143:7c00:6447:70ab:9ce:5144
2018-04-20 00:07:57,150 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 00:22:57,151 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 00:37:57,152 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 00:52:57,154 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 01:07:57,155 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 01:22:57,156 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 01:37:57,158 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 01:52:57,159 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 02:07:57,160 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 02:22:57,162 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 02:37:57,163 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 02:52:57,164 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 03:07:57,166 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 03:22:57,167 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 03:37:57,169 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 03:52:57,170 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 04:07:57,179 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 04:22:57,180 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 04:37:57,181 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 04:52:57,183 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 05:07:57,184 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 05:22:57,185 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 05:37:57,195 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 05:52:57,196 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 06:07:57,198 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 06:22:57,199 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 06:37:57,200 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 06:52:57,202 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 07:07:57,203 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 07:22:57,204 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 07:37:57,206 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 07:52:57,207 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 08:07:57,209 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 08:22:57,210 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 08:37:57,211 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 08:52:57,213 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 09:07:57,214 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 09:08:46,440 - tornado.access - WARNING - 403 GET /api/files?recursive=true (127.0.0.1) 8.77ms
2018-04-20 09:08:46,463 - tornado.access - WARNING - 403 GET /api/printerprofiles (127.0.0.1) 9.32ms
2018-04-20 09:08:46,474 - tornado.access - WARNING - 403 GET /api/timelapse?unrendered=true (127.0.0.1) 8.82ms
2018-04-20 09:08:46,486 - tornado.access - WARNING - 403 GET /api/slicing (127.0.0.1) 9.26ms
2018-04-20 09:08:46,498 - tornado.access - WARNING - 403 GET /api/settings (127.0.0.1) 9.15ms
2018-04-20 09:08:46,508 - tornado.access - WARNING - 403 GET /plugin/announcements/channels (127.0.0.1) 8.41ms
2018-04-20 09:08:46,530 - tornado.access - WARNING - 403 GET /plugin/softwareupdate/check (127.0.0.1) 8.22ms
2018-04-20 09:08:46,542 - tornado.access - WARNING - 403 GET /api/plugin/pluginmanager (127.0.0.1) 9.57ms
2018-04-20 09:08:46,862 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:136.24.111.207
2018-04-20 09:08:48,707 - octoprint.plugins.announcements - INFO - Loaded channel _important from https://octoprint.org/feeds/important.xml in 0.89s
2018-04-20 09:08:49,669 - octoprint.plugins.announcements - INFO - Loaded channel _releases from https://octoprint.org/feeds/releases.xml in 0.72s
2018-04-20 09:08:50,499 - octoprint.plugins.announcements - INFO - Loaded channel _octopi from https://octoprint.org/feeds/octopi.xml in 0.72s
2018-04-20 09:08:50,726 - octoprint.server.util.sockjs - INFO - Client connection closed: ::ffff:136.24.111.207
2018-04-20 09:22:38,746 - octoprint.server.util.sockjs - INFO - New connection from client: 2604:5500:c143:7c00:199:c272:f714:12bb
2018-04-20 09:22:53,526 - octoprint.server.api.system - INFO - Performing command for core:restart: sudo service octoprint restart
2018-04-20 09:22:53,675 - octoprint.server - INFO - Shutting down...
2018-04-20 09:22:54,187 - octoprint.events - INFO - Processing shutdown event, this will be our last event
2018-04-20 09:22:54,193 - octoprint.events - INFO - Event loop shut down
2018-04-20 09:22:54,207 - octoprint.server - INFO - Goodbye!
2018-04-20 09:22:56,949 - octoprint.startup - INFO - ******************************************************************************
2018-04-20 09:22:56,950 - octoprint.startup - INFO - Starting OctoPrint 1.3.8
2018-04-20 09:22:56,950 - octoprint.startup - INFO - ******************************************************************************
2018-04-20 09:22:56,985 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2018-04-20 09:22:57,841 - octoprint.startup - INFO - Blacklist processing done
2018-04-20 09:22:57,899 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2018-04-20 09:23:00,031 - octoprint.plugin.core - INFO - Found 12 plugin(s) providing 12 mixin implementations, 7 hook handlers
2018-04-20 09:23:00,128 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2018-04-20 09:23:00,153 - octoprint.server - INFO - Intermediary server started
2018-04-20 09:23:00,154 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2018-04-20 09:23:00,456 - octoprint.plugin.core - INFO - Found 12 plugin(s) providing 12 mixin implementations, 7 hook handlers
2018-04-20 09:23:00,493 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2018-04-20 09:23:03,105 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2018-04-20 09:23:03,199 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2018-04-20 09:23:05,592 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2018-04-20 09:23:07,997 - octoprint.util.pip - INFO - Version of pip is 9.0.3
2018-04-20 09:23:07,999 - octoprint.util.pip - INFO - pip installs to /home/pi/oprint/lib/python2.7/site-packages (writable -> yes), --user flag needed -> no, virtual env -> yes
2018-04-20 09:23:07,999 - octoprint.util.pip - INFO - ==> pip ok -> yes
2018-04-20 09:23:08,001 - octoprint.plugin.core - INFO - Initialized 12 plugin implementation(s)
2018-04-20 09:23:08,010 - 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-20 09:23:08,024 - 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-20 09:23:08,033 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2018-04-20 09:23:08,056 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2018-04-20 09:23:08,241 - octoprint.server - INFO - Shutting down intermediary server...
2018-04-20 09:23:08,722 - octoprint.server - INFO - Intermediary server shut down
2018-04-20 09:23:08,725 - octoprint.events - INFO - Processing startup event, this is our first event
2018-04-20 09:23:08,728 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2018-04-20 09:23:08,737 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2018-04-20 09:23:08,879 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2018-04-20 09:23:09,087 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi-taz for _http._tcp
2018-04-20 09:23:09,099 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi-taz for _octoprint._tcp
2018-04-20 09:23:09,102 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi-taz for SSDP
2018-04-20 09:23:09,103 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2018-04-20 09:23:09,120 - octoprint.plugins.octorant - INFO - Octorant is started !
2018-04-20 09:23:09,312 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://136.24.111.207:5601/'}
2018-04-20 09:23:09,592 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json
2018-04-20 09:23:09,919 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from https://plugins.octoprint.org/plugins.json
2018-04-20 09:23:11,219 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2018-04-20 09:23:11,231 - octoprint.plugins.pluginmanager - INFO - Loaded plugin notices data from https://plugins.octoprint.org/notices.json
2018-04-20 09:23:13,137 - octoprint.server.util.sockjs - INFO - New connection from client: 2604:5500:c143:7c00:199:c272:f714:12bb
2018-04-20 09:23:25,327 - octoprint.server.preemptive_cache - INFO - ... done in 16.01s
2018-04-20 09:23:25,346 - tornado.access - WARNING - 403 GET /api/plugin/octopi_support (127.0.0.1) 10.17ms
2018-04-20 09:23:25,359 - tornado.access - WARNING - 403 GET /api/connection (127.0.0.1) 9.72ms
2018-04-20 09:23:25,370 - tornado.access - WARNING - 403 GET /api/printer/command/custom (127.0.0.1) 9.43ms
2018-04-20 09:23:25,384 - tornado.access - WARNING - 403 GET /api/system/commands (127.0.0.1) 10.74ms
2018-04-20 09:23:25,396 - tornado.access - WARNING - 403 GET /api/plugin/printer_safety_check (127.0.0.1) 10.09ms
2018-04-20 09:23:25,571 - tornado.access - WARNING - 403 GET /api/files?recursive=true (127.0.0.1) 10.09ms
2018-04-20 09:23:25,583 - tornado.access - WARNING - 403 GET /api/printerprofiles (127.0.0.1) 10.33ms
2018-04-20 09:23:25,596 - tornado.access - WARNING - 403 GET /api/timelapse?unrendered=true (127.0.0.1) 10.30ms
2018-04-20 09:23:25,611 - tornado.access - WARNING - 403 GET /api/slicing (127.0.0.1) 11.60ms
2018-04-20 09:23:25,623 - tornado.access - WARNING - 403 GET /plugin/announcements/channels (127.0.0.1) 9.79ms
2018-04-20 09:23:25,635 - tornado.access - WARNING - 403 GET /api/settings (127.0.0.1) 9.47ms
2018-04-20 09:23:25,709 - tornado.access - WARNING - 403 GET /plugin/softwareupdate/check (127.0.0.1) 12.95ms
2018-04-20 09:23:25,722 - tornado.access - WARNING - 403 GET /api/plugin/pluginmanager (127.0.0.1) 10.81ms
2018-04-20 09:23:25,734 - octoprint.server.util.sockjs - INFO - Client connection closed: 2604:5500:c143:7c00:199:c272:f714:12bb
2018-04-20 09:23:25,992 - octoprint.server.util.sockjs - INFO - New connection from client: 2604:5500:c143:7c00:199:c272:f714:12bb
2018-04-20 09:23:44,554 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial port"
2018-04-20 09:23:44,631 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial port" to "Opening serial port"
2018-04-20 09:23:44,635 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2018-04-20 09:23:44,640 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 09:23:45,704 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 09:23:51,399 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2018-04-20 09:23:51,413 - octoprint.plugins.firmwareupdater - INFO - Got CONNECTED event
2018-04-20 09:23:51,417 - octoprint.plugins.firmwareupdater - INFO - Run postflash flag is not set
2018-04-20 09:23:51,508 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 09:23:51,564 - octoprint.util.comm - INFO - Printer reports firmware name "Marlin"
2018-04-20 09:23:51,570 - octoprint.util.comm - INFO - Firmware states that it supports temperature autoreporting
2018-04-20 09:24:03,600 - octoprint.filemanager.analysis - INFO - Starting analysis of local:20mm_cube_60pc_width.gcode
2018-04-20 09:24:03,604 - 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_60pc_width.gcode
2018-04-20 09:24:05,399 - octoprint.filemanager.analysis - INFO - Analysis of entry local:20mm_cube_60pc_width.gcode finished, needed 1.80s
2018-04-20 09:24:06,988 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing"
2018-04-20 09:24:07,003 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 09:38:00,130 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 09:50:15,888 - octoprint.util.comm - INFO - Finished in 1568.910 s.
2018-04-20 09:50:15,912 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-20 09:53:00,132 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2018-04-20 09:53:19,318 - octoprint.filemanager.analysis - INFO - Starting analysis of local:75mm_x_0.25mm_Cylinder_p60_width.gcode
2018-04-20 09:53:19,320 - 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_p60_width.gcode
2018-04-20 09:53:21,083 - octoprint.filemanager.analysis - INFO - Analysis of entry local:75mm_x_0.25mm_Cylinder_p60_width.gcode finished, needed 1.76s
2018-04-20 09:53:27,763 - octoprint.util.comm - INFO - Changing monitoring state from "Operational" to "Printing"
2018-04-20 09:53:27,782 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 10:06:46,693 - octoprint.util.comm - INFO - Finished in 798.932 s.
2018-04-20 10:06:46,722 - octoprint.util.comm - INFO - Changing monitoring state from "Printing" to "Operational"
2018-04-20 10:08:00,133 - octoprint.server.heartbeat - INFO - Server heartbeat <3