Rename verbose ckpt to checkpoint, add some more messages to it.

The messages relate to the volume of data being written in checkpoints.

6 files changed, 38 insertions, 14 deletions

diff --git a/src/block/block_ckpt.c b/src/block/block_ckpt.c
index 5f31442c785..173d3f4792a 100644
--- a/src/block/block_ckpt.c
+++ b/src/block/block_ckpt.c
@@ -58,12 +58,12 @@ __wt_block_checkpoint_load(WT_SESSION_IMPL *session, WT_BLOCK *block,
 	 */
 	*root_addr_sizep = 0;
 
-	if (WT_VERBOSE_ISSET(session, ckpt)) {
+	if (WT_VERBOSE_ISSET(session, checkpoint)) {
 		if (addr != NULL) {
 			WT_ERR(__wt_scr_alloc(session, 0, &tmp));
 			WT_ERR(__ckpt_string(session, block, addr, tmp));
 		}
-		WT_VERBOSE_ERR(session, ckpt,
+		WT_VERBOSE_ERR(session, checkpoint,
 		    "%s: load-checkpoint: %s", block->name,
 		    addr == NULL ? "[Empty]" : (const char *)tmp->data);
 	}
@@ -127,7 +127,7 @@ __wt_block_checkpoint_load(WT_SESSION_IMPL *session, WT_BLOCK *block,
 	 * enough I don't bother).
 	 */
 	if (!checkpoint) {
-		WT_VERBOSE_ERR(session, ckpt,
+		WT_VERBOSE_ERR(session, checkpoint,
 		    "truncate file to %" PRIuMAX, (uintmax_t)ci->file_size);
 		WT_ERR(__wt_ftruncate(session, block->fh, ci->file_size));
 	}
@@ -436,12 +436,12 @@ __ckpt_process(
 		    !F_ISSET(ckpt, WT_CKPT_DELETE))
 			continue;
 
-		if (WT_VERBOSE_ISSET(session, ckpt)) {
+		if (WT_VERBOSE_ISSET(session, 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, ckpt,
+			WT_VERBOSE_ERR(session, checkpoint,
 			    "%s: delete-checkpoint: %s: %s",
 			    block->name, ckpt->name, (const char *)tmp->data);
 		}
@@ -694,10 +694,10 @@ __ckpt_update(
 	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, ckpt)) {
+	if (WT_VERBOSE_ISSET(session, checkpoint)) {
 		WT_RET(__wt_scr_alloc(session, 0, &tmp));
 		WT_ERR(__ckpt_string(session, block, ckpt->raw.data, tmp));
-		WT_VERBOSE_ERR(session, ckpt,
+		WT_VERBOSE_ERR(session, checkpoint,
 		    "%s: create-checkpoint: %s: %s",
 		    block->name, ckpt->name, (const char *)tmp->data);
 	}
diff --git a/src/btree/bt_evict.c b/src/btree/bt_evict.c
index 0b0ce053b66..b0c30bab320 100644
--- a/src/btree/bt_evict.c
+++ b/src/btree/bt_evict.c
@@ -585,11 +585,18 @@ __wt_sync_file(WT_SESSION_IMPL *session, int syncop)
 	WT_PAGE *page;
 	WT_TXN *txn;
 	uint32_t flags;
+	uint64_t internal_bytes, leaf_bytes;
+	uint64_t internal_pages, leaf_pages;
+	struct timespec end, start;
 
 	btree = S2BT(session);
 	cache = S2C(session)->cache;
 	page = NULL;
 	txn = &session->txn;
+	internal_bytes = leaf_bytes = 0;
+	internal_pages = leaf_pages = 0;
+	if (WT_VERBOSE_ISSET(session, checkpoint))
+		WT_RET(__wt_epoch(session, &start));
 
 	switch (syncop) {
 	case WT_SYNC_CHECKPOINT:
@@ -609,6 +616,8 @@ __wt_sync_file(WT_SESSION_IMPL *session, int syncop)
 				if (txn->isolation == TXN_ISO_READ_COMMITTED)
 					__wt_txn_refresh(
 					    session, WT_TXN_NONE, 1);
+				leaf_bytes += page->memory_footprint;
+				++leaf_pages;
 				ret = __wt_rec_write(session, page, NULL, 0);
 				if (txn->isolation == TXN_ISO_READ_COMMITTED)
 					__wt_txn_release_snapshot(session);
@@ -649,8 +658,11 @@ __wt_sync_file(WT_SESSION_IMPL *session, int syncop)
 		WT_ERR(__wt_tree_walk(session, &page, flags));
 		while (page != NULL) {
 			/* Write dirty pages. */
-			if (__wt_page_is_modified(page))
+			if (__wt_page_is_modified(page)) {
+				internal_bytes += page->memory_footprint;
+				++internal_pages;
 				WT_ERR(__wt_rec_write(session, page, NULL, 0));
+			}
 			WT_ERR(__wt_tree_walk(session, &page, flags));
 		}
 		break;
@@ -661,6 +673,18 @@ err:	/* On error, clear any left-over tree walk. */
 	if (page != NULL)
 		WT_TRET(__wt_page_release(session, page));
 
+	if (WT_VERBOSE_ISSET(session, checkpoint)) {
+		WT_RET(__wt_epoch(session, &end));
+		WT_VERBOSE_ERR(session, checkpoint,
+		    "__wt_sync_file WT_SYNC_%s wrote:\n\t %" PRIu64
+		    " bytes, %" PRIu64 " pages of leaves\n\t %" PRIu64
+		    " bytes, %" PRIu64 " pages of internal\n\t"
+		    "Took: %" PRIu64 "ms\n",
+		    syncop == WT_SYNC_WRITE_LEAVES ?
+		    "WRITE_LEAVES" : "CHECKPOINT",
+		    leaf_bytes, leaf_pages, internal_bytes, internal_pages,
+		    WT_TIMEDIFF(end, start) / WT_MILLION);
+	}
 	if (btree->checkpointing) {
 		/*
 		 * Clear the checkpoint flag and push the change; not required,
diff --git a/src/config/config_def.c b/src/config/config_def.c
index ac13fb9693c..0e6e80cf8fa 100644
--- a/src/config/config_def.c
+++ b/src/config/config_def.c
@@ -43,7 +43,7 @@ static const WT_CONFIG_CHECK confchk_connection_reconfigure[] = {
 	    "choices=[\"all\",\"fast\",\"none\",\"clear\"]",
 	    NULL},
 	{ "verbose", "list",
-	    "choices=[\"block\",\"ckpt\",\"compact\",\"evict\","
+	    "choices=[\"block\",\"checkpoint\",\"compact\",\"evict\","
 	    "\"evictserver\",\"fileops\",\"log\",\"lsm\",\"mutex\","
 	    "\"overflow\",\"read\",\"readserver\",\"reconcile\",\"recovery\","
 	    "\"salvage\",\"shared_cache\",\"verify\",\"version\",\"write\"]",
@@ -276,7 +276,7 @@ static const WT_CONFIG_CHECK confchk_wiredtiger_open[] = {
 	    NULL},
 	{ "use_environment_priv", "boolean", NULL, NULL},
 	{ "verbose", "list",
-	    "choices=[\"block\",\"ckpt\",\"compact\",\"evict\","
+	    "choices=[\"block\",\"checkpoint\",\"compact\",\"evict\","
 	    "\"evictserver\",\"fileops\",\"log\",\"lsm\",\"mutex\","
 	    "\"overflow\",\"read\",\"readserver\",\"reconcile\",\"recovery\","
 	    "\"salvage\",\"shared_cache\",\"verify\",\"version\",\"write\"]",
diff --git a/src/conn/conn_api.c b/src/conn/conn_api.c
index b534fba5844..055e3bab48c 100644
--- a/src/conn/conn_api.c
+++ b/src/conn/conn_api.c
@@ -960,7 +960,7 @@ __conn_verbose_config(WT_SESSION_IMPL *session, const char *cfg[])
 		uint32_t flag;
 	} *ft, verbtypes[] = {
 		{ "block",		WT_VERB_block },
-		{ "ckpt",		WT_VERB_ckpt },
+		{ "checkpoint",		WT_VERB_checkpoint },
 		{ "compact",		WT_VERB_compact },
 		{ "evict",		WT_VERB_evict },
 		{ "evictserver",	WT_VERB_evictserver },
diff --git a/src/include/flags.h b/src/include/flags.h
index 702b07ef000..fbe50251a0e 100644
--- a/src/include/flags.h
+++ b/src/include/flags.h
@@ -47,7 +47,7 @@
 #define	WT_TXN_LOG_CKPT_START				0x00000002
 #define	WT_TXN_LOG_CKPT_STOP				0x00000001
 #define	WT_VERB_block					0x00020000
-#define	WT_VERB_ckpt					0x00010000
+#define	WT_VERB_checkpoint				0x00010000
 #define	WT_VERB_compact					0x00008000
 #define	WT_VERB_evict					0x00004000
 #define	WT_VERB_evictserver				0x00002000
diff --git a/src/include/wiredtiger.in b/src/include/wiredtiger.in
index 24ce96e189f..114ef38da49 100644
--- a/src/include/wiredtiger.in
+++ b/src/include/wiredtiger.in
@@ -1264,7 +1264,7 @@ struct __wt_connection {
 	 * @config{verbose, enable messages for various events.  Options are
 	 * given as a list\, such as
 	 * <code>"verbose=[evictserver\,read]"</code>., a list\, with values
-	 * chosen from the following options: \c "block"\, \c "ckpt"\, \c
+	 * chosen from the following options: \c "block"\, \c "checkpoint"\, \c
 	 * "compact"\, \c "evict"\, \c "evictserver"\, \c "fileops"\, \c "log"\,
 	 * \c "lsm"\, \c "mutex"\, \c "overflow"\, \c "read"\, \c "readserver"\,
 	 * \c "reconcile"\, \c "recovery"\, \c "salvage"\, \c "shared_cache"\,
@@ -1598,7 +1598,7 @@ struct __wt_connection {
  * information., a boolean flag; default \c false.}
  * @config{verbose, enable messages for various events.  Options are given as a
  * list\, such as <code>"verbose=[evictserver\,read]"</code>., a list\, with
- * values chosen from the following options: \c "block"\, \c "ckpt"\, \c
+ * values chosen from the following options: \c "block"\, \c "checkpoint"\, \c
  * "compact"\, \c "evict"\, \c "evictserver"\, \c "fileops"\, \c "log"\, \c
  * "lsm"\, \c "mutex"\, \c "overflow"\, \c "read"\, \c "readserver"\, \c
  * "reconcile"\, \c "recovery"\, \c "salvage"\, \c "shared_cache"\, \c