On 31.01.2013 11:01, /me wrote: > - The seventh job [...] reported the tape change: [...] > - The next four jobs (always in order of completion) did however > still report writing to tape Daily_2, the last one apparently > even starting to use it well after it had been unloaded:
Looking at the director's completion reports I see that, although the SD logged "Committing to "Daily_2" for these jobs, the data went actually to "Daily_1": 30-Jan 20:15 bacula-sd JobId 6156: Committing spooled data to Volume "Daily_2". Despooling 1,602,040,011 bytes ... 30-Jan 20:22 bacula-sd JobId 6156: Despooling elapsed time = 00:00:30, Transfer rate = 53.40 M Bytes/second 30-Jan 20:22 bacula-sd JobId 6156: Elapsed time=00:12:46, Transfer rate=2.089 M Bytes/second 30-Jan 20:22 bacula-sd JobId 6156: Sending spooled attrs to the Director. Despooling 29,281 bytes ... 30-Jan 20:23 backup-dir JobId 6156: Bacula backup-dir 5.2.12 (12Sep12): Build OS: x86_64-redhat-linux-gnu redhat Enterprise release JobId: 6156 Job: w2k3-web-dmz.2013-01-30_20.05.01_37 Backup Level: Incremental, since=2013-01-29 20:11:20 Client: "w2k3-web-dmz-fd" 5.2.10 (28Jun12) Microsoft Windows Home ServerStandard Edition Service Pack 2 (build 3790),Cross-compile,Win32 FileSet: "w2k3-web-dmz" 2012-01-20 22:05:00 Pool: "Daily" (From Run pool override) Catalog: "MyCatalog" (From Client resource) Storage: "LTO-3" (From Job resource) Scheduled time: 30-Jan-2013 20:05:01 Start time: 30-Jan-2013 20:10:13 End time: 30-Jan-2013 20:23:03 Elapsed time: 12 mins 50 secs Priority: 10 FD Files Written: 90 SD Files Written: 90 FD Bytes Written: 1,600,536,726 (1.600 GB) SD Bytes Written: 1,600,551,989 (1.600 GB) Rate: 2078.6 KB/s Software Compression: None VSS: yes Encryption: no Accurate: no Volume name(s): Daily_1 Volume Session Id: 290 Volume Session Time: 1357817315 Last Volume Bytes: 5,355,915,264 (5.355 GB) Non-fatal FD errors: 0 SD Errors: 0 FD termination status: OK SD termination status: OK Termination: Backup OK So apparently that's just a logging imperfection and I'll stop worrying about that. > - Then, most disquieting, the next one reported that tape as > previously written, and a file count mismatch: > > 30-Jan 20:28 bacula-sd JobId 6152: Volume "Daily_1" previously written, > moving to end of data. > 30-Jan 20:30 bacula-sd JobId 6152: Warning: For Volume "Daily_1": > The number of files mismatch! Volume=4 Catalog=3 > Correcting Catalog Again reviewing the director reports it would seem that no data was lost. The "SD Bytes Written" and "Last Volume Bytes" values do sum up approximately, even across the ominous message: [ts@backup ~]$ grep -e "Last Volume Bytes" -e "SD Bytes Written" -e "End of medium" -e "previously written" /tmp/log-20130130 SD Bytes Written: 428,089,875 (428.0 MB) Last Volume Bytes: 796,026,470,400 (796.0 GB) SD Bytes Written: 1,214,712,798 (1.214 GB) Last Volume Bytes: 797,242,134,528 (797.2 GB) SD Bytes Written: 45,777,531 (45.77 MB) Last Volume Bytes: 797,288,002,560 (797.2 GB) SD Bytes Written: 27,729,514 (27.72 MB) Last Volume Bytes: 797,315,807,232 (797.3 GB) SD Bytes Written: 123,939,387 (123.9 MB) Last Volume Bytes: 797,439,863,808 (797.4 GB) SD Bytes Written: 1,264,330,981 (1.264 GB) Last Volume Bytes: 798,705,202,176 (798.7 GB) 30-Jan 20:18 bacula-sd JobId 6142: End of medium on Volume "Daily_2" Bytes=799,806,099,456 Blocks=12,397,787 at 30-Jan-2013 20:18. SD Bytes Written: 4,849,031,881 (4.849 GB) Last Volume Bytes: 3,754,146,816 (3.754 GB) SD Bytes Written: 1,600,551,989 (1.600 GB) Last Volume Bytes: 5,355,915,264 (5.355 GB) SD Bytes Written: 2,555,884,712 (2.555 GB) Last Volume Bytes: 7,913,751,552 (7.913 GB) SD Bytes Written: 1,440,289,909 (1.440 GB) Last Volume Bytes: 9,355,143,168 (9.355 GB) SD Bytes Written: 5,604,420,853 (5.604 GB) Last Volume Bytes: 14,963,816,448 (14.96 GB) SD Bytes Written: 4,375,024,239 (4.375 GB) Last Volume Bytes: 19,342,761,984 (19.34 GB) 30-Jan 20:28 bacula-sd JobId 6152: Volume "Daily_1" previously written, moving to end of data. SD Bytes Written: 5,464,351,240 (5.464 GB) Last Volume Bytes: 24,811,186,176 (24.81 GB) SD Bytes Written: 18,312,939,961 (18.31 GB) Last Volume Bytes: 43,137,755,136 (43.13 GB) SD Bytes Written: 9,272,525,456 (9.272 GB) Last Volume Bytes: 52,417,161,216 (52.41 GB) SD Bytes Written: 434,418,948 (434.4 MB) Last Volume Bytes: 52,851,972,096 (52.85 GB) SD Bytes Written: 1,076,781,093 (1.076 GB) Last Volume Bytes: 53,929,838,592 (53.92 GB) SD Bytes Written: 4,742,245,237 (4.742 GB) Last Volume Bytes: 58,675,663,872 (58.67 GB) [ts@backup ~]$ Still I would sleep more peacefully if there was an explanation for the unexpected "previously written" and "number of files mismatch" messages. Thanks, Tilman -- Tilman Schmidt Phoenix Software GmbH Bonn, Germany
signature.asc
Description: OpenPGP digital signature
------------------------------------------------------------------------------ Everyone hates slow websites. So do we. Make your web apps faster with AppDynamics Download AppDynamics Lite for free today: http://p.sf.net/sfu/appdyn_d2d_jan
_______________________________________________ Bacula-users mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-users
