0000547: 15.2.1-15.1 director crashes when running >1 label job

ID	Project	Category	View Status	Date Submitted	Last Update

0000547	bareos-core	director	public	2015-10-28 18:07	2019-12-18 15:25

Reporter	avantsysadm@avant.ca	Assigned To
Priority	normal	Severity	crash	Reproducibility	sometimes
Status	closed	Resolution	duplicate
Platform	Linux	OS	CentOS	OS Version	6
Product Version	15.2.2
Fixed in Version	15.2.2

Summary	0000547: 15.2.1-15.1 director crashes when running >1 label job
Description	I have two autochangers connected to this server running 15.2.1. In one window, from bconsole, I issued "label storage=TL1000 barcodes", which was proceeding nicely. Then from another window, I issued "label storage=PV124T barcodes" which listed in the inventory, started the process, but caused the director to crash immediately after "Sending label command for Volume "000001L3" Slot 1..." appeared, and both bconsole sessions exited.
Additional Information	[root@backup1 ~]# cat $MAIL From root@localhost.ad.avant.ca Thu Oct 22 21:00:16 2015 Return-Path: <root@localhost.ad.avant.ca> X-Original-To: root@localhost Delivered-To: root@localhost.ad.avant.ca Received: from backup1.ad.avant.ca (localhost [127.0.0.1]) by backup1.ad.avant.ca (Postfix) with SMTP id CD0C0140D12 for <root@localhost>; Thu, 22 Oct 2015 21:00:16 -0500 (CDT) From: root@localhost.ad.avant.ca Subject: Bareos GDB traceback of bareos-dir on backup1.ad.avant.ca Sender: bareos@backup1.ad.avant.ca To: root@localhost.ad.avant.ca Date: Thu, 22 Oct 2015 21:00:16 -0500 (CDT) Message-Id: <20151023020016.CD0C0140D12@backup1.ad.avant.ca> Created /var/lib/bareos/bareos-dir.core.2524 for doing postmortem debugging Missing separate debuginfo for Try: yum --enablerepo='-debug' install /usr/lib/debug/.build-id/fa/be1ca508dffca0ce7e6bffdc6197edd22e4583 [New Thread 2530] [New Thread 2545] [New Thread 2546] [New Thread 2547] [New Thread 5088] [New Thread 5457] [New Thread 5899] [New Thread 8384] [New Thread 8389] [New Thread 8405] [New Thread 8406] [New Thread 8408] [New Thread 2524] [Thread debugging using libthread_db enabled] Core was generated by `/usr/sbin/bareos-dir -g bareos -c /etc/bareos/bareos-dir.conf'. #0 0x00007f5b539b4fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) $1 = '\000' <repeats 127 times> $2 = 0xb83068 "bareos-dir" $3 = 0xb830a8 "/usr/sbin/bareos-dir" $4 = 0x7f5b18175788 "PostgreSQL" $5 = 0x7f5b54ab6732 "15.2.1 (24 August 2015)" $6 = 0x7f5b54ab674a "x86_64-redhat-linux-gnu" $7 = 0x7f5b54ab6762 "redhat" $8 = 0x7f5b54ab6769 "CentOS release 6.6 (Final)" $9 = "backup1.ad.avant.ca", '\000' <repeats 236 times> $10 = 0x7f5b54ab6ca8 "redhat CentOS release 6.6 (Final)" Environment variable "TestName" not defined. #0 0x00007f5b539b4fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a86042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007f5b54a96d31 in check_deadlock () at lockmgr.c:566 0000003 0x00007f5b539ada51 in start_thread (arg=0x7f5b4b40d700) at pthread_create.c:301 0000004 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 13 (Thread 0x7f5b55bbd7e0 (LWP 2524)): #0 0x00007f5b539b532d in __libc_waitpid (pid=<value optimized out>, stat_loc=<value optimized out>, options=<value optimized out>) at ../sysdeps/unix/sysv/linux/waitpid.c:41 0000001 0x00007f5b54aa64f1 in signal_handler (sig=11) at signal.c:240 0000002 <signal handler called> 0000003 __strlen_sse2 () at ../sysdeps/x86_64/strlen.S:32 0000004 0x00007f5b54a8151f in bvsnprintf(char , int32_t, const char , typedef __va_list_tag __va_list_tag ) (buffer=0x7f5b2400e3b0 "Client b BackupYs.2015-10-22_10.16.59_44 not found.\n", maxlen=2130, format=0x475d51 " has illegal backup protocol %s for Native backup\n", args=0x7ffe6dc2d4c0) at bsnprintf.c:133 0000005 0x00007f5b54a9ccda in Jmsg (jcr=0xbc27d8, type=3, mtime=0, fmt=0x475d48 "Client %s has illegal backup protocol %s for Native backup\n") at message.c:1626 0000006 0x0000000000410eba in validate_storage (jcr=0xbc27d8) at backup.c:80 0000007 do_native_backup_init (jcr=0xbc27d8) at backup.c:117 0000008 0x000000000042d643 in setup_job (jcr=0xbc27d8, suppress_output=<value optimized out>) at job.c:257 0000009 0x000000000042d8bd in run_job (jcr=0xbc27d8) at job.c:80 0000010 0x0000000000422445 in main (argc=<value optimized out>, argv=<value optimized out>) at dird.c:394 Thread 12 (Thread 0x7f5b0ffff700 (LWP 8408)): #0 0x00007f5b539b47dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a82cc6 in BSOCK_TCP::read_nbytes (this=0x7f5b1847be08, ptr=0x7f5b0fffe9dc "\313\343", <incomplete sequence \347\220>, nbytes=4) at bsock_tcp.c:906 0000002 0x00007f5b54a83166 in BSOCK_TCP::recv (this=0x7f5b1847be08) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7f5b1847be08, allow_any_message=false) at getmsg.c:150 0000004 0x00000000004342e7 in msg_thread (arg=0xb85448) at msgchan.c:426 0000005 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0x7f5b1845a9b8) at lockmgr.c:926 0000006 0x00007f5b539ada51 in start_thread (arg=0x7f5b0ffff700) at pthread_create.c:301 0000007 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 11 (Thread 0x7f5b40dfa700 (LWP 8406)): #0 0x00007f5b539b47dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a82cc6 in BSOCK_TCP::read_nbytes (this=0x7f5b18001f08, ptr=0x7f5b40df98cc "", nbytes=4) at bsock_tcp.c:906 0000002 0x00007f5b54a83166 in BSOCK_TCP::recv (this=0x7f5b18001f08) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7f5b18001f08, allow_any_message=false) at getmsg.c:150 0000004 0x000000000041077f in wait_for_job_termination (jcr=0xb85448, timeout=<value optimized out>) at backup.c:650 0000005 0x0000000000413915 in do_native_backup (jcr=0xb85448) at backup.c:591 0000006 0x000000000042cd19 in job_thread (arg=0xb85448) at job.c:419 0000007 0x000000000042e98b in jobq_server (arg=0x6a7920) at jobq.c:450 0000008 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0xbadca8) at lockmgr.c:926 0000009 0x00007f5b539ada51 in start_thread (arg=0x7f5b40dfa700) at pthread_create.c:301 0000010 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 10 (Thread 0x7f5b28dfa700 (LWP 8405)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007f5b54a95a40 in bthread_cond_timedwait_p (cond=0x6a7948, m=0x6a7920, abstime=0x7f5b28df9ce0, file=0x47e418 "jobq.c", line=397) at lockmgr.c:811 0000002 0x000000000042f7a0 in jobq_server (arg=0x6a7920) at jobq.c:397 0000003 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0xbbfd58) at lockmgr.c:926 0000004 0x00007f5b539ada51 in start_thread (arg=0x7f5b28dfa700) at pthread_create.c:301 0000005 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 9 (Thread 0x7f5b2bfff700 (LWP 8389)): #0 0x00007f5b539b47dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a82cc6 in BSOCK_TCP::read_nbytes (this=0x7f5b30006c28, ptr=0x7f5b2bffe9dc "\313\343\347\220\061\060\061\071", nbytes=4) at bsock_tcp.c:906 0000002 0x00007f5b54a83166 in BSOCK_TCP::recv (this=0x7f5b30006c28) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7f5b30006c28, allow_any_message=false) at getmsg.c:150 0000004 0x00000000004342e7 in msg_thread (arg=0xbba788) at msgchan.c:426 0000005 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0x7f5b30028c88) at lockmgr.c:926 0000006 0x00007f5b539ada51 in start_thread (arg=0x7f5b2bfff700) at pthread_create.c:301 0000007 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 8 (Thread 0x7f5b2b5fe700 (LWP 8384)): #0 0x00007f5b539b47dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a82cc6 in BSOCK_TCP::read_nbytes (this=0x7f5b081b8c48, ptr=0x7f5b2b5fd29c "\313\343", <incomplete sequence \347\220>, nbytes=4) at bsock_tcp.c:906 0000002 0x00007f5b54a83166 in BSOCK_TCP::recv (this=0x7f5b081b8c48) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7f5b081b8c48, allow_any_message=false) at getmsg.c:150 0000004 0x000000000043634a in start_storage_daemon_job (jcr=0xbc3c88, rstore=0x0, wstore=0xbae418, send_bsr=false) at msgchan.c:327 0000005 0x0000000000413635 in do_native_backup (jcr=0xbc3c88) at backup.c:395 0000006 0x000000000042cd19 in job_thread (arg=0xbc3c88) at job.c:419 0000007 0x000000000042e98b in jobq_server (arg=0x6a7920) at jobq.c:450 0000008 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0xbc1148) at lockmgr.c:926 0000009 0x00007f5b539ada51 in start_thread (arg=0x7f5b2b5fe700) at pthread_create.c:301 0000010 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 7 (Thread 0x7f5b421fc700 (LWP 5899)): #0 0x00007f5b539b47dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a82cc6 in BSOCK_TCP::read_nbytes (this=0x7f5b24193098, ptr=0x7f5b421fb29c "\313\343琣\020(V[\177", nbytes=4) at bsock_tcp.c:906 0000002 0x00007f5b54a83166 in BSOCK_TCP::recv (this=0x7f5b24193098) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7f5b24193098, allow_any_message=false) at getmsg.c:150 0000004 0x000000000043634a in start_storage_daemon_job (jcr=0xbbff18, rstore=0x0, wstore=0xb8d618, send_bsr=false) at msgchan.c:327 0000005 0x0000000000413635 in do_native_backup (jcr=0xbbff18) at backup.c:395 0000006 0x000000000042cd19 in job_thread (arg=0xbbff18) at job.c:419 0000007 0x000000000042e98b in jobq_server (arg=0x6a7920) at jobq.c:450 0000008 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0x7f5b182f1df8) at lockmgr.c:926 0000009 0x00007f5b539ada51 in start_thread (arg=0x7f5b421fc700) at pthread_create.c:301 0000010 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 6 (Thread 0x7f5b417fb700 (LWP 5457)): #0 0x00007f5b539b47dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a82cc6 in BSOCK_TCP::read_nbytes (this=0x7f5b30027768, ptr=0x7f5b417fa8cc "", nbytes=4) at bsock_tcp.c:906 0000002 0x00007f5b54a83166 in BSOCK_TCP::recv (this=0x7f5b30027768) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7f5b30027768, allow_any_message=false) at getmsg.c:150 0000004 0x000000000041077f in wait_for_job_termination (jcr=0xbba788, timeout=<value optimized out>) at backup.c:650 0000005 0x0000000000413915 in do_native_backup (jcr=0xbba788) at backup.c:591 0000006 0x000000000042cd19 in job_thread (arg=0xbba788) at job.c:419 0000007 0x000000000042e98b in jobq_server (arg=0x6a7920) at jobq.c:450 0000008 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0x7f5b181cee98) at lockmgr.c:926 0000009 0x00007f5b539ada51 in start_thread (arg=0x7f5b417fb700) at pthread_create.c:301 0000010 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 5 (Thread 0x7f5b2a1fc700 (LWP 5088)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007f5b54a95a40 in bthread_cond_timedwait_p (cond=0x6a7948, m=0x6a7920, abstime=0x7f5b2a1fbce0, file=0x47e418 "jobq.c", line=397) at lockmgr.c:811 0000002 0x000000000042f7a0 in jobq_server (arg=0x6a7920) at jobq.c:397 0000003 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0x7f5b2c02ed18) at lockmgr.c:926 0000004 0x00007f5b539ada51 in start_thread (arg=0x7f5b2a1fc700) at pthread_create.c:301 0000005 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 4 (Thread 0x7f5b42bfd700 (LWP 2547)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007f5b54a95a40 in bthread_cond_timedwait_p (cond=0x6a7e40, m=0x6a7f20, abstime=0x7f5b42bfcc10, file=0x48410c "stats.c", line=117) at lockmgr.c:811 0000002 0x000000000044596d in wait_for_next_run (arg=<value optimized out>) at stats.c:117 0000003 statistics_thread_runner (arg=<value optimized out>) at stats.c:325 0000004 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0xbba2d8) at lockmgr.c:926 0000005 0x00007f5b539ada51 in start_thread (arg=0x7f5b42bfd700) at pthread_create.c:301 0000006 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 3 (Thread 0x7f5b435fe700 (LWP 2546)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007f5b54a95a40 in bthread_cond_timedwait_p (cond=0x7f5b54ccaba0, m=0x7f5b54ccab60, abstime=0x7f5b435fdd60, file=0x7f5b54abad5a "watchdog.c", line=313) at lockmgr.c:811 0000002 0x00007f5b54ab02f8 in watchdog_thread (arg=<value optimized out>) at watchdog.c:313 0000003 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0xbba2d8) at lockmgr.c:926 0000004 0x00007f5b539ada51 in start_thread (arg=0x7f5b435fe700) at pthread_create.c:301 0000005 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 2 (Thread 0x7f5b43fff700 (LWP 2545)): #0 0x00007f5b5293e113 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87 0000001 0x00007f5b54a7a206 in bnet_thread_server_tcp (addr_list=0x7f5b3c001168, max_clients=1140841872, sockfds=0x7f5b3c001078, client_wq=0x6a7ba0, nokeepalive=false, handle_client_request=0x1) at bnet_server_tcp.c:298 0000002 0x000000000043edcf in connect_thread (arg=0xb85328) at socket_server.c:100 0000003 0x00007f5b54a96c6d in lmgr_thread_launcher (x=0xbb9928) at lockmgr.c:926 0000004 0x00007f5b539ada51 in start_thread (arg=0x7f5b43fff700) at pthread_create.c:301 0000005 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 1 (Thread 0x7f5b4b40d700 (LWP 2530)): #0 0x00007f5b539b4fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f5b54a86042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007f5b54a96d31 in check_deadlock () at lockmgr.c:566 0000003 0x00007f5b539ada51 in start_thread (arg=0x7f5b4b40d700) at pthread_create.c:301 0000004 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 #0 0x00007f5b539b4fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) No locals. 0000001 0x00007f5b54a86042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 171 status = nanosleep(&timeout, NULL); timeout = {tv_sec = 30, tv_nsec = 0} tv = {tv_sec = 3, tv_usec = 140030239138595} tz = {tz_minuteswest = 0, tz_dsttime = 0} status = <value optimized out> 0000002 0x00007f5b54a96d31 in check_deadlock () at lockmgr.c:566 566 while (!bmicrosleep(30, 0)) { __clframe = {__cancel_routine = 0x7f5b54a96820 <cln_hdl(void)>, __cancel_arg = 0x0, __do_it = 1, __cancel_type = <value optimized out>} old = 0 0000003 0x00007f5b539ada51 in start_thread (arg=0x7f5b4b40d700) at pthread_create.c:301 301 THREAD_SETMEM (pd, result, CALL_THREAD_FCT (pd)); __res = <value optimized out> pd = 0x7f5b4b40d700 now = <value optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140030081292032, -2015895037997726867, 140030223590240, 140030081292736, 0, 3, 1923191682668184429, 1923244923606025069}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <value optimized out> pagesize_m1 = <value optimized out> sp = <value optimized out> freesize = <value optimized out> 0000004 0x00007f5b5294793d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 115 call %rax No locals. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available. From root@localhost.ad.avant.ca Wed Oct 28 12:03:56 2015 Return-Path: <root@localhost.ad.avant.ca> X-Original-To: root@localhost Delivered-To: root@localhost.ad.avant.ca Received: from backup1.ad.avant.ca (localhost [127.0.0.1]) by backup1.ad.avant.ca (Postfix) with SMTP id B7001140D1E for <root@localhost>; Wed, 28 Oct 2015 12:03:56 -0500 (CDT) From: root@localhost.ad.avant.ca Subject: Bareos GDB traceback of bareos-dir on backup1.ad.avant.ca Sender: bareos@backup1.ad.avant.ca To: root@localhost.ad.avant.ca Date: Wed, 28 Oct 2015 12:03:56 -0500 (CDT) Message-Id: <20151028170356.B7001140D1E@backup1.ad.avant.ca> Created /var/lib/bareos/bareos-dir.core.15666 for doing postmortem debugging Missing separate debuginfo for Try: yum --enablerepo='-debug' install /usr/lib/debug/.build-id/fa/be1ca508dffca0ce7e6bffdc6197edd22e4583 [New Thread 15668] [New Thread 15670] [New Thread 15671] [New Thread 15672] [New Thread 26147] [New Thread 26148] [New Thread 26336] [New Thread 15666] [Thread debugging using libthread_db enabled] Core was generated by `/usr/sbin/bareos-dir -g bareos -c /etc/bareos/bareos-dir.conf'. #0 0x00007efee2647fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) $1 = '\000' <repeats 127 times> $2 = 0x2610068 "bareos-dir" $3 = 0x26100a8 "/usr/sbin/bareos-dir" $4 = 0x7efe9c03dfd8 "PostgreSQL" $5 = 0x7efee3749732 "15.2.1 (24 August 2015)" $6 = 0x7efee374974a "x86_64-redhat-linux-gnu" $7 = 0x7efee3749762 "redhat" $8 = 0x7efee3749769 "CentOS release 6.6 (Final)" $9 = "backup1.ad.avant.ca", '\000' <repeats 236 times> $10 = 0x7efee3749ca8 "redhat CentOS release 6.6 (Final)" Environment variable "TestName" not defined. #0 0x00007efee2647fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007efee3719042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007efee3729d31 in check_deadlock () at lockmgr.c:566 0000003 0x00007efee2640a51 in start_thread (arg=0x7efeda0a0700) at pthread_create.c:301 0000004 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 8 (Thread 0x7efee48507e0 (LWP 15666)): #0 0x00007efee2647fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007efee3719042 in bmicrosleep (sec=60, usec=0) at bsys.c:171 0000002 0x0000000000444780 in wait_for_next_job (one_shot_job_to_run=<value optimized out>) at scheduler.c:124 0000003 0x0000000000422435 in main (argc=<value optimized out>, argv=<value optimized out>) at dird.c:393 Thread 7 (Thread 0x7efed1573700 (LWP 26336)): #0 0x00007efee264832d in __libc_waitpid (pid=<value optimized out>, stat_loc=<value optimized out>, options=<value optimized out>) at ../sysdeps/unix/sysv/linux/waitpid.c:41 0000001 0x00007efee37394f1 in signal_handler (sig=11) at signal.c:240 0000002 <signal handler called> 0000003 0x00007efee3714086 in bvsnprintf(char , int32_t, const char , typedef __va_list_tag __va_list_tag ) (buffer=0x7efdea248050 "", maxlen=-1646561203, format=<value optimized out>, args=0x7efed15719e0) at bsnprintf.c:413 0000004 0x00007efee3714cb7 in BSOCK::fsend (this=0x7efecc001378, fmt=0x48e036 "%s") at bsock.c:216 0000005 0x0000000000453a13 in UAContext::send_msg (this=0x7efea4005818, fmt=0x48e036 "%s") at ua_output.c:1337 0000006 0x00000000004518c3 in send_label_request (ua=0x7efea4005818, mr=0x7efed1571db0, omr=<value optimized out>, pr=0x7efed1572740, relabel=false, media_record_exists=false, drive=0) at ua_label.c:611 0000007 0x00000000004527a2 in label_from_barcodes (ua=0x7efea4005818, cmd=<value optimized out>, relabel=<value optimized out>) at ua_label.c:477 0000008 do_label (ua=0x7efea4005818, cmd=<value optimized out>, relabel=<value optimized out>) at ua_label.c:155 0000009 0x000000000045297b in label_cmd (ua=<value optimized out>, cmd=<value optimized out>) at ua_label.c:497 0000010 0x000000000044a589 in do_a_command (ua=0x7efea4005818) at ua_cmds.c:327 0000011 0x0000000000467a9c in handle_UA_client_request (user=0x7efecc001378) at ua_server.c:97 0000012 0x000000000043ee5d in handle_connection_request (arg=0x7efecc001378) at socket_server.c:83 0000013 0x00007efee374379d in workq_server (arg=0x6a7ba0) at workq.c:335 0000014 0x00007efee3729c6d in lmgr_thread_launcher (x=0x7efecc001588) at lockmgr.c:926 0000015 0x00007efee2640a51 in start_thread (arg=0x7efed1573700) at pthread_create.c:301 0000016 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 6 (Thread 0x7efeba9f7700 (LWP 26148)): #0 0x00007efee2647fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007efee3719042 in bmicrosleep (sec=2, usec=0) at bsys.c:171 0000002 0x000000000042ed86 in jobq_server (arg=0x6a7920) at jobq.c:628 0000003 0x00007efee3729c6d in lmgr_thread_launcher (x=0x7efe9c041008) at lockmgr.c:926 0000004 0x00007efee2640a51 in start_thread (arg=0x7efeba9f7700) at pthread_create.c:301 0000005 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 5 (Thread 0x7efea2bfd700 (LWP 26147)): #0 0x00007efee26477dd in read () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007efee3715cc6 in BSOCK_TCP::read_nbytes (this=0x7efe9c0645c8, ptr=0x7efea2bfb96c "\376~", nbytes=4) at bsock_tcp.c:906 0000002 0x00007efee3716166 in BSOCK_TCP::recv (this=0x7efe9c0645c8) at bsock_tcp.c:478 0000003 0x00000000004262ad in bget_dirmsg (bs=0x7efe9c0645c8, allow_any_message=true) at getmsg.c:150 0000004 0x00000000004518ec in send_label_request (ua=0x7efe9c006bf8, mr=0x7efea2bfbdb0, omr=<value optimized out>, pr=0x7efea2bfc740, relabel=false, media_record_exists=false, drive=0) at ua_label.c:610 0000005 0x00000000004527a2 in label_from_barcodes (ua=0x7efe9c006bf8, cmd=<value optimized out>, relabel=<value optimized out>) at ua_label.c:477 0000006 do_label (ua=0x7efe9c006bf8, cmd=<value optimized out>, relabel=<value optimized out>) at ua_label.c:155 0000007 0x000000000045297b in label_cmd (ua=<value optimized out>, cmd=<value optimized out>) at ua_label.c:497 0000008 0x000000000044a589 in do_a_command (ua=0x7efe9c006bf8) at ua_cmds.c:327 0000009 0x0000000000467a9c in handle_UA_client_request (user=0x7efecc001168) at ua_server.c:97 0000010 0x000000000043ee5d in handle_connection_request (arg=0x7efecc001168) at socket_server.c:83 0000011 0x00007efee374379d in workq_server (arg=0x6a7ba0) at workq.c:335 0000012 0x00007efee3729c6d in lmgr_thread_launcher (x=0x7efecc001378) at lockmgr.c:926 0000013 0x00007efee2640a51 in start_thread (arg=0x7efea2bfd700) at pthread_create.c:301 0000014 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 4 (Thread 0x7efed1f74700 (LWP 15672)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007efee3728a40 in bthread_cond_timedwait_p (cond=0x6a7e40, m=0x6a7f20, abstime=0x7efed1f73c10, file=0x48410c "stats.c", line=117) at lockmgr.c:811 0000002 0x000000000044596d in wait_for_next_run (arg=<value optimized out>) at stats.c:117 0000003 statistics_thread_runner (arg=<value optimized out>) at stats.c:325 0000004 0x00007efee3729c6d in lmgr_thread_launcher (x=0x2648968) at lockmgr.c:926 0000005 0x00007efee2640a51 in start_thread (arg=0x7efed1f74700) at pthread_create.c:301 0000006 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 3 (Thread 0x7efed2975700 (LWP 15671)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007efee3728a40 in bthread_cond_timedwait_p (cond=0x7efee395dba0, m=0x7efee395db60, abstime=0x7efed2974d60, file=0x7efee374dd5a "watchdog.c", line=313) at lockmgr.c:811 0000002 0x00007efee37432f8 in watchdog_thread (arg=<value optimized out>) at watchdog.c:313 0000003 0x00007efee3729c6d in lmgr_thread_launcher (x=0x2648968) at lockmgr.c:926 0000004 0x00007efee2640a51 in start_thread (arg=0x7efed2975700) at pthread_create.c:301 0000005 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 2 (Thread 0x7efed3376700 (LWP 15670)): #0 0x00007efee15d1113 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87 0000001 0x00007efee370d206 in bnet_thread_server_tcp (addr_list=0x7efecc001378, max_clients=-751350384, sockfds=0x7efecc001078, client_wq=0x6a7ba0, nokeepalive=false, handle_client_request=0x1) at bnet_server_tcp.c:298 0000002 0x000000000043edcf in connect_thread (arg=0x26122d8) at socket_server.c:100 0000003 0x00007efee3729c6d in lmgr_thread_launcher (x=0x2648c18) at lockmgr.c:926 0000004 0x00007efee2640a51 in start_thread (arg=0x7efed3376700) at pthread_create.c:301 0000005 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 1 (Thread 0x7efeda0a0700 (LWP 15668)): #0 0x00007efee2647fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007efee3719042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007efee3729d31 in check_deadlock () at lockmgr.c:566 0000003 0x00007efee2640a51 in start_thread (arg=0x7efeda0a0700) at pthread_create.c:301 0000004 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 #0 0x00007efee2647fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) No locals. 0000001 0x00007efee3719042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 171 status = nanosleep(&timeout, NULL); timeout = {tv_sec = 30, tv_nsec = 0} tv = {tv_sec = 3, tv_usec = 139633202729763} tz = {tz_minuteswest = 0, tz_dsttime = 0} status = <value optimized out> 0000002 0x00007efee3729d31 in check_deadlock () at lockmgr.c:566 566 while (!bmicrosleep(30, 0)) { __clframe = {__cancel_routine = 0x7efee3729820 <cln_hdl(void)>, __cancel_arg = 0x0, __do_it = 1, __cancel_type = <value optimized out>} old = 0 0000003 0x00007efee2640a51 in start_thread (arg=0x7efeda0a0700) at pthread_create.c:301 301 THREAD_SETMEM (pd, result, CALL_THREAD_FCT (pd)); __res = <value optimized out> pd = 0x7efeda0a0700 now = <value optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139633044883200, -2028772558636072715, 139633187181408, 139633044883904, 0, 3, 2172404116149485813, 2172317025632764149}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <value optimized out> pagesize_m1 = <value optimized out> sp = <value optimized out> freesize = <value optimized out> 0000004 0x00007efee15da93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 115 call %rax No locals. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available.
Tags	No tags attached.

