When verify fails, dump the good/bad blocks to files
[fio.git] / verify.c
index 6b54b70ff672ffd3c75f7e0b3b72d35592c1e91c..81b05a9034f5017debf6a3604099975f1697d7fa 100644 (file)
--- a/verify.c
+++ b/verify.c
@@ -10,6 +10,8 @@
 #include "fio.h"
 #include "verify.h"
 #include "smalloc.h"
+#include "trim.h"
+#include "lib/rand.h"
 
 #include "crc/md5.h"
 #include "crc/crc64.h"
 #include "crc/sha512.h"
 #include "crc/sha1.h"
 
-static void fill_random_bytes(struct thread_data *td, void *p, unsigned int len)
-{
-       unsigned int todo;
-       int r;
-
-       while (len) {
-               r = os_random_long(&td->verify_state);
-
-               /*
-                * lrand48_r seems to be broken and only fill the bottom
-                * 32-bits, even on 64-bit archs with 64-bit longs
-                */
-               todo = sizeof(r);
-               if (todo > len)
-                       todo = len;
-
-               memcpy(p, &r, todo);
-
-               len -= todo;
-               p += todo;
-       }
-}
+static void populate_hdr(struct thread_data *td, struct io_u *io_u,
+                        struct verify_header *hdr, unsigned int header_num,
+                        unsigned int header_len);
 
-static void fill_pattern(struct thread_data *td, void *p, unsigned int len)
+void fill_pattern(struct thread_data *td, void *p, unsigned int len, struct io_u *io_u, unsigned long seed, int use_seed)
 {
        switch (td->o.verify_pattern_bytes) {
        case 0:
                dprint(FD_VERIFY, "fill random bytes len=%u\n", len);
-               fill_random_bytes(td, p, len);
+               if (use_seed)
+                       __fill_random_buf(p, len, seed);
+               else
+                       io_u->rand_seed = fill_random_buf(p, len);
                break;
        case 1:
+               if (io_u->buf_filled_len >= len) {
+                       dprint(FD_VERIFY, "using already filled verify pattern b=0 len=%u\n", len);
+                       return;
+               }
                dprint(FD_VERIFY, "fill verify pattern b=0 len=%u\n", len);
                memset(p, td->o.verify_pattern[0], len);
+               io_u->buf_filled_len = len;
                break;
        default: {
                unsigned int i = 0, size = 0;
                unsigned char *b = p;
 
+               if (io_u->buf_filled_len >= len) {
+                       dprint(FD_VERIFY, "using already filled verify pattern b=%d len=%u\n",
+                                       td->o.verify_pattern_bytes, len);
+                       return;
+               }
                dprint(FD_VERIFY, "fill verify pattern b=%d len=%u\n",
                                        td->o.verify_pattern_bytes, len);
 
@@ -69,6 +65,7 @@ static void fill_pattern(struct thread_data *td, void *p, unsigned int len)
                        memcpy(b+i, td->o.verify_pattern, size);
                        i += size;
                }
+               io_u->buf_filled_len = len;
                break;
                }
        }
