X-Git-Url: http://git.vrable.net/?a=blobdiff_plain;f=bluesky%2Fdebug.c;h=5523b1ca4ccbe44f0f180b989512c0dbd812f00c;hb=8ff0fd08d6e1cc97cdb7e94b7cd97dc28c29e674;hp=312a0e1c80bf1422b0c55bca1a3673f890a11db2;hpb=f597cd5067ed36508118d2ecd29338e7b81f47e4;p=bluesky.git diff --git a/bluesky/debug.c b/bluesky/debug.c index 312a0e1..5523b1c 100644 --- a/bluesky/debug.c +++ b/bluesky/debug.c @@ -3,7 +3,29 @@ * Copyright (C) 2009 The Regents of the University of California * Written by Michael Vrable * - * TODO: Licensing + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * 3. Neither the name of the University nor the names of its contributors + * may be used to endorse or promote products derived from this software + * without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE REGENTS AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE REGENTS OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. */ #include @@ -31,19 +53,183 @@ static void inode_dump(gpointer key, gpointer value, gpointer user_data) locked ? 'T' : 'F', inode->refcount); g_print(" Type: %d Mode: %o\n", inode->type, inode->mode); - g_print(" change_count = %"PRIu64", change_commit = %"PRIu64"\n", - inode->change_count, inode->change_commit); + g_print(" change_count = %"PRIu64", change_commit = %"PRIu64", " + "change_cloud = %"PRIu64"\n", + inode->change_count, inode->change_commit, inode->change_cloud); +} + +static void cloudlog_dump(gpointer key, gpointer value, gpointer user_data) +{ + BlueSkyCloudLog *log = (BlueSkyCloudLog *)value; + + for (int i = 0; i < sizeof(BlueSkyCloudID); i++) { + g_print("%02x", (uint8_t)(log->id.bytes[i])); + } + g_print(": refs=%d ty=%d inode=%"PRIu64" locs=%x log@(%d,%d) cloud@(%d,%d,%d)\n", + log->refcount, + log->type, log->inum, + log->location_flags | (log->data != NULL ? 0x100 : 0), + log->log_seq, log->log_offset, log->location.directory, + log->location.sequence, log->location.offset); } +static void cache_dump(gpointer key, gpointer value, gpointer user_data) +{ + BlueSkyCacheFile *cache = (BlueSkyCacheFile *)value; + + int64_t age = bluesky_get_current_time() - cache->atime; + g_print("%s addr=%p mapcount=%d refcount=%d atime_age=%f", + cache->filename, cache->addr, cache->mapcount, cache->refcount, + age / 1e6); + if (cache->fetching) + g_print(" (fetching)"); + g_print("\n"); +} + + +void inode_map_dump(GSequence *inode_map) +{ + GSequenceIter *i, *j; + + g_print("\nInode map dump:\n"); + for (i = g_sequence_get_begin_iter(inode_map); + !g_sequence_iter_is_end(i); i = g_sequence_iter_next(i)) + { + InodeMapRange *range = (InodeMapRange *)g_sequence_get(i); + + g_print(" Range [%"PRIu64", %"PRIu64"]\n", range->start, range->end); + + for (j = g_sequence_get_begin_iter(range->map_entries); + !g_sequence_iter_is_end(j); j = g_sequence_iter_next(j)) + { + InodeMapEntry *entry = (InodeMapEntry *)g_sequence_get(j); + BlueSkyCloudLog *item = entry->item; + if (item != NULL) { + char *id = bluesky_cloudlog_id_to_string(item->id); + g_print(" Entry %"PRIu64" id=%s\n", entry->inum, id); + g_free(id); + } else { + g_print(" Entry %"PRIu64" not available\n", entry->inum); + } + } + } +} /* Dump a summary of filesystem state as it is cached in memory. */ void bluesky_debug_dump(BlueSkyFS *fs) { - g_print("*** DEBUG DUMP FOR FILESYSTEM %s ***\n", fs->name); - g_print("Cached blocks: %d\tDirty blocks: %d\n", - g_atomic_int_get(&fs->cache_total), - g_atomic_int_get(&fs->cache_dirty)); + g_print("\n*** DEBUG DUMP FOR FILESYSTEM %s ***\n", fs->name); + g_print("Dirty blocks: %d\n", g_atomic_int_get(&fs->cache_dirty)); g_print("Cached inodes: %u\tNext inode: %"PRIu64"\n", g_hash_table_size(fs->inodes), fs->next_inum); + g_print("Cloudlog cache: %d dirty, %d writeback, %d journal, %d cloud\n", + g_atomic_int_get(&fs->cache_log_dirty), + g_atomic_int_get(&fs->cache_log_writeback), + g_atomic_int_get(&fs->cache_log_journal), + g_atomic_int_get(&fs->cache_log_cloud)); + + GList *item; + g_print("Unsynced inode list:"); + for (item = fs->unlogged_list.next; item != NULL; item = item->next) { + g_print(" %"PRIu64";", ((BlueSkyInode *)item->data)->inum); + } + g_print("\n"); + g_print("Dirty inode LRU list:"); + for (item = fs->dirty_list.next; item != NULL; item = item->next) { + g_print(" %"PRIu64";", ((BlueSkyInode *)item->data)->inum); + } + g_print("\n"); + g_print("Accessed inode LRU list:"); + for (item = fs->accessed_list.next; item != NULL; item = item->next) { + g_print(" %"PRIu64";", ((BlueSkyInode *)item->data)->inum); + } + g_print("\n"); g_hash_table_foreach(fs->inodes, inode_dump, fs); + + g_print("\nLog Objects:\n"); + g_hash_table_foreach(fs->locations, cloudlog_dump, fs); + + g_print("\nJournal/Cache Files:\n"); + g_hash_table_foreach(fs->log->mmap_cache, cache_dump, fs); + g_print("\n"); + + g_mutex_lock(fs->lock); + inode_map_dump(fs->inode_map); + g_mutex_unlock(fs->lock); +} + +/* Statistics counters: for operation counts, bytes transferred, etc. */ +static GStaticMutex stats_lock = G_STATIC_MUTEX_INIT; +static GList *stats_list = NULL; + +struct bluesky_stats *bluesky_stats_new(const char *name) +{ + struct bluesky_stats *stats = g_new0(struct bluesky_stats, 1); + stats->name = name; + g_static_mutex_lock(&stats_lock); + stats_list = g_list_append(stats_list, stats); + g_static_mutex_unlock(&stats_lock); + return stats; +} + +void bluesky_stats_add(struct bluesky_stats *stats, int64_t value) +{ + __sync_fetch_and_add(&stats->count, (int64_t)1); + __sync_fetch_and_add(&stats->sum, value); +} + +void bluesky_stats_dump_all() +{ + g_static_mutex_lock(&stats_lock); + for (GList *item = stats_list; item != NULL; item = item->next) { + struct bluesky_stats *stats = (struct bluesky_stats *)item->data; + g_print("%s: count=%"PRIi64" sum=%"PRIi64"\n", + stats->name, stats->count, stats->sum); + } + g_static_mutex_unlock(&stats_lock); +} + +static void periodic_stats_dumper(FILE *f) +{ + const int64_t interval = 10 * 1000000000ULL; + bluesky_time_hires timestamp = bluesky_now_hires(); + bluesky_time_hires next_timestamp = timestamp; + + while (TRUE) { + g_static_mutex_lock(&stats_lock); + timestamp = bluesky_now_hires(); + fprintf(f, "********\ntime=%f\n\n", timestamp / 1e9); + for (GList *item = stats_list; item != NULL; item = item->next) { + struct bluesky_stats *stats = (struct bluesky_stats *)item->data; + fprintf(f, "%s: count=%"PRIi64" sum=%"PRIi64"\n", + stats->name, stats->count, stats->sum); + } + g_static_mutex_unlock(&stats_lock); + fflush(f); + + /* Wait until ten seconds from the last timestamp, with a few extra + * checks for sanity (always try to wait some amount of time in the + * range [0, 20] seconds). */ + timestamp = bluesky_now_hires(); + next_timestamp += interval; + if (next_timestamp < timestamp) { + next_timestamp = timestamp; + continue; + } + if (next_timestamp - timestamp > 2 * interval) { + next_timestamp = timestamp + interval; + } + + struct timespec delay; + delay.tv_sec = (next_timestamp - timestamp) / 1000000000; + delay.tv_nsec = (next_timestamp - timestamp) % 1000000000; + nanosleep(&delay, NULL); + } +} + +/* Start a background thread that will periodically dump statistics counters to + * he specified file every ten seconds. */ +void bluesky_stats_run_periodic_dump(FILE *f) +{ + g_thread_create((GThreadFunc)periodic_stats_dumper, f, FALSE, NULL); }