1 1
Z11ntal33r

Log file access events to find out why HDDs spin-up

Recommended Posts

Hi,

I've two Tinker Board servers running latest Armbian stable Debian GNU/Linux 9 with 4.19.*-rockchip. In that regard, I've connected some HDDs and from the log I see that every day at a specific time all HDDs are spinning up as seen below in the spoiler. This happens for both servers at the same specific time every day..

Spoiler

# Server 1
May 13 06:25:26 Tinkerboard hd-idle[29538]: sda spinup
May 13 06:25:26 Tinkerboard hd-idle[29538]: sdc spinup
May 13 06:25:26 Tinkerboard hd-idle[29538]: sdb spinup
May 13 06:35:36 Tinkerboard hd-idle[29538]: sda spindown
May 13 06:35:45 Tinkerboard hd-idle[29538]: sdc spindown
May 13 06:35:45 Tinkerboard hd-idle[29538]: sdb spindown
May 14 06:26:07 Tinkerboard hd-idle[29538]: sda spinup
May 14 06:26:07 Tinkerboard hd-idle[29538]: sdc spinup
May 14 06:26:07 Tinkerboard hd-idle[29538]: sdb spinup
May 14 06:36:17 Tinkerboard hd-idle[29538]: sda spindown
May 14 06:36:26 Tinkerboard hd-idle[29538]: sdc spindown
May 14 06:36:26 Tinkerboard hd-idle[29538]: sdb spindown
May 15 06:25:51 Tinkerboard hd-idle[29538]: sda spinup
May 15 06:25:51 Tinkerboard hd-idle[29538]: sdc spinup
May 15 06:25:51 Tinkerboard hd-idle[29538]: sdb spinup
May 15 06:36:01 Tinkerboard hd-idle[29538]: sda spindown
May 15 06:36:10 Tinkerboard hd-idle[29538]: sdc spindown
May 15 06:36:10 Tinkerboard hd-idle[29538]: sdb spindown
May 16 06:25:33 Tinkerboard hd-idle[29538]: sda spinup
May 16 06:25:33 Tinkerboard hd-idle[29538]: sdc spinup
May 16 06:25:33 Tinkerboard hd-idle[29538]: sdb spinup
May 16 06:35:43 Tinkerboard hd-idle[29538]: sda spindown
May 16 06:35:52 Tinkerboard hd-idle[29538]: sdc spindown
May 16 06:35:52 Tinkerboard hd-idle[29538]: sdb spindown

# Server 2
May 13 06:25:37 Tinkerboard hd-idle[794]: sda spinup
May 13 06:25:37 Tinkerboard hd-idle[794]: sdb spinup
May 13 06:35:42 Tinkerboard hd-idle[794]: sda spindown
May 13 06:35:43 Tinkerboard hd-idle[794]: sdb spindown
May 14 06:25:45 Tinkerboard hd-idle[794]: sda spinup
May 14 06:25:45 Tinkerboard hd-idle[794]: sdb spinup
May 14 06:35:52 Tinkerboard hd-idle[794]: sda spindown
May 14 06:35:53 Tinkerboard hd-idle[794]: sdb spindown
May 15 06:25:48 Tinkerboard hd-idle[794]: sda spinup
May 15 06:25:48 Tinkerboard hd-idle[794]: sdb spinup
May 15 06:35:56 Tinkerboard hd-idle[794]: sda spindown
May 15 06:35:56 Tinkerboard hd-idle[794]: sdb spindown
May 16 06:25:44 Tinkerboard hd-idle[794]: sda spinup
May 16 06:25:44 Tinkerboard hd-idle[794]: sdb spinup
May 16 06:35:54 Tinkerboard hd-idle[794]: sda spindown
May 16 06:35:54 Tinkerboard hd-idle[794]: sdb spindown

 

I've been thinking of using fatrace to trace file access events around the specific time to find which service that spins up my HDDs, however, when I try to use fatrace by running the code below I get the message "Cannot initialize fanotify: Function not implemented". I've come across two bug reports which seems to be related to this issue: some archs/kernels define O_LARGEFILE and Hardcoded KERNEL_O_LARGEFILE does not work on ARM. So, I guess fatrace is not an option given that it's not enabled in the kernel configuration.

$ sudo fatrace -o /tmp/trace -s 60
Cannot initialize fanotify: Function not implemented


btrace doesn't seem to be working either as seen below.

$ sudo btrace /dev/sdb
BLKTRACESETUP(2) /dev/sdb failed: 5/Input/output error


Neither is iotop as seen below.

$ sudo iotop
Could not run iotop as some of the requirements are not met:
- Linux >= 2.6.20 with
  - I/O accounting support (CONFIG_TASKSTATS, CONFIG_TASK_DELAY_ACCT, CONFIG_TASK_IO_ACCOUNTING)


Any recommendation for tools that I can use to find out which process that is spinning up my HDDs every day? 

Thanks in advance!:)

Share this post


Link to post
Share on other sites

I suspected that "Function not implemented" was related to some kernel configuration, however, I'm looking for an alternative to find processes which are accessing all three HDDs every day at the same time without disabling processes one by one...

 

I've found blktrace which seems to give some relevant information as seen below. So, I'm going to run the following command a minute before the timestamp my HDDs are spinning up

$ sudo blktrace -d /dev/sdb -o - | blkparse -i -
  8,16   1        1     0.000000000    17  C   N [0]
  8,16   2        1 1266874889.708500152   888  G   N [smartd]
  8,16   2        2 1266874889.708505985   888  I   N 0 [smartd]
  8,16   2        3 1266874889.708510360   888  D   N 0 [smartd]
  8,16   1        2     5.001279610    17  C   N [0]
  8,16   1        3     5.002521825    17  C   N [65531]
  8,16   2        4     5.000177978   888  G   N [smartd]
  8,16   2        5     5.000184978   888  I   N 0 [smartd]
  8,16   2        6     5.000188770   888  D   N 0 [smartd]
  8,16   2        7     5.001649445 30968  G   N [kworker/2:2]
  8,16   2        8     5.001652070 30968  I   N 0 [kworker/2:2]
  8,16   2        9     5.001653528 30968  D   N 0 [kworker/2:2]

 

I'll also run strace to see if I can get some more information regarding this

sudo strace -f -e open -t ls 2>&1

 

Tracking syscalls with auditctl (Audit framework) is also a possibility I've found and might be possible if kernels CONFIG_AUDIT is enabled. I'll look more into auditctl tomorrow if I don't find some relevant information from blktrace or strace.

Share this post


Link to post
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.
Note: Your post will require moderator approval before it will be visible.

Guest
Reply to this topic...

×   Pasted as rich text.   Restore formatting

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

Loading...
1 1