Ratelimit deadman zevents as with delay zevents #11786

ghost · 2021-03-23T21:48:16Z

Motivation and Context

Just as delay zevents can flood the zevent pipe when a vdev becomes
unresponsive, so do the deadman zevents.

Description

Ratelimit deadman zevents according to the same tunable as for delay
zevents.

Make existing deadman tests run on FreeBSD.

Add a test for the deadman event ratelimit.

How Has This Been Tested?

Ran ZTS on FreeBSD and Linux.

Types of changes

Bug fix (non-breaking change which fixes an issue)
New feature (non-breaking change which adds functionality)
Performance enhancement (non-breaking change which improves efficiency)
Code cleanup (non-breaking change which makes code smaller or more readable)
Breaking change (fix or feature that would cause existing functionality to change)
Library ABI change (libzfs, libzfs_core, libnvpair, libuutil and libzfsbootenv)
Documentation (a change to man pages or other documentation)

Checklist:

My code follows the OpenZFS code style requirements.
I have updated the documentation accordingly.
I have read the contributing document.
I have added tests to cover my changes.
I have run the ZFS Test Suite with this change applied.
All commit messages are properly formatted and contain Signed-off-by.

behlendorf · 2021-03-24T21:15:30Z

Good find. It just looks like the test case still needs to be refined a little.

http://build.zfsonlinux.org/builders/CentOS%208%20x86_64%20%28TEST%29/builds/3320/steps/shell_4/logs/summary

ghost · 2021-03-24T22:22:01Z

Add sleep 10 after writing in the test to give the events time to trickle through the kernel

ghost · 2021-03-25T16:45:22Z

Change the sleep into a loop that will try for up to 30 seconds

Starting to wonder how much work zpool wait -t events would be to implement...

ghost · 2021-03-25T21:56:03Z

Doubled the timeout waiting for events

Increasing the timeout seemed to help the first time, but one or two still failed. This really shouldn't take that long, but we seem to get unlucky on AWS from time to time. I hope 60 seconds is plenty of time in practice.

behlendorf · 2021-03-26T17:57:42Z

Even with the 60s limit we seem to have hit it with the Github Actions CI builders. That's really quite a long time, and taking a quick look at the console logs it does look like the deadman ran. So it seems there should have been events. But it's suspicious that both the Github Actions CI builders failed.

behlendorf · 2021-03-31T17:00:59Z

tests/zfs-tests/tests/functional/deadman/deadman_ratelimit.ksh

+		log_fail "No dropped events after $TIMEOUT seconds"
+	fi
+	sleep 1
+done


This doesn't look right to me. Why are we expecting dropped events here? I'd expect to only see drops reported when we overflow the zfs_zevent_len_max queue depth and the ZED doesn't consume the event before it's discard. Events which are internally ratelimited on the kernel side and never posted aren't considered to be drops.

What we've been meaning to do for a while is increase the default zfs_zevent_len_max to make drops far more uncommon. The current value is really very low, and scaled of the number of cpus which doesn't make much sense.

Thanks, I definitely misunderstood that. I'll look for another way to test this.

In fact zfs_is_ratelimiting_event() does increment ratelimit_dropped via fm_erpt_dropped_increment() when the rate limiting kicks in, so I should expect to see dropped events. ZED is not running during these tests, either. I wonder if it's possible the zio is actually completing in under 1ms, so no deadman events are posted? That feels too good to be true.

ghost · 2021-04-01T18:21:16Z

Rebased
Removed the check for dropped events

Looks like something slipped in to break the build on stable/12

behlendorf · 2021-04-01T23:03:49Z

tests/zfs-tests/tests/functional/deadman/deadman_ratelimit.ksh

+log_must zinject -a
+log_must dd if=$mntpnt/file of=$TEST_BASE_DIR/devnull oflag=sync
+
+sleep 10


Is the sleep here needed with such a short deadman timeout?

