Try running the bacula-fd with -d 300 to capture much more information when it
fails.

Also, what is the FileSet definition?

Is the Storage Daemon also running Bacula version 15.0.2?

__Martin


>>>>> On Thu, 5 Sep 2024 19:44:40 +0200, Dragan Milivojević said:
> 
> Hi all
> 
> An issue with Bacula version 15.0.2, basically Bacula fails to save files, 
> all that is
> stored is file names and no data, not even metadata.
> 
> For example:
> 
> 
> *list jobid=81
> +-------+------------+---------------------+------+-------+----------+----------+-----------+
> | jobid | name       | starttime           | type | level | jobfiles | 
> jobbytes | jobstatus |
> +-------+------------+---------------------+------+-------+----------+----------+-----------+
> |    81 | GalileoJob | 2024-09-03 21:29:10 | B    | I     |      480 |    
> 9,459 | T         |
> +-------+------------+---------------------+------+-------+----------+----------+-----------+
> *list files jobid=81
> +----------------------------------------------------------------------------------------------------+
> | filename                                                                    
>                          |
> +----------------------------------------------------------------------------------------------------+
> | /boot/grub2/grubenv                                                         
>                          |
> | 
> /home/galileo/.local/share/keybase/kbfs_settings/v1/kbfsSettings.leveldb/004100.log
>                   |
> 
> 
> Clipped for verbosity ...
> 
> | 
> /home/galileo/.config/google-chrome/CertificateRevocation/9084/manifest.json  
>                        |
> | /home/hs/tmp/drvo/                                                          
>                          |
> | /home/hs/tmp/drvo/drvo_notes.txt                                            
>                          |
> | /home/hs/tmp/drvo/fplrn008.pdf                                              
>                          |
> | 
> /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/_metadata/
>                    |
> | 
> /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/_metadata/verified_contents.json
>  |
> | /home/galileo/.config/google-chrome/CertificateRevocation/9082/_metadata/   
>                          |
> | 
> /home/galileo/.config/google-chrome/CertificateRevocation/9082/_metadata/verified_contents.json
>       |
> | /home/galileo/.config/google-chrome/Profile 
> 1/blob_storage/dfd7d552-d0fb-4fdd-8b75-ef7a9d27db71/     |
> | /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/    
>                          |
> | 
> /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/LICENSE
>                       |
> | 
> /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/keys.json
>                     |
> | 
> /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/manifest.fingerprint
>          |
> | 
> /home/galileo/.config/google-chrome/TrustTokenKeyCommitments/2024.9.3.1/manifest.json
>                 |
> | /home/galileo/.config/google-chrome/TpcdMetadata/2024.9.2.1/_metadata/      
>                          |
> | 
> /home/galileo/.config/google-chrome/TpcdMetadata/2024.9.2.1/_metadata/verified_contents.json
>          |
> | /home/galileo/.config/google-chrome/TpcdMetadata/2024.9.2.1/                
>                          |
> | 
> /home/galileo/.config/google-chrome/TpcdMetadata/2024.9.2.1/manifest.fingerprint
>                      |
> | /home/galileo/.config/google-chrome/TpcdMetadata/2024.9.2.1/manifest.json   
>                          |
> | /home/galileo/.config/google-chrome/TpcdMetadata/2024.9.2.1/metadata.pb     
>                          |
> +----------------------------------------------------------------------------------------------------+
> +-------+------------+---------------------+------+-------+----------+----------+-----------+
> | jobid | name       | starttime           | type | level | jobfiles | 
> jobbytes | jobstatus |
> +-------+------------+---------------------+------+-------+----------+----------+-----------+
> |    81 | GalileoJob | 2024-09-03 21:29:10 | B    | I     |      480 |    
> 9,459 | T         |
> +-------+------------+---------------------+------+-------+----------+----------+-----------+
> *restore jobid=81
> You have selected the following JobId: 81
> 
> Building directory tree for JobId(s) 81 ...  +++++
> 54 files inserted into the tree.
> 
> You are now entering file selection mode where you add (mark) and
> remove (unmark) files to be restored. No files are initially added, unless
> you used the "all" keyword on the command line.
> Enter "done" to leave this mode.
> 
> cwd is: /
> $ c/home/hs/tmp/drvo/o/
> cwd is: /home/hs/tmp/drvo/
> $ dir
> ----------   0 root     root               0  1970-01-01 01:00:00  
> /home/hs/tmp/drvo/drvo_notes.txt/
> ----------   0 root     root               0  1970-01-01 01:00:00  
> /home/hs/tmp/drvo/fplrn008.pdf/
> 
> 
> 
> $ mark drvo_notes.txt
> 1 file marked.
> $ done
> Bootstrap records written to /var/spool/bacula/bacula-dir.restore.7.bsr
> 
> The Job will require the following (*=>InChanger):
> Volume(s)                 Storage(s)                SD Device(s)
> ===========================================================================
> 
> Incr-Pool_Volume-001      DirectorAutochanger       LocalFileChgr0
> 
> Volumes marked with "*" are in the Autochanger.
> 
> 
> 2 files selected to be restored.
> 
> Defined Clients:
> 1: bacula-fd
> 2: galileo-fd
> Select the Client (1-2): 1
> Run Restore job
> JobName:         RestoreFiles
> Bootstrap:       /var/spool/bacula/bacula-dir.restore.7.bsr
> Where:           /bacula/restores
> Replace:         Always
> FileSet:         ServersFS
> Backup Client:   bacula-fd
> Restore Client:  bacula-fd
> Storage:         DirectorAutochanger
> When:            2024-09-05 00:42:55
> Catalog:         MyCatalog
> Priority:        10
> Plugin Options:  *None*
> OK to run? (Yes/mod/no): y
> Job queued. JobId=105
> *m
> 05-Sep 00:43 bacula-dir JobId 105: Start Restore Job 
> RestoreFiles.2024-09-05_00.42.58_04
> 05-Sep 00:43 bacula-dir JobId 105: Restoring files from JobId(s) 81
> 05-Sep 00:43 bacula-dir JobId 105: Connected to Storage "DirectorAutochanger" 
> at 10.1.0.93:9103 with TLS
> 05-Sep 00:43 bacula-dir JobId 105: Using Device "LocalFileChgr0-Dev1" to read.
> 05-Sep 00:43 bacula-dir JobId 105: Connected to Client "bacula-fd" at 
> localhost:9102 with TLS
> 05-Sep 00:43 bacula-fd JobId 105: Connected to Storage at 10.1.0.93:9103 with 
> TLS
> 05-Sep 00:43 bacula-sd JobId 105: Ready to read from volume 
> "Incr-Pool_Volume-001" on File device "LocalFileChgr0-Dev1" 
> (/bacula/storage/LocalFile/).
> 05-Sep 00:43 bacula-sd JobId 105: Forward spacing Volume 
> "Incr-Pool_Volume-001" to addr=2742713
> 05-Sep 00:43 bacula-sd JobId 105: Elapsed time=00:00:01, Transfer rate=220  
> Bytes/second
> 05-Sep 00:43 bacula-fd JobId 105: Warning: Unexpected stream="0" ignored. 
> This shouldn't happen!
> 05-Sep 00:43 bacula-fd JobId 105: Warning: Unexpected stream="0" ignored. 
> This shouldn't happen!
> 05-Sep 00:43 bacula-dir JobId 105: Bacula bacula-dir 15.0.2 (21Mar24):
> Build OS:               x86_64-redhat-linux-gnu redhat Enterprise 9.4
> JobId:                  105
> Job:                    RestoreFiles.2024-09-05_00.42.58_04
> Restore Client:         "bacula-fd" 15.0.2 (21Mar24) 
> x86_64-redhat-linux-gnu,redhat,Enterprise 9.4
> Where:                  /bacula/restores
> Replace:                Always
> Start time:             05-Sep-2024 00:43:00
> End time:               05-Sep-2024 00:43:00
> Elapsed time:           1 sec
> Files Expected:         2
> Files Restored:         2
> Bytes Restored:         0 (0 B)
> Rate:                   0.0 KB/s
> FD Errors:              0
> FD termination status:  OK
> SD termination status:  OK
> Termination:            Restore OK
> 
> 05-Sep 00:43 bacula-dir JobId 105: Begin pruning Jobs older than 1 month 5 
> days .
> 05-Sep 00:43 bacula-dir JobId 105: No Jobs found to prune.
> 05-Sep 00:43 bacula-dir JobId 105: Begin pruning Files.
> 05-Sep 00:43 bacula-dir JobId 105: No Files found to prune.
> 05-Sep 00:43 bacula-dir JobId 105: End auto prune.
> 
> 
> 
> 
> 
> 
> I ran a new job last nigh with bacula-fd in debug mode but nothing useful was 
> produced.
> 
> 
> 
> 
> 
> bacula-fd -f -c /etc/bacula/bacula-fd.conf -u root -g root -d 9 -v -m
> 
> 
> galileo-fd: events.c:48-106 Events: code=FJ0001 daemon=galileo-fd 
> ref=0x7ff3cc01cf08 type=job source=bacula-dir text=Job Start jobid=106 
> job=GalileoJob.2024-09-05_03.34.59_05
> galileo-fd: metaplugin.cpp:3159-106 kubernetes: handlePluginEvent (3) 
> pContext = 7ff3cc01aab8 thid = 7ff3df4006c0
> galileo-fd: events.c:48-106 Events: code=FJ0002 daemon=galileo-fd 
> ref=0x7ff3cc01cf08 type=job source=bacula-dir text=Job End jobid=106 
> job=GalileoJob.2024-09-05_03.34.59_05
> galileo-fd: metaplugin.cpp:3159-106 kubernetes: handlePluginEvent (4) 
> pContext = 7ff3cc01aab8 thid = 7ff3df4006c0
> galileo-fd: metaplugin.cpp:3159-106 kubernetes: handlePluginEvent (2) 
> pContext = 7ff3cc01aab8 thid = 7ff3df4006c0
> galileo-fd: events.c:48-106 Events: code=FC0001 daemon=galileo-fd 
> ref=0x7ff3cc01cf08 type=connection source=bacula-dir text=Director 
> disconnection
> galileo-fd: metaplugin.cpp:3113-106 kubernetes: freePlugin this=7ff3cc01aab8
> 
> 
> 
> *estimate job=GalileoJob level=Incremental accurate=yes listing
> Using Catalog "MyCatalog"
> Connecting to Client galileo-fd at 10.8.0.8:9102
> -rw-r--r--   1 root     root                   1180 2024-09-05 01:26:37  
> /root/bacula_exclude.list
> -rw-------   1 root     root                  16116 2024-09-05 01:26:37  
> /root/.viminfo
> dr-xr-x---  29 root     root                   4096 2024-09-05 01:26:37  /root
> 
> 
> 
> Clipped for verbosity ...
> 
> 
> 
> srwxr-xr-x   1 galileo  galileo                   0 2024-02-28 19:35:18  
> /home/galileo/.electrum/daemon_rpc_socket
> -rw-r--r--   1 galileo  galileo              524288 2024-09-05 03:33:36  
> /home/hs/tmp/bacula_test/test3.bin
> drwxr-xr-x   2 galileo  galileo                  74 2024-09-05 03:33:36  
> /home/hs/tmp/bacula_test
> 2000 OK estimate files=52 bytes=5,374,912
> *
> *
> *run job=GalileoJob level=Incremental accurate=yes
> Run Backup job
> JobName:  GalileoJob
> Level:    Incremental
> Client:   galileo-fd
> FileSet:  WorkStationsFS
> Pool:     Incr-Pool (From Job resource)
> Storage:  DirectorAutochanger (From Pool resource)
> When:     2024-09-05 03:34:57
> Priority: 10
> OK to run? (Yes/mod/no): y
> Job queued. JobId=106
> *
> You have messages.
> *m
> 05-Sep 03:35 bacula-dir JobId 106: Start Backup JobId 106, 
> Job=GalileoJob.2024-09-05_03.34.59_05
> 05-Sep 03:35 bacula-dir JobId 106: Connected to Storage "DirectorAutochanger" 
> at 10.1.0.93:9103 with TLS
> 05-Sep 03:35 bacula-dir JobId 106: Using Device "LocalFileChgr0-Dev1" to 
> write.
> 05-Sep 03:35 bacula-dir JobId 106: Connected to Client "galileo-fd" at 
> 10.8.0.8:9102 with TLS
> 05-Sep 03:35 galileo-fd JobId 106: Connected to Storage at 10.1.0.93:9103 
> with TLS
> 05-Sep 03:35 bacula-dir JobId 106: Sending Accurate information to the FD.
> 05-Sep 03:35 bacula-sd JobId 106: Volume "Incr-Pool_Volume-004" previously 
> written, moving to end of data.
> 05-Sep 03:35 bacula-sd JobId 106: Ready to append to end of Volume 
> "Incr-Pool_Volume-004" size=10,677,763
> 05-Sep 03:35 bacula-sd JobId 106: Elapsed time=00:00:14, Transfer rate=2.884 
> K Bytes/second
> 05-Sep 03:35 bacula-sd JobId 106: Sending spooled attrs to the Director. 
> Despooling 53,484 bytes ...
> 05-Sep 03:35 bacula-dir JobId 106: Bacula bacula-dir 15.0.2 (21Mar24):
> Build OS:               x86_64-redhat-linux-gnu redhat Enterprise 9.4
> JobId:                  106
> Job:                    GalileoJob.2024-09-05_03.34.59_05
> Backup Level:           Incremental, since=2024-09-05 00:46:06
> Client:                 "galileo-fd" 15.0.2 (21Mar24) 
> x86_64-redhat-linux-gnu,redhat,
> FileSet:                "WorkStationsFS" 2024-08-16 01:21:39
> Pool:                   "Incr-Pool" (From Job resource)
> Catalog:                "MyCatalog" (From Client resource)
> Storage:                "DirectorAutochanger" (From Pool resource)
> Scheduled time:         05-Sep-2024 03:34:57
> Start time:             05-Sep-2024 03:35:01
> End time:               05-Sep-2024 03:35:53
> Elapsed time:           52 secs
> Priority:               10
> FD Files Written:       269
> SD Files Written:       269
> FD Bytes Written:       3,479 (3.479 KB)
> SD Bytes Written:       40,379 (40.37 KB)
> Rate:                   0.1 KB/s
> Software Compression:   99.2% 120.6:1
> Comm Line Compression:  11.9% 1.1:1
> Snapshot/VSS:           no
> Encryption:             no
> Accurate:               yes
> Volume name(s):         Incr-Pool_Volume-004
> Volume Session Id:      45
> Volume Session Time:    1725159919
> Last Volume Bytes:      10,722,402 (10.72 MB)
> Non-fatal FD errors:    0
> SD Errors:              0
> FD termination status:  OK
> SD termination status:  OK
> Termination:            Backup OK
> 
> 05-Sep 03:35 bacula-dir JobId 106: Begin pruning Jobs older than 1 month 5 
> days .
> 05-Sep 03:35 bacula-dir JobId 106: No Jobs found to prune.
> 05-Sep 03:35 bacula-dir JobId 106: Begin pruning Files.
> 05-Sep 03:35 bacula-dir JobId 106: No Files found to prune.
> 05-Sep 03:35 bacula-dir JobId 106: End auto prune.
> 
> *restore jobid=106
> Using Catalog "MyCatalog"
> You have selected the following JobId: 106
> 
> Building directory tree for JobId(s) 106 ...  +
> 11 files inserted into the tree.
> 
> You are now entering file selection mode where you add (mark) and
> remove (unmark) files to be restored. No files are initially added, unless
> you used the "all" keyword on the command line.
> Enter "done" to leave this mode.
> 
> cwd is: /
> $ cd /home/hs/tmp/bacula_tests
> cwd is: /home/hs/tmp/bacula_test/
> $ dir
> ----------   0 root     root               0  1970-01-01 01:00:00  
> /home/hs/tmp/bacula_test/test3.bin/
> $ mark test3.binin
> 1 file marked.
> $ done
> Bootstrap records written to /var/spool/bacula/bacula-dir.restore.8.bsr
> 
> The Job will require the following (*=>InChanger):
> Volume(s)                 Storage(s)                SD Device(s)
> ===========================================================================
> 
> Incr-Pool_Volume-004      DirectorAutochanger       LocalFileChgr0
> 
> Volumes marked with "*" are in the Autochanger.
> 
> 
> 1 file selected to be restored.
> 
> Defined Clients:
> 1: bacula-fd
> 2: galileo-fd
> Select the Client (1-2): 1
> Run Restore job
> JobName:         RestoreFiles
> Bootstrap:       /var/spool/bacula/bacula-dir.restore.8.bsr
> Where:           /bacula/restores
> Replace:         Always
> FileSet:         ServersFS
> Backup Client:   bacula-fd
> Restore Client:  bacula-fd
> Storage:         DirectorAutochanger
> When:            2024-09-05 03:37:02
> Catalog:         MyCatalog
> Priority:        10
> Plugin Options:  *None*
> OK to run? (Yes/mod/no): y
> Job queued. JobId=107
> *
> You have messages.
> *m
> 05-Sep 03:37 bacula-dir JobId 107: Start Restore Job 
> RestoreFiles.2024-09-05_03.37.04_06
> 05-Sep 03:37 bacula-dir JobId 107: Restoring files from JobId(s) 106
> 05-Sep 03:37 bacula-dir JobId 107: Connected to Storage "DirectorAutochanger" 
> at 10.1.0.93:9103 with TLS
> 05-Sep 03:37 bacula-dir JobId 107: Using Device "LocalFileChgr0-Dev1" to read.
> 05-Sep 03:37 bacula-dir JobId 107: Connected to Client "bacula-fd" at 
> localhost:9102 with TLS
> 05-Sep 03:37 bacula-fd JobId 107: Connected to Storage at 10.1.0.93:9103 with 
> TLS
> 05-Sep 03:37 bacula-sd JobId 107: Ready to read from volume 
> "Incr-Pool_Volume-004" on File device "LocalFileChgr0-Dev1" 
> (/bacula/storage/LocalFile/).
> 05-Sep 03:37 bacula-sd JobId 107: Forward spacing Volume 
> "Incr-Pool_Volume-004" to addr=10677763
> 05-Sep 03:37 bacula-sd JobId 107: Elapsed time=00:00:01, Transfer rate=117  
> Bytes/second
> 05-Sep 03:37 bacula-fd JobId 107: Warning: Unexpected stream="0" ignored. 
> This shouldn't happen!
> 05-Sep 03:37 bacula-dir JobId 107: Bacula bacula-dir 15.0.2 (21Mar24):
> Build OS:               x86_64-redhat-linux-gnu redhat Enterprise 9.4
> JobId:                  107
> Job:                    RestoreFiles.2024-09-05_03.37.04_06
> Restore Client:         "bacula-fd" 15.0.2 (21Mar24) 
> x86_64-redhat-linux-gnu,redhat,Enterprise 9.4
> Where:                  /bacula/restores
> Replace:                Always
> Start time:             05-Sep-2024 03:37:06
> End time:               05-Sep-2024 03:37:06
> Elapsed time:           1 sec
> Files Expected:         1
> Files Restored:         1
> Bytes Restored:         0 (0 B)
> Rate:                   0.0 KB/s
> FD Errors:              0
> FD termination status:  OK
> SD termination status:  OK
> Termination:            Restore OK
> 
> 05-Sep 03:37 bacula-dir JobId 107: Begin pruning Jobs older than 1 month 5 
> days .
> 05-Sep 03:37 bacula-dir JobId 107: No Jobs found to prune.
> 05-Sep 03:37 bacula-dir JobId 107: Begin pruning Files.
> 05-Sep 03:37 bacula-dir JobId 107: No Files found to prune.
> 05-Sep 03:37 bacula-dir JobId 107: End auto prune.
> 
> 
> 
> Unfortunately the issue seems to be intermittent, I can't construct a 
> repeatable test case.
> 2 days ago I did practically the same and there were no issues. Few days 
> before that the issue was repeatable.
> 
> I created a new test job with a new file set (just a few files in a test 
> folder) but I wasn't able to trigger the issue.
> Only hint so far was that if I disable accurate backups it seems to fix it 
> but that was only one run so far, so not confirmed.
> 
> When I first setup this backup server (I was previously using an ancient 
> Bacula v5 for about 13 years) I noticed other issues:
> 
> When setting this server I ran the initial full backup and a couple of 
> incrementals.
> Every time I ran a new incremental bacula would include ancient files from my 
> various archived projects that haven't changed
> in years and it constantly includes socket files that haven't been touched.
> 
> So has anyone seen anything like this before and how to proceed with 
> debugging this?
> 
> Thanks
> Dragan
>   
> 
> 
> _______________________________________________
> Bacula-users mailing list
> Bacula-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
> 


_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Reply via email to