[pkg-gnupg-maint] Bug#841143: [PATCH 1/2] dotlock.c: add a lot of debug logging
Ian Jackson
ijackson at chiark.greenend.org.uk
Sun Jan 8 22:48:15 UTC 2017
This doesn't seem to be sensibly controllable other than at compile
time because the relevant logging control variables are not available.
I hope upstream will be able to improve that.
Signed-off-by: Ian Jackson <ijackson at chiark.greenend.org.uk>
---
common/dotlock.c | 58 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 58 insertions(+)
diff --git a/common/dotlock.c b/common/dotlock.c
index 7ebd523..037125a 100644
--- a/common/dotlock.c
+++ b/common/dotlock.c
@@ -471,6 +471,18 @@ map_w32_to_errno (DWORD w32_err)
}
#endif /*HAVE_DOSISH_SYSTEM*/
+#define DLOG(h, m, ...) do{ \
+ dotlock_t DLOG_h = (h); \
+ int DLOG_se = errno; \
+ if (/*DBG_IPC*/ 0) \
+ log_debug("dotlock %p %s " m, (DLOG_h), \
+ !(DLOG_h) ? "(none)" : \
+ !(DLOG_h)->lockname ? "(null)" : \
+ (DLOG_h)->lockname, \
+ ##__VA_ARGS__); \
+ errno = DLOG_se; \
+ }while(0)
+
/* Entirely disable all locking. This function should be called
before any locking is done. It may be called right at startup of
@@ -478,6 +490,7 @@ map_w32_to_errno (DWORD w32_err)
void
dotlock_disable (void)
{
+ DLOG(0, "dotlock_disable\n");
never_lock = 1;
}
@@ -489,6 +502,8 @@ maybe_deadlock (dotlock_t h)
dotlock_t r;
int res = 0;
+ DLOG(h, "maybe_deadlock\n");
+
LOCK_all_lockfiles ();
for (r=all_lockfiles; r; r = r->next)
{
@@ -519,6 +534,8 @@ read_lockfile (dotlock_t h, int *same_node )
size_t expected_len;
int res, nread;
+ DLOG(h, "read_lockfile()\n");
+
*same_node = 0;
expected_len = 10 + 1 + h->nodename_len + 1;
if ( expected_len >= sizeof buffer_space)
@@ -591,6 +608,7 @@ read_lockfile (dotlock_t h, int *same_node )
if (buffer != buffer_space)
xfree (buffer);
+ DLOG(h, "read_lockfile(%d) = %ld\n", *same_node, (long)pid);
return pid;
}
#endif /*HAVE_POSIX_SYSTEM */
@@ -610,6 +628,8 @@ use_hardlinks_p (const char *tname)
unsigned int nlink;
int res;
+ DLOG(0, "use_hardlinks_p(%s)\n", tname);
+
if (stat (tname, &sb))
return -1;
nlink = (unsigned int)sb.st_nlink;
@@ -632,6 +652,8 @@ use_hardlinks_p (const char *tname)
unlink (lname);
xfree (lname);
+
+ DLOG(0, "use_hardlinks_p(%s) = %d\n", tname, res);
return res;
}
#endif /*HAVE_POSIX_SYSTEM */
@@ -652,6 +674,8 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
struct utsname utsbuf;
size_t tnamelen;
+ DLOG(h, "dotlock_create_unix(%s)...\n", file_to_lock);
+
snprintf (pidstr, sizeof pidstr, "%10d\n", (int)getpid() );
/* Create a temporary file. */
@@ -682,6 +706,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
all_lockfiles = h->next;
UNLOCK_all_lockfiles ();
xfree (h);
+ DLOG(h, "dotlock_create_unix()=0 (!xtrymalloc)\n");
return NULL;
}
h->nodename_len = strlen (nodename);
@@ -691,6 +716,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
snprintf (h->tname+h->nodename_off, tnamelen - h->nodename_off,
"%s.%d", nodename, (int)getpid ());
+ DLOG(h, "dotlock_create_unix() open...\n");
do
{
my_set_errno (0);
@@ -698,6 +724,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
S_IRUSR|S_IRGRP|S_IROTH|S_IWUSR );
}
while (fd == -1 && errno == EINTR);
+ DLOG(h, "dotlock_create_unix() open=%d...\n", fd);
if ( fd == -1 )
{
@@ -709,6 +736,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
xfree (h->tname);
xfree (h);
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_create_unix()=0 (fd=-1) E=%d\n",errno);
return NULL;
}
if ( write (fd, pidstr, 11 ) != 11 )
@@ -754,6 +782,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
xfree (h->tname);
xfree (h);
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_create_unix()=0 (!lockname) E=%d\n",errno);
return NULL;
}
strcpy (stpcpy (h->lockname, file_to_lock), EXTSEP_S "lock");
@@ -761,6 +790,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
if (h->use_o_excl)
my_debug_1 ("locking for '%s' done via O_EXCL\n", h->lockname);
+ DLOG(h, "dotlock_create_unix()=%p\n", h);
return h;
write_failed:
@@ -776,6 +806,7 @@ dotlock_create_unix (dotlock_t h, const char *file_to_lock)
xfree (h);
my_set_errno (saveerrno);
}
+ DLOG(h, "dotlock_create_unix()=0 (write_failed) E=%d\n",errno);
return NULL;
}
#endif /*HAVE_POSIX_SYSTEM*/
@@ -936,6 +967,10 @@ dotlock_get_fd (dotlock_t h)
static void
dotlock_destroy_unix (dotlock_t h)
{
+ DLOG(h, "dotlock_destroy_unix() locked=%d lockname=%s tname=%s\n",
+ h->locked,
+ h->lockname ? h->lockname : "(null)",
+ h->tname ? h->tname : "(null)");
if (h->locked && h->lockname)
unlink (h->lockname);
if (h->tname && !h->use_o_excl)
@@ -968,6 +1003,7 @@ dotlock_destroy (dotlock_t h)
{
dotlock_t hprev, htmp;
+ DLOG(h, "dotlock_destroy()\n");
if ( !h )
return;
@@ -1015,12 +1051,15 @@ dotlock_take_unix (dotlock_t h, long timeout)
int same_node;
int saveerrno;
+ DLOG(h, "dotlock_create_unix(timeout=%ld) ...\n", timeout);
+
again:
if (h->use_o_excl)
{
/* No hardlink support - use open(O_EXCL). */
int fd;
+ DLOG(h, "dotlock_take_unix() open...\n");
do
{
my_set_errno (0);
@@ -1028,6 +1067,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
S_IRUSR|S_IRGRP|S_IROTH|S_IWUSR );
}
while (fd == -1 && errno == EINTR);
+ DLOG(h, "dotlock_take_unix() open=%d E=%d...\n",fd,errno);
if (fd == -1 && errno == EEXIST)
; /* Lock held by another process. */
@@ -1037,6 +1077,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
my_error_2 ("lock not made: open(O_EXCL) of '%s' failed: %s\n",
h->lockname, strerror (saveerrno));
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_take_unix()=-1 (fd=-1) E=%d\n",errno);
return -1;
}
else
@@ -1051,6 +1092,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
&& !close (fd))
{
h->locked = 1;
+ DLOG(h, "dotlock_take_unix()=0 (write)\n");
return 0;
}
/* Write error. */
@@ -1060,6 +1102,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
close (fd);
unlink (h->lockname);
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_take_unix()=-1 (write) E=%d\n",errno);
return -1;
}
}
@@ -1079,12 +1122,14 @@ dotlock_take_unix (dotlock_t h, long timeout)
that link succeeded but stat failed due to changed
permissions. We can't do anything about it, though. */
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_take_unix()=-1 (stat) E=%d\n",errno);
return -1;
}
if (sb.st_nlink == 2)
{
h->locked = 1;
+ DLOG(h, "dotlock_take_unix()=0 (nlink)\n");
return 0; /* Okay. */
}
}
@@ -1097,6 +1142,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
saveerrno = errno;
my_info_0 ("cannot read lockfile\n");
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_take_unix()=-1 (read) E=%d\n",errno);
return -1;
}
my_info_0 ("lockfile disappeared\n");
@@ -1106,6 +1152,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
{
my_info_0 ("Oops: lock already held by us\n");
h->locked = 1;
+ DLOG(h, "dotlock_take_unix()=0 (oops)\n");
return 0; /* okay */
}
else if ( same_node && kill (pid, 0) && errno == ESRCH )
@@ -1115,6 +1162,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
of the stale file tries to lock right at the same time as we. */
my_info_1 (_("removing stale lockfile (created by %d)\n"), pid);
unlink (h->lockname);
+ DLOG(h, "dotlock_take_unix() again...\n");
goto again;
}
@@ -1161,6 +1209,7 @@ dotlock_take_unix (dotlock_t h, long timeout)
}
my_set_errno (EACCES);
+ DLOG(h, "dotlock_take_unix()=-1 (EACCES) E=%d\n",errno);
return -1;
}
#endif /*HAVE_POSIX_SYSTEM*/
@@ -1264,18 +1313,22 @@ dotlock_release_unix (dotlock_t h)
int pid, same_node;
int saveerrno;
+ DLOG(h, "dotlock_release_unix...\n");
+
pid = read_lockfile (h, &same_node);
if ( pid == -1 )
{
saveerrno = errno;
my_error_0 ("release_dotlock: lockfile error\n");
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_release_unix()=-1 (read) E=%d\n",errno);
return -1;
}
if ( pid != getpid() || !same_node )
{
my_error_1 ("release_dotlock: not our lock (pid=%d)\n", pid);
my_set_errno (EACCES);
+ DLOG(h, "dotlock_release_unix()=-1 (not ours) E=%d\n",errno);
return -1;
}
@@ -1285,10 +1338,12 @@ dotlock_release_unix (dotlock_t h)
my_error_1 ("release_dotlock: error removing lockfile '%s'\n",
h->lockname);
my_set_errno (saveerrno);
+ DLOG(h, "dotlock_release_unix()=-1 (unlink) E=%d\n",errno);
return -1;
}
/* Fixme: As an extra check we could check whether the link count is
now really at 1. */
+ DLOG(h, "dotlock_release_unix()=0\n");
return 0;
}
#endif /*HAVE_POSIX_SYSTEM */
@@ -1321,6 +1376,7 @@ int
dotlock_release (dotlock_t h)
{
int ret;
+ DLOG(h, "dotlock_release\n");
/* To avoid atexit race conditions we first check whether there are
any locks left. It might happen that another atexit handler
@@ -1361,10 +1417,12 @@ void
dotlock_remove_lockfiles (void)
{
dotlock_t h, h2;
+ DLOG(0, "dotlock_remove_lockfiles\n");
/* First set the lockfiles list to NULL so that for example
dotlock_release is aware that this function is currently
running. */
+
LOCK_all_lockfiles ();
h = all_lockfiles;
all_lockfiles = NULL;
--
2.11.0
More information about the pkg-gnupg-maint
mailing list