t/cindex.t "associate w/o search" test hangs for me

t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

Eric:

I'm trying to have tests pass on CentOS7 with the current master and I'm
apparently not able to get past the "associate w/o search" test.

When I run `prove -bvw t/cindex.t` I get to:

    ok 76 - xcpdb compact

and then it just sits there. If I look at the process table, I can see that
the next test is attempting to run, but it just hangs forever. This is what
pstree shows:

     └─prove,4431 -w /usr/local/bin/prove -bvw t/cindex.t
         └─-cindex -u --al,4432
             ├─cidx shard[0],4646
             └─cidx shard[1],4647

Anything I can do to figure out why this is happening?

-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
>          └─-cindex -u --al,4432
>              ├─cidx shard[0],4646
>              └─cidx shard[1],4647
> 
> Anything I can do to figure out why this is happening?

You can show me strace and lsof +E of the processes (any other
processes (join|sort|awk|perl)?).  This code is highly in flux,
so it's also fine to rm the test for now since nothing
public-facing is using -cindex, yet...

Re: t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

On Tue, Nov 14, 2023 at 10:16:53PM +0000, Eric Wong wrote:
> Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> >          └─-cindex -u --al,4432
> >              ├─cidx shard[0],4646
> >              └─cidx shard[1],4647
> > 
> > Anything I can do to figure out why this is happening?
> 
> You can show me strace and lsof +E of the processes (any other
> processes (join|sort|awk|perl)?).  This code is highly in flux,
> so it's also fine to rm the test for now since nothing
> public-facing is using -cindex, yet...

Yeah, but I figured I'll poke a bit in case it's helpful.