avantsysadm@avant.ca 2015-10-28 18:10 reporter ~0001893	Correction... it has nothing to do with running two label commands at once. I can't label the PV124T tapes at all - it crashes immediately: [root@backup1 bareos]# service bareos-dir start Checking Configuration and Database connection ... bareos-dir: bsys.c:59-0 Safe_unlink excluded: /var/lib/bareos/bareos-dir.bareos-dir.39956088.mail bareos-dir: smartall.c:414-0 Orphaned buffer: bareos-dir 24 bytes at 25f75e8 from watchdog.c:91 bareos-dir: smartall.c:414-0 Orphaned buffer: bareos-dir 24 bytes at 25f6ff8 from watchdog.c:92 Starting Bareos Director services: [ OK ] [root@backup1 bareos]# bconsole Connecting to Director backup1.ad.avant.ca:9101 1000 OK: backup1-dir Version: 15.2.1 (24 August 2015) Enter a period to cancel a command. *label storage=PV124T barcodes Automatically selected Catalog: MyCatalog Using Catalog "MyCatalog" Connecting to Storage daemon PV124T at backup1.ad.avant.ca:9103 ... 3306 Issuing autochanger "slots" command. Device "autochanger-pv124t" has 16 slots. Connecting to Storage daemon PV124T at backup1.ad.avant.ca:9103 ... 3306 Issuing autochanger "list" command. The following Volumes will be labeled: Slot Volume ============== 1 000001L3 2 000002L3 3 000003L3 4 000004L3 5 000005L3 6 000006L3 7 000007L3 8 000008L3 9 000009L3 10 000010L3 11 000011L3 12 000017L3 13 000013L3 14 000018L3 15 000019L3 Do you want to label these Volumes? (yes\|no): yes Defined Pools: 1: Incremental 2: Scratch 3: LTO6 4: LTO3 5: VirtualFull 6: Full 7: Differential Select the Pool (1-7): 4 Connecting to Storage daemon PV124T at backup1.ad.avant.ca:9103 ... Sending label command for Volume "000001L3" Slot 1 ... [root@backup1 bareos]#

