[Plugin] Parity Check Tuning

[itimpi]

OK - I can see from that log that the reason it restarted from 0 is that appears to be the saved restart position for some reason?   I need to see if I can identify why that might be the case.

[jmt380]

Good Evening,

 

I am observing the following entries in my syslog every 7 minutes when a parity check is in progress:

 

crond[1196]: exit status 255 from user root /usr/local/emhttp/plugins/parity.check.tuning/parity.check.tuning.php "monitor" &>/dev/null

 

Whenever this message appears in the syslog, the phplog records the following message:

 

[03-Apr-2024 16:36:27 America/New_York] PHP Fatal error:  Uncaught TypeError: array_merge(): Argument #1 must be of type array, null given in /usr/local/emhttp/plugins/dynamix/include/CustomMerge.php:16
Stack trace:
#0 /usr/local/emhttp/plugins/dynamix/include/CustomMerge.php(16): array_merge(NULL, Array)
#1 /usr/local/emhttp/plugins/parity.check.tuning/parity.check.tuning.php(333): require_once('/usr/local/emht...')
#2 {main}
  thrown in /usr/local/emhttp/plugins/dynamix/include/CustomMerge.php on line 16

 

I am currently running version 6.12.9 of Unraid and version 2024.02.15 of the Parity Check Tuning plugin.  I did upgrade Unraid from v6.11.5 to v6.12.9 very recently.  I do not capture and retain my syslogs, so I don't know if this was an issue before, or if this is something new.  I perform a parity check every 2 months, and can't remember if I saw these errors last time or not.  Do you have any insight as to why I might be seeing these messages in the syslog?

 

Thank you for your time.

[itimpi]

@jmt380  Thanks for reporting this.   I will have to see if I can recreate the problem on 6.12.9 and/or 6.12.10.   I must admit I have not gotten around to explicitly tested against those releases thinking nothing in the Release Notes looked like it would break the plugin - but it looks like that might have been optimistic 😒.   The fact it occurs every 7 minutes tells me it is the monitor task the plugin runs while a check is in progress.  The CustomMerge file mentioned is a built-in Unraid one that I have made use of and it is possible something in it has changed that I need to take account of (or write a replacement for it so I no longer need it).

[itimpi]

@jmt380 So far I have not been able to replicate your issue when running a test on 6.12.9.   Just in case it is something specific to the way you have your array setup perhaps you could let me have a screenshot of your Main tab so I can try and set up my test environment to mirror that as closely s possible.   Alternatively a copy of your diagnostics would allow me to extract the needed information from there.

[jmt380]

I DM'd you my diagnostics.

 

Looking into this further on my end.  The error log seems to indicate an issue at line 16 of the CustomMerge.php script.  Line's 15 and 16 of that script are:

 

$smartALL = '/boot/config/smart-all.cfg';
if (file_exists($smartALL)) $var = array_merge($var, parse_ini_file($smartALL));

 

My flashdrive does contain the file smart-all.cfg.  It looks like the reason that file exists on my flashdrive is because I had enabled notifications for attribute 188 under Global Smart Settings...I'm not really sure why I did that, or if possibly that was the default way back when I originally installed Unraid.  Regardless, it is my understanding that attribute 188 is now NOT enabled by default in Unraid.  I unchecked the box for attribute 188, and now my /boot/config/smart-all.cfg is blank.

I am guessing this has likely solved my issue.  I will perform a manual parity check over the next day or two and report back.

[itimpi]

Thanks for that feedback.

 

Given that extra information I was able to recreate the issue and will put a fix into the next release of the plugin.  I need to initialise a variable that the CustomMerge script expects to already have been loaded before it is called.   The error will occur anytime you make a change under Settings->Disk Settings away from the defaults.

[shpitz461]

Hi,

I've installed the plugin via ssh, and when I call 'status' I get the following:

Quote

 parity.check status
Status:  Manual Correcting Parity-Check  (0.1% completed)

When I run one of the parity status scripts available in this post:

I get the correct status:

Quote

Status:   STARTED
Progress: 14727 GB of 18000 GB (81.8%)
Speed:    144.1 MB/sec
Finish:   6h 18m

And here are the stats from var.ini:

Quote

