Hi,

I've just experienced something similar, and, because I use version 1.37.38 I copy the devel list.

The error:
"Number of files mismatch!"

In this case, the catalog has 2, the volme 2 files.

Interestingly, this tape from a pool where this morning a job from one client should go, but the job had an error:

14-Sep 09:42 goblin-sd: BeowulfStd.2005-09-14_08.20.01 Fatal error: acquire.c:359 Wanted Volume "DAT-120-0043", but device "HP DAT 0" (/dev/nst1) is busy writing on "DAT-120-0022" . 14-Sep 09:42 beowulf-fd: BeowulfStd.2005-09-14_08.20.01 Fatal error: c:\cygwin\home\kern\bacula\k\src\win32\filed\../../filed/job.c:1597 Bad response to Append Data command. Wanted 3000 OK data
, got 3903 Error append data

The tape in question is:
Choose a query (1-19): Unexpected question has been received.
15
Enter Volume name: Unexpected question has been received.
DAT-120-0042
+-------+------------+---------------------+------+-------+-------+---------------+--------+
| JobId | Name       | StartTime           | Type | Level | Files | Bytes       
  | Status |
+-------+------------+---------------------+------+-------+-------+---------------+--------+
| 3,057 | DracheStd  | 2005-08-31 08:20:01 | B    | D     | 2,525 |   
986,900,617 | T      |
| 3,058 | BeowulfStd | 2005-08-31 08:20:05 | B    | D     | 1,685 |   
930,059,897 | T      |
| 3,227 | BeowulfStd | 2005-09-14 09:48:21 | B    | D     | 3,394 | 
1,929,569,994 | T      |
+-------+------------+---------------------+------+-------+-------+---------------+--------+


The job report for the manually started job from Beowulf looks like this:

14-Sep 09:48 goblin-dir: Prior failed job found. Upgrading to Differential.
14-Sep 09:48 goblin-dir: RunBefore: Host beowulf is up.
14-Sep 09:48 goblin-dir: Start Backup JobId 3227, 
Job=BeowulfStd.2005-09-14_09.48.21
14-Sep 09:48 goblin-sd: Job BeowulfStd.2005-09-14_09.48.21 waiting to reserve a 
device.
14-Sep 10:01 beowulf-fd: DIR and FD clocks differ by 1 seconds, FD 
automatically adjusting.
14-Sep 10:01 beowulf-fd: ClientRunBeforeJob: Saving registry...
14-Sep 10:02 beowulf-fd: ClientRunBeforeJob: Registry done. Now saving 
systemstate according to ntbackup
14-Sep 10:06 beowulf-fd: ClientRunBeforeJob: Pre-Backup work done.
14-Sep 10:07 goblin-sd: Please mount Volume "DAT-120-0043" on Storage Device "HP DAT 
0" (/dev/nst1) for Job BeowulfStd.2005-09-14_09.48.21
14-Sep 10:53 goblin-sd: BeowulfStd.2005-09-14_09.48.21 Warning: Director wanted Volume 
"DAT-120-0043".
    Current Volume "DAT-120-0041" not acceptable because:
    1998 Volume "DAT-120-0041" status is Full, but should be Append, Purged or 
