View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001417bareos-corefile daemonpublic2022-01-03 06:562022-09-21 15:17
ReporterBeshiros Assigned Tobruno-at-bareos  
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionduplicate 
PlatformMacOSMacOS XOS Version10
Product Version21.0.0 
Summary0001417: Backups triggering twice with "Run On Incoming Connect Interval
DescriptionI am currently setting up backups for Laptops using the "Run On Incoming Connect Interval" feature. So far, backups are triggering upon connections every 12 to 16 hours, so I'm happy with that. However, every time backups are triggered, a second backup is scheduled to run immediately after. Backups running on normal schedules do not have this problem. Both client (MacOS) and director (Docker running on Linux) are running version 20.0.1. Here is an example of the log :

1623 Backup Cosmos 2021-12-27 22:56:09 2021-12-27 22:56:15 MacHome Incremental 18 6.37 MB
1622 Backup Cosmos 2021-12-27 22:55:09 2021-12-27 22:55:24 MacHome Incremental 385 291.17 MB
1610 Backup Cosmos 2021-12-27 09:06:38 2021-12-27 09:08:24 MacHome Incremental 2340 4.69 GB
1609 Backup Cosmos 2021-12-27 09:04:48 2021-12-27 09:06:34 MacHome Incremental 2339 4.7 GB
1608 Backup Cosmos 2021-12-26 18:31:34 2021-12-26 18:33:37 MacHome Incremental 5138 5.15 GB
1607 Backup Cosmos 2021-12-26 18:29:04 2021-12-26 18:31:23 MacHome Incremental 5138 5.15 GB

Steps To ReproduceThe configuration of the job is as follows :

Job {
  Name = "Backup Cosmos"
  Client = "cosmos"
  JobDefs = "DefaultJob"
  FileSet = "MacHome"

  RunOnIncomingConnectInterval = 12h

   # Run Script with would ping monitoring system removed for simplicity
}

JobDefs {
  Name = "DefaultJob"
  Type = Backup
  Storage = File
  Messages = Standard
  Pool = Incremental
  Priority = 10
  Write Bootstrap = "/var/lib/bareos/%c.bsr"
  Full Backup Pool = Full
  Differential Backup Pool = Differential
  Incremental Backup Pool = Incremental
  Max Diff Interval = 10d
  Max Full Interval = 35d
}

Client {
   Name = cosmos
   Address = x.x.x.x
   Password = xyz

   Connection From Client To Director = yes
   Heartbeat Interval = 60
}

On the client, the following line is added to the myself.conf

Connection From Client To Director = yes
Additional InformationLooking at the client log, I noticed that when the first backup job is started on a client, a second socket it opened :

