diff options
author | sueloverso <sue@mongodb.com> | 2017-08-30 09:41:16 -0400 |
---|---|---|
committer | GitHub <noreply@github.com> | 2017-08-30 09:41:16 -0400 |
commit | 9ab5e592e8ae5f7ad5522dfaf49d8f130d69168e (patch) | |
tree | 4fde43ab6aca5b896f3be84f26417f9752af1ef0 | |
parent | 0cdb4a0a43f968ed3bed62ade31517e19c860c94 (diff) | |
download | mongo-9ab5e592e8ae5f7ad5522dfaf49d8f130d69168e.tar.gz |
WT-3529 Add WT_CONNECTION::debug_info method. (#3610)
* WT-3529 Add WT_CONNECTION::dump method.
* Add dump of logging subsystem
* Rename method to conn->debug_info. Rename LSN macro.
* Add debug info for handles. Add ifdefs.
* Add sessions dump
* Add cursor debug information
* Add WT_UNUSED and clean up string output.
* Add const
* Make the API undocumented.
Don't hide it behind HAVE_VERBOSE or HAVE_DIAGNOSTIC. There
are no performance costs to enabling the code, so I think
it's better to keep the story simple.
* Add more strings for cursor bits. Other review feedback
* Print number of internal sessions.
* Fix return after jump to err.
* Add debug_info unit test
* Whitespace
-rw-r--r-- | dist/api_data.py | 14 | ||||
-rw-r--r-- | dist/s_string.ok | 1 | ||||
-rw-r--r-- | lang/java/java_doc.i | 1 | ||||
-rw-r--r-- | src/config/config_def.c | 15 | ||||
-rw-r--r-- | src/conn/conn_api.c | 158 | ||||
-rw-r--r-- | src/conn/conn_dhandle.c | 40 | ||||
-rw-r--r-- | src/evict/evict_lru.c | 2 | ||||
-rw-r--r-- | src/include/config.h | 89 | ||||
-rw-r--r-- | src/include/extern.h | 4 | ||||
-rw-r--r-- | src/include/log.h | 7 | ||||
-rw-r--r-- | src/include/wiredtiger.in | 27 | ||||
-rw-r--r-- | src/log/log_sys.c | 61 | ||||
-rw-r--r-- | src/txn/txn.c | 143 | ||||
-rw-r--r-- | test/suite/test_debug_info.py | 71 |
14 files changed, 517 insertions, 116 deletions
diff --git a/dist/api_data.py b/dist/api_data.py index 37f9baedc70..6936ab6c96f 100644 --- a/dist/api_data.py +++ b/dist/api_data.py @@ -1213,6 +1213,20 @@ methods = { don't free memory during close''', type='boolean'), ]), +'WT_CONNECTION.debug_info' : Method([ + Config('cache', 'false', r''' + print cache information''', type='boolean'), + Config('cursors', 'false', r''' + print all open cursor information''', type='boolean'), + Config('handles', 'false', r''' + print open handles information''', type='boolean'), + Config('log', 'false', r''' + print log information''', type='boolean'), + Config('sessions', 'false', r''' + print open session information''', type='boolean'), + Config('txn', 'false', r''' + print global txn information''', type='boolean'), +]), 'WT_CONNECTION.reconfigure' : Method( connection_reconfigure_log_configuration +\ connection_reconfigure_statistics_log_configuration +\ diff --git a/dist/s_string.ok b/dist/s_string.ok index 099e5860aee..e6597734999 100644 --- a/dist/s_string.ok +++ b/dist/s_string.ok @@ -177,6 +177,7 @@ INMEM INSN INTL INULL +INUSE ISA ITEMs ITER diff --git a/lang/java/java_doc.i b/lang/java/java_doc.i index 75d393adcde..28990234e59 100644 --- a/lang/java/java_doc.i +++ b/lang/java/java_doc.i @@ -57,6 +57,7 @@ COPYDOC(__wt_session, WT_SESSION, transaction_sync) COPYDOC(__wt_connection, WT_CONNECTION, async_flush) COPYDOC(__wt_connection, WT_CONNECTION, async_new_op) COPYDOC(__wt_connection, WT_CONNECTION, close) +COPYDOC(__wt_connection, WT_CONNECTION, debug_info) COPYDOC(__wt_connection, WT_CONNECTION, reconfigure) COPYDOC(__wt_connection, WT_CONNECTION, configure_method) COPYDOC(__wt_connection, WT_CONNECTION, is_new) diff --git a/src/config/config_def.c b/src/config/config_def.c index 764006b024d..9f08872dc61 100644 --- a/src/config/config_def.c +++ b/src/config/config_def.c @@ -15,6 +15,16 @@ static const WT_CONFIG_CHECK confchk_WT_CONNECTION_close[] = { { NULL, NULL, NULL, NULL, NULL, 0 } }; +static const WT_CONFIG_CHECK confchk_WT_CONNECTION_debug_info[] = { + { "cache", "boolean", NULL, NULL, NULL, 0 }, + { "cursors", "boolean", NULL, NULL, NULL, 0 }, + { "handles", "boolean", NULL, NULL, NULL, 0 }, + { "log", "boolean", NULL, NULL, NULL, 0 }, + { "sessions", "boolean", NULL, NULL, NULL, 0 }, + { "txn", "boolean", NULL, NULL, NULL, 0 }, + { NULL, NULL, NULL, NULL, NULL, 0 } +}; + static const WT_CONFIG_CHECK confchk_WT_CONNECTION_load_extension[] = { { "config", "string", NULL, NULL, NULL, 0 }, { "early_load", "boolean", NULL, NULL, NULL, 0 }, @@ -1114,6 +1124,11 @@ static const WT_CONFIG_ENTRY config_entries[] = { "leak_memory=false", confchk_WT_CONNECTION_close, 1 }, + { "WT_CONNECTION.debug_info", + "cache=false,cursors=false,handles=false,log=false,sessions=false" + ",txn=false", + confchk_WT_CONNECTION_debug_info, 6 + }, { "WT_CONNECTION.load_extension", "config=,early_load=false,entry=wiredtiger_extension_init," "terminate=wiredtiger_extension_terminate", diff --git a/src/conn/conn_api.c b/src/conn/conn_api.c index b29b6184ce3..bacfcc6d5e6 100644 --- a/src/conn/conn_api.c +++ b/src/conn/conn_api.c @@ -1093,6 +1093,49 @@ err: /* } /* + * __conn_debug_info -- + * WT_CONNECTION->debug_info method. + */ +static int +__conn_debug_info(WT_CONNECTION *wt_conn, const char *config) +{ + WT_CONFIG_ITEM cval; + WT_CONNECTION_IMPL *conn; + WT_DECL_RET; + WT_SESSION_IMPL *session; + + conn = (WT_CONNECTION_IMPL *)wt_conn; + + CONNECTION_API_CALL(conn, session, debug_info, config, cfg); + + WT_ERR(__wt_config_gets(session, cfg, "cache", &cval)); + if (cval.val != 0) + WT_ERR(__wt_verbose_dump_cache(session)); + + WT_ERR(__wt_config_gets(session, cfg, "cursors", &cval)); + if (cval.val != 0) + WT_ERR(__wt_verbose_dump_sessions(session, true)); + + WT_ERR(__wt_config_gets(session, cfg, "handles", &cval)); + if (cval.val != 0) + WT_ERR(__wt_verbose_dump_handles(session)); + + WT_ERR(__wt_config_gets(session, cfg, "log", &cval)); + if (cval.val != 0) + WT_ERR(__wt_verbose_dump_log(session)); + + WT_ERR(__wt_config_gets(session, cfg, "sessions", &cval)); + if (cval.val != 0) + WT_ERR(__wt_verbose_dump_sessions(session, false)); + + WT_ERR(__wt_config_gets(session, cfg, "txn", &cval)); + if (cval.val != 0) + WT_ERR(__wt_verbose_dump_txn(session)); +err: + API_END_RET(session, ret); +} + +/* * __conn_reconfigure -- * WT_CONNECTION->reconfigure method. */ @@ -1780,6 +1823,120 @@ __wt_verbose_config(WT_SESSION_IMPL *session, const char *cfg[]) } /* + * __wt_verbose_dump_sessions -- + * Print out debugging information about sessions. + */ +int +__wt_verbose_dump_sessions(WT_SESSION_IMPL *session, bool show_cursors) +{ + WT_CONNECTION_IMPL *conn; + WT_CURSOR *cursor; + WT_DECL_ITEM(buf); + WT_DECL_RET; + WT_SESSION_IMPL *s; + uint32_t i, internal; + + conn = S2C(session); + WT_RET(__wt_msg(session, "%s", WT_DIVIDER)); + WT_RET(__wt_msg(session, "Active sessions: %" PRIu32 " Max: %" PRIu32, + conn->session_cnt, conn->session_size)); + WT_RET(__wt_scr_alloc(session, 0, &buf)); + internal = 0; + for (s = conn->sessions, i = 0; i < conn->session_cnt; ++s, ++i) { + /* + * If it is not active or it is an internal session + * it is not interesting. + */ + if (!s->active) + continue; + if (F_ISSET(s, WT_SESSION_INTERNAL)) { + ++internal; + continue; + } + WT_ASSERT(session, i == s->id); + WT_ERR(__wt_msg(session, + "Session: ID: %" PRIu32 " @: 0x%p", i, (void *)s)); + WT_ERR(__wt_msg(session, " Name: %s", + s->name == NULL ? "EMPTY" : s->name)); + if (!show_cursors) { + WT_ERR(__wt_msg(session, " Last operation: %s", + s->lastop == NULL ? "NONE" : s->lastop)); + WT_ERR(__wt_msg(session, " Current dhandle: %s", + s->dhandle == NULL ? "NONE" : s->dhandle->name)); + WT_ERR(__wt_msg(session, " Backup in progress: %s", + s->bkp_cursor == NULL ? "no" : "yes")); + WT_ERR(__wt_msg(session, " Compact state: %s", + s->compact_state == WT_COMPACT_NONE ? "none" : + (s->compact_state == WT_COMPACT_RUNNING ? + "running" : "success"))); + WT_ERR(__wt_msg(session, + " Flags: 0x%" PRIx32, s->flags)); + WT_ERR(__wt_msg(session, " Isolation level: %s", + s->isolation == WT_ISO_READ_COMMITTED ? + "read-committed" : + (s->isolation == WT_ISO_READ_UNCOMMITTED ? + "read-uncommitted" : "snapshot"))); + WT_ERR(__wt_msg(session, " Transaction:")); + WT_ERR(__wt_verbose_dump_txn_one(session, &s->txn)); + } else { + WT_ERR(__wt_msg(session, + " Number of positioned cursors: %u", s->ncursors)); + TAILQ_FOREACH(cursor, &s->cursors, q) { + WT_ERR(__wt_msg(session, + "Cursor @ %p:", (void *)cursor)); + WT_ERR(__wt_msg(session, + " URI: %s, Internal URI: %s", + cursor->uri == NULL ? "EMPTY" : cursor->uri, + cursor->internal_uri == NULL ? "EMPTY" : + cursor->internal_uri)); + if (F_ISSET(cursor, WT_CURSTD_OPEN)) { + WT_ERR(__wt_buf_fmt( + session, buf, "OPEN")); + if (F_ISSET(cursor, + WT_CURSTD_KEY_SET) || + F_ISSET(cursor, + WT_CURSTD_VALUE_SET)) + WT_ERR(__wt_buf_catfmt(session, + buf, ", POSITIONED")); + else + WT_ERR(__wt_buf_catfmt(session, + buf, ", RESET")); + if (F_ISSET(cursor, WT_CURSTD_APPEND)) + WT_ERR(__wt_buf_catfmt(session, + buf, ", APPEND")); + if (F_ISSET(cursor, WT_CURSTD_BULK)) + WT_ERR(__wt_buf_catfmt(session, + buf, ", BULK")); + if (F_ISSET(cursor, + WT_CURSTD_META_INUSE)) + WT_ERR(__wt_buf_catfmt(session, + buf, ", META_INUSE")); + if (F_ISSET(cursor, + WT_CURSTD_OVERWRITE)) + WT_ERR(__wt_buf_catfmt(session, + buf, ", OVERWRITE")); + WT_ERR(__wt_msg(session, + " %s", (const char *)buf->data)); + } + WT_ERR(__wt_msg(session, + " Flags: 0x%" PRIx32, cursor->flags)); + WT_ERR(__wt_msg(session, + " Key_format: %s, Value_format: %s", + cursor->key_format == NULL ? "EMPTY" : + cursor->key_format, + cursor->value_format == NULL ? "EMPTY" : + cursor->value_format)); + } + } + } + if (!show_cursors) + WT_ERR(__wt_msg(session, + "Internal sessions: %" PRIu32, internal)); +err: __wt_scr_free(session, &buf); + return (ret); +} + +/* * __wt_timing_stress_config -- * Set timing stress for test delay configuration. */ @@ -2045,6 +2202,7 @@ wiredtiger_open(const char *home, WT_EVENT_HANDLER *event_handler, __conn_async_flush, __conn_async_new_op, __conn_close, + __conn_debug_info, __conn_reconfigure, __conn_get_home, __conn_configure_method, diff --git a/src/conn/conn_dhandle.c b/src/conn/conn_dhandle.c index 197443ebf1c..af22cbb2bc2 100644 --- a/src/conn/conn_dhandle.c +++ b/src/conn/conn_dhandle.c @@ -810,3 +810,43 @@ restart: return (ret); } + +/* + * __wt_verbose_dump_handles -- + * Dump information about all data handles. + */ +int +__wt_verbose_dump_handles(WT_SESSION_IMPL *session) +{ + WT_CONNECTION_IMPL *conn; + WT_DATA_HANDLE *dhandle; + + conn = S2C(session); + + WT_RET(__wt_msg(session, "%s", WT_DIVIDER)); + WT_RET(__wt_msg(session, "Data handle dump:")); + for (dhandle = NULL;;) { + WT_WITH_HANDLE_LIST_READ_LOCK(session, + WT_DHANDLE_NEXT(session, dhandle, &conn->dhqh, q)); + if (dhandle == NULL) + return (0); + WT_RET(__wt_msg(session, "Name: %s", dhandle->name)); + if (dhandle->checkpoint != NULL) + WT_RET(__wt_msg(session, + "Checkpoint: %s", dhandle->checkpoint)); + WT_RET(__wt_msg(session, " Sessions referencing handle: %" + PRIu32, dhandle->session_ref)); + WT_RET(__wt_msg(session, " Sessions using handle: %" + PRId32, dhandle->session_inuse)); + WT_RET(__wt_msg(session, " Exclusive references to handle: %" + PRIu32, dhandle->excl_ref)); + if (dhandle->excl_ref != 0) + WT_RET(__wt_msg(session, + " Session with exclusive use: %p", + (void *)dhandle->excl_session)); + WT_RET(__wt_msg(session, + " Flags: 0x%08" PRIx32, dhandle->flags)); + } + WT_RET(__wt_msg(session, "%s", WT_DIVIDER)); + return (0); +} diff --git a/src/evict/evict_lru.c b/src/evict/evict_lru.c index 62f0294170b..e7faa3c01ef 100644 --- a/src/evict/evict_lru.c +++ b/src/evict/evict_lru.c @@ -2418,7 +2418,6 @@ __wt_evict_priority_clear(WT_SESSION_IMPL *session) S2BT(session)->evict_priority = 0; } -#if defined(HAVE_DIAGNOSTIC) || defined(HAVE_VERBOSE) /* * __verbose_dump_cache_single -- * Output diagnostic information about a single file in the cache. @@ -2571,4 +2570,3 @@ __wt_verbose_dump_cache(WT_SESSION_IMPL *session) return (0); } -#endif diff --git a/src/include/config.h b/src/include/config.h index d02ec21023b..3698290f21b 100644 --- a/src/include/config.h +++ b/src/include/config.h @@ -56,50 +56,51 @@ struct __wt_config_parser_impl { #define WT_CONFIG_ENTRY_WT_CONNECTION_add_extractor 4 #define WT_CONFIG_ENTRY_WT_CONNECTION_async_new_op 5 #define WT_CONFIG_ENTRY_WT_CONNECTION_close 6 -#define WT_CONFIG_ENTRY_WT_CONNECTION_load_extension 7 -#define WT_CONFIG_ENTRY_WT_CONNECTION_open_session 8 -#define WT_CONFIG_ENTRY_WT_CONNECTION_query_timestamp 9 -#define WT_CONFIG_ENTRY_WT_CONNECTION_reconfigure 10 -#define WT_CONFIG_ENTRY_WT_CONNECTION_rollback_to_stable 11 -#define WT_CONFIG_ENTRY_WT_CONNECTION_set_file_system 12 -#define WT_CONFIG_ENTRY_WT_CONNECTION_set_timestamp 13 -#define WT_CONFIG_ENTRY_WT_CURSOR_close 14 -#define WT_CONFIG_ENTRY_WT_CURSOR_reconfigure 15 -#define WT_CONFIG_ENTRY_WT_SESSION_alter 16 -#define WT_CONFIG_ENTRY_WT_SESSION_begin_transaction 17 -#define WT_CONFIG_ENTRY_WT_SESSION_checkpoint 18 -#define WT_CONFIG_ENTRY_WT_SESSION_close 19 -#define WT_CONFIG_ENTRY_WT_SESSION_commit_transaction 20 -#define WT_CONFIG_ENTRY_WT_SESSION_compact 21 -#define WT_CONFIG_ENTRY_WT_SESSION_create 22 -#define WT_CONFIG_ENTRY_WT_SESSION_drop 23 -#define WT_CONFIG_ENTRY_WT_SESSION_join 24 -#define WT_CONFIG_ENTRY_WT_SESSION_log_flush 25 -#define WT_CONFIG_ENTRY_WT_SESSION_log_printf 26 -#define WT_CONFIG_ENTRY_WT_SESSION_open_cursor 27 -#define WT_CONFIG_ENTRY_WT_SESSION_rebalance 28 -#define WT_CONFIG_ENTRY_WT_SESSION_reconfigure 29 -#define WT_CONFIG_ENTRY_WT_SESSION_rename 30 -#define WT_CONFIG_ENTRY_WT_SESSION_reset 31 -#define WT_CONFIG_ENTRY_WT_SESSION_rollback_transaction 32 -#define WT_CONFIG_ENTRY_WT_SESSION_salvage 33 -#define WT_CONFIG_ENTRY_WT_SESSION_snapshot 34 -#define WT_CONFIG_ENTRY_WT_SESSION_strerror 35 -#define WT_CONFIG_ENTRY_WT_SESSION_timestamp_transaction 36 -#define WT_CONFIG_ENTRY_WT_SESSION_transaction_sync 37 -#define WT_CONFIG_ENTRY_WT_SESSION_truncate 38 -#define WT_CONFIG_ENTRY_WT_SESSION_upgrade 39 -#define WT_CONFIG_ENTRY_WT_SESSION_verify 40 -#define WT_CONFIG_ENTRY_colgroup_meta 41 -#define WT_CONFIG_ENTRY_file_config 42 -#define WT_CONFIG_ENTRY_file_meta 43 -#define WT_CONFIG_ENTRY_index_meta 44 -#define WT_CONFIG_ENTRY_lsm_meta 45 -#define WT_CONFIG_ENTRY_table_meta 46 -#define WT_CONFIG_ENTRY_wiredtiger_open 47 -#define WT_CONFIG_ENTRY_wiredtiger_open_all 48 -#define WT_CONFIG_ENTRY_wiredtiger_open_basecfg 49 -#define WT_CONFIG_ENTRY_wiredtiger_open_usercfg 50 +#define WT_CONFIG_ENTRY_WT_CONNECTION_debug_info 7 +#define WT_CONFIG_ENTRY_WT_CONNECTION_load_extension 8 +#define WT_CONFIG_ENTRY_WT_CONNECTION_open_session 9 +#define WT_CONFIG_ENTRY_WT_CONNECTION_query_timestamp 10 +#define WT_CONFIG_ENTRY_WT_CONNECTION_reconfigure 11 +#define WT_CONFIG_ENTRY_WT_CONNECTION_rollback_to_stable 12 +#define WT_CONFIG_ENTRY_WT_CONNECTION_set_file_system 13 +#define WT_CONFIG_ENTRY_WT_CONNECTION_set_timestamp 14 +#define WT_CONFIG_ENTRY_WT_CURSOR_close 15 +#define WT_CONFIG_ENTRY_WT_CURSOR_reconfigure 16 +#define WT_CONFIG_ENTRY_WT_SESSION_alter 17 +#define WT_CONFIG_ENTRY_WT_SESSION_begin_transaction 18 +#define WT_CONFIG_ENTRY_WT_SESSION_checkpoint 19 +#define WT_CONFIG_ENTRY_WT_SESSION_close 20 +#define WT_CONFIG_ENTRY_WT_SESSION_commit_transaction 21 +#define WT_CONFIG_ENTRY_WT_SESSION_compact 22 +#define WT_CONFIG_ENTRY_WT_SESSION_create 23 +#define WT_CONFIG_ENTRY_WT_SESSION_drop 24 +#define WT_CONFIG_ENTRY_WT_SESSION_join 25 +#define WT_CONFIG_ENTRY_WT_SESSION_log_flush 26 +#define WT_CONFIG_ENTRY_WT_SESSION_log_printf 27 +#define WT_CONFIG_ENTRY_WT_SESSION_open_cursor 28 +#define WT_CONFIG_ENTRY_WT_SESSION_rebalance 29 +#define WT_CONFIG_ENTRY_WT_SESSION_reconfigure 30 +#define WT_CONFIG_ENTRY_WT_SESSION_rename 31 +#define WT_CONFIG_ENTRY_WT_SESSION_reset 32 +#define WT_CONFIG_ENTRY_WT_SESSION_rollback_transaction 33 +#define WT_CONFIG_ENTRY_WT_SESSION_salvage 34 +#define WT_CONFIG_ENTRY_WT_SESSION_snapshot 35 +#define WT_CONFIG_ENTRY_WT_SESSION_strerror 36 +#define WT_CONFIG_ENTRY_WT_SESSION_timestamp_transaction 37 +#define WT_CONFIG_ENTRY_WT_SESSION_transaction_sync 38 +#define WT_CONFIG_ENTRY_WT_SESSION_truncate 39 +#define WT_CONFIG_ENTRY_WT_SESSION_upgrade 40 +#define WT_CONFIG_ENTRY_WT_SESSION_verify 41 +#define WT_CONFIG_ENTRY_colgroup_meta 42 +#define WT_CONFIG_ENTRY_file_config 43 +#define WT_CONFIG_ENTRY_file_meta 44 +#define WT_CONFIG_ENTRY_index_meta 45 +#define WT_CONFIG_ENTRY_lsm_meta 46 +#define WT_CONFIG_ENTRY_table_meta 47 +#define WT_CONFIG_ENTRY_wiredtiger_open 48 +#define WT_CONFIG_ENTRY_wiredtiger_open_all 49 +#define WT_CONFIG_ENTRY_wiredtiger_open_basecfg 50 +#define WT_CONFIG_ENTRY_wiredtiger_open_usercfg 51 /* * configuration section: END * DO NOT EDIT: automatically built by dist/flags.py. diff --git a/src/include/extern.h b/src/include/extern.h index 41137687a53..f4846029026 100644 --- a/src/include/extern.h +++ b/src/include/extern.h @@ -248,6 +248,7 @@ extern int __wt_conn_remove_encryptor(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL extern int __wt_extractor_config(WT_SESSION_IMPL *session, const char *uri, const char *config, WT_EXTRACTOR **extractorp, int *ownp) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_conn_remove_extractor(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_verbose_config(WT_SESSION_IMPL *session, const char *cfg[]) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); +extern int __wt_verbose_dump_sessions(WT_SESSION_IMPL *session, bool show_cursors) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_timing_stress_config(WT_SESSION_IMPL *session, const char *cfg[]) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_cache_config(WT_SESSION_IMPL *session, bool reconfigure, const char *cfg[]) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_cache_create(WT_SESSION_IMPL *session, const char *cfg[]) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); @@ -268,6 +269,7 @@ extern int __wt_conn_btree_apply(WT_SESSION_IMPL *session, const char *uri, int extern int __wt_conn_dhandle_close_all( WT_SESSION_IMPL *session, const char *uri, bool mark_dead) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_conn_dhandle_discard_single( WT_SESSION_IMPL *session, bool final, bool mark_dead) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_conn_dhandle_discard(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); +extern int __wt_verbose_dump_handles(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_connection_init(WT_CONNECTION_IMPL *conn) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern void __wt_connection_destroy(WT_CONNECTION_IMPL *conn); extern int __wt_logmgr_reconfig(WT_SESSION_IMPL *session, const char **cfg) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); @@ -436,6 +438,7 @@ extern int64_t __wt_log_slot_release(WT_MYSLOT *myslot, int64_t size); extern void __wt_log_slot_free(WT_SESSION_IMPL *session, WT_LOGSLOT *slot); extern int __wt_log_system_record( WT_SESSION_IMPL *session, WT_FH *log_fh, WT_LSN *lsn) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_log_recover_system(WT_SESSION_IMPL *session, const uint8_t **pp, const uint8_t *end, WT_LSN *lsnp) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); +extern int __wt_verbose_dump_log(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_clsm_request_switch(WT_CURSOR_LSM *clsm) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_clsm_await_switch(WT_CURSOR_LSM *clsm) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_clsm_init_merge( WT_CURSOR *cursor, u_int start_chunk, uint32_t start_id, u_int nchunks) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); @@ -786,6 +789,7 @@ extern void __wt_txn_destroy(WT_SESSION_IMPL *session); extern int __wt_txn_global_init(WT_SESSION_IMPL *session, const char *cfg[]) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern void __wt_txn_global_destroy(WT_SESSION_IMPL *session); extern int __wt_txn_global_shutdown(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); +extern int __wt_verbose_dump_txn_one(WT_SESSION_IMPL *session, WT_TXN *txn) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_verbose_dump_txn(WT_SESSION_IMPL *session) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_checkpoint_get_handles(WT_SESSION_IMPL *session, const char *cfg[]) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); extern int __wt_txn_checkpoint(WT_SESSION_IMPL *session, const char *cfg[], bool waiting) WT_GCC_FUNC_DECL_ATTRIBUTE((warn_unused_result)); diff --git a/src/include/log.h b/src/include/log.h index e6acdd1e834..3ec874ad5b6 100644 --- a/src/include/log.h +++ b/src/include/log.h @@ -58,6 +58,13 @@ union __wt_lsn { #define WT_IS_ZERO_LSN(l) ((l)->file_offset == 0) /* + * Macro to print an LSN. + */ +#define WT_LSN_MSG(lsn, msg) \ + __wt_msg(session, "%s LSN: [%" PRIu32 "][%" PRIu32 "]", \ + (msg), (lsn)->l.file, (lsn)->l.offset) + +/* * Both of the macros below need to change if the content of __wt_lsn * ever changes. The value is the following: * txnid, record type, operation type, file id, operation key, operation value diff --git a/src/include/wiredtiger.in b/src/include/wiredtiger.in index 485cd34ec7a..7eee17e285c 100644 --- a/src/include/wiredtiger.in +++ b/src/include/wiredtiger.in @@ -1980,6 +1980,33 @@ struct __wt_connection { int __F(close)(WT_HANDLE_CLOSED(WT_CONNECTION) *connection, const char *config); +#ifndef DOXYGEN + /*! + * Output debug information for various subsystems. The output format + * may change over time, gathering the debug information may be + * invasive, and the information reported may not provide a point in + * time view of the system. + * + * @param connection the connection handle + * @configstart{WT_CONNECTION.debug_info, see dist/api_data.py} + * @config{cache, print cache information., a boolean flag; default \c + * false.} + * @config{cursors, print all open cursor information., a boolean flag; + * default \c false.} + * @config{handles, print open handles information., a boolean flag; + * default \c false.} + * @config{log, print log information., a boolean flag; default \c + * false.} + * @config{sessions, print open session information., a boolean flag; + * default \c false.} + * @config{txn, print global txn information., a boolean flag; default + * \c false.} + * @configend + * @errors + */ + int __F(debug_info)(WT_CONNECTION *connection, const char *config); +#endif + /*! * Reconfigure a connection handle. * diff --git a/src/log/log_sys.c b/src/log/log_sys.c index 4eb2a8e23d2..6956aa99fe7 100644 --- a/src/log/log_sys.c +++ b/src/log/log_sys.c @@ -85,3 +85,64 @@ __wt_log_recover_system(WT_SESSION_IMPL *session, return (0); } + +/* + * __wt_verbose_dump_log -- + * Dump information about the logging subsystem. + */ +int +__wt_verbose_dump_log(WT_SESSION_IMPL *session) +{ + WT_CONNECTION_IMPL *conn; + WT_LOG *log; + + conn = S2C(session); + log = conn->log; + + WT_RET(__wt_msg(session, "%s", WT_DIVIDER)); + WT_RET(__wt_msg(session, "Logging subsystem: Enabled: %s", + FLD_ISSET(conn->log_flags, WT_CONN_LOG_ENABLED) ? "yes" : "no")); + if (!FLD_ISSET(conn->log_flags, WT_CONN_LOG_ENABLED)) + return (0); + /* + * Logging is enabled, print out the other information. + */ + WT_RET(__wt_msg(session, "Archiving: %s", + FLD_ISSET(conn->log_flags, WT_CONN_LOG_ARCHIVE) ? "yes" : "no")); + WT_RET(__wt_msg(session, "Running downgraded: %s", + FLD_ISSET(conn->log_flags, WT_CONN_LOG_DOWNGRADED) ? "yes" : "no")); + WT_RET(__wt_msg(session, "Zero fill files: %s", + FLD_ISSET(conn->log_flags, WT_CONN_LOG_ZERO_FILL) ? "yes" : "no")); + WT_RET(__wt_msg(session, "Pre-allocate files: %s", + conn->log_prealloc > 0 ? "yes" : "no")); + WT_RET(__wt_msg(session, "Logging directory: %s", conn->log_path)); + WT_RET(__wt_msg(session, "Logging maximum file size: %" PRId64, + (int64_t)conn->log_file_max)); + WT_RET(__wt_msg(session, "Log sync setting: %s", + !FLD_ISSET(conn->txn_logsync, WT_LOG_SYNC_ENABLED) ? "none" : + FLD_ISSET(conn->txn_logsync, WT_LOG_DSYNC) ? "dsync" : + FLD_ISSET(conn->txn_logsync, WT_LOG_FLUSH) ? "write to OS" : + FLD_ISSET(conn->txn_logsync, WT_LOG_FSYNC) ? + "fsync to disk": "unknown sync setting")); + WT_RET(__wt_msg(session, "Log record allocation alignment: %" PRIu32, + log->allocsize)); + WT_RET(__wt_msg(session, "Current log file number: %" PRIu32, + log->fileid)); + WT_RET(__wt_msg(session, "Current log version number: %" PRIu16, + log->log_version)); + WT_RET(WT_LSN_MSG(&log->alloc_lsn, "Next allocation")); + WT_RET(WT_LSN_MSG(&log->bg_sync_lsn, "Last background sync")); + WT_RET(WT_LSN_MSG(&log->ckpt_lsn, "Last checkpoint")); + WT_RET(WT_LSN_MSG(&log->sync_dir_lsn, "Last directory sync")); + WT_RET(WT_LSN_MSG(&log->sync_lsn, "Last sync")); + WT_RET(WT_LSN_MSG(&log->trunc_lsn, "Recovery truncate")); + WT_RET(WT_LSN_MSG(&log->write_lsn, "Last written")); + WT_RET(WT_LSN_MSG(&log->write_start_lsn, "Start of last written")); + /* + * If we wanted a dump of the slots, it would go here. Walking + * the slot pool may not require a lock since they're statically + * allocated, but output could be inconsistent without it. + */ + + return (0); +} diff --git a/src/txn/txn.c b/src/txn/txn.c index 09efb2924bf..e5b14492205 100644 --- a/src/txn/txn.c +++ b/src/txn/txn.c @@ -1028,7 +1028,70 @@ __wt_txn_global_shutdown(WT_SESSION_IMPL *session) return (0); } -#if defined(HAVE_DIAGNOSTIC) || defined(HAVE_VERBOSE) +/* + * __wt_verbose_dump_txn_one -- + * Output diagnostic information about a transaction structure. + */ +int +__wt_verbose_dump_txn_one(WT_SESSION_IMPL *session, WT_TXN *txn) +{ +#ifdef HAVE_TIMESTAMPS + char hex_timestamp[3][2 * WT_TIMESTAMP_SIZE + 1]; +#endif + const char *iso_tag; + + iso_tag = "INVALID"; + switch (txn->isolation) { + case WT_ISO_READ_COMMITTED: + iso_tag = "WT_ISO_READ_COMMITTED"; + break; + case WT_ISO_READ_UNCOMMITTED: + iso_tag = "WT_ISO_READ_UNCOMMITTED"; + break; + case WT_ISO_SNAPSHOT: + iso_tag = "WT_ISO_SNAPSHOT"; + break; + } +#ifdef HAVE_TIMESTAMPS + WT_RET(__wt_timestamp_to_hex_string( + session, hex_timestamp[0], &txn->commit_timestamp)); + WT_RET(__wt_timestamp_to_hex_string( + session, hex_timestamp[1], &txn->first_commit_timestamp)); + WT_RET(__wt_timestamp_to_hex_string( + session, hex_timestamp[2], &txn->read_timestamp)); + WT_RET(__wt_msg(session, + "mod count: %u" + ", snap min: %" PRIu64 + ", snap max: %" PRIu64 + ", commit_timestamp: %s" + ", first_commit_timestamp: %s" + ", read_timestamp: %s" + ", flags: 0x%08" PRIx32 + ", isolation: %s", + txn->mod_count, + txn->snap_min, + txn->snap_max, + hex_timestamp[0], + hex_timestamp[1], + hex_timestamp[2], + txn->flags, + iso_tag)); +#else + WT_RET(__wt_msg(session, + "mod count: %u" + ", snap min: %" PRIu64 + ", snap max: %" PRIu64 + ", flags: 0x%08" PRIx32 + ", isolation: %s", + txn->mod_count, + txn->snap_min, + txn->snap_max, + txn->flags, + iso_tag)); +#endif + return (0); +} + /* * __wt_verbose_dump_txn -- * Output diagnostic information about the global transaction state. @@ -1037,15 +1100,15 @@ int __wt_verbose_dump_txn(WT_SESSION_IMPL *session) { WT_CONNECTION_IMPL *conn; + WT_SESSION_IMPL *sess; WT_TXN_GLOBAL *txn_global; - WT_TXN *txn; WT_TXN_STATE *s; - const char *iso_tag; uint64_t id; uint32_t i, session_cnt; #ifdef HAVE_TIMESTAMPS char hex_timestamp[3][2 * WT_TIMESTAMP_SIZE + 1]; #endif + conn = S2C(session); txn_global = &conn->txn_global; @@ -1110,78 +1173,18 @@ __wt_verbose_dump_txn(WT_SESSION_IMPL *session) /* Skip sessions with no active transaction */ if ((id = s->id) == WT_TXN_NONE && s->pinned_id == WT_TXN_NONE) continue; - - txn = &conn->sessions[i].txn; - iso_tag = "INVALID"; - switch (txn->isolation) { - case WT_ISO_READ_COMMITTED: - iso_tag = "WT_ISO_READ_COMMITTED"; - break; - case WT_ISO_READ_UNCOMMITTED: - iso_tag = "WT_ISO_READ_UNCOMMITTED"; - break; - case WT_ISO_SNAPSHOT: - iso_tag = "WT_ISO_SNAPSHOT"; - break; - } -#ifdef HAVE_TIMESTAMPS - WT_RET(__wt_timestamp_to_hex_string( - session, hex_timestamp[0], &txn->commit_timestamp)); - WT_RET(__wt_timestamp_to_hex_string( - session, hex_timestamp[1], &txn->first_commit_timestamp)); - WT_RET(__wt_timestamp_to_hex_string( - session, hex_timestamp[2], &txn->read_timestamp)); - WT_RET(__wt_msg(session, - "ID: %8" PRIu64 - ", mod count: %u" - ", pinned ID: %8" PRIu64 - ", snap min: %" PRIu64 - ", snap max: %" PRIu64 - ", commit_timestamp: %s" - ", first_commit_timestamp: %s" - ", read_timestamp: %s" - ", metadata pinned ID: %" PRIu64 - ", flags: 0x%08" PRIx32 - ", name: %s" - ", isolation: %s", - id, - txn->mod_count, - s->pinned_id, - txn->snap_min, - txn->snap_max, - hex_timestamp[0], - hex_timestamp[1], - hex_timestamp[2], - s->metadata_pinned, - txn->flags, - conn->sessions[i].name == NULL ? - "EMPTY" : conn->sessions[i].name, - iso_tag)); -#else + sess = &conn->sessions[i]; WT_RET(__wt_msg(session, - "ID: %6" PRIu64 - ", mod count: %u" + "ID: %" PRIu64 ", pinned ID: %" PRIu64 - ", snap min: %" PRIu64 - ", snap max: %" PRIu64 ", metadata pinned ID: %" PRIu64 - ", flags: 0x%08" PRIx32 - ", name: %s" - ", isolation: %s", - id, - txn->mod_count, - s->pinned_id, - txn->snap_min, - txn->snap_max, - s->metadata_pinned, - txn->flags, - conn->sessions[i].name == NULL ? - "EMPTY" : conn->sessions[i].name, - iso_tag)); -#endif + ", name: %s", + id, s->pinned_id, s->metadata_pinned, + sess->name == NULL ? + "EMPTY" : sess->name)); + WT_RET(__wt_verbose_dump_txn_one(sess, &sess->txn)); } WT_RET(__wt_msg(session, "%s", WT_DIVIDER)); return (0); } -#endif diff --git a/test/suite/test_debug_info.py b/test/suite/test_debug_info.py new file mode 100644 index 00000000000..97fa8efbc86 --- /dev/null +++ b/test/suite/test_debug_info.py @@ -0,0 +1,71 @@ +#!/usr/bin/env python +# +# Public Domain 2014-2017 MongoDB, Inc. +# Public Domain 2008-2014 WiredTiger, Inc. +# +# This is free and unencumbered software released into the public domain. +# +# Anyone is free to copy, modify, publish, use, compile, sell, or +# distribute this software, either in source code form or as a compiled +# binary, for any purpose, commercial or non-commercial, and by any +# means. +# +# In jurisdictions that recognize copyright laws, the author or authors +# of this software dedicate any and all copyright interest in the +# software to the public domain. We make this dedication for the benefit +# of the public at large and to the detriment of our heirs and +# successors. We intend this dedication to be an overt act of +# relinquishment in perpetuity of all present and future rights to this +# software under copyright law. +# +# THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, +# EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF +# MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. +# IN NO EVENT SHALL THE AUTHORS BE LIABLE FOR ANY CLAIM, DAMAGES OR +# OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, +# ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR +# OTHER DEALINGS IN THE SOFTWARE. + +import wiredtiger, wttest + +# test_debug_info.py +# Test WT_CONNECTION::debug_info undocumented feature +class test_debug_info(wttest.WiredTigerTestCase): + conn_config = 'create,log=(enabled),statistics=(fast)' + uri = 'file:test_conndump' + def conn_cursors(self): + + self.session.create(self.uri, 'key_format=i,value_format=i') + c = self.session.open_cursor(self.uri, None) + keys = range(1, 101) + for k in keys: + c[k] = 1 + c.close() + c = self.session.open_cursor(self.uri, None) + val = c[50] + self.conn.debug_info('cursors') + c.close() + + def conn_cursors_special(self, special_uri): + c = self.session.open_cursor(special_uri, None, None) + self.conn.debug_info('cursors') + c.close() + + def test_debug(self): + with self.expectedStdoutPattern('Data handle dump'): + self.conn.debug_info('handles') + + with self.expectedStdoutPattern('Active'): + self.conn.debug_info('sessions') + + with self.expectedStdoutPattern('POSITIONED'): + self.conn_cursors() + + special = ['backup:', 'log:', 'metadata:', 'statistics:'] + for s in special: + pat = 'URI: ' + s + with self.expectedStdoutPattern(pat): + self.conn_cursors_special(s) + +if __name__ == '__main__': + wttest.run() |