avantsysadm@avant.ca 2015-10-28 18:10 reporter ~0001894	From root@localhost.ad.avant.ca Wed Oct 28 12:08:54 2015 Return-Path: <root@localhost.ad.avant.ca> X-Original-To: root@localhost Delivered-To: root@localhost.ad.avant.ca Received: from backup1.ad.avant.ca (localhost [127.0.0.1]) by backup1.ad.avant.ca (Postfix) with SMTP id 9ED2A14038C for <root@localhost>; Wed, 28 Oct 2015 12:08:54 -0500 (CDT) From: root@localhost.ad.avant.ca Subject: Bareos GDB traceback of bareos-dir on backup1.ad.avant.ca Sender: bareos@backup1.ad.avant.ca To: root@localhost.ad.avant.ca Date: Wed, 28 Oct 2015 12:08:54 -0500 (CDT) Message-Id: <20151028170854.9ED2A14038C@backup1.ad.avant.ca> Created /var/lib/bareos/bareos-dir.core.26493 for doing postmortem debugging Missing separate debuginfo for Try: yum --enablerepo='-debug' install /usr/lib/debug/.build-id/fa/be1ca508dffca0ce7e6bffdc6197edd22e4583 [New Thread 26495] [New Thread 26497] [New Thread 26498] [New Thread 26499] [New Thread 26504] [New Thread 26493] [Thread debugging using libthread_db enabled] Core was generated by `/usr/sbin/bareos-dir -g bareos -c /etc/bareos/bareos-dir.conf'. #0 0x00007f4b7c678fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) $1 = '\000' <repeats 127 times> $2 = 0x12be068 "bareos-dir" $3 = 0x12be0a8 "/usr/sbin/bareos-dir" $4 = 0x12f7308 "PostgreSQL" $5 = 0x7f4b7d77a732 "15.2.1 (24 August 2015)" $6 = 0x7f4b7d77a74a "x86_64-redhat-linux-gnu" $7 = 0x7f4b7d77a762 "redhat" $8 = 0x7f4b7d77a769 "CentOS release 6.6 (Final)" $9 = "backup1.ad.avant.ca", '\000' <repeats 236 times> $10 = 0x7f4b7d77aca8 "redhat CentOS release 6.6 (Final)" Environment variable "TestName" not defined. #0 0x00007f4b7c678fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f4b7d74a042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007f4b7d75ad31 in check_deadlock () at lockmgr.c:566 0000003 0x00007f4b7c671a51 in start_thread (arg=0x7f4b740d1700) at pthread_create.c:301 0000004 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 6 (Thread 0x7f4b7e8817e0 (LWP 26493)): #0 0x00007f4b7c678fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f4b7d74a042 in bmicrosleep (sec=60, usec=0) at bsys.c:171 0000002 0x0000000000444780 in wait_for_next_job (one_shot_job_to_run=<value optimized out>) at scheduler.c:124 0000003 0x0000000000422435 in main (argc=<value optimized out>, argv=<value optimized out>) at dird.c:393 Thread 5 (Thread 0x7f4b6abfd700 (LWP 26504)): #0 0x00007f4b7c67932d in __libc_waitpid (pid=<value optimized out>, stat_loc=<value optimized out>, options=<value optimized out>) at ../sysdeps/unix/sysv/linux/waitpid.c:41 0000001 0x00007f4b7d76a4f1 in signal_handler (sig=11) at signal.c:240 0000002 <signal handler called> 0000003 0x00007f4b7d745086 in bvsnprintf(char , int32_t, const char , typedef __va_list_tag __va_list_tag ) (buffer=0x7f4aba248050 "", maxlen=-1646561203, format=<value optimized out>, args=0x7f4b6abfb9e0) at bsnprintf.c:413 0000004 0x00007f4b7d745cb7 in BSOCK::fsend (this=0x7f4b64001168, fmt=0x48e036 "%s") at bsock.c:216 0000005 0x0000000000453a13 in UAContext::send_msg (this=0x7f4b5c002c58, fmt=0x48e036 "%s") at ua_output.c:1337 0000006 0x00000000004518c3 in send_label_request (ua=0x7f4b5c002c58, mr=0x7f4b6abfbdb0, omr=<value optimized out>, pr=0x7f4b6abfc740, relabel=false, media_record_exists=false, drive=0) at ua_label.c:611 0000007 0x00000000004527a2 in label_from_barcodes (ua=0x7f4b5c002c58, cmd=<value optimized out>, relabel=<value optimized out>) at ua_label.c:477 0000008 do_label (ua=0x7f4b5c002c58, cmd=<value optimized out>, relabel=<value optimized out>) at ua_label.c:155 0000009 0x000000000045297b in label_cmd (ua=<value optimized out>, cmd=<value optimized out>) at ua_label.c:497 0000010 0x000000000044a589 in do_a_command (ua=0x7f4b5c002c58) at ua_cmds.c:327 0000011 0x0000000000467a9c in handle_UA_client_request (user=0x7f4b64001168) at ua_server.c:97 0000012 0x000000000043ee5d in handle_connection_request (arg=0x7f4b64001168) at socket_server.c:83 0000013 0x00007f4b7d77479d in workq_server (arg=0x6a7ba0) at workq.c:335 0000014 0x00007f4b7d75ac6d in lmgr_thread_launcher (x=0x7f4b64002618) at lockmgr.c:926 0000015 0x00007f4b7c671a51 in start_thread (arg=0x7f4b6abfd700) at pthread_create.c:301 0000016 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 4 (Thread 0x7f4b6b5fe700 (LWP 26499)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007f4b7d759a40 in bthread_cond_timedwait_p (cond=0x6a7e40, m=0x6a7f20, abstime=0x7f4b6b5fdc10, file=0x48410c "stats.c", line=117) at lockmgr.c:811 0000002 0x000000000044596d in wait_for_next_run (arg=<value optimized out>) at stats.c:117 0000003 statistics_thread_runner (arg=<value optimized out>) at stats.c:325 0000004 0x00007f4b7d75ac6d in lmgr_thread_launcher (x=0x12fa308) at lockmgr.c:926 0000005 0x00007f4b7c671a51 in start_thread (arg=0x7f4b6b5fe700) at pthread_create.c:301 0000006 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 3 (Thread 0x7f4b6bfff700 (LWP 26498)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:239 0000001 0x00007f4b7d759a40 in bthread_cond_timedwait_p (cond=0x7f4b7d98eba0, m=0x7f4b7d98eb60, abstime=0x7f4b6bffed60, file=0x7f4b7d77ed5a "watchdog.c", line=313) at lockmgr.c:811 0000002 0x00007f4b7d7742f8 in watchdog_thread (arg=<value optimized out>) at watchdog.c:313 0000003 0x00007f4b7d75ac6d in lmgr_thread_launcher (x=0x12fa308) at lockmgr.c:926 0000004 0x00007f4b7c671a51 in start_thread (arg=0x7f4b6bfff700) at pthread_create.c:301 0000005 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 2 (Thread 0x7f4b713af700 (LWP 26497)): #0 0x00007f4b7b602113 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87 0000001 0x00007f4b7d73e206 in bnet_thread_server_tcp (addr_list=0x7f4b64001168, max_clients=1899683216, sockfds=0x7f4b64001078, client_wq=0x6a7ba0, nokeepalive=false, handle_client_request=0x1) at bnet_server_tcp.c:298 0000002 0x000000000043edcf in connect_thread (arg=0x12c02d8) at socket_server.c:100 0000003 0x00007f4b7d75ac6d in lmgr_thread_launcher (x=0x12f9418) at lockmgr.c:926 0000004 0x00007f4b7c671a51 in start_thread (arg=0x7f4b713af700) at pthread_create.c:301 0000005 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 Thread 1 (Thread 0x7f4b740d1700 (LWP 26495)): #0 0x00007f4b7c678fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007f4b7d74a042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007f4b7d75ad31 in check_deadlock () at lockmgr.c:566 0000003 0x00007f4b7c671a51 in start_thread (arg=0x7f4b740d1700) at pthread_create.c:301 0000004 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 #0 0x00007f4b7c678fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) No locals. 0000001 0x00007f4b7d74a042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 171 status = nanosleep(&timeout, NULL); timeout = {tv_sec = 30, tv_nsec = 0} tv = {tv_sec = 139962046290368, tv_usec = 139962220091637} tz = {tz_minuteswest = 1, tz_dsttime = 0} status = <value optimized out> 0000002 0x00007f4b7d75ad31 in check_deadlock () at lockmgr.c:566 566 while (!bmicrosleep(30, 0)) { __clframe = {__cancel_routine = 0x7f4b7d75a820 <cln_hdl(void)>, __cancel_arg = 0x0, __do_it = 1, __cancel_type = <value optimized out>} old = 0 0000003 0x00007f4b7c671a51 in start_thread (arg=0x7f4b740d1700) at pthread_create.c:301 301 THREAD_SETMEM (pd, result, CALL_THREAD_FCT (pd)); __res = <value optimized out> pd = 0x7f4b740d1700 now = <value optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139962046289664, 8443793311896799661, 139962188587872, 139962046290368, 0, 3, -8378796071317567059, -8378778290812515923}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <value optimized out> pagesize_m1 = <value optimized out> sp = <value optimized out> freesize = <value optimized out> 0000004 0x00007f4b7b60b93d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 115 call *%rax No locals. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available.

avantsysadm@avant.ca 2015-10-28 19:32 reporter ~0001895	aaaand.... crap. Now I can't label tapes on the TL1000, either. I was previously able to successfully label tapes on the TL1000 using 'barcode', using this version of Bareos. I'm not sure what changed :-(.

pstorz 2015-11-03 09:22 administrator ~0001906	Hello Adam, can you please do setdebug director level=500 trace=1 in the commandline, produce your crash and attach the resulting trace file? Thank you very much.

avantsysadm@avant.ca 2015-11-03 15:22 reporter ~0001907	[root@backup1 ~]# sudo -u bareos bareos-dir -d 500 -dt -m -v -f bareos-dir (10): dird.c:197-0 Debug level = 500 03-Nov-2015 08:19:42.553328 bareos-dir (10): dird.c:197-0 Debug level = 500 03-Nov-2015 08:19:42.553519 bareos-dir (400): lex.c:238-0 Open config file: /etc/bareos/bareos-dir.conf 03-Nov-2015 08:19:42.553776 bareos-dir (9): inc_conf.c:380-0 set wildfile d48148 size=1 [A-Z]:/pagefile.sys 03-Nov-2015 08:19:42.553787 bareos-dir (9): inc_conf.c:380-0 set wilddir d48148 size=1 [A-Z]:/RECYCLER 03-Nov-2015 08:19:42.553796 bareos-dir (9): inc_conf.c:380-0 set wilddir d48148 size=2 [A-Z]:/$RECYCLE.BIN 03-Nov-2015 08:19:42.553806 bareos-dir (9): inc_conf.c:380-0 set wilddir d48148 size=3 [A-Z]:/System Volume Information 03-Nov-2015 08:19:42.554471 bareos-dir (400): lex.c:238-0 Open config file: /etc/bareos/bareos-dir.d/webui-consoles.conf 03-Nov-2015 08:19:42.554522 bareos-dir (400): lex.c:238-0 Open config file: /etc/bareos/bareos-dir.d/webui-profiles.conf 03-Nov-2015 08:19:42.554579 bareos-dir (400): lex.c:238-0 Open config file: /etc/bareos/bareos-dir.conf 03-Nov-2015 08:19:42.554943 bareos-dir (500): runscript.c:41-0 runscript: creating new RUNSCRIPT object 03-Nov-2015 08:19:42.554956 bareos-dir (500): runscript.c:232-0 runscript: setting command = /usr/lib/bareos/scripts/make_catalog_backup.pl MyCatalog 03-Nov-2015 08:19:42.554964 bareos-dir (500): runscript.c:249-0 runscript: setting target = 03-Nov-2015 08:19:42.554971 bareos-dir (200): runscript.c:334-0 runscript: debug 03-Nov-2015 08:19:42.554978 bareos-dir (200): runscript.c:335-0 --> RunScript 03-Nov-2015 08:19:42.554985 bareos-dir (200): runscript.c:336-0 --> Command=/usr/lib/bareos/scripts/make_catalog_backup.pl MyCatalog 03-Nov-2015 08:19:42.554991 bareos-dir (200): runscript.c:337-0 --> Target= 03-Nov-2015 08:19:42.554997 bareos-dir (200): runscript.c:338-0 --> RunOnSuccess=1 03-Nov-2015 08:19:42.555004 bareos-dir (200): runscript.c:339-0 --> RunOnFailure=0 03-Nov-2015 08:19:42.555010 bareos-dir (200): runscript.c:340-0 --> FailJobOnError=1 03-Nov-2015 08:19:42.555016 bareos-dir (200): runscript.c:341-0 --> RunWhen=2 03-Nov-2015 08:19:42.555025 bareos-dir (500): runscript.c:41-0 runscript: creating new RUNSCRIPT object 03-Nov-2015 08:19:42.555031 bareos-dir (500): runscript.c:232-0 runscript: setting command = /usr/lib/bareos/scripts/delete_catalog_backup 03-Nov-2015 08:19:42.555038 bareos-dir (500): runscript.c:249-0 runscript: setting target = 03-Nov-2015 08:19:42.555044 bareos-dir (200): runscript.c:334-0 runscript: debug 03-Nov-2015 08:19:42.555049 bareos-dir (200): runscript.c:335-0 --> RunScript 03-Nov-2015 08:19:42.555055 bareos-dir (200): runscript.c:336-0 --> Command=/usr/lib/bareos/scripts/delete_catalog_backup 03-Nov-2015 08:19:42.555062 bareos-dir (200): runscript.c:337-0 --> Target= 03-Nov-2015 08:19:42.555068 bareos-dir (200): runscript.c:338-0 --> RunOnSuccess=1 03-Nov-2015 08:19:42.555074 bareos-dir (200): runscript.c:339-0 --> RunOnFailure=0 03-Nov-2015 08:19:42.555080 bareos-dir (200): runscript.c:340-0 --> FailJobOnError=0 03-Nov-2015 08:19:42.555086 bareos-dir (200): runscript.c:341-0 --> RunWhen=1 03-Nov-2015 08:19:42.555334 bareos-dir (400): lex.c:238-0 Open config file: /etc/bareos/bareos-dir.d/webui-consoles.conf 03-Nov-2015 08:19:42.555371 bareos-dir (400): lex.c:238-0 Open config file: /etc/bareos/bareos-dir.d/webui-profiles.conf 03-Nov-2015 08:19:42.558925 bareos-dir (250): message.c:351-0 Copy message resource d4ef08 to d72f88 03-Nov-2015 08:19:42.558999 bareos-dir (8): bsys.c:693-0 Could not open state file. sfd=-1 size=192: ERR=No such file or directory 03-Nov-2015 08:19:42.559067 bareos-dir (100): dird.c:335-0 backend path: /usr/lib64/bareos/backends 03-Nov-2015 08:19:42.559077 bareos-dir (150): dir_plugins.c:205-0 Load dir plugins 03-Nov-2015 08:19:42.559099 bareos-dir (50): plugins.c:222-0 load_plugins 03-Nov-2015 08:19:42.559139 bareos-dir (50): plugins.c:299-0 Rejected plugin: want=-dir.so name=scsicrypto-sd.so len=16 03-Nov-2015 08:19:42.559147 bareos-dir (50): plugins.c:299-0 Rejected plugin: want=-dir.so name=bpipe-fd.so len=11 03-Nov-2015 08:19:42.559153 bareos-dir (50): plugins.c:299-0 Rejected plugin: want=-dir.so name=autoxflate-sd.so len=16 03-Nov-2015 08:19:42.559160 bareos-dir (50): plugins.c:299-0 Rejected plugin: want=-dir.so name=scsitapealert-sd.so len=19 03-Nov-2015 08:19:42.559227 bareos-dir (50): plugins.c:286-0 Failed to find any plugins in /usr/lib64/bareos/plugins 03-Nov-2015 08:19:42.559240 bareos-dir (150): dir_plugins.c:218-0 No plugins loaded 03-Nov-2015 08:19:42.559249 bareos-dir (100): cats_backends.c:63-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename dbi, partly_compare = true 03-Nov-2015 08:19:42.559259 bareos-dir (100): cats_backends.c:63-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename mysql, partly_compare = false 03-Nov-2015 08:19:42.559267 bareos-dir (100): cats_backends.c:63-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename postgresql, partly_compare = false 03-Nov-2015 08:19:42.559275 bareos-dir (100): cats_backends.c:161-0 db_init_database: testing backend /usr/lib64/bareos/backends/libbareoscats-postgresql.so 03-Nov-2015 08:19:42.564520 bareos-dir (100): cats_backends.c:226-0 db_init_database: loaded backend /usr/lib64/bareos/backends/libbareoscats-postgresql.so 03-Nov-2015 08:19:42.564537 bareos-dir (100): postgresql.c:1229-0 db_init_database first time 03-Nov-2015 08:19:42.574186 bareos-dir (50): postgresql.c:239-0 pg_real_connect done 03-Nov-2015 08:19:42.574201 bareos-dir (50): postgresql.c:241-0 db_user=bareos db_name=bareos db_password= 03-Nov-2015 08:19:42.574213 bareos-dir (500): postgresql.c:579-0 db_sql_query starts with 'SELECT VersionId FROM Version' 03-Nov-2015 08:19:42.574225 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT VersionId FROM Version' 03-Nov-2015 08:19:42.675689 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.675704 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.675711 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.675716 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.675722 bareos-dir (500): postgresql.c:589-0 db_sql_query succeeded. checking handler 03-Nov-2015 08:19:42.675728 bareos-dir (500): postgresql.c:592-0 db_sql_query invoking handler 03-Nov-2015 08:19:42.675734 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.675739 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.675746 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.675752 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '2004' 03-Nov-2015 08:19:42.675758 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.675764 bareos-dir (500): postgresql.c:594-0 db_sql_query sql_fetch_row worked 03-Nov-2015 08:19:42.675788 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.675795 bareos-dir (500): postgresql.c:786-0 sql_fetch_row row number '1' is NOT acceptable (0..1) 03-Nov-2015 08:19:42.675801 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning 0 03-Nov-2015 08:19:42.675811 bareos-dir (500): postgresql.c:601-0 db_sql_query finished 03-Nov-2015 08:19:42.675817 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SET datestyle TO 'ISO, YMD'' 03-Nov-2015 08:19:42.687341 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.687355 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.687360 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.687366 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.687372 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SET cursor_tuple_fraction=1' 03-Nov-2015 08:19:42.687443 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.687449 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.687455 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.687460 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.687466 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SET standard_conforming_strings=on' 03-Nov-2015 08:19:42.687516 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.687523 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.687529 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.687534 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.687540 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT getdatabaseencoding()' 03-Nov-2015 08:19:42.689205 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.689217 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.689223 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.689229 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.689234 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.689240 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.689246 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.689252 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value 'SQL_ASCII' 03-Nov-2015 08:19:42.689257 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.689263 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SET client_encoding TO 'SQL_ASCII'' 03-Nov-2015 08:19:42.689320 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.689327 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.689332 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.689338 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.689348 bareos-dir (500): postgresql.c:579-0 db_sql_query starts with 'SHOW max_connections' 03-Nov-2015 08:19:42.689358 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SHOW max_connections' 03-Nov-2015 08:19:42.689430 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.689436 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.689442 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.689447 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.689453 bareos-dir (500): postgresql.c:589-0 db_sql_query succeeded. checking handler 03-Nov-2015 08:19:42.689458 bareos-dir (500): postgresql.c:592-0 db_sql_query invoking handler 03-Nov-2015 08:19:42.689464 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.689469 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.689475 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '100' 03-Nov-2015 08:19:42.689481 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.689487 bareos-dir (500): postgresql.c:594-0 db_sql_query sql_fetch_row worked 03-Nov-2015 08:19:42.689493 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.689498 bareos-dir (500): postgresql.c:786-0 sql_fetch_row row number '1' is NOT acceptable (0..1) 03-Nov-2015 08:19:42.689504 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning 0 03-Nov-2015 08:19:42.689511 bareos-dir (500): postgresql.c:601-0 db_sql_query finished 03-Nov-2015 08:19:42.689533 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='VirtualFull'' 03-Nov-2015 08:19:42.711748 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.711761 bareos-dir (500): postgresql.c:655-0 we have 22 fields 03-Nov-2015 08:19:42.711767 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.711777 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.711785 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.711791 bareos-dir (500): postgresql.c:758-0 we need space for 176 bytes 03-Nov-2015 08:19:42.711797 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.711803 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '8' 03-Nov-2015 08:19:42.711809 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value 'VirtualFull' 03-Nov-2015 08:19:42.711815 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '2' has value '0' 03-Nov-2015 08:19:42.711820 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '3' has value '100' 03-Nov-2015 08:19:42.711826 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '4' has value '0' 03-Nov-2015 08:19:42.711832 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '5' has value '1' 03-Nov-2015 08:19:42.711837 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '6' has value '0' 03-Nov-2015 08:19:42.711843 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '7' has value '1' 03-Nov-2015 08:19:42.711848 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '8' has value '1' 03-Nov-2015 08:19:42.711854 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '9' has value '31536000' 03-Nov-2015 08:19:42.711860 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '10' has value '0' 03-Nov-2015 08:19:42.711865 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '11' has value '0' 03-Nov-2015 08:19:42.711871 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '12' has value '0' 03-Nov-2015 08:19:42.711877 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '13' has value '53687091200' 03-Nov-2015 08:19:42.711882 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '14' has value 'Backup' 03-Nov-2015 08:19:42.711888 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '15' has value '0' 03-Nov-2015 08:19:42.711894 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '16' has value 'VirtualFull-' 03-Nov-2015 08:19:42.711900 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '17' has value '0' 03-Nov-2015 08:19:42.711905 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '18' has value '0' 03-Nov-2015 08:19:42.711911 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '19' has value '0' 03-Nov-2015 08:19:42.711917 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '20' has value '0' 03-Nov-2015 08:19:42.711922 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '21' has value '0' 03-Nov-2015 08:19:42.711928 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d864f8 03-Nov-2015 08:19:42.711941 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=8' 03-Nov-2015 08:19:42.722976 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.722988 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.722994 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.722999 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.723005 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.723010 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.723017 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.723023 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.723028 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.723038 bareos-dir (400): sql_get.c:666-0 Actual NumVols=0 Pool NumVols=0 03-Nov-2015 08:19:42.723055 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=8' 03-Nov-2015 08:19:42.723214 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.723221 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.723226 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.723232 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.723237 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.723242 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.723248 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.723254 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.723260 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.723266 bareos-dir (400): sql_update.c:265-0 NumVols=0 03-Nov-2015 08:19:42.723279 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Pool SET NumVols=0,MaxVols=100,UseOnce=0,UseCatalog=1,AcceptAnyVolume=0,VolRetention='31536000',VolUseDuration='0',MaxVolJobs=0,MaxVolFiles=0,MaxVolBytes=53687091200,Recycle=1,AutoPrune=1,LabelType=0,LabelFormat='VirtualFull-',RecyclePoolId=0,ScratchPoolId=0,ActionOnPurge=0,MinBlockSize=0,MaxBlockSize=0 WHERE PoolId=8' 03-Nov-2015 08:19:42.725363 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.725376 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.725381 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.725387 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.725399 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='Full'' 03-Nov-2015 08:19:42.725595 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.725601 bareos-dir (500): postgresql.c:655-0 we have 22 fields 03-Nov-2015 08:19:42.725607 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.725612 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.725618 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.725623 bareos-dir (500): postgresql.c:758-0 we need space for 176 bytes 03-Nov-2015 08:19:42.725629 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.725636 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '1' 03-Nov-2015 08:19:42.725641 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value 'Full' 03-Nov-2015 08:19:42.725647 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '2' has value '64' 03-Nov-2015 08:19:42.725653 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '3' has value '100' 03-Nov-2015 08:19:42.725659 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '4' has value '0' 03-Nov-2015 08:19:42.725664 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '5' has value '1' 03-Nov-2015 08:19:42.725670 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '6' has value '0' 03-Nov-2015 08:19:42.725676 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '7' has value '1' 03-Nov-2015 08:19:42.725682 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '8' has value '1' 03-Nov-2015 08:19:42.725687 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '9' has value '31536000' 03-Nov-2015 08:19:42.725693 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '10' has value '0' 03-Nov-2015 08:19:42.725699 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '11' has value '0' 03-Nov-2015 08:19:42.725705 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '12' has value '0' 03-Nov-2015 08:19:42.725710 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '13' has value '53687091200' 03-Nov-2015 08:19:42.725716 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '14' has value 'Backup' 03-Nov-2015 08:19:42.725722 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '15' has value '0' 03-Nov-2015 08:19:42.725728 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '16' has value 'Full-' 03-Nov-2015 08:19:42.725734 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '17' has value '0' 03-Nov-2015 08:19:42.725739 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '18' has value '0' 03-Nov-2015 08:19:42.725745 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '19' has value '0' 03-Nov-2015 08:19:42.725751 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '20' has value '0' 03-Nov-2015 08:19:42.725757 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '21' has value '0' 03-Nov-2015 08:19:42.725762 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d864f8 03-Nov-2015 08:19:42.725792 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=1' 03-Nov-2015 08:19:42.725939 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.725947 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.725953 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.725959 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.725964 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.725970 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.725976 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.725982 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '64' 03-Nov-2015 08:19:42.725988 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.725995 bareos-dir (400): sql_get.c:666-0 Actual NumVols=64 Pool NumVols=64 03-Nov-2015 08:19:42.726003 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=1' 03-Nov-2015 08:19:42.726126 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.726132 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.726138 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.726143 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.726149 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.726155 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.726160 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.726166 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '64' 03-Nov-2015 08:19:42.726172 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.726179 bareos-dir (400): sql_update.c:265-0 NumVols=64 03-Nov-2015 08:19:42.726188 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Pool SET NumVols=64,MaxVols=100,UseOnce=0,UseCatalog=1,AcceptAnyVolume=0,VolRetention='31536000',VolUseDuration='0',MaxVolJobs=0,MaxVolFiles=0,MaxVolBytes=53687091200,Recycle=1,AutoPrune=1,LabelType=0,LabelFormat='Full-',RecyclePoolId=0,ScratchPoolId=0,ActionOnPurge=0,MinBlockSize=0,MaxBlockSize=0 WHERE PoolId=1' 03-Nov-2015 08:19:42.726496 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.726504 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.726509 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.726515 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.726524 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='Scratch'' 03-Nov-2015 08:19:42.726716 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.726723 bareos-dir (500): postgresql.c:655-0 we have 22 fields 03-Nov-2015 08:19:42.726728 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.726734 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.726739 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.726745 bareos-dir (500): postgresql.c:758-0 we need space for 176 bytes 03-Nov-2015 08:19:42.726751 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.726757 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '4' 03-Nov-2015 08:19:42.726763 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value 'Scratch' 03-Nov-2015 08:19:42.726769 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '2' has value '0' 03-Nov-2015 08:19:42.726785 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '3' has value '0' 03-Nov-2015 08:19:42.726792 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '4' has value '0' 03-Nov-2015 08:19:42.726798 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '5' has value '1' 03-Nov-2015 08:19:42.726807 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '6' has value '0' 03-Nov-2015 08:19:42.726815 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '7' has value '1' 03-Nov-2015 08:19:42.726821 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '8' has value '1' 03-Nov-2015 08:19:42.726827 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '9' has value '31536000' 03-Nov-2015 08:19:42.726833 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '10' has value '0' 03-Nov-2015 08:19:42.726839 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '11' has value '0' 03-Nov-2015 08:19:42.726845 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '12' has value '0' 03-Nov-2015 08:19:42.726850 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '13' has value '0' 03-Nov-2015 08:19:42.726856 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '14' has value 'Backup' 03-Nov-2015 08:19:42.726862 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '15' has value '0' 03-Nov-2015 08:19:42.726869 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '16' has value '' 03-Nov-2015 08:19:42.726875 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '17' has value '0' 03-Nov-2015 08:19:42.726883 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '18' has value '0' 03-Nov-2015 08:19:42.726889 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '19' has value '0' 03-Nov-2015 08:19:42.726895 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '20' has value '0' 03-Nov-2015 08:19:42.726901 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '21' has value '0' 03-Nov-2015 08:19:42.726907 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d864f8 03-Nov-2015 08:19:42.726915 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=4' 03-Nov-2015 08:19:42.727125 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.727146 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.727154 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.727160 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.727166 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.727172 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.727179 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.727185 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.727191 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.727200 bareos-dir (400): sql_get.c:666-0 Actual NumVols=0 Pool NumVols=0 03-Nov-2015 08:19:42.727211 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=4' 03-Nov-2015 08:19:42.727408 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.727414 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.727420 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.727425 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.727431 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.727436 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.727442 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.727448 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.727454 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.727461 bareos-dir (400): sql_update.c:265-0 NumVols=0 03-Nov-2015 08:19:42.727470 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Pool SET NumVols=0,MaxVols=0,UseOnce=0,UseCatalog=1,AcceptAnyVolume=0,VolRetention='31536000',VolUseDuration='0',MaxVolJobs=0,MaxVolFiles=0,MaxVolBytes=0,Recycle=1,AutoPrune=1,LabelType=0,LabelFormat='',RecyclePoolId=0,ScratchPoolId=0,ActionOnPurge=0,MinBlockSize=0,MaxBlockSize=0 WHERE PoolId=4' 03-Nov-2015 08:19:42.727966 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.727979 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.727985 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.727991 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.728002 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='LTO6'' 03-Nov-2015 08:19:42.728204 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.728210 bareos-dir (500): postgresql.c:655-0 we have 22 fields 03-Nov-2015 08:19:42.728216 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.728222 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.728227 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.728233 bareos-dir (500): postgresql.c:758-0 we need space for 176 bytes 03-Nov-2015 08:19:42.728240 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.728246 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '6' 03-Nov-2015 08:19:42.728252 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value 'LTO6' 03-Nov-2015 08:19:42.728258 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '2' has value '0' 03-Nov-2015 08:19:42.728263 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '3' has value '0' 03-Nov-2015 08:19:42.728269 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '4' has value '0' 03-Nov-2015 08:19:42.728275 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '5' has value '1' 03-Nov-2015 08:19:42.728281 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '6' has value '0' 03-Nov-2015 08:19:42.728287 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '7' has value '1' 03-Nov-2015 08:19:42.728293 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '8' has value '1' 03-Nov-2015 08:19:42.728299 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '9' has value '31536000' 03-Nov-2015 08:19:42.728304 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '10' has value '0' 03-Nov-2015 08:19:42.728310 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '11' has value '0' 03-Nov-2015 08:19:42.728316 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '12' has value '0' 03-Nov-2015 08:19:42.728322 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '13' has value '0' 03-Nov-2015 08:19:42.728328 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '14' has value 'Backup' 03-Nov-2015 08:19:42.728334 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '15' has value '0' 03-Nov-2015 08:19:42.728340 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '16' has value '' 03-Nov-2015 08:19:42.728346 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '17' has value '0' 03-Nov-2015 08:19:42.728351 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '18' has value '0' 03-Nov-2015 08:19:42.728357 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '19' has value '0' 03-Nov-2015 08:19:42.728363 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '20' has value '0' 03-Nov-2015 08:19:42.728369 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '21' has value '0' 03-Nov-2015 08:19:42.728375 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d864f8 03-Nov-2015 08:19:42.728383 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=6' 03-Nov-2015 08:19:42.728513 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.728520 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.728526 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.728531 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.728537 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.728543 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.728549 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.728555 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.728561 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.728568 bareos-dir (400): sql_get.c:666-0 Actual NumVols=0 Pool NumVols=0 03-Nov-2015 08:19:42.728576 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=6' 03-Nov-2015 08:19:42.728690 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.728697 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.728703 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.728708 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.728714 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.728720 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.728726 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.728732 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.728738 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.728745 bareos-dir (400): sql_update.c:265-0 NumVols=0 03-Nov-2015 08:19:42.728754 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Pool SET NumVols=0,MaxVols=0,UseOnce=0,UseCatalog=1,AcceptAnyVolume=0,VolRetention='31536000',VolUseDuration='0',MaxVolJobs=0,MaxVolFiles=0,MaxVolBytes=0,Recycle=1,AutoPrune=1,LabelType=0,LabelFormat='',RecyclePoolId=0,ScratchPoolId=0,ActionOnPurge=0,MinBlockSize=0,MaxBlockSize=0 WHERE PoolId=6' 03-Nov-2015 08:19:42.729054 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.729063 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.729069 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.729075 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.729084 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT PoolId,Name,NumVols,MaxVols,UseOnce,UseCatalog,AcceptAnyVolume,AutoPrune,Recycle,VolRetention,VolUseDuration,MaxVolJobs,MaxVolFiles,MaxVolBytes,PoolType,LabelType,LabelFormat,RecyclePoolId,ScratchPoolId,ActionOnPurge,MinBlocksize,MaxBlocksize FROM Pool WHERE Pool.Name='LTO3'' 03-Nov-2015 08:19:42.729279 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.729287 bareos-dir (500): postgresql.c:655-0 we have 22 fields 03-Nov-2015 08:19:42.729293 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.729299 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.729304 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.729310 bareos-dir (500): postgresql.c:758-0 we need space for 176 bytes 03-Nov-2015 08:19:42.729316 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.729322 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '7' 03-Nov-2015 08:19:42.729329 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value 'LTO3' 03-Nov-2015 08:19:42.729335 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '2' has value '0' 03-Nov-2015 08:19:42.729341 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '3' has value '0' 03-Nov-2015 08:19:42.729347 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '4' has value '0' 03-Nov-2015 08:19:42.729353 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '5' has value '1' 03-Nov-2015 08:19:42.729359 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '6' has value '0' 03-Nov-2015 08:19:42.729364 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '7' has value '1' 03-Nov-2015 08:19:42.729370 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '8' has value '1' 03-Nov-2015 08:19:42.729376 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '9' has value '31536000' 03-Nov-2015 08:19:42.729383 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '10' has value '0' 03-Nov-2015 08:19:42.729389 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '11' has value '0' 03-Nov-2015 08:19:42.729395 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '12' has value '0' 03-Nov-2015 08:19:42.729401 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '13' has value '0' 03-Nov-2015 08:19:42.729407 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '14' has value 'Backup' 03-Nov-2015 08:19:42.729413 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '15' has value '0' 03-Nov-2015 08:19:42.729418 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '16' has value '' 03-Nov-2015 08:19:42.729424 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '17' has value '0' 03-Nov-2015 08:19:42.729430 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '18' has value '0' 03-Nov-2015 08:19:42.729436 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '19' has value '0' 03-Nov-2015 08:19:42.729442 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '20' has value '0' 03-Nov-2015 08:19:42.729448 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '21' has value '0' 03-Nov-2015 08:19:42.729454 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d864f8 03-Nov-2015 08:19:42.729462 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=7' 03-Nov-2015 08:19:42.729586 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.729592 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.729598 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.729604 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.729609 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.729615 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.729621 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.729627 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.729633 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.729640 bareos-dir (400): sql_get.c:666-0 Actual NumVols=0 Pool NumVols=0 03-Nov-2015 08:19:42.729647 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT count() from Media WHERE PoolId=7' 03-Nov-2015 08:19:42.729763 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.729818 bareos-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.729825 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.729837 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.729842 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.729848 bareos-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.729854 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.729861 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '0' 03-Nov-2015 08:19:42.729866 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.729873 bareos-dir (400): sql_update.c:265-0 NumVols=0 03-Nov-2015 08:19:42.729882 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Pool SET NumVols=0,MaxVols=0,UseOnce=0,UseCatalog=1,AcceptAnyVolume=0,VolRetention='31536000',VolUseDuration='0',MaxVolJobs=0,MaxVolFiles=0,MaxVolBytes=0,Recycle=1,AutoPrune=1,LabelType=0,LabelFormat='',RecyclePoolId=0,ScratchPoolId=0,ActionOnPurge=0,MinBlockSize=0,MaxBlockSize=0 WHERE PoolId=7' 03-Nov-2015 08:19:42.730191 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.730199 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.730204 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.730210 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.730218 bareos-dir (500): dird.c:1138-0 create cat=MyCatalog for client=backup1-fd 03-Nov-2015 08:19:42.730232 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT ClientId,Uname FROM Client WHERE Name='backup1-fd'' 03-Nov-2015 08:19:42.739681 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.739694 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.739700 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.739705 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.739711 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.739716 bareos-dir (500): postgresql.c:758-0 we need space for 16 bytes 03-Nov-2015 08:19:42.739723 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.739729 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '4' 03-Nov-2015 08:19:42.739735 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value '15.2.1 (24aug15) x86_64-redhat-linux-gnu,redhat,CentOS release 6.6 (Final),CentOS_6,x86_64' 03-Nov-2015 08:19:42.739741 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.739750 bareos-dir (500): dird.c:1138-0 create cat=MyCatalog for client=tecnet1-fd 03-Nov-2015 08:19:42.739758 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT ClientId,Uname FROM Client WHERE Name='tecnet1-fd'' 03-Nov-2015 08:19:42.739875 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.739883 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.739888 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.739894 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.739899 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.739905 bareos-dir (500): postgresql.c:758-0 we need space for 16 bytes 03-Nov-2015 08:19:42.739910 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.739916 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '2' 03-Nov-2015 08:19:42.739922 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value '15.4.0 (03oct15) sparc-sun-solaris2.11,solaris,5.11' 03-Nov-2015 08:19:42.739928 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7c118 03-Nov-2015 08:19:42.739935 bareos-dir (500): dird.c:1138-0 create cat=MyCatalog for client=ys-fd 03-Nov-2015 08:19:42.739942 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT ClientId,Uname FROM Client WHERE Name='ys-fd'' 03-Nov-2015 08:19:42.740024 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.740030 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.740036 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.740041 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.740046 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.740052 bareos-dir (500): postgresql.c:758-0 we need space for 16 bytes 03-Nov-2015 08:19:42.740057 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.740063 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '3' 03-Nov-2015 08:19:42.740069 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value '15.4.0 (03oct15) sparc-sun-solaris2.10,solaris,5.10' 03-Nov-2015 08:19:42.740075 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.740087 bareos-dir (200): sql_create.c:385-0 In create mediatype 03-Nov-2015 08:19:42.740094 bareos-dir (200): sql_create.c:389-0 selectmediatype: SELECT MediaTypeId,MediaType FROM MediaType WHERE MediaType='File' 03-Nov-2015 08:19:42.740100 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT MediaTypeId,MediaType FROM MediaType WHERE MediaType='File'' 03-Nov-2015 08:19:42.740856 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.740869 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.740876 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.740882 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.740911 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT StorageId,AutoChanger FROM Storage WHERE Name='File'' 03-Nov-2015 08:19:42.751248 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.751260 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.751266 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.751271 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.751277 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.751282 bareos-dir (500): postgresql.c:758-0 we need space for 16 bytes 03-Nov-2015 08:19:42.751288 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.751294 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '1' 03-Nov-2015 08:19:42.751300 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value '0' 03-Nov-2015 08:19:42.751306 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.751323 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Storage SET AutoChanger=0 WHERE StorageId=1' 03-Nov-2015 08:19:42.751602 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.751608 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.751614 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.751619 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.751626 bareos-dir (200): sql_create.c:385-0 In create mediatype 03-Nov-2015 08:19:42.751633 bareos-dir (200): sql_create.c:389-0 selectmediatype: SELECT MediaTypeId,MediaType FROM MediaType WHERE MediaType='tape' 03-Nov-2015 08:19:42.751639 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT MediaTypeId,MediaType FROM MediaType WHERE MediaType='tape'' 03-Nov-2015 08:19:42.751729 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.751736 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.751741 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.751746 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.751758 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT StorageId,AutoChanger FROM Storage WHERE Name='TL1000'' 03-Nov-2015 08:19:42.751839 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.751846 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.751851 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.751857 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.751863 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.751869 bareos-dir (500): postgresql.c:758-0 we need space for 16 bytes 03-Nov-2015 08:19:42.751877 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.751883 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '2' 03-Nov-2015 08:19:42.751889 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value '0' 03-Nov-2015 08:19:42.751895 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.751903 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Storage SET AutoChanger=0 WHERE StorageId=2' 03-Nov-2015 08:19:42.752159 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.752165 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.752171 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.752176 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.752183 bareos-dir (200): sql_create.c:385-0 In create mediatype 03-Nov-2015 08:19:42.752189 bareos-dir (200): sql_create.c:389-0 selectmediatype: SELECT MediaTypeId,MediaType FROM MediaType WHERE MediaType='tape' 03-Nov-2015 08:19:42.752195 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT MediaTypeId,MediaType FROM MediaType WHERE MediaType='tape'' 03-Nov-2015 08:19:42.752288 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.752294 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.752299 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.752305 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.752315 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT StorageId,AutoChanger FROM Storage WHERE Name='PV124T'' 03-Nov-2015 08:19:42.752389 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.752396 bareos-dir (500): postgresql.c:655-0 we have 2 fields 03-Nov-2015 08:19:42.752401 bareos-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.752406 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.752412 bareos-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.752417 bareos-dir (500): postgresql.c:758-0 we need space for 16 bytes 03-Nov-2015 08:19:42.752423 bareos-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.752429 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '3' 03-Nov-2015 08:19:42.752434 bareos-dir (500): postgresql.c:778-0 sql_fetch_row field '1' has value '0' 03-Nov-2015 08:19:42.752440 bareos-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning d7bf88 03-Nov-2015 08:19:42.752447 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Storage SET AutoChanger=0 WHERE StorageId=3' 03-Nov-2015 08:19:42.752619 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.752625 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.752631 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.752636 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.752644 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Job SET JobStatus='f', StartTime=SchedTime, EndTime=SchedTime WHERE JobStatus = 'C'' 03-Nov-2015 08:19:42.767238 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.767250 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.767256 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.767261 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.767268 bareos-dir (500): postgresql.c:622-0 sql_query starts with 'UPDATE Job SET JobStatus='f', EndTime=StartTime WHERE JobStatus = 'R'' 03-Nov-2015 08:19:42.767564 bareos-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.767570 bareos-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.767576 bareos-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.767581 bareos-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.767854 backup1-dir (500): dird.c:1272-0 Skipped: . 03-Nov-2015 08:19:42.767863 backup1-dir (500): dird.c:1272-0 Skipped: .. 03-Nov-2015 08:19:42.767871 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.24569464.mail 03-Nov-2015 08:19:42.767878 backup1-dir (500): dird.c:1272-0 Skipped: ys-fd.bsr 03-Nov-2015 08:19:42.767883 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.8606408.mail 03-Nov-2015 08:19:42.767889 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.18526072.mail 03-Nov-2015 08:19:42.767895 backup1-dir (500): dird.c:1272-0 Skipped: amanda1-dir.conmsg 03-Nov-2015 08:19:42.767901 backup1-dir (500): dird.c:1272-0 Skipped: mtx.err.we0OBFayVT 03-Nov-2015 08:19:42.767907 backup1-dir (500): dird.c:1272-0 Skipped: bareos.23848.traceback 03-Nov-2015 08:19:42.767912 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.core.8138 03-Nov-2015 08:19:42.767918 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.23030680.mail 03-Nov-2015 08:19:42.767924 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.29573848.mail 03-Nov-2015 08:19:42.767930 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.17182728.mail 03-Nov-2015 08:19:42.767936 backup1-dir (500): dird.c:1272-0 Skipped: amanda1-fd.bsr 03-Nov-2015 08:19:42.767941 backup1-dir (500): dird.c:1272-0 Skipped: bareos.30510.traceback 03-Nov-2015 08:19:42.767947 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.36474360.mail 03-Nov-2015 08:19:42.767953 backup1-dir (500): dird.c:1272-0 Skipped: bareos.26493.traceback 03-Nov-2015 08:19:42.767958 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.8991688.mail 03-Nov-2015 08:19:42.767964 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.26170056.mail 03-Nov-2015 08:19:42.767970 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.33415096.mail 03-Nov-2015 08:19:42.767976 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.25120680.mail 03-Nov-2015 08:19:42.767982 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.14048088.mail 03-Nov-2015 08:19:42.767987 backup1-dir (500): dird.c:1272-0 Skipped: bareos-sd.9103.pid 03-Nov-2015 08:19:42.768025 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.11646904.mail 03-Nov-2015 08:19:42.768032 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.32619352.mail 03-Nov-2015 08:19:42.768038 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.15757320.mail 03-Nov-2015 08:19:42.768044 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.16386120.mail 03-Nov-2015 08:19:42.768050 backup1-dir (500): dird.c:1272-0 Skipped: bareos.15666.traceback 03-Nov-2015 08:19:42.768055 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.9101.pid 03-Nov-2015 08:19:42.768061 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.14918744.mail 03-Nov-2015 08:19:42.768067 backup1-dir (500): dird.c:1272-0 Skipped: bareos-fd.9102.pid 03-Nov-2015 08:19:42.768073 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.31184936.mail 03-Nov-2015 08:19:42.768081 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.35701944.mail 03-Nov-2015 08:19:42.768087 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.20778920.mail 03-Nov-2015 08:19:42.768093 backup1-dir (500): dird.c:1272-0 Skipped: bareos-sd.9103.state 03-Nov-2015 08:19:42.768099 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.26664840.mail 03-Nov-2015 08:19:42.768104 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.8724488.mail 03-Nov-2015 08:19:42.768110 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.core.23848 03-Nov-2015 08:19:42.768116 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.10957704.mail 03-Nov-2015 08:19:42.768122 backup1-dir (500): dird.c:1272-0 Skipped: .psql_history 03-Nov-2015 08:19:42.768151 backup1-dir (100): dird.c:1280-0 Unlink: /var/lib/bareos/backup1-dir.BackupHexen.2015-11-02_18.00.00_04.30035112.mail 03-Nov-2015 08:19:42.768212 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.15083352.mail 03-Nov-2015 08:19:42.768218 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.33268296.mail 03-Nov-2015 08:19:42.768228 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.21995528.mail 03-Nov-2015 08:19:42.768234 backup1-dir (500): dird.c:1272-0 Skipped: bareos.8138.traceback 03-Nov-2015 08:19:42.768240 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.33031976.mail 03-Nov-2015 08:19:42.768246 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.33293016.mail 03-Nov-2015 08:19:42.768252 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.core.26493 03-Nov-2015 08:19:42.768258 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.30039560.mail 03-Nov-2015 08:19:42.768263 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.39956088.mail 03-Nov-2015 08:19:42.768272 backup1-dir (500): dird.c:1272-0 Skipped: bareos-fd.9102.state 03-Nov-2015 08:19:42.768278 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.20095768.mail 03-Nov-2015 08:19:42.768284 backup1-dir (500): dird.c:1272-0 Skipped: bareos.26841.traceback 03-Nov-2015 08:19:42.768290 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.37679032.mail 03-Nov-2015 08:19:42.768296 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.28341016.mail 03-Nov-2015 08:19:42.768302 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.15079752.mail 03-Nov-2015 08:19:42.768308 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.22717320.mail 03-Nov-2015 08:19:42.768314 backup1-dir (500): dird.c:1272-0 Skipped: mtx.err.MUbIYYGzZ7 03-Nov-2015 08:19:42.768320 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.17847384.mail 03-Nov-2015 08:19:42.768325 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.12890696.mail 03-Nov-2015 08:19:42.768331 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.27567576.mail 03-Nov-2015 08:19:42.768337 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.19554168.mail 03-Nov-2015 08:19:42.768343 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.39161960.mail 03-Nov-2015 08:19:42.768349 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.28439112.mail 03-Nov-2015 08:19:42.768355 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.14062648.mail 03-Nov-2015 08:19:42.768361 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.36405272.mail 03-Nov-2015 08:19:42.768370 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.18424392.mail 03-Nov-2015 08:19:42.768376 backup1-dir (500): dird.c:1272-0 Skipped: tecnet1-fd.bsr 03-Nov-2015 08:19:42.768382 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.9883576.mail 03-Nov-2015 08:19:42.768388 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.33219384.mail 03-Nov-2015 08:19:42.768394 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.core.26841 03-Nov-2015 08:19:42.768828 backup1-dir (500): dird.c:1272-0 Skipped: bareos.4667.traceback 03-Nov-2015 08:19:42.768851 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.14486040.mail 03-Nov-2015 08:19:42.768858 backup1-dir (500): dird.c:1272-0 Skipped: backup1-fd.bsr 03-Nov-2015 08:19:42.768864 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.17257240.mail 03-Nov-2015 08:19:42.768870 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.39277656.mail 03-Nov-2015 08:19:42.768876 backup1-dir (500): dird.c:1272-0 Skipped: bareos.2524.traceback 03-Nov-2015 08:19:42.768881 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.30269304.mail 03-Nov-2015 08:19:42.768887 backup1-dir (500): dird.c:1272-0 Skipped: amanda1-dir.BackupYs.2015-10-20_21.00.00_05.32740328.mail 03-Nov-2015 08:19:42.768893 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.32164440.mail 03-Nov-2015 08:19:42.768899 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.13005704.mail 03-Nov-2015 08:19:42.768907 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.8101912.mail 03-Nov-2015 08:19:42.768914 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.35039304.mail 03-Nov-2015 08:19:42.768920 backup1-dir (500): dird.c:1272-0 Skipped: mtx.err.RbVc0kbWz7 03-Nov-2015 08:19:42.768926 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.31042392.mail 03-Nov-2015 08:19:42.768932 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.7979128.mail 03-Nov-2015 08:19:42.768938 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.20562888.mail 03-Nov-2015 08:19:42.768947 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.36413448.mail 03-Nov-2015 08:19:42.768953 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.34836408.mail 03-Nov-2015 08:19:42.768958 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.22937464.mail 03-Nov-2015 08:19:42.768967 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.4667.bactrace 03-Nov-2015 08:19:42.768973 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.35746872.mail 03-Nov-2015 08:19:42.768979 backup1-dir (500): dird.c:1272-0 Skipped: storage 03-Nov-2015 08:19:42.768984 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.19848824.mail 03-Nov-2015 08:19:42.768990 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.21570504.mail 03-Nov-2015 08:19:42.768996 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.39583672.mail 03-Nov-2015 08:19:42.769002 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.core.15666 03-Nov-2015 08:19:42.769008 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.39019080.mail 03-Nov-2015 08:19:42.769013 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.24846024.mail 03-Nov-2015 08:19:42.769019 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.32195272.mail 03-Nov-2015 08:19:42.769027 backup1-dir (500): dird.c:1272-0 Skipped: amanda1-dir.30510.bactrace 03-Nov-2015 08:19:42.769033 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.19365800.mail 03-Nov-2015 08:19:42.769044 backup1-dir (500): dird.c:1272-0 Skipped: bareos-dir.bareos-dir.14102408.mail 03-Nov-2015 08:19:42.769113 backup1-dir (200): dird.c:374-0 Start UA server 03-Nov-2015 08:19:42.769283 backup1-dir (100): bnet_server_tcp.c:166-0 Addresses host[ipv4;0.0.0.0;9101] 03-Nov-2015 08:19:42.769301 backup1-dir (100): job.c:1725-0 wstorage=File 03-Nov-2015 08:19:42.769312 backup1-dir (100): job.c:1734-0 wstore=File where=Job resource 03-Nov-2015 08:19:42.769330 backup1-dir (100): job.c:1362-0 JobId=0 created Job=JobMonitor.2015-11-03_08.19.42_01 03-Nov-2015 08:19:42.770053 backup1-dir (200): dird.c:391-0 wait for next job 03-Nov-2015 08:19:42.770071 backup1-dir (200): scheduler.c:98-0 Enter wait_for_next_job 03-Nov-2015 08:19:42.770079 backup1-dir (200): scheduler.c:322-0 enter find_runs() 03-Nov-2015 08:19:42.770103 backup1-dir (200): scheduler.c:338-0 now = 5638c27e: h=8 m=10 md=2 wd=2 wom=0 woy=45 yday=306 03-Nov-2015 08:19:42.770105 backup1-dir (100): job.c:1725-0 wstorage=File 03-Nov-2015 08:19:42.770118 03-Nov-2015 08:19:42.770135 backup1-dir (100): job.c:1734-0 wstore=File where=Job resource backup1-dir (200): scheduler.c:358-0 nh = 5638d08e: h=9 m=10 md=2 wd=2 wom=0 woy=45 yday=306 03-Nov-2015 08:19:42.770162 backup1-dir (100): job.c:1362-0 JobId=0 created Job=StatisticsCollector.2015-11-03_08.19.42_02 03-Nov-2015 08:19:42.770163 03-Nov-2015 08:19:42.770179 backup1-dir (200): scheduler.c:375-0 backup1-dir (100): sql_pooling.c:60-0 db_sql_get_non_pooled_connection allocating 1 new non pooled database connection to database bareos, backend type postgresql Got job: BackupMyself 03-Nov-2015 08:19:42.770197 03-Nov-2015 08:19:42.770203 backup1-dir (200): scheduler.c:420-0 run@d46c78: run_now=0 run_nh=0 backup1-dir (100): cats_backends.c:63-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename dbi, partly_compare = true 03-Nov-2015 08:19:42.770218 backup1-dir (200): scheduler.c:375-0 Got job: BackupHexen 03-Nov-2015 08:19:42.770228 03-Nov-2015 08:19:42.770239 backup1-dir (100): cats_backends.c:63-0 backup1-dir (200): scheduler.c:420-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename mysql, partly_compare = false run@d46c78: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770258 03-Nov-2015 08:19:42.770264 backup1-dir (100): cats_backends.c:63-0 backup1-dir (200): scheduler.c:375-0 db_init_database: Trying to find mapping of given interfacename postgresql to mapping interfacename postgresql, partly_compare = false Got job: BackupMorty 03-Nov-2015 08:19:42.770286 backup1-dir (100): postgresql.c:1229-0 db_init_database first time 03-Nov-2015 08:19:42.770291 backup1-dir (200): scheduler.c:420-0 run@d46c78: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770317 backup1-dir (200): scheduler.c:375-0 Got job: BackupPVE 03-Nov-2015 08:19:42.770324 backup1-dir (200): scheduler.c:420-0 run@d46c78: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770330 backup1-dir (200): scheduler.c:375-0 Got job: BackupTecnet1 03-Nov-2015 08:19:42.770336 backup1-dir (200): scheduler.c:420-0 run@d46c78: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770342 backup1-dir (200): scheduler.c:375-0 Got job: BackupYs 03-Nov-2015 08:19:42.770348 backup1-dir (200): scheduler.c:420-0 run@d46c78: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770353 backup1-dir (200): scheduler.c:375-0 Got job: BackupCatalog 03-Nov-2015 08:19:42.770359 backup1-dir (200): scheduler.c:420-0 run@d46e28: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770367 backup1-dir (200): scheduler.c:375-0 Got job: CopyToLTO6 03-Nov-2015 08:19:42.770373 backup1-dir (200): scheduler.c:420-0 run@d46c78: run_now=0 run_nh=0 03-Nov-2015 08:19:42.770379 backup1-dir (200): scheduler.c:441-0 Leave find_runs() 03-Nov-2015 08:19:42.772251 backup1-dir (50): postgresql.c:239-0 pg_real_connect done 03-Nov-2015 08:19:42.772264 backup1-dir (50): postgresql.c:241-0 db_user=bareos db_name=bareos db_password= 03-Nov-2015 08:19:42.772271 backup1-dir (500): postgresql.c:579-0 db_sql_query starts with 'SELECT VersionId FROM Version' 03-Nov-2015 08:19:42.772278 backup1-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT VersionId FROM Version' 03-Nov-2015 08:19:42.772761 backup1-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.772785 backup1-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.772791 backup1-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.772796 backup1-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.772802 backup1-dir (500): postgresql.c:589-0 db_sql_query succeeded. checking handler 03-Nov-2015 08:19:42.772809 backup1-dir (500): postgresql.c:592-0 db_sql_query invoking handler 03-Nov-2015 08:19:42.772815 backup1-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.772821 backup1-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.772829 backup1-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.772836 backup1-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value '2004' 03-Nov-2015 08:19:42.772842 backup1-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning 7f6fd000bcd8 03-Nov-2015 08:19:42.772849 backup1-dir (500): postgresql.c:594-0 db_sql_query sql_fetch_row worked 03-Nov-2015 08:19:42.772855 backup1-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.772861 backup1-dir (500): postgresql.c:786-0 sql_fetch_row row number '1' is NOT acceptable (0..1) 03-Nov-2015 08:19:42.772866 backup1-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning 0 03-Nov-2015 08:19:42.772874 backup1-dir (500): postgresql.c:601-0 db_sql_query finished 03-Nov-2015 08:19:42.772880 backup1-dir (500): postgresql.c:622-0 sql_query starts with 'SET datestyle TO 'ISO, YMD'' 03-Nov-2015 08:19:42.773046 backup1-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.773060 backup1-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.773066 backup1-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.773072 backup1-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.773077 backup1-dir (500): postgresql.c:622-0 sql_query starts with 'SET cursor_tuple_fraction=1' 03-Nov-2015 08:19:42.773173 backup1-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.773179 backup1-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.773185 backup1-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.773190 backup1-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.773196 backup1-dir (500): postgresql.c:622-0 sql_query starts with 'SET standard_conforming_strings=on' 03-Nov-2015 08:19:42.773257 backup1-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.773272 backup1-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.773279 backup1-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.773286 backup1-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.773292 backup1-dir (500): postgresql.c:622-0 sql_query starts with 'SELECT getdatabaseencoding()' 03-Nov-2015 08:19:42.773458 backup1-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.773468 backup1-dir (500): postgresql.c:655-0 we have 1 fields 03-Nov-2015 08:19:42.773474 backup1-dir (500): postgresql.c:658-0 we have 1 rows 03-Nov-2015 08:19:42.773479 backup1-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.773485 backup1-dir (500): postgresql.c:746-0 sql_fetch_row start 03-Nov-2015 08:19:42.773491 backup1-dir (500): postgresql.c:758-0 we need space for 8 bytes 03-Nov-2015 08:19:42.773498 backup1-dir (500): postgresql.c:772-0 sql_fetch_row row number '0' is acceptable (0..1) 03-Nov-2015 08:19:42.773504 backup1-dir (500): postgresql.c:778-0 sql_fetch_row field '0' has value 'SQL_ASCII' 03-Nov-2015 08:19:42.773510 backup1-dir (500): postgresql.c:789-0 sql_fetch_row finishes returning 7f6fd000bb18 03-Nov-2015 08:19:42.773517 backup1-dir (500): postgresql.c:622-0 sql_query starts with 'SET client_encoding TO 'SQL_ASCII'' 03-Nov-2015 08:19:42.773571 backup1-dir (500): postgresql.c:649-0 we have a result 03-Nov-2015 08:19:42.773578 backup1-dir (500): postgresql.c:655-0 we have 0 fields 03-Nov-2015 08:19:42.773583 backup1-dir (500): postgresql.c:658-0 we have 0 rows 03-Nov-2015 08:19:42.773589 backup1-dir (500): postgresql.c:709-0 sql_query finishing 03-Nov-2015 08:19:42.773595 backup1-dir (200): stats.c:164-0 statistics_thread_runner: Doing work at 1446560382 03-Nov-2015 08:19:42.773607 backup1-dir (200): stats.c:178-0 statistics_thread_runner: flushing pending statistics 03-Nov-2015 08:19:47.340202 backup1-dir (110): socket_server.c:73-0 Conn: Hello UserAgent calling 03-Nov-2015 08:19:47.340244 backup1-dir (100): job.c:1725-0 wstorage=File 03-Nov-2015 08:19:47.340252 backup1-dir (100): job.c:1734-0 wstore=File where=Job resource 03-Nov-2015 08:19:47.340265 backup1-dir (100): job.c:1362-0 JobId=0 created Job=-Console-.2015-11-03_08.19.47_03 03-Nov-2015 08:19:47.340494 backup1-dir (50): cram-md5.c:68-0 send: auth cram-md5 <108108180.1446560387@backup1-dir> ssl=0 03-Nov-2015 08:19:47.340624 backup1-dir (100): cram-md5.c:123-0 cram-get received: auth cram-md5 <266312514.1446560387@bconsole> ssl=0 03-Nov-2015 08:19:47.340650 backup1-dir (99): cram-md5.c:143-0 sending resp to challenge: s4+4Cl/kB4/QF+Nqv7+X/B 03-Nov-2015 08:19:56.132592 backup1-dir (120): ua_cmds.c:1323-0 setdebug:setdebug director level=500 trace=1: BAREOS interrupted by signal 11: Segmentation violation Kaboom! bareos-dir, backup1-dir got signal 11 - Segmentation violation. Attempting traceback. Kaboom! exepath=/root Calling: /root/btraceback /root/bareos-dir 27694 /var/lib/bareos execv: /root/btraceback failed: ERR=Permission denied The btraceback call returned 255 Dumping: /var/lib/bareos/backup1-dir.27694.bactrace ==== bactrace output ==== Attempt to dump locks threadid=0x7f6fd75fe700 max=1 current=-1 threadid=0x7f6fd7fff700 max=2 current=-1 threadid=0x7f6fe5259700 max=2 current=-1 threadid=0x7f6fe5c5a700 max=0 current=-1 threadid=0x7f6fe897c700 max=0 current=-1 threadid=0x7f6ff312b7e0 max=2 current=-1 Attempt to dump current JCRs. njcrs=3 threadid=0x7f6ff312b7e0 JobId=0 JobStatus=R jcr=0xd7e8b8 name=JobMonitor.2015-11-03_08.19.42_01 threadid=0x7f6ff312b7e0 killable=0 JobId=0 JobStatus=R jcr=0xd7e8b8 name=JobMonitor.2015-11-03_08.19.42_01 use_count=1 JobType=I JobLevel= sched_time=03-Nov-2015 08:19 start_time=03-Nov-2015 08:19 end_time=31-Dec-1969 18:00 wait_time=31-Dec-1969 18:00 db=(nil) db_batch=(nil) batch_started=0 threadid=0x7f6fd7fff700 JobId=0 JobStatus=R jcr=0x7f6fd0001148 name=StatisticsCollector.2015-11-03_08.19.42_02 threadid=0x7f6fd7fff700 killable=0 JobId=0 JobStatus=R jcr=0x7f6fd0001148 name=StatisticsCollector.2015-11-03_08.19.42_02 use_count=1 JobType=I JobLevel= sched_time=03-Nov-2015 08:19 start_time=03-Nov-2015 08:19 end_time=31-Dec-1969 18:00 wait_time=31-Dec-1969 18:00 db=0x7f6fd0002a88 db_batch=(nil) batch_started=0 B_DB=0x7f6fd0002a88 db_name=bareos db_user=bareos connected=true cmd="db_init_database first time " changes=0 RWLOCK=0x7f6fd0002a90 w_active=0 w_wait=0 threadid=0x7f6fd75fe700 JobId=0 JobStatus=R jcr=0x7f6fc8001078 name=-Console-.2015-11-03_08.19.47_03 threadid=0x7f6fd75fe700 killable=0 JobId=0 JobStatus=R jcr=0x7f6fc8001078 name=-Console-.2015-11-03_08.19.47_03 use_count=1 JobType=U JobLevel= sched_time=03-Nov-2015 08:19 start_time=03-Nov-2015 08:19 end_time=31-Dec-1969 18:00 wait_time=31-Dec-1969 18:00 db=0x7f6fd0002a88 db_batch=(nil) batch_started=0 B_DB=0x7f6fd0002a88 db_name=bareos db_user=bareos connected=true cmd="db_init_database first time " changes=0 RWLOCK=0x7f6fd0002a90 w_active=0 w_wait=0 ==== End baktrace output ==== [root@backup1 ~]#

avantsysadm@avant.ca 2015-11-03 15:24 reporter ~0001908	I'm not sure what other trace file that was supposed to generate... if trace=1 merely generated /var/lib/bareos/backup1-dir.27694.bactrace, it's (in its entirety) at the end of the above output.

avantsysadm@avant.ca 2015-11-03 15:24 reporter ~0001909	Message 4: From root@localhost.ad.avant.ca Tue Nov 3 08:23:49 2015 Return-Path: <root@localhost.ad.avant.ca> X-Original-To: root@localhost Delivered-To: root@localhost.ad.avant.ca From: root@localhost.ad.avant.ca Subject: Bareos GDB traceback of bareos-dir on backup1.ad.avant.ca Sender: bareos@backup1.ad.avant.ca To: root@localhost.ad.avant.ca Date: Tue, 03 Nov 2015 08:23:49 -0600 (CST) Status: R Created /var/lib/bareos/bareos-dir.core.27810 for doing postmortem debugging Missing separate debuginfo for Try: yum --enablerepo='-debug' install /usr/lib/debug/.build-id/fa/be1ca508dff ca0ce7e6bffdc6197edd22e4583 [New Thread 27812] [New Thread 27814] [New Thread 27815] [New Thread 27816] [New Thread 27822] [New Thread 27810] [Thread debugging using libthread_db enabled] Core was generated by `/usr/sbin/bareos-dir -g bareos -c /etc/bareos/bareos-dir. conf'. #0 0x00007fa1ea6f2fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) $1 = '\000' <repeats 127 times> $2 = 0x154e068 "bareos-dir" $3 = 0x154e0a8 "/usr/sbin/bareos-dir" $4 = 0x1585d68 "PostgreSQL" $5 = 0x7fa1eb7f4732 "15.2.1 (24 August 2015)" $6 = 0x7fa1eb7f474a "x86_64-redhat-linux-gnu" $7 = 0x7fa1eb7f4762 "redhat" $8 = 0x7fa1eb7f4769 "CentOS release 6.6 (Final)" $9 = "backup1.ad.avant.ca", '\000' <repeats 236 times> $10 = 0x7fa1eb7f4ca8 "redhat CentOS release 6.6 (Final)" Environment variable "TestName" not defined. #0 0x00007fa1ea6f2fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007fa1eb7c4042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007fa1eb7d4d31 in check_deadlock () at lockmgr.c:566 0000003 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1e214b700) at pthread_create.c: 301 0000004 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 Thread 6 (Thread 0x7fa1ec8fa7e0 (LWP 27810)): #0 0x00007fa1ea6f2fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007fa1eb7c4042 in bmicrosleep (sec=60, usec=0) at bsys.c:171 0000002 0x0000000000444780 in wait_for_next_job (one_shot_job_to_run=<value optimize d out>) at scheduler.c:124 0000003 0x0000000000422435 in main (argc=<value optimized out>, argv=<value optimize d out>) at dird.c:393 Thread 5 (Thread 0x7fa1d9573700 (LWP 27822)): #0 0x00007fa1ea6f332d in __libc_waitpid (pid=<value optimized out>, stat_loc=<v alue optimized out>, options=<value optimized out>) at ../sysdeps/unix/sysv/linu x/waitpid.c:41 0000001 0x00007fa1eb7e44f1 in signal_handler (sig=11) at signal.c:240 0000002 <signal handler called> 0000003 0x00007fa1eb7bf086 in bvsnprintf(char , int32_t, const char , typedef __va _list_tag __va_list_tag ) (buffer=0x7fa126248050 "", maxlen=-1646561203, format =<value optimized out>, args=0x7fa1d9572510) at bsnprintf.c:413 0000004 0x00007fa1eb7bfcb7 in BSOCK::fsend (this=0x7fa1d4001168, fmt=0x48e036 "%s") at bsock.c:216 0000005 0x0000000000453a13 in UAContext::send_msg (this=0x7fa1c4002c58, fmt=0x48e036 "%s") at ua_output.c:1337 0000006 0x0000000000442aa2 in get_volume_name_from_SD (ua=0x7fa1c4002c58, Slot=<valu e optimized out>, drive=<value optimized out>) at sd_cmds.c:195 0000007 0x000000000046f19a in update_slots (ua=0x7fa1c4002c58) at ua_update.c:1084 0000008 0x0000000000471e18 in update_cmd (ua=0x7fa1c4002c58, cmd=<value optimized ou t>) at ua_update.c:106 0000009 0x000000000044a589 in do_a_command (ua=0x7fa1c4002c58) at ua_cmds.c:327 0000010 0x0000000000467a9c in handle_UA_client_request (user=0x7fa1d4001168) at ua_s erver.c:97 0000011 0x000000000043ee5d in handle_connection_request (arg=0x7fa1d4001168) at sock et_server.c:83 0000012 0x00007fa1eb7ee79d in workq_server (arg=0x6a7ba0) at workq.c:335 0000013 0x00007fa1eb7d4c6d in lmgr_thread_launcher (x=0x7fa1d4002618) at lockmgr.c:9 26 0000014 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1d9573700) at pthread_create.c: 301 0000015 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 Thread 4 (Thread 0x7fa1d9f74700 (LWP 27816)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x8 6_64/pthread_cond_timedwait.S:239 0000001 0x00007fa1eb7d3a40 in bthread_cond_timedwait_p (cond=0x6a7e40, m=0x6a7f20, a bstime=0x7fa1d9f73c10, file=0x48410c "stats.c", line=117) at lockmgr.c:811 0000002 0x000000000044596d in wait_for_next_run (arg=<value optimized out>) at stats .c:117 0000003 statistics_thread_runner (arg=<value optimized out>) at stats.c:325 0000004 0x00007fa1eb7d4c6d in lmgr_thread_launcher (x=0x1587c18) at lockmgr.c:926 0000005 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1d9f74700) at pthread_create.c: 301 0000006 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 Thread 3 (Thread 0x7fa1da975700 (LWP 27815)): #0 pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x8 6_64/pthread_cond_timedwait.S:239 0000001 0x00007fa1eb7d3a40 in bthread_cond_timedwait_p (cond=0x7fa1eba08ba0, m=0x7fa 1eba08b60, abstime=0x7fa1da974d60, file=0x7fa1eb7f8d5a "watchdog.c", line=313) a t lockmgr.c:811 0000002 0x00007fa1eb7ee2f8 in watchdog_thread (arg=<value optimized out>) at watchdo g.c:313 0000003 0x00007fa1eb7d4c6d in lmgr_thread_launcher (x=0x1587c18) at lockmgr.c:926 0000004 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1da975700) at pthread_create.c: 301 0000005 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 Thread 2 (Thread 0x7fa1db376700 (LWP 27814)): #0 0x00007fa1e967c113 in __poll (fds=<value optimized out>, nfds=<value optimiz ed out>, timeout=<value optimized out>) at ../sysdeps/unix/sysv/linux/poll.c:87 0000001 0x00007fa1eb7b8206 in bnet_thread_server_tcp (addr_list=0x7fa1d4001168, max_ clients=-617132656, sockfds=0x7fa1d4001078, client_wq=0x6a7ba0, nokeepalive=fals e, handle_client_request=0x1) at bnet_server_tcp.c:298 0000002 0x000000000043edcf in connect_thread (arg=0x15502d8) at socket_server.c:100 0000003 0x00007fa1eb7d4c6d in lmgr_thread_launcher (x=0x1587e78) at lockmgr.c:926 0000004 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1db376700) at pthread_create.c: 301 0000005 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 Thread 1 (Thread 0x7fa1e214b700 (LWP 27812)): #0 0x00007fa1ea6f2fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 0000001 0x00007fa1eb7c4042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 0000002 0x00007fa1eb7d4d31 in check_deadlock () at lockmgr.c:566 0000003 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1e214b700) at pthread_create.c: 301 0000004 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 #0 0x00007fa1ea6f2fbd in nanosleep () at ../sysdeps/unix/syscall-template.S:82 82 T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS) No locals. 0000001 0x00007fa1eb7c4042 in bmicrosleep (sec=30, usec=0) at bsys.c:171 171 status = nanosleep(&timeout, NULL); timeout = {tv_sec = 30, tv_nsec = 0} tv = {tv_sec = 140333259471296, tv_usec = 140333433272565} tz = {tz_minuteswest = -341803296, tz_dsttime = 32673} status = <value optimized out> 0000002 0x00007fa1eb7d4d31 in check_deadlock () at lockmgr.c:566 566 while (!bmicrosleep(30, 0)) { __clframe = {__cancel_routine = 0x7fa1eb7d4820 <cln_hdl(void)>, __cancel_arg = 0x0, __do_it = 1, __cancel_type = <value optimized out>} old = 32673 0000003 0x00007fa1ea6eba51 in start_thread (arg=0x7fa1e214b700) at pthread_create.c: 301 301 THREAD_SETMEM (pd, result, CALL_THREAD_FCT (pd)); __res = <value optimized out> pd = 0x7fa1e214b700 now = <value optimized out> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140333259470592, 2585875960086994091 , 140333401768800, 140333259471296, 0, 3, -2548715964846498645, -254869804684587 0933}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}} not_first_call = <value optimized out> pagesize_m1 = <value optimized out> sp = <value optimized out> freesize = <value optimized out> 0000004 0x00007fa1e968593d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S: 115 115 call *%rax No locals. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available. #0 0x0000000000000000 in ?? () No symbol table info available.