Recycle.
14-Sep 10:53 goblin-sd: 3301 Issuing autochanger "loaded drive 0" command.
14-Sep 10:53 goblin-sd: 3302 Autochanger "loaded drive 0", result is Slot 5.
14-Sep 10:53 goblin-sd: 3307 Issuing autochanger "unload slot 5, drive 0" 
command.
14-Sep 10:53 goblin-sd: 3304 Issuing autochanger "load slot 4, drive 0" command.
14-Sep 10:54 goblin-sd: 3305 Autochanger "load slot 4, drive 0", status is OK.
14-Sep 10:54 goblin-sd: 3301 Issuing autochanger "loaded drive 0" command.
14-Sep 10:54 goblin-sd: 3302 Autochanger "loaded drive 0", result is Slot 4.
14-Sep 10:54 goblin-sd: Volume "DAT-120-0043" previously written, moving to end 
of data.
14-Sep 10:55 goblin-sd: Ready to append to end of Volume "DAT-120-0043" at 
file=7.
14-Sep 10:55 goblin-sd: Spooling data ...
14-Sep 10:55 beowulf-fd: Generate VSS snapshots. Driver="VSS WinXP", 
Drive(s)="C"
14-Sep 10:55 beowulf-fd: VSS Writer: "MSDEWriter", State: 1 (VSS_WS_STABLE)
14-Sep 10:55 beowulf-fd: VSS Writer: "WMI Writer", State: 5 
(VSS_WS_WAITING_FOR_BACKUP_COMPLETE)
14-Sep 10:55 beowulf-fd: VSS Writer: "Microsoft Writer (Service State)", State: 
1 (VSS_WS_STABLE)
14-Sep 10:55 beowulf-fd: VSS Writer: "Microsoft Writer (Bootable State)", 
State: 1 (VSS_WS_STABLE)
14-Sep 11:08 goblin-sd: Committing spooled data to Volume. Despooling 
1,932,554,590 bytes ...
14-Sep 11:44 goblin-sd: End of Volume "DAT-120-0043" at 8:14178 on device "HP DAT 
0" (/dev/nst1). Write of 64512 bytes got -1.
14-Sep 11:44 goblin-sd: Re-read of last block succeeded.
14-Sep 11:44 goblin-sd: End of medium on Volume "DAT-120-0043" 
Bytes=7,584,615,071 Blocks=117,572 at 14-Sep-2005 11:44.
14-Sep 11:46 goblin-sd: 3301 Issuing autochanger "loaded drive 0" command.
14-Sep 11:46 goblin-sd: 3302 Autochanger "loaded drive 0", result is Slot 4.
14-Sep 11:46 goblin-sd: 3307 Issuing autochanger "unload slot 4, drive 0" 
command.
14-Sep 11:46 goblin-sd: 3304 Issuing autochanger "load slot 3, drive 0" command.
14-Sep 11:47 goblin-sd: 3305 Autochanger "load slot 3, drive 0", status is OK.
14-Sep 11:47 goblin-sd: 3301 Issuing autochanger "loaded drive 0" command.
14-Sep 11:47 goblin-sd: 3302 Autochanger "loaded drive 0", result is Slot 3.
14-Sep 11:47 goblin-sd: Volume "DAT-120-0042" previously written, moving to end 
of data.
14-Sep 11:47 goblin-sd: Ready to append to end of Volume "DAT-120-0042" at 
file=2.
14-Sep 11:47 goblin-sd: New volume "DAT-120-0042" mounted on device "HP DAT 0" 
(/dev/nst1) at 14-Sep-2005 11:47.
14-Sep 11:48 goblin-sd: Sending spooled attrs to the Director. Despooling 
1,278,547 bytes ...
14-Sep 11:49 beowulf-fd: ClientRunAfterJob: Deleting temporary files
14-Sep 11:49 goblin-dir: Bacula 1.37.38 (04Sep05): 14-Sep-2005 11:49:11
  JobId:                  3227
  Job:                    BeowulfStd.2005-09-14_09.48.21
  Backup Level:           Differential (upgraded from Differential)
  Client:                 "beowulf-fd" Windows XP,MVS,NT 5.1.2600
  FileSet:                "WindowsXP-C" 2005-01-12 10:49:17
  Pool:                   "Diff"
  Storage:                "HPDAT"
  Scheduled time:         14-Sep-2005 09:48:18
  Start time:             14-Sep-2005 09:48:21
  End time:               14-Sep-2005 11:49:11
  Priority:               10
  FD Files Written:       3,394
  SD Files Written:       3,394
  FD Bytes Written:       1,929,569,994
  SD Bytes Written:       1,930,300,576
  Rate:                   266.1 KB/s
  Software Compression:   None
  Volume name(s):         DAT-120-0043|DAT-120-0042
  Volume Session Id:      8
  Volume Session Time:    1126675939
  Last Volume Bytes:      1,926,310,601
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

So, bacula knows that this job went to this volume but didn't correctly update it's catalog!?

My problem troubleshooting all this is that I only see these problems when running multiple jobs in parallel, and using different pools where jobs have to wait for one another... the resulting debug output and console log is accordingly a little long :-)

Arno

On 14.09.2005 15:13, Alan Brown wrote:
On Tue, 13 Sep 2005, Arunav Mandal wrote:

I understand this is a known bug, fixed in CVS.


What happens when I change the error to Append manually will the tape be used again?


I've tried this, it errors again. Switch the tape to used and let it expire, or purge it if the incomplete backup is the only thing on the tape.




-------------------------------------------------------
SF.Net email is sponsored by:
Tame your development challenges with Apache's Geronimo App Server. Download it for free - -and be entered to win a 42" plasma tv or your very
own Sony(tm)PSP.  Click here to play: http://sourceforge.net/geronimo.php
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users


--
IT-Service Lehmann                    [EMAIL PROTECTED]
Arno Lehmann                  http://www.its-lehmann.de


-------------------------------------------------------
SF.Net email is sponsored by:
Tame your development challenges with Apache's Geronimo App Server. Download it for free - -and be entered to win a 42" plasma tv or your very
own Sony(tm)PSP.  Click here to play: http://sourceforge.net/geronimo.php
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Reply via email to