What's preventing spindown of disks on RPI?

I have a RPi3 with an external USB hardddisk attached which appeared to be not to be spinning down although the setup (via hdparm was correct. But how to determine what was the cause of activity to the disk?


The RPi has the following udev rule in place:

# /etc/udev/rules.d/50-hdparm.rules
ACTION=="add|change", SUBSYSTEMS=="usb", KERNEL=="sd[a-z]", ATTR{queue/rotational}=="1", RUN+="/sbin/hdparm -B 127 -S 24 /dev/%k"

which will automatically spin down any USB harddisk after inactivity.

The first thing to check was that the hdparm where still enabled, so reissue: hdparm -B 127 -S 12 to force spindown after 30secs. Watching the harddisk's LED, it was observed that periodically access was made.

Next, iotop was installed to watch active processes:

$ iotop -oPa -d 2
Total DISK READ : 0.00 B/s | Total DISK WRITE : 0.00 B/s
Actual DISK READ: 0.00 B/s | Actual DISK WRITE: 0.00 B/s
PID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
92 be/3 root 0.00 B 36.00 K 0.00 % 0.09 % [jbd2/sda[1-8]]
1149 be/5 pi 0.00 B 8.00 K 0.00 % 0.00 % [kodi_v7.bin --lircdev /var/run/lirc/lircd]
1134 be/4 root 0.00 B 16.00 K 0.00 % 0.00 % nmbd -D

Unfortunately this does not indicate what disk is being written to. However, I was aware that I had put located /home/pi/.kodi to the harddisk. Using lsof would also give indication of files.

But what was causing kodi to periodically write to disk?

$ echo 3 > /proc/sys/vm/block_dump
$ dmesg | grep sda
[ 5005.780036] kodi_v7.bin(3416): READ block 222687232 on sda1 (48 sectors)
[ 5005.836028] kodi_v7.bin(3416): dirtied inode 6949830 (kodi.log) on sda1
[ 5005.836046] kodi_v7.bin(3416): dirtied inode 6949830 (kodi.log) on sda1
[ 5005.836322] kodi_v7.bin(3416): WRITE block 223450880 on sda1 (24 sectors)
[ 5005.837227] jbd2/sda1-8(376): WRITE block 134489640 on sda1 (8 sectors)
[ 5005.837251] jbd2/sda1-8(376): WRITE block 134489648 on sda1 (8 sectors)
[ 5005.837262] jbd2/sda1-8(376): WRITE block 134489656 on sda1 (8 sectors)
[ 5005.837268] jbd2/sda1-8(376): WRITE block 134489664 on sda1 (8 sectors)
[ 5005.837274] jbd2/sda1-8(376): WRITE block 134489672 on sda1 (8 sectors)
[ 5005.837280] jbd2/sda1-8(376): WRITE block 134489680 on sda1 (8 sectors)
[ 5005.837286] jbd2/sda1-8(376): WRITE block 134489688 on sda1 (8 sectors)
[ 5005.838370] jbd2/sda1-8(376): WRITE block 134489696 on sda1 (8 sectors)
[ 5005.855334] kodi_v7.bin(3416): WRITE block 222570176 on sda1 (8 sectors)
[ 5005.855373] kodi_v7.bin(3416): WRITE block 222571008 on sda1 (8 sectors)
[ 5005.856293] jbd2/sda1-8(376): WRITE block 134489704 on sda1 (8 sectors)
[ 5005.856314] jbd2/sda1-8(376): WRITE block 134489712 on sda1 (8 sectors)
[ 5005.856814] jbd2/sda1-8(376): WRITE block 134489720 on sda1 (8 sectors)
[ 5006.148729] kodi_v7.bin(3415): READ block 222606072 on sda1 (448 sectors)
[ 5006.251071] kodi_v7.bin(3415): dirtied inode 6949830 (kodi.log) on sda1
[ 5006.251136] kodi_v7.bin(3415): dirtied inode 6949830 (kodi.log) on sda1
[ 5006.251806] kodi_v7.bin(3415): WRITE block 223385336 on sda1 (24 sectors)

Once we had the confirmation that it was kodi a few searches revealed an addon was misconfigured. Once this was fixed, another look at iotop and dmesg confirmed no more spurious writes to disk and the disk was able to spin down as expected.