test: 'seen set from rename' potentially racy

test: 'seen set from rename' potentially racy

[Konstantin Ryabitsev]

Hello:

I was having some trouble using "make check" on the Fedora build system:

#   Failed test 'seen set from rename'
#   at t/lei-watch.t line 61.
#                   '/tmp/pi-lei-watch-11080-FYz2/lei-daemon/md2/cur/9bf1002c49eb075df47247b74d69bcd555e23422=99:2,'
#     doesn't match '(?^:S\z)'
# [
#   '/tmp/pi-lei-watch-11080-FYz2/lei-daemon/md2/cur/9bf1002c49eb075df47247b74d69bcd555e23422=99:2,'
# ]

This wasn't happening in my own chroot builds, so I'm suspecting that the
faster system on the Fedora build infra side is causing this failure,
therefore perhaps some kind of race condition. 

You can see the entire log here:

https://download.copr.fedorainfracloud.org/results/icon/b4/fedora-35-x86_64/02928611-public-inbox/build.log.gz

Switching to "make test" seems to help, which is what I've done for now.

Cheers,
-K

Re: test: 'seen set from rename' potentially racy

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> Hello:
> 
> I was having some trouble using "make check" on the Fedora build system:
> 
> #   Failed test 'seen set from rename'
> #   at t/lei-watch.t line 61.
> #                   '/tmp/pi-lei-watch-11080-FYz2/lei-daemon/md2/cur/9bf1002c49eb075df47247b74d69bcd555e23422=99:2,'
> #     doesn't match '(?^:S\z)'
> # [
> #   '/tmp/pi-lei-watch-11080-FYz2/lei-daemon/md2/cur/9bf1002c49eb075df47247b74d69bcd555e23422=99:2,'
> # ]
> 
> This wasn't happening in my own chroot builds, so I'm suspecting that the
> faster system on the Fedora build infra side is causing this failure,
> therefore perhaps some kind of race condition. 

Hmm, I thought I fixed it...  Does increasing the tick sleep time help?

diff --git a/t/lei-watch.t b/t/lei-watch.t
index 9158571c..8126b707 100644
--- a/t/lei-watch.t
+++ b/t/lei-watch.t
@@ -49,13 +49,13 @@ test_lei(sub {
 	lei_ok 'ls-watch';
 	like($lei_out, qr/^\Qmaildir:$md\E$/sm, 'maildir shown');
 	lei_ok qw(q mid:testmessage@example.com -o), $md, '-I', "$ro_home/t1";
 	my @f = glob("$md/cur/*:2,");
 	is(scalar(@f), 1, 'got populated maildir with one result');
 	rename($f[0], "$f[0]S") or xbail "rename $!"; # set (S)een
-	tick($have_fast_inotify ? 0.1 : 2.1); # always needed for 1 CPU systems
+	tick($have_fast_inotify ? 1 : 5); # always needed for 1 CPU systems
 	lei_ok qw(note-event done); # flushes immediately (instead of 5s)
 
 	lei_ok qw(q mid:testmessage@example.com -o), $md2, '-I', "$ro_home/t1";
 	my @f2 = glob("$md2/*/*");
 	is(scalar(@f2), 1, 'got one result');
 	like($f2[0], qr/S\z/, 'seen set from rename') or diag explain(\@f2);

Maybe 1s is too much and 0.2s is enough.

> https://download.copr.fedorainfracloud.org/results/icon/b4/fedora-35-x86_64/02928611-public-inbox/build.log.gz

"prove --state=save -bvw -j3", so 2 cores?  Any idea what
CONFIG_HZ is on that system?

> Switching to "make test" seems to help, which is what I've done for now.

OK, so it could be load related.  There could probably be a way
to "subscribe" for updates to lei-daemon so sleeping wouldn't be
necessary.  I'll see abouit it next week, got some other stuff
to take care of...

Re: test: 'seen set from rename' potentially racy

[Eric Wong]

Eric Wong <e@80x24.org> wrote:
> Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> > Hello:
> > 
> > I was having some trouble using "make check" on the Fedora build system:
> > 
> > #   Failed test 'seen set from rename'
> > #   at t/lei-watch.t line 61.
> > #                   '/tmp/pi-lei-watch-11080-FYz2/lei-daemon/md2/cur/9bf1002c49eb075df47247b74d69bcd555e23422=99:2,'
> > #     doesn't match '(?^:S\z)'
> > # [
> > #   '/tmp/pi-lei-watch-11080-FYz2/lei-daemon/md2/cur/9bf1002c49eb075df47247b74d69bcd555e23422=99:2,'
> > # ]
> > 
> > This wasn't happening in my own chroot builds, so I'm suspecting that the
> > faster system on the Fedora build infra side is causing this failure,
> > therefore perhaps some kind of race condition. 
> 
> Hmm, I thought I fixed it...  Does increasing the tick sleep time help?

Nope, 5fb5b6d1a62b74b3 (t/lei-watch: test with with higher sleep, 2021-11-10)
didn't help...

> 
> > https://download.copr.fedorainfracloud.org/results/icon/b4/fedora-35-x86_64/02928611-public-inbox/build.log.gz
> 
> "prove --state=save -bvw -j3", so 2 cores?  Any idea what
> CONFIG_HZ is on that system?
> 
> > Switching to "make test" seems to help, which is what I've done for now.
> 
> OK, so it could be load related.  There could probably be a way
> to "subscribe" for updates to lei-daemon so sleeping wouldn't be
> necessary.  I'll see abouit it next week, got some other stuff
> to take care of...

That's on the table in case I get my mind back or somebody else
helps.  I haven't been able to work on anything requiring
original thought in months (not that it's ever been great), so I
think disabling flaky tests for now is the least bad option:

---------------8<-----------
Subject: [PATCH] t/lei-*watch: disable flaky tests by default for now

Properly fixing these tests is too difficult for me at the
moment, so just disable these tests for now.  A proper fix and
fleshing out support for inotify will hopefully happen at some
point.
---
 t/lei-auto-watch.t | 1 +
 t/lei-watch.t      | 1 +
 2 files changed, 2 insertions(+)

diff --git a/t/lei-auto-watch.t b/t/lei-auto-watch.t
index d5661ae5..f871188d 100644
--- a/t/lei-auto-watch.t
+++ b/t/lei-auto-watch.t
@@ -3,6 +3,7 @@
 # License: AGPL-3.0+ <https://www.gnu.org/licenses/agpl-3.0.txt>
 use strict; use v5.10.1; use PublicInbox::TestCommon;
 use File::Basename qw(basename);
+plan skip_all => "TEST_FLAKY not enabled for $0" if !$ENV{TEST_FLAKY};
 my $have_fast_inotify = eval { require Linux::Inotify2 } ||
 	eval { require IO::KQueue };
 $have_fast_inotify or
diff --git a/t/lei-watch.t b/t/lei-watch.t
index e6066033..24d9f5c8 100644
--- a/t/lei-watch.t
+++ b/t/lei-watch.t
@@ -3,6 +3,7 @@
 # License: AGPL-3.0+ <https://www.gnu.org/licenses/agpl-3.0.txt>
 use strict; use v5.10.1; use PublicInbox::TestCommon;
 use File::Path qw(make_path remove_tree);
+plan skip_all => "TEST_FLAKY not enabled for $0" if !$ENV{TEST_FLAKY};
 require_mods('lei');
 my $have_fast_inotify = eval { require Linux::Inotify2 } ||
 	eval { require IO::KQueue };