I can't do +E because that's not available to me under CentOS7 (I can't wait
until we move on, but just when we think the yak is fully shaved, we find more
clumps of thick fur we hadn't considered). Is the output of the regular "lsof
-p" helpful at all?

Strace for all three processes (-cindex, cidx shard[0], cidx shard[1]) just
sits at:

    select(24, [13 16], NULL, NULL, NULL

As far as I can see, there are no other processes other than cidx.

Hope that helps,
-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> On Tue, Nov 14, 2023 at 10:16:53PM +0000, Eric Wong wrote:
> > Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> > >          └─-cindex -u --al,4432
> > >              ├─cidx shard[0],4646
> > >              └─cidx shard[1],4647
> > > 
> > > Anything I can do to figure out why this is happening?
> > 
> > You can show me strace and lsof +E of the processes (any other
> > processes (join|sort|awk|perl)?).  This code is highly in flux,
> > so it's also fine to rm the test for now since nothing
> > public-facing is using -cindex, yet...
> 
> Yeah, but I figured I'll poke a bit in case it's helpful.
> 
> I can't do +E because that's not available to me under CentOS7 (I can't wait
> until we move on, but just when we think the yak is fully shaved, we find more
> clumps of thick fur we hadn't considered). Is the output of the regular "lsof
> -p" helpful at all?

Sure.

> Strace for all three processes (-cindex, cidx shard[0], cidx shard[1]) just
> sits at:
> 
>     select(24, [13 16], NULL, NULL, NULL

OK, that's still useful.  One FD is signalfd, the others would
be a SOCK_SEQPACKET socket, I think...

> As far as I can see, there are no other processes other than cidx.

OK.  Hmm.. Perhaps `kill -CHLD' on the top-level cindex process
can move it along?  There's still some weird timeout/sleep
behavior leftover from Danga::Socket that should probably be
removed:

-------8<------
Subject: [PATCH] ds: run @post_loop_do if any user-queued events run

---
 We can probably kill more hacky wakeup behavior throughout
 cindex and maybe other places with this patch...

 lib/PublicInbox/DS.pm | 8 +++++---
 1 file changed, 5 insertions(+), 3 deletions(-)

diff --git a/lib/PublicInbox/DS.pm b/lib/PublicInbox/DS.pm
index da26efc4..4c8b502f 100644
--- a/lib/PublicInbox/DS.pm
+++ b/lib/PublicInbox/DS.pm
@@ -144,13 +144,14 @@ sub next_tick () {
 		# https://rt.perl.org/Public/Bug/Display.html?id=114340
 		blessed($obj) ? $obj->event_step : $obj->();
 	}
+	1;
 }
 
 # runs timers and returns milliseconds for next one, or next event loop
 sub RunTimers {
-	next_tick();
+	my $ran = next_tick();
 
-	return ($nextq ? 0 : $loop_timeout) unless @Timers;
+	return ($nextq || $ran ? 0 : $loop_timeout) unless @Timers;
 
 	my $now = now();
 
@@ -159,10 +160,11 @@ sub RunTimers {
 		my $to_run = shift(@Timers);
 		delete $UniqTimer{$to_run->[1] // ''};
 		$to_run->[2]->(@$to_run[3..$#$to_run]);
+		$ran = 1;
 	}
 
 	# timers may enqueue into nextq:
-	return 0 if $nextq;
+	return 0 if $nextq || $ran;
 
 	return $loop_timeout unless @Timers;
 

Re: t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

On Tue, Nov 14, 2023 at 10:46:57PM +0000, Eric Wong wrote:
> > I can't do +E because that's not available to me under CentOS7 (I can't wait
> > until we move on, but just when we think the yak is fully shaved, we find more
> > clumps of thick fur we hadn't considered). Is the output of the regular "lsof
> > -p" helpful at all?
> 
> Sure.

Sent privately.

> > Strace for all three processes (-cindex, cidx shard[0], cidx shard[1]) just
> > sits at:
> > 
> >     select(24, [13 16], NULL, NULL, NULL
> 
> OK, that's still useful.  One FD is signalfd, the others would
> be a SOCK_SEQPACKET socket, I think...
> 
> > As far as I can see, there are no other processes other than cidx.
> 
> OK.  Hmm.. Perhaps `kill -CHLD' on the top-level cindex process
> can move it along? 

Didn't seem to do anything. The cidx shards were still there, and even running
"kill" on those processes directly didn't make them go away. Killing the
-cindex process itself does move things along without a failure.

-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> On Tue, Nov 14, 2023 at 10:46:57PM +0000, Eric Wong wrote:
> > > I can't do +E because that's not available to me under CentOS7 (I can't wait
> > > until we move on, but just when we think the yak is fully shaved, we find more
> > > clumps of thick fur we hadn't considered). Is the output of the regular "lsof
> > > -p" helpful at all?
> > 
> > Sure.
> 
> Sent privately.

My, that's a lot of pipes...

I should've told you to try this debug patch earlier, but this
might help...  (and our test suite should really be able to
watch messages like this while capturing)

diff --git a/t/cindex.t b/t/cindex.t
index 60711492..e582acbf 100644
--- a/t/cindex.t
+++ b/t/cindex.t
@@ -210,7 +210,7 @@ EOM
 	my $cmd = [ qw(-cindex -u --all --associate -d), "$tmp/ext",
 		'-I', $basic->{inboxdir} ];
 	$cidx_out = $cidx_err = '';
-	ok(run_script($cmd, $env, $opt), 'associate w/o search');
+	ok(run_script($cmd, $env, undef), 'associate w/o search');
 	like($cidx_err, qr/W: \Q$basic->{inboxdir}\E not indexed for search/,
 		'non-Xapian-enabled inbox noted');
 }

The like() test will fail with the above change, of course; but
maybe something else is amiss on your system and showing stderr
will help.  FWIW, I can't reproduce the problem on my CentOS7 VM.

Re: t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

On Tue, Nov 14, 2023 at 11:46:20PM +0000, Eric Wong wrote:
> My, that's a lot of pipes...
> 
> I should've told you to try this debug patch earlier, but this
> might help...  (and our test suite should really be able to
> watch messages like this while capturing)

Will try this shorty -- currently running a git bisect to find the last time
when tests passed on this system.

> The like() test will fail with the above change, of course; but
> maybe something else is amiss on your system and showing stderr
> will help.  FWIW, I can't reproduce the problem on my CentOS7 VM.

There are two sources of potential discrepancy:

- differences in CPAN module versions I have installed
- different git or xapian14 versions

If you want to try with the newest xapian14 release, you can enable the LFIT
copr on your test system:

yum copr enable icon/lfit

That should let you install xapian14-core and xapian14-bindings-perl, plus
git241. This will, at least, get you to the same version of those two things
that we have.

Thanks for your help!

-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

On Tue, Nov 14, 2023 at 06:51:00PM -0500, Konstantin Ryabitsev wrote:
> On Tue, Nov 14, 2023 at 11:46:20PM +0000, Eric Wong wrote:
> > My, that's a lot of pipes...
> > 
> > I should've told you to try this debug patch earlier, but this
> > might help...  (and our test suite should really be able to
> > watch messages like this while capturing)
> 
> Will try this shorty -- currently running a git bisect to find the last time
> when tests passed on this system.

Looks like the last time I am able to successfully run "make test" is before
this commit:

    b231d91f42d791becf7b6861e723833d71e73237 is the first bad commit

The error I start getting after this commit is:

t/extsearch.t ................ 160/?
#   Failed test 'lei_err=unindexed extindex /tmp/pi-extsearch-12765-FmsY/extindex not supported
#
# Argument "-TERM" isn't numeric in kill at /home/mricon/public-inbox-test/blib/lib/PublicInbox/IPC.pm line 442.
# Argument "-TERM" isn't numeric in kill at /home/mricon/public-inbox-test/blib/lib/PublicInbox/IPC.pm line 442.
# # converted 0 messages
# '
#   at /home/mricon/public-inbox-test/blib/lib/PublicInbox/TestCommon.pm line 579.
# Looks like you failed 1 test of 172.
t/extsearch.t ................ Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/172 subtests

It is repeated multiple times after.

HTH.

-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> Looks like the last time I am able to successfully run "make test" is before
> this commit:
> 
>     b231d91f42d791becf7b6861e723833d71e73237 is the first bad commit
> 
> The error I start getting after this commit is:
> 
> t/extsearch.t ................ 160/?
> #   Failed test 'lei_err=unindexed extindex /tmp/pi-extsearch-12765-FmsY/extindex not supported
> #
> # Argument "-TERM" isn't numeric in kill at /home/mricon/public-inbox-test/blib/lib/PublicInbox/IPC.pm line 442.

Thanks, that (and another bug) should be fixed with:
https://public-inbox.org/meta/20231115010457.1047199-1-e@80x24.org/

But it's unrelated to cindex, so something else is amiss...

Re: t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

On Wed, Nov 15, 2023 at 01:06:42AM +0000, Eric Wong wrote:
> Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> > Looks like the last time I am able to successfully run "make test" is before
> > this commit:
> > 
> >     b231d91f42d791becf7b6861e723833d71e73237 is the first bad commit
> > 
> > The error I start getting after this commit is:
> > 
> > t/extsearch.t ................ 160/?
> > #   Failed test 'lei_err=unindexed extindex /tmp/pi-extsearch-12765-FmsY/extindex not supported
> > #
> > # Argument "-TERM" isn't numeric in kill at /home/mricon/public-inbox-test/blib/lib/PublicInbox/IPC.pm line 442.
> 
> Thanks, that (and another bug) should be fixed with:
> https://public-inbox.org/meta/20231115010457.1047199-1-e@80x24.org/

Thanks, that is indeed much better! But I still get a few errors.

First a non-critical:

t/gcf2_client.t .............. 1/? Can't locate object method "fail" via package "PublicInbox::Gcf2Client" at /home/mricon/public-inbox-test/blib/lib/PublicInbox/Git.pm line 269.
        (in cleanup) Can't locate object method "fail" via package "PublicInbox::Gcf2Client" at /home/mricon/public-inbox-test/blib/lib/PublicInbox/Git.pm line 269.
# Tests were run but no plan was declared and done_testing() was not seen.
# Looks like your test exited with 65280 just after 2.
t/gcf2_client.t .............. Dubious, test returned 255 (wstat 65280, 0xff00)

Then just a bit later this one:

t/imapd.t .................... 2/? Bailout called.  Further testing stopped:  FETCH socket closed while reading data from server
FAILED--Further testing stopped: FETCH socket closed while reading data from server
make: *** [test_dynamic] Error 255

This one looks odd but I do see it happen every time I run the test.

-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> t/gcf2_client.t .............. 1/? Can't locate object method "fail" via package "PublicInbox::Gcf2Client" at /home/mricon/public-inbox-test/blib/lib/PublicInbox/Git.pm line 269.
>         (in cleanup) Can't locate object method "fail" via package "PublicInbox::Gcf2Client" at /home/mricon/public-inbox-test/blib/lib/PublicInbox/Git.pm line 269.
> # Tests were run but no plan was declared and done_testing() was not seen.
> # Looks like your test exited with 65280 just after 2.
> t/gcf2_client.t .............. Dubious, test returned 255 (wstat 65280, 0xff00)
> 
> Then just a bit later this one:
> 
> t/imapd.t .................... 2/? Bailout called.  Further testing stopped:  FETCH socket closed while reading data from server
> FAILED--Further testing stopped: FETCH socket closed while reading data from server
> make: *** [test_dynamic] Error 255
> 
> This one looks odd but I do see it happen every time I run the test.

Both are actually related to our libgit2 support.  Working on a
fix now since I didn't have libgit2 installed.

But I'm hesitant to do much with libgit2 since -extindex has
basically made it obsolete scalability-wise.  Fwiw, both major
commercial git hosts are ditching libgit2:

	https://public-inbox.org/git/ZRrfN2lbg14IOLiK@nand.local/

Re: t/cindex.t "associate w/o search" test hangs for me

[Konstantin Ryabitsev]

On Wed, Nov 15, 2023 at 03:09:28AM +0000, Eric Wong wrote:
> > t/imapd.t .................... 2/? Bailout called.  Further testing stopped:  FETCH socket closed while reading data from server
> > FAILED--Further testing stopped: FETCH socket closed while reading data from server
> > make: *** [test_dynamic] Error 255
> > 
> > This one looks odd but I do see it happen every time I run the test.
> 
> Both are actually related to our libgit2 support.  Working on a
> fix now since I didn't have libgit2 installed.
> 
> But I'm hesitant to do much with libgit2 since -extindex has
> basically made it obsolete scalability-wise.  Fwiw, both major
> commercial git hosts are ditching libgit2:
> 
> 	https://public-inbox.org/git/ZRrfN2lbg14IOLiK@nand.local/

I'm quite happy to not require libgit2 -- I've always found it easier to just
use git plumbing commands even if this requires exec'ing an external
executable.

-K

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> I'm quite happy to not require libgit2 -- I've always found it easier to just
> use git plumbing commands even if this requires exec'ing an external
> executable.

Yeah, I don't have libgit2 installed on most of my systems, either.

Hoping git itself eventually makes it easier to deal with
multiple repos...  -cindex has to run show-ref on every single
coderepo (so over 1k on my gko mirror) even for the incremental
no-op case and that gets expensive...

libgit2 [was: Re: t/cindex.t "associate w/o search" test hangs for me]

[Eric Wong]

Eric Wong <e@80x24.org> wrote:
> Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> > I'm quite happy to not require libgit2 -- I've always found it easier to just
> > use git plumbing commands even if this requires exec'ing an external
> > executable.

Sorry, I forget, individual inboxes via read-only interfaces
still benefit from it for now.  LeiALE needs to be be made for
public-facing uses, I think...

> Yeah, I don't have libgit2 installed on most of my systems, either.

yhbt.net/lore still does, actually :x

Re: t/cindex.t "associate w/o search" test hangs for me

[Eric Wong]

Konstantin Ryabitsev <konstantin@linuxfoundation.org> wrote:
> There are two sources of potential discrepancy:
> 
> - differences in CPAN module versions I have installed
> - different git or xapian14 versions

Could also be CPU count or CPU speeds since IPC bugs are
sensitive to that.  That said, I can't get cindex.t to fail
with 1, 2, or 4 cores enabled in the QEMU VM.  But I am on
some ancient Athlon CPU that CentOS warns about on bootup.

> That should let you install xapian14-core and xapian14-bindings-perl, plus
> git241. This will, at least, get you to the same version of those two things
> that we have.

Yup, only had xapian 1.4.22 before but 1.4.24 also succeeds for me.

Also, it works both with/without xapian14-core-devel libs
and after `rm -rf ~/.cache/public-inbox/inline-c/*c++*'
to force a rebuild.

It should switch between Xapian Perl bindings and C++ xap_helper
depending on whether the -devel libs (and g++) are available,
which is fine for tests.  The C++ version is basically required
for working with lore + git.kernel.org volumes, though...

[PATCH] cindex: fix test when missing time(1) executable

[Eric Wong]

Eric Wong <e@80x24.org> wrote:
> +++ b/t/cindex.t
> @@ -210,7 +210,7 @@ EOM
>  	my $cmd = [ qw(-cindex -u --all --associate -d), "$tmp/ext",
>  		'-I', $basic->{inboxdir} ];
>  	$cidx_out = $cidx_err = '';
> -	ok(run_script($cmd, $env, $opt), 'associate w/o search');
> +	ok(run_script($cmd, $env, undef), 'associate w/o search');
>  	like($cidx_err, qr/W: \Q$basic->{inboxdir}\E not indexed for search/,
>  		'non-Xapian-enabled inbox noted');
>  }

Yeah, using this on your new VM showed the problem right away:

------8<------
Subject: [PATCH] cindex: fix test when missing time(1) executable

It was only there for development purposes because associate is
slow, but it causes the test to get stuck on systems where it's
not available.  So remove it and just call join(1posix).

Note: this is not the `time' builtin found in shells, this
executable shows memory and pagefault info (and more with the
`-v' switch).  Unfortunately, it's not installed on many systems
despite being widely-packaged.

Reported-by: Konstantin Ryabitsev <konstantin@linuxfoundation.org>
---
 lib/PublicInbox/CodeSearchIdx.pm | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/PublicInbox/CodeSearchIdx.pm b/lib/PublicInbox/CodeSearchIdx.pm
index 9ceef16c..3a30b5e5 100644
--- a/lib/PublicInbox/CodeSearchIdx.pm
+++ b/lib/PublicInbox/CodeSearchIdx.pm
@@ -890,7 +890,7 @@ sub associate {
 	my @pending = keys %{$self->{PENDING}};
 	die "E: pending=@pending jobs not done\n" if @pending;
 	progress($self, 'associating...');
-	my @join = ('time', @JOIN, 'to_ibx_id', 'to_root_id');
+	my @join = (@JOIN, 'to_ibx_id', 'to_root_id');
 	my $rd = popen_rd(\@join, $CMD_ENV, { -C => "$TMPDIR" });
 	my %score;
 	while (<$rd>) { # PFX ibx_ids root_id


Much more gnarly work happening in this area :>

Re: [PATCH] cindex: fix test when missing time(1) executable

[Konstantin Ryabitsev]

On Wed, Nov 15, 2023 at 05:55:49AM +0000, Eric Wong wrote:
> Eric Wong <e@80x24.org> wrote:
> > +++ b/t/cindex.t
> > @@ -210,7 +210,7 @@ EOM
> >  	my $cmd = [ qw(-cindex -u --all --associate -d), "$tmp/ext",
> >  		'-I', $basic->{inboxdir} ];
> >  	$cidx_out = $cidx_err = '';
> > -	ok(run_script($cmd, $env, $opt), 'associate w/o search');
> > +	ok(run_script($cmd, $env, undef), 'associate w/o search');
> >  	like($cidx_err, qr/W: \Q$basic->{inboxdir}\E not indexed for search/,
> >  		'non-Xapian-enabled inbox noted');
> >  }
> 
> Yeah, using this on your new VM showed the problem right away:

Yes, I can confirm that this hang is now gone. \o/
All the tests succeed now with the latest master.

Thanks, as always!

-K