diff options
author | Keith Bostic <keith@wiredtiger.com> | 2014-05-05 09:59:23 -0400 |
---|---|---|
committer | Keith Bostic <keith@wiredtiger.com> | 2014-05-05 09:59:23 -0400 |
commit | a95292657755b62346b46a2302445faea038d6f2 (patch) | |
tree | a78273257a628bf5166c813cebf0128367e55ace /src | |
parent | 1ecf3ced6fc6a65869b34976e2b3c3279742d455 (diff) | |
download | mongo-a95292657755b62346b46a2302445faea038d6f2.tar.gz |
A somewhat different approach to --enable-verbose: inline __wt_verbose()
and the test of the verbose flag, remove all of the WT_VERBOSE_XXX #defines
other than WT_VERBOSE_ISSET.
Diffstat (limited to 'src')
44 files changed, 469 insertions, 487 deletions
diff --git a/src/block/block_ckpt.c b/src/block/block_ckpt.c index fa175c9e637..4227d2d7c03 100644 --- a/src/block/block_ckpt.c +++ b/src/block/block_ckpt.c @@ -60,14 +60,14 @@ __wt_block_checkpoint_load(WT_SESSION_IMPL *session, WT_BLOCK *block, */ *root_addr_sizep = 0; - if (WT_VERBOSE_ISSET(session, checkpoint)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_CHECKPOINT)) { if (addr != NULL) { WT_ERR(__wt_scr_alloc(session, 0, &tmp)); WT_ERR(__ckpt_string(session, block, addr, tmp)); } - WT_VERBOSE_ERR(session, checkpoint, + WT_ERR(__wt_verbose(session, WT_VERB_CHECKPOINT, "%s: load-checkpoint: %s", block->name, - addr == NULL ? "[Empty]" : (const char *)tmp->data); + addr == NULL ? "[Empty]" : (const char *)tmp->data)); } /* @@ -129,8 +129,8 @@ __wt_block_checkpoint_load(WT_SESSION_IMPL *session, WT_BLOCK *block, * enough I don't bother). */ if (!checkpoint) { - WT_VERBOSE_ERR(session, checkpoint, - "truncate file to %" PRIuMAX, (uintmax_t)ci->file_size); + WT_ERR(__wt_verbose(session, WT_VERB_CHECKPOINT, + "truncate file to %" PRIuMAX, (uintmax_t)ci->file_size)); WT_ERR(__wt_ftruncate(session, block->fh, ci->file_size)); } @@ -481,14 +481,14 @@ __ckpt_process(WT_SESSION_IMPL *session, WT_BLOCK *block, WT_CKPT *ckptbase) !F_ISSET(ckpt, WT_CKPT_DELETE)) continue; - if (WT_VERBOSE_ISSET(session, checkpoint)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_CHECKPOINT)) { if (tmp == NULL) WT_ERR(__wt_scr_alloc(session, 0, &tmp)); WT_ERR(__ckpt_string( session, block, ckpt->raw.data, tmp)); - WT_VERBOSE_ERR(session, checkpoint, + WT_ERR(__wt_verbose(session, WT_VERB_CHECKPOINT, "%s: delete-checkpoint: %s: %s", - block->name, ckpt->name, (const char *)tmp->data); + block->name, ckpt->name, (const char *)tmp->data)); } /* @@ -723,12 +723,12 @@ __ckpt_update(WT_SESSION_IMPL *session, WT_RET(__wt_block_ckpt_to_buffer(session, block, &endp, ci)); ckpt->raw.size = WT_PTRDIFF(endp, ckpt->raw.mem); - if (WT_VERBOSE_ISSET(session, checkpoint)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_CHECKPOINT)) { WT_RET(__wt_scr_alloc(session, 0, &tmp)); WT_ERR(__ckpt_string(session, block, ckpt->raw.data, tmp)); - WT_VERBOSE_ERR(session, checkpoint, + WT_ERR(__wt_verbose(session, WT_VERB_CHECKPOINT, "%s: create-checkpoint: %s: %s", - block->name, ckpt->name, (const char *)tmp->data); + block->name, ckpt->name, (const char *)tmp->data)); } err: __wt_scr_free(&tmp); diff --git a/src/block/block_compact.c b/src/block/block_compact.c index 21b0155e1ca..2dfc51bb1f9 100644 --- a/src/block/block_compact.c +++ b/src/block/block_compact.c @@ -80,7 +80,7 @@ __wt_block_compact_skip(WT_SESSION_IMPL *session, WT_BLOCK *block, int *skipp) __wt_spin_lock(session, &block->live_lock); - if (WT_VERBOSE_ISSET(session, compact)) + if (WT_VERBOSE_ISSET(session, WT_VERB_COMPACT)) WT_ERR(__block_dump_avail(session, block)); /* Sum the number of available bytes in the first 90% of the file. */ @@ -99,14 +99,14 @@ __wt_block_compact_skip(WT_SESSION_IMPL *session, WT_BLOCK *block, int *skipp) if (avail >= fh->size / 10) *skipp = 0; - WT_VERBOSE_ERR(session, compact, + WT_ERR(__wt_verbose(session, WT_VERB_COMPACT, "%s: %" PRIuMAX "MB (%" PRIuMAX ") available space in the first " "90%% of the file, require 10%% or %" PRIuMAX "MB (%" PRIuMAX ") to perform compaction, compaction %s", block->name, (uintmax_t)avail / WT_MEGABYTE, (uintmax_t)avail, (uintmax_t)(fh->size / 10) / WT_MEGABYTE, (uintmax_t)fh->size / 10, - *skipp ? "skipped" : "proceeding"); + *skipp ? "skipped" : "proceeding")); err: __wt_spin_unlock(session, &block->live_lock); @@ -175,8 +175,8 @@ __block_dump_avail(WT_SESSION_IMPL *session, WT_BLOCK *block) el = &block->live.avail; size = block->fh->size; - WT_RET(__wt_verbose( - session, "file size %" PRIuMAX "MB (%" PRIuMAX ") with %" PRIuMAX + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, + "file size %" PRIuMAX "MB (%" PRIuMAX ") with %" PRIuMAX "%% space available %" PRIuMAX "MB (%" PRIuMAX ")", (uintmax_t)size / WT_MEGABYTE, (uintmax_t)size, ((uintmax_t)el->bytes * 100) / (uintmax_t)size, @@ -201,8 +201,8 @@ __block_dump_avail(WT_SESSION_IMPL *session, WT_BLOCK *block) #ifdef __VERBOSE_OUTPUT_PERCENTILE for (i = 0; i < WT_ELEMENTS(percentile); ++i) { v = percentile[i] * 512; - WT_RET(__wt_verbose( - session, "%2u%%: %12" PRIuMAX "MB, (%" PRIuMAX "B, %" + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, + "%2u%%: %12" PRIuMAX "MB, (%" PRIuMAX "B, %" PRIuMAX "%%)", i, (uintmax_t)v / WT_MEGABYTE, (uintmax_t)v, (uintmax_t)((v * 100) / (off_t)el->bytes))); @@ -210,8 +210,8 @@ __block_dump_avail(WT_SESSION_IMPL *session, WT_BLOCK *block) #endif for (i = 0; i < WT_ELEMENTS(decile); ++i) { v = decile[i] * 512; - WT_RET(__wt_verbose( - session, "%2u%%: %12" PRIuMAX "MB, (%" PRIuMAX "B, %" + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, + "%2u%%: %12" PRIuMAX "MB, (%" PRIuMAX "B, %" PRIuMAX "%%)", i * 10, (uintmax_t)v / WT_MEGABYTE, (uintmax_t)v, (uintmax_t)((v * 100) / (off_t)el->bytes))); diff --git a/src/block/block_ext.c b/src/block/block_ext.c index c1af2a30b8f..dd9f775dfa4 100644 --- a/src/block/block_ext.c +++ b/src/block/block_ext.c @@ -468,9 +468,9 @@ __block_extend( fh->size += size; WT_STAT_FAST_DATA_INCR(session, block_extension); - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "file extend %" PRIdMAX "B @ %" PRIdMAX, - (intmax_t)size, (intmax_t)*offp); + (intmax_t)size, (intmax_t)*offp)); return (0); } @@ -533,21 +533,21 @@ append: WT_RET(__block_extend(session, block, offp, size)); /* If doing a partial allocation, adjust the record and put it back. */ if (ext->size > size) { - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "allocate %" PRIdMAX " from range %" PRIdMAX "-%" PRIdMAX ", range shrinks to %" PRIdMAX "-%" PRIdMAX, (intmax_t)size, (intmax_t)ext->off, (intmax_t)(ext->off + ext->size), (intmax_t)(ext->off + size), - (intmax_t)(ext->off + size + ext->size - size)); + (intmax_t)(ext->off + size + ext->size - size))); ext->off += size; ext->size -= size; WT_RET(__block_ext_insert(session, &block->live.avail, ext)); } else { - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "allocate range %" PRIdMAX "-%" PRIdMAX, - (intmax_t)ext->off, (intmax_t)(ext->off + ext->size)); + (intmax_t)ext->off, (intmax_t)(ext->off + ext->size))); __wt_block_ext_free(session, ext); } @@ -575,8 +575,8 @@ __wt_block_free(WT_SESSION_IMPL *session, /* Crack the cookie. */ WT_RET(__wt_block_buffer_to_addr(block, addr, &offset, &size, &cksum)); - WT_VERBOSE_RET(session, block, - "free %" PRIdMAX "/%" PRIdMAX, (intmax_t)offset, (intmax_t)size); + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, + "free %" PRIdMAX "/%" PRIdMAX, (intmax_t)offset, (intmax_t)size)); #ifdef HAVE_DIAGNOSTIC WT_RET(__wt_block_misplaced(session, block, "free", offset, size, 1)); @@ -891,7 +891,8 @@ __wt_block_extlist_merge(WT_SESSION_IMPL *session, WT_EXTLIST *a, WT_EXTLIST *b) WT_EXTLIST tmp; u_int i; - WT_VERBOSE_RET(session, block, "merging %s into %s", a->name, b->name); + WT_RET(__wt_verbose( + session, WT_VERB_BLOCK, "merging %s into %s", a->name, b->name)); /* * Sometimes the list we are merging is much bigger than the other: if @@ -1027,9 +1028,9 @@ __block_merge(WT_SESSION_IMPL *session, WT_EXTLIST *el, off_t off, off_t size) after = NULL; } if (before == NULL && after == NULL) { - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "%s: insert range %" PRIdMAX "-%" PRIdMAX, - el->name, (intmax_t)off, (intmax_t)(off + size)); + el->name, (intmax_t)off, (intmax_t)(off + size))); return (__block_off_insert(session, el, off, size)); } @@ -1044,12 +1045,12 @@ __block_merge(WT_SESSION_IMPL *session, WT_EXTLIST *el, off_t off, off_t size) if (before == NULL) { WT_RET(__block_off_remove(session, el, after->off, &ext)); - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "%s: range grows from %" PRIdMAX "-%" PRIdMAX ", to %" PRIdMAX "-%" PRIdMAX, el->name, (intmax_t)ext->off, (intmax_t)(ext->off + ext->size), - (intmax_t)off, (intmax_t)(off + ext->size + size)); + (intmax_t)off, (intmax_t)(off + ext->size + size))); ext->off = off; ext->size += size; @@ -1061,13 +1062,13 @@ __block_merge(WT_SESSION_IMPL *session, WT_EXTLIST *el, off_t off, off_t size) } WT_RET(__block_off_remove(session, el, before->off, &ext)); - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "%s: range grows from %" PRIdMAX "-%" PRIdMAX ", to %" PRIdMAX "-%" PRIdMAX, el->name, (intmax_t)ext->off, (intmax_t)(ext->off + ext->size), (intmax_t)ext->off, - (intmax_t)(ext->off + ext->size + size)); + (intmax_t)(ext->off + ext->size + size))); ext->size += size; } @@ -1169,7 +1170,7 @@ corrupted: WT_ERR_MSG(session, WT_ERROR, WT_ERR(func(session, el, off, size)); } - if (WT_VERBOSE_ISSET(session, block)) + if (WT_VERBOSE_ISSET(session, WT_VERB_BLOCK)) WT_ERR(__block_extlist_dump(session, "read extlist", el, 0)); err: __wt_scr_free(&tmp); @@ -1192,7 +1193,7 @@ __wt_block_extlist_write(WT_SESSION_IMPL *session, uint32_t entries; uint8_t *p; - if (WT_VERBOSE_ISSET(session, block)) + if (WT_VERBOSE_ISSET(session, WT_VERB_BLOCK)) WT_RET(__block_extlist_dump(session, "write extlist", el, 0)); /* @@ -1264,9 +1265,9 @@ __wt_block_extlist_write(WT_SESSION_IMPL *session, WT_TRET(__wt_block_off_remove_overlap( session, &block->live.alloc, el->offset, el->size)); - WT_VERBOSE_ERR(session, block, + WT_ERR(__wt_verbose(session, WT_VERB_BLOCK, "%s written %" PRIdMAX "/%" PRIu32, - el->name, (intmax_t)el->offset, el->size); + el->name, (intmax_t)el->offset, el->size)); err: __wt_scr_free(&tmp); return (ret); @@ -1295,9 +1296,9 @@ __wt_block_extlist_truncate( if (ext->off + ext->size != fh->size) return (0); - WT_VERBOSE_RET(session, block, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "truncate file from %" PRIdMAX " to %" PRIdMAX, - (intmax_t)fh->size, (intmax_t)ext->off); + (intmax_t)fh->size, (intmax_t)ext->off)); /* * We're about to remove the extent list entry, save the value, we need @@ -1371,30 +1372,31 @@ __block_extlist_dump( WT_EXT *ext; WT_SIZE *szp; - WT_RET(__wt_verbose( - session, "%s: %s: %" PRIu64 " bytes, by offset:%s", + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, + "%s: %s: %" PRIu64 " bytes, by offset:%s", tag, el->name, el->bytes, el->entries == 0 ? " [Empty]" : "")); if (el->entries == 0) return (0); WT_EXT_FOREACH(ext, el->off) - WT_RET(__wt_verbose(session, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "\t{%" PRIuMAX "/%" PRIuMAX "}", (uintmax_t)ext->off, (uintmax_t)ext->size)); if (!show_size) return (0); - WT_RET(__wt_verbose(session, "%s: %s: by size:%s", + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, + "%s: %s: by size:%s", tag, el->name, el->entries == 0 ? " [Empty]" : "")); if (el->entries == 0) return (0); WT_EXT_FOREACH(szp, el->sz) { - WT_RET(__wt_verbose(session, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "\t{%" PRIuMAX "}", (uintmax_t)szp->size)); WT_EXT_FOREACH_OFF(ext, szp->off) - WT_RET(__wt_verbose(session, + WT_RET(__wt_verbose(session, WT_VERB_BLOCK, "\t\t{%" PRIuMAX "/%" PRIuMAX "}", (uintmax_t)ext->off, (uintmax_t)ext->size)); } diff --git a/src/block/block_open.c b/src/block/block_open.c index 23e69027718..12a2da119f8 100644 --- a/src/block/block_open.c +++ b/src/block/block_open.c @@ -102,7 +102,7 @@ __wt_block_open(WT_SESSION_IMPL *session, WT_CONNECTION_IMPL *conn; WT_DECL_RET; - WT_VERBOSE_TRET(session, block, "open: %s", filename); + WT_TRET(__wt_verbose(session, WT_VERB_BLOCK, "open: %s", filename)); conn = S2C(session); *blockp = NULL; @@ -198,8 +198,8 @@ __wt_block_close(WT_SESSION_IMPL *session, WT_BLOCK *block) conn = S2C(session); - WT_VERBOSE_TRET(session, - block, "close: %s", block->name == NULL ? "" : block->name ); + WT_TRET(__wt_verbose(session, WT_VERB_BLOCK, + "close: %s", block->name == NULL ? "" : block->name )); __wt_spin_lock(session, &conn->block_lock); @@ -262,13 +262,13 @@ __desc_read(WT_SESSION_IMPL *session, WT_BLOCK *block) session, block->fh, (off_t)0, (size_t)block->allocsize, buf->mem)); desc = buf->mem; - WT_VERBOSE_ERR(session, block, + WT_ERR(__wt_verbose(session, WT_VERB_BLOCK, "%s: magic %" PRIu32 ", major/minor: %" PRIu32 "/%" PRIu32 ", checksum %#" PRIx32, block->name, desc->magic, desc->majorv, desc->minorv, - desc->cksum); + desc->cksum)); /* * We fail the open if the checksum fails, or the magic number is wrong diff --git a/src/block/block_read.c b/src/block/block_read.c index 7ebe451f4ff..278c35eb0e3 100644 --- a/src/block/block_read.c +++ b/src/block/block_read.c @@ -168,9 +168,9 @@ __wt_block_read_off(WT_SESSION_IMPL *session, size_t bufsize; uint32_t page_cksum; - WT_VERBOSE_RET(session, read, + WT_RET(__wt_verbose(session, WT_VERB_READ, "off %" PRIuMAX ", size %" PRIu32 ", cksum %" PRIu32, - (uintmax_t)offset, size, cksum); + (uintmax_t)offset, size, cksum)); /* * Grow the buffer as necessary and read the block. Buffers should be diff --git a/src/block/block_slvg.c b/src/block/block_slvg.c index e54ee2519cd..8dd7a21fbc6 100644 --- a/src/block/block_slvg.c +++ b/src/block/block_slvg.c @@ -142,9 +142,9 @@ __wt_block_salvage_next(WT_SESSION_IMPL *session, session, block, tmp, offset, size, cksum) == 0) break; -skip: WT_VERBOSE_ERR(session, salvage, +skip: WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "skipping %" PRIu32 "B at file offset %" PRIuMAX, - allocsize, (uintmax_t)offset); + allocsize, (uintmax_t)offset)); /* Free the allocation-size block. */ WT_ERR(__wt_block_off_free( diff --git a/src/block/block_vrfy.c b/src/block/block_vrfy.c index 3ecfdf9842d..4b299419bd8 100644 --- a/src/block/block_vrfy.c +++ b/src/block/block_vrfy.c @@ -328,13 +328,12 @@ __verify_filefrag_add(WT_SESSION_IMPL *session, WT_BLOCK *block, { uint64_t f, frag, frags, i; - WT_UNUSED(type); /* If verbose is disabled */ - WT_VERBOSE_RET(session, verify, + WT_RET(__wt_verbose(session, WT_VERB_VERIFY, "add file block%s%s%s at %" PRIuMAX "-%" PRIuMAX " (%" PRIuMAX ")", type == NULL ? "" : " (", type == NULL ? "" : type, type == NULL ? "" : ")", - (uintmax_t)offset, (uintmax_t)(offset + size), (uintmax_t)size); + (uintmax_t)offset, (uintmax_t)(offset + size), (uintmax_t)size)); /* Check each chunk against the total file size. */ if (offset + size > block->fh->size) @@ -406,7 +405,7 @@ __verify_filefrag_chk(WT_SESSION_IMPL *session, WT_BLOCK *block) __bit_set(block->fragfile, last); } - if (!WT_VERBOSE_ISSET(session, verify)) + if (!WT_VERBOSE_ISSET(session, WT_VERB_VERIFY)) continue; __wt_errx(session, @@ -432,9 +431,9 @@ __verify_ckptfrag_add( { uint64_t f, frag, frags, i; - WT_VERBOSE_RET(session, verify, + WT_RET(__wt_verbose(session, WT_VERB_VERIFY, "add checkpoint block at %" PRIuMAX "-%" PRIuMAX " (%" PRIuMAX ")", - (uintmax_t)offset, (uintmax_t)(offset + size), (uintmax_t)size); + (uintmax_t)offset, (uintmax_t)(offset + size), (uintmax_t)size)); /* * Check each chunk against the checkpoint's size, a checkpoint should @@ -497,7 +496,7 @@ __verify_ckptfrag_chk(WT_SESSION_IMPL *session, WT_BLOCK *block) __bit_clear(block->fragckpt, last); } - if (!WT_VERBOSE_ISSET(session, verify)) + if (!WT_VERBOSE_ISSET(session, WT_VERB_VERIFY)) continue; __wt_errx(session, diff --git a/src/block/block_write.c b/src/block/block_write.c index 62f87226177..acb01601d87 100644 --- a/src/block/block_write.c +++ b/src/block/block_write.c @@ -241,9 +241,9 @@ __wt_block_write_off(WT_SESSION_IMPL *session, WT_BLOCK *block, WT_STAT_FAST_CONN_INCR(session, block_write); WT_STAT_FAST_CONN_INCRV(session, block_byte_write, align_size); - WT_VERBOSE_RET(session, write, + WT_RET(__wt_verbose(session, WT_VERB_WRITE, "off %" PRIuMAX ", size %" PRIuMAX ", cksum %" PRIu32, - (uintmax_t)offset, (uintmax_t)align_size, blk->cksum); + (uintmax_t)offset, (uintmax_t)align_size, blk->cksum)); *offsetp = offset; *sizep = WT_STORE_SIZE(align_size); diff --git a/src/btree/bt_evict.c b/src/btree/bt_evict.c index c4ade741c19..34a71e8bad2 100644 --- a/src/btree/bt_evict.c +++ b/src/btree/bt_evict.c @@ -129,12 +129,12 @@ __wt_evict_server_wake(WT_SESSION_IMPL *session) conn = S2C(session); cache = conn->cache; - if (WT_VERBOSE_ISSET(session, evictserver)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_EVICTSERVER)) { uint64_t bytes_inuse, bytes_max; bytes_inuse = __wt_cache_bytes_inuse(cache); bytes_max = conn->cache_size; - WT_RET(__wt_verbose(session, + WT_RET(__wt_verbose(session, WT_VERB_EVICTSERVER, "waking, bytes inuse %s max (%" PRIu64 "MB %s %" PRIu64 "MB)", bytes_inuse <= bytes_max ? "<=" : ">", @@ -184,16 +184,17 @@ __wt_cache_evict_server(void *arg) break; F_CLR(cache, WT_EVICT_ACTIVE); - WT_VERBOSE_ERR(session, evictserver, "sleeping"); + WT_ERR(__wt_verbose(session, WT_VERB_EVICTSERVER, "sleeping")); /* Don't rely on signals: check periodically. */ WT_ERR_TIMEDOUT_OK( __wt_cond_wait(session, cache->evict_cond, 100000)); - WT_VERBOSE_ERR(session, evictserver, "waking"); + WT_ERR(__wt_verbose(session, WT_VERB_EVICTSERVER, "waking")); } - WT_VERBOSE_ERR(session, evictserver, "exiting"); + WT_ERR(__wt_verbose(session, WT_VERB_EVICTSERVER, "exiting")); -err: WT_VERBOSE_TRET(session, evictserver, "waiting for helper threads"); +err: WT_TRET(__wt_verbose( + session, WT_VERB_EVICTSERVER, "waiting for helper threads")); for (i = 0; i < cache->eviction_workers; i++) { WT_TRET(__wt_cond_signal(session, cache->evict_waiter_cond)); WT_TRET(__wt_thread_join(session, workers[i].tid)); @@ -251,12 +252,14 @@ __evict_worker(void *arg) WT_ERR(__wt_open_session(conn, 1, NULL, NULL, &session)); while (F_ISSET(conn, WT_CONN_EVICTION_RUN)) { - WT_VERBOSE_ERR(session, evictserver, "worker sleeping"); + WT_ERR(__wt_verbose( + session, WT_VERB_EVICTSERVER, "worker sleeping")); WT_ERR( __wt_cond_wait(session, cache->evict_waiter_cond, 100000)); if (!F_ISSET(conn, WT_CONN_EVICTION_RUN)) break; - WT_VERBOSE_ERR(session, evictserver, "worker waking"); + WT_ERR(__wt_verbose( + session, WT_VERB_EVICTSERVER, "worker waking")); WT_ERR(__evict_lru_pages(session, 1)); } @@ -265,7 +268,7 @@ __evict_worker(void *arg) err: __wt_err(session, ret, "cache eviction helper error"); } - WT_VERBOSE_TRET(session, evictserver, "helper exiting"); + WT_TRET(__wt_verbose(session, WT_VERB_EVICTSERVER, "helper exiting")); if (session != conn->default_session) (void)session->iface.close(&session->iface, NULL); @@ -322,10 +325,10 @@ __evict_pass(WT_SESSION_IMPL *session) break; F_SET(cache, WT_EVICT_ACTIVE); - WT_VERBOSE_RET(session, evictserver, + WT_RET(__wt_verbose(session, WT_VERB_EVICTSERVER, "Eviction pass with: Max: %" PRIu64 " In use: %" PRIu64 " Dirty: %" PRIu64, - bytes_max, bytes_inuse, dirty_inuse); + bytes_max, bytes_inuse, dirty_inuse)); /* * When the cache is full, track whether pages are being @@ -351,8 +354,9 @@ __evict_pass(WT_SESSION_IMPL *session) F_SET(cache, WT_EVICT_STUCK); WT_STAT_FAST_CONN_INCR( session, cache_eviction_slow); - WT_VERBOSE_RET(session, evictserver, - "unable to reach eviction goal"); + WT_RET(__wt_verbose( + session, WT_VERB_EVICTSERVER, + "unable to reach eviction goal")); break; } } else @@ -926,8 +930,8 @@ __evict_walk_file(WT_SESSION_IMPL *session, u_int *slotp, uint32_t flags) __evict_init_candidate(session, evict, btree->evict_ref); ++evict; - WT_VERBOSE_RET(session, evictserver, - "select: %p, size %" PRIu64, page, page->memory_footprint); + WT_RET(__wt_verbose(session, WT_VERB_EVICTSERVER, + "select: %p, size %" PRIu64, page, page->memory_footprint)); } /* If the walk was interrupted by a locked page, that's okay. */ diff --git a/src/btree/bt_handle.c b/src/btree/bt_handle.c index 4dfd615d223..686ff70c31d 100644 --- a/src/btree/bt_handle.c +++ b/src/btree/bt_handle.c @@ -179,6 +179,7 @@ __btree_conf(WT_SESSION_IMPL *session, WT_CKPT *ckpt) WT_CONFIG_ITEM cval; WT_CONNECTION_IMPL *conn; WT_NAMED_COMPRESSOR *ncomp; + int64_t maj_version, min_version; uint32_t bitcnt; int fixed; const char **cfg; @@ -188,19 +189,14 @@ __btree_conf(WT_SESSION_IMPL *session, WT_CKPT *ckpt) cfg = btree->dhandle->cfg; /* Dump out format information. */ -#ifdef HAVE_VERBOSE - { - int64_t maj_version, min_version; - if (WT_VERBOSE_ISSET(session, version)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_VERSION)) { WT_RET(__wt_config_gets(session, cfg, "version.major", &cval)); maj_version = cval.val; WT_RET(__wt_config_gets(session, cfg, "version.minor", &cval)); min_version = cval.val; - WT_VERBOSE_RET(session, version, - "%" PRIu64 ".%" PRIu64, maj_version, min_version); - } + WT_RET(__wt_verbose(session, WT_VERB_VERSION, + "%" PRIu64 ".%" PRIu64, maj_version, min_version)); } -#endif /* Get the file ID. */ WT_RET(__wt_config_gets(session, cfg, "id", &cval)); diff --git a/src/btree/bt_read.c b/src/btree/bt_read.c index 4352ba92931..37ff7f1737c 100644 --- a/src/btree/bt_read.c +++ b/src/btree/bt_read.c @@ -67,8 +67,8 @@ __wt_cache_read(WT_SESSION_IMPL *session, WT_REF *ref) WT_ERR(__wt_delete_page_instantiate(session, ref)); } - WT_VERBOSE_ERR(session, read, - "page %p: %s", page, __wt_page_type_string(page->type)); + WT_ERR(__wt_verbose(session, WT_VERB_READ, + "page %p: %s", page, __wt_page_type_string(page->type))); WT_PUBLISH(ref->state, WT_REF_MEM); return (0); diff --git a/src/btree/bt_slvg.c b/src/btree/bt_slvg.c index 3e461a03584..628eaa44c75 100644 --- a/src/btree/bt_slvg.c +++ b/src/btree/bt_slvg.c @@ -361,10 +361,10 @@ __slvg_read(WT_SESSION_IMPL *session, WT_STUFF *ss) case WT_PAGE_BLOCK_MANAGER: case WT_PAGE_COL_INT: case WT_PAGE_ROW_INT: - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s page ignored %s", __wt_page_type_string(dsk->type), - (const char *)as->data); + (const char *)as->data)); WT_ERR(bm->free(bm, session, addr, addr_size)); continue; } @@ -379,18 +379,18 @@ __slvg_read(WT_SESSION_IMPL *session, WT_STUFF *ss) * discard these pages now. */ if (__wt_verify_dsk(session, as->data, buf) != 0) { - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s page failed verify %s", __wt_page_type_string(dsk->type), - (const char *)as->data); + (const char *)as->data)); WT_ERR(bm->free(bm, session, addr, addr_size)); continue; } - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "tracking %s page, generation %" PRIu64 " %s", __wt_page_type_string(dsk->type), dsk->write_gen, - (const char *)as->data); + (const char *)as->data)); switch (dsk->type) { case WT_PAGE_COL_FIX: @@ -491,11 +491,11 @@ __slvg_trk_leaf(WT_SESSION_IMPL *session, trk->col_start = dsk->recno; trk->col_stop = dsk->recno + (dsk->u.entries - 1); - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s records %" PRIu64 "-%" PRIu64, __wt_addr_string( session, trk->addr.addr, trk->addr.size, ss->tmp1), - trk->col_start, trk->col_stop); + trk->col_start, trk->col_stop)); break; case WT_PAGE_COL_VAR: /* @@ -512,11 +512,11 @@ __slvg_trk_leaf(WT_SESSION_IMPL *session, trk->col_start = dsk->recno; trk->col_stop = stop_recno - 1; - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s records %" PRIu64 "-%" PRIu64, __wt_addr_string( session, trk->addr.addr, trk->addr.size, ss->tmp1), - trk->col_start, trk->col_stop); + trk->col_start, trk->col_stop)); /* Column-store pages can contain overflow items. */ WT_ERR(__slvg_trk_leaf_ovfl(session, dsk, trk)); @@ -536,21 +536,21 @@ __slvg_trk_leaf(WT_SESSION_IMPL *session, WT_ERR(__wt_row_leaf_key_copy(session, page, &page->pg_row_d[page->pg_row_entries - 1], &trk->row_stop)); - if (WT_VERBOSE_ISSET(session, salvage)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_SALVAGE)) { WT_ERR(__wt_buf_set_printable(session, ss->tmp1, trk->row_start.data, trk->row_start.size)); - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s start key %.*s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, ss->tmp2), - (int)ss->tmp1->size, (char *)ss->tmp1->data); + (int)ss->tmp1->size, (char *)ss->tmp1->data)); WT_ERR(__wt_buf_set_printable(session, ss->tmp1, trk->row_stop.data, trk->row_stop.size)); - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s stop key %.*s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, ss->tmp2), - (int)ss->tmp1->size, (char *)ss->tmp1->data); + (int)ss->tmp1->size, (char *)ss->tmp1->data)); } /* Row-store pages can contain overflow items. */ @@ -631,12 +631,12 @@ __slvg_trk_leaf_ovfl( unpack->size, &trk->ovfl[ovfl_cnt].addr)); trk->ovfl[ovfl_cnt].size = (uint8_t)unpack->size; - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s overflow reference %s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), __wt_addr_string(session, - unpack->data, unpack->size,trk->ss->tmp2)); + unpack->data, unpack->size,trk->ss->tmp2))); if (++ovfl_cnt == trk->ovfl_cnt) break; @@ -800,12 +800,12 @@ __slvg_col_range_overlap( a_trk = ss->pages[a_slot]; b_trk = ss->pages[b_slot]; - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s and %s range overlap", __wt_addr_string( session, a_trk->addr.addr, a_trk->addr.size, ss->tmp1), __wt_addr_string( - session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2)); + session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2))); /* * The key ranges of two WT_TRACK pages in the array overlap -- choose @@ -960,12 +960,12 @@ delete: WT_RET(__slvg_trk_free(session, a_trk->col_stop = b_trk->col_start - 1; F_SET(a_trk, WT_TRACK_MERGE); -merge: WT_VERBOSE_RET(session, salvage, +merge: WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s and %s require merge", __wt_addr_string( session, a_trk->addr.addr, a_trk->addr.size, ss->tmp1), __wt_addr_string( - session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2)); + session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2))); return (0); } @@ -1021,18 +1021,16 @@ __slvg_col_range_missing(WT_SESSION_IMPL *session, WT_STUFF *ss) uint64_t r; uint32_t i; - WT_UNUSED(session); /* Required if verbose is disabled */ - for (i = 0, r = 0; i < ss->pages_next; ++i) { if ((trk = ss->pages[i]) == NULL) continue; if (trk->col_start != r + 1) { - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s column-store missing range from %" PRIu64 " to %" PRIu64 " inclusive", __wt_addr_string(session, trk->addr.addr, trk->addr.size, ss->tmp1), - r + 1, trk->col_start - 1); + r + 1, trk->col_start - 1)); /* * We need to instantiate deleted items for the missing @@ -1164,12 +1162,12 @@ __slvg_col_build_leaf(WT_SESSION_IMPL *session, WT_TRACK *trk, WT_REF *ref) cookie->skip = skip = trk->col_start - page->pg_var_recno; cookie->take = take = (trk->col_stop - trk->col_start) + 1; - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge discarding first %" PRIu64 " records, " "then taking %" PRIu64 " records", __wt_addr_string( session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), - skip, take); + skip, take)); /* * Discard backing overflow pages for any items being discarded that @@ -1189,11 +1187,11 @@ __slvg_col_build_leaf(WT_SESSION_IMPL *session, WT_TRACK *trk, WT_REF *ref) page->pg_var_recno = trk->col_missing; cookie->missing = trk->col_start - trk->col_missing; - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge inserting %" PRIu64 " missing records", __wt_addr_string( session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), - cookie->missing); + cookie->missing)); } ref->key.recno = page->pg_var_recno; @@ -1244,7 +1242,6 @@ __slvg_col_merge_ovfl(WT_SESSION_IMPL *session, uint64_t recno, start, stop; uint32_t i; - WT_UNUSED(trk); /* Required if verbose is disabled */ bm = S2BT(session)->bm; unpack = &_unpack; @@ -1262,12 +1259,12 @@ __slvg_col_merge_ovfl(WT_SESSION_IMPL *session, if (recno >= start && recno <= stop) continue; - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge discard freed overflow reference %s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), __wt_addr_string(session, - unpack->data, unpack->size, trk->ss->tmp2)); + unpack->data, unpack->size, trk->ss->tmp2))); WT_RET(bm->free(bm, session, unpack->data, unpack->size)); } @@ -1360,12 +1357,12 @@ __slvg_row_range_overlap( a_trk = ss->pages[a_slot]; b_trk = ss->pages[b_slot]; - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s and %s range overlap", __wt_addr_string( session, a_trk->addr.addr, a_trk->addr.size, ss->tmp1), __wt_addr_string( - session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2)); + session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2))); /* * The key ranges of two WT_TRACK pages in the array overlap -- choose @@ -1538,12 +1535,12 @@ delete: WT_RET(__slvg_trk_free(session, WT_RET(__slvg_key_copy(session, A_TRK_STOP, B_TRK_START)); F_SET(a_trk, WT_TRACK_CHECK_STOP | WT_TRACK_MERGE); -merge: WT_VERBOSE_RET(session, salvage, +merge: WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s and %s require merge", __wt_addr_string( session, a_trk->addr.addr, a_trk->addr.size, ss->tmp1), __wt_addr_string( - session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2)); + session, b_trk->addr.addr, b_trk->addr.size, ss->tmp2))); return (0); } @@ -1777,15 +1774,15 @@ __slvg_row_build_leaf( btree->collator, key, &trk->row_start, cmp)); if (cmp >= 0) break; - if (WT_VERBOSE_ISSET(session, salvage)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_SALVAGE)) { WT_ERR(__wt_buf_set_printable(session, ss->tmp1, key->data, key->size)); - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge discarding leading key %.*s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, ss->tmp2), (int)ss->tmp1->size, - (char *)ss->tmp1->data); + (char *)ss->tmp1->data)); } ++skip_start; } @@ -1801,15 +1798,15 @@ __slvg_row_build_leaf( btree->collator, key, &trk->row_stop, cmp)); if (cmp < 0) break; - if (WT_VERBOSE_ISSET(session, salvage)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_SALVAGE)) { WT_ERR(__wt_buf_set_printable(session, ss->tmp1, key->data, key->size)); - WT_VERBOSE_ERR(session, salvage, + WT_ERR(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge discarding trailing key %.*s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, ss->tmp2), (int)ss->tmp1->size, - (char *)ss->tmp1->data); + (char *)ss->tmp1->data)); } ++skip_stop; } @@ -1908,8 +1905,6 @@ __slvg_row_merge_ovfl(WT_SESSION_IMPL *session, WT_IKEY *ikey; WT_ROW *rip; - WT_UNUSED(trk); /* Required if verbose is disabled */ - bm = S2BT(session)->bm; unpack = &_unpack; @@ -1921,12 +1916,12 @@ __slvg_row_merge_ovfl(WT_SESSION_IMPL *session, cell = (WT_CELL *)ikey; __wt_cell_unpack(cell, unpack); if (unpack->type == WT_CELL_KEY_OVFL) { - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge discard freed overflow reference %s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), __wt_addr_string(session, - unpack->data, unpack->size, trk->ss->tmp2)); + unpack->data, unpack->size, trk->ss->tmp2))); WT_RET(bm->free( bm, session, unpack->data, unpack->size)); @@ -1936,12 +1931,12 @@ __slvg_row_merge_ovfl(WT_SESSION_IMPL *session, continue; __wt_cell_unpack(cell, unpack); if (unpack->type == WT_CELL_VALUE_OVFL) { - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s merge discard freed overflow reference %s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), __wt_addr_string(session, - unpack->data, unpack->size, trk->ss->tmp2)); + unpack->data, unpack->size, trk->ss->tmp2))); WT_RET(bm->free( bm, session, unpack->data, unpack->size)); @@ -2076,12 +2071,12 @@ __slvg_ovfl_reconcile(WT_SESSION_IMPL *session, WT_STUFF *ss) sizeof(WT_TRACK *), __slvg_ovfl_compare); F_CLR(*searchp, WT_TRACK_OVFL_REFD); } - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s references unavailable overflow page %s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, ss->tmp1), __wt_addr_string(session, - addr->addr, addr->size, ss->tmp2)); + addr->addr, addr->size, ss->tmp2))); WT_RET(__slvg_trk_free( session, &ss->pages[i], WT_TRK_FREE_BLOCKS)); break; @@ -2213,10 +2208,10 @@ __slvg_ovfl_discard(WT_SESSION_IMPL *session, WT_STUFF *ss) for (i = 0; i < ss->ovfl_next; ++i) { if (F_ISSET(ss->ovfl[i], WT_TRACK_OVFL_REFD)) continue; - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s unused overflow page", __wt_addr_string(session, - ss->ovfl[i]->addr.addr, ss->ovfl[i]->addr.size,ss->tmp1)); + ss->ovfl[i]->addr.addr, ss->ovfl[i]->addr.size,ss->tmp1))); WT_RET(__slvg_trk_free( session, &ss->ovfl[i], WT_TRK_FREE_BLOCKS)); } @@ -2270,11 +2265,11 @@ __slvg_trk_free(WT_SESSION_IMPL *session, WT_TRACK **trkp, uint32_t flags) * verbose description. */ if (LF_ISSET(WT_TRK_FREE_BLOCKS)) { - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s page discarded: discard freed file bytes %" PRIu32, __wt_addr_string( session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), - trk->size); + trk->size)); WT_RET(bm->free(bm, session, trk->addr.addr, trk->addr.size)); } __wt_free(session, trk->addr.addr); @@ -2282,12 +2277,12 @@ __slvg_trk_free(WT_SESSION_IMPL *session, WT_TRACK **trkp, uint32_t flags) for (i = 0; i < trk->ovfl_cnt; ++i) { addr = &trk->ovfl[i]; if (LF_ISSET(WT_TRK_FREE_OVFL)) { - WT_VERBOSE_RET(session, salvage, + WT_RET(__wt_verbose(session, WT_VERB_SALVAGE, "%s page discarded: discard freed overflow page %s", __wt_addr_string(session, trk->addr.addr, trk->addr.size, trk->ss->tmp1), __wt_addr_string(session, - addr->addr, addr->size, trk->ss->tmp2)); + addr->addr, addr->size, trk->ss->tmp2))); WT_RET(bm->free(bm, session, addr->addr, addr->size)); } __wt_free(session, addr->addr); diff --git a/src/btree/bt_sync.c b/src/btree/bt_sync.c index 2f3ad8d6fc5..84e5261310e 100644 --- a/src/btree/bt_sync.c +++ b/src/btree/bt_sync.c @@ -31,7 +31,7 @@ __sync_file(WT_SESSION_IMPL *session, int syncop) internal_bytes = leaf_bytes = 0; internal_pages = leaf_pages = 0; - if (WT_VERBOSE_ISSET(session, checkpoint)) + if (WT_VERBOSE_ISSET(session, WT_VERB_CHECKPOINT)) WT_ERR(__wt_epoch(session, &start)); switch (syncop) { @@ -137,9 +137,9 @@ __sync_file(WT_SESSION_IMPL *session, int syncop) WT_ILLEGAL_VALUE_ERR(session); } - if (WT_VERBOSE_ISSET(session, checkpoint)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_CHECKPOINT)) { WT_ERR(__wt_epoch(session, &end)); - WT_VERBOSE_ERR(session, checkpoint, + WT_ERR(__wt_verbose(session, WT_VERB_CHECKPOINT, "__sync_file WT_SYNC_%s wrote:\n\t %" PRIu64 " bytes, %" PRIu64 " pages of leaves\n\t %" PRIu64 " bytes, %" PRIu64 " pages of internal\n\t" @@ -147,7 +147,7 @@ __sync_file(WT_SESSION_IMPL *session, int syncop) syncop == WT_SYNC_WRITE_LEAVES ? "WRITE_LEAVES" : "CHECKPOINT", leaf_bytes, leaf_pages, internal_bytes, internal_pages, - WT_TIMEDIFF(end, start) / WT_MILLION); + WT_TIMEDIFF(end, start) / WT_MILLION)); } err: /* On error, clear any left-over tree walk. */ diff --git a/src/btree/bt_vrfy.c b/src/btree/bt_vrfy.c index 703213d9655..ab1f8f89d8d 100644 --- a/src/btree/bt_vrfy.c +++ b/src/btree/bt_vrfy.c @@ -86,8 +86,8 @@ __wt_verify(WT_SESSION_IMPL *session, const char *cfg[]) /* Loop through the file's checkpoints, verifying each one. */ WT_CKPT_FOREACH(ckptbase, ckpt) { - WT_VERBOSE_ERR(session, verify, - "%s: checkpoint %s", btree->dhandle->name, ckpt->name); + WT_ERR(__wt_verbose(session, WT_VERB_VERIFY, + "%s: checkpoint %s", btree->dhandle->name, ckpt->name)); /* Fake checkpoints require no work. */ if (F_ISSET(ckpt, WT_CKPT_FAKE)) @@ -260,9 +260,9 @@ __verify_tree(WT_SESSION_IMPL *session, WT_REF *ref, WT_VSTUFF *vs) unpack = &_unpack; WT_CLEAR(*unpack); /* -Wuninitialized */ - WT_VERBOSE_RET(session, verify, "%s %s", + WT_RET(__wt_verbose(session, WT_VERB_VERIFY, "%s %s", __wt_page_addr_string(session, ref, vs->tmp1), - __wt_page_type_string(page->type)); + __wt_page_type_string(page->type))); #ifdef HAVE_DIAGNOSTIC if (vs->dump_address) WT_RET(__wt_msg(session, "%s %s", diff --git a/src/btree/rec_evict.c b/src/btree/rec_evict.c index a1b4e5b9ed1..e373a2905eb 100644 --- a/src/btree/rec_evict.c +++ b/src/btree/rec_evict.c @@ -30,8 +30,8 @@ __wt_rec_evict(WT_SESSION_IMPL *session, WT_REF *ref, int exclusive) page = ref->page; istree = 0; - WT_VERBOSE_RET(session, evict, - "page %p (%s)", page, __wt_page_type_string(page->type)); + WT_RET(__wt_verbose(session, WT_VERB_EVICT, + "page %p (%s)", page, __wt_page_type_string(page->type))); /* * Pin the oldest transaction ID: eviction looks at page structures @@ -460,7 +460,7 @@ __hazard_exclusive(WT_SESSION_IMPL *session, WT_REF *ref, int top) WT_STAT_FAST_DATA_INCR(session, cache_eviction_hazard); WT_STAT_FAST_CONN_INCR(session, cache_eviction_hazard); - WT_VERBOSE_RET( - session, evict, "page %p hazard request failed", ref->page); + WT_RET(__wt_verbose(session, WT_VERB_EVICT, + "page %p hazard request failed", ref->page)); return (EBUSY); } diff --git a/src/btree/rec_split.c b/src/btree/rec_split.c index 68e429fa921..436bcbc1c9d 100644 --- a/src/btree/rec_split.c +++ b/src/btree/rec_split.c @@ -211,9 +211,9 @@ __split_deepen(WT_SESSION_IMPL *session, WT_PAGE *parent) __split_deepen_min_child); WT_STAT_FAST_CONN_INCR(session, cache_eviction_deepen); - WT_VERBOSE_ERR(session, split, + WT_ERR(__wt_verbose(session, WT_VERB_SPLIT, "%p: %" PRIu32 " elements, splitting into %" PRIu32 " children", - parent, pindex->entries, children); + parent, pindex->entries, children)); /* * If the workload is prepending/appending to the tree, we could deepen @@ -797,11 +797,11 @@ __wt_split_evict(WT_SESSION_IMPL *session, WT_REF *ref, int exclusive) __wt_cache_page_inmem_decr(session, parent, parent_decr); WT_STAT_FAST_CONN_INCR(session, cache_eviction_split); - WT_VERBOSE_ERR(session, split, + WT_ERR(__wt_verbose(session, WT_VERB_SPLIT, "%p: %s split into parent %p %" PRIu32 " -> %" PRIu32 " (%" PRIu32 ")", child, __wt_page_type_string(child->type), parent, parent_entries, - result_entries, result_entries - parent_entries); + result_entries, result_entries - parent_entries)); /* * Simple page splits trickle up the tree, that is, as leaf pages grow diff --git a/src/btree/rec_track.c b/src/btree/rec_track.c index f3a5d043ff0..1ed9127bdb3 100644 --- a/src/btree/rec_track.c +++ b/src/btree/rec_track.c @@ -24,33 +24,6 @@ __ovfl_track_init(WT_SESSION_IMPL *session, WT_PAGE *page) return (__wt_calloc_def(session, 1, &page->modify->ovfl_track)); } -#ifndef HAVE_VERBOSE -#define OVFL_VERBOSE_DISCARD(s, p, c, t) -#define OVFL_VERBOSE_REUSE(s, p, r, t) do { \ - WT_UNUSED((s)); \ -} while (0) -#define OVFL_VERBOSE_TXNC(s, p, txn, t) -#else -static int __ovfl_discard_verbose( - WT_SESSION_IMPL *, WT_PAGE *, WT_CELL *, const char *); -static int __ovfl_reuse_verbose( - WT_SESSION_IMPL *, WT_PAGE *, WT_OVFL_REUSE *, const char *); -static int __ovfl_txnc_verbose( - WT_SESSION_IMPL *, WT_PAGE *, WT_OVFL_TXNC *, const char *); - -#define OVFL_VERBOSE_DISCARD(s, p, c, t) do { \ - if (WT_VERBOSE_ISSET((s), overflow)) \ - WT_RET(__ovfl_discard_verbose((s), (p), (c), (t))); \ -} while (0) -#define OVFL_VERBOSE_REUSE(s, p, r, t) do { \ - if (WT_VERBOSE_ISSET((s), overflow)) \ - WT_RET(__ovfl_reuse_verbose((s), (p), (r), (t))); \ -} while (0) -#define OVFL_VERBOSE_TXNC(s, p, txn, t) do { \ - if (WT_VERBOSE_ISSET((s), overflow)) \ - WT_RET(__ovfl_txnc_verbose((s), (p), (txn), (t))); \ -} while (0) - /* * __ovfl_discard_verbose -- * Dump information about a discard overflow record. @@ -68,74 +41,16 @@ __ovfl_discard_verbose( unpack = &_unpack; __wt_cell_unpack(cell, unpack); - WT_VERBOSE_ERR(session, overflow, + WT_ERR(__wt_verbose(session, WT_VERB_OVERFLOW, "discard: %s%s%p %s", tag == NULL ? "" : tag, tag == NULL ? "" : ": ", page, - __wt_addr_string(session, unpack->data, unpack->size, tmp)); - -err: __wt_scr_free(&tmp); - return (ret); -} - -/* - * __ovfl_reuse_verbose -- - * Dump information about a reuse overflow record. - */ -static int -__ovfl_reuse_verbose(WT_SESSION_IMPL *session, - WT_PAGE *page, WT_OVFL_REUSE *reuse, const char *tag) -{ - WT_DECL_ITEM(tmp); - WT_DECL_RET; - - WT_RET(__wt_scr_alloc(session, 64, &tmp)); - - WT_VERBOSE_ERR(session, overflow, - "reuse: %s%s%p %s (%s%s%s) {%.*s}", - tag == NULL ? "" : tag, - tag == NULL ? "" : ": ", - page, - __wt_addr_string( - session, WT_OVFL_REUSE_ADDR(reuse), reuse->addr_size, tmp), - F_ISSET(reuse, WT_OVFL_REUSE_INUSE) ? "inuse" : "", - F_ISSET(reuse, WT_OVFL_REUSE_INUSE) && - F_ISSET(reuse, WT_OVFL_REUSE_JUST_ADDED) ? ", " : "", - F_ISSET(reuse, WT_OVFL_REUSE_JUST_ADDED) ? "just-added" : "", - WT_MIN(reuse->value_size, 40), (char *)WT_OVFL_REUSE_VALUE(reuse)); - -err: __wt_scr_free(&tmp); - return (ret); -} - -/* - * __ovfl_txnc_verbose -- - * Dump information about a transaction-cached overflow record. - */ -static int -__ovfl_txnc_verbose(WT_SESSION_IMPL *session, - WT_PAGE *page, WT_OVFL_TXNC *txnc, const char *tag) -{ - WT_DECL_ITEM(tmp); - WT_DECL_RET; - - WT_RET(__wt_scr_alloc(session, 64, &tmp)); - - WT_VERBOSE_ERR(session, overflow, - "txn-cache: %s%s%p %s %" PRIu64 " {%.*s}", - tag == NULL ? "" : tag, - tag == NULL ? "" : ": ", - page, - __wt_addr_string( - session, WT_OVFL_TXNC_ADDR(txnc), txnc->addr_size, tmp), - txnc->current, - WT_MIN(txnc->value_size, 40), (char *)WT_OVFL_TXNC_VALUE(txnc)); + __wt_addr_string(session, unpack->data, unpack->size, tmp))); err: __wt_scr_free(&tmp); return (ret); } -#endif #if 0 /* @@ -155,7 +70,7 @@ __ovfl_discard_dump(WT_SESSION_IMPL *session, WT_PAGE *page) track = page->modify->ovfl_track; for (i = 0, cellp = track->discard; i < track->discard_entries; ++i, ++cellp) - OVFL_VERBOSE_DISCARD(sssion, page, *cellp, "dump"); + (void)__ovfl_discard_verbose(session, page, *cellp, "dump"); } #endif @@ -174,10 +89,12 @@ __ovfl_discard_wrapup(WT_SESSION_IMPL *session, WT_PAGE *page) track = page->modify->ovfl_track; for (i = 0, cellp = track->discard; i < track->discard_entries; ++i, ++cellp) { - OVFL_VERBOSE_DISCARD(session, page, *cellp, "free"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET(__ovfl_discard_verbose( + session, page, *cellp, "free")); /* Discard each cell's overflow item. */ - WT_TRET(__wt_ovfl_discard(session, *cellp)); + WT_RET(__wt_ovfl_discard(session, *cellp)); } __wt_free(session, track->discard); @@ -221,7 +138,8 @@ __wt_ovfl_discard_add(WT_SESSION_IMPL *session, WT_PAGE *page, WT_CELL *cell) track->discard_entries + 1, &track->discard)); track->discard[track->discard_entries++] = cell; - OVFL_VERBOSE_DISCARD(session, page, cell, "add"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET(__ovfl_discard_verbose(session, page, cell, "add")); return (0); } @@ -244,6 +162,36 @@ __wt_ovfl_discard_free(WT_SESSION_IMPL *session, WT_PAGE *page) track->discard_entries = track->discard_allocated = 0; } +/* + * __ovfl_reuse_verbose -- + * Dump information about a reuse overflow record. + */ +static int +__ovfl_reuse_verbose(WT_SESSION_IMPL *session, + WT_PAGE *page, WT_OVFL_REUSE *reuse, const char *tag) +{ + WT_DECL_ITEM(tmp); + WT_DECL_RET; + + WT_RET(__wt_scr_alloc(session, 64, &tmp)); + + WT_ERR(__wt_verbose(session, WT_VERB_OVERFLOW, + "reuse: %s%s%p %s (%s%s%s) {%.*s}", + tag == NULL ? "" : tag, + tag == NULL ? "" : ": ", + page, + __wt_addr_string( + session, WT_OVFL_REUSE_ADDR(reuse), reuse->addr_size, tmp), + F_ISSET(reuse, WT_OVFL_REUSE_INUSE) ? "inuse" : "", + F_ISSET(reuse, WT_OVFL_REUSE_INUSE) && + F_ISSET(reuse, WT_OVFL_REUSE_JUST_ADDED) ? ", " : "", + F_ISSET(reuse, WT_OVFL_REUSE_JUST_ADDED) ? "just-added" : "", + WT_MIN(reuse->value_size, 40), (char *)WT_OVFL_REUSE_VALUE(reuse))); + +err: __wt_scr_free(&tmp); + return (ret); +} + #if 0 /* * __ovfl_reuse_dump -- @@ -259,7 +207,7 @@ __ovfl_reuse_dump(WT_SESSION_IMPL *session, WT_PAGE *page) head = page->modify->ovfl_track->ovfl_reuse; for (reuse = head[0]; reuse != NULL; reuse = reuse->next[0]) - OVFL_VERBOSE_REUSE(session, page, reuse, "dump"); + (void)__ovfl_reuse_verbose(session, page, reuse, "dump"); } #endif @@ -423,7 +371,9 @@ __ovfl_reuse_wrapup(WT_SESSION_IMPL *session, WT_PAGE *page) decr += WT_OVFL_SIZE(WT_OVFL_REUSE) + reuse->addr_size + reuse->value_size; - OVFL_VERBOSE_REUSE(session, page, reuse, "free"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET( + __ovfl_reuse_verbose(session, page, reuse, "free")); WT_RET(bm->free( bm, session, WT_OVFL_REUSE_ADDR(reuse), reuse->addr_size)); __wt_free(session, reuse); @@ -479,7 +429,9 @@ __ovfl_reuse_wrapup_err(WT_SESSION_IMPL *session, WT_PAGE *page) } *e = (*e)->next[0]; - OVFL_VERBOSE_REUSE(session, page, reuse, "free"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET( + __ovfl_reuse_verbose(session, page, reuse, "free")); WT_TRET(bm->free( bm, session, WT_OVFL_REUSE_ADDR(reuse), reuse->addr_size)); __wt_free(session, reuse); @@ -517,7 +469,8 @@ __wt_ovfl_reuse_search(WT_SESSION_IMPL *session, WT_PAGE *page, *addr_sizep = reuse->addr_size; F_SET(reuse, WT_OVFL_REUSE_INUSE); - OVFL_VERBOSE_REUSE(session, page, reuse, "reclaim"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET(__ovfl_reuse_verbose(session, page, reuse, "reclaim")); return (1); } @@ -575,7 +528,8 @@ __wt_ovfl_reuse_add(WT_SESSION_IMPL *session, WT_PAGE *page, *stack[i] = reuse; } - OVFL_VERBOSE_REUSE(session, page, reuse, "add"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET(__ovfl_reuse_verbose(session, page, reuse, "add")); return (0); } @@ -602,6 +556,33 @@ __wt_ovfl_reuse_free(WT_SESSION_IMPL *session, WT_PAGE *page) } } +/* + * __ovfl_txnc_verbose -- + * Dump information about a transaction-cached overflow record. + */ +static int +__ovfl_txnc_verbose(WT_SESSION_IMPL *session, + WT_PAGE *page, WT_OVFL_TXNC *txnc, const char *tag) +{ + WT_DECL_ITEM(tmp); + WT_DECL_RET; + + WT_RET(__wt_scr_alloc(session, 64, &tmp)); + + WT_ERR(__wt_verbose(session, WT_VERB_OVERFLOW, + "txn-cache: %s%s%p %s %" PRIu64 " {%.*s}", + tag == NULL ? "" : tag, + tag == NULL ? "" : ": ", + page, + __wt_addr_string( + session, WT_OVFL_TXNC_ADDR(txnc), txnc->addr_size, tmp), + txnc->current, + WT_MIN(txnc->value_size, 40), (char *)WT_OVFL_TXNC_VALUE(txnc))); + +err: __wt_scr_free(&tmp); + return (ret); +} + #if 0 /* * __ovfl_txnc_dump -- @@ -617,7 +598,7 @@ __ovfl_txnc_dump(WT_SESSION_IMPL *session, WT_PAGE *page) head = page->modify->ovfl_track->ovfl_txnc; for (txnc = head[0]; txnc != NULL; txnc = txnc->next[0]) - OVFL_VERBOSE_TXNC(session, page, txnc, "dump"); + (void)__ovfl_txnc_verbose(session, page, txnc, "dump"); } #endif @@ -746,7 +727,9 @@ __ovfl_txnc_wrapup(WT_SESSION_IMPL *session, WT_PAGE *page) decr += WT_OVFL_SIZE(WT_OVFL_TXNC) + txnc->addr_size + txnc->value_size; - OVFL_VERBOSE_TXNC(session, page, txnc, "free"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET( + __ovfl_txnc_verbose(session, page, txnc, "free")); __wt_free(session, txnc); } @@ -836,7 +819,8 @@ __wt_ovfl_txnc_add(WT_SESSION_IMPL *session, WT_PAGE *page, *stack[i] = txnc; } - OVFL_VERBOSE_TXNC(session, page, txnc, "add"); + if (WT_VERBOSE_ISSET(session, WT_VERB_OVERFLOW)) + WT_RET(__ovfl_txnc_verbose(session, page, txnc, "add")); return (0); } diff --git a/src/btree/rec_write.c b/src/btree/rec_write.c index 09de20a35d3..cd1d2944bd2 100644 --- a/src/btree/rec_write.c +++ b/src/btree/rec_write.c @@ -350,8 +350,8 @@ __wt_rec_write(WT_SESSION_IMPL *session, WT_RET_MSG(session, WT_ERROR, "Attempt to reconcile a clean page."); - WT_VERBOSE_RET( - session, reconcile, "%s", __wt_page_type_string(page->type)); + WT_RET(__wt_verbose(session, + WT_VERB_RECONCILE, "%s", __wt_page_type_string(page->type))); WT_STAT_FAST_CONN_INCR(session, rec_pages); WT_STAT_FAST_DATA_INCR(session, rec_pages); if (LF_ISSET(WT_EVICTION_LOCKED)) { @@ -479,8 +479,8 @@ __rec_root_write(WT_SESSION_IMPL *session, WT_PAGE *page, uint32_t flags) WT_ILLEGAL_VALUE(session); } - WT_VERBOSE_RET(session, split, - "root page split -> %" PRIu32 " pages", mod->mod_multi_entries); + WT_RET(__wt_verbose(session, WT_VERB_SPLIT, + "root page split -> %" PRIu32 " pages", mod->mod_multi_entries)); /* * Create a new root page, initialize the array of child references, @@ -4500,7 +4500,8 @@ __rec_write_wrapup(WT_SESSION_IMPL *session, WT_RECONCILE *r, WT_PAGE *page) switch (r->bnd_next) { case 0: /* Page delete */ - WT_VERBOSE_RET(session, reconcile, "page %p empty", page); + WT_RET(__wt_verbose( + session, WT_VERB_RECONCILE, "page %p empty", page)); WT_STAT_FAST_DATA_INCR(session, rec_page_delete); /* If this is the root page, we need to create a sync point. */ @@ -4547,9 +4548,9 @@ __rec_write_wrapup(WT_SESSION_IMPL *session, WT_RECONCILE *r, WT_PAGE *page) F_SET(mod, WT_PM_REC_REPLACE); break; default: /* Page split */ - WT_VERBOSE_RET(session, reconcile, + WT_RET(__wt_verbose(session, WT_VERB_RECONCILE, "page %p reconciled into %" PRIu32 " pages", - page, r->bnd_next); + page, r->bnd_next)); switch (page->type) { case WT_PAGE_COL_INT: @@ -4565,12 +4566,11 @@ __rec_write_wrapup(WT_SESSION_IMPL *session, WT_RECONCILE *r, WT_PAGE *page) WT_ILLEGAL_VALUE(session); } -#if 0 /* * Display the actual split keys: not turned on because it's a * lot of output and not generally useful. */ - if (WT_VERBOSE_ISSET(session, split)) { + if (WT_VERBOSE_ISSET(session, WT_VERB_SPLIT)) { WT_DECL_ITEM(tkey); WT_DECL_RET; uint32_t i; @@ -4585,25 +4585,26 @@ __rec_write_wrapup(WT_SESSION_IMPL *session, WT_RECONCILE *r, WT_PAGE *page) WT_ERR(__wt_buf_set_printable( session, tkey, bnd->key.data, bnd->key.size)); - WT_VERBOSE_ERR(session, split, + WT_ERR(__wt_verbose( + session, WT_VERB_SPLIT, "split: starting key " "%.*s", (int)tkey->size, - (const char *)tkey->data); + (const char *)tkey->data)); break; case WT_PAGE_COL_FIX: case WT_PAGE_COL_INT: case WT_PAGE_COL_VAR: - WT_VERBOSE_ERR(session, split, + WT_ERR(__wt_verbose( + session, WT_VERB_SPLIT, "split: starting recno %" PRIu64, - bnd->recno); + bnd->recno)); break; WT_ILLEGAL_VALUE_ERR(session); } err: __wt_scr_free(&tkey); WT_RET(ret); } -#endif if (r->bnd_next > r->bnd_next_max) { r->bnd_next_max = r->bnd_next; WT_STAT_FAST_DATA_SET( diff --git a/src/conn/conn_api.c b/src/conn/conn_api.c index 72a0658aa92..29db4ced7ef 100644 --- a/src/conn/conn_api.c +++ b/src/conn/conn_api.c @@ -962,27 +962,27 @@ __wt_conn_verbose_config(WT_SESSION_IMPL *session, const char *cfg[]) const char *name; uint32_t flag; } *ft, verbtypes[] = { - { "api", WT_VERB_api }, - { "block", WT_VERB_block }, - { "checkpoint", WT_VERB_checkpoint }, - { "compact", WT_VERB_compact }, - { "evict", WT_VERB_evict }, - { "evictserver", WT_VERB_evictserver }, - { "fileops", WT_VERB_fileops }, - { "log", WT_VERB_log }, - { "lsm", WT_VERB_lsm }, - { "metadata", WT_VERB_metadata }, - { "mutex", WT_VERB_mutex }, - { "overflow", WT_VERB_overflow }, - { "read", WT_VERB_read }, - { "reconcile", WT_VERB_reconcile }, - { "recovery", WT_VERB_recovery }, - { "salvage", WT_VERB_salvage }, - { "shared_cache", WT_VERB_shared_cache }, - { "split", WT_VERB_split }, - { "verify", WT_VERB_verify }, - { "version", WT_VERB_version }, - { "write", WT_VERB_write }, + { "api", WT_VERB_API }, + { "block", WT_VERB_BLOCK }, + { "checkpoint", WT_VERB_CHECKPOINT }, + { "compact", WT_VERB_COMPACT }, + { "evict", WT_VERB_EVICT }, + { "evictserver", WT_VERB_EVICTSERVER }, + { "fileops", WT_VERB_FILEOPS }, + { "log", WT_VERB_LOG }, + { "lsm", WT_VERB_LSM }, + { "metadata", WT_VERB_METADATA }, + { "mutex", WT_VERB_MUTEX }, + { "overflow", WT_VERB_OVERFLOW }, + { "read", WT_VERB_READ }, + { "reconcile", WT_VERB_RECONCILE }, + { "recovery", WT_VERB_RECOVERY }, + { "salvage", WT_VERB_SALVAGE }, + { "shared_cache", WT_VERB_SHARED_CACHE }, + { "split", WT_VERB_SPLIT }, + { "verify", WT_VERB_VERIFY }, + { "version", WT_VERB_VERSION }, + { "write", WT_VERB_WRITE }, { NULL, 0 } }; @@ -1173,7 +1173,8 @@ wiredtiger_open(const char *home, WT_EVENT_HANDLER *event_handler, WT_ERR(__conn_statistics_config(session, cfg)); /* Now that we know if verbose is configured, output the version. */ - WT_VERBOSE_ERR(session, version, "%s", WIREDTIGER_VERSION_STRING); + WT_ERR(__wt_verbose( + session, WT_VERB_VERSION, "%s", WIREDTIGER_VERSION_STRING)); /* * Open the connection, then reset the local session as the real one diff --git a/src/conn/conn_cache_pool.c b/src/conn/conn_cache_pool.c index cb51c4f53f2..f5f5482518f 100644 --- a/src/conn/conn_cache_pool.c +++ b/src/conn/conn_cache_pool.c @@ -92,8 +92,8 @@ __wt_conn_cache_pool_config(WT_SESSION_IMPL *session, const char **cfg) "cache pool server", 0, &cp->cache_pool_cond)); __wt_process.cache_pool = cp; - WT_VERBOSE_ERR(session, shared_cache, - "Created cache pool %s.", cp->name); + WT_ERR(__wt_verbose(session, + WT_VERB_SHARED_CACHE, "Created cache pool %s", cp->name)); } else if (!reconfiguring && !WT_STRING_MATCH( __wt_process.cache_pool->name, pool_name, strlen(pool_name))) /* Only a single cache pool is supported. */ @@ -163,10 +163,9 @@ __wt_conn_cache_pool_config(WT_SESSION_IMPL *session, const char **cfg) cp->size = size; cp->chunk = chunk; - WT_VERBOSE_ERR(session, shared_cache, + WT_ERR(__wt_verbose(session, WT_VERB_SHARED_CACHE, "Configured cache pool %s. Size: %" PRIu64 - ", chunk size: %" PRIu64, - cp->name, cp->size, cp->chunk); + ", chunk size: %" PRIu64, cp->name, cp->size, cp->chunk)); F_SET(conn, WT_CONN_CACHE_POOL); err: __wt_spin_unlock(session, &__wt_process.spinlock); @@ -204,8 +203,8 @@ __wt_conn_cache_pool_open(WT_SESSION_IMPL *session) TAILQ_INSERT_TAIL(&cp->cache_pool_qh, conn, cpq); __wt_spin_unlock(session, &cp->cache_pool_lock); - WT_VERBOSE_RET(session, shared_cache, - "Added %s to cache pool %s.", conn->home, cp->name); + WT_RET(__wt_verbose(session, WT_VERB_SHARED_CACHE, + "Added %s to cache pool %s", conn->home, cp->name)); /* Start the cache pool server if required. */ if (create_server) { @@ -254,8 +253,8 @@ __wt_conn_cache_pool_destroy(WT_CONNECTION_IMPL *conn) * queue. We did increment the reference count, so proceed regardless. */ if (found) { - WT_VERBOSE_TRET(session, shared_cache, - "Removing %s from cache pool.", entry->home); + WT_TRET(__wt_verbose(session, WT_VERB_SHARED_CACHE, + "Removing %s from cache pool", entry->home)); TAILQ_REMOVE(&cp->cache_pool_qh, entry, cpq); /* Give the connection's resources back to the pool. */ @@ -282,16 +281,16 @@ __wt_conn_cache_pool_destroy(WT_CONNECTION_IMPL *conn) * connection. A new one will be created by the next balance pass. */ if (cp->session != NULL && conn == S2C(cp->session)) { - WT_VERBOSE_TRET(cp->session, shared_cache, - "Freeing a cache pool session due to connection close."); + WT_TRET(__wt_verbose(cp->session, WT_VERB_SHARED_CACHE, + "Freeing a cache pool session due to connection close")); wt_session = &cp->session->iface; WT_TRET(wt_session->close(wt_session, NULL)); cp->session = NULL; } if (!F_ISSET(cp, WT_CACHE_POOL_RUN)) { - WT_VERBOSE_TRET( - session, shared_cache, "Destroying cache pool."); + WT_TRET(__wt_verbose( + session, WT_VERB_SHARED_CACHE, "Destroying cache pool")); __wt_spin_lock(session, &__wt_process.spinlock); /* * We have been holding the pool lock - no connections could @@ -406,9 +405,9 @@ __cache_pool_assess(uint64_t *phighest) if (cache->cp_current_evict > highest) highest = cache->cp_current_evict; } - WT_VERBOSE_RET(cp->session, shared_cache, + WT_RET(__wt_verbose(cp->session, WT_VERB_SHARED_CACHE, "Highest eviction count: %" PRIu64 ", entries: %" PRIu64, - highest, entries); + highest, entries)); /* Normalize eviction information across connections. */ highest = highest / (entries + 1); ++highest; /* Avoid divide by zero. */ @@ -436,11 +435,11 @@ __cache_pool_adjust(uint64_t highest, uint64_t bump_threshold) reserved = read_pressure = 0; grew = 0; force = (cp->currently_used > cp->size); - if (WT_VERBOSE_ISSET(cp->session, shared_cache)) { - WT_VERBOSE_RET(cp->session, shared_cache, - "Cache pool distribution: "); - WT_VERBOSE_RET(cp->session, shared_cache, - "\t" "cache_size, read_pressure, skips: "); + if (WT_VERBOSE_ISSET(cp->session, WT_VERB_SHARED_CACHE)) { + WT_RET(__wt_verbose(cp->session, + WT_VERB_SHARED_CACHE, "Cache pool distribution: ")); + WT_RET(__wt_verbose(cp->session, WT_VERB_SHARED_CACHE, + "\t" "cache_size, read_pressure, skips: ")); } TAILQ_FOREACH(entry, &cp->cache_pool_qh, cpq) { @@ -449,9 +448,9 @@ __cache_pool_adjust(uint64_t highest, uint64_t bump_threshold) adjusted = 0; read_pressure = cache->cp_current_evict / highest; - WT_VERBOSE_RET(cp->session, shared_cache, + WT_RET(__wt_verbose(cp->session, WT_VERB_SHARED_CACHE, "\t%" PRIu64 ", %" PRIu64 ", %" PRIu32, - entry->cache_size, read_pressure, cache->cp_skip_count); + entry->cache_size, read_pressure, cache->cp_skip_count)); /* Allow to stabilize after changes. */ if (cache->cp_skip_count > 0 && --cache->cp_skip_count > 0) @@ -498,9 +497,9 @@ __cache_pool_adjust(uint64_t highest, uint64_t bump_threshold) entry->cache_size -= adjusted; cp->currently_used -= adjusted; } - WT_VERBOSE_RET(cp->session, shared_cache, + WT_RET(__wt_verbose(cp->session, WT_VERB_SHARED_CACHE, "Allocated %s%" PRId64 " to %s", - grew ? "" : "-", adjusted, entry->home); + grew ? "" : "-", adjusted, entry->home)); /* * TODO: Add a loop waiting for connection to give up * cache. diff --git a/src/conn/conn_log.c b/src/conn/conn_log.c index 25fa0262a47..be35a99d8aa 100644 --- a/src/conn/conn_log.c +++ b/src/conn/conn_log.c @@ -99,9 +99,9 @@ __log_archive_server(void *arg) lsn = log->ckpt_lsn; lsn.offset = 0; - WT_VERBOSE_ERR(session, log, + WT_ERR(__wt_verbose(session, WT_VERB_LOG, "log_archive: ckpt LSN %" PRIu32 ",%" PRIu64, - lsn.file, lsn.offset); + lsn.file, lsn.offset)); /* * Main archive code. Get the list of all log files and * remove any earlier than the checkpoint LSN. diff --git a/src/include/api.h b/src/include/api.h index 01afe3382ab..4e9efd1b3c7 100644 --- a/src/include/api.h +++ b/src/include/api.h @@ -16,7 +16,7 @@ #define API_CALL_NOCONF(s, h, n, cur, dh) do { \ API_SESSION_INIT(s, h, n, cur, dh); \ WT_ERR(F_ISSET(S2C(s), WT_CONN_PANIC) ? __wt_panic(s) : 0); \ - WT_VERBOSE_ERR((s), api, "CALL: " #h ":" #n) + WT_ERR(__wt_verbose((s), WT_VERB_API, "CALL: " #h ":" #n)) #define API_CALL(s, h, n, cur, dh, config, cfg) do { \ const char *cfg[] = \ @@ -26,7 +26,7 @@ WT_ERR(((config) != NULL) ? \ __wt_config_check((s), \ WT_CONFIG_REF(session, h##_##n), (config), 0) : 0); \ - WT_VERBOSE_ERR((s), api, "CALL: " #h ":" #n) + WT_ERR(__wt_verbose((s), WT_VERB_API, "CALL: " #h ":" #n)) #define API_END(s, ret) \ if ((s) != NULL) { \ diff --git a/src/include/extern.h b/src/include/extern.h index e9e71d0d64a..c084cc2ae2b 100644 --- a/src/include/extern.h +++ b/src/include/extern.h @@ -1346,6 +1346,13 @@ extern uint32_t __wt_cksum(const void *chunk, size_t len); extern void __wt_cksum_init(void); extern void __wt_event_handler_set(WT_SESSION_IMPL *session, WT_EVENT_HANDLER *handler); +extern int __wt_eventv(WT_SESSION_IMPL *session, + int msg_event, + int error, + const char *file_name, + int line_number, + const char *fmt, + va_list ap); extern void __wt_err(WT_SESSION_IMPL *session, int error, const char *fmt, @@ -1375,11 +1382,6 @@ extern int __wt_ext_msg_printf( WT_EXTENSION_API *wt_api, 3, 4))); extern int __wt_progress(WT_SESSION_IMPL *session, const char *s, uint64_t v); -extern int __wt_verbose(WT_SESSION_IMPL *session, - const char *fmt, - ...) WT_GCC_ATTRIBUTE((format (printf, - 2, - 3))); extern void __wt_assert(WT_SESSION_IMPL *session, int error, const char *file_name, diff --git a/src/include/flags.h b/src/include/flags.h index 34e1e07856a..88711720c0d 100644 --- a/src/include/flags.h +++ b/src/include/flags.h @@ -47,27 +47,27 @@ #define WT_TXN_LOG_CKPT_PREPARE 0x00000004 #define WT_TXN_LOG_CKPT_START 0x00000002 #define WT_TXN_LOG_CKPT_STOP 0x00000001 -#define WT_VERB_api 0x00100000 -#define WT_VERB_block 0x00080000 -#define WT_VERB_checkpoint 0x00040000 -#define WT_VERB_compact 0x00020000 -#define WT_VERB_evict 0x00010000 -#define WT_VERB_evictserver 0x00008000 -#define WT_VERB_fileops 0x00004000 -#define WT_VERB_log 0x00002000 -#define WT_VERB_lsm 0x00001000 -#define WT_VERB_metadata 0x00000800 -#define WT_VERB_mutex 0x00000400 -#define WT_VERB_overflow 0x00000200 -#define WT_VERB_read 0x00000100 -#define WT_VERB_reconcile 0x00000080 -#define WT_VERB_recovery 0x00000040 -#define WT_VERB_salvage 0x00000020 -#define WT_VERB_shared_cache 0x00000010 -#define WT_VERB_split 0x00000008 -#define WT_VERB_verify 0x00000004 -#define WT_VERB_version 0x00000002 -#define WT_VERB_write 0x00000001 +#define WT_VERB_API 0x00100000 +#define WT_VERB_BLOCK 0x00080000 +#define WT_VERB_CHECKPOINT 0x00040000 +#define WT_VERB_COMPACT 0x00020000 +#define WT_VERB_EVICT 0x00010000 +#define WT_VERB_EVICTSERVER 0x00008000 +#define WT_VERB_FILEOPS 0x00004000 +#define WT_VERB_LOG 0x00002000 +#define WT_VERB_LSM 0x00001000 +#define WT_VERB_METADATA 0x00000800 +#define WT_VERB_MUTEX 0x00000400 +#define WT_VERB_OVERFLOW 0x00000200 +#define WT_VERB_READ 0x00000100 +#define WT_VERB_RECONCILE 0x00000080 +#define WT_VERB_RECOVERY 0x00000040 +#define WT_VERB_SALVAGE 0x00000020 +#define WT_VERB_SHARED_CACHE 0x00000010 +#define WT_VERB_SPLIT 0x00000008 +#define WT_VERB_VERIFY 0x00000004 +#define WT_VERB_VERSION 0x00000002 +#define WT_VERB_WRITE 0x00000001 /* * flags section: END * DO NOT EDIT: automatically built by dist/flags.py. diff --git a/src/include/misc.h b/src/include/misc.h index fc9107017e4..693c5b4a518 100644 --- a/src/include/misc.h +++ b/src/include/misc.h @@ -127,24 +127,9 @@ /* Verbose messages. */ #ifdef HAVE_VERBOSE #define WT_VERBOSE_ISSET(session, f) \ - (FLD_ISSET(S2C(session)->verbose, WT_VERB_##f)) -#define WT_VERBOSE_ERR(session, f, ...) do { \ - if (WT_VERBOSE_ISSET(session, f)) \ - WT_ERR(__wt_verbose(session, #f ": " __VA_ARGS__)); \ -} while (0) -#define WT_VERBOSE_RET(session, f, ...) do { \ - if (WT_VERBOSE_ISSET(session, f)) \ - WT_RET(__wt_verbose(session, #f ": " __VA_ARGS__)); \ -} while (0) -#define WT_VERBOSE_TRET(session, f, ...) do { \ - if (WT_VERBOSE_ISSET(session, f)) \ - WT_TRET(__wt_verbose(session, #f ": " __VA_ARGS__)); \ -} while (0) + (FLD_ISSET(S2C(session)->verbose, f)) #else #define WT_VERBOSE_ISSET(session, f) 0 -#define WT_VERBOSE_ERR(session, f, ...) -#define WT_VERBOSE_RET(session, f, ...) -#define WT_VERBOSE_TRET(session, f, ...) #endif /* diff --git a/src/include/misc.i b/src/include/misc.i new file mode 100644 index 00000000000..73caed09c8c --- /dev/null +++ b/src/include/misc.i @@ -0,0 +1,32 @@ +/*- + * Copyright (c) 2008-2014 WiredTiger, Inc. + * All rights reserved. + * + * See the file LICENSE for redistribution information. + */ + +/* + * __wt_verbose -- + * Verbose message. + */ +static inline int +__wt_verbose(WT_SESSION_IMPL *session, int flag, const char *fmt, ...) + WT_GCC_FUNC_ATTRIBUTE((format (printf, 2, 3))) +{ +#ifdef HAVE_VERBOSE + WT_DECL_RET; + va_list ap; + + if (WT_VERBOSE_ISSET(session, flag)) { + va_start(ap, fmt); + ret = __wt_eventv(session, 1, 0, NULL, 0, fmt, ap); + va_end(ap); + } + return (ret); +#else + WT_UNUSED(session); + WT_UNUSED(fmt); + WT_UNUSED(flag); + return (0); +#endif +} diff --git a/src/include/wt_internal.h b/src/include/wt_internal.h index 87133be1573..d2807e83a5c 100644 --- a/src/include/wt_internal.h +++ b/src/include/wt_internal.h @@ -268,6 +268,7 @@ struct __wt_update; #include "verify_build.h" #include "buf.i" +#include "misc.i" #include "intpack.i" /* required by cell.i, packing.i */ #include "packing.i" #include "cell.i" /* required by btree.i */ diff --git a/src/log/log.c b/src/log/log.c index b1d45403e47..ead8ebb94d6 100644 --- a/src/log/log.c +++ b/src/log/log.c @@ -154,8 +154,8 @@ __wt_log_remove(WT_SESSION_IMPL *session, uint32_t lognum) WT_ERR(__wt_scr_alloc(session, 0, &path)); WT_ERR(__wt_log_filename(session, lognum, path)); - WT_VERBOSE_ERR(session, log, "log_remove: remove log %s", - (char *)path->data); + WT_ERR(__wt_verbose(session, WT_VERB_LOG, + "log_remove: remove log %s", (char *)path->data)); WT_ERR(__wt_remove(session, path->data)); err: __wt_scr_free(&path); return (ret); @@ -173,8 +173,8 @@ __log_openfile(WT_SESSION_IMPL *session, int ok_create, WT_FH **fh, uint32_t id) WT_RET(__wt_scr_alloc(session, 0, &path)); WT_ERR(__wt_log_filename(session, id, path)); - WT_VERBOSE_ERR(session, log, "opening log %s", - (const char *)path->data); + WT_ERR(__wt_verbose(session, WT_VERB_LOG, + "opening log %s", (const char *)path->data)); WT_ERR(__wt_open( session, path->data, ok_create, 0, WT_FILE_TYPE_LOG, fh)); err: __wt_scr_free(&path); @@ -210,8 +210,8 @@ __wt_log_open(WT_SESSION_IMPL *session) firstlog = WT_MIN(firstlog, lognum); } log->fileid = lastlog; - WT_VERBOSE_ERR(session, log, "log_open: first log %d last log %d", - firstlog, lastlog); + WT_ERR(__wt_verbose(session, WT_VERB_LOG, + "log_open: first log %d last log %d", firstlog, lastlog)); log->first_lsn.file = firstlog; log->first_lsn.offset = 0; @@ -248,13 +248,13 @@ __wt_log_close(WT_SESSION_IMPL *session) log = conn->log; if (log->log_close_fh != NULL && log->log_close_fh != log->log_fh) { - WT_VERBOSE_RET(session, log, - "closing old log %s", log->log_close_fh->name); + WT_RET(__wt_verbose(session, WT_VERB_LOG, + "closing old log %s", log->log_close_fh->name)); WT_RET(__wt_close(session, log->log_close_fh)); } if (log->log_fh != NULL) { - WT_VERBOSE_RET(session, log, - "closing log %s", log->log_fh->name); + WT_RET(__wt_verbose(session, WT_VERB_LOG, + "closing log %s", log->log_fh->name)); WT_RET(__wt_close(session, log->log_fh)); log->log_fh = NULL; } @@ -741,11 +741,10 @@ __wt_log_scan(WT_SESSION_IMPL *session, WT_LSN *lsnp, uint32_t flags, if (func == NULL) return (0); - if (LF_ISSET(WT_LOGSCAN_RECOVER)) { - WT_VERBOSE_RET(session, log, + if (LF_ISSET(WT_LOGSCAN_RECOVER)) + WT_RET(__wt_verbose(session, WT_VERB_LOG, "__wt_log_scan truncating to %u/%" PRIuMAX, - log->trunc_lsn.file, (uintmax_t)log->trunc_lsn.offset); - } + log->trunc_lsn.file, (uintmax_t)log->trunc_lsn.offset)); if (log != NULL) { allocsize = log->allocsize; @@ -1126,8 +1125,8 @@ __wt_log_vprintf(WT_SESSION_IMPL *session, const char *fmt, va_list ap) (void)vsnprintf((char *)logrec->data + logrec->size, len, fmt, ap); - WT_VERBOSE_ERR(session, log, - "log_printf: %s", (char *)logrec->data + logrec->size); + WT_ERR(__wt_verbose(session, WT_VERB_LOG, + "log_printf: %s", (char *)logrec->data + logrec->size)); logrec->size += len; WT_ERR(__wt_log_write(session, logrec, NULL, 0)); diff --git a/src/lsm/lsm_merge.c b/src/lsm/lsm_merge.c index 7ef0562a20e..b755a9bda00 100644 --- a/src/lsm/lsm_merge.c +++ b/src/lsm/lsm_merge.c @@ -245,10 +245,10 @@ __wt_lsm_merge( /* Allocate an ID for the merge. */ dest_id = WT_ATOMIC_ADD(lsm_tree->last, 1); - WT_VERBOSE_RET(session, lsm, + WT_RET(__wt_verbose(session, WT_VERB_LSM, "Merging chunks %u-%u into %u (%" PRIu64 " records)" ", generation %" PRIu32, - start_chunk, end_chunk, dest_id, record_count, generation); + start_chunk, end_chunk, dest_id, record_count, generation)); WT_RET(__wt_calloc_def(session, 1, &chunk)); chunk->id = dest_id; @@ -312,9 +312,9 @@ __wt_lsm_merge( WT_STAT_FAST_CONN_INCRV(session, lsm_rows_merged, insert_count % LSM_MERGE_CHECK_INTERVAL); ++lsm_tree->merge_progressing; - WT_VERBOSE_ERR(session, lsm, + WT_ERR(__wt_verbose(session, WT_VERB_LSM, "Bloom size for %" PRIu64 " has %" PRIu64 " items inserted.", - record_count, insert_count); + record_count, insert_count)); /* * We've successfully created the new chunk. Now install it. We need @@ -411,13 +411,12 @@ err: if (src != NULL) __wt_free(session, chunk->uri); __wt_free(session, chunk); - if (ret == EINTR) { - WT_VERBOSE_TRET(session, lsm, - "Merge aborted due to close"); - } else { - WT_VERBOSE_TRET(session, lsm, - "Merge failed with %s", wiredtiger_strerror(ret)); - } + if (ret == EINTR) + WT_TRET(__wt_verbose(session, WT_VERB_LSM, + "Merge aborted due to close")); + else + WT_TRET(__wt_verbose(session, WT_VERB_LSM, + "Merge failed with %s", wiredtiger_strerror(ret))); F_CLR(session, WT_SESSION_NO_CACHE); } return (ret); diff --git a/src/lsm/lsm_tree.c b/src/lsm/lsm_tree.c index 300403c2077..bf92109fc00 100644 --- a/src/lsm/lsm_tree.c +++ b/src/lsm/lsm_tree.c @@ -764,10 +764,10 @@ __wt_lsm_tree_switch(WT_SESSION_IMPL *session, WT_LSM_TREE *lsm_tree) WT_ERR(__wt_realloc_def(session, &lsm_tree->chunk_alloc, nchunks + 1, &lsm_tree->chunk)); - WT_VERBOSE_ERR(session, lsm, + WT_ERR(__wt_verbose(session, WT_VERB_LSM, "Tree switch to: %" PRIu32 ", checkpoint throttle %ld, " "merge throttle %ld", - new_id, lsm_tree->ckpt_throttle, lsm_tree->merge_throttle); + new_id, lsm_tree->ckpt_throttle, lsm_tree->merge_throttle)); WT_ERR(__wt_calloc_def(session, 1, &chunk)); chunk->id = new_id; diff --git a/src/lsm/lsm_worker.c b/src/lsm/lsm_worker.c index f6ddd305aca..689d1f70878 100644 --- a/src/lsm/lsm_worker.c +++ b/src/lsm/lsm_worker.c @@ -167,13 +167,12 @@ __wt_lsm_merge_worker(void *vargs) old_aggressive = aggressive; aggressive = chunk_wait / lsm_tree->merge_min; - if (aggressive > old_aggressive) { - WT_VERBOSE_ERR(session, lsm, + if (aggressive > old_aggressive) + WT_ERR(__wt_verbose(session, WT_VERB_LSM, "LSM merge got aggressive (%u), " "%u / %" PRIu64, aggressive, stallms, - lsm_tree->chunk_fill_ms); - } + lsm_tree->chunk_fill_ms)); } } @@ -304,8 +303,8 @@ __wt_lsm_checkpoint_worker(void *arg) if (F_ISSET(chunk, WT_LSM_CHUNK_ONDISK)) continue; - WT_VERBOSE_ERR(session, lsm, - "LSM worker flushing %u", i); + WT_ERR(__wt_verbose(session, WT_VERB_LSM, + "LSM worker flushing %u", i)); /* * Flush the file before checkpointing: this is the @@ -354,8 +353,8 @@ __wt_lsm_checkpoint_worker(void *arg) if (F_ISSET(lsm_tree, WT_LSM_TREE_NEED_SWITCH)) break; - WT_VERBOSE_ERR(session, lsm, - "LSM worker checkpointing %u", i); + WT_ERR(__wt_verbose(session, WT_VERB_LSM, + "LSM worker checkpointing %u", i)); WT_WITH_SCHEMA_LOCK(session, ret = __wt_schema_worker(session, chunk->uri, @@ -398,8 +397,8 @@ __wt_lsm_checkpoint_worker(void *arg) break; } - WT_VERBOSE_ERR(session, lsm, - "LSM worker checkpointed %u", i); + WT_ERR(__wt_verbose(session, WT_VERB_LSM, + "LSM worker checkpointed %u", i)); } keep_going: __lsm_unpin_chunks(session, &cookie); @@ -497,10 +496,10 @@ __lsm_bloom_create(WT_SESSION_IMPL *session, WT_CLEAR(key); WT_ERR_NOTFOUND_OK(__wt_bloom_get(bloom, &key)); - WT_VERBOSE_ERR(session, lsm, + WT_ERR(__wt_verbose(session, WT_VERB_LSM, "LSM worker created bloom filter %s. " "Expected %" PRIu64 " items, got %" PRIu64, - chunk->bloom_uri, chunk->count, insert_count); + chunk->bloom_uri, chunk->count, insert_count)); /* Ensure the bloom filter is in the metadata. */ WT_ERR(__wt_lsm_tree_lock(session, lsm_tree, 1)); @@ -636,9 +635,9 @@ __lsm_free_chunks(WT_SESSION_IMPL *session, WT_LSM_TREE *lsm_tree) if ((ret = __lsm_drop_file( session, chunk->bloom_uri)) == EBUSY) { ret = 0; - WT_VERBOSE_ERR(session, lsm, + WT_ERR(__wt_verbose(session, WT_VERB_LSM, "LSM worker bloom drop busy: %s.", - chunk->bloom_uri); + chunk->bloom_uri)); ++skipped; continue; } else @@ -654,9 +653,9 @@ __lsm_free_chunks(WT_SESSION_IMPL *session, WT_LSM_TREE *lsm_tree) if ((ret = __lsm_drop_file( session, chunk->uri)) == EBUSY) { ret = 0; - WT_VERBOSE_ERR(session, lsm, + WT_ERR(__wt_verbose(session, WT_VERB_LSM, "LSM worker drop busy: %s.", - chunk->uri); + chunk->uri)); ++skipped; continue; } else diff --git a/src/meta/meta_table.c b/src/meta/meta_table.c index 49f472e267b..75cf4713c48 100644 --- a/src/meta/meta_table.c +++ b/src/meta/meta_table.c @@ -91,10 +91,10 @@ __wt_metadata_insert( WT_CURSOR *cursor; WT_DECL_RET; - WT_VERBOSE_RET(session, metadata, + WT_RET(__wt_verbose(session, WT_VERB_METADATA, "Insert: key: %s, value: %s, tracking: %s, %s" "turtle", key, value, WT_META_TRACKING(session) ? "true" : "false", - __metadata_turtle(key) ? "" : "not "); + __metadata_turtle(key) ? "" : "not ")); if (__metadata_turtle(key)) WT_RET_MSG(session, EINVAL, @@ -122,10 +122,10 @@ __wt_metadata_update( WT_CURSOR *cursor; WT_DECL_RET; - WT_VERBOSE_RET(session, metadata, + WT_RET(__wt_verbose(session, WT_VERB_METADATA, "Update: key: %s, value: %s, tracking: %s, %s" "turtle", key, value, WT_META_TRACKING(session) ? "true" : "false", - __metadata_turtle(key) ? "" : "not "); + __metadata_turtle(key) ? "" : "not ")); if (__metadata_turtle(key)) return (__wt_turtle_update(session, key, value)); @@ -152,10 +152,10 @@ __wt_metadata_remove(WT_SESSION_IMPL *session, const char *key) WT_CURSOR *cursor; WT_DECL_RET; - WT_VERBOSE_RET(session, metadata, + WT_RET(__wt_verbose(session, WT_VERB_METADATA, "Remove: key: %s, tracking: %s, %s" "turtle", key, WT_META_TRACKING(session) ? "true" : "false", - __metadata_turtle(key) ? "" : "not "); + __metadata_turtle(key) ? "" : "not ")); if (__metadata_turtle(key)) WT_RET_MSG(session, EINVAL, @@ -187,10 +187,10 @@ __wt_metadata_search( *valuep = NULL; - WT_VERBOSE_RET(session, metadata, + WT_RET(__wt_verbose(session, WT_VERB_METADATA, "Search: key: %s, tracking: %s, %s" "turtle", key, WT_META_TRACKING(session) ? "true" : "false", - __metadata_turtle(key) ? "" : "not "); + __metadata_turtle(key) ? "" : "not ")); if (__metadata_turtle(key)) return (__wt_turtle_read(session, key, valuep)); diff --git a/src/os_posix/os_dir.c b/src/os_posix/os_dir.c index 5699d5d358d..98b2d4926cd 100644 --- a/src/os_posix/os_dir.c +++ b/src/os_posix/os_dir.c @@ -38,9 +38,10 @@ __wt_dirlist(WT_SESSION_IMPL *session, const char *dir, const char *prefix, if (flags == 0) LF_SET(WT_DIRLIST_INCLUDE); - WT_VERBOSE_ERR(session, fileops, "wt_dirlist of %s %s prefix %s", + WT_ERR(__wt_verbose(session, WT_VERB_FILEOPS, + "wt_dirlist of %s %s prefix %s", path, LF_ISSET(WT_DIRLIST_INCLUDE) ? "include" : "exclude", - prefix == NULL ? "all" : prefix); + prefix == NULL ? "all" : prefix)); WT_SYSCALL_RETRY(((dirp = opendir(path)) == NULL ? 1 : 0), ret); if (ret != 0) diff --git a/src/os_posix/os_fallocate.c b/src/os_posix/os_fallocate.c index aa72bfcca10..dc8ba432269 100644 --- a/src/os_posix/os_fallocate.c +++ b/src/os_posix/os_fallocate.c @@ -20,9 +20,8 @@ __wt_fallocate(WT_SESSION_IMPL *session, WT_FH *fh, off_t offset, off_t len) { WT_DECL_RET; - WT_UNUSED(session); /* If verbose is disabled */ - - WT_VERBOSE_RET(session, fileops, "%s: fallocate", fh->name); + WT_RET(__wt_verbose( + session, WT_VERB_FILEOPS, "%s: fallocate", fh->name)); /* * Prefer the non-portable Linux fallocate call if it's available, diff --git a/src/os_posix/os_filesize.c b/src/os_posix/os_filesize.c index 3d8cb8490ef..7c78c845dd4 100644 --- a/src/os_posix/os_filesize.c +++ b/src/os_posix/os_filesize.c @@ -17,7 +17,7 @@ __wt_filesize(WT_SESSION_IMPL *session, WT_FH *fh, off_t *sizep) struct stat sb; WT_DECL_RET; - WT_VERBOSE_RET(session, fileops, "%s: fstat", fh->name); + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, "%s: fstat", fh->name)); WT_SYSCALL_RETRY(fstat(fh->fd, &sb), ret); if (ret == 0) { diff --git a/src/os_posix/os_fsync.c b/src/os_posix/os_fsync.c index b88f04d3026..6f180d75e0d 100644 --- a/src/os_posix/os_fsync.c +++ b/src/os_posix/os_fsync.c @@ -16,7 +16,7 @@ __wt_fsync(WT_SESSION_IMPL *session, WT_FH *fh) { WT_DECL_RET; - WT_VERBOSE_RET(session, fileops, "%s: fsync", fh->name); + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, "%s: fsync", fh->name)); #ifdef HAVE_FDATASYNC WT_SYSCALL_RETRY(fdatasync(fh->fd), ret); diff --git a/src/os_posix/os_map.c b/src/os_posix/os_map.c index fcb81659d44..119b850ec4f 100644 --- a/src/os_posix/os_map.c +++ b/src/os_posix/os_map.c @@ -16,8 +16,8 @@ __wt_mmap(WT_SESSION_IMPL *session, WT_FH *fh, void *mapp, size_t *lenp) { void *map; - WT_VERBOSE_RET(session, fileops, - "%s: map %" PRIuMAX " bytes", fh->name, (uintmax_t)fh->size); + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, + "%s: map %" PRIuMAX " bytes", fh->name, (uintmax_t)fh->size)); if ((map = mmap(NULL, (size_t)fh->size, PROT_READ, @@ -110,8 +110,8 @@ __wt_mmap_discard(WT_SESSION_IMPL *session, void *p, size_t size) int __wt_munmap(WT_SESSION_IMPL *session, WT_FH *fh, void *map, size_t len) { - WT_VERBOSE_RET(session, fileops, - "%s: unmap %" PRIuMAX " bytes", fh->name, (uintmax_t)len); + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, + "%s: unmap %" PRIuMAX " bytes", fh->name, (uintmax_t)len)); if (munmap(map, len) == 0) return (0); diff --git a/src/os_posix/os_mtx.c b/src/os_posix/os_mtx.c index b6005ebc87d..3a10d4e1e93 100644 --- a/src/os_posix/os_mtx.c +++ b/src/os_posix/os_mtx.c @@ -74,8 +74,8 @@ __wt_cond_wait(WT_SESSION_IMPL *session, WT_CONDVAR *cond, long usecs) * This function MUST handle a NULL session handle. */ if (session != NULL) { - WT_VERBOSE_RET( - session, mutex, "wait %s cond (%p)", cond->name, cond); + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "wait %s cond (%p)", cond->name, cond)); WT_STAT_FAST_CONN_INCR(session, cond_wait); } @@ -126,9 +126,9 @@ __wt_cond_signal(WT_SESSION_IMPL *session, WT_CONDVAR *cond) * !!! * This function MUST handle a NULL session handle. */ - if (session != NULL && WT_VERBOSE_ISSET(session, mutex)) - WT_RET(__wt_verbose( - session, "signal %s cond (%p)", cond->name, cond)); + if (session != NULL) + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "signal %s cond (%p)", cond->name, cond)); /* Fast path if already signalled. */ if (cond->waiters == -1) @@ -185,8 +185,8 @@ __wt_rwlock_alloc( rwlock->name = name; *rwlockp = rwlock; - WT_VERBOSE_ERR(session, mutex, - "rwlock: alloc %s (%p)", rwlock->name, rwlock); + WT_ERR(__wt_verbose(session, WT_VERB_MUTEX, + "rwlock: alloc %s (%p)", rwlock->name, rwlock)); if (0) { err: __wt_free(session, rwlock); @@ -203,8 +203,8 @@ __wt_readlock(WT_SESSION_IMPL *session, WT_RWLOCK *rwlock) { WT_DECL_RET; - WT_VERBOSE_RET(session, mutex, - "rwlock: readlock %s (%p)", rwlock->name, rwlock); + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "rwlock: readlock %s (%p)", rwlock->name, rwlock)); WT_STAT_FAST_CONN_INCR(session, rwlock_read); if ((ret = pthread_rwlock_rdlock(&rwlock->rwlock)) == 0) @@ -221,8 +221,8 @@ __wt_try_writelock(WT_SESSION_IMPL *session, WT_RWLOCK *rwlock) { WT_DECL_RET; - WT_VERBOSE_RET(session, mutex, - "rwlock: try_writelock %s (%p)", rwlock->name, rwlock); + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "rwlock: try_writelock %s (%p)", rwlock->name, rwlock)); WT_STAT_FAST_CONN_INCR(session, rwlock_write); if ((ret = @@ -240,8 +240,8 @@ __wt_writelock(WT_SESSION_IMPL *session, WT_RWLOCK *rwlock) { WT_DECL_RET; - WT_VERBOSE_RET(session, mutex, - "rwlock: writelock %s (%p)", rwlock->name, rwlock); + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "rwlock: writelock %s (%p)", rwlock->name, rwlock)); WT_STAT_FAST_CONN_INCR(session, rwlock_write); if ((ret = pthread_rwlock_wrlock(&rwlock->rwlock)) == 0) @@ -258,8 +258,8 @@ __wt_rwunlock(WT_SESSION_IMPL *session, WT_RWLOCK *rwlock) { WT_DECL_RET; - WT_VERBOSE_RET(session, mutex, - "rwlock: unlock %s (%p)", rwlock->name, rwlock); + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "rwlock: unlock %s (%p)", rwlock->name, rwlock)); if ((ret = pthread_rwlock_unlock(&rwlock->rwlock)) == 0) return (0); @@ -281,8 +281,8 @@ __wt_rwlock_destroy(WT_SESSION_IMPL *session, WT_RWLOCK **rwlockp) return (0); *rwlockp = NULL; - WT_VERBOSE_RET(session, mutex, - "rwlock: destroy %s (%p)", rwlock->name, rwlock); + WT_RET(__wt_verbose(session, WT_VERB_MUTEX, + "rwlock: destroy %s (%p)", rwlock->name, rwlock)); if ((ret = pthread_rwlock_destroy(&rwlock->rwlock)) == 0) { __wt_free(session, rwlock); diff --git a/src/os_posix/os_open.c b/src/os_posix/os_open.c index c6938dad9fd..9a0bff8df16 100644 --- a/src/os_posix/os_open.c +++ b/src/os_posix/os_open.c @@ -74,7 +74,7 @@ __wt_open(WT_SESSION_IMPL *session, fd = -1; path = NULL; - WT_VERBOSE_RET(session, fileops, "%s: open", name); + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, "%s: open", name)); /* Increment the reference count if we already have the file open. */ matched = 0; diff --git a/src/os_posix/os_remove.c b/src/os_posix/os_remove.c index a7e511b48d7..d44b1bf1c2c 100644 --- a/src/os_posix/os_remove.c +++ b/src/os_posix/os_remove.c @@ -49,7 +49,7 @@ __wt_remove(WT_SESSION_IMPL *session, const char *name) WT_DECL_RET; char *path; - WT_VERBOSE_RET(session, fileops, "%s: remove", name); + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, "%s: remove", name)); __remove_file_check(session, name); diff --git a/src/os_posix/os_rename.c b/src/os_posix/os_rename.c index 200638378d1..ddbb59aaf37 100644 --- a/src/os_posix/os_rename.c +++ b/src/os_posix/os_rename.c @@ -17,7 +17,8 @@ __wt_rename(WT_SESSION_IMPL *session, const char *from, const char *to) WT_DECL_RET; char *from_path, *to_path; - WT_VERBOSE_RET(session, fileops, "rename %s to %s", from, to); + WT_RET(__wt_verbose( + session, WT_VERB_FILEOPS, "rename %s to %s", from, to)); from_path = to_path = NULL; diff --git a/src/os_posix/os_rw.c b/src/os_posix/os_rw.c index becb00281ac..e2b133f2b77 100644 --- a/src/os_posix/os_rw.c +++ b/src/os_posix/os_rw.c @@ -21,9 +21,9 @@ __wt_read( WT_STAT_FAST_CONN_INCR(session, read_io); - WT_VERBOSE_RET(session, fileops, + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, "%s: read %zu bytes at offset %" PRIuMAX, - fh->name, len, (uintmax_t)offset); + fh->name, len, (uintmax_t)offset)); /* Assert direct I/O is aligned and a multiple of the alignment. */ WT_ASSERT(session, @@ -60,9 +60,9 @@ __wt_write(WT_SESSION_IMPL *session, WT_STAT_FAST_CONN_INCR(session, write_io); - WT_VERBOSE_RET(session, fileops, + WT_RET(__wt_verbose(session, WT_VERB_FILEOPS, "%s: write %zu bytes at offset %" PRIuMAX, - fh->name, len, (uintmax_t)offset); + fh->name, len, (uintmax_t)offset)); /* Assert direct I/O is aligned and a multiple of the alignment. */ WT_ASSERT(session, diff --git a/src/support/err.c b/src/support/err.c index 0536d69ae4a..ea9f13dcd2e 100644 --- a/src/support/err.c +++ b/src/support/err.c @@ -135,11 +135,11 @@ __wt_event_handler_set(WT_SESSION_IMPL *session, WT_EVENT_HANDLER *handler) } /* - * __eventv -- + * __wt_eventv -- * Report a message to an event handler. */ -static int -__eventv(WT_SESSION_IMPL *session, int msg_event, int error, +int +__wt_eventv(WT_SESSION_IMPL *session, int msg_event, int error, const char *file_name, int line_number, const char *fmt, va_list ap) { WT_EVENT_HANDLER *handler; @@ -303,7 +303,7 @@ __wt_err(WT_SESSION_IMPL *session, int error, const char *fmt, ...) * an error value to return. */ va_start(ap, fmt); - (void)__eventv(session, 0, error, NULL, 0, fmt, ap); + (void)__wt_eventv(session, 0, error, NULL, 0, fmt, ap); va_end(ap); } @@ -322,7 +322,7 @@ __wt_errx(WT_SESSION_IMPL *session, const char *fmt, ...) * an error value to return. */ va_start(ap, fmt); - (void)__eventv(session, 0, 0, NULL, 0, fmt, ap); + (void)__wt_eventv(session, 0, 0, NULL, 0, fmt, ap); va_end(ap); } @@ -343,7 +343,7 @@ __wt_ext_err_printf( session = ((WT_CONNECTION_IMPL *)wt_api->conn)->default_session; va_start(ap, fmt); - ret = __eventv(session, 0, 0, NULL, 0, fmt, ap); + ret = __wt_eventv(session, 0, 0, NULL, 0, fmt, ap); va_end(ap); return (ret); } @@ -434,23 +434,6 @@ __wt_progress(WT_SESSION_IMPL *session, const char *s, uint64_t v) } /* - * __wt_verbose -- - * Verbose message. - */ -int -__wt_verbose(WT_SESSION_IMPL *session, const char *fmt, ...) - WT_GCC_FUNC_ATTRIBUTE((format (printf, 2, 3))) -{ - WT_DECL_RET; - va_list ap; - - va_start(ap, fmt); - ret = __eventv(session, 1, 0, NULL, 0, fmt, ap); - va_end(ap); - return (ret); -} - -/* * __wt_assert -- * Assert and other unexpected failures, includes file/line information * for debugging. @@ -463,7 +446,7 @@ __wt_assert(WT_SESSION_IMPL *session, va_list ap; va_start(ap, fmt); - (void)__eventv(session, 0, error, file_name, line_number, fmt, ap); + (void)__wt_eventv(session, 0, error, file_name, line_number, fmt, ap); va_end(ap); #ifdef HAVE_DIAGNOSTIC diff --git a/src/txn/txn_recover.c b/src/txn/txn_recover.c index 34f53a3ef61..a1dc91d24da 100644 --- a/src/txn/txn_recover.c +++ b/src/txn/txn_recover.c @@ -60,8 +60,8 @@ __recovery_cursor(WT_SESSION_IMPL *session, WT_RECOVERY *r, else if (id > r->max_fileid) r->max_fileid = id; else if (id >= r->nfiles || r->files[id].uri == NULL) - WT_VERBOSE_RET(session, recovery, - "No file found with ID %u (max %u)", id, r->nfiles); + WT_RET(__wt_verbose(session, WT_VERB_RECOVERY, + "No file found with ID %u (max %u)", id, r->nfiles)); else if ((c = r->files[id].c) == NULL) { WT_RET(__wt_open_cursor( session, r->files[id].uri, NULL, cfg, &c)); @@ -82,10 +82,10 @@ __recovery_cursor(WT_SESSION_IMPL *session, WT_RECOVERY *r, #define GET_RECOVERY_CURSOR(session, r, lsnp, fileid, cp) \ WT_ERR(__recovery_cursor( \ (session), (r), (lsnp), (fileid), 0, (cp))); \ - WT_VERBOSE_ERR((session), recovery, \ + WT_ERR(__wt_verbose((session), WT_VERB_RECOVERY, \ "%s op %d to file %d at LSN %u/%" PRIuMAX, \ (cursor == NULL) ? "Skipping" : "Applying", \ - optype, fileid, lsnp->file, (uintmax_t)lsnp->offset); \ + optype, fileid, lsnp->file, (uintmax_t)lsnp->offset)); \ if (cursor == NULL) \ break @@ -314,9 +314,9 @@ __recovery_setup_file(WT_RECOVERY *r, const char *uri, const char *config) (int)cval.len, cval.str); r->files[fileid].ckpt_lsn = lsn; - WT_VERBOSE_RET(r->session, recovery, + WT_RET(__wt_verbose(r->session, WT_VERB_RECOVERY, "Recovering %s with id %u @ (%" PRIu32 ", %" PRIu64 ")", - uri, fileid, lsn.file, lsn.offset); + uri, fileid, lsn.file, lsn.offset)); return (0); @@ -426,9 +426,9 @@ __wt_txn_recover(WT_SESSION_IMPL *default_session) * Pass WT_LOGSCAN_RECOVER so that old logs get truncated. */ r.metadata_only = 0; - WT_VERBOSE_ERR(session, recovery, + WT_ERR(__wt_verbose(session, WT_VERB_RECOVERY, "Main recovery loop: starting at %u/%" PRIuMAX, - r.ckpt_lsn.file, (uintmax_t)r.ckpt_lsn.offset); + r.ckpt_lsn.file, (uintmax_t)r.ckpt_lsn.offset)); if (IS_INIT_LSN(&r.ckpt_lsn)) WT_ERR(__wt_log_scan(session, NULL, WT_LOGSCAN_FIRST | WT_LOGSCAN_RECOVER, |