elita (100): lib/bsys.cc:576-0 ReadStateFile seek to 192
elita (100): lib/recent_job_results_list.cc:57-0 Read num_items=10
elita (10): filed/socket_server.cc:128-0 filed: listening on port 9102
elita (100): lib/jcr.cc:195-0 Construct JobControlRecord
elita (100): lib/bnet_server_tcp.cc:160-0 Addresses host[ipv4;0.0.0.0;9102]
elita (100): lib/bsock.cc:84-0 Construct BareosSocket
elita (100): lib/bsock.cc:163-0 All source addresses
elita (100): lib/bsock_tcp.cc:234-0 Current host[ipv4;10.0.1.204;9101] All host[ipv4;10.0.1.204;9101]
elita (100): lib/bsock_tcp.cc:152-0 who=bareos-dir host=10.0.1.204 port=9101
elita (100): lib/tls_openssl_private.cc:65-0 Construct TlsOpenSslPrivate
elita (100): lib/tls_openssl_private.cc:606-0 Set tcp filedescriptor: <4>
elita (100): lib/tls_openssl_private.cc:618-0 Set protocol: <>
elita (100): lib/tls_openssl_private.cc:552-0 Set ca_certfile: <>
elita (100): lib/tls_openssl_private.cc:558-0 Set ca_certdir: <>
elita (100): lib/tls_openssl_private.cc:564-0 Set crlfile_: <>
elita (100): lib/tls_openssl_private.cc:570-0 Set certfile_: <>
elita (100): lib/tls_openssl_private.cc:576-0 Set keyfile_: <>
elita (100): lib/tls_openssl_private.cc:594-0 Set dhfile_: <>
elita (100): lib/tls_openssl_private.cc:612-0 Set cipherlist: <>
elita (100): lib/tls_openssl_private.cc:600-0 Set Verify Peer: <false>
elita (50): lib/tls_openssl.cc:65-0 Preparing TLS_PSK CLIENT context for identity R_CLIENT elita
elita (100): lib/tls_openssl_private.cc:537-0 psk_client_cb. identity: R_CLIENT elita.
elita (50): lib/bnet.cc:196-0 TLS client negotiation established.
elita (10): filed/dir_cmd.cc:2331-0 Opened connection with Director bareos-dir
elita (100): lib/cram_md5.cc:166-0 cram-get received: auth cram-md5 <489928684.1641010677@R_DIRECTOR::bareos-dir> ssl=1
elita (50): lib/cram_md5.cc:62-0 my_name: <R_CLIENT::elita> - challenge_name: <R_DIRECTOR::bareos-dir>
elita (99): lib/cram_md5.cc:231-0 sending resp to challenge: m89SGwF7Ax+VTU++K5+zEC
elita (50): lib/cram_md5.cc:106-0 send: auth cram-md5 <1288004040.1641010677@R_CLIENT::elita> ssl=1
elita (50): lib/cram_md5.cc:134-0 Authenticate OK f59utyt55ldroh+th4+gFD
elita (100): lib/jcr.cc:195-0 Construct JobControlRecord
elita (100): filed/dir_cmd.cc:462-0 <dird: JobId=1695 Job=Backup_Elita.2022-01-01_04.18.15_21 SDid=24 SDtime=1640922268 Authorization=LCEA-AANP-JPBG-CCLB-FEOF-NNMP-FMBO-PIFL ssl=4

elita (100): lib/bsock.cc:84-0 Construct BareosSocket
elita (100): lib/bsock.cc:163-0 All source addresses
elita (100): filed/dir_cmd.cc:473-0 Executing JobId= command.
elita (100): lib/bsock_tcp.cc:234-0 Current host[ipv4;10.0.1.204;9101] All host[ipv4;10.0.1.204;9101]
elita (5): filed/dir_cmd.cc:1623-0 set sd auth key
elita (5): filed/dir_cmd.cc:1626-0 set sd ssl_policy to 4
elita (100): lib/bsock_tcp.cc:152-0 who=bareos-dir host=10.0.1.204 port=9101
elita (100): lib/tls_openssl_private.cc:65-0 Construct TlsOpenSslPrivate
elita (100): lib/tls_openssl_private.cc:606-0 Set tcp filedescriptor: <5>
elita (100): lib/tls_openssl_private.cc:618-0 Set protocol: <>
elita (100): lib/tls_openssl_private.cc:552-0 Set ca_certfile: <>
elita (100): lib/tls_openssl_private.cc:558-0 Set ca_certdir: <>
elita (100): lib/tls_openssl_private.cc:564-0 Set crlfile_: <>
elita (100): lib/tls_openssl_private.cc:570-0 Set certfile_: <>
elita (100): lib/tls_openssl_private.cc:576-0 Set keyfile_: <>
elita (100): lib/tls_openssl_private.cc:594-0 Set dhfile_: <>
elita (100): lib/tls_openssl_private.cc:612-0 Set cipherlist: <>
elita (100): lib/tls_openssl_private.cc:600-0 Set Verify Peer: <false>
elita (50): lib/tls_openssl.cc:65-0 Preparing TLS_PSK CLIENT context for identity R_CLIENT elita
elita (100): lib/tls_openssl_private.cc:537-0 psk_client_cb. identity: R_CLIENT elita.
elita (50): lib/bnet.cc:196-0 TLS client negotiation established.
elita (10): filed/dir_cmd.cc:2331-0 Opened connection with Director bareos-dir
elita (100): filed/dir_cmd.cc:462-0 <dird: level = differential mtime_only=0

