POSIX semaphore fd collision on macOS

Michael Weiser <[email protected]> Mon, 19 Feb 2018 00:38:04 +0100
Newsgroups gmane.comp.archivers.amanda.devel
Message-ID <[email protected]>
Hi,

I've been seeing dump failures with amanda >= 3.3.9 on macOS where gzip
complains of a broken pipe and shm_ring_sem_wait of a bad file
descriptor. Turns out, POSIX semaphores are fds or at least sufficiently
fd-like on macOS so that there can be a collision between
shm_ring->sem_write and client_pipe[1] in sendbackup-gnutar.c. The patch
below fixes the problem for me.

This is the relevant part of sendbackup's debug log:

Sun Feb 18 22:03:02.952132000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: gnutar: /Users/michael/amanda/libexec/amanda/runtar: pid 49467
Sun Feb 18 22:03:02.952338000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: shm_ring_link /amanda_shm_control-49462-0
Sun Feb 18 22:03:02.952575000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: am_sem_open 0x7 1
Sun Feb 18 22:03:02.952641000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: am_sem_open 0x8 1
Sun Feb 18 22:03:02.952703000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: am_sem_open 0xb 1
Sun Feb 18 22:03:02.952765000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: am_sem_open 0xc 1
Sun Feb 18 22:03:02.952810000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: shm_ring_producer_set_size
Sun Feb 18 22:03:02.953219000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: Started backup
Sun Feb 18 22:03:02.953438000 2018: pid 49463: thd-0x7fbf6a82fc50: sendbackup: fd_to_shm_ring
Sun Feb 18 22:03:02.973320000 2018: pid 49466: thd-0x7fbf6a42fc00: sendbackup: Started index creator: "/Users/michael/amanda/bin/tar -tf - 2>/dev/null | sed -e 's/^\.//'"
Sun Feb 18 22:03:03.432984000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup:  48:    size(|): Total bytes written: 10240 (10KiB, 874KiB/s)
Sun Feb 18 22:03:03.492060000 2018: pid 49466: thd-0x7fbf6a42fc00: sendbackup: Index created successfully
Sun Feb 18 22:03:03.507099000 2018: pid 49463: thd-0x7fbf6a82fc50: sendbackup: shm_ring_sem_wait: failed_sem_wait: Bad file descriptor
Sun Feb 18 22:03:04.519015000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: close_producer_shm_ring sem_close(sem_write 0x7
Sun Feb 18 22:03:04.519235000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: am_sem_close 0x7 0
Sun Feb 18 22:03:04.519574000 2018: pid 49463: thd-0x7fbf6a42fc00: sendbackup: sem_close(0x7) failed: Bad file descriptor

This is what dtruss has to say about it:

49449/0x1476b:  sem_open(0x1028C70B8, 0x0, 0x101)                = 7 0
note: sem_open returns no 7 which suspiciously looks like an fd ---^
49449/0x1476b:  write_nocancel(0xA, "Sun Feb 18 22:03:00.117935000 2018: pid 49449: thd-0x7fdb6f506e00: sendbackup: am_sem_open 0x7 1\n\0", 0
x61)                = 97 0
49449/0x1476b:  sem_open(0x1028C70EA, 0x0, 0x201)                = 8 0
49449/0x1476b:  write_nocancel(0xA, "Sun Feb 18 22:03:00.118053000 2018: pid 49449: thd-0x7fdb6f506e00: sendbackup: am_sem_open 0x8 1\n\0", 0
x61)                = 97 0
49449/0x1476b:  sem_open(0x1028C711C, 0x0, 0x301)                = 11 0
49449/0x1476b:  write_nocancel(0xA, "Sun Feb 18 22:03:00.118138000 2018: pid 49449: thd-0x7fdb6f506e00: sendbackup: am_sem_open 0xb 1\n\0", 0
x61)                = 97 0
49449/0x1476b:  sem_open(0x1028C714E, 0x0, 0x401)                = 12 0
49449/0x1476b:  write_nocancel(0xA, "Sun Feb 18 22:03:00.118213000 2018: pid 49449: thd-0x7fdb6f506e00: sendbackup: am_sem_open 0xc 1\n\0", 0
x61)                = 97 0
49449/0x1476b:  write_nocancel(0xA, "Sun Feb 18 22:03:00.118268000 2018: pid 49449: thd-0x7fdb6f506e00: sendbackup: shm_ring_producer_set_siz
e\n\0", 0x6A)               = 106 0
49449/0x1476b:  sem_wait(0x7, 0x0, 0x0)          = 0 0
here it still works ------^
49449/0x1476b:  ftruncate(0x5, 0x80000, 0x0)             = 0 0
49449/0x1476b:  mmap(0x0, 0x80000, 0x3, 0x1, 0x5, 0x0)           = 0x102E84000 0
49449/0x1476b:  sem_post(0x8, 0x0, 0x0)          = 0 0
49449/0x1476b:  bsdthread_create(0x102CCBB90, 0x7FDB6F80D000, 0x80000)           = 79929344 0
49449/0x1476b:  close(0x7)               = 0 0
and here it's closed---^
49449/0x1476b:  bsdthread_create(0x102CCBB90, 0x7FDB6F80D050, 0x80000)           = 80465920 0
49449/0x1476b:  write_nocancel(0xA, "Sun Feb 18 22:03:00.118778000 2018: pid 49449: thd-0x7fdb6f506e00: sendbackup: Started backup\n\0", 0x5E)           = 94 0
[...]
49449/0x14775:  readv(0x6, 0x700004CBCE70, 0x1)          = 0 0
49449/0x14775:  sem_post(0x8, 0x0, 0x0)          = 0 0
49449/0x14775:  sem_post(0x8, 0x0, 0x0)          = 0 0
49449/0x14775:  sem_wait(0x7, 0x0, 0x0)          = -1 Err#9
there's the EBADF error later on --->
49449/0x14775:  write_nocancel(0xA, "Sun Feb 18 22:03:00.807654000 2018: pid 49449: thd-0x7fdb6f80d050: sendbackup: shm_ring_sem_wait: failed_sem_wait: Bad file descriptor\n\0", 0x87)          = 135 0
49449/0x14775:  sem_post(0x8, 0x0, 0x0)          = 0 0
49449/0x14775:  sem_post(0x7, 0x0, 0x0)          = -1 Err#9
49449/0x14775:  sem_post(0xB, 0x0, 0x0)          = 0 0
49449/0x14775:  sem_post(0xC, 0x0, 0x0)          = 0 0

This is the offending code in sendbackup-gnutar.c:

    if (shm_control_name) {
        // opens sem_write as fd 7 on Mac
        shm_ring = shm_ring_link(shm_control_name);
        shm_ring_producer_set_size(shm_ring, NETWORK_BLOCK_BYTES*16, NETWORK_BLOCK_BYTES*4);
        native_crc.in  = native_pipe[0];
        if (!have_filter) {
            native_crc.out = dumpout;
            native_crc.shm_ring = shm_ring;
            native_crc.thread = g_thread_create(handle_crc_to_shm_ring_thread,
                                        (gpointer)&native_crc, TRUE, NULL);
        } else {
            native_crc.out = dumpout;
            native_crc.thread = g_thread_create(handle_crc_thread,
                                        (gpointer)&native_crc, TRUE, NULL);
	    // closes fd 7
            close(client_pipe[1]);
            client_crc.in  = client_pipe[0];
            client_crc.out = dataf;
            client_crc.shm_ring = shm_ring;
            client_crc.thread = g_thread_create(handle_crc_to_shm_ring_thread,
                                        (gpointer)&client_crc, TRUE, NULL);
        }

The changes to sendbackup-dump and sendbackup proper are untested but
seem reasonably similar to what I needed to fix in sendbackup-gnutar to
make my problem go away.

From 11519217d637d6dfbf945924775f53a7df717e1d Mon Sep 17 00:00:00 2001
From: Michael Weiser <[email protected]>
Date: Mon, 19 Feb 2018 00:02:12 +0100
Subject: [PATCH] * client-src/sendbackup.c, client-src/sendbackup-gnutar.c,  
 client-src/sendbackup-dump.c: Close client pipe fd before linking   shared
 memory ring to avoid EBADF on Mac where semaphores are fds

---
 ChangeLog                      | 5 +++++
 client-src/sendbackup-dump.c   | 5 +++--
 client-src/sendbackup-gnutar.c | 5 +++--
 client-src/sendbackup.c        | 4 ++--
 4 files changed, 13 insertions(+), 6 deletions(-)

diff --git a/ChangeLog b/ChangeLog
index d3d667db..85b872d9 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,8 @@
+2018-02-18  Michael Weiser <[email protected]>
+	* client-src/sendbackup.c, client-src/sendbackup-gnutar.c,
+	  client-src/sendbackup-dump.c: Close client pipe fd before linking
+	  shared memory ring to avoid EBADF on Mac where semaphores are fds
+
 2018-02-12  Jean-Louis Martineau <[email protected]>
 	* perl/Amanda/Changer/disk.pm: Make slot dit with permission 0700
 
diff --git a/client-src/sendbackup-dump.c b/client-src/sendbackup-dump.c
index 1ff12232..7e67ca4f 100644
--- a/client-src/sendbackup-dump.c
+++ b/client-src/sendbackup-dump.c
@@ -515,6 +515,9 @@ char *progname;
     if (dle->create_index)
 	aclose(indexf);
 
+    if (have_filter)
+	close(client_pipe[1]);
+
     if (shm_control_name) {
 	shm_ring = shm_ring_link(shm_control_name);
 	shm_ring_producer_set_size(shm_ring, NETWORK_BLOCK_BYTES*16, NETWORK_BLOCK_BYTES*4);
@@ -528,7 +531,6 @@ char *progname;
 	    native_crc.out = dumpout;
 	    native_crc.thread = g_thread_create(handle_crc_thread,
 				(gpointer)&native_crc, TRUE, NULL);
-	    close(client_pipe[1]);
 	    client_crc.in  = client_pipe[0];
 	    client_crc.out = dumpout;
 	    client_crc.shm_ring = shm_ring;
@@ -542,7 +544,6 @@ char *progname;
 				(gpointer)&native_crc, TRUE, NULL);
 
 	if (have_filter) {
-	    close(client_pipe[1]);
 	    client_crc.in  = client_pipe[0];
 	    client_crc.out = dataf;
 	    client_crc.thread = g_thread_create(handle_crc_thread,
diff --git a/client-src/sendbackup-gnutar.c b/client-src/sendbackup-gnutar.c
index 7fe356b9..11e05ba6 100644
--- a/client-src/sendbackup-gnutar.c
+++ b/client-src/sendbackup-gnutar.c
@@ -655,6 +655,9 @@ start_backup(
     if (dle->create_index)
 	aclose(indexf);
 
+    if (have_filter)
+	close(client_pipe[1]);
+
     if (shm_control_name) {
 	shm_ring = shm_ring_link(shm_control_name);
 	shm_ring_producer_set_size(shm_ring, NETWORK_BLOCK_BYTES*16, NETWORK_BLOCK_BYTES*4);
@@ -668,7 +671,6 @@ start_backup(
 	    native_crc.out = dumpout;
 	    native_crc.thread = g_thread_create(handle_crc_thread,
 					(gpointer)&native_crc, TRUE, NULL);
-	    close(client_pipe[1]);
 	    client_crc.in  = client_pipe[0];
 	    client_crc.out = dataf;
 	    client_crc.shm_ring = shm_ring;
@@ -682,7 +684,6 @@ start_backup(
 					(gpointer)&native_crc, TRUE, NULL);
 
 	if (have_filter) {
-	    close(client_pipe[1]);
 	    client_crc.in  = client_pipe[0];
 	    client_crc.out = dataf;
 	    client_crc.thread = g_thread_create(handle_crc_thread,
diff --git a/client-src/sendbackup.c b/client-src/sendbackup.c
index 1700f88b..a6b6a521 100644
--- a/client-src/sendbackup.c
+++ b/client-src/sendbackup.c
@@ -951,6 +951,8 @@ main(
 
 
 	    close(native_pipe[1]);
+	    if (have_filter)
+		close(client_pipe[1]);
 
 	    if (shm_control_name && dle->data_path == DATA_PATH_AMANDA) {
 		shm_ring = shm_ring_link(shm_control_name);
@@ -965,7 +967,6 @@ main(
 		    native_crc.out = dumpout;
 		    native_crc.thread = g_thread_create(handle_crc_thread,
 					 (gpointer)&native_crc, TRUE, NULL);
-		    close(client_pipe[1]);
 		    client_crc.shm_ring = shm_ring;
 		    client_crc.in  = client_pipe[0];
 		    client_crc.out = datafd;
@@ -979,7 +980,6 @@ main(
 					(gpointer)&native_crc, TRUE, NULL);
 
 		if (have_filter) {
-		    close(client_pipe[1]);
 		    client_crc.in  = client_pipe[0];
 		    client_crc.out = datafd;
 		    client_crc.thread = g_thread_create(handle_crc_thread,
-- 
2.14.3 (Apple Git-98)

-- 
Thanks,
Michael