I'm not sure what's going on here. I put the sleep there under the understanding that events might not have finished making their way into the queue by the time we go to look for them. Ten seconds should have been overkill, but apparently it's not even enough in some cases. There are some test bots failing to see any deadman events somehow.

Unfortunately, I can't reproduce these failures locally. The tests are working as intended on FreeBSD and Linux in my dev environments. I'll continue auditing the zevent code. Perhaps there are some more hidden issues like the ratelimit_dropped one I came across already.

I'd suggest updating the test to use the file_wait_event function from events_common.ksh. That checks the ZED log for the message and you can set a maximum timeout... although I guess that wouldn't be portable for FreeBSD. But you could write something similar.

One other thing you might try is to replace the zinject -a with a zpool export; zpool import. While zinject -a should drop the cache, it may not drop everything if for example the buffers are still being written back. In which case they'll be cache hits for your dd read and you won't trigger the deadman probably.

ghost · 2021-04-05T19:17:35Z

Rebased
Export and import rather than using zinject to clear the ARC

behlendorf · 2021-04-06T20:45:46Z

tests/zfs-tests/tests/functional/deadman/deadman_ratelimit.ksh

+log_must file_write -b 1048576 -c 8 -o create -d 0 -f $mntpnt/file
+log_must zpool export $TESTPOOL
+log_must zpool import $TESTPOOL
+log_must dd if=$mntpnt/file of=$TEST_BASE_DIR/devnull oflag=sync


It looks like in the most recent results we didn't see any delays. Perhaps we should make sure the deadman will trigger by additionally injecting some IO delays in to the pipeline. Check out the apply_zinject_delays function in perf.shlib for how to use zinject for this.

Just as delay zevents can flood the zevent pipe when a vdev becomes unresponsive, so do the deadman zevents. Ratelimit deadman zevents according to the same tunable as for delay zevents. Signed-off-by: Ryan Moeller <ryan@iXsystems.com>

Signed-off-by: Ryan Moeller <ryan@iXsystems.com>

ghost · 2021-04-06T21:54:24Z

Rebased
Inject delay for testing

ghost · 2021-04-07T16:48:25Z

🎉

behlendorf · 2021-04-07T17:06:01Z

Alright! Let me just resubmit those builds for good measure then this should be good to go.

Just as delay zevents can flood the zevent pipe when a vdev becomes unresponsive, so do the deadman zevents. Ratelimit deadman zevents according to the same tunable as for delay zevents. Enable deadman tests on FreeBSD and add a test for deadman event ratelimiting. Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov> Reviewed-by: Don Brady <don.brady@delphix.com> Signed-off-by: Ryan Moeller <ryan@iXsystems.com> Closes openzfs#11786

Just as delay zevents can flood the zevent pipe when a vdev becomes unresponsive, so do the deadman zevents. Ratelimit deadman zevents according to the same tunable as for delay zevents. Enable deadman tests on FreeBSD and add a test for deadman event ratelimiting. Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov> Reviewed-by: Don Brady <don.brady@delphix.com> Signed-off-by: Ryan Moeller <ryan@iXsystems.com> Closes #11786

Just as delay zevents can flood the zevent pipe when a vdev becomes unresponsive, so do the deadman zevents. Ratelimit deadman zevents according to the same tunable as for delay zevents. Enable deadman tests on FreeBSD and add a test for deadman event ratelimiting. Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov> Reviewed-by: Don Brady <don.brady@delphix.com> Signed-off-by: Ryan Moeller <ryan@iXsystems.com> Closes openzfs#11786

Just as delay zevents can flood the zevent pipe when a vdev becomes unresponsive, so do the deadman zevents. Ratelimit deadman zevents according to the same tunable as for delay zevents. Enable deadman tests on FreeBSD and add a test for deadman event ratelimiting. Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov> Reviewed-by: Don Brady <don.brady@delphix.com> Signed-off-by: Ryan Moeller <ryan@iXsystems.com> Closes #11786

ghost added the Status: Code Review Needed Ready for review and testing label Mar 23, 2021

behlendorf approved these changes Mar 24, 2021

View reviewed changes