elita (100): filed/dir_cmd.cc:473-0 Executing level = command.
elita (10): filed/dir_cmd.cc:1447-0 LevelCmd: level = differential mtime_only=0
elita (100): filed/dir_cmd.cc:462-0 <dird: level = since_utime 1640620669 mtime_only=0 prev_job=Backup_Elita.2021-12-27_15.57.08_06

elita (100): filed/dir_cmd.cc:473-0 Executing level = command.
elita (100): lib/cram_md5.cc:166-0 elita (10): filed/dir_cmd.cc:1447-0 LevelCmd: level = since_utime 1640620669 mtime_only=0 prev_job=Backup_Elita.2021-12-27_15.57.08_06
cram-get received: auth cram-md5 <642302895.1641010697@R_DIRECTOR::bareos-dir> ssl=1
elita (100): filed/dir_cmd.cc:1499-0 since_time=1640620669 prev_job=Backup_Elita.2021-12-27_15.57.08_06
elita (50): lib/cram_md5.cc:62-0 my_name: <R_CLIENT::elita> - challenge_name: <R_DIRECTOR::bareos-dir>
elita (99): lib/cram_md5.cc:231-0 sending resp to challenge: K++4U7+Bt4UHJ4+U4QoiSB
elita (50): lib/cram_md5.cc:106-0 send: auth cram-md5 <861086444.1641010697@R_CLIENT::elita> ssl=1
elita (50): lib/cram_md5.cc:134-0 Authenticate OK cxBcYkYgy5xq17/ucR+b1D

According to this page ( https://docs.bareos.org/TasksAndConcepts/NetworkSetup.html ) this is normal behavior :

When a waiting connection is used for a job, the Bareos File Daemon will detect this and creates an additional connection. This is required, to keep the client responsive for additional commands, like cancel.

The problem is that the director detects this as a new incoming connection and triggers a second backup. I can even see the connect time change for the client in the Bareos-Dir Status (Client Initiated Connections (waiting for jobs)). Is there a special way to ignore this second connection, or is it possible that "Run On Incoming Connect Interval" is broken?
TagsNo tags attached.

Relationships

duplicate of 0001466 closedbruno-at-bareos Backups triggering twice with "Run On Incoming Connect Interval 

Activities

Beshiros

Beshiros

2022-01-03 06:57

reporter   ~0004444

I had the problem when running on Bareos 20.1. Upgrading to Bareos 21 and I still have the problem.
khvalera

khvalera

2022-05-26 18:53

reporter   ~0004625

Just ran into this same problem :( Linux Version 21.1.3
bruno-at-bareos

bruno-at-bareos

2022-09-21 15:17

manager   ~0004752

Hello sorry, could you please attach to 0001466, I will mark this one as duplicate even if it was created before, but solution will happen there.
Thanks
bruno-at-bareos

bruno-at-bareos

2022-09-21 15:17

manager   ~0004753

Fixes and discussion will happen in 1466

Issue History

Date Modified Username Field Change
2022-01-03 06:56 Beshiros New Issue
2022-01-03 06:57 Beshiros Note Added: 0004444
2022-05-26 18:53 khvalera Note Added: 0004625
2022-05-27 23:11 khvalera Issue cloned: 0001466
2022-09-21 15:17 bruno-at-bareos Note Added: 0004752
2022-09-21 15:17 bruno-at-bareos Assigned To => bruno-at-bareos
2022-09-21 15:17 bruno-at-bareos Status new => closed
2022-09-21 15:17 bruno-at-bareos Resolution open => duplicate
2022-09-21 15:17 bruno-at-bareos Note Added: 0004753
2022-09-21 15:17 bruno-at-bareos Relationship added duplicate of 0001466