Date: Wed, 20 Aug 2003 09:24:24 -0700 (PDT) From: Nate Lawson <nate@root.org> To: freebsd-threads@freebsd.org, freebsd-stable@freebsd.org Subject: (Fwd) Lost data on FreeBSD tape (fwd) Message-ID: <20030820092347.G20029@root.org>
next in thread | raw e-mail | index | archive | help
This message is in MIME format. The first part should be readable text, while the remaining parts are likely unreadable without MIME-aware tools. Send mail to mime@docserver.cac.washington.edu for more info. --Message-Boundary-2321 Content-Type: TEXT/PLAIN; CHARSET=US-ASCII Content-ID: <20030820092347.I20029@root.org> Content-Description: Mail message body This appears to be a pthreads problem, not scsi. Anyone care to look at it? ---------- Forwarded message ---------- Date: Wed, 20 Aug 2003 11:24:42 -0400 From: Dan Langille <dan@langille.org> To: freebsd-scsi@freebsd.org Cc: Kern Sibbald <kern@sibbald.com> Subject: (Fwd) Lost data on FreeBSD tape I've been working with Kern Sibbald, author of Bacula (http://www.bacula.org/) to iron out a few nits on the FreeBSD port of the software. Below you'll find his latest attempts to isolate the problem. Attached is a small test program and how to produce the problem. Could someone else please try to reproduce the error? Thanks ------- Forwarded message follows ------- Subject: Lost data on FreeBSD tape From: Kern Sibbald <kern@sibbald.com> To: Dan Langille <dan@langille.org> Organization: Date sent: 20 Aug 2003 11:01:23 +0200 Hello Dan, I've finally found how to create the problem and how to eliminate it. I think you or some FreeBSD guy will have to look at the source code. My testing confirms what I previously wrote that Bacula fails as well as btape doing either Bacula style writes or raw write() calls. There is only one strange twist to this: the demo program that I sent you works. If you recompile the demo program and add -pthread to both the compile and the link, data is lost -- and once you remove the -pthread on the compile and link, the program works again. The interesting thing is that when the program works, it gets a 0 status on a write, which indicates that the tape is at the end of the Logical EOF marker (or in other words, the tape is almost full): Write failed. Last block written=17294. stat=0 ERR=Unknown error: 0 When the program is compiled/linked with the -pthread option, it does not receive the 0 status from a write(), but rather gets a -1, which means the tape is full and you cannot write any more: Write failed. Last block written=17926. stat=-1 ERR=No space left on device There are two things to note: 1. When the program fails, it gets a -1 status with no previous 0 status. 2. When the program fails, it has written about 700 more blocks on the tape compared to the working program. One can easily understand why data is lost. So, bottom line: the pthread libraries somehow seem to lose the logical end of tape marker (i.e. return status of 0 from write()). I attach a copy of the program with documentation at the top on how to produce the problem and the output that one gets. Best regards, Kern PS: feel free to pass this email on. ------- End of forwarded message ------- -- Dan Langille : http://www.langille.org/ --Message-Boundary-2321 Content-Type: APPLICATION/OCTET-STREAM; NAME=-; TYPE=Plain Content-Transfer-Encoding: BASE64 Content-ID: <20030820092347.N20029@root.org> Content-Description: Content-Disposition: ATTACHMENT; FILENAME=- SGVsbG8gRGFuLA0KDQpJJ3ZlIGZpbmFsbHkgZm91bmQgaG93IHRvIGNyZWF0ZSB0aGUgcHJv YmxlbQ0KYW5kIGhvdyB0byBlbGltaW5hdGUgaXQuIEkgdGhpbmsgeW91IG9yIHNvbWUNCkZy ZWVCU0QgZ3V5IHdpbGwgaGF2ZSB0byBsb29rIGF0IHRoZSBzb3VyY2UNCmNvZGUuDQoNCk15 IHRlc3RpbmcgY29uZmlybXMgd2hhdCBJIHByZXZpb3VzbHkgd3JvdGUgdGhhdA0KQmFjdWxh IGZhaWxzIGFzIHdlbGwgYXMgYnRhcGUgZG9pbmcgZWl0aGVyIEJhY3VsYQ0Kc3R5bGUgd3Jp dGVzIG9yIHJhdyB3cml0ZSgpIGNhbGxzLiAgVGhlcmUgaXMgb25seQ0Kb25lIHN0cmFuZ2Ug dHdpc3QgdG8gdGhpczogdGhlIGRlbW8gcHJvZ3JhbSB0aGF0DQpJIHNlbnQgeW91IHdvcmtz LiANCg0KSWYgeW91IHJlY29tcGlsZSB0aGUgZGVtbyBwcm9ncmFtIGFuZCBhZGQNCi1wdGhy ZWFkIHRvIGJvdGggdGhlIGNvbXBpbGUgYW5kIHRoZSBsaW5rLCBkYXRhDQppcyBsb3N0IC0t IGFuZCBvbmNlIHlvdSByZW1vdmUgdGhlIC1wdGhyZWFkDQpvbiB0aGUgY29tcGlsZSBhbmQg bGluaywgdGhlIHByb2dyYW0gd29ya3MgYWdhaW4uDQoNClRoZSBpbnRlcmVzdGluZyB0aGlu ZyBpcyB0aGF0IHdoZW4gdGhlIHByb2dyYW0NCndvcmtzLCBpdCBnZXRzIGEgMCBzdGF0dXMg b24gYSB3cml0ZSwgd2hpY2gNCmluZGljYXRlcyB0aGF0IHRoZSB0YXBlIGlzIGF0IHRoZSBl bmQgb2YgdGhlDQpMb2dpY2FsIEVPRiBtYXJrZXIgKG9yIGluIG90aGVyIHdvcmRzLCB0aGUN CnRhcGUgaXMgYWxtb3N0IGZ1bGwpOg0KDQogV3JpdGUgZmFpbGVkLiAgTGFzdCBibG9jayB3 cml0dGVuPTE3Mjk0LiBzdGF0PTAgRVJSPVVua25vd24gZXJyb3I6IDANCg0KV2hlbiB0aGUg cHJvZ3JhbSBpcyBjb21waWxlZC9saW5rZWQgd2l0aCB0aGUNCi1wdGhyZWFkIG9wdGlvbiwg aXQgZG9lcyBub3QgcmVjZWl2ZSB0aGUgMA0Kc3RhdHVzIGZyb20gYSB3cml0ZSgpLCBidXQg cmF0aGVyIGdldHMNCmEgLTEsIHdoaWNoIG1lYW5zIHRoZSB0YXBlIGlzIGZ1bGwgYW5kDQp5 b3UgY2Fubm90IHdyaXRlIGFueSBtb3JlOg0KDQpXcml0ZSBmYWlsZWQuICBMYXN0IGJsb2Nr IHdyaXR0ZW49MTc5MjYuIHN0YXQ9LTEgRVJSPU5vIHNwYWNlIGxlZnQgb24NCmRldmljZQ0K DQpUaGVyZSBhcmUgdHdvIHRoaW5ncyB0byBub3RlOiAxLiBXaGVuIHRoZSBwcm9ncmFtIGZh aWxzLA0KaXQgZ2V0cyBhIC0xIHN0YXR1cyB3aXRoIG5vIHByZXZpb3VzIDAgc3RhdHVzLiAg Mi4gV2hlbg0KdGhlIHByb2dyYW0gZmFpbHMsIGl0IGhhcyB3cml0dGVuIGFib3V0IDcwMCBt b3JlIGJsb2Nrcw0Kb24gdGhlIHRhcGUgY29tcGFyZWQgdG8gdGhlIHdvcmtpbmcgcHJvZ3Jh bS4gT25lIGNhbg0KZWFzaWx5IHVuZGVyc3RhbmQgd2h5IGRhdGEgaXMgbG9zdC4gIA0KDQpT bywgYm90dG9tIGxpbmU6IHRoZSBwdGhyZWFkIGxpYnJhcmllcyBzb21laG93DQpzZWVtIHRv IGxvc2UgdGhlIGxvZ2ljYWwgZW5kIG9mIHRhcGUgbWFya2VyDQooaS5lLiByZXR1cm4gc3Rh dHVzIG9mIDAgZnJvbSB3cml0ZSgpKS4gDQoNCkkgYXR0YWNoIGEgY29weSBvZiB0aGUgcHJv Z3JhbSB3aXRoIGRvY3VtZW50YXRpb24NCmF0IHRoZSB0b3Agb24gaG93IHRvIHByb2R1Y2Ug dGhlIHByb2JsZW0gYW5kDQp0aGUgb3V0cHV0IHRoYXQgb25lIGdldHMuDQoNCkJlc3QgcmVn YXJkcywNCg0KS2Vybg0KDQpQUzogZmVlbCBmcmVlIHRvIHBhc3MgdGhpcyBlbWFpbCBvbi4N Cg0K --Message-Boundary-2321 Content-Type: TEXT/PLAIN; CHARSET=US-ASCII Content-ID: <20030820092347.L20029@root.org> Content-Description: Text from file 'tapetest.c' /* * * Program to test loss of data at EOM on * FreeBSD systems. * * Kern Sibbald, August 2003 * * If you build this program with: * * c++ -g -O2 -Wall -c tapetest.c * c++ -g -O2 -Wall tapetest.o -o tapetest * * Procedure for testing tape * ./tapetest /dev/your-tape-device * rewind * rawfill * rewind * scan * * The output will be: * * ======== * Rewound /dev/nsa0 * *Begin writing blocks of 64512 bytes. * ++++++++++++++++++++ ... * Write failed. Last block written=17294. stat=0 ERR=Unknown error: 0 * weof_dev * Wrote EOF to /dev/nsa0 * *Rewound /dev/nsa0 * *Starting scan at file 0 * 17294 blocks of 64512 bytes in file 0 * End of File mark. * End of File mark. * End of tape * Total files=1, blocks=17294, bytes = 1115670528 * ======== * * which is correct. Notice that the return status is * 0, while in the example below, which fails, the return * status is -1. * * If you build this program with: * * c++ -g -O2 -Wall -pthread -c tapetest.c * c++ -g -O2 -Wall -pthread tapetest.o -o tapetest * Note, we simply added -pthread compared to the * previous example. * * Procedure for testing tape * ./tapetest /dev/your-tape-device * rewind * rawfill * rewind * scan * * The output will be: * * ======== * Rewound /dev/nsa0 * *Begin writing blocks of 64512 bytes. * +++++++++++++++++++++++++++++ ... * Write failed. Last block written=17926. stat=-1 ERR=No space left on device * weof_dev * Wrote EOF to /dev/nsa0 * *Rewound /dev/nsa0 * *Starting scan at file 0 * 17913 blocks of 64512 bytes in file 0 * End of File mark. * End of File mark. * End of tape * Total files=1, blocks=17913, bytes = 1155603456 * ======== * * which is incroorect because it wrote 17,926 blocks but read * back only 17,913 blocks. * * */ #include <stdio.h> #include <unistd.h> #include <stdlib.h> #include <stdarg.h> #include <errno.h> #include <sys/ioctl.h> #include <string.h> #include <strings.h> #include <sys/mtio.h> #include <sys/types.h> #include <sys/stat.h> #include <fcntl.h> #include <ctype.h> #define FALSE 0 #define TRUE 1 #define dev_state(dev, state) ((dev)->state & (state)) /* Device state bits */ #define ST_OPENED (1<<0) /* set when device opened */ #define ST_TAPE (1<<1) /* is a tape device */ #define ST_FILE (1<<2) /* is a file device */ #define ST_FIFO (1<<3) /* is a fifo device */ #define ST_PROG (1<<4) /* is a program device */ #define ST_LABEL (1<<5) /* label found */ #define ST_MALLOC (1<<6) /* dev packet malloc'ed in init_dev() */ #define ST_APPEND (1<<7) /* ready for Bacula append */ #define ST_READ (1<<8) /* ready for Bacula read */ #define ST_EOT (1<<9) /* at end of tape */ #define ST_WEOT (1<<10) /* Got EOT on write */ #define ST_EOF (1<<11) /* Read EOF i.e. zero bytes */ #define ST_NEXTVOL (1<<12) /* Start writing on next volume */ #define ST_SHORT (1<<13) /* Short block read */ #define BLOCK_SIZE (512 * 126) /* Exported variables */ int quit = 0; char buf[100000]; int verbose = 0; int debug_level = 0; int fd = 0; struct DEVICE { int fd; int dev_errno; int file; int block_num; int state; char *buf; int buf_len; char *dev_name; int file_addr; }; DEVICE *dev; #define uint32_t unsigned long #define uint64_t unsigned long long /* Forward referenced subroutines */ static void do_tape_cmds(); static void helpcmd(); static void scancmd(); static void rewindcmd(); static void rawfill_cmd(); /* Static variables */ static char cmd[1000]; static void usage(); int get_cmd(char *prompt); /********************************************************************* * * Main Bacula Pool Creation Program * */ int main(int argc, char *argv[]) { int ch; while ((ch = getopt(argc, argv, "d:v?")) != -1) { switch (ch) { case 'd': /* set debug level */ debug_level = atoi(optarg); if (debug_level <= 0) { debug_level = 1; } break; case 'v': verbose++; break; case '?': default: helpcmd(); exit(0); } } argc -= optind; argv += optind; /* See if we can open a device */ if (argc == 0) { printf("No archive name specified.\n"); usage(); exit(1); } else if (argc != 1) { printf("Improper number of arguments specified.\n"); usage(); exit(1); } fd = open(argv[0], O_RDWR); if (fd < 0) { printf("Error opening %s ERR=%s\n", argv[0], strerror(errno)); exit(1); } dev = (DEVICE *)malloc(sizeof(DEVICE)); memset(dev, 0, sizeof(DEVICE)); dev->fd = fd; dev->dev_name = strdup(argv[0]); dev->buf_len = BLOCK_SIZE; dev->buf = (char *)malloc(BLOCK_SIZE); do_tape_cmds(); return 0; } int rewind_dev(DEVICE *dev) { struct mtop mt_com; if (dev->fd < 0) { dev->dev_errno = EBADF; printf("Bad call to rewind_dev. Device %s not open\n", dev->dev_name); return 0; } dev->state &= ~(ST_APPEND|ST_READ|ST_EOT|ST_EOF|ST_WEOT); /* remove EOF/EOT flags */ dev->block_num = dev->file = 0; mt_com.mt_op = MTREW; mt_com.mt_count = 1; if (ioctl(dev->fd, MTIOCTOP, (char *)&mt_com) < 0) { dev->dev_errno = errno; printf("Rewind error on %s. ERR=%s.\n", dev->dev_name, strerror(dev->dev_errno)); return 0; } return 1; } /* * Write an end of file on the device * Returns: 0 on success * non-zero on failure */ int weof_dev(DEVICE *dev, int num) { struct mtop mt_com; int stat; if (dev->fd < 0) { dev->dev_errno = EBADF; printf("Bad call to fsf_dev. Archive not open\n"); return -1; } dev->state &= ~(ST_EOT | ST_EOF); /* remove EOF/EOT flags */ dev->block_num = 0; printf("weof_dev\n"); mt_com.mt_op = MTWEOF; mt_com.mt_count = num; stat = ioctl(dev->fd, MTIOCTOP, (char *)&mt_com); if (stat == 0) { dev->file++; dev->file_addr = 0; } else { dev->dev_errno = errno; printf("ioctl MTWEOF error on %s. ERR=%s.\n", dev->dev_name, strerror(dev->dev_errno)); } return stat; } void quitcmd() { quit = 1; } /* * Rewind the tape. */ static void rewindcmd() { if (!rewind_dev(dev)) { printf("Bad status from rewind. ERR=%s\n", strerror(dev->dev_errno)); } else { printf("Rewound %s\n", dev->dev_name); } } /* * Write and end of file on the tape */ static void weofcmd() { int stat; if ((stat = weof_dev(dev, 1)) < 0) { printf("Bad status from weof %d. ERR=%s\n", stat, strerror(dev->dev_errno)); return; } else { printf("Wrote EOF to %s\n", dev->dev_name); } } /* * Read a record from the tape */ static void rrcmd() { char *buf; int stat, len; if (!get_cmd("Enter length to read: ")) { return; } len = atoi(cmd); if (len < 0 || len > 1000000) { printf("Bad length entered, using default of 1024 bytes.\n"); len = 1024; } buf = (char *)malloc(len); stat = read(fd, buf, len); if (stat > 0 && stat <= len) { errno = 0; } printf("Read of %d bytes gives stat=%d. ERR=%s\n", len, stat, strerror(errno)); free(buf); } /* * Write a record to the tape */ static void wrcmd() { int stat; int rfd; rfd = open("/dev/urandom", O_RDONLY); if (rfd) { read(rfd, dev->buf, dev->buf_len); } else { printf("Cannot open /dev/urandom.\n"); return; } printf("Write one block of %u bytes.\n", dev->buf_len); stat = write(dev->fd, dev->buf, dev->buf_len); if (stat != (int)dev->buf_len) { if (stat == -1) { printf("Bad status from write. ERR=%s\n", strerror(errno)); } else { printf("Expected to write %d bytes but wrote only %d.\n", dev->buf_len, stat); } } } /* * Scan tape by reading block by block. Report what is * on the tape. Note, this command does raw reads, and as such * will not work with fixed block size devices. */ static void scancmd() { int stat; int blocks, tot_blocks, tot_files; int block_size; uint64_t bytes; blocks = block_size = tot_blocks = 0; bytes = 0; if (dev->state & ST_EOT) { printf("End of tape\n"); return; } tot_files = dev->file; printf("Starting scan at file %u\n", dev->file); for (;;) { if ((stat = read(dev->fd, buf, sizeof(buf))) < 0) { dev->dev_errno = errno; printf("Bad status from read %d. ERR=%s\n", stat, strerror(dev->dev_errno)); if (blocks > 0) printf("%d block%s of %d bytes in file %d\n", blocks, blocks>1?"s":"", block_size, dev->file); return; } if (stat != block_size) { if (blocks > 0) { printf("%d block%s of %d bytes in file %d\n", blocks, blocks>1?"s":"", block_size, dev->file); blocks = 0; } block_size = stat; } if (stat == 0) { /* EOF */ printf("End of File mark.\n"); /* Two reads of zero means end of tape */ if (dev->state & ST_EOF) dev->state |= ST_EOT; else { dev->state |= ST_EOF; dev->file++; } if (dev->state & ST_EOT) { printf("End of tape\n"); break; } } else { /* Got data */ dev->state &= ~ST_EOF; blocks++; tot_blocks++; bytes += stat; } } tot_files = dev->file - tot_files; printf("Total files=%d, blocks=%d, bytes = %d\n", tot_files, tot_blocks, (int)bytes); } static void rawfill_cmd() { int stat; int rfd; uint32_t block_num = 0; uint32_t *p; int my_errno; rfd = open("/dev/urandom", O_RDONLY); if (rfd) { read(rfd, dev->buf, dev->buf_len); } else { printf("Cannot open /dev/urandom.\n"); return; } p = (uint32_t *)dev->buf; printf("Begin writing blocks of %u bytes.\n", dev->buf_len); for ( ;; ) { *p = block_num; stat = write(dev->fd, dev->buf, dev->buf_len); if (stat == (int)dev->buf_len) { if ((block_num++ % 100) == 0) { printf("+"); fflush(stdout); } continue; } break; } my_errno = errno; printf("\n"); weofcmd(); printf("Write failed. Last block written=%d. stat=%d ERR=%s\n", (int)block_num, stat, strerror(my_errno)); } /* Strip any trailing junk from the command */ void strip_trailing_junk(char *cmd) { char *p; p = cmd + strlen(cmd) - 1; /* strip trailing junk from command */ while ((p >= cmd) && (*p == '\n' || *p == '\r' || *p == ' ')) *p-- = 0; } /* folded search for string - case insensitive */ int fstrsch(char *a, char *b) /* folded case search */ { register char *s1,*s2; register char c1=0, c2=0; s1=a; s2=b; while (*s1) { /* do it the fast way */ if ((*s1++ | 0x20) != (*s2++ | 0x20)) return 0; /* failed */ } while (*a) { /* do it over the correct slow way */ if (isupper(c1 = *a)) { c1 = tolower((int)c1); } if (isupper(c2 = *b)) { c2 = tolower((int)c2); } if (c1 != c2) { return 0; } a++; b++; } return 1; } struct cmdstruct { char *key; void (*func)(); char *help; }; static struct cmdstruct commands[] = { {"help", helpcmd, "print this command"}, {"quit", quitcmd, "quit tapetest"}, {"rawfill", rawfill_cmd, "use write() to fill tape"}, {"rewind", rewindcmd, "rewind the tape"}, {"rr", rrcmd, "raw read the tape"}, {"wr", wrcmd, "raw write one block to the tape"}, {"scan", scancmd, "read() tape block by block to EOT and report"}, {"weof", weofcmd, "write an EOF on the tape"}, }; #define comsize (sizeof(commands)/sizeof(struct cmdstruct)) static void do_tape_cmds() { unsigned int i; int found; while (get_cmd("*")) { found = 0; for (i=0; i<comsize; i++) /* search for command */ if (fstrsch(cmd, commands[i].key)) { (*commands[i].func)(); /* go execute command */ found = 1; break; } if (!found) { printf("%s is an illegal command\n", cmd); } if (quit) { break; } } } static void helpcmd() { unsigned int i; usage(); printf(" Command Description\n ======= ===========\n"); for (i=0; i<comsize; i++) printf(" %-10s %s\n", commands[i].key, commands[i].help); printf("\n"); } static void usage() { fprintf(stderr, "Usage: tapetest [-d debug_level] [device_name]\n" " -dnn set debug level to nn\n" " -? print this message.\n" "\n"); } /* * Get next input command from terminal. This * routine is REALLY primitive, and should be enhanced * to have correct backspacing, etc. */ int get_cmd(char *prompt) { int i = 0; int ch; fprintf(stdout, prompt); /* We really should turn off echoing and pretty this * up a bit. */ cmd[i] = 0; while ((ch = fgetc(stdin)) != EOF) { if (ch == '\n') { strip_trailing_junk(cmd); return 1; } else if (ch == 4 || ch == 0xd3 || ch == 0x8) { if (i > 0) cmd[--i] = 0; continue; } cmd[i++] = ch; cmd[i] = 0; } quit = 1; return 0; } --Message-Boundary-2321 Content-Type: TEXT/PLAIN; CHARSET=us-ascii Content-ID: <20030820092347.U20029@root.org> Content-Description: Content-Disposition: INLINE _______________________________________________ freebsd-scsi@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-scsi To unsubscribe, send any mail to "freebsd-scsi-unsubscribe@freebsd.org" --Message-Boundary-2321--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20030820092347.G20029>