We are having issues with our electrics, so I wrote a simple bash script to try to log when the events were happening. I've created a cron job that runs every minute to run the script.
The idea of the script is quite simple, write the timestamp to /tmp/powerlast.tmp. If next time the script runs, the gap in time is greater than 90 seconds append an entry using the $powerlast value to the powerfailure.csv file.
I'm getting some strange results, for example at on 24th Dec @ 11:50am the electrics tripped, but the script is telling me that it occurred at 11:20am - this is wrong.
#!/bin/bash
powercsv=~/powerfailure.csv
powerlast=/tmp/powerlast.tmp
frequency=60 # seconds
margin=$(($frequency+($frequency/2)))
if [ ! -f "$powercsv" ]; then
echo "timestamp,weekofyear,dayofyear,day,date,month,year,hour,minute" > "$powercsv"
fi
if [ ! -f "$powerlast" ]; then
echo "4133980799" > "$powerlast"
fi
last=$(($(cat "$powerlast"))) # seconds since epoch
now=$(($(date +%s))) # seconds since epoch
lastdate=$(date -d @$last)
nowdate=$(date -d @$now)
if [ $now -lt $last ]; then
# first run ever
echo "$now" > "$powerlast"
else
# aim is to detect gaps greater than the run frequency.
# echo "margin $margin frequency $frequency"
echo "$now" > "$powerlast"
gap=$(($now-$last))
if [ $gap -gt $margin ]; then
echo "$nowdate: Power interruption detected at $lastdate! $gap exceeds $margin second limit."
weekofyear=$(date -d @$last +%V)
dayofyear=$(date -d @$last +%j)
day=$(date -d @$last +%a)
date=$(date -d @$last +%d)
month=$(date -d @$last +%m)
year=$(date -d @$last +%y)
hour=$(date -d @$last +%H)
minute=$(date -d @$last +%M)
echo "$last,$weekofyear,$dayofyear,$day,$date,$month,$year,$hour,$minute" >> "$powercsv"
fi
fi
I scheduled a task to run * * * * * /home/usr/powerfailure/powerfailure.sh
via crontab -e
I've checked the file that I use to track the last uptime and it seems to be OK (I checked my clock and it's the same).
$ grep -Eo '^[0-9]+' /tmp/powerlast.tmp | while read x; do date -d @$x; done
Tue Dec 24 12:41:02 GMT 2019
Oddly, all my entries seem to be logging approximately 20 past the hour.
$ grep -Eo '^[0-9]+' powerfailure.csv | while read x; do date -d @$x; done
Fri Dec 20 13:03:02 GMT 2019
Sat Dec 21 10:18:01 GMT 2019
Sat Dec 21 11:18:02 GMT 2019
Sat Dec 21 19:20:02 GMT 2019
Sun Dec 22 02:19:01 GMT 2019
Mon Dec 23 14:21:02 GMT 2019
Tue Dec 24 07:20:02 GMT 2019
Tue Dec 24 11:20:01 GMT 2019
I checked the /var/log/syslog and found some odd timestamp ordering in there, so I think this may be to blame, but I don't know why it's doing this.
Dec 24 11:45:01 raspberrypi CRON[9915]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:46:02 raspberrypi CRON[9976]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:47:01 raspberrypi CRON[10011]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:17:46 raspberrypi cron[324]: (CRON) INFO (pidfile fd = 3)
Dec 24 11:17:46 raspberrypi cron[324]: (pi) ORPHAN (no passwd entry)
Dec 24 11:17:46 raspberrypi cron[324]: (CRON) INFO (Running @reboot jobs)
Dec 24 11:18:01 raspberrypi CRON[737]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:19:01 raspberrypi CRON[1459]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:20:01 raspberrypi CRON[2308]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:20:01 raspberrypi CRON[2313]: (smmsp) CMD (test -x /etc/init.d/sendmail && test -x /usr/share/sendmail/sendmail && test -x /usr/lib/sm.bin/sendmail && /usr/share/sendmail/sendmail cron-msp)
Dec 24 11:52:35 raspberrypi CRON[3237]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:53:01 raspberrypi CRON[3657]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)
Dec 24 11:54:01 raspberrypi CRON[4600]: (usr) CMD (/home/usr/powerfailure/powerfailure.sh)