Diff options
authorBryce Kwon <bryce@brycekwon.com>
committerBryce Kwon <bryce@brycekwon.com>
commit
parent
tree
download
Keep lock contention out of the error log
process_slot logged every failure to lock, so each request that found its slot being filled left a line, while refresh_slot logged none, so an expired slot in a directory the server cannot write was served stale for good without a word. lock_slot now logs the step that failed, as the scan does, and leaves out only another request at work.
Diffstat (limited to '')
-rw-r--r--source/cache.c36
-rwxr-xr-xtests/t0003-cache.sh22
2 files changed, 45 insertions, 13 deletions
diff --git a/source/cache.c b/source/cache.c
index 12151b8..64b7148 100644
--- a/source/cache.c
+++ b/source/cache.c
@@ -196,26 +196,37 @@ static int is_modified(struct cache_slot *slot)
* The lock file becomes the slot once it is renamed, so it has to open with
* the key the same way a slot does. The lock is taken without blocking,
* because failing to get it is how a second process learns that this slot is
- * already being rebuilt, so it returns an errno instead of waiting.
+ * already being rebuilt, so it returns an errno instead of waiting. Every
+ * other failure is logged here, for both callers.
*/
static int lock_slot(struct cache_slot *slot)
{
struct stat held, named;
+ int err;
// Close-on-exec, so that a program the fill runs gets the file only
// as its stdout, and holds the lock no longer than it can write there.
slot->lock_fd = open(slot->lock_path, O_RDWR | O_CREAT | O_CLOEXEC, S_IRUSR | S_IWUSR);
- if (slot->lock_fd == -1)
- return errno;
+ if (slot->lock_fd == -1) {
+ err = errno;
+ fprintf(stderr, "[cgit] Unable to open %s: %s (%d)\n", slot->lock_path, strerror(err), err);
+ return err;
+ }
// An flock rather than a POSIX record lock. The descriptor is put on
// stdout for the fill, and a record lock is dropped as soon as any
// descriptor on the file closes, which an exec filter does to stdout,
// while an flock holds until the last descriptor closes.
if (flock(slot->lock_fd, LOCK_EX | LOCK_NB) < 0) {
- int saved_errno = errno;
+ // A lock held elsewhere only means concurrent requests, which
+ // is not worth a line in the server log. Any other failure, a
+ // filesystem without lock support say, silently keeps the slot
+ // from ever being filled or refreshed and does deserve one.
+ err = errno;
+ if (err != EWOULDBLOCK)
+ fprintf(stderr, "[cgit] Unable to lock %s: %s (%d)\n", slot->lock_path, strerror(err), err);
close(slot->lock_fd);
slot->lock_fd = -1;
- return saved_errno;
+ return err;
}
// The lock landed on whatever inode the path named at open. A holder
// finishing in between renames that inode into place as the live
@@ -233,10 +244,14 @@ static int lock_slot(struct cache_slot *slot)
}
// A run that died before its rename leaves the lock file behind, so
// start from empty now that nobody else can be writing it.
- if (ftruncate(slot->lock_fd, 0) < 0)
- return errno;
- if (write_in_full(slot->lock_fd, slot->key, slot->keylen + 1) < 0)
- return errno;
+ if (
+ ftruncate(slot->lock_fd, 0) < 0 ||
+ write_in_full(slot->lock_fd, slot->key, slot->keylen + 1) < 0
+ ) {
+ err = errno;
+ fprintf(stderr, "[cgit] Unable to write %s: %s (%d)\n", slot->lock_path, strerror(err), err);
+ return err;
+ }
return 0;
}
@@ -425,8 +440,7 @@ static int process_slot(struct cache_slot *slot)
// straight to the client and the caller is told the request succeeded,
// because it did.
close_fd(&slot->cache_fd);
- if ((err = lock_slot(slot)) != 0) {
- fprintf(stderr, "[cgit] Unable to lock slot %s: %s (%d)\n", slot->lock_path, strerror(err), err);
+ if (lock_slot(slot)) {
slot->fn();
return 0;
}
diff --git a/tests/t0003-cache.sh b/tests/t0003-cache.sh
index 8b3f2f9..39f11a9 100755
--- a/tests/t0003-cache.sh
+++ b/tests/t0003-cache.sh
@@ -247,7 +247,8 @@ overlap_requests() {
# The fill writes the page into the lock file through stdout, and an exec
# filter puts its own pipe on stdout while it runs. The slot lock has to
# outlast that, or a second request on the slot rebuilds it under the first
-# and the first visitor gets the two pages spliced together.
+# and the first visitor gets the two pages spliced together. The second one
+# finding the lock held is ordinary contention, which logs nothing.
test_expect_success 'a slot stays locked while an exec filter runs' '
rm -rf cache3 && mkdir cache3 &&
write_script slow-filter.sh <<-EOF &&
@@ -264,7 +265,8 @@ test_expect_success 'a slot stays locked while an exec filter runs' '
overlap_requests &&
test $(grep -c "^Status:" first.out) = 1 &&
grep "id=.about." first.out &&
- ! grep "Unable to publish" first.err
+ ! grep "Unable to publish" first.err &&
+ ! grep "Unable to lock" second.err
'
# An flock lasts until the last copy of its descriptor closes, so a filter
@@ -294,6 +296,22 @@ test_expect_success PERL 'a filter holds the lock file only as its stdout' '
grep -F "lock file on fd 1." fd.out
'
+# A refresh that cannot take the lock serves the expired copy, and says why
+# unless the reason is another request doing the refresh. A line appended
+# to the copy shows that it is what was served.
+test_expect_success SANITY 'a refresh that cannot lock serves the expired slot and says why' '
+ rm -rf cache3 && mkdir cache3 &&
+ CGIT_CONFIG="$PWD/bigkeyrc" QUERY_STRING="url=bigpage/" cgit >/dev/null &&
+ slot=$(ls cache3) &&
+ echo "the expired copy" >>"cache3/$slot" &&
+ touch -t 200001010000 "cache3/$slot" &&
+ test_when_finished "chmod u+w cache3" &&
+ chmod a-w cache3 &&
+ CGIT_CONFIG="$PWD/bigkeyrc" QUERY_STRING="url=bigpage/" cgit >stale.out 2>stale.err &&
+ grep "the expired copy" stale.out &&
+ grep "Unable to open .*\.lock: Permission denied" stale.err
+'
+
# A scan is cached in a file named after the hash of its path, so a first
# scan finds out what that name is. The index page is left uncached, which
# makes each request read the list afresh.