Crash at hh:17:10 every day

[ech0]

After purchasing a Raspberry Pi 2 and upgrading it with the latest software I've started to get these unusual crashes/freezes at hh:17:10 everyday forcing me to reboot it physically by taking out the power cable. The last 5 crashes has been at.

12:17:10
04:17:10
16:17:10
07:17:10
03:17.10

What's odd is that it occurs at the same minute and second every time, it also "time jumps" before the crash according to syslog.

Ex. today it went from:
...
Mar 6 04:04:50 raspberrypi dhclient: bound to 192.168.0.150 -- renewal in 1679 seconds.
Mar 6 03:17:10 raspberrypi kernel: imklog 5.8.11, log source = /proc/kmsg started.
...
The syslog from the crash can be found here: http://pastebin.com/0DYMM2BA (Personally, I can't see anything wrong here)

I may also add that kmsg is empty, there's nothing to read there.

Steps that I've tried whilst troubleshooting:
1. Forcing the kernel to keep 64MB of RAM available at all times instead of the standard 8MB with

Code: Select all

vm.min_free_kbytes = 65536

2. Adding the following line in /boot/cmdline.txt

Code: Select all

smsc95xx.turbo_mode=N dwc_otg.dma_enable=1 dwc_otg.dma_burst_size=256

- A suggestion I found from searching around the webs

3. Adding 500MB of swap memory, in case the issue was that it for some odd reason would run out of RAM. Which seems highly unlikely..

None of which seems to have worked for me.

My config.txt files looks as follows (standard raspi-config settings for the Pi2)

Code: Select all

arm_freq=1000
gpu_mem=32
core_freq=500
sdram_freq=500
over_voltage=2

And htop displays the following in a regular idle mode:


Thankful for any suggestions I can get to troubleshoot this issue!

[rpdom]

I suspect the hh:17 thing is a red herring, caused by the fake-hwclock which saves the current time at 17 minutes past each hour - but you should look at what is in /etc/cron.hourly/ as those files are run at hh:17.

[hamjudo]

... it also "time jumps" before the crash according to syslog.

Ex. today it went from:
...
Mar 6 04:04:50 raspberrypi dhclient: bound to 192.168.0.150 -- renewal in 1679 seconds.
Mar 6 03:17:10 raspberrypi kernel: imklog 5.8.11, log source = /proc/kmsg started.
...

If the time jumps, ntpd isn't working right. This usually means there is a network problem.

Assuming you have another host on the network, you could compare the time once per minute with something like this:
script TimeStampRecord
while true; do ssh pi@192.168.0.150 date -u;date -u;sleep 60;done

This will record the local time and the time on the pi with issues once a minute until the pi with issues crashes. The record will go into the file TimeStampRecord. Here is what it will look like:

Code: Select all

pi@hamjudopi2 ~ $  script TimeStampRecord
Script started, file is TimeStampRecord
pi@hamjudopi2 ~ $ while true; do ssh pi@192.168.0.150 date -u;date -u;sleep 60;done
Fri Mar  6 19:10:57 UTC 2015
Fri Mar  6 19:10:57 UTC 2015
Fri Mar  6 19:11:57 UTC 2015
Fri Mar  6 19:11:58 UTC 2015
...

My guess is the badness starts when the time goes wonky.

[ech0]

I suspect the hh:17 thing is a red herring, caused by the fake-hwclock which saves the current time at 17 minutes past each hour - but you should look at what is in /etc/cron.hourly/ as those files are run at hh:17.

The directory /etc/cron.hourly/ only has the file fake-hwclock and the code within it is as follows

Code: Select all

if (command -v fake-hwclock >/dev/null 2>&1) ; then
  fake-hwclock save
fi

I can't recall modifying that file manually, so it should be standard.

@hamjudo
Great suggestion, I will set that up and try it.

[ech0]

I ran the TimeStamp script all night and woke up to this

Code: Select all

...
Sat Mar  7 05:00:04 UTC 2015
lör  7 mar 2015 05:00:04 UTC
Sat Mar  7 05:01:04 UTC 2015
lör  7 mar 2015 05:01:04 UTC
Sat Mar  7 05:02:05 UTC 2015
lör  7 mar 2015 05:02:05 UTC
ssh: connect to host 192.168.0.150 port 22: Connection timed out

So apparently it crashed somewhere around ~(05:02:06 and 05:03:06).
And syslog reports this at the given time. (I can't see anything out of the ordinary here besides the time jump. The DHCP service works fine, and I'm able to timestamp it after the DHCP messages)

Code: Select all

