]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
a5b7c9c7fa24fe1b4e5af8eb4657d9a2fc9c0419
[bacula/bacula] / bacula / src / stored / block.c
1 /*
2    Bacula® - The Network Backup Solution
3
4    Copyright (C) 2001-2010 Free Software Foundation Europe e.V.
5
6    The main author of Bacula is Kern Sibbald, with contributions from
7    many others, a complete list can be found in the file AUTHORS.
8    This program is Free Software; you can redistribute it and/or
9    modify it under the terms of version two of the GNU General Public
10    License as published by the Free Software Foundation and included
11    in the file LICENSE.
12
13    This program is distributed in the hope that it will be useful, but
14    WITHOUT ANY WARRANTY; without even the implied warranty of
15    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
16    General Public License for more details.
17
18    You should have received a copy of the GNU General Public License
19    along with this program; if not, write to the Free Software
20    Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA
21    02110-1301, USA.
22
23    Bacula® is a registered trademark of Kern Sibbald.
24    The licensor of Bacula is the Free Software Foundation Europe
25    (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich,
26    Switzerland, email:ftf@fsfeurope.org.
27 */
28 /*
29  *
30  *   block.c -- tape block handling functions
31  *
32  *              Kern Sibbald, March MMI
33  *                 added BB02 format October MMII
34  *
35  */
36
37
38 #include "bacula.h"
39 #include "stored.h"
40
41 static bool terminate_writing_volume(DCR *dcr);
42 static bool do_new_file_bookkeeping(DCR *dcr);
43 static bool do_dvd_size_checks(DCR *dcr);
44 static void reread_last_block(DCR *dcr);
45
46 /*
47  * Dump the block header, then walk through
48  * the block printing out the record headers.
49  */
50 void dump_block(DEV_BLOCK *b, const char *msg)
51 {
52    ser_declare;
53    char *p;
54    char Id[BLKHDR_ID_LENGTH+1];
55    uint32_t CheckSum, BlockCheckSum;
56    uint32_t block_len;
57    uint32_t BlockNumber;
58    uint32_t VolSessionId, VolSessionTime, data_len;
59    int32_t  FileIndex;
60    int32_t  Stream;
61    int bhl, rhl;
62    char buf1[100], buf2[100];
63
64    unser_begin(b->buf, BLKHDR1_LENGTH);
65    unser_uint32(CheckSum);
66    unser_uint32(block_len);
67    unser_uint32(BlockNumber);
68    unser_bytes(Id, BLKHDR_ID_LENGTH);
69    ASSERT(unser_length(b->buf) == BLKHDR1_LENGTH);
70    Id[BLKHDR_ID_LENGTH] = 0;
71    if (Id[3] == '2') {
72       unser_uint32(VolSessionId);
73       unser_uint32(VolSessionTime);
74       bhl = BLKHDR2_LENGTH;
75       rhl = RECHDR2_LENGTH;
76    } else {
77       VolSessionId = VolSessionTime = 0;
78       bhl = BLKHDR1_LENGTH;
79       rhl = RECHDR1_LENGTH;
80    }
81
82    if (block_len > 100000) {
83       Dmsg3(20, "Dump block %s 0x%x blocksize too big %u\n", msg, b, block_len);
84       return;
85    }
86
87    BlockCheckSum = bcrc32((uint8_t *)b->buf+BLKHDR_CS_LENGTH,
88                          block_len-BLKHDR_CS_LENGTH);
89    Pmsg6(000, _("Dump block %s %x: size=%d BlkNum=%d\n"
90 "               Hdrcksum=%x cksum=%x\n"),
91       msg, b, block_len, BlockNumber, CheckSum, BlockCheckSum);
92    p = b->buf + bhl;
93    while (p < (b->buf + block_len+WRITE_RECHDR_LENGTH)) {
94       unser_begin(p, WRITE_RECHDR_LENGTH);
95       if (rhl == RECHDR1_LENGTH) {
96          unser_uint32(VolSessionId);
97          unser_uint32(VolSessionTime);
98       }
99       unser_int32(FileIndex);
100       unser_int32(Stream);
101       unser_uint32(data_len);
102       Pmsg6(000, _("   Rec: VId=%u VT=%u FI=%s Strm=%s len=%d p=%x\n"),
103            VolSessionId, VolSessionTime, FI_to_ascii(buf1, FileIndex),
104            stream_to_ascii(buf2, Stream, FileIndex), data_len, p);
105       p += data_len + rhl;
106   }
107 }
108
109 /*
110  * Create a new block structure.
111  * We pass device so that the block can inherit the
112  * min and max block sizes.
113  */
114 DEV_BLOCK *new_block(DEVICE *dev)
115 {
116    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
117
118    memset(block, 0, sizeof(DEV_BLOCK));
119
120    /* If the user has specified a max_block_size, use it as the default */
121    if (dev->max_block_size == 0) {
122       block->buf_len = DEFAULT_BLOCK_SIZE;
123    } else {
124       block->buf_len = dev->max_block_size;
125    }
126    block->dev = dev;
127    block->block_len = block->buf_len;  /* default block size */
128    block->buf = get_memory(block->buf_len);
129    empty_block(block);
130    block->BlockVer = BLOCK_VER;       /* default write version */
131    Dmsg1(650, "Returning new block=%x\n", block);
132    return block;
133 }
134
135
136 /*
137  * Duplicate an existing block (eblock)
138  */
139 DEV_BLOCK *dup_block(DEV_BLOCK *eblock)
140 {
141    DEV_BLOCK *block = (DEV_BLOCK *)get_memory(sizeof(DEV_BLOCK));
142    int buf_len = sizeof_pool_memory(eblock->buf);
143
144    memcpy(block, eblock, sizeof(DEV_BLOCK));
145    block->buf = get_memory(buf_len);
146    memcpy(block->buf, eblock->buf, buf_len);
147    return block;
148 }
149
150
151 /*
152  * Only the first block checksum error was reported.
153  *   If there are more, report it now.
154  */
155 void print_block_read_errors(JCR *jcr, DEV_BLOCK *block)
156 {
157    if (block->read_errors > 1) {
158       Jmsg(jcr, M_ERROR, 0, _("%d block read errors not printed.\n"),
159          block->read_errors);
160    }
161 }
162
163 /*
164  * Free block
165  */
166 void free_block(DEV_BLOCK *block)
167 {
168    Dmsg1(999, "free_block buffer %x\n", block->buf);
169    free_memory(block->buf);
170    Dmsg1(999, "free_block block %x\n", block);
171    free_memory((POOLMEM *)block);
172 }
173
174 /* Empty the block -- for writing */
175 void empty_block(DEV_BLOCK *block)
176 {
177    block->binbuf = WRITE_BLKHDR_LENGTH;
178    block->bufp = block->buf + block->binbuf;
179    block->read_len = 0;
180    block->write_failed = false;
181    block->block_read = false;
182    block->FirstIndex = block->LastIndex = 0;
183 }
184
185 /*
186  * Create block header just before write. The space
187  * in the buffer should have already been reserved by
188  * init_block.
189  */
190 static void ser_block_header(DEV_BLOCK *block, bool do_checksum)
191 {
192    ser_declare;
193    uint32_t CheckSum = 0;
194    uint32_t block_len = block->binbuf;
195
196    Dmsg1(1390, "ser_block_header: block_len=%d\n", block_len);
197    ser_begin(block->buf, BLKHDR2_LENGTH);
198    ser_uint32(CheckSum);
199    ser_uint32(block_len);
200    ser_uint32(block->BlockNumber);
201    ser_bytes(WRITE_BLKHDR_ID, BLKHDR_ID_LENGTH);
202    if (BLOCK_VER >= 2) {
203       ser_uint32(block->VolSessionId);
204       ser_uint32(block->VolSessionTime);
205    }
206
207    /* Checksum whole block except for the checksum */
208    if (do_checksum) {
209       CheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
210                     block_len-BLKHDR_CS_LENGTH);
211    }
212    Dmsg1(1390, "ser_bloc_header: checksum=%x\n", CheckSum);
213    ser_begin(block->buf, BLKHDR2_LENGTH);
214    ser_uint32(CheckSum);              /* now add checksum to block header */
215 }
216
217 /*
218  * Unserialize the block header for reading block.
219  *  This includes setting all the buffer pointers correctly.
220  *
221  *  Returns: false on failure (not a block)
222  *           true  on success
223  */
224 static bool unser_block_header(JCR *jcr, DEVICE *dev, DEV_BLOCK *block)
225 {
226    ser_declare;
227    char Id[BLKHDR_ID_LENGTH+1];
228    uint32_t CheckSum, BlockCheckSum;
229    uint32_t block_len;
230    uint32_t block_end;
231    uint32_t BlockNumber;
232    int bhl;
233
234    unser_begin(block->buf, BLKHDR_LENGTH);
235    unser_uint32(CheckSum);
236    unser_uint32(block_len);
237    unser_uint32(BlockNumber);
238    unser_bytes(Id, BLKHDR_ID_LENGTH);
239    ASSERT(unser_length(block->buf) == BLKHDR1_LENGTH);
240
241    Id[BLKHDR_ID_LENGTH] = 0;
242    if (Id[3] == '1') {
243       bhl = BLKHDR1_LENGTH;
244       block->BlockVer = 1;
245       block->bufp = block->buf + bhl;
246       if (strncmp(Id, BLKHDR1_ID, BLKHDR_ID_LENGTH) != 0) {
247          dev->dev_errno = EIO;
248          Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
249             dev->file, dev->block_num, BLKHDR1_ID, Id);
250          if (block->read_errors == 0 || verbose >= 2) {
251             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
252          }
253          block->read_errors++;
254          return false;
255       }
256    } else if (Id[3] == '2') {
257       unser_uint32(block->VolSessionId);
258       unser_uint32(block->VolSessionTime);
259       bhl = BLKHDR2_LENGTH;
260       block->BlockVer = 2;
261       block->bufp = block->buf + bhl;
262       if (strncmp(Id, BLKHDR2_ID, BLKHDR_ID_LENGTH) != 0) {
263          dev->dev_errno = EIO;
264          Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
265             dev->file, dev->block_num, BLKHDR2_ID, Id);
266          if (block->read_errors == 0 || verbose >= 2) {
267             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
268          }
269          block->read_errors++;
270          return false;
271       }
272    } else {
273       dev->dev_errno = EIO;
274       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Wanted ID: \"%s\", got \"%s\". Buffer discarded.\n"),
275           dev->file, dev->block_num, BLKHDR2_ID, Id);
276       Dmsg1(50, "%s", dev->errmsg);
277       if (block->read_errors == 0 || verbose >= 2) {
278          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
279       }
280       block->read_errors++;
281       unser_uint32(block->VolSessionId);
282       unser_uint32(block->VolSessionTime);
283       return false;
284    }
285
286    /* Sanity check */
287    if (block_len > MAX_BLOCK_LENGTH) {
288       dev->dev_errno = EIO;
289       Mmsg3(dev->errmsg,  _("Volume data error at %u:%u! Block length %u is insane (too large), probably due to a bad archive.\n"),
290          dev->file, dev->block_num, block_len);
291       if (block->read_errors == 0 || verbose >= 2) {
292          Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
293       }
294       block->read_errors++;
295       return false;
296    }
297
298    Dmsg1(390, "unser_block_header block_len=%d\n", block_len);
299    /* Find end of block or end of buffer whichever is smaller */
300    if (block_len > block->read_len) {
301       block_end = block->read_len;
302    } else {
303       block_end = block_len;
304    }
305    block->binbuf = block_end - bhl;
306    block->block_len = block_len;
307    block->BlockNumber = BlockNumber;
308    Dmsg3(390, "Read binbuf = %d %d block_len=%d\n", block->binbuf,
309       bhl, block_len);
310    if (block_len <= block->read_len && dev->do_checksum()) {
311       BlockCheckSum = bcrc32((uint8_t *)block->buf+BLKHDR_CS_LENGTH,
312                          block_len-BLKHDR_CS_LENGTH);
313       if (BlockCheckSum != CheckSum) {
314          dev->dev_errno = EIO;
315          Mmsg6(dev->errmsg, _("Volume data error at %u:%u!\n" 
316             "Block checksum mismatch in block=%u len=%d: calc=%x blk=%x\n"),
317             dev->file, dev->block_num, (unsigned)BlockNumber, 
318             block_len, BlockCheckSum, CheckSum);
319          if (block->read_errors == 0 || verbose >= 2) {
320             Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
321          }
322          block->read_errors++;
323          if (!forge_on) {
324             return false;
325          }
326       }
327    }
328    return true;
329 }
330
331 /*
332  * Write a block to the device, with locking and unlocking
333  *
334  * Returns: true  on success
335  *        : false on failure
336  *
337  */
338 bool write_block_to_device(DCR *dcr)
339 {
340    bool stat = true;
341    DEVICE *dev = dcr->dev;
342    JCR *jcr = dcr->jcr;
343
344    if (dcr->spooling) {
345       stat = write_block_to_spool_file(dcr);
346       return stat;
347    }
348
349    if (!dcr->is_dev_locked()) {        /* device already locked? */
350       /* note, do not change this to dcr->r_dlock */
351       dev->r_dlock();                  /* no, lock it */
352    }
353
354    /*
355     * If a new volume has been mounted since our last write
356     *   Create a JobMedia record for the previous volume written,
357     *   and set new parameters to write this volume
358     * The same applies for if we are in a new file.
359     */
360    if (dcr->NewVol || dcr->NewFile) {
361       if (job_canceled(jcr)) {
362          stat = false;
363          goto bail_out;
364       }
365       /* Create a jobmedia record for this job */
366       if (!dir_create_jobmedia_record(dcr)) {
367          dev->dev_errno = EIO;
368          Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
369             dcr->getVolCatName(), jcr->Job);
370          set_new_volume_parameters(dcr);
371          stat = false;
372          goto bail_out;
373       }
374       if (dcr->NewVol) {
375          /* Note, setting a new volume also handles any pending new file */
376          set_new_volume_parameters(dcr);
377       } else {
378          set_new_file_parameters(dcr);
379       }
380    }
381
382    if (!write_block_to_dev(dcr)) {
383        if (job_canceled(jcr) || jcr->getJobType() == JT_SYSTEM) {
384           stat = false;
385        } else {
386           stat = fixup_device_block_write_error(dcr);
387        }
388    }
389
390 bail_out:
391    if (!dcr->is_dev_locked()) {        /* did we lock dev above? */
392       /* note, do not change this to dcr->dunlock */
393       dev->dunlock();                  /* unlock it now */
394    }
395    return stat;
396 }
397
398 /*
399  * Write a block to the device
400  *
401  *  Returns: true  on success or EOT
402  *           false on hard error
403  */
404 bool write_block_to_dev(DCR *dcr)
405 {
406    ssize_t stat = 0;
407    uint32_t wlen;                     /* length to write */
408    int hit_max1, hit_max2;
409    bool ok = true;
410    DEVICE *dev = dcr->dev;
411    JCR *jcr = dcr->jcr;
412    DEV_BLOCK *block = dcr->block;
413
414 #ifdef NO_TAPE_WRITE_TEST
415    empty_block(block);
416    return true;
417 #endif
418    if (job_canceled(jcr)) {
419       return false;
420    }
421
422    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
423
424    wlen = block->binbuf;
425    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
426       Dmsg0(100, "return write_block_to_dev no data to write\n");
427       return true;
428    }
429
430    /* dump_block(block, "before write"); */
431    if (dev->at_weot()) {
432       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
433       dev->dev_errno = ENOSPC;
434       Jmsg1(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM. dev=%s\n"), dev->print_name());
435       return false;
436    }
437    if (!dev->can_append()) {
438       dev->dev_errno = EIO;
439       Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume. dev=%s\n"), dev->print_name());
440       return false;
441    }
442
443    if (!dev->is_open()) {
444       Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on closed device=%s\n"), dev->print_name());
445       return false;
446    }
447    /*
448     * Clear to the end of the buffer if it is not full,
449     *  and on tape devices, apply min and fixed blocking.
450     */
451    if (wlen != block->buf_len) {
452       uint32_t blen;                  /* current buffer length */
453
454       Dmsg2(250, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
455       blen = wlen;
456
457       /* Adjust write size to min/max for tapes only */
458       if (dev->is_tape()) {
459          /* check for fixed block size */
460          if (dev->min_block_size == dev->max_block_size) {
461             wlen = block->buf_len;    /* fixed block size already rounded */
462          /* Check for min block size */
463          } else if (wlen < dev->min_block_size) {
464             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
465          /* Ensure size is rounded */
466          } else {
467             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
468          }
469       }
470       if (wlen-blen > 0) {
471          memset(block->bufp, 0, wlen-blen); /* clear garbage */
472       }
473    }
474
475    ser_block_header(block, dev->do_checksum());
476
477    /* Limit maximum Volume size to value specified by user */
478    hit_max1 = (dev->max_volume_size > 0) &&
479        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
480    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
481        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
482    if (hit_max1 || hit_max2) {
483       char ed1[50];
484       uint64_t max_cap;
485       Dmsg0(100, "==== Output bytes Triggered medium max capacity.\n");
486       if (hit_max1) {
487          max_cap = dev->max_volume_size;
488       } else {
489          max_cap = dev->VolCatInfo.VolCatMaxBytes;
490       }
491       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
492             edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
493       terminate_writing_volume(dcr);
494       reread_last_block(dcr);   /* DEBUG */
495       dev->dev_errno = ENOSPC;
496       return false;
497    }
498
499    /* Limit maximum File size on volume to user specified value */
500    if ((dev->max_file_size > 0) &&
501        (dev->file_size+block->binbuf) >= dev->max_file_size) {
502       dev->file_size = 0;             /* reset file size */
503
504       if (!dev->weof(1)) {            /* write eof */
505          Dmsg0(190, "WEOF error in max file size.\n");
506          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
507             dev->bstrerror());
508          terminate_writing_volume(dcr);
509          dev->dev_errno = ENOSPC;
510          return false;
511       }
512       if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
513          return false;
514       }
515
516       if (!do_new_file_bookkeeping(dcr)) {
517          /* Error message already sent */
518          return false;
519       }
520    }
521    
522    if (!do_dvd_size_checks(dcr)) {
523       /* Error message already sent */
524       return false;
525    }
526
527    dev->VolCatInfo.VolCatWrites++;
528    Dmsg1(1300, "Write block of %u bytes\n", wlen);
529 #ifdef DEBUG_BLOCK_ZEROING
530    uint32_t *bp = (uint32_t *)block->buf;
531    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
532       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
533    }
534 #endif
535
536    /*
537     * Do write here, make a somewhat feeble attempt to recover from 
538     *  I/O errors, or from the OS telling us it is busy.
539     */ 
540    int retry = 0;
541    errno = 0;
542    stat = 0;
543    do {
544       if (retry > 0 && stat == -1 && errno == EBUSY) {
545          berrno be;
546          Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
547                retry, stat, errno, be.bstrerror());
548          bmicrosleep(5, 0);    /* pause a bit if busy or lots of errors */
549          dev->clrerror(-1);
550       }
551       stat = dev->write(block->buf, (size_t)wlen);
552
553    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
554
555 #ifdef DEBUG_BLOCK_ZEROING
556    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
557       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
558    }
559 #endif
560
561    if (stat != (ssize_t)wlen) {
562       /* Some devices simply report EIO when the volume is full.
563        * With a little more thought we may be able to check
564        * capacity and distinguish real errors and EOT
565        * conditions.  In any case, we probably want to
566        * simulate an End of Medium.
567        */
568       if (stat == -1) {
569          berrno be;
570          dev->clrerror(-1);
571          if (dev->dev_errno == 0) {
572             dev->dev_errno = ENOSPC;        /* out of space */
573          }
574          if (dev->dev_errno != ENOSPC) {
575             dev->VolCatInfo.VolCatErrors++;
576             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
577                dev->file, dev->block_num, dev->print_name(), be.bstrerror());
578          }
579       } else {
580         dev->dev_errno = ENOSPC;            /* out of space */
581       }
582       if (dev->dev_errno == ENOSPC) {
583          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
584             dev->getVolCatName(),
585             dev->file, dev->block_num, dev->print_name(), wlen, stat);
586       }
587       if (debug_level >= 100) {
588          berrno be;
589          Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
590             dev->fd(), wlen, stat, dev->block_num, block->BlockNumber, 
591             dev->dev_errno, be.bstrerror(dev->dev_errno));
592       }
593
594       ok = terminate_writing_volume(dcr);
595       if (!ok && !forge_on) {
596          return false;
597       }
598       if (ok) {
599          reread_last_block(dcr);
600       }
601       return false;
602    }
603
604    /* We successfully wrote the block, now do housekeeping */
605    Dmsg2(1300, "VolCatBytes=%d newVolCatBytes=%d\n", (int)dev->VolCatInfo.VolCatBytes,
606       (int)(dev->VolCatInfo.VolCatBytes+wlen));
607    dev->VolCatInfo.VolCatBytes += wlen;         
608    dev->VolCatInfo.VolCatBlocks++;
609    dev->EndBlock = dev->block_num;
610    dev->EndFile  = dev->file;
611    dev->LastBlock = block->BlockNumber;
612    block->BlockNumber++;
613
614    /* Update dcr values */
615    if (dev->is_tape()) {
616       dcr->EndBlock = dev->EndBlock;
617       dcr->EndFile  = dev->EndFile;
618       dev->block_num++;
619    } else {
620       /* Save address of block just written */
621       uint64_t addr = dev->file_addr + wlen - 1;
622       dcr->EndBlock = (uint32_t)addr;
623       dcr->EndFile = (uint32_t)(addr >> 32);
624       dev->block_num = dcr->EndBlock;
625       dev->file = dcr->EndFile;
626    }
627    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
628    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
629       dcr->VolFirstIndex = block->FirstIndex;
630    }
631    if (block->LastIndex > 0) {
632       dcr->VolLastIndex = block->LastIndex;
633    }
634    dcr->WroteVol = true;
635    dev->file_addr += wlen;            /* update file address */
636    dev->file_size += wlen;
637    dev->part_size += wlen;
638
639    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
640    empty_block(block);
641    return true;
642 }
643
644 static void reread_last_block(DCR *dcr)
645 {
646 #define CHECK_LAST_BLOCK
647 #ifdef  CHECK_LAST_BLOCK
648    bool ok = true;
649    DEVICE *dev = dcr->dev;
650    JCR *jcr = dcr->jcr;
651    DEV_BLOCK *block = dcr->block;
652    /*
653     * If the device is a tape and it supports backspace record,
654     *   we backspace over one or two eof marks depending on
655     *   how many we just wrote, then over the last record,
656     *   then re-read it and verify that the block number is
657     *   correct.
658     */
659    if (dev->is_tape() && dev->has_cap(CAP_BSR)) {
660       /* Now back up over what we wrote and read the last block */
661       if (!dev->bsf(1)) {
662          berrno be;
663          ok = false;
664          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
665               be.bstrerror(dev->dev_errno));
666       }
667       if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
668          berrno be;
669          ok = false;
670          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
671               be.bstrerror(dev->dev_errno));
672       }
673       /* Backspace over record */
674       if (ok && !dev->bsr(1)) {
675          berrno be;
676          ok = false;
677          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
678               be.bstrerror(dev->dev_errno));
679          /*
680           *  On FreeBSD systems, if the user got here, it is likely that his/her
681           *    tape drive is "frozen".  The correct thing to do is a
682           *    rewind(), but if we do that, higher levels in cleaning up, will
683           *    most likely write the EOS record over the beginning of the
684           *    tape.  The rewind *is* done later in mount.c when another
685           *    tape is requested. Note, the clrerror() call in bsr()
686           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
687           */
688       }
689       if (ok) {
690          DEV_BLOCK *lblock = new_block(dev);
691          /* Note, this can destroy dev->errmsg */
692          dcr->block = lblock;
693          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
694             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
695                  dev->errmsg);
696          } else {
697             /*
698              * If we wrote block and the block numbers don't agree
699              *  we have a possible problem.
700              */
701             if (lblock->BlockNumber != dev->LastBlock) {
702                 if (dev->LastBlock > (lblock->BlockNumber + 1)) {
703                    Jmsg(jcr, M_FATAL, 0, _(
704 "Re-read of last block: block numbers differ by more than one.\n"
705 "Probable tape misconfiguration and data loss. Read block=%u Want block=%u.\n"),
706                        lblock->BlockNumber, dev->LastBlock);
707                  } else {
708                    Jmsg(jcr, M_ERROR, 0, _(
709 "Re-read of last block OK, but block numbers differ. Read block=%u Want block=%u.\n"),
710                        lblock->BlockNumber, dev->LastBlock);
711                  }
712             } else {
713                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
714             }
715          }
716          free_block(lblock);
717          dcr->block = block;
718       }
719    }
720 #endif
721 }
722
723 /*
724  * If this routine is called, we do our bookkeeping and
725  *   then assure that the volume will not be written any
726  *   more.
727  */
728 static bool terminate_writing_volume(DCR *dcr)
729 {
730    DEVICE *dev = dcr->dev;
731    bool ok = true;
732
733    /* Create a JobMedia record to indicated end of tape */
734    dev->VolCatInfo.VolCatFiles = dev->file;
735    if (!dir_create_jobmedia_record(dcr)) {
736       Dmsg0(190, "Error from create JobMedia\n");
737       dev->dev_errno = EIO;
738        Jmsg2(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
739             dcr->getVolCatName(), dcr->jcr->Job);
740        ok = false;
741    }
742    dcr->block->write_failed = true;
743    if (!dev->weof(1)) {         /* end the tape */
744       dev->VolCatInfo.VolCatErrors++;
745       Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
746            "%s"), dev->errmsg);
747       ok = false;
748       Dmsg0(100, "WEOF error.\n");
749    }
750    if (ok) {
751       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
752    }
753    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
754    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
755    
756    if (dev->is_dvd()) {
757       if (!dvd_write_part(dcr)) {             /* write last part */
758          dev->VolCatInfo.VolCatErrors++;
759          Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
760                                  "This Volume may not be readable.\n%s"),
761                          dev->errmsg);
762          ok = false;
763          Dmsg0(100, "dvd_write_part error.\n");
764       }
765       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
766    }
767    
768    if (!dir_update_volume_info(dcr, false, true)) {
769       ok = false;
770    }
771    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
772
773    /*
774     * Walk through all attached dcrs setting flag to call
775     * set_new_file_parameters() when that dcr is next used.
776     */
777    DCR *mdcr;
778    foreach_dlist(mdcr, dev->attached_dcrs) {
779       if (mdcr->jcr->JobId == 0) {
780          continue;
781       }
782       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
783    }
784    /* Set new file/block parameters for current dcr */
785    set_new_file_parameters(dcr);
786
787    if (ok && dev->has_cap(CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
788       dev->VolCatInfo.VolCatErrors++;
789       /* This may not be fatal since we already wrote an EOF */
790       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
791    }
792
793    dev->set_ateot();                  /* no more writing this tape */
794    Dmsg1(50, "*** Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
795    return ok;
796 }
797
798 /*
799  * Do bookkeeping when a new file is created on a Volume. This is
800  *  also done for disk files to generate the jobmedia records for
801  *  quick seeking.
802  */
803 static bool do_new_file_bookkeeping(DCR *dcr) 
804 {
805    DEVICE *dev = dcr->dev;
806    JCR *jcr = dcr->jcr;
807
808    /* Create a JobMedia record so restore can seek */
809    if (!dir_create_jobmedia_record(dcr)) {
810       Dmsg0(190, "Error from create_job_media.\n");
811       dev->dev_errno = EIO;
812       Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
813            dcr->getVolCatName(), jcr->Job);
814       terminate_writing_volume(dcr);
815       dev->dev_errno = EIO;
816       return false;
817    }
818    dev->VolCatInfo.VolCatFiles = dev->file;
819    if (!dir_update_volume_info(dcr, false, false)) {
820       Dmsg0(190, "Error from update_vol_info.\n");
821       terminate_writing_volume(dcr);
822       dev->dev_errno = EIO;
823       return false;
824    }
825    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
826
827    /*
828     * Walk through all attached dcrs setting flag to call
829     * set_new_file_parameters() when that dcr is next used.
830     */
831    DCR *mdcr;
832    foreach_dlist(mdcr, dev->attached_dcrs) {
833       if (mdcr->jcr->JobId == 0) {
834          continue;
835       }
836       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
837    }
838    /* Set new file/block parameters for current dcr */
839    set_new_file_parameters(dcr);
840    return true;
841 }
842
843 /*
844  * Do all checks for DVD sizes during writing.
845  */
846 static bool do_dvd_size_checks(DCR *dcr) 
847 {
848    DEVICE *dev = dcr->dev;
849    JCR *jcr = dcr->jcr;
850    DEV_BLOCK *block = dcr->block;
851
852    /* Don't go further if the device is not a dvd */
853    if (!dev->is_dvd()) {
854       return true;
855    }
856    
857    /* Limit maximum part size to value specified by user 
858     */
859    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
860       if (dev->part < dev->num_dvd_parts) {
861          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
862                " is less than the total number of parts (%d/%d, device=%s)\n"),
863                dev->part, dev->num_dvd_parts, dev->print_name());
864          dev->dev_errno = EIO;
865          return false;
866       }
867       
868       if (dvd_open_next_part(dcr) < 0) {
869          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
870                 dev->print_name(), dev->bstrerror());
871          dev->dev_errno = EIO;
872          return false;
873       }
874       
875       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
876             
877       if (!dir_update_volume_info(dcr, false, false)) {
878          Dmsg0(190, "Error from update_vol_info.\n");
879          dev->dev_errno = EIO;
880          return false;
881       }
882    }
883
884    dev->update_freespace();
885    
886    if (!dev->is_freespace_ok()) { /* Error while getting free space */
887       char ed1[50], ed2[50];
888       Dmsg1(100, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
889       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
890          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
891            dev->getVolCatName(),
892            dev->file, dev->block_num, dev->print_name(),
893            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
894            dev->free_space_errno, dev->errmsg);
895       dev->dev_errno = dev->free_space_errno;
896       return false;
897    }
898    
899    if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
900       char ed1[50], ed2[50];
901       Dmsg0(100, "==== Just enough free space on the device to write the current part...\n");
902       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
903          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
904             dev->getVolCatName(),
905             dev->file, dev->block_num, dev->print_name(),
906             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
907             dev->free_space_errno);
908       terminate_writing_volume(dcr);
909       dev->dev_errno = ENOSPC;
910       return false;
911    }   
912    return true;
913 }
914
915
916 /*
917  * Read block with locking
918  *
919  */
920 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
921 {
922    bool ok;
923    DEVICE *dev = dcr->dev;
924    Dmsg0(250, "Enter read_block_from_device\n");
925    dev->r_dlock();
926    ok = read_block_from_dev(dcr, check_block_numbers);
927    dev->dunlock();
928    Dmsg0(250, "Leave read_block_from_device\n");
929    return ok;
930 }
931
932 /*
933  * Read the next block into the block structure and unserialize
934  *  the block header.  For a file, the block may be partially
935  *  or completely in the current buffer.
936  */
937 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
938 {
939    ssize_t stat;
940    int looping;
941    uint32_t BlockNumber;
942    int retry;
943    JCR *jcr = dcr->jcr;
944    DEVICE *dev = dcr->dev;
945    DEV_BLOCK *block = dcr->block;
946
947    if (job_canceled(jcr)) {
948       return false;
949    }
950    
951    if (dev->at_eot()) {
952       return false;
953    }
954    looping = 0;
955    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
956          block->buf_len);
957
958 // ASSERT(dev->is_open());
959
960 reread:
961    if (looping > 1) {
962       dev->dev_errno = EIO;
963       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
964          dev->print_name());
965       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
966       block->read_len = 0;
967       return false;
968    }
969    
970 // #define lots_of_debug
971 #ifdef lots_of_debug
972    if (dev->at_eof() && dev->is_dvd()) {
973       Dmsg1(100, "file_size=%u\n",(unsigned int)dev->file_size);
974       Dmsg1(100, "file_addr=%u\n",(unsigned int)dev->file_addr);
975       Dmsg1(100, "lseek=%u\n",(unsigned int)lseek(dev->fd(), 0, SEEK_CUR));
976       Dmsg1(100, "part_start=%u\n",(unsigned int)dev->part_start);
977       Dmsg1(100, "part_size=%u\n", (unsigned int)dev->part_size);
978       Dmsg2(100, "part=%u num_dvd_parts=%u\n", dev->part, dev->num_dvd_parts);
979       Dmsg1(100, "VolCatInfo.VolCatParts=%u\n", (unsigned int)dev->VolCatInfo.VolCatParts);
980       Dmsg3(100, "Tests : %d %d %d\n", (dev->VolCatInfo.VolCatParts > 0), 
981          ((dev->file_addr-dev->part_start) == dev->part_size), 
982          (dev->part <= dev->VolCatInfo.VolCatParts));
983   }
984 #endif
985
986    /* Check for DVD part file end */
987    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
988         dev->part <= dev->num_dvd_parts) {
989       Dmsg0(400, "Call dvd_open_next_part\n");
990       if (dvd_open_next_part(dcr) < 0) {
991          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
992                dev->part, dev->print_name(), dev->bstrerror());
993          dev->dev_errno = EIO;
994          return false;
995       }
996    }
997    
998    retry = 0;
999    errno = 0;
1000    stat = 0;
1001    do {
1002       if ((retry > 0 && stat == -1 && errno == EBUSY)) {
1003          berrno be;
1004          Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
1005                retry, stat, errno, be.bstrerror());
1006          bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
1007          dev->clrerror(-1);
1008       }
1009       stat = dev->read(block->buf, (size_t)block->buf_len);
1010
1011    } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
1012    if (stat < 0) {
1013       berrno be;
1014       dev->clrerror(-1);
1015       Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
1016       block->read_len = 0;
1017       Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
1018          dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
1019       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1020       if (dev->at_eof()) {        /* EOF just seen? */
1021          dev->set_eot();          /* yes, error => EOT */
1022       }
1023       return false;
1024    }
1025    Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
1026       dev->file, dev->block_num);
1027    if (stat == 0) {             /* Got EOF ! */
1028       dev->block_num = 0;
1029       block->read_len = 0;
1030       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1031          dev->file, dev->block_num, dev->print_name());
1032       if (dev->at_eof()) {       /* EOF already read? */
1033          dev->set_eot();         /* yes, 2 EOFs => EOT */
1034          return 0;
1035       }
1036       dev->set_ateof();
1037       return false;             /* return eof */
1038    }
1039
1040    /* Continue here for successful read */
1041
1042    block->read_len = stat;      /* save length read */
1043    if (block->read_len == 80 && 
1044         (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
1045          dcr->device->label_type != B_BACULA_LABEL)) {
1046       /* ***FIXME*** should check label */
1047       Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
1048       dev->clear_eof();
1049       goto reread;             /* skip ANSI/IBM label */
1050    }
1051                                           
1052    if (block->read_len < BLKHDR2_LENGTH) {
1053       dev->dev_errno = EIO;
1054       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1055          dev->file, dev->block_num, block->read_len, dev->print_name());
1056       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1057       dev->set_short_block();   
1058       block->read_len = block->binbuf = 0;
1059       return false;             /* return error */
1060    }
1061
1062    BlockNumber = block->BlockNumber + 1;
1063    if (!unser_block_header(jcr, dev, block)) {
1064       if (forge_on) {
1065          dev->file_addr += block->read_len;
1066          dev->file_size += block->read_len;
1067          goto reread;
1068       }
1069       return false;
1070    }
1071
1072    /*
1073     * If the block is bigger than the buffer, we reposition for
1074     *  re-reading the block, allocate a buffer of the correct size,
1075     *  and go re-read.
1076     */
1077    if (block->block_len > block->buf_len) {
1078       dev->dev_errno = EIO;
1079       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1080          block->block_len, block->buf_len);
1081       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1082       Pmsg1(000, "%s", dev->errmsg);
1083       /* Attempt to reposition to re-read the block */
1084       if (dev->is_tape()) {
1085          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1086          if (!dev->bsr(1)) {
1087             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1088             block->read_len = 0;
1089             return false;
1090          }
1091       } else {
1092          Dmsg0(250, "Seek to beginning of block for reread.\n");
1093          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1094          pos -= block->read_len;
1095          dev->lseek(dcr, pos, SEEK_SET);
1096          dev->file_addr = pos;
1097       }
1098       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1099       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1100       Pmsg1(000, "%s", dev->errmsg);
1101       /* Set new block length */
1102       dev->max_block_size = block->block_len;
1103       block->buf_len = block->block_len;
1104       free_memory(block->buf);
1105       block->buf = get_memory(block->buf_len);
1106       empty_block(block);
1107       looping++;
1108       goto reread;                    /* re-read block with correct block size */
1109    }
1110
1111    if (block->block_len > block->read_len) {
1112       dev->dev_errno = EIO;
1113       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1114          dev->file, dev->block_num, block->read_len, dev->print_name());
1115       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1116       dev->set_short_block();
1117       block->read_len = block->binbuf = 0;
1118       return false;             /* return error */
1119    }
1120
1121    dev->clear_short_block();
1122    dev->clear_eof();
1123    dev->VolCatInfo.VolCatReads++;
1124    dev->VolCatInfo.VolCatRBytes += block->read_len;
1125
1126    dev->EndBlock = dev->block_num;
1127    dev->EndFile  = dev->file;
1128    dev->block_num++;
1129
1130    /* Update dcr values */
1131    if (dev->is_tape()) {
1132       dcr->EndBlock = dev->EndBlock;
1133       dcr->EndFile  = dev->EndFile;
1134    } else {
1135       /* We need to take care about a short block in EndBlock/File
1136        * computation 
1137        */
1138       uint32_t len = MIN(block->read_len, block->block_len);
1139       uint64_t addr = dev->file_addr + len - 1;
1140       dcr->EndBlock = (uint32_t)addr;
1141       dcr->EndFile = (uint32_t)(addr >> 32);
1142       dev->block_num = dev->EndBlock = dcr->EndBlock;
1143       dev->file = dev->EndFile = dcr->EndFile;
1144    }
1145    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
1146    dev->file_addr += block->read_len;
1147    dev->file_size += block->read_len;
1148
1149    /*
1150     * If we read a short block on disk,
1151     * seek to beginning of next block. This saves us
1152     * from shuffling blocks around in the buffer. Take a
1153     * look at this from an efficiency stand point later, but
1154     * it should only happen once at the end of each job.
1155     *
1156     * I've been lseek()ing negative relative to SEEK_CUR for 30
1157     *   years now. However, it seems that with the new off_t definition,
1158     *   it is not possible to seek negative amounts, so we use two
1159     *   lseek(). One to get the position, then the second to do an
1160     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1161     */
1162    Dmsg0(250, "At end of read block\n");
1163    if (block->read_len > block->block_len && !dev->is_tape()) {
1164       char ed1[50];
1165       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1166       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1167       pos -= (block->read_len - block->block_len);
1168       dev->lseek(dcr, pos, SEEK_SET);
1169       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1170          edit_int64(pos, ed1), block->block_len,
1171             block->read_len);
1172       dev->file_addr = pos;
1173       dev->file_size = pos;
1174    }
1175    Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1176       block->read_len, block->block_len);
1177    block->block_read = true;
1178    return true;
1179 }