mdColor="green-on"
mdNumDisks="12"
mdNumDisabled="0"
mdNumInvalid="0"
mdNumMissing="0"
mdNumNew="0"
mdNumErased="0"
mdResync="17578328012"
mdResyncCorr="1"
mdResyncPos="15530936"
mdResyncDb="7841188"
mdResyncDt="32"
mdResyncAction="check P Q"
mdResyncSize="17578328012"
mdState="STARTED"
mdVersion="2.9.27"

Any idea why the plugin shows the 0.1%? It's stuck at 0.1% for hours.

Thanks

[itimpi]

No idea I am afraid.   I have never seen this behaviour myself.   The command you gave is just reading the Unraid status information so no idea why it might not be correct.

[RobertP]

Following the most recent update of Parity Check Tuning (2024.04.27), I'm now receiving an  "Unclean shutdown detected".  Doesn't matter if I do a shut-down or a reboot - the msg shows up the next time I log in.  Happening on both my unRAID servers.  If it matters - my Parity Checks run monthly on the evening of the 1st of the month - so I have NOT run a parity check since the update.
Also rcving msgs that SAYS it kicked in an "Non-Correcting Parity Check" (zero errors), but I have not seen it actually running whenever I've looked.  My larger system Parity check usually takes a couple days (16TB), but this "Non-Correcting" check only took 2.5 hrs!?  The smaller system parity check usually takes 16 hrs and that matches the time for that system's "Non-Correcting" check.

[RobertP]

More on the error:  I have no dockers running and I have no VMs running.  My disk timeout is set to 90, same as it always has been.  I did have Dynamix's Directory Cache plugin, which Fix-Common-Problems just reported is not compatible w newest unRAID.  I de-installed the Directory cache, and have rebooted twice, but the error remains.  Attached are my "syslog-previous" files.

UR1-wopr-syslog-previous-2024-04-28 unclean shutdown.txt UR2-wspr-syslog-previous-2024-04-28 unclean shutdown.txt

[itimpi]

5 hours ago, RobertP said:

Following the most recent update of Parity Check Tuning (2024.04.27), I'm now receiving an  "Unclean shutdown detected".  Doesn't matter if I do a shut-down or a reboot - the msg shows up the next time I log in.  Happening on both my unRAID servers.  If it matters - my Parity Checks run monthly on the evening of the 1st of the month - so I have NOT run a parity check since the update.
Also rcving msgs that SAYS it kicked in an "Non-Correcting Parity Check" (zero errors), but I have not seen it actually running whenever I've looked.  My larger system Parity check usually takes a couple days (16TB), but this "Non-Correcting" check only took 2.5 hrs!?  The smaller system parity check usually takes 16 hrs and that matches the time for that system's "Non-Correcting" check.

 

Could you enable the testing mode of logging in the plugin, recreate the error; and then post diagnostics taken after that.  Hopefully with that I can work out why you are getting the message and issue a correction.

[RobertP]

See attached diag from both servers. 

Thanks,

Bob

 

ur2-wspr-diagnostics-20240428-0953.zip ur1-wopr-diagnostics-20240428-0954.zip

[itimpi]

@RobertP   Thanks for those logs.    I can now see why you get the spurious Unclean shutdown notification although I will have to work out why I was not getting it in my test environment.    It is a side-effect of a change I made to delay the Unclean shutdown message until the array is actually starting and the change is obviously not quite right.    I will work out the fix and release an update ASAP, although it is likely to be tomorrow before it is ready.

[RobertP]

I understand, no rush.  Don't kill yourself by debugging all day . . . lol !  I'll just keep ignoring the msg until you get a fix posted.

Bob

[SuperMario86]

On 4/28/2024 at 8:36 AM, RobertP said:

Following the most recent update of Parity Check Tuning (2024.04.27), I'm now receiving an  "Unclean shutdown detected".  Doesn't matter if I do a shut-down or a reboot - the msg shows up the next time I log in.  Happening on both my unRAID servers.  If it matters - my Parity Checks run monthly on the evening of the 1st of the month - so I have NOT run a parity check since the update.
Also rcving msgs that SAYS it kicked in an "Non-Correcting Parity Check" (zero errors), but I have not seen it actually running whenever I've looked.  My larger system Parity check usually takes a couple days (16TB), but this "Non-Correcting" check only took 2.5 hrs!?  The smaller system parity check usually takes 16 hrs and that matches the time for that system's "Non-Correcting" check.

 