...
Mar  7 05:00:31 raspberrypi dhclient: DHCPREQUEST on eth0 to 192.168.0.1 port 67
Mar  7 05:00:32 raspberrypi dhclient: DHCPACK from 192.168.0.1
Mar  7 05:00:32 raspberrypi dhclient: bound to 192.168.0.150 -- renewal in 1450 seconds.
Mar  7 04:17:10 raspberrypi kernel: imklog 5.8.11, log source = /proc/kmsg started.
Mar  7 04:17:10 raspberrypi rsyslogd: [origin software="rsyslogd" swVersion="5.8.11" x-pid="1939" x-info="http://www.rsyslog.com"] start
Mar  7 04:17:10 raspberrypi kernel: [    0.000000] Booting Linux on physical CPU 0xf00
...

However, here's where it gets interested. If I go back to 04.17:ss at the original time in the syslog (not when it time jumps).
I see this

Code: Select all

Mar  7 04:17:01 raspberrypi /USR/SBIN/CRON[16077]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)

As was mentioned in this thread, cron.hourly runs at hh:17:ss, but I only had this in the syslog at the time of the crash. (Not at ex: 01:17:ss | 02:17:ss | 03:17:ss and so forth)

So to sum up;
It seems like something is off with cron, am I right?

EDIT:
I couldn't see anything out of the ordinary in /etc/cron.hourly/ but considering this only happens once a day, I had a look at /etc/cron.daily/ and I have ten files there.
apache2, aptitude, dpkg, man-db, passwd, apt, bsdmainutils, logrotate, ntp and samba.

Considering I've done a little work with apache and samba, I decided to have a look there and noticed this in samba.

Code: Select all

BAK=/var/backups

umask 022
if cd $BAK; then
        # Make sure /etc/samba/smbpasswd exists
        if [ -f /etc/samba/smbpasswd ]; then
                cmp -s smbpasswd.bak /etc/samba/smbpasswd || cp -p /etc/samba/s$
        fi
fi

And by going in to /etc/samba/ I notice there is not a smbpasswd file. Perhaps that could be an issue?

[beta-tester]

Considering I've done a little work with apache and samba, I decided to have a look there and noticed this in samba.

Code: Select all

...
        # Make sure /etc/samba/smbpasswd exists
        if [ -f /etc/samba/smbpasswd ]; then
...

And by going in to /etc/samba/ I notice there is not a smbpasswd file. Perhaps that could be an issue?

no, that "if [ -f /etc/samba/smbpasswd ]" makes sure, that only when the smbpasswd file exists, the inner command will be executed. if there is no such file, nothing will be executed.

[buwuwu]

Hi,

are there any findings or recommandations to solve this problem?
It seems like I'm facing a similar problem but with the Raspberry Pi B+. The Computer seems to crash after the houlry cron sometimes and i need to reboot it by disturbing the power supply. I could not examine the problem completely until yet. There seem to be no regularity of crashes in my case. But the syslog entries and the time jumps are similar to those of ech0.

I'm running ntpd because i've had some clock problems without it. Is it possible that this can cause such a problem?

regards, christian

[Nautilus]

Hi,

I'm facing similar issues although it is not a specific hour of day (hh:17 applies) and I haven't seen the time jump yet. Only the fake hw clock is in cron hourly. It looks as though the pi reboots and gets stuck (both leds, red and green are lit). Any ideas how to troubleshoot. Can it be a problem with SD card?

[Nautilus]

Well, in fact this was a problem with the kernel. Being new to the world of Pi and facing some network issues (losing connection after few hours) early on I found a suggestion to run rpi-update. Which I now realise was a mistake (and also found that the network issues were caused by another device in the household) as I ended up updating to this very unstable version (btw, I did not downgrade, just updated again with the fixed version, so might be still running with an unstable kernel ).

The reason for the weird log entries after the crash (always hh:17) seem to relate to the nature of the crash. From other logs I saw the Pi was actually rebooting after the crash and got stuck somewhere in the middle of the boot sequence. At this point the time was coming from the fake hw clock - I assume - and it was always then from the latest hourly run at hh:17. "Timejumps", which I eventually found a few, would only happen if there were other log entries between the latest run of fake hw clock and the crash. From the crash itself there were nothing in the logs whatsoever. Only from the reboot which would then freeze...

[restomaguio]

Same as mine under Raspbian Wheezy with 'time out killing' errors or message. This was happening continuously and randomly but If I eject the SD and reboot again it went straight to desktop quite quickly. Never had this kind of problem in RISCOS. Raspbian Jessie boot sequence seems fine but the problem is the Motion for USB camera. RJ seems needs some debugging.

[aux99]

I had the same issue, Raspberry crashing daily at 06:17.

What I did to resolve this issue:
- Run all alle cron jobs manually

I noticed the man-db job was causing the daily crash so I altered the script and added the following on top:
exit 0

Now the crashes are over

(note; these scripts can be running in multiple places, for example the man-db is in .daily and .weekly)