select_file() bug in octoprint log output

octoprint.log

2018-04-20 20:46:33,923 - octoprint.startup - INFO - ******************************************************************************
2018-04-20 20:46:33,925 - octoprint.startup - INFO - Starting OctoPrint 1.4.0.dev979+g58f73f3
2018-04-20 20:46:33,926 - octoprint.startup - INFO - ******************************************************************************
2018-04-20 20:46:33,985 - octoprint.util.connectivity_checker - INFO - Connectivity changed from offline to online
2018-04-20 20:46:33,989 - octoprint.startup - INFO - Blacklist processing done
2018-04-20 20:46:34,033 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2018-04-20 20:46:34,423 - octoprint.plugin.core - INFO - Plugin CuraEngine (<= 15.04) is disabled.
2018-04-20 20:46:35,411 - octoprint.plugin.core - INFO - Plugin Virtual Printer is disabled.
2018-04-20 20:46:35,798 - octoprint.plugin.core - INFO - Found 14 plugin(s) providing 12 mixin implementations, 8 hook handlers
2018-04-20 20:46:35,896 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2018-04-20 20:46:35,924 - octoprint.server - INFO - Intermediary server started
2018-04-20 20:46:35,924 - octoprint.plugin.core - INFO - Loading plugins from /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins, /home/pi/.octoprint/plugins and installed plugin packages...
2018-04-20 20:46:36,221 - octoprint.plugin.core - INFO - Found 14 plugin(s) providing 12 mixin implementations, 8 hook handlers
2018-04-20 20:46:36,255 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2018-04-20 20:46:38,865 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2018-04-20 20:46:38,942 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2018-04-20 20:46:41,563 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python -m pip" as command to invoke pip
2018-04-20 20:46:44,010 - octoprint.util.pip - INFO - Version of pip is 9.0.1
2018-04-20 20:46:44,012 - 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 20:46:44,012 - octoprint.util.pip - INFO - ==> pip ok -> yes
2018-04-20 20:46:44,018 - octoprint.plugin.core - INFO - Initialized 12 plugin implementation(s)
2018-04-20 20:46:44,027 - octoprint.plugin.core - INFO - 14 plugin(s) registered with the system:
|  Announcement Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/announcements
|  Core Wizard (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/corewizard
| !CuraEngine (<= 15.04) (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/cura
|  Discovery (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/discovery
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/logging
|  Material Settings (0.1.0) = /home/pi/Octoprint-Material-Settings/octoprint_material_settings
|  Navbar Temperature Plugin (0.9) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_navbartemp
|  OctoPi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/octopi_support
|  Plugin Manager (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/pluginmanager
|  Print Queue (0.1.0) = /home/pi/Octoprint-Print-Queue/octoprint_print_queue
|  Printer Safety Check (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/printer_safety_check
|  Software Update (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/softwareupdate
|  TouchUI (0.3.11) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_touchui
| !Virtual Printer (bundled) = /home/pi/oprint/lib/python2.7/site-packages/OctoPrint-1.4.0.dev979_g58f73f3-py2.7.egg/octoprint/plugins/virtual_printer
2018-04-20 20:46:44,041 - 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: a22082
|      version: 0.14.0
|  python:
|    pip: 9.0.1
|    version: 2.7.9
|    virtualenv: /home/pi/oprint
2018-04-20 20:46:44,050 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2018-04-20 20:46:44,074 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2018-04-20 20:46:44,236 - octoprint.server - INFO - Shutting down intermediary server...
2018-04-20 20:46:44,276 - octoprint.server - INFO - Intermediary server shut down
2018-04-20 20:46:44,279 - octoprint.events - INFO - Processing startup event, this is our first event
2018-04-20 20:46:44,279 - octoprint.events - INFO - Adding 1 events to queue that were held back before startup event
2018-04-20 20:46:44,280 - octoprint.plugins.print_queue - INFO - on_event fired: Startup
2018-04-20 20:46:44,283 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2018-04-20 20:46:44,316 - octoprint.plugins.print_queue - INFO - on_event fired: ConnectivityChanged
2018-04-20 20:46:44,361 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2018-04-20 20:46:44,558 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2018-04-20 20:46:44,560 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2018-04-20 20:46:44,842 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for _http._tcp
2018-04-20 20:46:44,853 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for _octoprint._tcp
2018-04-20 20:46:44,856 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance on octopi for SSDP
2018-04-20 20:46:44,860 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2018-04-20 20:46:44,992 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2018-04-20 20:46:45,112 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2018-04-20 20:46:45,355 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://mikenew.io:8100/'}
2018-04-20 20:46:46,485 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.1.1
2018-04-20 20:46:46,550 - octoprint.plugins.print_queue - INFO - on_event fired: ClientOpened
2018-04-20 20:46:48,594 - octoprint.server.util.sockjs - INFO - New connection from client: 192.168.1.1
2018-04-20 20:46:48,653 - octoprint.plugins.print_queue - INFO - on_event fired: ClientOpened
2018-04-20 20:46:56,385 - octoprint.server.preemptive_cache - INFO - ... done in 11.03s
2018-04-20 20:46:56,386 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://octoprint.nerdpol.ovh:8100/'}
2018-04-20 20:47:01,023 - octoprint.server.preemptive_cache - INFO - ... done in 4.64s
2018-04-20 20:47:17,306 - octoprint.plugins.print_queue - INFO - on_event fired: Connecting
2018-04-20 20:47:17,330 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Detecting serial port"
2018-04-20 20:47:17,363 - octoprint.plugins.print_queue - INFO - on_event fired: PrinterStateChanged
2018-04-20 20:47:17,487 - octoprint.util.comm - INFO - Changing monitoring state from "Detecting serial port" to "Opening serial port"
2018-04-20 20:47:17,494 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2018-04-20 20:47:17,504 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 20:47:17,508 - octoprint.plugins.print_queue - INFO - on_event fired: PrinterStateChanged
2018-04-20 20:47:17,515 - octoprint.plugins.print_queue - INFO - on_event fired: PrinterStateChanged
2018-04-20 20:47:17,516 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2018-04-20 20:47:17,525 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-04-20 20:47:17,530 - octoprint.plugins.print_queue - INFO - on_event fired: PrinterStateChanged
2018-04-20 20:47:17,538 - octoprint.plugins.print_queue - INFO - on_event fired: Connected
2018-04-20 20:47:17,626 - octoprint.plugins.print_queue - INFO - on_event fired: UpdatedFiles
2018-04-20 20:47:20,224 - octoprint.plugins.print_queue - INFO - on_event fired: FileSelected
2018-04-20 20:47:20,225 - octoprint.plugins.print_queue - INFO - {'origin': 'local', 'name': u'test1.gcode', 'file': u'/home/pi/.octoprint/uploads/test_scripts/test1.gcode', 'path': u'test_scripts/test1.gcode', 'size': None, 'filename': u'test1.gcode'}
2018-04-20 20:47:21,555 - octoprint.plugins.print_queue - INFO - PQ: adding selected file: test_scripts/test1.gcode
2018-04-20 20:47:21,582 - octoprint.plugins.print_queue - INFO - on_event fired: FileDeselected
2018-04-20 20:47:23,489 - octoprint.plugins.print_queue - INFO - PQ: attempting to select and print file: test_scripts/test1.gcode
2018-04-20 20:47:23,519 - tornado.access - ERROR - 500 POST /plugin/print_queue/printcontinuously (192.168.1.1) 46.66ms