MinimServer & HDD Sleep

[MikeSpragg]

(18-04-2014 12:59)simoncn Wrote:  

(17-04-2014 23:49)MikeSpragg Wrote:  Here you go !

Thanks very much!

This log doesn't show any activity that could cause disk I/O. Here's a summary:

23:16:06 The NAS is disconnected from the network
23:16:06 The Monitor device sends out "alive" notifications on the loopback subnet
23:24:40 The MediaServer device sends out "alive" notifications on the loopback subnet
23:29:27 The Monitor device sends out "alive" notifications on the loopback subnet
23:38:09 The MediaServer device sends out "alive" notifications on the loopback subnet
23:42:18 The Monitor device sends out "alive" notifications on the loopback subnet
23:47:42 The NAS is reconnected to the network

If MinimServer logging is set to Info, this activity will not cause anything to be written to the log and will not cause any other disk I/O from the MinimServer/Java process.

If you are seeing disk I/O with MinimServer logging set to Info, this might be caused by something else on the QNAP that is handling the network activity generated by the "alive" notifications (for example, some kind of network logging). However, the timing of this "alive" activity doesn't fit with your earlier description that the disk I/O occurs regularly every 4 to 5 minutes.

Another possibility is that ohNet is doing something every 4 to 5 minutes that isn't being logged and is causing disk I/O. From my knowledge of how ohNet works, this seems very unlikely.

Can you produce a similar complete log of disk I/O activity for a 30-minute period when the NAS is disconnected from the LAN? This would be similar to the extracts you included in this post. When doing this, please set ohnet.debug to Default and MinimServer logging to Info. If I can see the complete picture over a 30-minute period, I might be able to spot some pattern.

Hi, as I need to be connected to run the script I can't disconnect the QNAP from the LAN whilst that runs - did you still want the complete log ?

[simoncn]

(18-04-2014 19:18)MikeSpragg Wrote:  Hi, as I need to be connected to run the script I can't disconnect the QNAP from the LAN whilst that runs - did you still want the complete log ?

I think it will cause problems if the NAS is on the network because the log will contain the side-effects of other network activity. I suspect the log entries that you posted earlier are likely to be in this category.

I am wondering if it is possible to run the script as a background process with output redirected to some other disk than the one(s) you are monitoring for I/O activity (for example, a USB memory stick). If so, it should be possible to start the script running and then exit the SSH window and disconnect the NAS from the network. It's important to run it as a background process (with the & suffix on the command) so it doesn't get killed when you exit the SSH window. After the test is complete, you could reconnect to the NAS and retrieve the redirected output.

[MikeSpragg]

Hi Simon, I'm just doing them now - I don't think the LAN/connection is the issue - I have two logs (in about 10 mins) and the difference is huge....

[MikeSpragg]

(18-04-2014 20:37)MikeSpragg Wrote:  Hi Simon, I'm just doing them now - I don't think the LAN/connection is the issue - I have two logs (in about 10 mins) and the difference is huge....

Hi Simon, enclosed are the logs. I've annotated them in readme.txt but, I'm fairly sure you can see - a major difference between log1 and log2. As I write this, the disks are still spun-down from 20:30 and haven't started up since.

[simoncn]

(18-04-2014 20:54)MikeSpragg Wrote:  Hi Simon, enclosed are the logs. I've annotated them in readme.txt but, I'm fairly sure you can see - a major difference between log1 and log2. As I write this, the disks are still spun-down from 20:30 and haven't started up since.

Thanks for doing this. I see the huge differences, but there is nothing in log1 that says the MinimServer process is doing the disk I/O. It is noticeable that log2 contains very similar entries to log1 but in smaller quantities. This would correspond to the smaller amount of network activity that is happening when MinimServer isn't running.

If the NAS is connected to the network and MinimServer is running, there will be lots of "UPnP chatter" across the network. I believe the additional disk I/O that is being logged in log1 is a side-effect of the increased network activity that is caused by this "UPnP chatter".

The best way to eliminate the "UPnP chatter" is to run the disk I/O logging test with the NAS disconnected from the network. This will provide definite confirmation whether MinimServer is doing something that is causing disk I/O to occur.

[simoncn]

(18-04-2014 21:44)MikeSpragg Wrote:  Presumably I could do the same test with just laptop connected directly to the qnap?

If it's a Windows laptop, it's very likely that it will create UPnP chatter. Were you thinking of having a router active on the LAN? This is also likely to create UPnP chatter.