avantsysadm@avant.ca 2015-11-03 16:39 reporter ~0001910	FYI - rebuilding bareos locally from the bareos-15.2 branch and running those binaries allows me to read & label tapes (so far). Weird behaviour in multiple other ways due to differences between my ./configure and the RPM ./configure, but I can probably figure those out eventually...

avantsysadm@avant.ca 2015-11-04 15:11 reporter ~0001911	The nightly builds also work correctly - only the 15.2.1 RPMs crash.

maik 2015-11-06 16:57 administrator ~0001928	Hello, this is probably already fixed, we are going to release a new version of 15.2 RC early next week. Please test it then again.

Date Modified	Username	Field	Change
2015-10-28 18:07	avantsysadm@avant.ca	New Issue
2015-10-28 18:10	avantsysadm@avant.ca	Note Added: 0001893
2015-10-28 18:10	avantsysadm@avant.ca	Note Added: 0001894
2015-10-28 19:32	avantsysadm@avant.ca	Note Added: 0001895
2015-11-03 09:22	pstorz	Note Added: 0001906
2015-11-03 15:22	avantsysadm@avant.ca	Note Added: 0001907
2015-11-03 15:24	avantsysadm@avant.ca	Note Added: 0001908
2015-11-03 15:24	avantsysadm@avant.ca	Note Added: 0001909
2015-11-03 16:39	avantsysadm@avant.ca	Note Added: 0001910
2015-11-04 15:11	avantsysadm@avant.ca	Note Added: 0001911
2015-11-06 16:57	maik	Note Added: 0001928
2015-11-06 16:57	maik	Status	new => feedback
2015-11-06 18:38	maik	Relationship added	child of 0000554
2015-11-26 21:13	mvwieringen	Status	feedback => resolved
2015-11-26 21:13	mvwieringen	Resolution	open => duplicate
2015-11-26 21:13	mvwieringen	Product Version	=> 15.2.2
2015-11-26 21:13	mvwieringen	Fixed in Version	=> 15.2.2
2019-12-18 15:25	arogge	Status	resolved => closed

Reporting new Issues is disabled, please Report new Issues at https://github.com/bareos/bareos/issues

View Issue Details

Relationships

Activities

Issue History