Re: test harness/test cases for common-src/shm-ring.c?
[email protected] (Eric Schnoebelen)
| Newsgroups | gmane.comp.archivers.amanda.devel |
|---|---|
| Message-ID | <[email protected]> |
Jean-Louis Martineau writes: - There is no functionality test - - Can you post the complete debug file? Sure, but it's very un-interesting. Hmm, with 3.4 and 3.4.1, EINVAL was returned by sem_*wait(), with 3.4.2 I am seeing a EBADF from sem_close(). In both cases, the errors keep sendbackup from sending the size line. Attached is the amdump results, the sendbackup log files, and the patch I applied to shm-ring.c to add additional debugging information (and create shorter shared memory/semaphore names as required by NetBSD's implementation.) - On 08/02/17 10:54 AM, Eric Schnoebelen wrote: - > I'm attempting to port Amanda 3.4.x to NetBSD, and am seeing strange - > failures from sendbackup. - > - > The failures are in shm-ring.c, with "invalid operand" (EINVAL) - > in shm_ring_sem_wait. - > - > Does a simpler test program exist for the functionality in - > shm-ring.c? Debugging as part of sendbackup is more painful - > than I have time for. - > - > Thank you, - > Eric -- Eric Schnoebelen [email protected] http://www.cirr.com You can only live once, but if you do it right, once is enough. $NetBSD$ Provide much shorter semaphore names for NetBSD, on which the names are limited to 14 characters. Plus much debugging --- common-src/shm-ring.c.orig 2016-11-23 16:11:16.000000000 +0000 +++ common-src/shm-ring.c @@ -54,12 +54,22 @@ #define DEFAULT_SHM_RING_BLOCK_SIZE (NETWORK_BLOCK_BYTES) #define DEFAULT_SHM_RING_SIZE (DEFAULT_SHM_RING_BLOCK_SIZE*8) -#define SHM_CONTROL_NAME "/amanda_shm_control-%d-%d" -#define SHM_DATA_NAME "/amanda_shm_data-%d-%d" -#define SEM_WRITE_NAME "/amanda_sem_write-%d-%d" -#define SEM_READ_NAME "/amanda_sem_read-%d-%d" -#define SEM_READY_NAME "/amanda_sem_ready-%d-%d" -#define SEM_START_NAME "/amanda_sem_start-%d-%d" +/* NetBSD only supports 14 character semaphore names */ +#if __NetBSD__ +# define SHM_CONTROL_NAME "/A_ctl-%04.4x-%02.2x" +# define SHM_DATA_NAME "/A_da-%04.4x-%02.2x" +# define SEM_WRITE_NAME "/A_wr-%04.4x-%02.2x" +# define SEM_READ_NAME "/A_rd-%04.4x-%02.2x" +# define SEM_READY_NAME "/A_rdy-%04.4x-%02.2x" +# define SEM_START_NAME "/A_st-%04.4x-%02.2x" +#else +# define SHM_CONTROL_NAME "/amanda_shm_control-%d-%d" +# define SHM_DATA_NAME "/amanda_shm_data-%d-%d" +# define SEM_WRITE_NAME "/amanda_sem_write-%d-%d" +# define SEM_READ_NAME "/amanda_sem_read-%d-%d" +# define SEM_READY_NAME "/amanda_sem_ready-%d-%d" +# define SEM_START_NAME "/amanda_sem_start-%d-%d" +#endif static int shm_ring_id = 0; GMutex *shm_ring_mutex = NULL; @@ -207,13 +217,21 @@ shm_ring_sem_wait( { int i; + + g_debug("shm_ring_sem_wait(shm_ring=%p, sem=%p): sem->ksem_magic=%x", + shm_ring, sem, *sem); + while(1) { struct timespec tv = {time(NULL)+300, 0}; #ifdef HAVE_SEM_TIMEDWAIT + g_debug("shm_ring_sem_wait(shm_ring=%p, sem=%p): sem_timedwait()", + shm_ring, sem); if (sem_timedwait(sem, &tv) == 0) return 0; #else + g_debug("shm_ring_sem_wait(shm_ring=%p, sem=%p): sem_wait()", + shm_ring, sem); if (sem_wait(sem) == 0) return 0; #endif @@ -223,11 +241,6 @@ shm_ring_sem_wait( return -1; } - if (shm_ring->mc->cancelled) { - g_debug("shm_ring_sem_wait: shm-ring is cancelled"); - return -1; - } - if (errno == EINTR) continue; @@ -272,7 +285,7 @@ fd_to_shm_ring( ssize_t n; size_t consumer_block_size; - g_debug("fd_to_shm_ring"); + g_debug("fd_to_shm_ring(fd=%d, shm_ring=%p,..)", fd, shm_ring); shm_ring_size = shm_ring->mc->ring_size; consumer_block_size = shm_ring->mc->consumer_block_size; @@ -285,6 +298,8 @@ fd_to_shm_ring( readx = shm_ring->mc->readx; if (shm_ring_size - (written - readx) >= shm_ring->block_size) break; + g_debug("fd_to_shm_ring(%d): shm_ring_sem_wait(,...->sem_write=%p)", + fd, shm_ring->sem_write); if (shm_ring_sem_wait(shm_ring, shm_ring->sem_write) != 0) { break; } @@ -308,6 +323,9 @@ fd_to_shm_ring( if (n > 0) { if (shm_ring->mc->written == 0 && shm_ring->mc->need_sem_ready) { sem_post(shm_ring->sem_ready); + g_debug( + "fd_to_shm_ring(%d): shm_ring_sem_wait(,...->sem_start=%p)", + fd, shm_ring->sem_start); if (shm_ring_sem_wait(shm_ring, shm_ring->sem_start) != 0) { break; } @@ -333,6 +351,8 @@ fd_to_shm_ring( } } + g_debug( "fd_to_shm_ring(%d): sem_post(shm_ring->sem_read=%p)", + fd, shm_ring->sem_read); sem_post(shm_ring->sem_read); sem_post(shm_ring->sem_read); @@ -340,6 +360,8 @@ fd_to_shm_ring( while (!shm_ring->mc->cancelled && (shm_ring->mc->written != shm_ring->mc->readx || !shm_ring->mc->eof_flag)) { + g_debug("fd_to_shm_ring(%d): shm_ring_sem_wait(,...->sem_write=%p)", + fd, shm_ring->sem_write); if (shm_ring_sem_wait(shm_ring, shm_ring->sem_write) != 0) { break; } @@ -350,6 +372,8 @@ void close_producer_shm_ring( shm_ring_t *shm_ring) { + g_debug("close_producer_shm_ring(shm_ring=%p)", shm_ring); + if (!shm_ring->mc->eof_flag) { shm_ring->mc->eof_flag = TRUE; } @@ -357,7 +381,6 @@ close_producer_shm_ring( sem_post(shm_ring->sem_start); sem_post(shm_ring->sem_write); sem_post(shm_ring->sem_read); -g_debug("close_producer_shm_ring sem_close(sem_write %p", shm_ring->sem_write); am_sem_close(shm_ring->sem_write); am_sem_close(shm_ring->sem_ready); am_sem_close(shm_ring->sem_read); @@ -389,12 +412,15 @@ shm_ring_to_security_stream( gsize usable = 0; gboolean eof_flag = FALSE; - g_debug("shm_ring_to_security_stream"); + g_debug("shm_ring_to_security_stream(shm_ring=%p", shm_ring); shm_ring_size = shm_ring->mc->ring_size; sem_post(shm_ring->sem_write); while (!shm_ring->mc->cancelled) { do { + g_debug("shm_ring_to_security_stream(shm_ring=%p): " + "shm_ring_sem_wait(,...->sem_read=%p)", + shm_ring, shm_ring->sem_read); if (shm_ring_sem_wait(shm_ring, shm_ring->sem_read) != 0) { break; } @@ -456,12 +482,15 @@ shm_ring_to_fd( gsize usable = 0; gboolean eof_flag = FALSE; - g_debug("shm_ring_to_fd"); + g_debug("shm_ring_to_fd(shm_ring=%p, fd=%d", shm_ring, fd); shm_ring_size = shm_ring->mc->ring_size; sem_post(shm_ring->sem_write); while (!shm_ring->mc->cancelled) { do { + g_debug("shm_ring_to_fd(%d): " + "shm_ring_sem_wait(shm_ring=%p, shm_ring->sem_read=%p)", + fd, shm_ring, shm_ring->sem_read); if (shm_ring_sem_wait(shm_ring, shm_ring->sem_read) != 0) { break; } @@ -533,12 +562,17 @@ shm_ring_producer_set_size( ssize_t block_size) { - g_debug("shm_ring_producer_set_size"); + g_debug( + "shm_ring_producer_set_size(shm_ring=%p, ring_size=%ld, block_size=%ld", + shm_ring, ring_size, block_size); shm_ring->ring_size = ring_size; shm_ring->block_size = block_size; shm_ring->mc->producer_ring_size = ring_size; shm_ring->mc->producer_block_size = block_size; + g_debug("shm_ring_producer_set_size: " + "shm_ring_sem_wait(shm_ring=%p, shm_ring->sem_write=%p)", + shm_ring, shm_ring->sem_write); if (shm_ring_sem_wait(shm_ring, shm_ring->sem_write) == -1) { exit(1); } @@ -596,6 +630,8 @@ am_sem_create( sem_t *r; int nb; + g_debug("am_sem_create(%s)", name); + g_mutex_lock(shm_ring_mutex); r = sem_open(name, O_CREAT | O_EXCL, S_IRUSR | S_IWUSR, 0); if (r == SEM_FAILED) { @@ -606,7 +642,9 @@ am_sem_create( hash_sem = g_hash_table_new(g_direct_hash, g_direct_equal); } nb = 1; -g_debug("am_sem_create %p %d", r, nb); + + g_debug("am_sem_create(%s) r=%p nb=%d *r=%x", name, r, nb, *r); + g_hash_table_insert(hash_sem, r, GINT_TO_POINTER(nb)); g_mutex_unlock(shm_ring_mutex); @@ -620,6 +658,7 @@ am_sem_open( sem_t *r; int nb; +g_debug("am_sem_open(%s)", name); g_mutex_lock(shm_ring_mutex); r = sem_open(name, 0); if (r == SEM_FAILED) { @@ -631,7 +670,7 @@ am_sem_open( } nb = GPOINTER_TO_INT(g_hash_table_lookup(hash_sem, r)); nb++; -g_debug("am_sem_open %p %d", r, nb); +g_debug("am_sem_open(%s) r=%p nb=%d, *r=%x", name, r, nb, *r); g_hash_table_insert(hash_sem, r, GINT_TO_POINTER(nb)); g_mutex_unlock(shm_ring_mutex); @@ -647,7 +686,7 @@ am_sem_close( g_mutex_lock(shm_ring_mutex); nb = GPOINTER_TO_INT(g_hash_table_lookup(hash_sem, sem)); nb--; -g_debug("am_sem_close %p %d", sem, nb); +g_debug("am_sem_close(sem=%p): nb=%d *sem=%x", sem, nb, *sem); if (nb <= 0) { g_hash_table_remove(hash_sem, sem); if (sem_close(sem) == -1) { @@ -734,13 +773,20 @@ shm_ring_consumer_set_size( ssize_t ring_size, /* shm_ring desired size */ ssize_t block_size) { - g_debug("shm_ring_consumer_set_size"); + g_debug( + "shm_ring_consumer_set_size(shm_ring=%p, ring_size=%ld, block_size=%ld)", + shm_ring, ring_size, block_size); shm_ring->ring_size = ring_size; shm_ring->block_size = block_size; shm_ring->mc->consumer_ring_size = ring_size; shm_ring->mc->consumer_block_size = block_size; sem_post(shm_ring->sem_write); + + g_debug("shm_ring_consumer_set_size: " + "shm_ring_sem_wait(shm_ring=%p, shm_ring->sem_read=%p)", + shm_ring, shm_ring->sem_read); + if (shm_ring_sem_wait(shm_ring, shm_ring->sem_read) == -1) { g_debug("shm_ring_consumer_set_size: fail shm_ring_sem_wait"); return; @@ -785,7 +831,7 @@ shm_ring_link( shm_ring_t *shm_ring = g_new0(shm_ring_t, 1); int i; - g_debug("shm_ring_link %s", name); + g_debug("shm_ring_link(name=%s)", name); shm_ring->shm_control_name = g_strdup(name); shm_ring->shm_control = shm_open(shm_ring->shm_control_name, O_RDWR, S_IRUSR | S_IWUSR); if (shm_ring->shm_control == -1) { @@ -821,7 +867,8 @@ void close_consumer_shm_ring( shm_ring_t *shm_ring) { -g_debug("close_consumer_shm_ring sem_close(sem_write %p", shm_ring->sem_write); +g_debug("close_consumer_shm_ring sem_close(shm_ring=%p)", shm_ring); +g_debug("close_consumer_shm_ring sem_close(sem_write %p)", shm_ring->sem_write); am_sem_close(shm_ring->sem_write); am_sem_close(shm_ring->sem_read); am_sem_close(shm_ring->sem_ready); Wed Feb 08 14:37:15.259464787 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: pid 4705 ruid 1009 euid 1009 version 3.4.2: start at Wed Feb 8 14:37:15 2017 Wed Feb 08 14:37:15.259597039 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: execve: /usr/pkg/libexec/amanda/sendbackup amandad bsd --shm-name /A_ctl-180d-00 Wed Feb 08 14:37:15.259667292 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: Version 3.4.2 Wed Feb 08 14:37:15.260017290 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: reading config file /usr/pkg/etc/amanda/amanda-client.conf Wed Feb 08 14:37:15.261700039 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: reading config file /usr/pkg/etc/amanda/verify/amanda-client.conf Wed Feb 08 14:37:15.267461765 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: pid 4705 ruid 1009 euid 1009 version 3.4.2: rename at Wed Feb 8 14:37:15 2017 Wed Feb 08 14:37:15.267540192 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <dle> Wed Feb 08 14:37:15.267596832 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <program>GNUTAR</program> Wed Feb 08 14:37:15.267896484 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <disk>/</disk> Wed Feb 08 14:37:15.267923252 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <level>1</level> Wed Feb 08 14:37:15.267955598 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <auth>bsd</auth> Wed Feb 08 14:37:15.267979178 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <compress>FAST</compress> Wed Feb 08 14:37:15.268002958 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <record>YES</record> Wed Feb 08 14:37:15.268027519 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <index>YES</index> Wed Feb 08 14:37:15.268050548 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <datapath>AMANDA</datapath> Wed Feb 08 14:37:15.268075495 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <exclude> Wed Feb 08 14:37:15.268095869 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: <list>/usr/pkg/etc/amanda/exclude</list> Wed Feb 08 14:37:15.268131627 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: </exclude> Wed Feb 08 14:37:15.268165060 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: line: </dle> Wed Feb 08 14:37:15.268211792 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: Parsed request as: program `GNUTAR' Wed Feb 08 14:37:15.268227476 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: disk `/' Wed Feb 08 14:37:15.268241248 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: device `/' Wed Feb 08 14:37:15.268255000 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: level 1 Wed Feb 08 14:37:15.268268927 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: since NODATE Wed Feb 08 14:37:15.268282638 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: options `' Wed Feb 08 14:37:15.268298682 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: datapath `AMANDA' Wed Feb 08 14:37:15.269120179 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: start: pkgsrc-nb7.cirr.com:/ lev 1 Wed Feb 08 14:37:15.269187040 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: Spawning "/usr/bin/gzip /usr/bin/gzip --fast" in pipeline Wed Feb 08 14:37:15.269670510 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: gnutar: pid 3677: /usr/bin/gzipWed Feb 08 14:37:15.269783223 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: pid 3677: /usr/bin/gzip --fast Wed Feb 08 14:37:15.270535878 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: gnutar: error opening '/var/amanda/verify/gnutar-lists//pkgsrc-nb7.cirr.com__0': No such file or directory Wed Feb 08 14:37:15.283519001 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: doing level 1 dump as listed-incremental to '/var/amanda/verify/gnutar-lists//pkgsrc-nb7.cirr.com__1.new' Wed Feb 08 14:37:15.285622569 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: Spawning "/usr/pkg/libexec/amanda/runtar runtar verify /usr/pkg/bin/gtar --create --file - --directory / --one-file-system --listed-incremental /var/amanda/verify/gnutar-lists//pkgsrc-nb7.cirr.com__1.new --sparse --ignore-failed-read --totals --exclude-from /tmp/amanda/sendbackup._.20170208143715.exclude ." in pipeline Wed Feb 08 14:37:15.286164978 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: gnutar: /usr/pkg/libexec/amanda/runtar: pid 25443 Wed Feb 08 14:37:15.286356355 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: shm_ring_link(name=/A_ctl-180d-00) Wed Feb 08 14:37:15.286546176 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_wr-180d-01) Wed Feb 08 14:37:15.286624747 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_wr-180d-01) r=0x7f7ff7b01850 nb=1, *r=f7b02830 Wed Feb 08 14:37:15.286643610 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rd-180d-02) Wed Feb 08 14:37:15.286662692 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rd-180d-02) r=0x7f7ff7b01870 nb=1, *r=f7b02a70 Wed Feb 08 14:37:15.286678205 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rdy-180d-03) Wed Feb 08 14:37:15.286696411 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rdy-180d-03) r=0x7f7ff7b01880 nb=1, *r=f7b02aa0 Wed Feb 08 14:37:15.286711817 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_st-180d-04) Wed Feb 08 14:37:15.286729990 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_st-180d-04) r=0x7f7ff7b01888 nb=1, *r=f7b02ad0 Wed Feb 08 14:37:15.286798652 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: shm_ring_producer_set_size(shm_ring=0x7f7ff7b67390, ring_size=524288, block_size=131072 Wed Feb 08 14:37:15.286817741 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: shm_ring_producer_set_size: shm_ring_sem_wait(shm_ring=0x7f7ff7b67390, shm_ring->sem_write=0x7f7ff7b01850) Wed Feb 08 14:37:15.286852800 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: shm_ring_sem_wait(shm_ring=0x7f7ff7b67390, sem=0x7f7ff7b01850): sem->ksem_magic=f7b02830 Wed Feb 08 14:37:15.286871243 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: shm_ring_sem_wait(shm_ring=0x7f7ff7b67390, sem=0x7f7ff7b01850): sem_wait() Wed Feb 08 14:37:15.298001157 2017: pid 12069: thd-0x7f7ff7b08e00: sendbackup: Started index creator: "/usr/pkg/bin/gtar -tf - 2>/dev/null | sed -e 's/^\.//'" Wed Feb 08 14:37:15.321436833 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: Started backup Wed Feb 08 14:37:15.321817134 2017: pid 4705: thd-0x7f7ff7b19850: sendbackup: fd_to_shm_ring(fd=7, shm_ring=0x7f7ff7b67390,..) Wed Feb 08 14:37:15.337271052 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./kern: directory is on a different filesystem; not dumped Wed Feb 08 14:37:15.337669839 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./proc: directory is on a different filesystem; not dumped Wed Feb 08 14:37:15.337976434 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./usr: directory is on a different filesystem; not dumped Wed Feb 08 14:37:15.338214750 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./var: directory is on a different filesystem; not dumped Wed Feb 08 14:37:15.348579378 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./dev/pts: directory is on a different filesystem; not dumped Wed Feb 08 14:37:21.018391910 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: 48: size(|): Total bytes written: 42670080 (41MiB, 7.2MiB/s) Wed Feb 08 14:37:21.024412504 2017: pid 12069: thd-0x7f7ff7b08e00: sendbackup: Index created successfully Wed Feb 08 14:37:21.030808293 2017: pid 4705: thd-0x7f7ff7b19850: sendbackup: fd_to_shm_ring(7): sem_post(shm_ring->sem_read=0x7f7ff7b01870) Wed Feb 08 14:37:21.031938273 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: close_producer_shm_ring(shm_ring=0x7f7ff7b67390) Wed Feb 08 14:37:21.031994239 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: am_sem_close(sem=0x7f7ff7b01850): nb=0 *sem=f7b02830 Wed Feb 08 14:37:21.032170335 2017: pid 4705: thd-0x7f7ff7b08e00: sendbackup: sem_close(0x7f7ff7b01850) failed: Bad file descriptor Wed Feb 08 14:37:30.241026770 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: pid 1406 ruid 1009 euid 1009 version 3.4.2: start at Wed Feb 8 14:37:30 2017 Wed Feb 08 14:37:30.241155702 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: execve: /usr/pkg/libexec/amanda/sendbackup amandad bsd --shm-name /A_ctl-5419-00 Wed Feb 08 14:37:30.241226172 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: Version 3.4.2 Wed Feb 08 14:37:30.241558844 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: reading config file /usr/pkg/etc/amanda/amanda-client.conf Wed Feb 08 14:37:30.242086507 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: reading config file /usr/pkg/etc/amanda/verify/amanda-client.conf Wed Feb 08 14:37:30.244416337 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: pid 1406 ruid 1009 euid 1009 version 3.4.2: rename at Wed Feb 8 14:37:30 2017 Wed Feb 08 14:37:30.244468898 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <dle> Wed Feb 08 14:37:30.244517879 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <program>GNUTAR</program> Wed Feb 08 14:37:30.244805233 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <disk>/</disk> Wed Feb 08 14:37:30.244831805 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <level>1</level> Wed Feb 08 14:37:30.244863662 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <auth>bsd</auth> Wed Feb 08 14:37:30.244887294 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <compress>FAST</compress> Wed Feb 08 14:37:30.244911109 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <record>YES</record> Wed Feb 08 14:37:30.244935006 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <index>YES</index> Wed Feb 08 14:37:30.244958295 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <datapath>AMANDA</datapath> Wed Feb 08 14:37:30.244983257 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <exclude> Wed Feb 08 14:37:30.245003945 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: <list>/usr/pkg/etc/amanda/exclude</list> Wed Feb 08 14:37:30.245039049 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: </exclude> Wed Feb 08 14:37:30.245071090 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: line: </dle> Wed Feb 08 14:37:30.245112719 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: Parsed request as: program `GNUTAR' Wed Feb 08 14:37:30.245128746 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: disk `/' Wed Feb 08 14:37:30.245142568 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: device `/' Wed Feb 08 14:37:30.245156378 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: level 1 Wed Feb 08 14:37:30.245170372 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: since NODATE Wed Feb 08 14:37:30.245184054 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: options `' Wed Feb 08 14:37:30.245199867 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: datapath `AMANDA' Wed Feb 08 14:37:30.246074134 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: start: pkgsrc-nb7.cirr.com:/ lev 1 Wed Feb 08 14:37:30.246141229 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: Spawning "/usr/bin/gzip /usr/bin/gzip --fast" in pipeline Wed Feb 08 14:37:30.246660212 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: gnutar: pid 24933: /usr/bin/gzipWed Feb 08 14:37:30.246772637 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: pid 24933: /usr/bin/gzip --fast Wed Feb 08 14:37:30.265281151 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: gnutar: error opening '/var/amanda/verify/gnutar-lists//pkgsrc-nb7.cirr.com__0': No such file or directory Wed Feb 08 14:37:30.274033857 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: doing level 1 dump as listed-incremental to '/var/amanda/verify/gnutar-lists//pkgsrc-nb7.cirr.com__1.new' Wed Feb 08 14:37:30.279677915 2017: pid 15729: thd-0x7f7ff7b08e00: sendbackup: Started index creator: "/usr/pkg/bin/gtar -tf - 2>/dev/null | sed -e 's/^\.//'" Wed Feb 08 14:37:30.280170841 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: Spawning "/usr/pkg/libexec/amanda/runtar runtar verify /usr/pkg/bin/gtar --create --file - --directory / --one-file-system --listed-incremental /var/amanda/verify/gnutar-lists//pkgsrc-nb7.cirr.com__1.new --sparse --ignore-failed-read --totals --exclude-from /tmp/amanda/sendbackup._.20170208143730.exclude ." in pipeline Wed Feb 08 14:37:30.284695397 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: gnutar: /usr/pkg/libexec/amanda/runtar: pid 17748 Wed Feb 08 14:37:30.284906126 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: shm_ring_link(name=/A_ctl-5419-00) Wed Feb 08 14:37:30.285113974 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_wr-5419-01) Wed Feb 08 14:37:30.285194077 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_wr-5419-01) r=0x7f7ff7b01850 nb=1, *r=f7b02830 Wed Feb 08 14:37:30.285212543 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rd-5419-02) Wed Feb 08 14:37:30.285231001 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rd-5419-02) r=0x7f7ff7b01870 nb=1, *r=f7b02a70 Wed Feb 08 14:37:30.285246587 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rdy-5419-03) Wed Feb 08 14:37:30.285264449 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_rdy-5419-03) r=0x7f7ff7b01880 nb=1, *r=f7b02aa0 Wed Feb 08 14:37:30.285279774 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_st-5419-04) Wed Feb 08 14:37:30.285297394 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_open(/A_st-5419-04) r=0x7f7ff7b01888 nb=1, *r=f7b02ad0 Wed Feb 08 14:37:30.285367457 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: shm_ring_producer_set_size(shm_ring=0x7f7ff7b67390, ring_size=524288, block_size=131072 Wed Feb 08 14:37:30.285387061 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: shm_ring_producer_set_size: shm_ring_sem_wait(shm_ring=0x7f7ff7b67390, shm_ring->sem_write=0x7f7ff7b01850) Wed Feb 08 14:37:30.285422919 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: shm_ring_sem_wait(shm_ring=0x7f7ff7b67390, sem=0x7f7ff7b01850): sem->ksem_magic=f7b02830 Wed Feb 08 14:37:30.285441463 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: shm_ring_sem_wait(shm_ring=0x7f7ff7b67390, sem=0x7f7ff7b01850): sem_wait() Wed Feb 08 14:37:30.307747900 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: Started backup Wed Feb 08 14:37:30.310324939 2017: pid 1406: thd-0x7f7ff7b19850: sendbackup: fd_to_shm_ring(fd=7, shm_ring=0x7f7ff7b67390,..) Wed Feb 08 14:37:30.325744955 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./kern: directory is on a different filesystem; not dumped Wed Feb 08 14:37:30.367632079 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./proc: directory is on a different filesystem; not dumped Wed Feb 08 14:37:30.367865976 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./usr: directory is on a different filesystem; not dumped Wed Feb 08 14:37:30.367975308 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./var: directory is on a different filesystem; not dumped Wed Feb 08 14:37:30.368073109 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./dev/pts: directory is on a different filesystem; not dumped Wed Feb 08 14:37:30.380332529 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 119: strange(?): /usr/pkg/bin/gtar: ./kern: file changed as we read it Wed Feb 08 14:37:35.609203826 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: 48: size(|): Total bytes written: 42670080 (41MiB, 7.8MiB/s) Wed Feb 08 14:37:35.614079096 2017: pid 15729: thd-0x7f7ff7b08e00: sendbackup: Index created successfully Wed Feb 08 14:37:35.627827537 2017: pid 1406: thd-0x7f7ff7b19850: sendbackup: fd_to_shm_ring(7): sem_post(shm_ring->sem_read=0x7f7ff7b01870) Wed Feb 08 14:37:35.629073203 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: close_producer_shm_ring(shm_ring=0x7f7ff7b67390) Wed Feb 08 14:37:35.629108726 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: am_sem_close(sem=0x7f7ff7b01850): nb=0 *sem=f7b02830 Wed Feb 08 14:37:35.629280285 2017: pid 1406: thd-0x7f7ff7b08e00: sendbackup: sem_close(0x7f7ff7b01850) failed: Bad file descriptor
(unnamed)
(message/rfc822, 4.9 KB) - not displayed