[MikeSpragg]

(19-04-2014 00:01)MikeSpragg Wrote:  

(18-04-2014 23:54)simoncn Wrote:  

(18-04-2014 21:44)MikeSpragg Wrote:  Presumably I could do the same test with just laptop connected directly to the qnap?

If it's a Windows laptop, it's very likely that it will create UPnP chatter. Were you thinking of having a router active on the LAN? This is also likely to create UPnP chatter.

No, it would be straight connection (x-over) (laptop straight to qnap). I'll see if the USB redirect works.

Hi Simon, OK - did an & version - which is attached. Unfortunately, very much the same (with LAN disconnected).

[simoncn]

(19-04-2014 01:30)MikeSpragg Wrote:  Hi Simon, OK - did an & version - which is attached. Unfortunately, very much the same (with LAN disconnected).

Thanks very much! I'll look at this later today. Did you redirect the output to a different disk (USB stick) that isn't one of the disks you are trying to spin down?

[simoncn]

(19-04-2014 01:30)MikeSpragg Wrote:  Hi Simon, OK - did an & version - which is attached. Unfortunately, very much the same (with LAN disconnected).

I think the significant activity is this:

After 200 seconds idle (A):

6277.220366] setcfg(32122): dirtied inode 6894 (CACHEDEV2_DATA.log.bak) on md9
<7>[316277.222210] setcfg(32123): dirtied inode 6929 (CACHEDEV2_DATA.log.bak) on md9
<7>[316277.225515] sed(32135): dirtied inode 6894 (CACHEDEV2_DATA.logafg0VQ) on md9
<7>[316277.273074] setcfg(32245): dirtied inode 6875 (vg1.log) on md9
<7>[316277.273326] setcfg(32245): dirtied inode 6929 (vg1.log.bak) on md9
<7>[316277.275816] sed(32248): dirtied inode 6875 (vg1.logbqqQfW) on md9

After 360 seconds idle (B):

<4>[316658.692110] md1_raid1(2930): WRITE block 982422920 on sda (3 sectors)
<4>[316658.703745] md1_raid1(2930): WRITE block 982422928 on sda (1 sectors)
<4>[316658.705889] md1_raid1(2930): WRITE block 982422920 on sda (3 sectors)
<4>[316658.710775] md1_raid1(2930): WRITE block 458626512 on sda (8 sectors)
<4>[316658.911573] md1_raid1(2930): WRITE block 982422920 on sda (3 sectors)
<4>[316658.914570] md1_raid1(2930): WRITE block 982422928 on sda (1 sectors)

After 194 seconds idle (C):

<7>[316877.204889] setcfg(8202): dirtied inode 6894 (CACHEDEV2_DATA.log) on md9
<7>[316877.205145] setcfg(8202): dirtied inode 6929 (CACHEDEV2_DATA.log.bak) on md9
<7>[316877.206453] setcfg(8203): dirtied inode 6894 (CACHEDEV2_DATA.log.bak) on md9
<7>[316877.207791] setcfg(8204): dirtied inode 6929 (CACHEDEV2_DATA.log.bak) on md9
<7>[316877.210302] sed(8207): dirtied inode 6894 (CACHEDEV2_DATA.log2o16UQ) on md9
<7>[316877.251374] setcfg(8240): dirtied inode 6875 (vg1.log) on md9
........
setcfg(8240): dirtied inode 6929 (vg1.log.bak) on md9
<7>[316877.254570] sed(8248): dirtied inode 6875 (vg1.logZ1OesT) on md9
<7>[316877.348734] setcfg(8389): dirtied inode 6808 (vg2.log) on md9
<7>[316877.348998] setcfg(8389): dirtied inode 6929 (vg2.log.bak) on md9
<7>[316877.351538] sed(8392): dirtied inode 6808 (vg2.logNdGDq0) on md9

After 154 seconds idle (D):

<7>[317128.917441] log_tool(12461): dirtied inode 13282 (event.log) on md9
<7>[317128.917871] log_tool(12461): dirtied inode 13300 (event.log-journal) on md9

In (A) and (C) there are references to vg1.log and vg2.log. These seem to be associated with valgrind (a debugging tool). Is it possible that the QTS 4.1 beta firmware contains valgrind debugging code that is writing to these log files? Can you look at these log files to see what they contain?

[MikeSpragg]

Yes, plugged in a USB disk and altered script. There is just one LV - 15TB RAID10.