Hi,
I get from time to time errors when backup up via my LTO-9 autochanger.
This happens mostly when I do a full backup (ca. 30 TB data), sometimes
when using differential backup.
I am using the updated mtx-changer-script by Bill Arlofski, as the one
out of the box was always running in timeouts when tape changing was needed.
This error popped up recently. And persisted now for several full
backups, now additionally for a differential one.
Anyone any idea where the problem is and how to solve it?
Thank you.
Cheers
Thorsten
->->-> Full Backup
01-Jun 00:30 -dir JobId 774: Start Backup JobId 774,
Job=Media.2024-06-01_00.30.01_49
01-Jun 00:30 -dir JobId 774: Using Device "LTO9-1" to write.
01-Jun 00:30 -sd JobId 774: Spooling data ...
01-Jun 02:30 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,244,987 MaxJobSpoolSize=1,000,000,000,000
01-Jun 02:30 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,244,987 bytes ...
01-Jun 03:44 -sd JobId 774: Despooling elapsed time = 01:04:45, Transfer rate =
257.4 M Bytes/second
01-Jun 03:44 -sd JobId 774: Spooling data again ...
01-Jun 04:47 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,243,817 MaxJobSpoolSize=1,000,000,000,000
01-Jun 04:47 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,243,817 bytes ...
01-Jun 06:06 -sd JobId 774: Despooling elapsed time = 01:07:27, Transfer rate =
247.0 M Bytes/second
01-Jun 06:06 -sd JobId 774: Spooling data again ...
01-Jun 07:06 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,241,132 MaxJobSpoolSize=1,000,000,000,000
01-Jun 07:06 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,241,132 bytes ...
01-Jun 08:09 -sd JobId 774: Despooling elapsed time = 00:56:43, Transfer rate =
293.8 M Bytes/second
01-Jun 08:09 -sd JobId 774: Spooling data again ...
01-Jun 09:19 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,240,635 MaxJobSpoolSize=1,000,000,000,000
01-Jun 09:19 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,240,635 bytes ...
01-Jun 10:22 -sd JobId 774: Despooling elapsed time = 01:02:16, Transfer rate =
267.6 M Bytes/second
01-Jun 10:22 -sd JobId 774: Spooling data again ...
01-Jun 11:16 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,241,201 MaxJobSpoolSize=1,000,000,000,000
01-Jun 11:16 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,241,201 bytes ...
01-Jun 12:13 -sd JobId 774: Despooling elapsed time = 00:57:01, Transfer rate =
292.3 M Bytes/second
01-Jun 12:13 -sd JobId 774: Spooling data again ...
01-Jun 17:43 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,240,167 MaxJobSpoolSize=1,000,000,000,000
01-Jun 17:43 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,240,167 bytes ...
01-Jun 18:40 -sd JobId 774: Despooling elapsed time = 00:57:30, Transfer rate =
289.8 M Bytes/second
01-Jun 18:40 -sd JobId 774: Spooling data again ...
02-Jun 00:24 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,239,418 MaxJobSpoolSize=1,000,000,000,000
02-Jun 00:24 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,239,418 bytes ...
02-Jun 01:27 -sd JobId 774: Despooling elapsed time = 01:03:48, Transfer rate =
261.2 M Bytes/second
02-Jun 01:28 -sd JobId 774: Spooling data again ...
02-Jun 18:51 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,241,639 MaxJobSpoolSize=1,000,000,000,000
02-Jun 18:51 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,241,639 bytes ...
02-Jun 20:00 -sd JobId 774: Despooling elapsed time = 01:09:28, Transfer rate =
239.9 M Bytes/second
02-Jun 20:00 -sd JobId 774: Spooling data again ...
03-Jun 08:41 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,242,356 MaxJobSpoolSize=1,000,000,000,000
03-Jun 08:41 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,242,356 bytes ...
03-Jun 09:39 -sd JobId 774: Despooling elapsed time = 00:58:38, Transfer rate =
284.2 M Bytes/second
03-Jun 09:40 -sd JobId 774: Spooling data again ...
03-Jun 12:24 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,244,895 MaxJobSpoolSize=1,000,000,000,000
03-Jun 12:24 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,244,895 bytes ...
03-Jun 13:23 -sd JobId 774: Despooling elapsed time = 00:58:22, Transfer rate =
285.5 M Bytes/second
03-Jun 13:23 -sd JobId 774: Spooling data again ...
03-Jun 14:26 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,245,230 MaxJobSpoolSize=1,000,000,000,000
03-Jun 14:26 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,245,230 bytes ...
03-Jun 15:35 -sd JobId 774: Despooling elapsed time = 01:09:12, Transfer rate =
240.8 M Bytes/second
03-Jun 15:35 -sd JobId 774: Spooling data again ...
03-Jun 16:31 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,244,372 MaxJobSpoolSize=1,000,000,000,000
03-Jun 16:31 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,244,372 bytes ...
03-Jun 17:30 -sd JobId 774: Despooling elapsed time = 00:59:25, Transfer rate =
280.5 M Bytes/second
03-Jun 17:30 -sd JobId 774: Spooling data again ...
03-Jun 18:21 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,244,044 MaxJobSpoolSize=1,000,000,000,000
03-Jun 18:21 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,244,044 bytes ...
03-Jun 19:18 -sd JobId 774: Despooling elapsed time = 00:57:25, Transfer rate =
290.2 M Bytes/second
03-Jun 19:18 -sd JobId 774: Spooling data again ...
03-Jun 20:10 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,243,835 MaxJobSpoolSize=1,000,000,000,000
03-Jun 20:10 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,243,835 bytes ...
03-Jun 21:08 -sd JobId 774: Despooling elapsed time = 00:57:39, Transfer rate =
289.1 M Bytes/second
03-Jun 21:08 -sd JobId 774: Spooling data again ...
03-Jun 21:58 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,245,149 MaxJobSpoolSize=1,000,000,000,000
03-Jun 21:58 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,245,149 bytes ...
03-Jun 23:13 -sd JobId 774: Despooling elapsed time = 01:14:34, Transfer rate =
223.5 M Bytes/second
03-Jun 23:13 -sd JobId 774: Spooling data again ...
04-Jun 00:34 -sd JobId 774: User specified Job spool size reached:
JobSpoolSize=1,000,000,244,531 MaxJobSpoolSize=1,000,000,000,000
04-Jun 00:34 -sd JobId 774: Writing spooled data to Volume. Despooling
1,000,000,244,531 bytes ...
04-Jun 00:53 -sd JobId 774: [SI0202] End of Volume "000002L9" at 340:33685 on device
"LTO9-1" (/dev/nst0). Write of 1048576 bytes got -1.
04-Jun 00:54 -sd JobId 774: Re-read of last block succeeded.
04-Jun 00:54 -sd JobId 774: End of medium on Volume "000002L9"
Bytes=18,395,174,098,944 Blocks=17,543,006 at 04-Jun-2024 00:54.
04-Jun 00:54 -sd JobId 774: 3307 Issuing autochanger "unload Volume 000002L9, Slot
5, Drive 0" command.
04-Jun 01:02 -sd JobId 774: 3995 Bad autochanger "unload Volume 000002L9, Slot 5,
Drive 0": ERR=Child died from signal 15: Termination
Results=Program killed by Bacula (timeout)
04-Jun 01:02 -dir JobId 774: There are no more Jobs associated with Volume
"000005L9". Marking it purged.
04-Jun 01:02 -dir JobId 774: All records pruned from Volume "000005L9"; marking it
"Purged"
04-Jun 01:02 -dir JobId 774: Recycled volume "000005L9"
04-Jun 01:02 -sd JobId 774: 3304 Issuing autochanger "load Volume 000005L9, Slot 6,
Drive 0" command.
04-Jun 01:07 -sd JobId 774: Fatal error: 3992 Bad autochanger "load Volume 000005L9
Slot 6, Drive 0": ERR=Child died from signal 15: Termination.
Results=Program killed by Bacula (timeout)
04-Jun 01:07 -sd JobId 774: Despooling elapsed time = 00:33:08, Transfer rate =
503.0 M Bytes/second
04-Jun 01:07 -sd JobId 774: Elapsed time=72:37:29, Transfer rate=61.18 M
Bytes/second
04-Jun 01:07 -fd JobId 774: Error: bsock.c:395 Wrote 65540 bytes to Storage
daemon:server06.brace.de:9103, but only 32768 accepted.
04-Jun 01:07 -fd JobId 774: Fatal error: backup.c:911 Network send error to SD.
ERR=Die Verbindung wurde vom Kommunikationspartner zurückgesetzt
04-Jun 01:07 -fd JobId 774: Error: bsock.c:275 Socket has errors=1 on call to
Storage daemon:server06.brace.de:9103
04-Jun 01:07 -dir JobId 774: Error: Bacula -dir 11.0.6 (10Mar22):
Build OS: x86_64-suse-linux-gnu openSUSE Tumbleweed
JobId: 774
Job: Media.2024-06-01_00.30.01_49
Backup Level: Full
Client: "-fd" 11.0.6 (10Mar22)
x86_64-suse-linux-gnu,openSUSE,Tumbleweed
FileSet: "mp3" 2023-05-28 10:49:51
Pool: "Tape" (From Job resource)
Catalog: "MyCatalog" (From Client resource)
Storage: "AutoChangerLTO" (From Job resource)
Scheduled time: 01-Jun-2024 00:30:00
Start time: 01-Jun-2024 00:30:03
End time: 04-Jun-2024 01:07:43
Elapsed time: 3 days 37 mins 40 secs
Priority: 10
FD Files Written: 114,098
SD Files Written: 114,098
FD Bytes Written: 15,996,274,768,684 (15.99 TB)
SD Bytes Written: 15,996,262,458,434 (15.99 TB)
Rate: 61180.6 KB/s
Software Compression: None
Comm Line Compression: 52.3% 2.1:1
Snapshot/VSS: no
Encryption: no
Accurate: no
Volume name(s): 000002L9
Volume Session Id: 47
Volume Session Time: 1715341026
Last Volume Bytes: 1 (1 B)
Non-fatal FD errors: 2
SD Errors: 1
FD termination status: Error
SD termination status: Error
Termination: *** Backup Error ***
<-<-<- differential ->->->
03-Jun 23:05 -dir JobId 777: Start Backup JobId 777,
Job=FileServer_Full.2024-06-03_23.05.00_52
03-Jun 23:05 -dir JobId 777: Using Device "LTO9-1" to write.
03-Jun 23:05 -sd JobId 777: Spooling data ...
03-Jun 23:12 -fd JobId 777: Could not stat
"/mnt/data/imap/mailarchiv/cyrus-directory1-20240531-23.tar.xz": ERR=Datei oder
Verzeichnis nicht gefunden
04-Jun 01:41 -sd JobId 777: User specified Job spool size reached:
JobSpoolSize=1,000,000,242,693 MaxJobSpoolSize=1,000,000,000,000
04-Jun 01:41 -sd JobId 777: Writing spooled data to Volume. Despooling
1,000,000,242,693 bytes ...
04-Jun 01:41 -sd JobId 777: Fatal error: block.c:163 [SF0205] Attempt to write on
read-only Volume. dev="LTO9-1" (/dev/nst0)
04-Jun 01:41 -sd JobId 777: Despooling elapsed time = 00:00:01, Transfer rate =
1.000 T Bytes/second
04-Jun 01:41 -sd JobId 777: Elapsed time=02:36:40, Transfer rate=106.3 M
Bytes/second
04-Jun 01:41 -fd JobId 777: Error: bsock.c:395 Wrote 65540 bytes to Storage
daemon:server06.brace.de:9103, but only 16384 accepted.
04-Jun 01:41 -fd JobId 777: Fatal error: backup.c:911 Network send error to SD.
ERR=Die Verbindung wurde vom Kommunikationspartner zurückgesetzt
04-Jun 01:41 -fd JobId 777: Error: bsock.c:275 Socket has errors=1 on call to
Storage daemon:server06.brace.de:9103
04-Jun 01:41 -dir JobId 777: Error: Bacula -dir 11.0.6 (10Mar22):
Build OS: x86_64-suse-linux-gnu openSUSE Tumbleweed
JobId: 777
Job: FileServer_Full.2024-06-03_23.05.00_52
Backup Level: Differential, since=2024-05-03 23:05:03
Client: "-fd" 11.0.6 (10Mar22)
x86_64-suse-linux-gnu,openSUSE,Tumbleweed
FileSet: "Full Set" 2023-07-08 23:05:01
Pool: "Tape" (From Job resource)
Catalog: "MyCatalog" (From Client resource)
Storage: "AutoChangerLTO" (From Job resource)
Scheduled time: 03-Jun-2024 23:05:00
Start time: 03-Jun-2024 23:05:04
End time: 04-Jun-2024 01:41:56
Elapsed time: 2 hours 36 mins 52 secs
Priority: 10
FD Files Written: 36,986
SD Files Written: 36,986
FD Bytes Written: 999,789,041,213 (999.7 GB)
SD Bytes Written: 999,766,361,888 (999.7 GB)
Rate: 106224.9 KB/s
Software Compression: None
Comm Line Compression: 25.7% 1.3:1
Snapshot/VSS: no
Encryption: no
Accurate: no
Volume name(s):
Volume Session Id: 48
Volume Session Time: 1715341026
Last Volume Bytes: 1 (1 B)
Non-fatal FD errors: 3
SD Errors: 1
FD termination status: Error
SD termination status: Error
Termination: *** Backup Error ***
<-<-<-
--
+ This Document is confidential + Dieses Dokument ist vertraulich +
->->-> Please register athttps://www.brace.de for getting always the latest news and
best informations! <-<-<-
* FOCUS Business Innovationschampion 2023, for development, prozesses, business
model and organisation *
* Awarded as "Employer of the Future"
* WINNER OF THE EXPORT AWARD BAVARIA 2021 *
++++ Please visit us at those events:
* CosmeticBusiness, June 05 - June 06, 2024, Munich, Germany
*Microencapsulation Industrial Convention, July 22-25, 2024, Frankfurt, Germany*
*Food Ingredients Europe, Nov. 19-21, 2024 in Frankfurt, Germany*
++++
BRACE GmbH
Dr. Thorsten Brandau (thorsten.bran...@brace.de)
President
Am Mittelberg 5
D-63791 Karlstein
Germany
Tel: +49 6188 991757
Fax: +49 6188 991759
https://www.brace.de
HRB5004 (Amtsgericht Aschaffenburg), VAT DE151299833, Managing Directors: Dr.
Thorsten Brandau
IMPORTANT NOTICE:
This email may be confidential, may be legally privileged, and is for the
intended recipient only.
Access, disclosure, copying, distribution, or reliance on any of it by anyone
else is prohibited
and may be a criminal offence. Please delete if obtained in error and email
confirmation to the sender.
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
