View Issue Details

IDProjectCategoryView StatusLast Update
0001590bareos-corefile daemonpublic2024-01-25 09:00
Reporterraschu Assigned Tobruno-at-bareos  
PrioritynormalSeveritymajorReproducibilityalways
Status closedResolutionno change required 
PlatformLinuxOSSLESOS Version15
Summary0001590: Bareos client works one time and lost connection
DescriptionHi Bareos-Team,

we have a strange problem that suddenly appeared after 1 month.
A client works only one time after restarting the service.

*resolve client=host1
Connecting to Client host1 at host1:9102
Probing client protocol... (result will be saved until config reload)
 Handshake: Immediate TLS, Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3

*resolve client=host1
Connecting to Client host1 at host1:9102
Failed to connect to Client host1.

The Versions are:

OS: open SUSE Leap v15.5
Bareos-Client: 23.0.1~pre23.b40879db9-34

If we try a backup, the error is:

"""
12-Jan 08:58 bareos-dir JobId 8354: Start Backup JobId 8354, Job=host1.2024-01-12_08.58.55_53
12-Jan 08:58 bareos-dir JobId 8354: Connected Storage daemon at storagehost1:9103, encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
12-Jan 08:58 bareos-dir JobId 8354: Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
12-Jan 08:58 bareos-dir JobId 8354: Connected Client: host1 at host1:9102, encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
12-Jan 09:09 bareos-dir JobId 8354: Fatal error: Network error during CRAM MD5 with 111.222.333.444
12-Jan 09:09 bareos-dir JobId 8354: Fatal error: Unable to authenticate with File daemon at "host1:9102"
12-Jan 09:09 bareos-dir JobId 8354: Fatal error: No Job status returned from FD.
12-Jan 09:09 bareos-dir JobId 8354: Error: Bareos bareos-dir 23.0.1~pre23.b40879db9 (05Jan24):
"""

The port 9102 is open.
There are no informations/errors in the journalctl on host1.

What could I do to find the error?

Thanks Ralf
TagsNo tags attached.

Activities

bruno-at-bareos

bruno-at-bareos

2024-01-16 14:36

manager   ~0005685

You should try to stat in front mode the bareos-fd with a higher debug level

/usr/sbin/bareos-fd -u root -g bareos -f --dt --debug-level 200 | tee -a /var/tmp/bareos-fd_debug.$(date "+%F_%H%M%S").log

That should normally then log what will happen during the first connection of the director.
status client=XXXX
is maybe more practical than starting a backup.
or running estimate job=YYYY listing
so you don't have to reserve a drive and a volume ...
raschu

raschu

2024-01-19 11:25

reporter   ~0005704

Thank you Bruno.

Today we were able to check the problem.

After some actions (reinstall, config-checks) the backup runs.

We'll wait and see if it works over the weekend.


Thanks Ralf



But there are still errors:


