I never got a reply on this, but as the disquieting "previously written" and "number of files mismatch" messages did not reoccur on the following tape change I will not pursue this further. The incorrect volume name in the "Committing spooled data" message I can live with.
HTH TS Am 01.02.2013 12:33, schrieb Tilman Schmidt: > 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_feb
_______________________________________________ Bacula-users mailing list Bacula-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/bacula-users
