Has anybody run into this problem? This is the first time I've seen this, and I've been running Bacula for almost a year. It looks like two jobs simultaneously wanted the same tape -- I seem to recall the need to use some sort of lock in the mtx script prior to 1.38, but I'm running 1.39.28 (linux). Is it possible that the storage daemon is allowing two threads to access the mtx-changer script at the same time? I don't understand enough about the autochanger algorithm to speculate further...
Thanks for any ideas, Ian -- First Job -- 01-Dec 02:00 sbgrid-dir: Start Backup JobId 742, Job=FS4_XRAY. 2006-12-01_02.00.01 01-Dec 01:45 xray-fd: DIR and FD clocks differ by -903 seconds, FD automatically adjusting. 01-Dec 02:41 sbgrid-sd: End of Volume "000108L2" at 288:15328 on device "LTO2A" (/dev/nst0). Write of 64512 bytes got -1. 01-Dec 02:42 sbgrid-sd: Re-read of last block succeeded. 01-Dec 02:42 sbgrid-sd: End of medium on Volume "000108L2" Bytes=280,227,677,184 Blocks=4,343,806 at 01-Dec-2006 02:42. 01-Dec 02:42 sbgrid-sd: 3307 Issuing autochanger "unload slot 37, drive 0" command. 01-Dec 02:42 sbgrid-sd: 3307 Issuing autochanger "unload slot 38, drive 1" command. 01-Dec 02:45 sbgrid-sd: 3304 Issuing autochanger "load slot 38, drive 0" command. 01-Dec 02:45 sbgrid-sd: 3305 Autochanger "load slot 38, drive 0", status is OK. 01-Dec 02:45 sbgrid-sd: 3301 Issuing autochanger "loaded? drive 0" command. 01-Dec 02:46 sbgrid-sd: 3302 Autochanger "loaded? drive 0", result is Slot 38. 01-Dec 02:46 sbgrid-sd: Volume "000109L2" previously written, moving to end of data. 01-Dec 02:47 sbgrid-sd: Ready to append to end of Volume "000109L2" at file=25. 01-Dec 02:47 sbgrid-sd: New volume "000109L2" mounted on device "LTO2A" (/dev/nst0) at 01-Dec-2006 02:47. 01-Dec 03:39 sbgrid-sd: Job write elapsed time = 01:33:58, Transfer rate = 19.86 M bytes/second 01-Dec 03:39 sbgrid-dir: Bacula 1.39.28 (12Nov06): 01-Dec-2006 03:39:33 -- Second Job -- 01-Dec 02:45 sbgrid-dir: Start Backup JobId 744, Job=WEB. 2006-12-01_02.45.00 01-Dec 02:30 web-fd: DIR and FD clocks differ by -903 seconds, FD automatically adjusting. 01-Dec 02:45 sbgrid-sd: 3301 Issuing autochanger "loaded? drive 1" command. 01-Dec 02:45 sbgrid-sd: 3302 Autochanger "loaded? drive 1", result: nothing loaded. 01-Dec 02:45 sbgrid-sd: 3304 Issuing autochanger "load slot 38, drive 1" command. 01-Dec 02:45 sbgrid-sd: WEB.2006-12-01_02.45.00 Fatal error: 3992 Bad autochanger "load slot 38, drive 1": ERR=Child exited with code 1. Results=source Element Address 4133 is Empty 01-Dec 02:30 web-fd: WEB.2006-12-01_02.45.00 Fatal error: job.c:1602 Bad response to Append Data command. Wanted 3000 OK data, got 3903 Error append data 01-Dec 02:45 sbgrid-dir: WEB.2006-12-01_02.45.00 Error: Bacula 1.39.28 (12Nov06): 01-Dec-2006 02:45:59 ------------------------------------------------------------------------- Take Surveys. Earn Cash. Influence the Future of IT Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys - and earn cash http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV _______________________________________________ Bacula-users mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-users