19-Jan-2024 09:33:44.082607 bareos-fd (10): lib/parse_conf.h:442-0 ConfigResourcesContainer: new configuration_resources_ 55de22d48e30
19-Jan-2024 09:33:44.082658 bareos-fd (100): lib/parse_conf.cc:182-0 config file = /etc/bareos/bareos-fd.d/*/*.conf
19-Jan-2024 09:33:44.082733 bareos-fd (100): lib/lex.cc:311-0 glob /etc/bareos/bareos-fd.d/*/*.conf: 4 files
19-Jan-2024 09:33:44.082741 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/client/myself.conf
19-Jan-2024 09:33:44.082761 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-dir.conf
19-Jan-2024 09:33:44.082768 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-mon.conf
19-Jan-2024 09:33:44.082777 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/messages/Standard.conf
19-Jan-2024 09:33:44.082944 bareos-fd (100): lib/lex.cc:311-0 glob /etc/bareos/bareos-fd.d/*/*.conf: 4 files
19-Jan-2024 09:33:44.082960 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/client/myself.conf
19-Jan-2024 09:33:44.082964 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-dir.conf
19-Jan-2024 09:33:44.082968 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-mon.conf
19-Jan-2024 09:33:44.082972 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/messages/Standard.conf
19-Jan-2024 09:33:44.084094 host-to-backup-fd (100): lib/bsys.cc:630-0 ReadStateFile seek to 192
19-Jan-2024 09:33:44.084115 host-to-backup-fd (100): lib/recent_job_results_list.cc:57-0 Read num_items=10
19-Jan-2024 09:33:44.084127 host-to-backup-fd (150): filed/fd_plugins.cc:1625-0 plugin dir is NULL
19-Jan-2024 09:33:44.084281 host-to-backup-fd (10): filed/socket_server.cc:122-0 filed: listening on port 9102
19-Jan-2024 09:33:44.084297 host-to-backup-fd (10): filed/socket_server.cc:122-0 filed: listening on port 9102
19-Jan-2024 09:33:44.084305 host-to-backup-fd (100): lib/bnet_server_tcp.cc:150-0 Addresses host[ipv4;0.0.0.0;9102] host[ipv6;::;9102]
19-Jan-2024 09:36:37.464328 bareos-fd (10): lib/parse_conf.h:442-0 ConfigResourcesContainer: new configuration_resources_ 56133fd11e30
19-Jan-2024 09:36:37.464371 bareos-fd (100): lib/parse_conf.cc:182-0 config file = /etc/bareos/bareos-fd.d/*/*.conf
19-Jan-2024 09:36:37.464449 bareos-fd (100): lib/lex.cc:311-0 glob /etc/bareos/bareos-fd.d/*/*.conf: 4 files
19-Jan-2024 09:36:37.464458 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/client/myself.conf
19-Jan-2024 09:36:37.464465 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-dir.conf
19-Jan-2024 09:36:37.464469 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-mon.conf
19-Jan-2024 09:36:37.464475 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/messages/Standard.conf
19-Jan-2024 09:36:37.464670 bareos-fd (100): lib/lex.cc:311-0 glob /etc/bareos/bareos-fd.d/*/*.conf: 4 files
19-Jan-2024 09:36:37.464678 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/client/myself.conf
19-Jan-2024 09:36:37.464683 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-dir.conf
19-Jan-2024 09:36:37.464686 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/director/bareos-mon.conf
19-Jan-2024 09:36:37.464690 bareos-fd (100): lib/lex.cc:214-0 open config file: /etc/bareos/bareos-fd.d/messages/Standard.conf
19-Jan-2024 09:36:37.465932 host-to-backup (100): lib/bsys.cc:630-0 ReadStateFile seek to 192
19-Jan-2024 09:36:37.465944 host-to-backup (100): lib/recent_job_results_list.cc:57-0 Read num_items=10
19-Jan-2024 09:36:37.465958 host-to-backup (150): filed/fd_plugins.cc:1625-0 plugin dir is NULL
19-Jan-2024 09:36:37.466096 host-to-backup (10): filed/socket_server.cc:122-0 filed: listening on port 9102
19-Jan-2024 09:36:37.466103 host-to-backup (10): filed/socket_server.cc:122-0 filed: listening on port 9102
19-Jan-2024 09:36:37.466116 host-to-backup (100): lib/bnet_server_tcp.cc:150-0 Addresses host[ipv4;0.0.0.0;9102] host[ipv6;::;9102]
19-Jan-2024 09:36:55.722503 host-to-backup (100): lib/bsock.cc:85-0 Construct BareosSocket
19-Jan-2024 09:36:55.723198 host-to-backup (100): lib/tls_openssl_private.cc:59-0 Construct TlsOpenSslPrivate
19-Jan-2024 09:36:55.723385 host-to-backup (100): lib/tls_openssl_private.cc:632-0 Set tcp filedescriptor: <5>
19-Jan-2024 09:36:55.723391 host-to-backup (100): lib/tls_openssl_private.cc:650-0 Set protocol: <>
19-Jan-2024 09:36:55.723395 host-to-backup (100): lib/tls_openssl_private.cc:572-0 Set ca_certfile: <>
19-Jan-2024 09:36:55.723398 host-to-backup (100): lib/tls_openssl_private.cc:578-0 Set ca_certdir: <>
19-Jan-2024 09:36:55.723400 host-to-backup (100): lib/tls_openssl_private.cc:584-0 Set crlfile_: <>
19-Jan-2024 09:36:55.723403 host-to-backup (100): lib/tls_openssl_private.cc:590-0 Set certfile_: <>
19-Jan-2024 09:36:55.723406 host-to-backup (100): lib/tls_openssl_private.cc:596-0 Set keyfile_: <>
19-Jan-2024 09:36:55.723408 host-to-backup (100): lib/tls_openssl_private.cc:614-0 Set dhfile_: <>
19-Jan-2024 09:36:55.723411 host-to-backup (100): lib/tls_openssl_private.cc:638-0 Set cipherlist: <>
19-Jan-2024 09:36:55.723413 host-to-backup (100): lib/tls_openssl_private.cc:644-0 Set ciphersuites: <>
19-Jan-2024 09:36:55.723416 host-to-backup (100): lib/tls_openssl_private.cc:620-0 Set Verify Peer: <false>
19-Jan-2024 09:36:55.723418 host-to-backup (100): lib/tls_openssl_private.cc:626-0 Set ktls: <false>
19-Jan-2024 09:36:55.723568 host-to-backup (100): lib/tls_openssl_private.cc:496-0 psk_server_cb. identitiy: R_DIRECTOR bareos-dir.
19-Jan-2024 09:36:55.723583 host-to-backup (100): lib/tls_openssl_private.cc:517-0 psk_server_cb. result: 32.
19-Jan-2024 09:36:55.724231 host-to-backup (50): lib/bnet.cc:143-0 TLS server negotiation established.
19-Jan-2024 09:36:55.724294 host-to-backup (110): filed/socket_server.cc:82-0 Conn: Hello Director bareos-dir calling

