[pkg-gnupg-maint] Bug#868550: Bug#868550: reprepro seems to provide a repro

[Ian Jackson]

Hi.  Thanks for your help with debugging this.

NIIBE Yutaka writes ("Re: [pkg-gnupg-maint] Bug#868550: reprepro seems to provide a repro"):
> Ian Jackson <ijackson at chiark.greenend.org.uk> wrote:
> > This might be relevant.  My test suite failures occur on a loaded
> > machine, because the test case runner parallelises separate tests.
> >
> > Does this produce a particular message, when it occurs ?
> 
> Yes.
...                }
> +              if (i >= SECS_TO_WAIT_FOR_AGENT)
> +                log_error ("agent invoked successfully, but...\n");

I tried this.  I applied this change and I can confirm that I have
seen this message in all the failing tests I looked at.

However, I also tried with the patch below, to increase the timeout.

With that patch, I can still reproduce the failure.  The passing tests
succeed and exit, leaving a failing test (so far, only one out of a
test run) sitting about.  The machine load is low.  There is no
gpg-agent running.  So the problem I am seeing is not simply that the
agent process is starved (although I don't doubt that the race you
describe exists).

The message, with this patch and yours, is still the same.  Here is an
example:

+ fakeroot apt-key add
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
Warning: apt-key output should not be parsed (stdout is not a terminal)
W: Unable to read /home/ian/things/Dgit/dgit/tests/tmp/downstream-gitless/ds-etc-apt/apt.conf.d/ - DirectoryExists (2: No such file or directory)
gpg: agent invoked successfully, but...
gpg: can't connect to the agent: IPC connect call failed
+ test 2 = 0

Each individual test runs with its own GNUPGHOME and is largely
singlethreaded so I think there are probably not multpile competing
agents starting up.  Is it possible that the agent started up and then
exited for some reason ?

I have a log generated by this
  log-file /home/ian/things/Dgit/dgit/tests/tmp/gnupg/gnupg/AGENT.log
in gpg-agent.conf but due to an infelicitly in my arrangments all of
the logs for concurrent tests share a logfile.  The log seems to
contain many fewer messages than expected leading me to suspect it is
not opened with O_APPEND.  I may see about sorting out a separate
logfile from each run which should tell me whether gpg-agent started
or not.

I hope some of this is of some use...

Thanks,
Ian.

commit 335bc79cc1ebeba1eb529c8e6b574d8ca1d9d947
Author: Ian Jackson <ijackson at chiark.greenend.org.uk>
Date:   Tue Aug 22 19:17:05 2017 +0100

    increase timeouts

diff --git a/common/asshelp.c b/common/asshelp.c
index 2cab310..4a9fb45 100644
--- a/common/asshelp.c
+++ b/common/asshelp.c
@@ -58,8 +58,8 @@
 # define SECS_TO_WAIT_FOR_AGENT 30
 # define SECS_TO_WAIT_FOR_DIRMNGR 30
 #else
-# define SECS_TO_WAIT_FOR_AGENT 5
-# define SECS_TO_WAIT_FOR_DIRMNGR 5
+# define SECS_TO_WAIT_FOR_AGENT 500
+# define SECS_TO_WAIT_FOR_DIRMNGR 500
 #endif
 
 /* A bitfield that specifies the assuan categories to log.  This is