@@ -100,7 +97,7 @@ static void hexdump(void *buffer, int len)
  */
 static inline unsigned int __hdr_size(int verify_type)
 {
-       unsigned int len = len;
+       unsigned int len = 0;
 
        switch (verify_type) {
        case VERIFY_NONE:
@@ -166,6 +163,7 @@ struct vcont {
         */
        struct io_u *io_u;
        unsigned int hdr_num;
+       struct thread_data *td;
 
        /*
         * Output, only valid in case of error
@@ -176,6 +174,70 @@ struct vcont {
        unsigned int crc_len;
 };
 
+static void dump_buf(char *buf, unsigned int len, const char *name,
+                    unsigned long long offset)
+{
+       char fname[80];
+       int ret, fd;
+
+       sprintf(fname, "%llu.%s", offset, name);
+
+       fd = open(fname, O_CREAT | O_TRUNC | O_WRONLY, 0644);
+       if (fd < 0) {
+               perror("open verify buf file");
+               return;
+       }
+
+       while (len) {
+               ret = write(fd, buf, len);
+               if (!ret)
+                       break;
+               else if (ret < 0) {
+                       perror("write verify buf file");
+                       break;
+               }
+               len -= ret;
+               buf += ret;
+       }
+
+       close(fd);
+       log_err("       %s data dumped as %s\n", name, fname);
+}
+
+static void dump_verify_buffers(struct verify_header *hdr, struct vcont *vc)
+{
+       struct thread_data *td = vc->td;
+       struct io_u *io_u = vc->io_u;
+       unsigned long hdr_offset;
+       unsigned int hdr_inc, header_num;
+       struct io_u dummy;
+       void *buf, *p;
+
+       hdr_offset = vc->hdr_num * hdr->len;
+
+       dump_buf(io_u->buf + hdr_offset, hdr->len, "received",
+                       io_u->offset + hdr_offset);
+
+       buf = p = malloc(io_u->buflen);
+       dummy = *io_u;
+       fill_pattern(td, p, io_u->buflen, &dummy, hdr->rand_seed, 1);
+
+       hdr_inc = io_u->buflen;
+       if (td->o.verify_interval)
+               hdr_inc = td->o.verify_interval;
+
+       header_num = 0;
+       for (; p < buf + io_u->buflen; p += hdr_inc) {
+               hdr = p;
+               populate_hdr(td, io_u, hdr, header_num, hdr_inc);
+               header_num++;
+       }
+
+       dump_buf(buf + hdr_offset, hdr->len, "expected",
+                       io_u->offset + hdr_offset);
+       free(buf);
+}
+
 static void log_verify_failure(struct verify_header *hdr, struct vcont *vc)
 {
        unsigned long long offset;
@@ -191,6 +253,8 @@ static void log_verify_failure(struct verify_header *hdr, struct vcont *vc)
                log_err("       Received CRC: ");
                hexdump(vc->bad_crc, vc->crc_len);
        }
+
+       dump_verify_buffers(hdr, vc);
 }
 
 /*
@@ -481,6 +545,40 @@ int verify_io_u_async(struct thread_data *td, struct io_u *io_u)
        return 0;
 }
 
+static int verify_trimmed_io_u(struct thread_data *td, struct io_u *io_u)
+{
+       static char zero_buf[1024];
+       unsigned int this_len, len;
+       int ret = 0;
+       void *p;
+
+       if (!td->o.trim_zero)
+               return 0;
+
+       len = io_u->buflen;
+       p = io_u->buf;
+       do {
+               this_len = sizeof(zero_buf);
+               if (this_len > len)
+                       this_len = len;
+               if (memcmp(p, zero_buf, this_len)) {
+                       ret = EILSEQ;
+                       break;
+               }
+               len -= this_len;
+               p += this_len;
+       } while (len);
+
+       if (!ret)
+               return 0;
+
+       log_err("trim: verify failed at file %s offset %llu, length %lu"
+               ", block offset %lu\n",
+                       io_u->file->file_name, io_u->offset, io_u->buflen,
+                       (unsigned long) (p - io_u->buf));
+       return ret;
+}
+
 int verify_io_u(struct thread_data *td, struct io_u *io_u)
 {
        struct verify_header *hdr;
@@ -490,6 +588,10 @@ int verify_io_u(struct thread_data *td, struct io_u *io_u)
 
        if (td->o.verify == VERIFY_NULL || io_u->ddir != DDIR_READ)
                return 0;
+       if (io_u->flags & IO_U_F_TRIMMED) {
+               ret = verify_trimmed_io_u(td, io_u);
+               goto done;
+       }
 
        hdr_inc = io_u->buflen;
        if (td->o.verify_interval)
@@ -501,6 +603,7 @@ int verify_io_u(struct thread_data *td, struct io_u *io_u)
                struct vcont vc = {
                        .io_u           = io_u,
                        .hdr_num        = hdr_num,
+                       .td             = td,
                };
 
                if (ret && td->o.verify_fatal)
@@ -581,6 +684,7 @@ int verify_io_u(struct thread_data *td, struct io_u *io_u)
                }
        }
 
+done:
        if (ret && td->o.verify_fatal)
                td->terminate = 1;
 
@@ -684,6 +788,82 @@ static void fill_md5(struct verify_header *hdr, void *p, unsigned int len)
        md5_update(&md5_ctx, p, len);
 }
 
+static void populate_hdr(struct thread_data *td, struct io_u *io_u,
+                        struct verify_header *hdr, unsigned int header_num,
+                        unsigned int header_len)
+{
+       unsigned int data_len;
+       void *data, *p;
+
+       p = (void *) hdr;
+
+       hdr->fio_magic = FIO_HDR_MAGIC;
+       hdr->len = header_len;
+       hdr->verify_type = td->o.verify;
+       hdr->rand_seed = io_u->rand_seed;
+       data_len = header_len - hdr_size(hdr);
+
+       data = p + hdr_size(hdr);
+       switch (td->o.verify) {
+       case VERIFY_MD5:
+               dprint(FD_VERIFY, "fill md5 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_md5(hdr, data, data_len);
+               break;
+       case VERIFY_CRC64:
+               dprint(FD_VERIFY, "fill crc64 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_crc64(hdr, data, data_len);
+               break;
+       case VERIFY_CRC32C:
+       case VERIFY_CRC32C_INTEL:
+               dprint(FD_VERIFY, "fill crc32c io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_crc32c(hdr, data, data_len);
+               break;
+       case VERIFY_CRC32:
+               dprint(FD_VERIFY, "fill crc32 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_crc32(hdr, data, data_len);
+               break;
+       case VERIFY_CRC16:
+               dprint(FD_VERIFY, "fill crc16 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_crc16(hdr, data, data_len);
+               break;
+       case VERIFY_CRC7:
+               dprint(FD_VERIFY, "fill crc7 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_crc7(hdr, data, data_len);
+               break;
+       case VERIFY_SHA256:
+               dprint(FD_VERIFY, "fill sha256 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_sha256(hdr, data, data_len);
+               break;
+       case VERIFY_SHA512:
+               dprint(FD_VERIFY, "fill sha512 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_sha512(hdr, data, data_len);
+               break;
+       case VERIFY_META:
+               dprint(FD_VERIFY, "fill meta io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_meta(hdr, td, io_u, header_num);
+               break;
+       case VERIFY_SHA1:
+               dprint(FD_VERIFY, "fill sha1 io_u %p, len %u\n",
+                                               io_u, hdr->len);
+               fill_sha1(hdr, data, data_len);
+               break;
+       default:
+               log_err("fio: bad verify type: %d\n", td->o.verify);
+               assert(0);
+       }
+       if (td->o.verify_offset)
+               memswp(p, p + td->o.verify_offset, hdr_size(hdr));
+}
+
 /*
  * fill body of io_u->buf with random data and add a header with the
  * crc32 or md5 sum of that data.
@@ -691,13 +871,13 @@ static void fill_md5(struct verify_header *hdr, void *p, unsigned int len)
 void populate_verify_io_u(struct thread_data *td, struct io_u *io_u)
 {
        struct verify_header *hdr;
-       void *p = io_u->buf, *data;
-       unsigned int hdr_inc, data_len, header_num = 0;
+       unsigned int hdr_inc, header_num = 0;
+       void *p = io_u->buf;
 
        if (td->o.verify == VERIFY_NULL)
                return;
 
-       fill_pattern(td, p, io_u->buflen);
+       fill_pattern(td, p, io_u->buflen, io_u, 0, 0);
 
        hdr_inc = io_u->buflen;
        if (td->o.verify_interval)
@@ -705,71 +885,7 @@ void populate_verify_io_u(struct thread_data *td, struct io_u *io_u)
 
        for (; p < io_u->buf + io_u->buflen; p += hdr_inc) {
                hdr = p;
-
-               hdr->fio_magic = FIO_HDR_MAGIC;
-               hdr->verify_type = td->o.verify;
-               hdr->len = hdr_inc;
-               data_len = hdr_inc - hdr_size(hdr);
-
-               data = p + hdr_size(hdr);
-               switch (td->o.verify) {
-               case VERIFY_MD5:
-                       dprint(FD_VERIFY, "fill md5 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_md5(hdr, data, data_len);
-                       break;
-               case VERIFY_CRC64:
-                       dprint(FD_VERIFY, "fill crc64 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_crc64(hdr, data, data_len);
-                       break;
-               case VERIFY_CRC32C:
-               case VERIFY_CRC32C_INTEL:
-                       dprint(FD_VERIFY, "fill crc32c io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_crc32c(hdr, data, data_len);
-                       break;
-               case VERIFY_CRC32:
-                       dprint(FD_VERIFY, "fill crc32 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_crc32(hdr, data, data_len);
-                       break;
-               case VERIFY_CRC16:
-                       dprint(FD_VERIFY, "fill crc16 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_crc16(hdr, data, data_len);
-                       break;
-               case VERIFY_CRC7:
-                       dprint(FD_VERIFY, "fill crc7 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_crc7(hdr, data, data_len);
-                       break;
-               case VERIFY_SHA256:
-                       dprint(FD_VERIFY, "fill sha256 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_sha256(hdr, data, data_len);
-                       break;
-               case VERIFY_SHA512:
-                       dprint(FD_VERIFY, "fill sha512 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_sha512(hdr, data, data_len);
-                       break;
-               case VERIFY_META:
-                       dprint(FD_VERIFY, "fill meta io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_meta(hdr, td, io_u, header_num);
-                       break;
-               case VERIFY_SHA1:
-                       dprint(FD_VERIFY, "fill sha1 io_u %p, len %u\n",
-                                                       io_u, hdr->len);
-                       fill_sha1(hdr, data, data_len);
-                       break;
-               default:
-                       log_err("fio: bad verify type: %d\n", td->o.verify);
-                       assert(0);
-               }
-               if (td->o.verify_offset)
-                       memswp(p, p + td->o.verify_offset, hdr_size(hdr));
+               populate_hdr(td, io_u, hdr, header_num, hdr_inc);
                header_num++;
        }
 }
@@ -789,18 +905,25 @@ int get_next_verify(struct thread_data *td, struct io_u *io_u)
 
                ipo = rb_entry(n, struct io_piece, rb_node);
                rb_erase(n, &td->io_hist_tree);
-               td->io_hist_len--;
+               assert(ipo->flags & IP_F_ONRB);
+               ipo->flags &= ~IP_F_ONRB;
        } else if (!flist_empty(&td->io_hist_list)) {
                ipo = flist_entry(td->io_hist_list.next, struct io_piece, list);
-               td->io_hist_len--;
                flist_del(&ipo->list);
+               assert(ipo->flags & IP_F_ONLIST);
+               ipo->flags &= ~IP_F_ONLIST;
        }
 
        if (ipo) {
+               td->io_hist_len--;
+
                io_u->offset = ipo->offset;
                io_u->buflen = ipo->len;
                io_u->file = ipo->file;
 
+               if (ipo->flags & IP_F_TRIMMED)
+                       io_u->flags |= IO_U_F_TRIMMED;
+
                if (!fio_file_open(io_u->file)) {
                        int r = td_io_open_file(td, io_u->file);
 
@@ -816,6 +939,8 @@ int get_next_verify(struct thread_data *td, struct io_u *io_u)
                io_u->ddir = DDIR_READ;
                io_u->xfer_buf = io_u->buf;
                io_u->xfer_buflen = io_u->buflen;
+
+               remove_trim_entry(td, ipo);
                free(ipo);
                dprint(FD_VERIFY, "get_next_verify: ret io_u %p\n", io_u);
                return 0;
@@ -897,12 +1022,16 @@ done:
 int verify_async_init(struct thread_data *td)
 {
        int i, ret;
+       pthread_attr_t attr;
+
+       pthread_attr_init(&attr);
+       pthread_attr_setstacksize(&attr, PTHREAD_STACK_MIN);
 
        td->verify_thread_exit = 0;
 
        td->verify_threads = malloc(sizeof(pthread_t) * td->o.verify_async);
        for (i = 0; i < td->o.verify_async; i++) {
-               ret = pthread_create(&td->verify_threads[i], NULL,
+               ret = pthread_create(&td->verify_threads[i], &attr,
                                        verify_async_thread, td);
                if (ret) {
                        log_err("fio: async verify creation failed: %s\n",
@@ -918,6 +1047,8 @@ int verify_async_init(struct thread_data *td)
                td->nr_verify_threads++;
        }
 
+       pthread_attr_destroy(&attr);
+
        if (i != td->o.verify_async) {
                log_err("fio: only %d verify threads started, exiting\n", i);
                td->verify_thread_exit = 1;