|
|
|
|
|
|
Can you provide a backtrace for 17.2, too?
Does the SD also crash if you disable statistics?
Thank you! |
|
|
|
|
|
|
|
With disabled statistics, the SD's didn't crash last night.
But the Director does (bareos.254990.traceback).
I'll disable the storage statistics for the next schedule on the director too.
After that I'll try 17.2.7.
Thanks! |
|
|
|
No crashes last night but some errors:
bareos-dir JobId 1161: Fatal error: Unable to authenticate with File daemon at ...
The FD runs on the storage server to backup itself.
Next I'll try 17.2.7 |
|
|
|
17.2.7 crashes too with activated statistics
See bareos.1491023.traceback and bareos.754636.traceback
bareos.1491023.traceback (7,154 bytes)
Created /var/lib/bareos/bareos-sd.core.1491023 for doing postmortem debugging
[New LWP 1491024]
[New LWP 1491026]
[New LWP 1491027]
[New LWP 291841]
[New LWP 1491023]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/bareos-sd'.
#0 0x00007f2777768e3d in nanosleep () from /usr/lib64/libpthread.so.0
$1 = '\000' <repeats 127 times>
$2 = 0xe0d068 "bareos-sd"
$3 = 0xe0d0a8 "/usr/sbin/bareos-sd"
$4 = 0x0
$5 = 0x7f27788f60fc "17.2.7 (16 Jul 2018)"
$6 = 0x7f27788f60e4 "x86_64-redhat-linux-gnu"
$7 = 0x7f27788f60dd "redhat"
$8 = 0x7f27788f65e0 "CentOS Linux release 7.5.1804 (Core) "
$9 = "elbcg1.eurolog.com", '\000' <repeats 237 times>
$10 = 0x7f27788f6608 "redhat CentOS Linux release 7.5.1804 (Core) "
Environment variable "TestName" not defined.
#0 0x00007f2777768e3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007f27788c2254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007f27788d4371 in check_deadlock () at lockmgr.c:568
#3 0x00007f2777761dd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007f2776657ead in clone () from /usr/lib64/libc.so.6
Thread 5 (Thread 0x7f277941d880 (LWP 1491023)):
#0 0x00007f277664d20d in poll () from /usr/lib64/libc.so.6
#1 0x00007f27788b60d1 in bnet_thread_server_tcp (addr_list=<optimized out>, max_clients=<optimized out>, sockfds=<optimized out>, client_wq=client_wq@entry=0x628620 <socket_workq>, nokeepalive=<optimized out>, handle_client_request=handle_client_request@entry=0x419a90 <handle_connection_request(void*)>) at bnet_server_tcp.c:306
#2 0x0000000000419e08 in start_socket_server (addrs=<optimized out>) at socket_server.c:122
#3 0x000000000040913a in main (argc=<optimized out>, argv=<optimized out>) at stored.c:322
Thread 4 (Thread 0x7f276e007700 (LWP 291841)):
#0 0x00007f2777769179 in waitpid () from /usr/lib64/libpthread.so.0
#1 0x00007f27788e58d4 in signal_handler (sig=11) at signal.c:240
#2 <signal handler called>
#3 smart_alloc_msg (file=0x7f27788f9038 "smartall.c", line=line@entry=229, fmt=0x7f27788f9178 "Overrun buffer: len=%d addr=%p allocated: %s:%d called from %s:%d\n", file=0x7f27788f9038 "smartall.c") at smartall.c:113
#4 0x00007f27788e662c in sm_free (file=0x7f27788f5b36 "mem_pool.c", line=257, fp=0x7f27440028c8) at smartall.c:230
#5 0x00007f27788d5bb4 in sm_free_pool_memory (fname=fname@entry=0x7f2778d63591 "block.c", lineno=lineno@entry=178, obuf=0x7f27440028e0 "") at mem_pool.c:257
#6 0x00007f2778d3f31a in free_block (block=<optimized out>) at block.c:178
#7 0x00007f2778d44ee1 in DEVICE::set_blocksizes (this=0x7f2760019a48, dcr=dcr@entry=0x7f2744001078) at dev.c:488
#8 0x00007f2778d4a49c in write_new_volume_label_to_dev (dcr=dcr@entry=0x7f2744001078, VolName=VolName@entry=0x7f2744001190 "IncDemo-0425", PoolName=PoolName@entry=0x7f2744001210 "IncDemo", relabel=relabel@entry=false) at label.c:463
#9 0x00007f2778d4d33c in DCR::try_autolabel (this=0x7f2744001078, opened=<optimized out>) at mount.c:784
#10 0x00007f2778d4e68a in DCR::mount_next_write_volume (this=this@entry=0x7f2744001078) at mount.c:245
#11 0x00007f2778d47944 in fixup_device_block_write_error (dcr=dcr@entry=0x7f2744001078, retries=retries@entry=4) at device.c:120
#12 0x00007f2778d4221b in DCR::write_block_to_device (this=this@entry=0x7f2744001078) at block.c:410
#13 0x00007f2778d51b31 in DCR::write_record (this=this@entry=0x7f2744001078) at record.c:668
#14 0x0000000000409fbd in do_append_data (jcr=jcr@entry=0x7f27440132c8, bs=bs@entry=0x7f2744001a48, what=what@entry=0x41ff9c "FD") at append.c:223
#15 0x00000000004112e4 in append_data_cmd (jcr=0x7f27440132c8) at fd_cmds.c:271
#16 0x00000000004116f9 in do_fd_commands (jcr=0x7f27440132c8) at fd_cmds.c:227
#17 0x0000000000411902 in run_job (jcr=jcr@entry=0x7f27440132c8) at fd_cmds.c:183
#18 0x0000000000412553 in do_job_run (jcr=0x7f27440132c8) at job.c:238
#19 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0xe4d638) at dir_cmd.c:315
#20 0x0000000000419b2b in handle_connection_request (arg=0xe4d638) at socket_server.c:100
#21 0x00007f27788efdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#22 0x00007f27788d43e0 in lmgr_thread_launcher (x=0xe0ed98) at lockmgr.c:928
#23 0x00007f2777761dd5 in start_thread () from /usr/lib64/libpthread.so.0
#24 0x00007f2776657ead in clone () from /usr/lib64/libc.so.6
Thread 3 (Thread 0x7f276d005700 (LWP 1491027)):
#0 0x00007f2777765d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1 0x00007f27788d483c in bthread_cond_timedwait_p (cond=cond@entry=0x628580 <wait_for_next_run>, m=m@entry=0x6285c0 <_ZL5mutex>, abstime=abstime@entry=0x7f276d004d50, file=file@entry=0x421280 "sd_stats.c", line=line@entry=400) at lockmgr.c:813
#2 0x0000000000418ddf in statistics_thread_runner (arg=arg@entry=0x0) at sd_stats.c:400
#3 0x00007f27788d43e0 in lmgr_thread_launcher (x=0xe404e8) at lockmgr.c:928
#4 0x00007f2777761dd5 in start_thread () from /usr/lib64/libpthread.so.0
#5 0x00007f2776657ead in clone () from /usr/lib64/libc.so.6
Thread 2 (Thread 0x7f276d806700 (LWP 1491026)):
#0 0x00007f2777765d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1 0x00007f27788d483c in bthread_cond_timedwait_p (cond=cond@entry=0x7f2778b0d7e0 <_ZL5timer>, m=m@entry=0x7f2778b0d820 <_ZL11timer_mutex>, abstime=abstime@entry=0x7f276d805d40, file=file@entry=0x7f27788faa02 "watchdog.c", line=line@entry=313) at lockmgr.c:813
#2 0x00007f27788ef3c8 in watchdog_thread (arg=arg@entry=0x0) at watchdog.c:313
#3 0x00007f27788d43e0 in lmgr_thread_launcher (x=0xe3fef8) at lockmgr.c:928
#4 0x00007f2777761dd5 in start_thread () from /usr/lib64/libpthread.so.0
#5 0x00007f2776657ead in clone () from /usr/lib64/libc.so.6
Thread 1 (Thread 0x7f276e808700 (LWP 1491024)):
#0 0x00007f2777768e3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007f27788c2254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007f27788d4371 in check_deadlock () at lockmgr.c:568
#3 0x00007f2777761dd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007f2776657ead in clone () from /usr/lib64/libc.so.6
#0 0x00007f2777768e3d in nanosleep () from /usr/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007f27788c2254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
171 status = nanosleep(&timeout, NULL);
timeout = {tv_sec = 30, tv_nsec = 0}
tv = {tv_sec = 0, tv_usec = -4146569487740786944}
tz = {tz_minuteswest = 1744834680, tz_dsttime = 32551}
status = <optimized out>
#2 0x00007f27788d4371 in check_deadlock () at lockmgr.c:568
568 while (!bmicrosleep(30, 0)) {
__clframe = <optimized out>
old = 0
#3 0x00007f2777761dd5 in start_thread () from /usr/lib64/libpthread.so.0
No symbol table info available.
#4 0x00007f2776657ead in clone () from /usr/lib64/libc.so.6
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
bareos.754636.traceback (20,752 bytes)
Created /var/lib/bareos/bareos-sd.core.754636 for doing postmortem debugging
[New LWP 754637]
[New LWP 754639]
[New LWP 754640]
[New LWP 309670]
[New LWP 309674]
[New LWP 310968]
[New LWP 311318]
[New LWP 409423]
[New LWP 414355]
[New LWP 435712]
[New LWP 439429]
[New LWP 462425]
[New LWP 462909]
[New LWP 465701]
[New LWP 754636]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/bareos-sd'.
#0 0x00007ff98a464e3d in nanosleep () from /usr/lib64/libpthread.so.0
$1 = '\000' <repeats 127 times>
$2 = 0x23e7068 "bareos-sd"
$3 = 0x23e70a8 "/usr/sbin/bareos-sd"
$4 = 0x0
$5 = 0x7ff98b5f20fc "17.2.7 (16 Jul 2018)"
$6 = 0x7ff98b5f20e4 "x86_64-redhat-linux-gnu"
$7 = 0x7ff98b5f20dd "redhat"
$8 = 0x7ff98b5f25e0 "CentOS Linux release 7.5.1804 (Core) "
$9 = "elbcg1.eurolog.com", '\000' <repeats 237 times>
$10 = 0x7ff98b5f2608 "redhat CentOS Linux release 7.5.1804 (Core) "
Environment variable "TestName" not defined.
#0 0x00007ff98a464e3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5be254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007ff98b5d0371 in check_deadlock () at lockmgr.c:568
#3 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 15 (Thread 0x7ff98c119880 (LWP 754636)):
#0 0x00007ff98934920d in poll () from /usr/lib64/libc.so.6
#1 0x00007ff98b5b20d1 in bnet_thread_server_tcp (addr_list=<optimized out>, max_clients=<optimized out>, sockfds=<optimized out>, client_wq=client_wq@entry=0x628620 <socket_workq>, nokeepalive=<optimized out>, handle_client_request=handle_client_request@entry=0x419a90 <handle_connection_request(void*)>) at bnet_server_tcp.c:306
#2 0x0000000000419e08 in start_socket_server (addrs=<optimized out>) at socket_server.c:122
#3 0x000000000040913a in main (argc=<optimized out>, argv=<optimized out>) at stored.c:322
Thread 14 (Thread 0x7ff95a7fc700 (LWP 465701)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff960001328, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff960001328) at bsock_tcp.c:550
#3 0x000000000041165d in do_fd_commands (jcr=0x7ff9600008e8) at fd_cmds.c:213
#4 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff9600008e8) at fd_cmds.c:183
#5 0x0000000000412553 in do_job_run (jcr=0x7ff9600008e8) at job.c:238
#6 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x2424168) at dir_cmd.c:315
#7 0x0000000000419b2b in handle_connection_request (arg=0x2424168) at socket_server.c:100
#8 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#9 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2419af8) at lockmgr.c:928
#10 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#11 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 13 (Thread 0x7ff979ffb700 (LWP 462909)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff964004a28, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff964004a28) at bsock_tcp.c:550
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff964004a28) at bget_msg.c:53
#4 0x0000000000409e30 in do_append_data (jcr=jcr@entry=0x7ff9640008e8, bs=bs@entry=0x7ff964004a28, what=what@entry=0x41ff9c "FD") at append.c:158
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff9640008e8) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff9640008e8) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff9640008e8) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff9640008e8) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x241a258) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x241a258) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2419af8) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 12 (Thread 0x7ff958ff9700 (LWP 462425)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff954002518, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff954002518) at bsock_tcp.c:550
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff954002518) at bget_msg.c:53
#4 0x0000000000409e30 in do_append_data (jcr=jcr@entry=0x7ff954002748, bs=bs@entry=0x7ff954002518, what=what@entry=0x41ff9c "FD") at append.c:158
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff954002748) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff954002748) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff954002748) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff954002748) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x23f00a8) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x23f00a8) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x241a588) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 11 (Thread 0x7ff937fff700 (LWP 439429)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff940404538, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff940404538) at bsock_tcp.c:550
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff940404538) at bget_msg.c:53
#4 0x0000000000409e30 in do_append_data (jcr=jcr@entry=0x7ff940002188, bs=bs@entry=0x7ff940404538, what=what@entry=0x41ff9c "FD") at append.c:158
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff940002188) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff940002188) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff940002188) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff940002188) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x24193b8) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x24193b8) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x23e8d98) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 10 (Thread 0x7ff980d03700 (LWP 435712)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff948003b58, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff948003b58) at bsock_tcp.c:550
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff948003b58) at bget_msg.c:53
#4 0x0000000000409e30 in do_append_data (jcr=jcr@entry=0x7ff948001078, bs=bs@entry=0x7ff948003b58, what=what@entry=0x41ff9c "FD") at append.c:158
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff948001078) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff948001078) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff948001078) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff948001078) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x24199b8) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x24199b8) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2419af8) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 9 (Thread 0x7ff97a7fc700 (LWP 414355)):
#0 0x00007ff98a4644ed in __lll_lock_wait () from /usr/lib64/libpthread.so.0
#1 0x00007ff98a45fdcb in _L_lock_883 () from /usr/lib64/libpthread.so.0
#2 0x00007ff98a45fc98 in pthread_mutex_lock () from /usr/lib64/libpthread.so.0
#3 0x00007ff98b5cf78b in lmgr_p (m=m@entry=0x7ff98b808ac0 <_ZL5mutex>) at lockmgr.c:91
#4 0x00007ff98b5d06ed in bthread_mutex_lock_p (m=m@entry=0x7ff98b808ac0 <_ZL5mutex>, file=file@entry=0x7ff98b5f1b36 "mem_pool.c", line=line@entry=145) at lockmgr.c:770
#5 0x00007ff98b5d162a in sm_get_pool_memory (fname=fname@entry=0x7ff98ba64632 "record.c", lineno=lineno@entry=493, pool=pool@entry=6) at mem_pool.c:145
#6 0x00007ff98ba4d2be in new_record (with_data=with_data@entry=true) at record.c:493
#7 0x00007ff98ba45070 in write_session_label (dcr=dcr@entry=0x7ff9680008e8, label=label@entry=-5) at label.c:799
#8 0x00000000004099ef in do_append_data (jcr=jcr@entry=0x7ff968003de8, bs=bs@entry=0x7ff968014548, what=what@entry=0x41ff9c "FD") at append.c:277
#9 0x00000000004112e4 in append_data_cmd (jcr=0x7ff968003de8) at fd_cmds.c:271
#10 0x00000000004116f9 in do_fd_commands (jcr=0x7ff968003de8) at fd_cmds.c:227
#11 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff968003de8) at fd_cmds.c:183
#12 0x0000000000412553 in do_job_run (jcr=0x7ff968003de8) at job.c:238
#13 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x2422c78) at dir_cmd.c:315
#14 0x0000000000419b2b in handle_connection_request (arg=0x2422c78) at socket_server.c:100
#15 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#16 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2419af8) at lockmgr.c:928
#17 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#18 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 8 (Thread 0x7ff9797fa700 (LWP 409423)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff944403198, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff944403198) at bsock_tcp.c:550
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff944403198) at bget_msg.c:53
#4 0x0000000000409eb8 in do_append_data (jcr=jcr@entry=0x7ff944001768, bs=bs@entry=0x7ff944403198, what=what@entry=0x41ff9c "FD") at append.c:209
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff944001768) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff944001768) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff944001768) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff944001768) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x2427528) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x2427528) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x23e8d98) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 7 (Thread 0x7ff9597fa700 (LWP 311318)):
#0 0x00007ff98a465179 in waitpid () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5e18d4 in signal_handler (sig=11) at signal.c:240
#2 <signal handler called>
#3 smart_alloc_msg (file=0x7ff98b5f5038 "smartall.c", line=line@entry=229, fmt=0x7ff98b5f5178 "Overrun buffer: len=%d addr=%p allocated: %s:%d called from %s:%d\n", file=0x7ff98b5f5038 "smartall.c") at smartall.c:113
#4 0x00007ff98b5e262c in sm_free (file=0x7ff98b5f1b36 "mem_pool.c", line=257, fp=0x7ff974000be8) at smartall.c:230
#5 0x00007ff98b5d1bb4 in sm_free_pool_memory (fname=fname@entry=0x7ff98ba5f591 "block.c", lineno=lineno@entry=178, obuf=0x7ff974000c00 "") at mem_pool.c:257
#6 0x00007ff98ba3b31a in free_block (block=<optimized out>) at block.c:178
#7 0x00007ff98ba40ee1 in DEVICE::set_blocksizes (this=0x7ff97401b9a8, dcr=dcr@entry=0x7ff974042728) at dev.c:488
#8 0x00007ff98ba4649c in write_new_volume_label_to_dev (dcr=dcr@entry=0x7ff974042728, VolName=VolName@entry=0x7ff974042840 "IncDemo-0461", PoolName=PoolName@entry=0x7ff9740428c0 "IncDemo", relabel=relabel@entry=false) at label.c:463
#9 0x00007ff98ba4933c in DCR::try_autolabel (this=0x7ff974042728, opened=<optimized out>) at mount.c:784
#10 0x00007ff98ba4a68a in DCR::mount_next_write_volume (this=this@entry=0x7ff974042728) at mount.c:245
#11 0x00007ff98ba43944 in fixup_device_block_write_error (dcr=dcr@entry=0x7ff974042728, retries=retries@entry=4) at device.c:120
#12 0x00007ff98ba3e21b in DCR::write_block_to_device (this=this@entry=0x7ff974042728) at block.c:410
#13 0x00007ff98ba4db31 in DCR::write_record (this=this@entry=0x7ff974042728) at record.c:668
#14 0x0000000000409fbd in do_append_data (jcr=jcr@entry=0x7ff9740421f8, bs=bs@entry=0x7ff974042ca8, what=what@entry=0x41ff9c "FD") at append.c:223
#15 0x00000000004112e4 in append_data_cmd (jcr=0x7ff9740421f8) at fd_cmds.c:271
#16 0x00000000004116f9 in do_fd_commands (jcr=0x7ff9740421f8) at fd_cmds.c:227
#17 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff9740421f8) at fd_cmds.c:183
#18 0x0000000000412553 in do_job_run (jcr=0x7ff9740421f8) at job.c:238
#19 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x2421788) at dir_cmd.c:315
#20 0x0000000000419b2b in handle_connection_request (arg=0x2421788) at socket_server.c:100
#21 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#22 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x241a1c8) at lockmgr.c:928
#23 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#24 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 6 (Thread 0x7ff959ffb700 (LWP 310968)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff95c0144d8, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff95c0144d8) at bsock_tcp.c:550
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff95c0144d8) at bget_msg.c:53
#4 0x0000000000409e30 in do_append_data (jcr=jcr@entry=0x7ff95c0008e8, bs=bs@entry=0x7ff95c0144d8, what=what@entry=0x41ff9c "FD") at append.c:158
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff95c0008e8) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff95c0008e8) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff95c0008e8) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff95c0008e8) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x2419e58) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x2419e58) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x241a1c8) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 5 (Thread 0x7ff97affd700 (LWP 309674)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff9500130f8, ptr=<optimized out>, nbytes=65536) at bsock_tcp.c:978
#2 0x00007ff98b5bb846 in BSOCK_TCP::recv (this=0x7ff9500130f8) at bsock_tcp.c:617
#3 0x00007ff98b5b132d in bget_msg (sock=sock@entry=0x7ff9500130f8) at bget_msg.c:53
#4 0x0000000000409eb8 in do_append_data (jcr=jcr@entry=0x7ff9500008e8, bs=bs@entry=0x7ff9500130f8, what=what@entry=0x41ff9c "FD") at append.c:209
#5 0x00000000004112e4 in append_data_cmd (jcr=0x7ff9500008e8) at fd_cmds.c:271
#6 0x00000000004116f9 in do_fd_commands (jcr=0x7ff9500008e8) at fd_cmds.c:227
#7 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff9500008e8) at fd_cmds.c:183
#8 0x0000000000412553 in do_job_run (jcr=0x7ff9500008e8) at job.c:238
#9 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x241a088) at dir_cmd.c:315
#10 0x0000000000419b2b in handle_connection_request (arg=0x241a088) at socket_server.c:100
#11 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#12 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2425398) at lockmgr.c:928
#13 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#14 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 4 (Thread 0x7ff978ff9700 (LWP 309670)):
#0 0x00007ff98a4646fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5bbdce in BSOCK_TCP::read_nbytes (this=0x7ff94c0030d8, ptr=<optimized out>, nbytes=4) at bsock_tcp.c:978
#2 0x00007ff98b5bb60c in BSOCK_TCP::recv (this=0x7ff94c0030d8) at bsock_tcp.c:550
#3 0x000000000041165d in do_fd_commands (jcr=0x7ff94c013788) at fd_cmds.c:213
#4 0x0000000000411902 in run_job (jcr=jcr@entry=0x7ff94c013788) at fd_cmds.c:183
#5 0x0000000000412553 in do_job_run (jcr=0x7ff94c013788) at job.c:238
#6 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x24181f8) at dir_cmd.c:315
#7 0x0000000000419b2b in handle_connection_request (arg=0x24181f8) at socket_server.c:100
#8 0x00007ff98b5ebdd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#9 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2419fe8) at lockmgr.c:928
#10 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#11 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 3 (Thread 0x7ff97b7fe700 (LWP 754640)):
#0 0x00007ff98a461d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5d083c in bthread_cond_timedwait_p (cond=cond@entry=0x628580 <wait_for_next_run>, m=m@entry=0x6285c0 <_ZL5mutex>, abstime=abstime@entry=0x7ff97b7fdd50, file=file@entry=0x421280 "sd_stats.c", line=line@entry=400) at lockmgr.c:813
#2 0x0000000000418ddf in statistics_thread_runner (arg=arg@entry=0x0) at sd_stats.c:400
#3 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x2419e48) at lockmgr.c:928
#4 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#5 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 2 (Thread 0x7ff97bfff700 (LWP 754639)):
#0 0x00007ff98a461d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5d083c in bthread_cond_timedwait_p (cond=cond@entry=0x7ff98b8097e0 <_ZL5timer>, m=m@entry=0x7ff98b809820 <_ZL11timer_mutex>, abstime=abstime@entry=0x7ff97bffed40, file=file@entry=0x7ff98b5f6a02 "watchdog.c", line=line@entry=313) at lockmgr.c:813
#2 0x00007ff98b5eb3c8 in watchdog_thread (arg=arg@entry=0x0) at watchdog.c:313
#3 0x00007ff98b5d03e0 in lmgr_thread_launcher (x=0x241a588) at lockmgr.c:928
#4 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#5 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
Thread 1 (Thread 0x7ff981504700 (LWP 754637)):
#0 0x00007ff98a464e3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007ff98b5be254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007ff98b5d0371 in check_deadlock () at lockmgr.c:568
#3 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
#0 0x00007ff98a464e3d in nanosleep () from /usr/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007ff98b5be254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
171 status = nanosleep(&timeout, NULL);
timeout = {tv_sec = 30, tv_nsec = 0}
tv = {tv_sec = 0, tv_usec = 1275120912404580352}
tz = {tz_minuteswest = 2080379000, tz_dsttime = 32761}
status = <optimized out>
#2 0x00007ff98b5d0371 in check_deadlock () at lockmgr.c:568
568 while (!bmicrosleep(30, 0)) {
__clframe = <optimized out>
old = 0
#3 0x00007ff98a45ddd5 in start_thread () from /usr/lib64/libpthread.so.0
No symbol table info available.
#4 0x00007ff989353ead in clone () from /usr/lib64/libc.so.6
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
|
|
|
|
Now 17.2.7 crashes with statistics off.
bareos.2834141.traceback (7,946 bytes)
Created /var/lib/bareos/bareos-sd.core.2834141 for doing postmortem debugging
[New LWP 2834142]
[New LWP 2834144]
[New LWP 3783196]
[New LWP 3783200]
[New LWP 2834141]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/bareos-sd'.
#0 0x00007f080c15de3d in nanosleep () from /usr/lib64/libpthread.so.0
$1 = '\000' <repeats 127 times>
$2 = 0x208e068 "bareos-sd"
$3 = 0x208e0a8 "/usr/sbin/bareos-sd"
$4 = 0x0
$5 = 0x7f080d2eb0fc "17.2.7 (16 Jul 2018)"
$6 = 0x7f080d2eb0e4 "x86_64-redhat-linux-gnu"
$7 = 0x7f080d2eb0dd "redhat"
$8 = 0x7f080d2eb5e0 "CentOS Linux release 7.5.1804 (Core) "
$9 = "elbcg1.eurolog.com", '\000' <repeats 237 times>
$10 = 0x7f080d2eb608 "redhat CentOS Linux release 7.5.1804 (Core) "
Environment variable "TestName" not defined.
#0 0x00007f080c15de3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007f080d2b7254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007f080d2c9371 in check_deadlock () at lockmgr.c:568
#3 0x00007f080c156dd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007f080b04cead in clone () from /usr/lib64/libc.so.6
Thread 5 (Thread 0x7f080de12880 (LWP 2834141)):
#0 0x00007f080b04220d in poll () from /usr/lib64/libc.so.6
#1 0x00007f080d2ab0d1 in bnet_thread_server_tcp (addr_list=<optimized out>, max_clients=<optimized out>, sockfds=<optimized out>, client_wq=client_wq@entry=0x628620 <socket_workq>, nokeepalive=<optimized out>, handle_client_request=handle_client_request@entry=0x419a90 <handle_connection_request(void*)>) at bnet_server_tcp.c:306
#2 0x0000000000419e08 in start_socket_server (addrs=<optimized out>) at socket_server.c:122
#3 0x000000000040913a in main (argc=<optimized out>, argv=<optimized out>) at stored.c:322
Thread 4 (Thread 0x7f08011f9700 (LWP 3783200)):
#0 0x00007f080c15e179 in waitpid () from /usr/lib64/libpthread.so.0
#1 0x00007f080d2da8d4 in signal_handler (sig=11) at signal.c:240
#2 <signal handler called>
#3 smart_alloc_msg (file=0x7f080d2ee038 "smartall.c", line=line@entry=229, fmt=0x7f080d2ee178 "Overrun buffer: len=%d addr=%p allocated: %s:%d called from %s:%d\n", file=0x7f080d2ee038 "smartall.c") at smartall.c:113
#4 0x00007f080d2db62c in sm_free (file=0x7f080d2eab36 "mem_pool.c", line=257, fp=0x7f07dc4369f8) at smartall.c:230
#5 0x00007f080d2cabb4 in sm_free_pool_memory (fname=fname@entry=0x7f080d758591 "block.c", lineno=lineno@entry=178, obuf=0x7f07dc436a10 "") at mem_pool.c:257
#6 0x00007f080d73431a in free_block (block=<optimized out>) at block.c:178
#7 0x00007f080d739ee1 in DEVICE::set_blocksizes (this=0x7f07f403ee68, dcr=dcr@entry=0x7f07dc437098) at dev.c:488
#8 0x00007f080d73f49c in write_new_volume_label_to_dev (dcr=dcr@entry=0x7f07dc437098, VolName=VolName@entry=0x7f07dc4371b0 "ConDemo-0604", PoolName=PoolName@entry=0x7f07dc437230 "ConDemo", relabel=relabel@entry=false) at label.c:463
#9 0x00007f080d74233c in DCR::try_autolabel (this=0x7f07dc437098, opened=<optimized out>) at mount.c:784
#10 0x00007f080d74368a in DCR::mount_next_write_volume (this=this@entry=0x7f07dc437098) at mount.c:245
#11 0x00007f080d73c944 in fixup_device_block_write_error (dcr=dcr@entry=0x7f07dc437098, retries=retries@entry=4) at device.c:120
#12 0x00007f080d73721b in DCR::write_block_to_device (this=0x7f07dc437098) at block.c:410
#13 0x000000000041376c in clone_record_internally (dcr=<optimized out>, rec=<optimized out>) at mac.c:247
#14 0x00007f080d744f1f in read_records (dcr=0x7f07dc036428, record_cb=record_cb@entry=0x413650 <clone_record_internally(DCR*, DEV_RECORD*)>, mount_cb=0x4084d0 <_Z22mount_next_read_volumeP3DCR@plt>) at read_record.c:477
#15 0x0000000000414348 in do_mac_run (jcr=0x7f07dc014268) at mac.c:699
#16 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x20bef88) at dir_cmd.c:315
#17 0x0000000000419b2b in handle_connection_request (arg=0x20bef88) at socket_server.c:100
#18 0x00007f080d2e4dd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#19 0x00007f080d2c93e0 in lmgr_thread_launcher (x=0x20c09b8) at lockmgr.c:928
#20 0x00007f080c156dd5 in start_thread () from /usr/lib64/libpthread.so.0
#21 0x00007f080b04cead in clone () from /usr/lib64/libc.so.6
Thread 3 (Thread 0x7f07e8ff9700 (LWP 3783196)):
#0 0x00007f080c15d6fd in read () from /usr/lib64/libpthread.so.0
#1 0x00007f080d73c227 in DEVICE::read (this=0x7f07f4019a48, buf=0x7f07d04130b0, len=4194304) at dev.c:1167
#2 0x00007f080d734662 in DCR::read_block_from_dev (this=this@entry=0x7f07d0041fd8, check_block_numbers=check_block_numbers@entry=true) at block.c:995
#3 0x00007f080d7373b4 in DCR::read_block_from_device (this=this@entry=0x7f07d0041fd8, check_block_numbers=check_block_numbers@entry=true) at block.c:932
#4 0x00007f080d7444ad in read_next_block_from_device (dcr=dcr@entry=0x7f07d0041fd8, sessrec=sessrec@entry=0x7f07d0043698, record_cb=record_cb@entry=0x413650 <clone_record_internally(DCR*, DEV_RECORD*)>, mount_cb=mount_cb@entry=0x4084d0 <_Z22mount_next_read_volumeP3DCR@plt>, status=status@entry=0x7f07e8ff8ad6) at read_record.c:194
#5 0x00007f080d744de3 in read_records (dcr=0x7f07d0041fd8, record_cb=record_cb@entry=0x413650 <clone_record_internally(DCR*, DEV_RECORD*)>, mount_cb=0x4084d0 <_Z22mount_next_read_volumeP3DCR@plt>) at read_record.c:401
#6 0x0000000000414348 in do_mac_run (jcr=0x7f07d0001078) at mac.c:699
#7 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x20c9c68) at dir_cmd.c:315
#8 0x0000000000419b2b in handle_connection_request (arg=0x20c9c68) at socket_server.c:100
#9 0x00007f080d2e4dd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#10 0x00007f080d2c93e0 in lmgr_thread_launcher (x=0x20c1178) at lockmgr.c:928
#11 0x00007f080c156dd5 in start_thread () from /usr/lib64/libpthread.so.0
#12 0x00007f080b04cead in clone () from /usr/lib64/libc.so.6
Thread 2 (Thread 0x7f08021fb700 (LWP 2834144)):
#0 0x00007f080c15ad12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1 0x00007f080d2c983c in bthread_cond_timedwait_p (cond=cond@entry=0x7f080d5027e0 <_ZL5timer>, m=m@entry=0x7f080d502820 <_ZL11timer_mutex>, abstime=abstime@entry=0x7f08021fad40, file=file@entry=0x7f080d2efa02 "watchdog.c", line=line@entry=313) at lockmgr.c:813
#2 0x00007f080d2e43c8 in watchdog_thread (arg=arg@entry=0x0) at watchdog.c:313
#3 0x00007f080d2c93e0 in lmgr_thread_launcher (x=0x20c0ef8) at lockmgr.c:928
#4 0x00007f080c156dd5 in start_thread () from /usr/lib64/libpthread.so.0
#5 0x00007f080b04cead in clone () from /usr/lib64/libc.so.6
Thread 1 (Thread 0x7f08031fd700 (LWP 2834142)):
#0 0x00007f080c15de3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007f080d2b7254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007f080d2c9371 in check_deadlock () at lockmgr.c:568
#3 0x00007f080c156dd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007f080b04cead in clone () from /usr/lib64/libc.so.6
#0 0x00007f080c15de3d in nanosleep () from /usr/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007f080d2b7254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
171 status = nanosleep(&timeout, NULL);
timeout = {tv_sec = 30, tv_nsec = 0}
tv = {tv_sec = 0, tv_usec = 3294014104822255872}
tz = {tz_minuteswest = -67104648, tz_dsttime = 32519}
status = <optimized out>
#2 0x00007f080d2c9371 in check_deadlock () at lockmgr.c:568
568 while (!bmicrosleep(30, 0)) {
__clframe = <optimized out>
old = 0
#3 0x00007f080c156dd5 in start_thread () from /usr/lib64/libpthread.so.0
No symbol table info available.
#4 0x00007f080b04cead in clone () from /usr/lib64/libc.so.6
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
bareos.3909678.traceback (8,340 bytes)
Created /var/lib/bareos/bareos-sd.core.3909678 for doing postmortem debugging
[New LWP 3909679]
[New LWP 3909681]
[New LWP 3909682]
[New LWP 3909692]
[New LWP 3909678]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/bareos-sd'.
#0 0x00007fe06d9bee3d in nanosleep () from /usr/lib64/libpthread.so.0
$1 = '\000' <repeats 127 times>
$2 = 0x85c068 "bareos-sd"
$3 = 0x85c0a8 "/usr/sbin/bareos-sd"
$4 = 0x0
$5 = 0x7fe06eb4c0fc "17.2.7 (16 Jul 2018)"
$6 = 0x7fe06eb4c0e4 "x86_64-redhat-linux-gnu"
$7 = 0x7fe06eb4c0dd "redhat"
$8 = 0x7fe06eb4c5e0 "CentOS Linux release 7.5.1804 (Core) "
$9 = "elbcg1.eurolog.com", '\000' <repeats 237 times>
$10 = 0x7fe06eb4c608 "redhat CentOS Linux release 7.5.1804 (Core) "
Environment variable "TestName" not defined.
#0 0x00007fe06d9bee3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007fe06eb18254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007fe06eb2a371 in check_deadlock () at lockmgr.c:568
#3 0x00007fe06d9b7dd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007fe06c8adead in clone () from /usr/lib64/libc.so.6
Thread 5 (Thread 0x7fe06f673880 (LWP 3909678)):
#0 0x00007fe06c8a320d in poll () from /usr/lib64/libc.so.6
#1 0x00007fe06eb0c0d1 in bnet_thread_server_tcp (addr_list=<optimized out>, max_clients=<optimized out>, sockfds=<optimized out>, client_wq=client_wq@entry=0x628620 <socket_workq>, nokeepalive=<optimized out>, handle_client_request=handle_client_request@entry=0x419a90 <handle_connection_request(void*)>) at bnet_server_tcp.c:306
#2 0x0000000000419e08 in start_socket_server (addrs=<optimized out>) at socket_server.c:122
#3 0x000000000040913a in main (argc=<optimized out>, argv=<optimized out>) at stored.c:322
Thread 4 (Thread 0x7fe05e7fb700 (LWP 3909692)):
#0 0x00007fe06d9be4ed in __lll_lock_wait () from /usr/lib64/libpthread.so.0
#1 0x00007fe06d9b9dcb in _L_lock_883 () from /usr/lib64/libpthread.so.0
#2 0x00007fe06d9b9c98 in pthread_mutex_lock () from /usr/lib64/libpthread.so.0
#3 0x00007fe06eb2978b in lmgr_p (m=m@entry=0x7fe06ed62ac0 <_ZL5mutex>) at lockmgr.c:91
#4 0x00007fe06eb2a6ed in bthread_mutex_lock_p (m=m@entry=0x7fe06ed62ac0 <_ZL5mutex>, file=file@entry=0x7fe06eb4bb36 "mem_pool.c", line=line@entry=145) at lockmgr.c:770
#5 0x00007fe06eb2b62a in sm_get_pool_memory (fname=fname@entry=0x41daac "../lib/mem_pool.h", lineno=lineno@entry=92, pool=pool@entry=1) at mem_pool.c:145
#6 0x000000000040ae5d in POOL_MEM (this=0x7fe05e7fa600) at ../lib/mem_pool.h:92
#7 SD_DCR::dir_update_volume_info (this=0x7fe054053568, label=<optimized out>, update_LastWritten=<optimized out>) at askdir.c:349
#8 0x00007fe06ef97e60 in do_new_file_bookkeeping (dcr=0x7fe054053568) at block.c:897
#9 DCR::write_block_to_dev (this=this@entry=0x7fe054053568) at block.c:565
#10 0x00007fe06ef981d8 in DCR::write_block_to_device (this=0x7fe054053568) at block.c:406
#11 0x000000000041376c in clone_record_internally (dcr=<optimized out>, rec=<optimized out>) at mac.c:247
#12 0x00007fe06efa5f1f in read_records (dcr=0x7fe054042c88, record_cb=record_cb@entry=0x413650 <clone_record_internally(DCR*, DEV_RECORD*)>, mount_cb=0x4084d0 <_Z22mount_next_read_volumeP3DCR@plt>) at read_record.c:477
#13 0x0000000000414348 in do_mac_run (jcr=0x7fe054001078) at mac.c:699
#14 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x88e798) at dir_cmd.c:315
#15 0x0000000000419b2b in handle_connection_request (arg=0x88e798) at socket_server.c:100
#16 0x00007fe06eb45dd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#17 0x00007fe06eb2a3e0 in lmgr_thread_launcher (x=0x88ef18) at lockmgr.c:928
#18 0x00007fe06d9b7dd5 in start_thread () from /usr/lib64/libpthread.so.0
#19 0x00007fe06c8adead in clone () from /usr/lib64/libc.so.6
Thread 3 (Thread 0x7fe05ffff700 (LWP 3909682)):
#0 0x00007fe06d9bf179 in waitpid () from /usr/lib64/libpthread.so.0
#1 0x00007fe06eb3b8d4 in signal_handler (sig=11) at signal.c:240
#2 <signal handler called>
#3 smart_alloc_msg (file=0x7fe06eb4f038 "smartall.c", line=line@entry=229, fmt=0x7fe06eb4f178 "Overrun buffer: len=%d addr=%p allocated: %s:%d called from %s:%d\n", file=0x7fe06eb4f038 "smartall.c") at smartall.c:113
#4 0x00007fe06eb3c62c in sm_free (file=0x7fe06eb4bb36 "mem_pool.c", line=257, fp=0x7fe0500a46b8) at smartall.c:230
#5 0x00007fe06eb2bbb4 in sm_free_pool_memory (fname=fname@entry=0x7fe06efb9591 "block.c", lineno=lineno@entry=178, obuf=0x7fe0500a46d0 "") at mem_pool.c:257
#6 0x00007fe06ef9531a in free_block (block=<optimized out>) at block.c:178
#7 0x00007fe06ef9aee1 in DEVICE::set_blocksizes (this=0x7fe050039048, dcr=dcr@entry=0x7fe050092cc8) at dev.c:488
#8 0x00007fe06efa049c in write_new_volume_label_to_dev (dcr=dcr@entry=0x7fe050092cc8, VolName=VolName@entry=0x7fe050092de0 "ConDemo-0607", PoolName=PoolName@entry=0x7fe050092e60 "ConDemo", relabel=relabel@entry=false) at label.c:463
#9 0x00007fe06efa333c in DCR::try_autolabel (this=0x7fe050092cc8, opened=<optimized out>) at mount.c:784
#10 0x00007fe06efa468a in DCR::mount_next_write_volume (this=this@entry=0x7fe050092cc8) at mount.c:245
#11 0x00007fe06ef9d944 in fixup_device_block_write_error (dcr=dcr@entry=0x7fe050092cc8, retries=retries@entry=4) at device.c:120
#12 0x00007fe06ef9821b in DCR::write_block_to_device (this=0x7fe050092cc8) at block.c:410
#13 0x000000000041376c in clone_record_internally (dcr=<optimized out>, rec=<optimized out>) at mac.c:247
#14 0x00007fe06efa5f1f in read_records (dcr=0x7fe050082458, record_cb=record_cb@entry=0x413650 <clone_record_internally(DCR*, DEV_RECORD*)>, mount_cb=0x4084d0 <_Z22mount_next_read_volumeP3DCR@plt>) at read_record.c:477
#15 0x0000000000414348 in do_mac_run (jcr=0x7fe050001078) at mac.c:699
#16 0x0000000000410aaa in handle_director_connection (dir=dir@entry=0x88e3b8) at dir_cmd.c:315
#17 0x0000000000419b2b in handle_connection_request (arg=0x88e3b8) at socket_server.c:100
#18 0x00007fe06eb45dd5 in workq_server (arg=arg@entry=0x628620 <socket_workq>) at workq.c:336
#19 0x00007fe06eb2a3e0 in lmgr_thread_launcher (x=0x88e4f8) at lockmgr.c:928
#20 0x00007fe06d9b7dd5 in start_thread () from /usr/lib64/libpthread.so.0
#21 0x00007fe06c8adead in clone () from /usr/lib64/libc.so.6
Thread 2 (Thread 0x7fe05f7fe700 (LWP 3909681)):
#0 0x00007fe06d9bbd12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /usr/lib64/libpthread.so.0
#1 0x00007fe06eb2a83c in bthread_cond_timedwait_p (cond=cond@entry=0x7fe06ed637e0 <_ZL5timer>, m=m@entry=0x7fe06ed63820 <_ZL11timer_mutex>, abstime=abstime@entry=0x7fe05f7fdd40, file=file@entry=0x7fe06eb50a02 "watchdog.c", line=line@entry=313) at lockmgr.c:813
#2 0x00007fe06eb453c8 in watchdog_thread (arg=arg@entry=0x0) at watchdog.c:313
#3 0x00007fe06eb2a3e0 in lmgr_thread_launcher (x=0x88f588) at lockmgr.c:928
#4 0x00007fe06d9b7dd5 in start_thread () from /usr/lib64/libpthread.so.0
#5 0x00007fe06c8adead in clone () from /usr/lib64/libc.so.6
Thread 1 (Thread 0x7fe064a5e700 (LWP 3909679)):
#0 0x00007fe06d9bee3d in nanosleep () from /usr/lib64/libpthread.so.0
#1 0x00007fe06eb18254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
#2 0x00007fe06eb2a371 in check_deadlock () at lockmgr.c:568
#3 0x00007fe06d9b7dd5 in start_thread () from /usr/lib64/libpthread.so.0
#4 0x00007fe06c8adead in clone () from /usr/lib64/libc.so.6
#0 0x00007fe06d9bee3d in nanosleep () from /usr/lib64/libpthread.so.0
No symbol table info available.
#1 0x00007fe06eb18254 in bmicrosleep (sec=sec@entry=30, usec=usec@entry=0) at bsys.c:171
171 status = nanosleep(&timeout, NULL);
timeout = {tv_sec = 30, tv_nsec = 0}
tv = {tv_sec = 0, tv_usec = -5333927592180770048}
tz = {tz_minuteswest = 1610616952, tz_dsttime = 32736}
status = <optimized out>
#2 0x00007fe06eb2a371 in check_deadlock () at lockmgr.c:568
568 while (!bmicrosleep(30, 0)) {
__clframe = <optimized out>
old = 0
#3 0x00007fe06d9b7dd5 in start_thread () from /usr/lib64/libpthread.so.0
No symbol table info available.
#4 0x00007fe06c8adead in clone () from /usr/lib64/libc.so.6
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
#0 0x0000000000000000 in ?? ()
No symbol table info available.
|
|
|
|
We would love to look at your configuration. Can you share your bareos-sd and director configuration? The latter one can be generated with "status all verbose".
Please note that there would be passwords inside the configuration that need to be obfuscated.
If you cannot upload the information here, you can also send it directly to me. |
|
arogge
2019-01-29 13:22
manager
~0003213
Last edited: 2019-01-29 13:22
|
Can you check (e.g. from bareos.log) wether the storage-daemon crashed everytime it labeled a volume in one of the pools with maximum block size set to a custom value?
|
|
|
|
Indeed, it does. But it didn't crashed many times before.
Here are some bareos.log lines around the crash:
27-Jan 03:43 elbcg1-sd JobId 2362: User defined maximum volume capacity 107,374,182,400 exceeded on device "FileConDemo7" (/mnt/cephfs/bareos/storage/consolidated/demo/).
27-Jan 03:43 elbcg1-sd JobId 2362: End of medium on Volume "ConDemo-0600" Bytes=107,369,988,277 Blocks=25,599 at 27-Jan-2019 03:43.
27-Jan 03:43 bareos-dir JobId 2362: Created new Volume "ConDemo-0604" in catalog.
27-Jan 03:43 elbcg1-sd: ABORTING due to ERROR in smartall.c:229
Overrun buffer: len=145 addr=7f07dc4369f8 allocated: block.c:123 called from mem_pool.c:257
27-Jan 03:43 bareos-dir JobId 2362: Fatal error: Director's comm line to SD dropped.
27-Jan 04:01 elbcg1-sd JobId 2369: End of Volume at file 24 on device "FileIncDemo2" (/mnt/cephfs/bareos/storage/incremental/demo/), Volume "IncDemo-0125"
27-Jan 04:01 elbcg1-sd JobId 2369: Ready to read from volume "IncDemo-0119" on device "FileIncDemo2" (/mnt/cephfs/bareos/storage/incremental/demo/).
27-Jan 04:01 elbcg1-sd JobId 2369: Forward spacing Volume "IncDemo-0119" to file:block 0:207710437.
27-Jan 04:17 elbcg1-sd JobId 2369: User defined maximum volume capacity 107,374,182,400 exceeded on device "FileConDemo1" (/mnt/cephfs/bareos/storage/consolidated/demo/).
27-Jan 04:17 elbcg1-sd JobId 2369: End of medium on Volume "ConDemo-0605" Bytes=107,369,988,300 Blocks=25,599 at 27-Jan-2019 04:17.
27-Jan 04:17 bareos-dir JobId 2369: Created new Volume "ConDemo-0607" in catalog.
27-Jan 04:17 elbcg1-sd: ABORTING due to ERROR in smartall.c:229
Overrun buffer: len=145 addr=7fe0500a46b8 allocated: block.c:123 called from mem_pool.c:257
27-Jan 04:17 bareos-dir JobId 2369: Fatal error: Director's comm line to SD dropped. |
|
|
|
Seems like it crashes when labeling a new filesystem volume where Maximum Block Size set.
The setting should only be used on tape drives, so using it on filesystem volumes seems to be not tested thoroughly.
I'll try to reproduce the issue. |
|
arogge
2019-01-29 15:00
manager
~0003216
Last edited: 2019-01-29 15:00
|
Sorry, I cannot make it crash on my machine with the most recent 17.2 branch or 17.2.7 right now.
Is it correct you are running director and sd in version 17.2.7 on a CentOS 7.6? Are you using our RPM packages?
|
|
|
|
Yes, it's CentOS 7.6 but with self compiled packages.
I made it with instructions from this site https://www.spheron1.uk/2018/03/14/building-bareos-rpms-on-centos-6-7/
The 18.2.4-rc2 version is from your download area.
The Maximum Block Size was set to speedup the I/O to/from our CephFS to tape (4MB object size and hints from https://www.bareos.org/en/Whitepapers/articles/Speed_Tuning_of_Tape_Drives.html).
I'm not sure if it's still necessary. I have a tape server now with lot's of SSDs for spooling to prevent shoe-shining.
What do you think about running the SD with a reasonable debug level and what would that be? |
|
|
|
Hmm... can you make this happen with our 18.2.4rc2 packages and statistics disabled?
I had another look at the tracebacks and the type of crash changed when you disabled statistics: With stats enabled you were running into a known issue with statistics. With stats disabled, you're now running into this new issue with labeling.
Apart from your crashes:
We recommend setting Maximum Block Size for tape pools only. Even if you set it for your tapes you don't need to set it for your filesystem volumes. Also, if you're running Ceph, there is a RADOS backend in bareos-sd bypassing the need for cephfs interacting with Ceph directly. Did you already try that?
Have you run into read/write-performance issues with your cephfs setup or why did you set Maximum Block Size on your filesystem volumes at all? |
|
|
|
With 18.2.4-rc2 it didn't crash with statistics disabled. But I had it only for one day disabled.
I'll install 18.2.4-rc2 and let it run for a while. Is the statistics issue fixed in that version?
I tried the Droplet backend but had no luck.
Is it worth now to try Droplet or RADOS with 18.2.4-rc2? |
|
|
|
Running the SD at another debug level won't help.
What happens is that the buffer for dev->block overruns (i.e. there is a write behind the end of the buffer) and when it is free()d during write_new_volume_label_to_dev()'s call to set_blocksized() the smart allocator kills the SD because it detects the overrun.
I'll need a way to reproduce this and look at it with a debugger. If you can make it crash with our 18.2.4rc2 RPMs, maybe I can make it crash with these, too.
Can you btw. make it crash by issuing a label command in bconsole to label a new volume in one of the Pools with Maximum Block Size set? |
|
|
|
No, it doesn't crash while labeling. Unfortunately it crashes sporadically. |
|
|
|
Hmm.. can't see any differences with or without statistics.
See bareos.1491023.traceback with statistics and bareos.2834141.traceback without.
Both crashes at set_blocksizes -> free_block etc. |
|
|
|
The very first crash you posted was different. It crashed during sha1_block_data_order_avx() in openssl.
That's why I suggested to test again with 18.2.4rc2 and disabled statistics. |
|
|
|
just installed 18.2.4-rc2 and have statistics disabled. :-) |
|
|
|
Sorry, but the 18.2.4-rc2 SD crashes too.
Thread 8 (Thread 0x7f3138ff9700 (LWP 2058295)):
#0 0x00007f315d199179 in waitpid () from /lib64/libpthread.so.0
0000001 0x00007f315dace1e4 in SignalHandler (sig=11) at /usr/src/debug/bareos-18.2.4rc2/src/lib/signal.cc:241
0000002 <signal handler called>
0000003 SmartAllocMsg (file=0x7f315daf5a88 "/home/abuild/rpmbuild/BUILD/bareos-18.2.4rc2/src/lib/smartall.cc", line=line@entry=229, fmt=0x7f315daf5b58 "Overrun buffer: len=%d addr=%p allocated: %s:%d called from %s:%d\n", file=0x7f315daf5a88 "/home/abuild/rpmbuild/BUILD/bareos-18.2.4rc2/src/lib/smartall.cc") at /usr/src/debug/bareos-18.2.4rc2/src/lib/smartall.cc:113
0000004 0x00007f315dacef3c in sm_free (file=0x7f315daf2a38 "/home/abuild/rpmbuild/BUILD/bareos-18.2.4rc2/src/lib/mem_pool.cc", line=258, fp=0x7f3114042a48) at /usr/src/debug/bareos-18.2.4rc2/src/lib/smartall.cc:230
0000005 0x00007f315dabee8c in SmFreePoolMemory (fname=fname@entry=0x7f315e1ef280 "/home/abuild/rpmbuild/BUILD/bareos-18.2.4rc2/src/stored/block.cc", lineno=lineno@entry=176, obuf=0x7f3114042a60 "") at /usr/src/debug/bareos-18.2.4rc2/src/lib/mem_pool.cc:258
0000006 0x00007f315e1ca6da in storagedaemon::FreeBlock (block=<optimized out>) at /usr/src/debug/bareos-18.2.4rc2/src/stored/block.cc:176
0000007 0x00007f315e1d0389 in storagedaemon::Device::SetBlocksizes (this=0x7f314c038178, dcr=dcr@entry=0x7f3114052c98) at /usr/src/debug/bareos-18.2.4rc2/src/stored/dev.cc:555
0000008 0x00007f315e1d4e9c in storagedaemon::WriteNewVolumeLabelToDev (dcr=dcr@entry=0x7f3114052c98, VolName=VolName@entry=0x7f3114052da8 "ConDemo-0700", PoolName=PoolName@entry=0x7f3114052e28 "ConDemo", relabel=relabel@entry=false) at /usr/src/debug/bareos-18.2.4rc2/src/stored/label.cc:471 |
|
|
|
This is actually "good" news. If our 18.2 packages crash then it is not your build that is broken, but the software itself.
I'll see whether or not the 18.2 packages you've installed are compiled with support for heap corruption detection and come back to you. |
|
|
|
Can you try with the packages from http://download.bareos.org/bareos/people/arogge/smcheck/CentOS_7/x86_64/ ?
If you run "bareos-sd -f -d 200 > /some/logfile" it will run in debug mode with memory corruption detection enabled. The resulting logfile might help me to understand the issue. |
|
|
|
With the debug version the SD doesn't crash anymore.
But on the other hand I've changed the config a little because the consolidation jobs failed.
Last night the SD stops responding to the director.
It is still running if you need some debug information of the process. |
|
|
|
If you cannot reproduce the problem anymore, can we close the bug? |
|
|
|
I've made an upgrade to 18.2.5. No crashes since then.
So, yes we can close it :-) |
|