19-Jan-2024 09:36:55.724305 host-to-backup (110): filed/socket_server.cc:87-0 Got a DIR connection at 19-Jan-2024 09:36:55
19-Jan-2024 09:36:55.724313 host-to-backup (100): lib/jcr.cc:185-0 Construct JobControlRecord
19-Jan-2024 09:36:55.724338 host-to-backup (120): filed/dir_cmd.cc:545-0 Calling Authenticate
19-Jan-2024 09:36:55.724544 host-to-backup (50): lib/cram_md5.cc:106-0 send: auth cram-md5 <2119645918.1705653415@R_CLIENT::host-to-backup> ssl=2
19-Jan-2024 09:36:55.765608 host-to-backup (100): lib/cram_md5.cc:167-0 cram-get received: auth cram-md5 <614168299.1705653415@R_DIRECTOR::bareos-dir> ssl=2
19-Jan-2024 09:36:55.765628 host-to-backup (50): lib/cram_md5.cc:61-0 my_name: <R_CLIENT::host-to-backup> - challenge_name: <R_DIRECTOR::bareos-dir>
19-Jan-2024 09:36:55.765644 host-to-backup (99): lib/cram_md5.cc:232-0 sending resp to challenge: WyR2jX+rv6o8nn8Id0/GwB
19-Jan-2024 09:36:55.766125 host-to-backup (120): filed/dir_cmd.cc:546-0 OK Authenticate
19-Jan-2024 09:36:55.766412 host-to-backup (200): lib/runscript.cc:112-0 runscript: running all RunScript object (ClientAfterJob) JobStatus=C
19-Jan-2024 09:36:55.766423 host-to-backup (150): filed/fd_plugins.cc:358-0 No bplugin_list: GeneratePluginEvent ignored.
19-Jan-2024 09:36:55.767129 host-to-backup (100): lib/tls_openssl_private.cc:90-0 Destruct TlsOpenSslPrivate
19-Jan-2024 09:36:55.767159 host-to-backup (100): lib/bsock.cc:137-0 Destruct BareosSocket
19-Jan-2024 09:36:55.767170 host-to-backup (100): lib/jcr.cc:270-0 FreeCommonJcr: 7fa2f4014aa0
19-Jan-2024 09:36:55.767177 host-to-backup (100): filed/dir_cmd.cc:482-0 Done with FreeJcr
19-Jan-2024 09:36:58.408522 host-to-backup (100): lib/bsock.cc:85-0 Construct BareosSocket
19-Jan-2024 09:36:58.491221 host-to-backup (100): lib/tls_openssl_private.cc:59-0 Construct TlsOpenSslPrivate
19-Jan-2024 09:36:58.491355 host-to-backup (100): lib/tls_openssl_private.cc:632-0 Set tcp filedescriptor: <5>
19-Jan-2024 09:36:58.491361 host-to-backup (100): lib/tls_openssl_private.cc:650-0 Set protocol: <>
19-Jan-2024 09:36:58.491364 host-to-backup (100): lib/tls_openssl_private.cc:572-0 Set ca_certfile: <>
19-Jan-2024 09:36:58.491367 host-to-backup (100): lib/tls_openssl_private.cc:578-0 Set ca_certdir: <>
19-Jan-2024 09:36:58.491369 host-to-backup (100): lib/tls_openssl_private.cc:584-0 Set crlfile_: <>
19-Jan-2024 09:36:58.491372 host-to-backup (100): lib/tls_openssl_private.cc:590-0 Set certfile_: <>
19-Jan-2024 09:36:58.491375 host-to-backup (100): lib/tls_openssl_private.cc:596-0 Set keyfile_: <>
19-Jan-2024 09:36:58.491377 host-to-backup (100): lib/tls_openssl_private.cc:614-0 Set dhfile_: <>
19-Jan-2024 09:36:58.491379 host-to-backup (100): lib/tls_openssl_private.cc:638-0 Set cipherlist: <>
19-Jan-2024 09:36:58.491382 host-to-backup (100): lib/tls_openssl_private.cc:644-0 Set ciphersuites: <>
19-Jan-2024 09:36:58.491384 host-to-backup (100): lib/tls_openssl_private.cc:620-0 Set Verify Peer: <false>
19-Jan-2024 09:36:58.491387 host-to-backup (100): lib/tls_openssl_private.cc:626-0 Set ktls: <false>
19-Jan-2024 09:36:58.491476 host-to-backup (100): lib/tls_openssl_private.cc:496-0 psk_server_cb. identitiy: R_DIRECTOR bareos-mon.
19-Jan-2024 09:36:58.491485 host-to-backup (100): lib/tls_openssl_private.cc:517-0 psk_server_cb. result: 32.
19-Jan-2024 09:36:58.491544 host-to-backup (50): lib/crypto_openssl.cc:1593-0 jcr=0 Connect failure: ERR=error:141FA0FD:SSL routines:tls_psk_do_binder:binder does not verify
19-Jan-2024 09:36:58.491917 host-to-backup (100): lib/tls_openssl_private.cc:90-0 Destruct TlsOpenSslPrivate
19-Jan-2024 09:36:58.491925 host-to-backup (50): lib/bsock.cc:645-0 TLS negotiation failed.
19-Jan-2024 09:36:58.491957 host-to-backup (100): lib/bsock.cc:137-0 Destruct BareosSocket
bruno-at-bareos