I get the same. Came here after an heart attack

 

15 hours ago, itimpi said:

@RobertP   Thanks for those logs.    I can now see why you get the spurious Unclean shutdown notification although I will have to work out why I was not getting it in my test environment.    It is a side-effect of a change I made to delay the Unclean shutdown message until the array is actually starting and the change is obviously not quite right.    I will work out the fix and release an update ASAP, although it is likely to be tomorrow before it is ready.

 

Thanks!

[itimpi]

@RobertP @SuperMario86  I have just pushed an update to the plugin that should stop you getting spurious notifications about an Unclean shutdown having occurred.   I would welcome confirmation from your end that it has fixed the issue you were seeing.

[SuperMario86]

31 minutes ago, itimpi said:

@RobertP @SuperMario86  I have just pushed an update to the plugin that should stop you getting spurious notifications about an Unclean shutdown having occurred.   I would welcome confirmation from your end that it has fixed the issue you were seeing.

Confirmed working fine!!

 

Thanks!

[RobertP]

Working good for me also.  Thanks for the fast fix.

Bob

[wayner]

My log is showing a Parity Check Tuning issue:  Parity Check Tuning: ERROR: marker file found for both scheduled and automatic

 

There are dozens of these messages in my log for Jun 22 and 23 - the last such message was at June 23 08:48..  But the parity check did properly complete and I can see this message in my logs "23-06-2024 08:54 AM Parity Check Tuning [PORTRUSH] Scheduled Correcting Parity-Check finished (0 errors)"

 

Is this something to worry about, or should it go away now?  I did have an unclean shutdown on June 15.

 

 

 

[itimpi]

It is basically a warning that the plugin has found what it thinks is some inconsistent state information.   This can happen after crashes or unclean shutdowns and in your case it looks like that happened while a parity check was in progress.   I have tried to catch all the obvious paths to try and clean up things to stop the message re-occurring but there still seem to be some that creep through.   It does not stop the plugin from running and should auto-correct itself when the parity check finishes.

[Masterwishx]

@itimpi seems some typo <br> :     

 

this is the discord message, in unraid all fine.

 

Edited July 4 by Masterwishx

[itimpi]

2 hours ago, Masterwishx said:

@itimpi seems some typo <br> :     

 

this is the discord message, in unraid all fine.

 

That will be because the message is in HTML format for the Unraid GUI (hence the <br> to force a line break).  

[Szene]

Is it normal that when I have the "Use increments for manual Parity Check:" set to "No" that I still get an log entry in the history?




The Parity-Check at the bottom of the screen is the one I had started manually on Thursday which finished today on Saturday, but as you can see I got a second entry from the plugin a few minutes later.

Why do I have 2 entrys for the same check? I doubt that 2 checks can run at the same time, or? Speeds at the beginning are around 280MB/s but they drop to 5-90MB/s at around 20TB.

parity.check.tuning.progress.save parity-checks_from_config.log parity-checks_from_plugin.log

Edited July 27 by Szene

[itimpi]

On 7/27/2024 at 9:10 PM, Szene said:

Why do I have 2 entrys for the same check? I doubt that 2 checks can run at the same time, or? Speeds at the beginning are around 280MB/s but they drop to 5-90MB/s at around 20TB.

It is normal for the plugin to always enhance the log entry in the history regardless of whether you are using it to run increments, but it should be finding the one the standard check produced and enhancing that rather than creating a new entry,  

 

However something strange is going on as the standard check should only write an entry when it completes - not when it starts and you suggest that you did not have a check that completed on Thursday.   What version of Unraid are you using so I can check that the default check has not changed its logging behaviour.

[Szene]

Exactly, it was started on Thursday and completed on Saturday. Before I started it on Thursday there was only the one Parity-Sync entry from the 18th. Im running the current latest stable version 6.12.11.

But it's a good information that the time beeing displayed in the history should be the finishing time. If we can't find aynthing wrong in the first glance then I think I can wait to see if it also happens to scheduled checks. My next one would be in Oktober. It seemed just really strange to me.