CRITICAL: Could not initialize environment detector: bad marshal data (unknown type code)

I'm mostly just reporting what I'm seeing for the sake of documentation. Plot spoiler: it could possibly be under-voltage.

What is the problem?
First bootup of the day, OctoPrint didn't start up as expected. The log indicated that it couldn't initialize the environment detector with a CRITICAL stop.

What did you already try to solve it?
Nothing yet. I've not seen this one before in years of doing this.

Logs (octoprint.log, serial.log or output on terminal tab, browser error console ...)

octoprint.log:

2019-10-23 15:10:50,307 - octoprint.plugins.oneclickmetal - INFO - OCM ControlSerial.send(): <: {"id": "neopixel_2", "status": "success"}
2019-10-23 15:19:41,869 - octoprint.startup - INFO - ******************************************************************************
2019-10-23 15:19:41,871 - octoprint.startup - INFO - Starting OctoPrint 1.3.11
2019-10-23 15:19:41,875 - octoprint.startup - INFO - ******************************************************************************
2019-10-23 15:19:41,974 - octoprint.startup - INFO - Blacklist processing done, adding 1 blacklisted plugin versions: roomtemp (any)
2019-10-23 15:19:42,073 - 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...
2019-10-23 15:19:46,813 - octoprint.plugin.core - INFO - Plugin Anonymous Usage Tracking is disabled.
2019-10-23 15:19:47,235 - octoprint.plugin.core - INFO - Plugin Force Login is disabled.
2019-10-23 15:19:47,386 - octoprint.plugin.core - INFO - Plugin Pi Support Plugin is disabled.
2019-10-23 15:19:47,730 - octoprint.plugins.octoprint.plugins.discovery - INFO - pybonjour is not installed, Zeroconf Discovery won't be available
2019-10-23 15:19:47,761 - octoprint.plugin.core - INFO - Found 17 plugin(s) providing 14 mixin implementations, 19 hook handlers
2019-10-23 15:19:47,798 - octoprint.startup - CRITICAL - Could not initialize environment detector: bad marshal data (unknown type code)
2019-10-23 15:19:47,799 - octoprint.startup - CRITICAL - There was a fatal error starting up OctoPrint.

Additional information about your setup (OctoPrint version, OctoPi version, printer, firmware, browser, operating system, ...)

  • OctoPrint v1.3.11 from OctoPi 0.15.1
  • Raspberry Pi 3B
  • Pi Support Plugin is disabled on this rig
  • Smoothieboard 5xC 1.1
  • Ethernet cable attached, as well as wifi connected
  • Have not installed the Raspbian Desktop
  • Everything is plugged into a good-quality UPS
  • A PyBoard is connected via USB
  • A multimeter measures between 4.88VDC and 4.92VDC this morning. Hm... it usually reads a solid 5.2V. It drops about 0.3V on writing to the microSD, for what it's worth. There's a small chance that this could be under-voltage rearing its head. Disconnecting the PyBoard brings the average back up to 5.0VDC; it must be consuming about 0.1VDC. Disconnecting the Smoothieboard = 5.02VDC (0.02VDC) but it's now settling in at 4.96VDC or so. Disconnecting the PN532 RFID/NFC reader doesn't seem to make a difference. Disconnecting the Pi NoIR webcam brings it up slightly (0.03VDC). Disconnecting the Ethernet cable adds another 0.02VDC. Removing the TFT input cable makes no difference. Disconnecting the HDMI cable seems to make no difference. Naked, it's now 5.05VDC. So everything plugged in consumes a total of 0.17VDC when it's idle.

I'll keep an eye on it. I'm mostly just wondering what could cause this.

Reboot:

It seemed to be hanging on this command for some time during the reboot: Stopping Restore / save the current clock... (three minutes and a half)

So I looked that up and it's linked to a bug at least for the Raspberry Pi 3B+ model or maybe it's just referenced. And yes, I do have Bluetooth disabled in /boot/config.txt. I'm checking to verify that I haven't accidentally used a 3B+ here (no, it's a 3B). Pretty sure I've run an update/upgrade since the timeframe of that bug.

After the reboot eventually working, everything is fine of course.


Some back-story:

  • I've just replaced this Raspberry Pi 3B this week
  • I was noticing that each morning it didn't want to come up
  • The existence of a custom splash screen and suppressing console logging (earlier) prevented me from really seeing anything going on at bootup; this is now turned off temporarily
  • The new Pi3B seems happier and didn't give me problem yesterday
  • And yet, I still had a hiccup this morning with the new Pi3B

Best Guess:

Upon first bootup of the day the computer is cold and the core(s) consume more power booting up and might have created a perfectly-timed under-voltage event when OctoPrint was trying to talk to the operating system.

UPDATE:

I think this has to do with time-synchronization services on the OctoPi image. I created an issue to track this.

1 Like