ghost force-pushed the ratelimit-deadman branch from f2741f8 to 42e3c5f Compare March 24, 2021 21:45

ghost force-pushed the ratelimit-deadman branch from 42e3c5f to eeced36 Compare March 25, 2021 16:43

ghost force-pushed the ratelimit-deadman branch from eeced36 to 9007277 Compare March 25, 2021 21:51

behlendorf reviewed Mar 31, 2021

View reviewed changes

behlendorf self-requested a review April 1, 2021 15:51

ghost force-pushed the ratelimit-deadman branch from 9007277 to df58a01 Compare April 1, 2021 18:01

behlendorf reviewed Apr 1, 2021

View reviewed changes

ghost force-pushed the ratelimit-deadman branch from df58a01 to 1c9dab8 Compare April 5, 2021 19:16

don-brady approved these changes Apr 5, 2021

View reviewed changes

behlendorf reviewed Apr 6, 2021

View reviewed changes

Ryan Moeller added 3 commits April 6, 2021 17:43

Ratelimit deadman zevents as with delay zevents

4e75c82

Just as delay zevents can flood the zevent pipe when a vdev becomes unresponsive, so do the deadman zevents. Ratelimit deadman zevents according to the same tunable as for delay zevents. Signed-off-by: Ryan Moeller <ryan@iXsystems.com>

ZTS: Enable deadman tests on FreeBSD

8307414

Signed-off-by: Ryan Moeller <ryan@iXsystems.com>

ZTS: Add test for deadman event ratelimit

ddf3ec8

Signed-off-by: Ryan Moeller <ryan@iXsystems.com>

ghost force-pushed the ratelimit-deadman branch from 1c9dab8 to ddf3ec8 Compare April 6, 2021 21:53

behlendorf added Status: Accepted Ready to integrate (reviewed, tested) and removed Status: Code Review Needed Ready for review and testing labels Apr 7, 2021

behlendorf merged commit e778b04 into openzfs:master Apr 7, 2021

ghost deleted the ratelimit-deadman branch April 8, 2021 04:59

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Ratelimit deadman zevents as with delay zevents #11786

Ratelimit deadman zevents as with delay zevents #11786

ghost commented Mar 23, 2021

behlendorf commented Mar 24, 2021

ghost commented Mar 24, 2021

ghost commented Mar 25, 2021

ghost commented Mar 25, 2021

behlendorf commented Mar 26, 2021

behlendorf Mar 31, 2021

ghost Mar 31, 2021

ghost Apr 2, 2021

ghost commented Apr 1, 2021

behlendorf Apr 1, 2021

ghost Apr 2, 2021

behlendorf Apr 2, 2021

ghost commented Apr 5, 2021

behlendorf Apr 6, 2021

ghost commented Apr 6, 2021

ghost commented Apr 7, 2021

behlendorf commented Apr 7, 2021

Ratelimit deadman zevents as with delay zevents #11786

Ratelimit deadman zevents as with delay zevents #11786

Conversation

ghost commented Mar 23, 2021

Motivation and Context

Description

How Has This Been Tested?

Types of changes

Checklist:

behlendorf commented Mar 24, 2021

ghost commented Mar 24, 2021

ghost commented Mar 25, 2021

ghost commented Mar 25, 2021

behlendorf commented Mar 26, 2021

behlendorf Mar 31, 2021

Choose a reason for hiding this comment

ghost Mar 31, 2021

Choose a reason for hiding this comment

ghost Apr 2, 2021

Choose a reason for hiding this comment

ghost commented Apr 1, 2021

behlendorf Apr 1, 2021

Choose a reason for hiding this comment

ghost Apr 2, 2021

Choose a reason for hiding this comment

behlendorf Apr 2, 2021

Choose a reason for hiding this comment

ghost commented Apr 5, 2021

behlendorf Apr 6, 2021

Choose a reason for hiding this comment

ghost commented Apr 6, 2021

ghost commented Apr 7, 2021

behlendorf commented Apr 7, 2021