View Issue Details

IDProjectCategoryView StatusLast Update
0000547bareos-core[All Projects] directorpublic2015-11-26 21:13
Reporteravantsysadm@avant.caAssigned To 
PrioritynormalSeveritycrashReproducibilitysometimes
Status resolvedResolutionduplicate 
PlatformLinuxOSCentOSOS Version6
Product Version15.2.2 
Fixed in Version15.2.2 
Summary0000547: 15.2.1-15.1 director crashes when running >1 label job
DescriptionI 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.
TagsNo tags attached.
bareos-master: impact
bareos-master: action
bareos-19.2: impact
bareos-19.2: action
bareos-18.2: impact
bareos-18.2: action
bareos-17.2: impact
bareos-17.2: action
bareos-16.2: impact
bareos-16.2: action
bareos-15.2: impact
bareos-15.2: action
bareos-14.2: impact
bareos-14.2: action
bareos-13.2: impact
bareos-13.2: action
bareos-12.4: impact
bareos-12.4: action

Relationships

child of 0000554 closed Release bareos-15.2.2 

Activities

avantsysadm@avant.ca

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

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

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

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

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

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

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

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

avantsysadm@avant.ca

2015-11-04 15:11

reporter   ~0001911

The nightly builds also work correctly - only the 15.2.1 RPMs crash.
maik

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.

Issue History

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