Hello, In general, it is *much* better to deal with these problems (1 per bug report) in a bug report. I cannot properly track and analyse complicated bugs via email -- it just doesn't work for me. I've suggested ways to make the bugs system which is *not* broken work for you.
More notes below: On Friday 20 July 2007 19:36, Doytchin Spiridonov wrote: > Hello Kern, > > thank you for the answer. Glad to hear that this is a bug as I was > really confused with our setup when you said it could be that. We will > try the 2.1.28 and I will let you know if we find any other problems. Certain false SQL errors should be fixed in 2.1.28. > > The reason we tried the 2.1.26 is because we found several other > *important* problems with the 2.0.3. I am personally still > investigating and will let you know if I can find some details *when* > they happen as I can't reproduce definitely (once it happens then it > is OK). > > To summarize there are 3(4) other problems: > > 1. One that I submitted as a bug (not the current, the other where > there is a problem with the Volume) - I am 100% sure it is not an FS > problem, nor a hardware problem. But as this happened once I doubt we > will find what happened actually. I am still keeping this volume so if > you have any ideas for tests against it to find what is the problem it > will appreciate any info. > > 2. The others 2(3) I still didn't reported as we are still testing > are: > > a) numerous files are restored with bigger size than the original; if > we cut the file to the original number of bytes it matches the > original file; these are not log files nor they are changed between > backups; the appended data were part from another file (at least the > one case where I closely investigated the larger file, I found which > was the pther file part from which was appended, while the other file > was restored OK, strange); also the important thing is that this > happens only if we restore numerous files (full restore for example) > while if we restore the single file it is restored OK - I am pretty > sure this is also bug of Bacula (2.0.3). An example error: This problem seems to be related to the "illegal" block addresses you are seeing. It *may* be related to some 32/64 bit sign extension problem, but I have not been able to reproduce it. I am still waiting for an answer to my question about the details of the hardware you are running: manufacturer, chip set, running virtual machines, ...? > --- > 17-Jul 01:14 Storage: Forward spacing Volume "FILE0002" to file:block 0:999935901. > 17-Jul 01:14 b3: Restore_b3.d6.int.2007-07-17_01.13.42 Error: attribs.c:407 File size of restored file > /home/exclude/res_delme/b3.2/usr/src/kernels/2.6.17.11-grsec-x86-2/drivers/usb/misc/emi62_fw_m.h > not correct. Original > 795679, restored 854336. > --- > and it is clear this .h file didn't changed. I have more examples. > > b) after some time (but not large enough so any files are purged, > removed etc from the backup) on restore a lot of files are missing; > this is true for full retsore or even single restore - it just doesn't > restore the specified file - while they are in catalog, they are not > restored. For example 200K files are marked for restored, actually > 190K are retsored (and those are not hardlinks etc, just plain normal > files and directories). Example: > --- > Files Expected: 180,145 > Files Restored: 90,094 > --- > Clearly 90K files are not hardlinks or any other ignored files and > there were missing dirs like the whole /home and others. This may be the same seek problem. I have told you how to turn off disk seeking to test. > > > I was able to reproduce two times the a) and b) cases: > > 1) full-differential-incremental every day (for 3 days) after that we > tested and both problematic cases were present I don't understand the above. It is unclear. > > 2) full before midnight and differential after midnight (so all of > that in 1 hour) and both cases were present. I do not understan the above. It is unclear. > > I guess these are definitely Bacula bugs (and are really important) > but I would like to try to do more backups to see if we will face the > same problem. After that I will report both bugs. > > By the way have you heard of or faced those two bugs? If so is there > any chance they would be fixed in the latest beta? Sorry, I don't understand the English. > > c) The third minor bug is that Bacula doesn't restore (correctly) > sockets, but is trying to change permissions and so generates errors > like this: 16-Jul 09:07 b3: Restore_b3.d6.int.2007-07-16_09.05.28 > Error: attribs.c:448 Unable to set file times > /home/exclude/res_delme/var/lib/mysql.old/mysql.sock: ERR=No such file > or directory This could be a bug. I've never seen it, but I will look at the code at the indicated place. > > This is really a minor bug but would be nice to be fixed so we don't > get false error messages. > > > I will wait for your reply regarding a) and b) as we were running > backup of our servers for a month and after we discovered both > (especially b) cases we found that actually we have not walid backups > and can't restore the data... > > > > ______________________________________ > Doytchin Spiridonov, Upravitel > [EMAIL PROTECTED] > > aLink Ltd. > 57 Cherkovna str., Sofia, Bulgaria > Phone: (02) 944.11.16 > ______________________________________ > > > Friday, July 20, 2007, 6:05:45 PM: > > KS> Hello Doytchin, > > KS> On Friday 20 July 2007 13:14, Doytchin Spiridonov wrote: > >> Hello Kern, > >> > >> this is the msg that doesn't appear at the bug report system, Re bug > >> ID 0000896: > > KS> OK, this looks like a minor bug that was in 2.1.26. It *should* be fixed in > KS> the current SVN or in version 2.1.28, which I have just made and will release > KS> a bit later today. > > KS> As far as I can tell, this creates no problems in your backups, but it would > KS> be *much* preferable to be on a version where this does not happen. > > KS> In the future, if you either upload the output to the bug report or paste it > KS> directly into the Bugs Note window, it will be included with the bug report. > > KS> I would appreciate it if you would either try the current SVN or try 2.1.28 > KS> when it comes out later today, and post the results back to the bug report. > > KS> Thanks. > > KS> Regards, > > KS> Kern > > >> > >> > >> More details (1.msgs in director and 2.sd debug msgs) > >> > >> 1. The messages in the director: > >> > >> 19-Jul 17:46 Director: Start Backup JobId 1, Job=XXX > >> 19-Jul 17:46 Director: Using Volume "FILE0001" from 'Scratch' pool. > >> 19-Jul 17:46 Director: XXX Warning: Unable to update Volume record: > >> ERR=sql_update.c:382 Update failed: affected_rows=0 for UPDATE Media SET > >> > KS> VolJobs=0,VolFiles=0,VolBlocks=0,VolBytes=0,VolMounts=0,VolErrors=0,VolWrites=0,MaxVolBytes=4697620480,VolStatus='Append',Slot=0,InChanger=0,VolReadTime=0,VolWriteTime=0,VolParts=0,LabelType=0,StorageId=1,PoolId=2,VolRetention=4320000,VolUseDuration=82800,MaxVolJobs=0,MaxVolFiles=0,Enabled=1,LocationId=0,ScratchPoolId=0,RecyclePoolId=0,RecycleCount=0 > >> WHERE VolumeName='' > >> 19-Jul 17:46 Director: Using Device "FileStorage" > >> 19-Jul 17:46 b1: ClientBeforeJob: run command "YYY" > >> 19-Jul 17:46 Storage: Labeled new Volume "FILE0001" on device "FileStorage" > KS> (/home/bacula). > >> 19-Jul 17:46 Storage: Wrote label to prelabeled Volume "FILE0001" on > KS> device "FileStorage" (/home/bacula) > >> 19-Jul 17:55 Storage: Job write elapsed time = 00:08:18, Transfer rate = > KS> 2.701 M bytes/second > >> 19-Jul 17:55 b1: ClientAfterJob: run command "ZZZ" > >> 19-Jul 17:55 Director: Bacula Director 2.1.26 (12Jul07): 19-Jul-2007 > KS> 17:55:17 > >> Build OS: x86_64-redhat-linux-gnu redhat > >> JobId: 1 > >> Job: XXX > >> Backup Level: Full > >> Client: "b1" 2.1.26 (12Jul07) > KS> x86_64-redhat-linux-gnu,redhat, > >> FileSet: "GeneralSet" 2007-07-19 17:46:44 > >> Pool: "Monthly" (From Job resource) > >> Storage: "Storage" (From Job resource) > >> Scheduled time: 19-Jul-2007 17:46:40 > >> Start time: 19-Jul-2007 17:46:46 > >> End time: 19-Jul-2007 17:55:17 > >> Elapsed time: 8 mins 31 secs > >> Priority: 10 > >> FD Files Written: 129,243 > >> SD Files Written: 129,243 > >> FD Bytes Written: 1,327,770,498 (1.327 GB) > >> SD Bytes Written: 1,345,540,825 (1.345 GB) > >> Rate: 2598.4 KB/s > >> Software Compression: 58.3 % > >> VSS: no > >> Encryption: no > >> Volume name(s): FILE0001 > >> Volume Session Id: 1 > >> Volume Session Time: 1184856289 > >> Last Volume Bytes: 1,350,903,188 (1.350 GB) > >> Non-fatal FD errors: 0 > >> SD Errors: 0 > >> FD termination status: OK > >> SD termination status: OK > >> Termination: Backup OK > >> > >> 19-Jul 17:55 Director: Begin pruning Jobs. > >> 19-Jul 17:55 Director: No Jobs found to prune. > >> 19-Jul 17:55 Director: Begin pruning Files. > >> 19-Jul 17:55 Director: No Files found to prune. > >> 19-Jul 17:55 Director: End auto prune. > >> > >> > >> 2. debug messages from sd (the jobs was manually cancelled as only the > KS> beginning is important when the director's error appear): > >> > >> bacula-sd: message.c:253 Copy message resource 584878 to 595bf8 > >> Storage: jcr.c:132 read_last_jobs seek to 192 > >> Storage: jcr.c:139 Read num_items=0 > >> Storage: bpipe.c:371 Run program returning 0 > >> Storage: stored.c:478 calling init_dev /home/bacula > >> Storage: dev.c:250 init_dev: tape=0 dev_name=/home/bacula > >> Storage: stored.c:480 SD init done /home/bacula > >> Storage: mem_pool.c:377 garbage collect memory pool > >> Storage: bnet_server.c:96 Addresses host[ipv4:10.2.1.11:9103] > >> Storage: bnet.c:666 who=client host=10.2.1.11 port=36643 > >> Storage: dircmd.c:171 Conn: Hello Director Director calling > >> Storage: dircmd.c:181 Got a DIR connection > >> Storage: cram-md5.c:71 send: auth cram-md5 <[EMAIL PROTECTED]> > KS> ssl=0 > >> Storage: cram-md5.c:131 cram-get: auth cram-md5 > KS> <[EMAIL PROTECTED]> ssl=0 > >> Storage: cram-md5.c:150 sending resp to challenge: w/Rl835GbXA2e8+e2jUssD > >> Storage: dircmd.c:202 Message channel init completed. > >> Storage: dircmd.c:209 <dird: JobId=1 job=XXX job_name=Backup_b1.d6.int > KS> client_name=b1 type=66 level=70 FileSet=GeneralSet NoAttr=0 SpoolAttr=0 > KS> FileSetMD5=Zm/Nd/lpVk+ee++ddQ/H2B SpoolData=0 WritePartAfterJob=1 > KS> PreferMountedVols=1 > >> > >> Storage: dircmd.c:223 Do command: JobId= > >> Storage: job.c:86 <dird: JobId=1 job=XXX job_name=Backup_b1.d6.int > KS> client_name=b1 type=66 level=70 FileSet=GeneralSet NoAttr=0 SpoolAttr=0 > KS> FileSetMD5=Zm/Nd/lpVk+ee++ddQ/H2B SpoolData=0 WritePartAfterJob=1 > KS> PreferMountedVols=1 > >> Storage: job.c:139 >dird: 3000 OK Job SDid=1 SDtime=1184892131 > KS> Authorization=GBHB-LPFO-CMMI-FOPK-BFAD-IFEB-FLIG-KFLK > >> Storage: dircmd.c:209 <dird: use storage=Storage media_type=File > KS> pool_name=Monthly pool_type=Backup append=1 copy=0 stripe=0 > >> > >> Storage: dircmd.c:223 Do command: use storage= > >> Storage: reserve.c:588 jid=1 <dird: use storage=Storage media_type=File > KS> pool_name=Monthly pool_type=Backup append=1 copy=0 stripe=0 > >> Storage: reserve.c:617 jid=1 <dird device: use device=FileStorage > >> Storage: reserve.c:634 jid=1 Storage=Storage media_type=File pool=Monthly > KS> pool_type=Backup append=1 > >> Storage: reserve.c:636 jid=1 Device=FileStorage > >> Storage: reserve.c:717 jid=1 PrefMnt=1 exact=1 suitable=0 chgronly=0 any=0 > >> Storage: reserve.c:830 jid=1 PrefMnt=1 exact=1 suitable=0 chgronly=0 > >> Storage: reserve.c:988 jid=1 search res for FileStorage > >> Storage: reserve.c:1020 jid=1 Try match res=FileStorage > >> Storage: reserve.c:1060 jid=1 chk MediaType device=File request=File > >> Storage: reserve.c:1083 jid=1 try reserve FileStorage > >> Storage: reserve.c:1097 jid=1 have_vol=0 vol= > >> Storage: reserve.c:1256 jid=1 reserve_append device is "FileStorage" > KS> (/home/bacula) > >> Storage: reserve.c:1288 jid=1 PrefMnt=1 exact=1 suitable=1 chgronly=0 any=0 > >> Storage: reserve.c:1413 jid=1 OK Dev avail reserved "FileStorage" > KS> (/home/bacula) > >> Storage: reserve.c:1266 jid=1 Inc reserve=1 dev="FileStorage" (/home/bacula) > KS> 597c08 > >> Storage: reserve.c:1107 jid=1 Reserved=1 dev_name=FileStorage mediatype=File > KS> pool=Monthly ok=1 > >> Storage: askdir.c:256 dir_find_next_appendable_volume > >> Storage: askdir.c:271 >dird: CatReq Job=XXX FindMedia=1 pool_name=Monthly > KS> media_type=File > >> Storage: askdir.c:182 <dird 1000 OK VolName= VolJobs=0 VolFiles=0 > KS> VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 > KS> MaxVolBytes=4697620480 VolCapacityBytes=0 VolStatus=Append Slot=0 > KS> MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 > KS> EndBlock=0 VolParts=0 LabelType=0 MediaId=20 > >> > >> Storage: askdir.c:204 do_reqest_vol_info return true slot=0 Volume= > >> Storage: reserve.c:406 jid=1 find_vol= found=0 > >> Storage: reserve.c:534 jid=1 Vol= not in use. > >> Storage: reserve.c:313 jid=1 reserve_volume > >> Storage: reserve.c:238 jid=1 new Vol= at 59a898 dev="FileStorage" > KS> (/home/bacula) > >> Storage: reserve.c:181 jid=1 List from end new volume: at 59a898 on > KS> device "FileStorage" (/home/bacula) > >> Storage: reserve.c:1112 jid=1 looking for Volume= > >> Storage: reserve.c:1150 jid=1 >dird changer: 3000 OK use device > KS> device=FileStorage > >> Storage: reserve.c:1031 jid=1 Device FileStorage reserved=1 for append. > >> Storage: reserve.c:961 jid=1 available device found=FileStorage > >> Storage: dircmd.c:209 <dird: run > >> Storage: dircmd.c:223 Do command: run > >> Storage: job.c:154 Run_cmd: run > >> Storage: job.c:173 XXX waiting 1800 sec for FD to contact SD > >> Storage: bnet.c:666 who=client host=10.2.1.11 port=36643 > >> Storage: dircmd.c:171 Conn: Hello Start Job XXX > >> Storage: dircmd.c:173 Got a FD connection > >> Storage: job.c:215 Found Job XXX > >> Storage: cram-md5.c:71 send: auth cram-md5 <[EMAIL PROTECTED]> > KS> ssl=0 > >> Storage: cram-md5.c:131 cram-get: auth cram-md5 <[EMAIL PROTECTED]> > KS> ssl=0 > >> Storage: cram-md5.c:150 sending resp to challenge: 4G92X5/9z+4Y14/bmE+XLD > >> Storage: job.c:232 OK Authentication Job XXX > >> Storage: job.c:191 Running job XXX > >> Storage: fd_cmds.c:122 Start run Job=XXX > >> Storage: fd_cmds.c:160 <filed: append open session > >> Storage: fd_cmds.c:228 Append open session: append open session > >> Storage: fd_cmds.c:238 >filed: 3000 OK open ticket = 1 > >> Storage: fd_cmds.c:160 <filed: append data 1 > >> Storage: fd_cmds.c:190 Append data: append data 1 > >> Storage: fd_cmds.c:192 <bfiled: append data 1 > >> Storage: append.c:73 Start append data. res=1 > >> Storage: lock.c:237 set blocked=BST_DOING_ACQUIRE from lock.c:142 > >> Storage: acquire.c:320 acquire_append device is disk > >> Storage: acquire.c:409 Not in append mode, try mount. > >> Storage: acquire.c:415 Do mount_next_write_vol > >> Storage: mount.c:74 Enter mount_next_volume(release=0) dev="FileStorage" > KS> (/home/bacula) > >> Storage: mount.c:84 mount_next_vol retry=0 > >> Storage: mount.c:110 Before dir_find_next_appendable_volume. > >> Storage: askdir.c:256 dir_find_next_appendable_volume > >> Storage: askdir.c:271 >dird: CatReq Job=XXX FindMedia=1 pool_name=Monthly > KS> media_type=File > >> Storage: askdir.c:182 <dird 1000 OK VolName=FILE0001 VolJobs=0 VolFiles=0 > KS> VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 > KS> MaxVolBytes=4697620480 VolCapacityBytes=0 VolStatus=Append Slot=0 > KS> MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 > KS> EndBlock=0 VolParts=0 LabelType=0 MediaId=1 > >> > >> Storage: askdir.c:204 do_reqest_vol_info return true slot=0 Volume=FILE0001 > >> Storage: reserve.c:406 jid=1 find_vol=FILE0001 found=0 > >> Storage: reserve.c:181 jid=1 List from find_volume: at 59a898 on > KS> device "FileStorage" (/home/bacula) > >> Storage: reserve.c:534 jid=1 Vol=FILE0001 not in use. > >> Storage: reserve.c:313 jid=1 reserve_volume FILE0001 > >> Storage: reserve.c:181 jid=1 List from begin reserve_volume: at 59a898 on > KS> device "FileStorage" (/home/bacula) > >> Storage: reserve.c:335 jid=1 reserve_vol free vol= at 59a898 > >> Storage: reserve.c:181 jid=1 List from reserve_vol free: at 59a898 on > KS> device "FileStorage" (/home/bacula) > >> Storage: reserve.c:238 jid=1 new Vol=FILE0001 at 59a898 dev="FileStorage" > KS> (/home/bacula) > >> Storage: reserve.c:181 jid=1 List from end new volume: FILE0001 at 59a898 on > KS> device "FileStorage" (/home/bacula) > >> Storage: mount.c:122 After find_next_append. Vol=FILE0001 Slot=0 Parts=0 > >> Storage: autochanger.c:121 Device "FileStorage" (/home/bacula) is not an > KS> autochanger > >> Storage: mount.c:142 autoload_dev returns 0 > >> Storage: mount.c:155 (2)Ask=0 > >> Storage: mount.c:158 Ask=0 autochanger=0 > >> Storage: mount.c:168 want vol=FILE0001 > >> Storage: dev.c:292 open dev: type=1 dev_name="FileStorage" (/home/bacula) > KS> vol=FILE0001 mode=OPEN_READ_WRITE > >> Storage: dev.c:302 call open_file_device mode=OPEN_READ_WRITE > >> Storage: dev.c:1932 Enter mount > >> Storage: dev.c:474 open disk: mode=OPEN_READ_WRITE > KS> open(/home/bacula/FILE0001, 0x2, 0640) > >> Storage: dev.c:481 open failed: dev.c:480 Could not > KS> open: /home/bacula/FILE0001, ERR=No such file or directory > >> Storage: dev.c:489 open dev: disk fd=-1 opened, part=0/0, part_size=0 > >> Storage: dev.c:306 preserve=0x0 fd=-1 > >> Storage: mount.c:507 Create volume label > >> Storage: label.c:316 write_volume_label() > >> Storage: label.c:331 New VolName=FILE0001 > >> Storage: dev.c:292 open dev: type=1 dev_name="FileStorage" (/home/bacula) > KS> vol=FILE0001 mode=OPEN_READ_WRITE > >> Storage: dev.c:302 call open_file_device mode=OPEN_READ_WRITE > >> Storage: dev.c:1932 Enter mount > >> Storage: dev.c:474 open disk: mode=OPEN_READ_WRITE > KS> open(/home/bacula/FILE0001, 0x2, 0640) > >> Storage: dev.c:481 open failed: dev.c:480 Could not > KS> open: /home/bacula/FILE0001, ERR=No such file or directory > >> Storage: dev.c:489 open dev: disk fd=-1 opened, part=0/0, part_size=0 > >> Storage: dev.c:306 preserve=0x0 fd=-1 > >> Storage: dev.c:292 open dev: type=1 dev_name="FileStorage" (/home/bacula) > KS> vol=FILE0001 mode=CREATE_READ_WRITE > >> Storage: dev.c:302 call open_file_device mode=CREATE_READ_WRITE > >> Storage: dev.c:1932 Enter mount > >> Storage: dev.c:474 open disk: mode=CREATE_READ_WRITE > KS> open(/home/bacula/FILE0001, 0x42, 0640) > >> Storage: dev.c:489 open dev: disk fd=7 opened, part=0/0, part_size=0 > >> Storage: dev.c:306 preserve=0x0 fd=7 > >> Storage: label.c:338 Label type=0 > >> Storage: label.c:596 Start create_volume_label() > >> Storage: dev.c:1815 Clear volhdr vol= > >> > >> Volume Label: > >> Id : Bacula 1.0 immortal > >> VerNo : 11 > >> VolName : FILE0001 > >> PrevVolName : > >> VolFile : 0 > >> LabelType : PRE_LABEL > >> LabelSize : 0 > >> PoolName : Monthly > >> MediaType : File > >> PoolType : Backup > >> HostName : b1.d6.net > >> Date label written: 20-Jul-2007 03:42 > >> Storage: label.c:584 Created Vol label rec: FI=PRE_LABEL len=157 > >> Storage: label.c:373 Wrote label of 157 bytes to "FileStorage" > KS> (/home/bacula) > >> Storage: label.c:376 Call write_block_to_dev() > >> Storage: block.c:445 binbuf=193 buf_len=64512 > >> Storage: label.c:391 Wrote block to device > >> Storage: dev.c:1625 weof_dev > >> > >> Volume Label: > >> Id : Bacula 1.0 immortal > >> VerNo : 11 > >> VolName : FILE0001 > >> PrevVolName : > >> VolFile : 0 > >> LabelType : PRE_LABEL > >> LabelSize : 0 > >> PoolName : Monthly > >> MediaType : File > >> PoolType : Backup > >> HostName : b1.d6.net > >> Date label written: 20-Jul-2007 03:42 > >> Storage: reserve.c:313 jid=1 reserve_volume FILE0001 > >> Storage: reserve.c:181 jid=1 List from begin reserve_volume: FILE0001 at > KS> 59a898 on device "FileStorage" (/home/bacula) > >> Storage: reserve.c:181 jid=1 List from end new volume: FILE0001 at 59a898 on > KS> device "FileStorage" (/home/bacula) > >> Storage: mount.c:517 dir_update_vol_info. Set Append > >> Storage: askdir.c:339 Update cat VolFiles=0 > >> Storage: askdir.c:358 >dird: CatReq Job=XXX UpdateMedia VolName=FILE0001 > KS> VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 > KS> VolWrites=0 MaxVolBytes=4697620480 EndTime=1184892168 VolStatus=Append Slot=0 > KS> relabel=1 InChanger=0 VolReadTime=0 VolWriteTime=0 VolFirstWritten=0 > KS> VolParts=0 > >> Storage: askdir.c:182 <dird 1000 OK VolName=FILE0001 VolJobs=0 VolFiles=0 > KS> VolBlocks=0 VolBytes=0 VolMounts=0 VolErrors=0 VolWrites=0 > KS> MaxVolBytes=4697620480 VolCapacityBytes=0 VolStatus=Append Slot=0 > KS> MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=0 EndFile=0 > KS> EndBlock=0 VolParts=0 LabelType=0 MediaId=1 > >> > >> Storage: askdir.c:204 do_reqest_vol_info return true slot=0 Volume=FILE0001 > >> Storage: dev.c:283 Close fd for mode change. > >> Storage: dev.c:292 open dev: type=1 dev_name="FileStorage" (/home/bacula) > KS> vol=FILE0001 mode=OPEN_READ_WRITE > >> Storage: dev.c:302 call open_file_device mode=OPEN_READ_WRITE > >> Storage: dev.c:1932 Enter mount > >> Storage: dev.c:474 open disk: mode=OPEN_READ_WRITE > KS> open(/home/bacula/FILE0001, 0x2, 0640) > >> Storage: dev.c:489 open dev: disk fd=7 opened, part=0/0, part_size=193 > >> Storage: dev.c:306 preserve=0x40 fd=7 > >> Storage: label.c:81 Enter read_volume_label res=1 device="FileStorage" > KS> (/home/bacula) vol=FILE0001 dev_Vol=FILE0001 > >> Storage: label.c:104 Leave read_volume_label() VOL_OK > >> Storage: mount.c:237 Want dirVol=FILE0001 dirStat=Append > >> Storage: mount.c:244 Vol OK name=FILE0001 > >> Storage: label.c:430 set append found freshly labeled volume. fd=7 > KS> dev=597c08 > >> Storage: label.c:280 write Label in write_volume_label_to_block() > >> Storage: label.c:584 Created Vol label rec: FI=VOL_LABEL len=157 > >> Storage: label.c:294 Wrote label of 157 bytes to block > >> Storage: label.c:482 Attempt to write to device fd=7. > >> Storage: block.c:445 binbuf=193 buf_len=64512 > >> Storage: label.c:506 dir_update_vol_info. Set Append > >> Storage: askdir.c:339 Update cat VolFiles=0 > >> Storage: askdir.c:358 >dird: CatReq Job=XXX UpdateMedia VolName=FILE0001 > KS> VolJobs=0 VolFiles=0 VolBlocks=0 VolBytes=193 VolMounts=1 VolErrors=0 > KS> VolWrites=1 MaxVolBytes=4697620480 EndTime=1184892168 VolStatus=Append Slot=0 > KS> relabel=1 InChanger=0 VolReadTime=0 VolWriteTime=4 VolFirstWritten=0 > KS> VolParts=0 > >> Storage: askdir.c:182 <dird 1000 OK VolName=FILE0001 VolJobs=0 VolFiles=0 > KS> VolBlocks=0 VolBytes=193 VolMounts=1 VolErrors=0 VolWrites=1 > KS> MaxVolBytes=4697620480 VolCapacityBytes=0 VolStatus=Append Slot=0 > KS> MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=4 EndFile=0 > KS> EndBlock=0 VolParts=0 LabelType=0 MediaId=1 > >> > >> Storage: askdir.c:204 do_reqest_vol_info return true slot=0 Volume=FILE0001 > >> Storage: label.c:522 OK from rewrite vol label. > >> Storage: mount.c:471 set APPEND, normal return from mount_next_write_volume. > KS> dev="FileStorage" (/home/bacula) > >> Storage: acquire.c:427 Output pos=0:192 > >> Storage: askdir.c:339 Update cat VolFiles=0 > >> Storage: askdir.c:358 >dird: CatReq Job=XXX UpdateMedia VolName=FILE0001 > KS> VolJobs=1 VolFiles=0 VolBlocks=0 VolBytes=193 VolMounts=1 VolErrors=0 > KS> VolWrites=1 MaxVolBytes=4697620480 EndTime=1184892168 VolStatus=Append Slot=0 > KS> relabel=0 InChanger=0 VolReadTime=0 VolWriteTime=4 VolFirstWritten=0 > KS> VolParts=0 > >> Storage: askdir.c:182 <dird 1000 OK VolName=FILE0001 VolJobs=1 VolFiles=0 > KS> VolBlocks=0 VolBytes=193 VolMounts=1 VolErrors=0 VolWrites=1 > KS> MaxVolBytes=4697620480 VolCapacityBytes=0 VolStatus=Append Slot=0 > KS> MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=4 EndFile=0 > KS> EndBlock=0 VolParts=0 LabelType=0 MediaId=1 > >> > >> Storage: askdir.c:204 do_reqest_vol_info return true slot=0 Volume=FILE0001 > >> Storage: acquire.c:439 Dec reserve=0 dev="FileStorage" (/home/bacula) > >> Storage: lock.c:247 unblock BST_DOING_ACQUIRE from lock.c:151 > >> Storage: append.c:96 Begin append device="FileStorage" (/home/bacula) > >> Storage: append.c:101 Just after acquire_device_for_append > >> Storage: label.c:698 session_label record=59b4f0 > >> Storage: label.c:754 Write sesson_label record JobId=1 FI=SOS_LABEL SessId=1 > KS> Strm=1 len=159 remainder=0 > >> Storage: label.c:758 Leave write_session_label Block=192d File=0d > >> Storage: block.c:445 binbuf=64501 buf_len=64512 > >> Storage: block.c:445 binbuf=64511 buf_len=64512 > >> Storage: block.c:445 binbuf=64504 buf_len=64512 > >> Storage: block.c:445 binbuf=64509 buf_len=64512 > >> Storage: block.c:445 binbuf=64507 buf_len=64512 > >> Storage: block.c:445 binbuf=64506 buf_len=64512 > >> Storage: block.c:445 binbuf=64510 buf_len=64512 > >> Storage: block.c:445 binbuf=64504 buf_len=64512 > >> Storage: block.c:445 binbuf=64505 buf_len=64512 > >> Storage: block.c:445 binbuf=64501 buf_len=64512 > >> Storage: block.c:445 binbuf=64509 buf_len=64512 > >> Storage: block.c:445 binbuf=64501 buf_len=64512 > >> Storage: block.c:445 binbuf=64509 buf_len=64512 > >> Storage: block.c:445 binbuf=64502 buf_len=64512 > >> Storage: block.c:445 binbuf=64502 buf_len=64512 > >> Storage: block.c:445 binbuf=64504 buf_len=64512 > >> Storage: block.c:445 binbuf=64501 buf_len=64512 > >> Storage: block.c:445 binbuf=64502 buf_len=64512 > >> Storage: block.c:445 binbuf=64509 buf_len=64512 > >> Storage: block.c:445 binbuf=64502 buf_len=64512 > >> Storage: block.c:445 binbuf=64503 buf_len=64512 > >> Storage: block.c:445 binbuf=64507 buf_len=64512 > >> Storage: block.c:445 binbuf=64504 buf_len=64512 > >> Storage: bnet.c:666 who=client host=10.2.1.11 port=36643 > >> Storage: dircmd.c:171 Conn: Hello Director Director calling > >> Storage: dircmd.c:181 Got a DIR connection > >> Storage: cram-md5.c:71 send: auth cram-md5 <[EMAIL PROTECTED]> > KS> ssl=0 > >> Storage: cram-md5.c:131 cram-get: auth cram-md5 > KS> <[EMAIL PROTECTED]> ssl=0 > >> Storage: cram-md5.c:150 sending resp to challenge: BR+6o/0wU5YmPi/Ew7oDSD > >> Storage: append.c:284 Write EOS label JobStatus=f > >> Storage: label.c:698 session_label record=59ccf0 > >> Storage: label.c:754 Write sesson_label record JobId=1 FI=EOS_LABEL SessId=1 > KS> Strm=1 len=195 remainder=0 > >> Storage: label.c:758 Leave write_session_label Block=216566813d File=0d > >> Storage: append.c:300 back from write_end_session_label() > >> Storage: block.c:445 binbuf=51508 buf_len=64512 > >> Storage: acquire.c:478 release_device device "FileStorage" (/home/bacula) is > KS> disk > >> Storage: acquire.c:500 There are 0 writers in release_device > >> Storage: acquire.c:502 dir_create_jobmedia_record. Release > >> Storage: askdir.c:402 >dird: CatReq Job=XXX CreateJobMedia FirstIndex=1 > KS> LastIndex=36181 StartFile=0 EndFile=0 StartBlock=193 EndBlock=216618321 > KS> Copy=0 Strip=0 MediaId=1 > >> Storage: askdir.c:409 <dir: 1000 OK CreateJobMedia > >> Storage: dev.c:1625 weof_dev > >> Storage: acquire.c:515 dir_update_vol_info. Release0 > >> Storage: askdir.c:339 Update cat VolFiles=0 > >> Storage: askdir.c:358 >dird: CatReq Job=XXX UpdateMedia VolName=FILE0001 > KS> VolJobs=1 VolFiles=0 VolBlocks=3358 VolBytes=216618322 VolMounts=1 > KS> VolErrors=0 VolWrites=3359 MaxVolBytes=4697620480 EndTime=1184892229 > KS> VolStatus=Append Slot=0 relabel=0 InChanger=0 VolReadTime=0 > KS> VolWriteTime=812902 VolFirstWritten=0 VolParts=0 > >> Storage: askdir.c:182 <dird 1000 OK VolName=FILE0001 VolJobs=1 VolFiles=0 > KS> VolBlocks=3358 VolBytes=216618322 VolMounts=1 VolErrors=0 VolWrites=3359 > KS> MaxVolBytes=4697620480 VolCapacityBytes=0 VolStatus=Append Slot=0 > KS> MaxVolJobs=0 MaxVolFiles=0 InChanger=0 VolReadTime=0 VolWriteTime=812902 > KS> EndFile=0 EndBlock=216618321 VolParts=0 LabelType=0 MediaId=1 > >> > >> Storage: askdir.c:204 do_reqest_vol_info return true slot=0 Volume=FILE0001 > >> Storage: dev.c:1825 close_dev "FileStorage" (/home/bacula) > >> Storage: dev.c:1815 Clear volhdr vol=FILE0001 > >> Storage: acquire.c:561 JobId=1 broadcast wait_device_release > >> Storage: reserve.c:489 jid=1 free_volume FILE0001 dev="FileStorage" > KS> (/home/bacula) > >> Storage: acquire.c:572 ===== Device "FileStorage" (/home/bacula) released by > KS> JobId=1 > >> Storage: append.c:339 return from do_append_data() ok=0 > >> Storage: dircmd.c:226 Command run reqeusts quit > >> Storage: mem_pool.c:377 garbage collect memory pool > >> Storage: dircmd.c:202 Message channel init completed. > >> Storage: dircmd.c:209 <dird: cancel Job=XXX > >> > >> Storage: dircmd.c:223 Do command: cancel > >> Storage: mem_pool.c:377 garbage collect memory pool > >> > ------------------------------------------------------------------------- This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2005. http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ _______________________________________________ Bacula-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-devel
