]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
More DCR implementation + debug code for zeroed block headers
[bacula/bacula] / bacula / src / stored / block.c
1 /*
2  *
3  *   block.c -- tape block handling functions
4  *
5  *              Kern Sibbald, March MMI
6  *                 added BB02 format October MMII
7  *
8  *   Version $Id$
9  *
10  */
11 /*
12    Copyright (C) 2000-2004 Kern Sibbald and John Walker
13
14    This program is free software; you can redistribute it and/or
15    modify it under the terms of the GNU General Public License as
16    published by the Free Software Foundation; either version 2 of
17    the License, or (at your option) any later version.
18
19    This program is distributed in the hope that it will be useful,
20    but WITHOUT ANY WARRANTY; without even the implied warranty of
21    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
22    General Public License for more details.
23
24    You should have received a copy of the GNU General Public
25    License along with this program; if not, write to the Free
26    Software Foundation, Inc., 59 Temple Place - Suite 330, Boston,
27    MA 02111-1307, USA.
28
29  */
30
31
32 #include "bacula.h"
33 #include "stored.h"
34
35 extern int debug_level;
36
37 /*
38  * Dump the block header, then walk through
39  * the block printing out the record headers.
40  */
41 void dump_block(DEV_BLOCK *b, const char *msg)
42 {
43    ser_declare;
44    char *p;
45    char Id[BLKHDR_ID_LENGTH+1];
46    uint32_t CheckSum, BlockCheckSum;
47    uint32_t block_len;
48    uint32_t BlockNumber;
49    uint32_t VolSessionId, VolSessionTime, data_len;
50    int32_t  FileIndex;
51    int32_t  Stream;
52    int bhl, rhl;
53
54    unser_begin(b->buf, BLKHDR1_LENGTH);
55    unser_uint32(CheckSum);
56    unser_uint32(block_len);
57    unser_uint32(BlockNumber);
58    unser_bytes(Id, BLKHDR_ID_LENGTH);
59    ASSERT(unser_length(b->buf) == BLKHDR1_LENGTH);
60    Id[BLKHDR_ID_LENGTH] = 0;
61    if (Id[3] == '2') {
62       unser_uint32(VolSessionId);
63       unser_uint32(VolSessionTime);
64       bhl = BLKHDR2_LENGTH;
65       rhl = RECHDR2_LENGTH;
66    } else {
67       VolSessionId = VolSessionTime = 0;
68       bhl = BLKHDR1_LENGTH;
69       rhl = RECHDR1_LENGTH;
70    }
71
72    if (block_len > 100000) {
73       Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len);
74       return;
75    }
76
77    BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
78                          block_len-BLKHDR_CS_LENGTH);
79    Pmsg6(000, "Dump block %s %x: size=%d BlkNum=%d\n\
80                Hdrcksum=%x cksum=%x\n",
81       msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
82    p = b->buf + bhl;
83    while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) { 
84       unser_begin(p, WRITE_RECHDR_LENGTH);
85       if (rhl == RECHDR1_LENGTH) {
86          unser_uint32(VolSessionId);
87          unser_uint32(VolSessionTime);
88       }
89       unser_int32(FileIndex);
90       unser_int32(Stream);
91       unser_uint32(data_len);
92       Pmsg6(000, "   Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n",
93            VolSessionId, VolSessionTime, FI_to_ascii(FileIndex), 
94            stream_to_ascii(Stream, FileIndex), data_len, p);
95       p += data_len + rhl;
96   }
97 }
98     
99 /*
100  * Create a new block structure.                           
101  * We pass device so that the block can inherit the
102  * min and max block sizes.
103  */
104 DEV_BLOCK *new_block(DEVICE *dev)
105 {
106    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
107
108    memset(block, 0, sizeof(DEV_BLOCK));
109
110    /* If the user has specified a max_block_size, use it as the default */
111    if (dev->max_block_size == 0) {
112       block->buf_len = DEFAULT_BLOCK_SIZE;
113    } else {
114       block->buf_len = dev->max_block_size;
115    }
116    block->dev = dev;
117    block->block_len = block->buf_len;  /* default block size */
118    block->buf = get_memory(block->buf_len); 
119    empty_block(block);
120    block->BlockVer = BLOCK_VER;       /* default write version */
121    Dmsg1(90, "Returning new block=%x\n", block);
122    return block;
123 }
124
125
126 /*
127  * Duplicate an existing block (eblock)
128  */
129 DEV_BLOCK *dup_block(DEV_BLOCK *eblock)
130 {
131    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
132    int buf_len = sizeof_pool_memory(eblock->buf);
133
134    memcpy(block, eblock, sizeof(DEV_BLOCK));
135    block->buf = get_memory(buf_len);
136    memcpy(block->buf, eblock->buf, buf_len);
137    return block;
138 }
139
140
141 /* 
142  * Only the first block checksum error was reported.
143  *   If there are more, report it now.
144  */
145 void print_block_read_errors(JCR *jcr, DEV_BLOCK *block)
146 {
147    if (block->read_errors > 1) {
148       Jmsg(jcr, M_ERROR, 0, _("%d block read errors not printed.\n"),
149          block->read_errors);
150    }
151 }
152
153 /*
154  * Free block 
155  */
156 void free_block(DEV_BLOCK *block)
157 {
158    Dmsg1(199, "free_block buffer %x\n", block->buf);
159    free_memory(block->buf);
160    Dmsg1(199, "free_block block %x\n", block);
161    free_memory((POOLMEM *)block);
162 }
163
164 /* Empty the block -- for writing */
165 void empty_block(DEV_BLOCK *block)
166 {
167    block->binbuf = WRITE_BLKHDR_LENGTH;
168    block->bufp = block->buf + block->binbuf;
169    block->read_len = 0;
170    block->write_failed = false;
171    block->block_read = false;
172    block->FirstIndex = block->LastIndex = 0;
173 }
174
175 /*
176  * Create block header just before write. The space
177  * in the buffer should have already been reserved by
178  * init_block.
179  */
180 void ser_block_header(DEV_BLOCK *block)
181 {
182    ser_declare;
183    uint32_t CheckSum = 0;
184    uint32_t block_len = block->binbuf;
185    
186    Dmsg1(190, "ser_block_header: block_len=%d\n", block_len);
187    ser_begin(block->buf, BLKHDR2_LENGTH);
188    ser_uint32(CheckSum);
189    ser_uint32(block_len);
190    ser_uint32(block->BlockNumber);
191    ser_bytes(WRITE_BLKHDR_ID, BLKHDR_ID_LENGTH);
192    if (BLOCK_VER >= 2) {
193       ser_uint32(block->VolSessionId);
194       ser_uint32(block->VolSessionTime);
195    }
196
197    /* Checksum whole block except for the checksum */
198    CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH, 
199                  block_len-BLKHDR_CS_LENGTH);
200    Dmsg1(190, "ser_bloc_header: checksum=%x\n", CheckSum);
201    ser_begin(block->buf, BLKHDR2_LENGTH);
202    ser_uint32(CheckSum);              /* now add checksum to block header */
203 }
204
205 /*
206  * Unserialize the block header for reading block.
207  *  This includes setting all the buffer pointers correctly.
208  *
209  *  Returns: false on failure (not a block)
210  *           true  on success
211  */
212 static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
213 {
214    ser_declare;
215    char Id[BLKHDR_ID_LENGTH+1];
216    uint32_t CheckSum, BlockCheckSum;
217    uint32_t block_len;
218    uint32_t block_end;
219    uint32_t BlockNumber;
220    int bhl;
221
222    unser_begin(block->buf, BLKHDR_LENGTH);
223    unser_uint32(CheckSum);
224    unser_uint32(block_len);
225    unser_uint32(BlockNumber);
226    unser_bytes(Id, BLKHDR_ID_LENGTH);
227    ASSERT(unser_length(block->buf) == BLKHDR1_LENGTH);
228
229    Id[BLKHDR_ID_LENGTH] = 0;
230    if (Id[3] == '1') {
231       bhl = BLKHDR1_LENGTH;
232       block->BlockVer = 1;
233       block->bufp = block->buf + bhl;
234       if (strncmp(Id, BLKHDR1_ID, BLKHDR_ID_LENGTH) != 0) {
235          dev->dev_errno = EIO;
236          Mmsg4(&dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
237             dev->file, dev->block_num, BLKHDR1_ID, Id);
238          if (block->read_errors == 0 || verbose >= 2) {
239             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
240          }
241          block->read_errors++;
242          return false;
243       }
244    } else if (Id[3] == '2') {
245       unser_uint32(block->VolSessionId);
246       unser_uint32(block->VolSessionTime);
247       bhl = BLKHDR2_LENGTH;
248       block->BlockVer = 2;
249       block->bufp = block->buf + bhl;
250       if (strncmp(Id, BLKHDR2_ID, BLKHDR_ID_LENGTH) != 0) {
251          dev->dev_errno = EIO;
252          Mmsg4(&dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
253             dev->file, dev->block_num, BLKHDR2_ID, Id);
254          if (block->read_errors == 0 || verbose >= 2) {
255             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
256          }
257          block->read_errors++;
258          return false;
259       }
260    } else {
261       dev->dev_errno = EIO;
262       Mmsg4(&dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
263           dev->file, dev->block_num, BLKHDR2_ID, Id);
264       if (block->read_errors == 0 || verbose >= 2) {
265          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
266       }
267       block->read_errors++;
268       unser_uint32(block->VolSessionId);
269       unser_uint32(block->VolSessionTime);
270       return false;
271    }
272
273    /* Sanity check */
274    if (block_len > MAX_BLOCK_LENGTH) {
275       dev->dev_errno = EIO;
276       Mmsg3(&dev->errmsg,  _("Volume data error at %u:%u! Block length %u is insane (too large), probably due to a bad archive.\n"),
277          dev->file, dev->block_num, block_len);
278       if (block->read_errors == 0 || verbose >= 2) {
279          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
280       }
281       block->read_errors++;
282       return false;
283    }
284
285    Dmsg1(190, "unser_block_header block_len=%d\n", block_len);
286    /* Find end of block or end of buffer whichever is smaller */
287    if (block_len > block->read_len) {
288       block_end = block->read_len;
289    } else {
290       block_end = block_len;
291    }
292    block->binbuf = block_end - bhl;
293    block->block_len = block_len;
294    block->BlockNumber = BlockNumber;
295    Dmsg3(190, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
296       bhl, block_len);
297    if (block_len <= block->read_len) {
298       BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
299                          block_len-BLKHDR_CS_LENGTH);
300       if (BlockCheckSum != CheckSum) {
301          dev->dev_errno = EIO;
302          Mmsg5(&dev->errmsg, _("Volume data error at %u:%u! Block checksum mismatch in block %u: calc=%x blk=%x\n"), 
303             dev->file, dev->block_num, (unsigned)BlockNumber, BlockCheckSum, CheckSum);
304          if (block->read_errors == 0 || verbose >= 2) {
305             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
306          }
307          block->read_errors++;
308          if (!forge_on) {
309             return false;
310          }
311       }
312    }
313    return true;
314 }
315
316 /*  
317  * Write a block to the device, with locking and unlocking
318  *
319  * Returns: true  on success
320  *        : false on failure
321  *
322  */
323 bool write_block_to_device(DCR *dcr, DEV_BLOCK *block)
324 {
325    bool stat = true;
326    DEVICE *dev = dcr->dev;
327    JCR *jcr = dcr->jcr;
328
329
330    if (dcr->spooling) {
331       stat = write_block_to_spool_file(dcr, block);
332       return stat;
333    }
334
335    if (!dcr->dev_locked) {
336       lock_device(dev);
337    }
338
339    /*
340     * If a new volume has been mounted since our last write
341     *   Create a JobMedia record for the previous volume written,
342     *   and set new parameters to write this volume   
343     * The same applies for if we are in a new file.
344     */
345    if (dcr->NewVol || dcr->NewFile) {
346       /* Create a jobmedia record for this job */
347       if (!dir_create_jobmedia_record(jcr)) {
348          dev->dev_errno = EIO;
349          Jmsg(jcr, M_ERROR, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
350             jcr->VolCatInfo.VolCatName, jcr->Job);
351          set_new_volume_parameters(jcr, dev);
352          stat = false;
353          goto bail_out;
354       }
355       if (dcr->NewVol) {
356          /* Note, setting a new volume also handles any pending new file */
357          set_new_volume_parameters(jcr, dev);
358          dcr->NewFile = false;        /* this handled for new file too */
359       } else {
360          set_new_file_parameters(jcr, dev);
361       }
362    }
363
364    if (!write_block_to_dev(dcr, block)) {
365        stat = fixup_device_block_write_error(dcr, block);
366    }
367
368 bail_out:
369    if (!dcr->dev_locked) {
370       unlock_device(dev);
371    }
372    return stat;
373 }
374
375 /*
376  * Write a block to the device 
377  *
378  *  Returns: true  on success or EOT
379  *           false on hard error
380  */
381 bool write_block_to_dev(DCR *dcr, DEV_BLOCK *block)
382 {
383    ssize_t stat = 0;
384    uint32_t wlen;                     /* length to write */
385    int hit_max1, hit_max2;
386    bool ok;
387    DEVICE *dev = dcr->dev;
388    JCR *jcr = dcr->jcr;
389
390 #ifdef NO_TAPE_WRITE_TEST
391    empty_block(block);
392    return true;
393 #endif
394    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
395
396    /* dump_block(block, "before write"); */
397    if (dev->state & ST_WEOT) {
398       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
399       dev->dev_errno = ENOSPC;
400       Jmsg(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM.\n"));
401       return false;
402    }
403    wlen = block->binbuf;
404    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
405       Dmsg0(100, "return write_block_to_dev no data to write\n");
406       return true;
407    }
408    /* 
409     * Clear to the end of the buffer if it is not full,
410     *  and on tape devices, apply min and fixed blocking.
411     */
412    if (wlen != block->buf_len) {
413       uint32_t blen;                  /* current buffer length */
414
415       Dmsg2(200, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
416       blen = wlen;
417
418       /* Adjust write size to min/max for tapes only */
419       if (dev->state & ST_TAPE) {
420          /* check for fixed block size */
421          if (dev->min_block_size == dev->max_block_size) {
422             wlen = block->buf_len;    /* fixed block size already rounded */
423          /* Check for min block size */
424          } else if (wlen < dev->min_block_size) {
425             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
426          /* Ensure size is rounded */
427          } else {
428             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
429          }
430       }
431       if (wlen-blen > 0) {
432          memset(block->bufp, 0, wlen-blen); /* clear garbage */
433       }
434    }  
435
436    ser_block_header(block);
437
438    /* Limit maximum Volume size to value specified by user */
439    hit_max1 = (dev->max_volume_size > 0) &&
440        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
441    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
442        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
443    if (hit_max1 || hit_max2) {   
444       char ed1[50];
445       uint64_t max_cap;
446       Dmsg0(10, "==== Output bytes Triggered medium max capacity.\n");
447       if (hit_max1) {
448          max_cap = dev->max_volume_size;
449       } else {
450          max_cap = dev->VolCatInfo.VolCatMaxBytes;
451       }
452       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
453             edit_uint64_with_commas(max_cap, ed1),  dev->dev_name);
454       block->write_failed = true;
455       if (weof_dev(dev, 1) != 0) {            /* end tape */
456          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
457          dev->VolCatInfo.VolCatErrors++;
458       }
459       /* Don't do update after second EOF or file count will be wrong */
460       Dmsg0(100, "dir_update_volume_info\n");
461       dev->VolCatInfo.VolCatFiles = dev->file;
462       dir_update_volume_info(jcr, false);
463       if (dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {  /* write eof */
464          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
465          dev->VolCatInfo.VolCatErrors++;
466       }
467       dev->state |= (ST_EOF | ST_EOT | ST_WEOT);
468       dev->dev_errno = ENOSPC;
469       return false;
470    }
471
472    /* Limit maximum File size on volume to user specified value */
473    if ((dev->max_file_size > 0) && 
474        (dev->file_size+block->binbuf) >= dev->max_file_size) {
475
476       if (dev_state(dev, ST_TAPE) && weof_dev(dev, 1) != 0) {            /* write eof */
477          /* Write EOF */
478          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
479          block->write_failed = true;
480          dev->VolCatInfo.VolCatErrors++;
481          dev->state |= (ST_EOF | ST_EOT | ST_WEOT);
482          Dmsg0(100, "dir_update_volume_info\n");
483          dev->VolCatInfo.VolCatFiles = dev->file;
484          dir_update_volume_info(jcr, false);
485          dev->dev_errno = ENOSPC;
486          return false;
487       }
488
489       /* Create a JobMedia record so restore can seek */
490       Dmsg0(100, "dir_update_volume_info\n");
491       dev->VolCatInfo.VolCatFiles = dev->file;
492       dir_update_volume_info(jcr, false);
493       if (!dir_create_jobmedia_record(jcr)) {
494          dev->dev_errno = EIO;
495           Jmsg(jcr, M_ERROR, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
496                dcr->VolCatInfo.VolCatName, jcr->Job);
497           if (!forge_on) {
498              return false;
499           }
500       }
501       dev->file_size = 0;             /* reset file size */
502       /* 
503        * Walk through all attached jcrs indicating the file has changed   
504        */
505       Dmsg1(100, "Walk attached jcrs. Volume=%s\n", dev->VolCatInfo.VolCatName);
506       for (JCR *mjcr=NULL; (mjcr=next_attached_jcr(dev, mjcr)); ) {
507          if (mjcr->JobId == 0) {
508             continue;                 /* ignore console */
509          }
510          mjcr->dcr->NewFile = true;   /* set reminder to do set_new_file_params */
511       }
512       set_new_file_parameters(jcr, dev);
513    }
514
515    dev->VolCatInfo.VolCatWrites++;
516    Dmsg1(200, "Write block of %u bytes\n", wlen);      
517 #ifdef DEBUG_BLOCK_ZEROING
518    uint32_t *bp = (uint32_t *)block->buf;
519    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
520       Jmsg0(jcr, M_ABORT, 0, "Write block header zeroed.\n");
521    }
522 #endif
523
524    stat = write(dev->fd, block->buf, (size_t)wlen);
525
526 #ifdef DEBUG_BLOCK_ZEROING
527    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
528       Jmsg0(jcr, M_ABORT, 0, "Write block header zeroed.\n");
529    }
530 #endif
531
532    if (stat != (ssize_t)wlen) {
533       /* We should check for errno == ENOSPC, BUT many 
534        * devices simply report EIO when the volume is full.
535        * With a little more thought we may be able to check
536        * capacity and distinguish real errors and EOT
537        * conditions.  In any case, we probably want to
538        * simulate an End of Medium.
539        */
540       if (stat == -1) {
541          /* I have added the ifdefing here because it appears on
542           * FreeBSD where MTIOCERRSTAT is defined, this not only
543           * clears the error but clears the residual unwritten
544           * buffers -> data loss. As a consequence, on those
545           * systems (FreeBSD like), do the clrerror() only after
546           * the weof_dev() call.
547           */
548          clrerror_dev(dev, -1);
549          if (dev->dev_errno == 0) {
550             dev->dev_errno = ENOSPC;        /* out of space */
551          }
552          Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"), 
553             dev->file, dev->block_num, dev->dev_name, strerror(dev->dev_errno));
554       } else {
555         dev->dev_errno = ENOSPC;            /* out of space */
556          Jmsg(jcr, M_INFO, 0, _("End of medium at %u:%u on device %s. Write of %u bytes got %d.\n"), 
557             dev->file, dev->block_num, dev->dev_name, wlen, stat);
558       }  
559
560       Dmsg6(100, "=== Write error. size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n", 
561          wlen, stat, dev->block_num, block->BlockNumber, dev->dev_errno, strerror(dev->dev_errno));
562
563       block->write_failed = true;
564       if (weof_dev(dev, 1) != 0) {         /* end the tape */
565          dev->VolCatInfo.VolCatErrors++;
566          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
567       }
568       Dmsg0(100, "dir_update_volume_info\n");
569       dev->VolCatInfo.VolCatFiles = dev->file;
570       dir_update_volume_info(jcr, false);
571       if (dev_cap(dev, CAP_TWOEOF) && weof_dev(dev, 1) != 0) {  /* end the tape */
572          dev->VolCatInfo.VolCatErrors++;
573          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
574       }
575       dev->state |= (ST_EOF | ST_EOT | ST_WEOT);
576         
577       ok = true;
578 #define CHECK_LAST_BLOCK
579 #ifdef  CHECK_LAST_BLOCK
580       /* 
581        * If the device is a tape and it supports backspace record,
582        *   we backspace over one or two eof marks depending on 
583        *   how many we just wrote, then over the last record,
584        *   then re-read it and verify that the block number is
585        *   correct.
586        */
587       if ((dev->state & ST_TAPE) && dev_cap(dev, CAP_BSR)) {
588
589          /* Now back up over what we wrote and read the last block */
590          if (!bsf_dev(dev, 1)) {
591             ok = false;
592             Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), strerror(dev->dev_errno));
593          }
594          if (ok && dev_cap(dev, CAP_TWOEOF) && !bsf_dev(dev, 1)) {
595             ok = false;
596             Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), strerror(dev->dev_errno));
597          }
598          /* Backspace over record */
599          if (ok && !bsr_dev(dev, 1)) {
600             ok = false;
601             Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), strerror(dev->dev_errno));
602             /*
603              *  On FreeBSD systems, if the user got here, it is likely that his/her
604              *    tape drive is "frozen".  The correct thing to do is a 
605              *    rewind(), but if we do that, higher levels in cleaning up, will
606              *    most likely write the EOS record over the beginning of the
607              *    tape.  The rewind *is* done later in mount.c when another
608              *    tape is requested. Note, the clrerror_dev() call in bsr_dev()
609              *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
610              */
611          }
612          if (ok) {
613             DEV_BLOCK *lblock = new_block(dev);
614             /* Note, this can destroy dev->errmsg */
615             if (!read_block_from_dev(dcr, lblock, NO_BLOCK_NUMBER_CHECK)) {
616                Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), dev->errmsg);
617             } else {
618                if (lblock->BlockNumber+1 == block->BlockNumber) {
619                   Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
620                } else {
621                   Jmsg(jcr, M_ERROR, 0, _(
622 "Re-read of last block failed. Last block=%u Current block=%u.\n"),
623                        lblock->BlockNumber, block->BlockNumber);
624                }
625             }
626             free_block(lblock);
627          }
628       }
629 #endif
630       return false;
631    }
632
633    /* We successfully wrote the block, now do housekeeping */
634
635    dev->VolCatInfo.VolCatBytes += block->binbuf;
636    dev->VolCatInfo.VolCatBlocks++;   
637    dev->EndBlock = dev->block_num;
638    dev->EndFile  = dev->file;
639    dev->block_num++;
640    block->BlockNumber++;
641
642    /* Update jcr values */
643    if (dev_state(dev, ST_TAPE)) {
644       dcr->EndBlock = dev->EndBlock;
645       dcr->EndFile  = dev->EndFile;
646    } else {
647       /* Save address of start of block just written */
648       dcr->EndBlock = (uint32_t)dev->file_addr;
649       dcr->EndFile = (uint32_t)(dev->file_addr >> 32);
650    }
651    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
652       dcr->VolFirstIndex = block->FirstIndex;
653    }
654    if (block->LastIndex > 0) {
655       dcr->VolLastIndex = block->LastIndex;
656    }
657    dcr->WroteVol = true;
658    dev->file_addr += wlen;            /* update file address */
659    dev->file_size += wlen;
660
661    Dmsg2(190, "write_block: wrote block %d bytes=%d\n", dev->block_num,
662       wlen);
663    empty_block(block);
664    return true;
665 }
666
667 /*  
668  * Read block with locking
669  *
670  */
671 bool read_block_from_device(DCR *dcr, DEV_BLOCK *block, bool check_block_numbers)
672 {
673    bool stat;
674    DEVICE *dev = dcr->dev;
675    Dmsg0(90, "Enter read_block_from_device\n");
676    lock_device(dev);
677    stat = read_block_from_dev(dcr, block, check_block_numbers);
678    unlock_device(dev);
679    Dmsg0(90, "Leave read_block_from_device\n");
680    return stat;
681 }
682
683 /*
684  * Read the next block into the block structure and unserialize
685  *  the block header.  For a file, the block may be partially
686  *  or completely in the current buffer.
687  */
688 bool read_block_from_dev(DCR *dcr, DEV_BLOCK *block, bool check_block_numbers)
689 {
690    ssize_t stat;
691    int looping;
692    uint32_t BlockNumber;
693    int retry;
694    JCR *jcr = dcr->jcr;
695    DEVICE *dev = dcr->dev;
696
697    if (dev_state(dev, ST_EOT)) {
698       return false;
699    }
700    looping = 0;
701    Dmsg1(100, "Full read() in read_block_from_device() len=%d\n",
702          block->buf_len);
703 reread:
704    if (looping > 1) {
705       dev->dev_errno = EIO;
706       Mmsg1(&dev->errmsg, _("Block buffer size looping problem on device %s\n"),
707          dev->dev_name);
708       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
709       block->read_len = 0;
710       return false;
711    }
712    retry = 0;
713    do {
714 //    uint32_t *bp = (uint32_t *)block->buf;
715 //    Dmsg3(000, "Read %p %u at %llu\n", block->buf, block->buf_len, lseek(dev->fd, 0, SEEK_CUR));
716
717       stat = read(dev->fd, block->buf, (size_t)block->buf_len);
718
719 //    Dmsg8(000, "stat=%d Csum=%u blen=%u bnum=%u %c%c%c%c\n",stat, bp[0],bp[1],bp[2],
720 //      block->buf[12],block->buf[13],block->buf[14],block->buf[15]);
721
722       if (retry == 1) {
723          dev->VolCatInfo.VolCatErrors++;   
724       }
725    } while (stat == -1 && (errno == EINTR || errno == EIO) && retry++ < 11);
726    if (stat < 0) {
727       Dmsg1(90, "Read device got: ERR=%s\n", strerror(errno));
728       clrerror_dev(dev, -1);
729       block->read_len = 0;
730       Mmsg4(&dev->errmsg, _("Read error at file:blk %u:%u on device %s. ERR=%s.\n"), 
731          dev->file, dev->block_num, dev->dev_name, strerror(dev->dev_errno));
732       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
733       if (dev->state & ST_EOF) {  /* EOF just seen? */
734          dev->state |= ST_EOT;    /* yes, error => EOT */
735       }
736       return false;
737    }
738    Dmsg1(90, "Read device got %d bytes\n", stat);
739    if (stat == 0) {             /* Got EOF ! */
740       dev->block_num = block->read_len = 0;
741       Mmsg3(&dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"), 
742          dev->file, dev->block_num, dev->dev_name);
743       if (dev->state & ST_EOF) { /* EOF already read? */
744          dev->state |= ST_EOT;  /* yes, 2 EOFs => EOT */
745          block->read_len = 0;
746          return 0;
747       }
748       dev->file++;              /* increment file */
749       dev->state |= ST_EOF;     /* set EOF read */
750       block->read_len = 0;
751       return false;             /* return eof */
752    }
753    /* Continue here for successful read */
754    block->read_len = stat;      /* save length read */
755    if (block->read_len < BLKHDR2_LENGTH) {
756       dev->dev_errno = EIO;
757       Mmsg4(&dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"), 
758          dev->file, dev->block_num, block->read_len, dev->dev_name);
759       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
760       dev->state |= ST_SHORT;   /* set short block */
761       block->read_len = block->binbuf = 0;
762       return false;             /* return error */
763    }  
764
765    BlockNumber = block->BlockNumber + 1;
766    if (!unser_block_header(jcr, dev, block)) {
767       if (forge_on) {
768          dev->file_addr += block->read_len;
769          dev->file_size += block->read_len;
770          goto reread;
771       }
772       return false;
773    }
774
775    /*
776     * If the block is bigger than the buffer, we reposition for
777     *  re-reading the block, allocate a buffer of the correct size,
778     *  and go re-read.
779     */
780    if (block->block_len > block->buf_len) {
781       dev->dev_errno = EIO;
782       Mmsg2(&dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
783          block->block_len, block->buf_len);
784       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
785       Pmsg1(000, "%s", dev->errmsg);
786       /* Attempt to reposition to re-read the block */
787       if (dev->state & ST_TAPE) {
788          Dmsg0(100, "Backspace record for reread.\n");
789          if (!bsr_dev(dev, 1)) {
790             Jmsg(jcr, M_ERROR, 0, "%s", strerror_dev(dev));
791             block->read_len = 0;
792             return false;
793          }
794       } else {
795          Dmsg0(200, "Seek to beginning of block for reread.\n");
796          off_t pos = lseek(dev->fd, (off_t)0, SEEK_CUR); /* get curr pos */
797          pos -= block->read_len;
798          lseek(dev->fd, pos, SEEK_SET);   
799          dev->file_addr = pos;
800       }
801       Mmsg1(&dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
802       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
803       Pmsg1(000, "%s", dev->errmsg);
804       /* Set new block length */
805       dev->max_block_size = block->block_len;
806       block->buf_len = block->block_len;
807       free_memory(block->buf);
808       block->buf = get_memory(block->buf_len);
809       empty_block(block);
810       looping++;
811       goto reread;                    /* re-read block with correct block size */
812    }
813
814    if (block->block_len > block->read_len) {
815       dev->dev_errno = EIO;
816       Mmsg4(&dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"), 
817          dev->file, dev->block_num, block->read_len, dev->dev_name);
818       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
819       dev->state |= ST_SHORT;   /* set short block */
820       block->read_len = block->binbuf = 0;
821       return false;             /* return error */
822    }  
823
824    dev->state &= ~(ST_EOF|ST_SHORT); /* clear EOF and short block */
825    dev->VolCatInfo.VolCatReads++;   
826    dev->VolCatInfo.VolCatRBytes += block->read_len;
827
828    dev->VolCatInfo.VolCatBytes += block->block_len;
829    dev->VolCatInfo.VolCatBlocks++;   
830    dev->EndBlock = dev->block_num;
831    dev->EndFile  = dev->file;
832    dev->block_num++;
833
834    /* Update jcr values */
835    if (dev->state & ST_TAPE) {
836       dcr->EndBlock = dev->EndBlock;
837       dcr->EndFile  = dev->EndFile;
838    } else {
839       dcr->EndBlock = (uint32_t)dev->file_addr;
840       dcr->EndFile = (uint32_t)(dev->file_addr >> 32);
841       dev->block_num = dcr->EndBlock;
842       dev->file = dcr->EndFile;
843    }
844    dev->file_addr += block->block_len;
845    dev->file_size += block->block_len;
846
847    /*
848     * If we read a short block on disk,
849     * seek to beginning of next block. This saves us
850     * from shuffling blocks around in the buffer. Take a
851     * look at this from an efficiency stand point later, but
852     * it should only happen once at the end of each job.
853     *
854     * I've been lseek()ing negative relative to SEEK_CUR for 30
855     *   years now. However, it seems that with the new off_t definition,
856     *   it is not possible to seek negative amounts, so we use two
857     *   lseek(). One to get the position, then the second to do an
858     *   absolute positioning -- so much for efficiency.  KES Sep 02.
859     */
860    Dmsg0(200, "At end of read block\n");
861    if (block->read_len > block->block_len && !(dev->state & ST_TAPE)) {
862       off_t pos = lseek(dev->fd, (off_t)0, SEEK_CUR); /* get curr pos */
863       pos -= (block->read_len - block->block_len);
864       lseek(dev->fd, pos, SEEK_SET);   
865       Dmsg2(200, "Did lseek blk_size=%d rdlen=%d\n", block->block_len,
866             block->read_len);
867       dev->file_addr = pos;
868       dev->file_size = pos;
869    }
870    Dmsg2(200, "Exit read_block read_len=%d block_len=%d\n",
871       block->read_len, block->block_len);
872    block->block_read = true;
873    return true;
874 }