bruno-at-bareos

2024-01-23 13:47

manager   ~0005711

Rough guess : Look like the monitor console is not correctly configured

19-Jan-2024 09:36:58.491476 host-to-backup (100): lib/tls_openssl_private.cc:496-0 psk_server_cb. identitiy: R_DIRECTOR bareos-mon.
19-Jan-2024 09:36:58.491485 host-to-backup (100): lib/tls_openssl_private.cc:517-0 psk_server_cb. result: 32.
19-Jan-2024 09:36:58.491544 host-to-backup (50): lib/crypto_openssl.cc:1593-0 jcr=0 Connect failure: ERR=error:141FA0FD:SSL routines:tls_psk_do_binder:binder does not verify
19-Jan-2024 09:36:58.491917 host-to-backup (100): lib/tls_openssl_private.cc:90-0 Destruct TlsOpenSslPrivate
19-Jan-2024 09:36:58.491925 host-to-backup (50): lib/bsock.cc:645-0 TLS negotiation failed.
raschu

raschu

2024-01-24 18:04

reporter   ~0005718

Hi Bruno, ok. The backup works these days so it is fine for me. Thanks Ralf
bruno-at-bareos

bruno-at-bareos

2024-01-25 09:00

manager   ~0005720

Thanks for the report

Issue History

Date Modified Username Field Change
2024-01-12 10:04 raschu New Issue
2024-01-16 14:36 bruno-at-bareos Note Added: 0005685
2024-01-19 11:25 raschu Note Added: 0005704
2024-01-23 13:47 bruno-at-bareos Note Added: 0005711
2024-01-24 18:04 raschu Note Added: 0005718
2024-01-25 09:00 bruno-at-bareos Assigned To => bruno-at-bareos
2024-01-25 09:00 bruno-at-bareos Status new => closed
2024-01-25 09:00 bruno-at-bareos Resolution open => no change required
2024-01-25 09:00 bruno-at-bareos Note Added: 0005720