]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/stored/block.c
Switch from GPLv2 to AGPLv3
[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 three of the GNU Affero 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 Affero 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           if (jcr->getJobType() != JT_SYSTEM) {
385              terminate_writing_volume(dcr);
386           }
387           stat = false;
388        } else {
389           stat = fixup_device_block_write_error(dcr);
390        }
391    }
392
393 bail_out:
394    if (!dcr->is_dev_locked()) {        /* did we lock dev above? */
395       /* note, do not change this to dcr->dunlock */
396       dev->dunlock();                  /* unlock it now */
397    }
398    return stat;
399 }
400
401 /*
402  * Write a block to the device
403  *
404  *  Returns: true  on success or EOT
405  *           false on hard error
406  */
407 bool write_block_to_dev(DCR *dcr)
408 {
409    ssize_t stat = 0;
410    uint32_t wlen;                     /* length to write */
411    int hit_max1, hit_max2;
412    bool ok = true;
413    DEVICE *dev = dcr->dev;
414    JCR *jcr = dcr->jcr;
415    DEV_BLOCK *block = dcr->block;
416
417 #ifdef NO_TAPE_WRITE_TEST
418    empty_block(block);
419    return true;
420 #endif
421    if (job_canceled(jcr)) {
422       terminate_writing_volume(dcr);
423       return false;
424    }
425
426    ASSERT(block->binbuf == ((uint32_t) (block->bufp - block->buf)));
427
428    wlen = block->binbuf;
429    if (wlen <= WRITE_BLKHDR_LENGTH) {  /* Does block have data in it? */
430       Dmsg0(100, "return write_block_to_dev no data to write\n");
431       return true;
432    }
433
434    /* dump_block(block, "before write"); */
435    if (dev->at_weot()) {
436       Dmsg0(100, "return write_block_to_dev with ST_WEOT\n");
437       dev->dev_errno = ENOSPC;
438       Jmsg1(jcr, M_FATAL, 0,  _("Cannot write block. Device at EOM. dev=%s\n"), dev->print_name());
439       return false;
440    }
441    if (!dev->can_append()) {
442       dev->dev_errno = EIO;
443       Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on read-only Volume. dev=%s\n"), dev->print_name());
444       return false;
445    }
446
447    if (!dev->is_open()) {
448       Jmsg1(jcr, M_FATAL, 0, _("Attempt to write on closed device=%s\n"), dev->print_name());
449       return false;
450    }
451    /*
452     * Clear to the end of the buffer if it is not full,
453     *  and on tape devices, apply min and fixed blocking.
454     */
455    if (wlen != block->buf_len) {
456       uint32_t blen;                  /* current buffer length */
457
458       Dmsg2(250, "binbuf=%d buf_len=%d\n", block->binbuf, block->buf_len);
459       blen = wlen;
460
461       /* Adjust write size to min/max for tapes only */
462       if (dev->is_tape()) {
463          /* check for fixed block size */
464          if (dev->min_block_size == dev->max_block_size) {
465             wlen = block->buf_len;    /* fixed block size already rounded */
466          /* Check for min block size */
467          } else if (wlen < dev->min_block_size) {
468             wlen =  ((dev->min_block_size + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
469          /* Ensure size is rounded */
470          } else {
471             wlen = ((wlen + TAPE_BSIZE - 1) / TAPE_BSIZE) * TAPE_BSIZE;
472          }
473       }
474       if (wlen-blen > 0) {
475          memset(block->bufp, 0, wlen-blen); /* clear garbage */
476       }
477    }
478
479    ser_block_header(block, dev->do_checksum());
480
481    /* Limit maximum Volume size to value specified by user */
482    hit_max1 = (dev->max_volume_size > 0) &&
483        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->max_volume_size;
484    hit_max2 = (dev->VolCatInfo.VolCatMaxBytes > 0) &&
485        ((dev->VolCatInfo.VolCatBytes + block->binbuf)) >= dev->VolCatInfo.VolCatMaxBytes;
486    if (hit_max1 || hit_max2) {
487       char ed1[50];
488       uint64_t max_cap;
489       Dmsg0(100, "==== Output bytes Triggered medium max capacity.\n");
490       if (hit_max1) {
491          max_cap = dev->max_volume_size;
492       } else {
493          max_cap = dev->VolCatInfo.VolCatMaxBytes;
494       }
495       Jmsg(jcr, M_INFO, 0, _("User defined maximum volume capacity %s exceeded on device %s.\n"),
496             edit_uint64_with_commas(max_cap, ed1),  dev->print_name());
497       terminate_writing_volume(dcr);
498       reread_last_block(dcr);   /* DEBUG */
499       dev->dev_errno = ENOSPC;
500       return false;
501    }
502
503    /* Limit maximum File size on volume to user specified value */
504    if ((dev->max_file_size > 0) &&
505        (dev->file_size+block->binbuf) >= dev->max_file_size) {
506       dev->file_size = 0;             /* reset file size */
507
508       if (!dev->weof(1)) {            /* write eof */
509          Dmsg0(190, "WEOF error in max file size.\n");
510          Jmsg(jcr, M_FATAL, 0, _("Unable to write EOF. ERR=%s\n"), 
511             dev->bstrerror());
512          terminate_writing_volume(dcr);
513          dev->dev_errno = ENOSPC;
514          return false;
515       }
516       if (!write_ansi_ibm_labels(dcr, ANSI_EOF_LABEL, dev->VolHdr.VolumeName)) {
517          return false;
518       }
519
520       if (!do_new_file_bookkeeping(dcr)) {
521          /* Error message already sent */
522          return false;
523       }
524    }
525    
526    if (!do_dvd_size_checks(dcr)) {
527       /* Error message already sent */
528       return false;
529    }
530
531    dev->VolCatInfo.VolCatWrites++;
532    Dmsg1(1300, "Write block of %u bytes\n", wlen);
533 #ifdef DEBUG_BLOCK_ZEROING
534    uint32_t *bp = (uint32_t *)block->buf;
535    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
536       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
537    }
538 #endif
539
540    /*
541     * Do write here, make a somewhat feeble attempt to recover from 
542     *  I/O errors, or from the OS telling us it is busy.
543     */ 
544    int retry = 0;
545    errno = 0;
546    stat = 0;
547    do {
548       if (retry > 0 && stat == -1 && errno == EBUSY) {
549          berrno be;
550          Dmsg4(100, "===== write retry=%d stat=%d errno=%d: ERR=%s\n",
551                retry, stat, errno, be.bstrerror());
552          bmicrosleep(5, 0);    /* pause a bit if busy or lots of errors */
553          dev->clrerror(-1);
554       }
555       stat = dev->write(block->buf, (size_t)wlen);
556
557    } while (stat == -1 && (errno == EBUSY || errno == EIO) && retry++ < 3);
558
559 #ifdef DEBUG_BLOCK_ZEROING
560    if (bp[0] == 0 && bp[1] == 0 && bp[2] == 0 && block->buf[12] == 0) {
561       Jmsg0(jcr, M_ABORT, 0, _("Write block header zeroed.\n"));
562    }
563 #endif
564
565    if (stat != (ssize_t)wlen) {
566       /* Some devices simply report EIO when the volume is full.
567        * With a little more thought we may be able to check
568        * capacity and distinguish real errors and EOT
569        * conditions.  In any case, we probably want to
570        * simulate an End of Medium.
571        */
572       if (stat == -1) {
573          berrno be;
574          dev->clrerror(-1);
575          if (dev->dev_errno == 0) {
576             dev->dev_errno = ENOSPC;        /* out of space */
577          }
578          if (dev->dev_errno != ENOSPC) {
579             dev->VolCatInfo.VolCatErrors++;
580             Jmsg4(jcr, M_ERROR, 0, _("Write error at %u:%u on device %s. ERR=%s.\n"),
581                dev->file, dev->block_num, dev->print_name(), be.bstrerror());
582          }
583       } else {
584         dev->dev_errno = ENOSPC;            /* out of space */
585       }
586       if (dev->dev_errno == ENOSPC) {
587          Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s. Write of %u bytes got %d.\n"),
588             dev->getVolCatName(),
589             dev->file, dev->block_num, dev->print_name(), wlen, stat);
590       }
591       if (debug_level >= 100) {
592          berrno be;
593          Dmsg7(100, "=== Write error. fd=%d size=%u rtn=%d dev_blk=%d blk_blk=%d errno=%d: ERR=%s\n",
594             dev->fd(), wlen, stat, dev->block_num, block->BlockNumber, 
595             dev->dev_errno, be.bstrerror(dev->dev_errno));
596       }
597
598       ok = terminate_writing_volume(dcr);
599       if (!ok && !forge_on) {
600          return false;
601       }
602       if (ok) {
603          reread_last_block(dcr);
604       }
605       return false;
606    }
607
608    /* We successfully wrote the block, now do housekeeping */
609    Dmsg2(1300, "VolCatBytes=%d newVolCatBytes=%d\n", (int)dev->VolCatInfo.VolCatBytes,
610       (int)(dev->VolCatInfo.VolCatBytes+wlen));
611    dev->VolCatInfo.VolCatBytes += wlen;         
612    dev->VolCatInfo.VolCatBlocks++;
613    dev->EndBlock = dev->block_num;
614    dev->EndFile  = dev->file;
615    dev->LastBlock = block->BlockNumber;
616    block->BlockNumber++;
617
618    /* Update dcr values */
619    if (dev->is_tape()) {
620       dcr->EndBlock = dev->EndBlock;
621       dcr->EndFile  = dev->EndFile;
622       dev->block_num++;
623    } else {
624       /* Save address of block just written */
625       uint64_t addr = dev->file_addr + wlen - 1;
626       dcr->EndBlock = (uint32_t)addr;
627       dcr->EndFile = (uint32_t)(addr >> 32);
628       dev->block_num = dcr->EndBlock;
629       dev->file = dcr->EndFile;
630    }
631    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
632    if (dcr->VolFirstIndex == 0 && block->FirstIndex > 0) {
633       dcr->VolFirstIndex = block->FirstIndex;
634    }
635    if (block->LastIndex > 0) {
636       dcr->VolLastIndex = block->LastIndex;
637    }
638    dcr->WroteVol = true;
639    dev->file_addr += wlen;            /* update file address */
640    dev->file_size += wlen;
641    dev->part_size += wlen;
642
643    Dmsg2(1300, "write_block: wrote block %d bytes=%d\n", dev->block_num, wlen);
644    empty_block(block);
645    return true;
646 }
647
648 static void reread_last_block(DCR *dcr)
649 {
650 #define CHECK_LAST_BLOCK
651 #ifdef  CHECK_LAST_BLOCK
652    bool ok = true;
653    DEVICE *dev = dcr->dev;
654    JCR *jcr = dcr->jcr;
655    DEV_BLOCK *block = dcr->block;
656    /*
657     * If the device is a tape and it supports backspace record,
658     *   we backspace over one or two eof marks depending on
659     *   how many we just wrote, then over the last record,
660     *   then re-read it and verify that the block number is
661     *   correct.
662     */
663    if (dev->is_tape() && dev->has_cap(CAP_BSR)) {
664       /* Now back up over what we wrote and read the last block */
665       if (!dev->bsf(1)) {
666          berrno be;
667          ok = false;
668          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
669               be.bstrerror(dev->dev_errno));
670       }
671       if (ok && dev->has_cap(CAP_TWOEOF) && !dev->bsf(1)) {
672          berrno be;
673          ok = false;
674          Jmsg(jcr, M_ERROR, 0, _("Backspace file at EOT failed. ERR=%s\n"), 
675               be.bstrerror(dev->dev_errno));
676       }
677       /* Backspace over record */
678       if (ok && !dev->bsr(1)) {
679          berrno be;
680          ok = false;
681          Jmsg(jcr, M_ERROR, 0, _("Backspace record at EOT failed. ERR=%s\n"), 
682               be.bstrerror(dev->dev_errno));
683          /*
684           *  On FreeBSD systems, if the user got here, it is likely that his/her
685           *    tape drive is "frozen".  The correct thing to do is a
686           *    rewind(), but if we do that, higher levels in cleaning up, will
687           *    most likely write the EOS record over the beginning of the
688           *    tape.  The rewind *is* done later in mount.c when another
689           *    tape is requested. Note, the clrerror() call in bsr()
690           *    calls ioctl(MTCERRSTAT), which *should* fix the problem.
691           */
692       }
693       if (ok) {
694          DEV_BLOCK *lblock = new_block(dev);
695          /* Note, this can destroy dev->errmsg */
696          dcr->block = lblock;
697          if (!read_block_from_dev(dcr, NO_BLOCK_NUMBER_CHECK)) {
698             Jmsg(jcr, M_ERROR, 0, _("Re-read last block at EOT failed. ERR=%s"), 
699                  dev->errmsg);
700          } else {
701             /*
702              * If we wrote block and the block numbers don't agree
703              *  we have a possible problem.
704              */
705             if (lblock->BlockNumber != dev->LastBlock) {
706                 if (dev->LastBlock > (lblock->BlockNumber + 1)) {
707                    Jmsg(jcr, M_FATAL, 0, _(
708 "Re-read of last block: block numbers differ by more than one.\n"
709 "Probable tape misconfiguration and data loss. Read block=%u Want block=%u.\n"),
710                        lblock->BlockNumber, dev->LastBlock);
711                  } else {
712                    Jmsg(jcr, M_ERROR, 0, _(
713 "Re-read of last block OK, but block numbers differ. Read block=%u Want block=%u.\n"),
714                        lblock->BlockNumber, dev->LastBlock);
715                  }
716             } else {
717                Jmsg(jcr, M_INFO, 0, _("Re-read of last block succeeded.\n"));
718             }
719          }
720          free_block(lblock);
721          dcr->block = block;
722       }
723    }
724 #endif
725 }
726
727 /*
728  * If this routine is called, we do our bookkeeping and
729  *   then assure that the volume will not be written any
730  *   more.
731  */
732 static bool terminate_writing_volume(DCR *dcr)
733 {
734    DEVICE *dev = dcr->dev;
735    bool ok = true;
736
737    if (dev->at_eot()) {
738       return true;
739   }
740
741    /* Create a JobMedia record to indicated end of tape */
742    dev->VolCatInfo.VolCatFiles = dev->file;
743    if (!dir_create_jobmedia_record(dcr)) {
744       Dmsg0(190, "Error from create JobMedia\n");
745       dev->dev_errno = EIO;
746        Jmsg2(dcr->jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
747             dcr->getVolCatName(), dcr->jcr->Job);
748        ok = false;
749    }
750    dcr->block->write_failed = true;
751    if (!dev->weof(1)) {         /* end the tape */
752       dev->VolCatInfo.VolCatErrors++;
753       Jmsg(dcr->jcr, M_ERROR, 0, _("Error writing final EOF to tape. This Volume may not be readable.\n"
754            "%s"), dev->errmsg);
755       ok = false;
756       Dmsg0(100, "WEOF error.\n");
757    }
758    if (ok) {
759       ok = write_ansi_ibm_labels(dcr, ANSI_EOV_LABEL, dev->VolHdr.VolumeName);
760    }
761    bstrncpy(dev->VolCatInfo.VolCatStatus, "Full", sizeof(dev->VolCatInfo.VolCatStatus));
762    dev->VolCatInfo.VolCatFiles = dev->file;   /* set number of files */
763    
764    if (dev->is_dvd()) {
765       if (!dvd_write_part(dcr)) {             /* write last part */
766          dev->VolCatInfo.VolCatErrors++;
767          Jmsg(dcr->jcr, M_FATAL, 0, _("Error writing final part to DVD. "
768                                  "This Volume may not be readable.\n%s"),
769                          dev->errmsg);
770          ok = false;
771          Dmsg0(100, "dvd_write_part error.\n");
772       }
773       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
774    }
775    
776    if (!dir_update_volume_info(dcr, false, true)) {
777       ok = false;
778    }
779    Dmsg1(100, "dir_update_volume_info terminate writing -- %s\n", ok?"OK":"ERROR");
780
781    /*
782     * Walk through all attached dcrs setting flag to call
783     * set_new_file_parameters() when that dcr is next used.
784     */
785    DCR *mdcr;
786    foreach_dlist(mdcr, dev->attached_dcrs) {
787       if (mdcr->jcr->JobId == 0) {
788          continue;
789       }
790       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
791    }
792    /* Set new file/block parameters for current dcr */
793    set_new_file_parameters(dcr);
794
795    if (ok && dev->has_cap(CAP_TWOEOF) && !dev->weof(1)) {  /* end the tape */
796       dev->VolCatInfo.VolCatErrors++;
797       /* This may not be fatal since we already wrote an EOF */
798       Jmsg(dcr->jcr, M_ERROR, 0, "%s", dev->errmsg);
799    }
800
801    dev->set_ateot();                  /* no more writing this tape */
802    Dmsg1(50, "*** Leave terminate_writing_volume -- %s\n", ok?"OK":"ERROR");
803    return ok;
804 }
805
806 /*
807  * Do bookkeeping when a new file is created on a Volume. This is
808  *  also done for disk files to generate the jobmedia records for
809  *  quick seeking.
810  */
811 static bool do_new_file_bookkeeping(DCR *dcr) 
812 {
813    DEVICE *dev = dcr->dev;
814    JCR *jcr = dcr->jcr;
815
816    /* Create a JobMedia record so restore can seek */
817    if (!dir_create_jobmedia_record(dcr)) {
818       Dmsg0(190, "Error from create_job_media.\n");
819       dev->dev_errno = EIO;
820       Jmsg2(jcr, M_FATAL, 0, _("Could not create JobMedia record for Volume=\"%s\" Job=%s\n"),
821            dcr->getVolCatName(), jcr->Job);
822       terminate_writing_volume(dcr);
823       dev->dev_errno = EIO;
824       return false;
825    }
826    dev->VolCatInfo.VolCatFiles = dev->file;
827    if (!dir_update_volume_info(dcr, false, false)) {
828       Dmsg0(190, "Error from update_vol_info.\n");
829       terminate_writing_volume(dcr);
830       dev->dev_errno = EIO;
831       return false;
832    }
833    Dmsg0(100, "dir_update_volume_info max file size -- OK\n");
834
835    /*
836     * Walk through all attached dcrs setting flag to call
837     * set_new_file_parameters() when that dcr is next used.
838     */
839    DCR *mdcr;
840    foreach_dlist(mdcr, dev->attached_dcrs) {
841       if (mdcr->jcr->JobId == 0) {
842          continue;
843       }
844       mdcr->NewFile = true;        /* set reminder to do set_new_file_params */
845    }
846    /* Set new file/block parameters for current dcr */
847    set_new_file_parameters(dcr);
848    return true;
849 }
850
851 /*
852  * Do all checks for DVD sizes during writing.
853  */
854 static bool do_dvd_size_checks(DCR *dcr) 
855 {
856    DEVICE *dev = dcr->dev;
857    JCR *jcr = dcr->jcr;
858    DEV_BLOCK *block = dcr->block;
859
860    /* Don't go further if the device is not a dvd */
861    if (!dev->is_dvd()) {
862       return true;
863    }
864    
865    /* Limit maximum part size to value specified by user 
866     */
867    if (dev->max_part_size > 0 && ((dev->part_size + block->binbuf) >= dev->max_part_size)) {
868       if (dev->part < dev->num_dvd_parts) {
869          Jmsg3(dcr->jcr, M_FATAL, 0, _("Error while writing, current part number"
870                " is less than the total number of parts (%d/%d, device=%s)\n"),
871                dev->part, dev->num_dvd_parts, dev->print_name());
872          dev->dev_errno = EIO;
873          return false;
874       }
875       
876       if (dvd_open_next_part(dcr) < 0) {
877          Jmsg2(dcr->jcr, M_FATAL, 0, _("Unable to open device next part %s: ERR=%s\n"),
878                 dev->print_name(), dev->bstrerror());
879          dev->dev_errno = EIO;
880          return false;
881       }
882       
883       dev->VolCatInfo.VolCatParts = dev->num_dvd_parts;
884             
885       if (!dir_update_volume_info(dcr, false, false)) {
886          Dmsg0(190, "Error from update_vol_info.\n");
887          dev->dev_errno = EIO;
888          return false;
889       }
890    }
891
892    dev->update_freespace();
893    
894    if (!dev->is_freespace_ok()) { /* Error while getting free space */
895       char ed1[50], ed2[50];
896       Dmsg1(100, "Cannot get free space on the device ERR=%s.\n", dev->errmsg);
897       Jmsg(jcr, M_FATAL, 0, _("End of Volume \"%s\" at %u:%u on device %s "
898          "(part_size=%s, free_space=%s, free_space_errno=%d, errmsg=%s).\n"),
899            dev->getVolCatName(),
900            dev->file, dev->block_num, dev->print_name(),
901            edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
902            dev->free_space_errno, dev->errmsg);
903       dev->dev_errno = dev->free_space_errno;
904       return false;
905    }
906    
907    if ((dev->is_freespace_ok() && (dev->part_size + block->binbuf) >= dev->free_space)) {
908       char ed1[50], ed2[50];
909       Dmsg0(100, "==== Just enough free space on the device to write the current part...\n");
910       Jmsg(jcr, M_INFO, 0, _("End of Volume \"%s\" at %u:%u on device %s "
911          "(part_size=%s, free_space=%s, free_space_errno=%d).\n"),
912             dev->getVolCatName(),
913             dev->file, dev->block_num, dev->print_name(),
914             edit_uint64_with_commas(dev->part_size, ed1), edit_uint64_with_commas(dev->free_space, ed2),
915             dev->free_space_errno);
916       terminate_writing_volume(dcr);
917       dev->dev_errno = ENOSPC;
918       return false;
919    }   
920    return true;
921 }
922
923
924 /*
925  * Read block with locking
926  *
927  */
928 bool read_block_from_device(DCR *dcr, bool check_block_numbers)
929 {
930    bool ok;
931    DEVICE *dev = dcr->dev;
932    Dmsg0(250, "Enter read_block_from_device\n");
933    dev->r_dlock();
934    ok = read_block_from_dev(dcr, check_block_numbers);
935    dev->dunlock();
936    Dmsg0(250, "Leave read_block_from_device\n");
937    return ok;
938 }
939
940 /*
941  * Read the next block into the block structure and unserialize
942  *  the block header.  For a file, the block may be partially
943  *  or completely in the current buffer.
944  */
945 bool read_block_from_dev(DCR *dcr, bool check_block_numbers)
946 {
947    ssize_t stat;
948    int looping;
949    uint32_t BlockNumber;
950    int retry;
951    JCR *jcr = dcr->jcr;
952    DEVICE *dev = dcr->dev;
953    DEV_BLOCK *block = dcr->block;
954
955    if (job_canceled(jcr)) {
956       return false;
957    }
958    
959    if (dev->at_eot()) {
960       return false;
961    }
962    looping = 0;
963    Dmsg1(250, "Full read in read_block_from_device() len=%d\n",
964          block->buf_len);
965
966 // ASSERT(dev->is_open());
967
968 reread:
969    if (looping > 1) {
970       dev->dev_errno = EIO;
971       Mmsg1(dev->errmsg, _("Block buffer size looping problem on device %s\n"),
972          dev->print_name());
973       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
974       block->read_len = 0;
975       return false;
976    }
977    
978    /* Check for DVD part file end */
979    if (dev->at_eof() && dev->is_dvd() && dev->num_dvd_parts > 0 &&
980         dev->part <= dev->num_dvd_parts) {
981       Dmsg0(400, "Call dvd_open_next_part\n");
982       if (dvd_open_next_part(dcr) < 0) {
983          Jmsg3(dcr->jcr, M_FATAL, 0, _("Unable to open device part=%d %s: ERR=%s\n"),
984                dev->part, dev->print_name(), dev->bstrerror());
985          dev->dev_errno = EIO;
986          return false;
987       }
988    }
989    
990    retry = 0;
991    errno = 0;
992    stat = 0;
993    do {
994       if ((retry > 0 && stat == -1 && errno == EBUSY)) {
995          berrno be;
996          Dmsg4(100, "===== read retry=%d stat=%d errno=%d: ERR=%s\n",
997                retry, stat, errno, be.bstrerror());
998          bmicrosleep(10, 0);    /* pause a bit if busy or lots of errors */
999          dev->clrerror(-1);
1000       }
1001       stat = dev->read(block->buf, (size_t)block->buf_len);
1002
1003    } while (stat == -1 && (errno == EBUSY || errno == EINTR || errno == EIO) && retry++ < 3);
1004    if (stat < 0) {
1005       berrno be;
1006       dev->clrerror(-1);
1007       Dmsg1(250, "Read device got: ERR=%s\n", be.bstrerror());
1008       block->read_len = 0;
1009       Mmsg5(dev->errmsg, _("Read error on fd=%d at file:blk %u:%u on device %s. ERR=%s.\n"),
1010          dev->fd(), dev->file, dev->block_num, dev->print_name(), be.bstrerror());
1011       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1012       if (dev->at_eof()) {        /* EOF just seen? */
1013          dev->set_eot();          /* yes, error => EOT */
1014       }
1015       return false;
1016    }
1017    Dmsg3(250, "Read device got %d bytes at %u:%u\n", stat,
1018       dev->file, dev->block_num);
1019    if (stat == 0) {             /* Got EOF ! */
1020       dev->block_num = 0;
1021       block->read_len = 0;
1022       Mmsg3(dev->errmsg, _("Read zero bytes at %u:%u on device %s.\n"),
1023          dev->file, dev->block_num, dev->print_name());
1024       if (dev->at_eof()) {       /* EOF already read? */
1025          dev->set_eot();         /* yes, 2 EOFs => EOT */
1026          return 0;
1027       }
1028       dev->set_ateof();
1029       return false;             /* return eof */
1030    }
1031
1032    /* Continue here for successful read */
1033
1034    block->read_len = stat;      /* save length read */
1035    if (block->read_len == 80 && 
1036         (dcr->VolCatInfo.LabelType != B_BACULA_LABEL ||
1037          dcr->device->label_type != B_BACULA_LABEL)) {
1038       /* ***FIXME*** should check label */
1039       Dmsg2(100, "Ignore 80 byte ANSI label at %u:%u\n", dev->file, dev->block_num);
1040       dev->clear_eof();
1041       goto reread;             /* skip ANSI/IBM label */
1042    }
1043                                           
1044    if (block->read_len < BLKHDR2_LENGTH) {
1045       dev->dev_errno = EIO;
1046       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Very short block of %d bytes on device %s discarded.\n"),
1047          dev->file, dev->block_num, block->read_len, dev->print_name());
1048       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1049       dev->set_short_block();   
1050       block->read_len = block->binbuf = 0;
1051       return false;             /* return error */
1052    }
1053
1054    BlockNumber = block->BlockNumber + 1;
1055    if (!unser_block_header(jcr, dev, block)) {
1056       if (forge_on) {
1057          dev->file_addr += block->read_len;
1058          dev->file_size += block->read_len;
1059          goto reread;
1060       }
1061       return false;
1062    }
1063
1064    /*
1065     * If the block is bigger than the buffer, we reposition for
1066     *  re-reading the block, allocate a buffer of the correct size,
1067     *  and go re-read.
1068     */
1069    if (block->block_len > block->buf_len) {
1070       dev->dev_errno = EIO;
1071       Mmsg2(dev->errmsg,  _("Block length %u is greater than buffer %u. Attempting recovery.\n"),
1072          block->block_len, block->buf_len);
1073       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1074       Pmsg1(000, "%s", dev->errmsg);
1075       /* Attempt to reposition to re-read the block */
1076       if (dev->is_tape()) {
1077          Dmsg0(250, "BSR for reread; block too big for buffer.\n");
1078          if (!dev->bsr(1)) {
1079             Jmsg(jcr, M_ERROR, 0, "%s", dev->bstrerror());
1080             block->read_len = 0;
1081             return false;
1082          }
1083       } else {
1084          Dmsg0(250, "Seek to beginning of block for reread.\n");
1085          boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1086          pos -= block->read_len;
1087          dev->lseek(dcr, pos, SEEK_SET);
1088          dev->file_addr = pos;
1089       }
1090       Mmsg1(dev->errmsg, _("Setting block buffer size to %u bytes.\n"), block->block_len);
1091       Jmsg(jcr, M_INFO, 0, "%s", dev->errmsg);
1092       Pmsg1(000, "%s", dev->errmsg);
1093       /* Set new block length */
1094       dev->max_block_size = block->block_len;
1095       block->buf_len = block->block_len;
1096       free_memory(block->buf);
1097       block->buf = get_memory(block->buf_len);
1098       empty_block(block);
1099       looping++;
1100       goto reread;                    /* re-read block with correct block size */
1101    }
1102
1103    if (block->block_len > block->read_len) {
1104       dev->dev_errno = EIO;
1105       Mmsg4(dev->errmsg, _("Volume data error at %u:%u! Short block of %d bytes on device %s discarded.\n"),
1106          dev->file, dev->block_num, block->read_len, dev->print_name());
1107       Jmsg(jcr, M_ERROR, 0, "%s", dev->errmsg);
1108       dev->set_short_block();
1109       block->read_len = block->binbuf = 0;
1110       return false;             /* return error */
1111    }
1112
1113    dev->clear_short_block();
1114    dev->clear_eof();
1115    dev->VolCatInfo.VolCatReads++;
1116    dev->VolCatInfo.VolCatRBytes += block->read_len;
1117
1118    dev->EndBlock = dev->block_num;
1119    dev->EndFile  = dev->file;
1120    dev->block_num++;
1121
1122    /* Update dcr values */
1123    if (dev->is_tape()) {
1124       dcr->EndBlock = dev->EndBlock;
1125       dcr->EndFile  = dev->EndFile;
1126    } else {
1127       /* We need to take care about a short block in EndBlock/File
1128        * computation 
1129        */
1130       uint32_t len = MIN(block->read_len, block->block_len);
1131       uint64_t addr = dev->file_addr + len - 1;
1132       dcr->EndBlock = (uint32_t)addr;
1133       dcr->EndFile = (uint32_t)(addr >> 32);
1134       dev->block_num = dev->EndBlock = dcr->EndBlock;
1135       dev->file = dev->EndFile = dcr->EndFile;
1136    }
1137    dcr->VolMediaId = dev->VolCatInfo.VolMediaId;
1138    dev->file_addr += block->read_len;
1139    dev->file_size += block->read_len;
1140
1141    /*
1142     * If we read a short block on disk,
1143     * seek to beginning of next block. This saves us
1144     * from shuffling blocks around in the buffer. Take a
1145     * look at this from an efficiency stand point later, but
1146     * it should only happen once at the end of each job.
1147     *
1148     * I've been lseek()ing negative relative to SEEK_CUR for 30
1149     *   years now. However, it seems that with the new off_t definition,
1150     *   it is not possible to seek negative amounts, so we use two
1151     *   lseek(). One to get the position, then the second to do an
1152     *   absolute positioning -- so much for efficiency.  KES Sep 02.
1153     */
1154    Dmsg0(250, "At end of read block\n");
1155    if (block->read_len > block->block_len && !dev->is_tape()) {
1156       char ed1[50];
1157       boffset_t pos = dev->lseek(dcr, (boffset_t)0, SEEK_CUR); /* get curr pos */
1158       Dmsg1(250, "Current lseek pos=%s\n", edit_int64(pos, ed1));
1159       pos -= (block->read_len - block->block_len);
1160       dev->lseek(dcr, pos, SEEK_SET);
1161       Dmsg3(250, "Did lseek pos=%s blk_size=%d rdlen=%d\n", 
1162          edit_int64(pos, ed1), block->block_len,
1163             block->read_len);
1164       dev->file_addr = pos;
1165       dev->file_size = pos;
1166    }
1167    Dmsg2(250, "Exit read_block read_len=%d block_len=%d\n",
1168       block->read_len, block->block_len);
1169    block->block_read = true;
1170    return true;
1171 }