Should OctoPrint web interface take 5 minutes to start?


#1

What is the problem?
My OctoPi installation's web interface takes a pretty long time to start before it'll start accepting web requests
I timed how long it took between me running sudo service octopi start and it actually showing the printer controls and it took about 5 minutes. It will show the "Octoprint is starting page" for awhile, but then it has a long period where my browser will perpetually load saying "Waiting for " in the bottom corner. I opened up the chrome network activity log and it just showed the request as "pending" with 0 bytes being transferred.

What did you already try to solve it?
I tried disabling camera to see if it'd free up bandwith, but that's about all i could think of

Additional information about your setup

OctoPrint Version: 1.3.9
OctoPi Version: 0.15.1
Printer: Monoprice Select Mini V2
Printer Firmware: V40.115.3

octoprint.log
2018-11-04 04:30:35,410 - octoprint.startup - INFO - ******************************************************************************
2018-11-04 04:30:35,422 - octoprint.startup - INFO - Starting OctoPrint 1.3.9
2018-11-04 04:30:35,425 - octoprint.startup - INFO - ******************************************************************************
2018-11-04 04:30:36,657 - octoprint.startup - INFO - Blacklist processing done
2018-11-04 04:30:36,954 - 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-11-04 04:30:44,996 - octoprint.plugin.core - INFO - Plugin Printer Safety Check is disabled.
2018-11-04 04:30:50,747 - octoprint.plugin.core - INFO - Found 13 plugin(s) providing 12 mixin implementations, 8 hook handlers
2018-11-04 04:30:51,372 - octoprint.server.heartbeat - INFO - Starting server heartbeat, 900.0s interval
2018-11-04 04:30:51,623 - octoprint.server - INFO - Intermediary server started
2018-11-04 04:30:51,633 - 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-11-04 04:30:56,857 - octoprint.plugin.core - INFO - Found 13 plugin(s) providing 12 mixin implementations, 8 hook handlers
2018-11-04 04:30:57,182 - octoprint.filemanager.storage - INFO - Initializing the file metadata for /home/pi/.octoprint/uploads...
2018-11-04 04:30:57,195 - octoprint.filemanager.storage - INFO - ... file metadata for /home/pi/.octoprint/uploads initialized successfully.
2018-11-04 04:30:57,859 - octoprint.plugins.softwareupdate - INFO - Loaded version cache from disk
2018-11-04 04:31:12,656 - octoprint.util.pip - INFO - Using "/home/pi/oprint/bin/python2 -m pip" as command to invoke pip
2018-11-04 04:31:26,693 - octoprint.util.pip - INFO - Version of pip is 9.0.3
2018-11-04 04:31:26,707 - 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-11-04 04:31:26,716 - octoprint.util.pip - INFO - ==> pip ok -> yes
2018-11-04 04:31:26,747 - octoprint.plugin.core - INFO - Initialized 12 plugin implementation(s)
2018-11-04 04:31:26,819 - octoprint.plugin.core - INFO - 13 plugin(s) registered with the system:
|  Action Command Prompt Support (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/action_command_prompt
|  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
|  EEPROM Editor for MPSM (0.1.1) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_eeprom_MPSelectMini
|  Logging (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/logging
|  Malyan/Monoprice Connection Fix (0.1.0) = /home/pi/oprint/local/lib/python2.7/site-packages/octoprint_malyan_connection_fix
|  OctoPi Support Plugin (bundled) = /home/pi/oprint/lib/python2.7/site-packages/octoprint/plugins/octopi_support
|  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-11-04 04:31:26,966 - octoprint.environment - INFO - Detected environment is Python 2.7.13 under Linux (linux2). Details:
|  hardware:
|    cores: 1
|    freq: 900.0
|    ram: 388038656
|  os:
|    id: linux
|    platform: linux2
|  plugins:
|    octopi_support:
|      model: 1B
|      revision: 000f
|      version: 0.15.1
|  python:
|    pip: 9.0.3
|    version: 2.7.13
|    virtualenv: /home/pi/oprint
2018-11-04 04:31:27,030 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/webassets...
2018-11-04 04:31:27,148 - octoprint.server - INFO - Reset webasset folder /home/pi/.octoprint/generated/.webassets-cache...
2018-11-04 04:31:28,728 - octoprint.server - INFO - Shutting down intermediary server...
2018-11-04 04:31:28,830 - octoprint.server - INFO - Intermediary server shut down
2018-11-04 04:31:28,867 - octoprint.events - INFO - Processing startup event, this is our first event
2018-11-04 04:31:28,879 - octoprint.events - INFO - Adding 0 events to queue that were held back before startup event
2018-11-04 04:31:28,900 - octoprint.filemanager - INFO - Adding backlog items from all storage types to analysis queue...
2018-11-04 04:31:28,924 - octoprint.filemanager - INFO - Added 0 items from storage type "local" to analysis queue
2018-11-04 04:31:30,067 - octoprint.util.comm - INFO - Changing monitoring state from "Offline" to "Opening serial port"
2018-11-04 04:31:30,106 - octoprint.util.comm - INFO - Changing monitoring state from "Opening serial port" to "Connecting"
2018-11-04 04:31:30,211 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-11-04 04:31:30,348 - octoprint.util.comm - INFO - Changing monitoring state from "Connecting" to "Operational"
2018-11-04 04:31:30,377 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "Bedroom Printer" for _http._tcp
2018-11-04 04:31:30,647 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "Bedroom Printer" for _octoprint._tcp
2018-11-04 04:31:30,673 - octoprint.util.comm - INFO - M110 detected, setting current line number to 0
2018-11-04 04:31:30,743 - octoprint.plugins.discovery - INFO - Registered OctoPrint instance "Bedroom Printer" for SSDP
2018-11-04 04:31:30,798 - octoprint.server - INFO - Listening on http://127.0.0.1:5000
2018-11-04 04:31:30,933 - octoprint.util.comm - INFO - Printer reports firmware name "Malyan 4.0"
2018-11-04 04:31:30,983 - octoprint.util.comm - INFO - Detected Malyan firmware, enabling relevant features for issue free communication
2018-11-04 04:31:31,200 - octoprint.plugins.pluginmanager - INFO - Loaded plugin repository data from disk, was still valid
2018-11-04 04:31:33,373 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://192.168.1.109/'}
2018-11-04 04:31:40,241 - octoprint.plugins.pluginmanager - INFO - Loaded notice data from disk, was still valid
2018-11-04 04:33:14,027 - octoprint.server.preemptive_cache - INFO - ... done in 100.65s
2018-11-04 04:33:14,038 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://<redacted public ip>:1221/'}
2018-11-04 04:33:56,438 - octoprint.server.preemptive_cache - INFO - ... done in 42.40s
2018-11-04 04:33:56,449 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://<redacted public ip>:8080/'}
2018-11-04 04:34:38,787 - octoprint.server.preemptive_cache - INFO - ... done in 42.34s
2018-11-04 04:34:38,798 - octoprint.server.preemptive_cache - INFO - Preemptively caching / (ui _default) for {'query_string': 'l10n=en', 'path': '/', 'base_url': 'http://<redacted domain name>:8080/'}
2018-11-04 04:35:21,119 - octoprint.server.preemptive_cache - INFO - ... done in 42.32s
2018-11-04 04:36:04,715 - octoprint.server.util.sockjs - INFO - New connection from client: ::ffff:192.168.1.103

#2

Hi @zfwman!

Referring to your log, you have a RaspberryPi 1 with one core and 900 MHz clock frequency..
5 minutes it a long time, but could happen with that board.


#3

I see.

I could've sworn I used this pi in the past with it not taking this long.

Could it be an issue with the SD card read speed?
Or might overclocking to 1ghz speed it up a bit?


#4

The original pi with a single core is the issue. Octoprint with Apache uses quite a bit of processing power when it starts as it scans over the plugins and loads each of the active one's etc. It also uses quite a bit of memory.. if I remember correctly the Pi 1 also only has 256m of memory, so it is writing a swapfile to the SD card as well and using that as part of the memory that the running software needs. If you aren't using a class 10 SD card, you MIGHT see a marginal increase in speed by going to a class 10 card. Biggest bottleneck though is the Pi 1 itself.
If you start it then run top, then type I s 1, watch the wait percentage. Pretty sure that will be pretty high


#5

Ok, I will use my Pi 3 instead. I didn't realize how much power this application required so I went for my older Pi to use my newer Pis for other things.


#6

Were you using a Pi 1?