76 hour jobs exited when Raspberry π rebooted. How can I see what caused it?

Get Help
1

Subject says it all…76 hour job exited with a loud beep, no error messages, no offer to resume. Looking into the Rasp π, I see a couple of flurries of restarted services, and what looks like a reboot at around the time the job exited. What can I look for in the logs to find out why this happened? I assume

Run /sbin/init as init process

is a marker…that means a reboot? That was at 9:17 and the job quit at 9:39, or close to it.

But now that log lines are being written out of order? 
Jul 25 09:36:00 3-pi systemd[1]: Started Network Monitor.
Jul 25 09:36:00 3-pi networkcheck[18246]: Network monitoring not enabled.
Jul 25 09:36:00 3-pi systemd[1]: networkcheck.service: Succeeded.
Jul 25 09:37:00 3-pi systemd[1]: Started Network Monitor.
Jul 25 09:37:00 3-pi networkcheck[18253]: Network monitoring not enabled.
Jul 25 09:37:00 3-pi systemd[1]: networkcheck.service: Succeeded.
Jul 25 09:38:00 3-pi systemd[1]: Started Network Monitor.
Jul 25 09:38:00 3-pi networkcheck[18262]: Network monitoring not enabled.
Jul 25 09:38:00 3-pi systemd[1]: networkcheck.service: Succeeded.
Jul 25 09:17:07 3-pi fake-hwclock[132]: Thu 25 Jul 16:17:01 UTC 2024
Jul 25 09:17:07 3-pi systemd-fsck[146]: e2fsck 1.46.2 (28-Feb-2021)

Why are lines timestamped 9:38 before ones from 9:17?

I guess I am back to running from an SD card for now.

Prusa MK3s+
Raspberry π 3b with reliable Rasberry π power supply, no voltage issues.

2

First, please do not delete the template. Stick to it.

Please attach the systeminfo bundle to your next post.

Then, please bring your log snippet into a readable form using Preformatted Text.

Format

3

octoprint-systeminfo-20240725105422.zip (41.4 KB)

Systeminfo attached. I am a little frustrated so the idea of working through a template versus getting an answer to my question of how I find the last log line before a reboot doesn't appeal. The filament I was using has to be re-dried now apparently as it is behaving very poorly on a re-do of this job.

4

Understandable. But to help, we need as much and precise information as possible. That is the template for.

A back jump in time

2024-07-25 09:20:28,756 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 561619, 'printer_state': 'PRINTING'}
2024-07-25 09:35:11,162 - octoprint.server.heartbeat - INFO - Server heartbeat <3
2024-07-25 09:35:28,841 - octoprint.plugins.tracking - INFO - Sent tracking event ping, payload: {'octoprint_uptime': 562519, 'printer_state': 'PRINTING'}
2024-07-25 09:17:12,282 - octoprint.startup - INFO - ******************************************************************************
2024-07-25 09:17:12,287 - octoprint.startup - INFO - Starting OctoPrint 1.10.2
2024-07-25 09:17:12,297 - octoprint.startup - INFO - ******************************************************************************

Is usually cause by a power failure of the Pi PSU.

How do you power the Pi?

5

I use a genuine Raspberry π power supply made for the 3b.

6

I assume it is plugged into the wall outlet.

Do you have by chance a substitute for testing?

7

Only the unreliable 3rd party one it replaced.

I'm confused that it seems to have rebooted/restarted at 9:17 but the job didn't fail for another 20 minutes or so. It would be great to think there was a 20 minute buffer of commands but that's nt how this went.

8

Without an RTC.on the pi, it periodically writes the time to a temp file. When it reboots, it reads the file and the boot logs are filled with the time starting from that saved value. When it has networking online and finally polls the ntp server to set the time, then the time has an abrupt change when it resets to the current time.
If something caused the saved time to be corrupted, it could have set a time in the future, and when it hit the ntp server it bumped it back to the current time of 9:17

9

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.