From 797a92d84d79bf10ac426c11fcee064b5bcc4609 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Axel=20D=C3=B6rfler?= Date: Mon, 7 Apr 2008 10:32:03 +0000 Subject: [PATCH] * Made super block log handling endian-safe. * Made all debugging functions endian-safe. * Added tracing for log entries. * Added new KDL command "bfs_journal" to dump all pending log entries. * When BFS_DEBUGGER_COMMANDS is defined, the LogEntry class will also track the transaction ID it belonged to. * The "bfs" KDL command now sets some useful debugger variables. * The "bfs_allocator" KDL command now accepts the group index as 3rd argument. * Renamed Journal::_TransactionListener() to _TransactionIdle(), as that's all it is for. * Removed TODO comment in Volume::WriteSuperBlock(), as it's actually not true. git-svn-id: file:///srv/svn/repos/haiku/haiku/trunk@24852 a95241bf-73f2-0310-859d-f6bbb57e9c96 --- .../file_systems/bfs/BlockAllocator.cpp | 17 ++- .../kernel/file_systems/bfs/BlockAllocator.h | 2 +- src/add-ons/kernel/file_systems/bfs/Debug.cpp | 121 ++++++++++------ .../kernel/file_systems/bfs/Journal.cpp | 137 ++++++++++++++++-- src/add-ons/kernel/file_systems/bfs/Journal.h | 10 +- .../kernel/file_systems/bfs/Volume.cpp | 1 - 6 files changed, 221 insertions(+), 67 deletions(-) diff --git a/src/add-ons/kernel/file_systems/bfs/BlockAllocator.cpp b/src/add-ons/kernel/file_systems/bfs/BlockAllocator.cpp index 690fcc56c2..fc7c134909 100644 --- a/src/add-ons/kernel/file_systems/bfs/BlockAllocator.cpp +++ b/src/add-ons/kernel/file_systems/bfs/BlockAllocator.cpp @@ -1412,14 +1412,16 @@ BlockAllocator::CheckInode(Inode *inode, check_control *control) #ifdef BFS_DEBUGGER_COMMANDS - void -BlockAllocator::Dump() +BlockAllocator::Dump(int32 index) { kprintf("allocation groups: %ld\n", fNumGroups); kprintf("blocks per group: %ld\n", fBlocksPerGroup); for (int32 i = 0; i < fNumGroups; i++) { + if (index != -1 && i != index) + continue; + AllocationGroup& group = fGroups[i]; kprintf("[%3ld] num bits: %lu\n", i, group.NumBits()); @@ -1436,18 +1438,23 @@ BlockAllocator::Dump() int dump_block_allocator(int argc, char **argv) { + int32 group = -1; + if (argc == 3) { + group = parse_expression(argv[2]); + argc--; + } + if (argc != 2 || !strcmp(argv[1], "--help")) { - kprintf("usage: %s \n", argv[0]); + kprintf("usage: %s [group]\n", argv[0]); return 0; } Volume *volume = (Volume *)parse_expression(argv[1]); BlockAllocator &allocator = volume->Allocator(); - allocator.Dump(); + allocator.Dump(group); return 0; } - #endif // BFS_DEBUGGER_COMMANDS diff --git a/src/add-ons/kernel/file_systems/bfs/BlockAllocator.h b/src/add-ons/kernel/file_systems/bfs/BlockAllocator.h index add4f45927..4a5d152be4 100644 --- a/src/add-ons/kernel/file_systems/bfs/BlockAllocator.h +++ b/src/add-ons/kernel/file_systems/bfs/BlockAllocator.h @@ -46,7 +46,7 @@ class BlockAllocator { size_t BitmapSize() const; #ifdef BFS_DEBUGGER_COMMANDS - void Dump(); + void Dump(int32 index); #endif private: diff --git a/src/add-ons/kernel/file_systems/bfs/Debug.cpp b/src/add-ons/kernel/file_systems/bfs/Debug.cpp index e4006993cc..728f6fcf02 100644 --- a/src/add-ons/kernel/file_systems/bfs/Debug.cpp +++ b/src/add-ons/kernel/file_systems/bfs/Debug.cpp @@ -10,6 +10,7 @@ #include "BlockAllocator.h" #include "BPlusTree.h" #include "Inode.h" +#include "Journal.h" #define Print __out @@ -36,7 +37,8 @@ get_tupel(uint32 id) void dump_block_run(const char *prefix, const block_run &run) { - Print("%s(%d, %d, %d)\n", prefix, (int)run.allocation_group, run.start, run.length); + Print("%s(%d, %d, %d)\n", prefix, (int)run.allocation_group, run.start, + run.length); } @@ -45,22 +47,33 @@ dump_super_block(const disk_super_block *superBlock) { Print("disk_super_block:\n"); Print(" name = %s\n", superBlock->name); - Print(" magic1 = %#08x (%s) %s\n", (int)superBlock->magic1, get_tupel(superBlock->magic1), (superBlock->magic1 == SUPER_BLOCK_MAGIC1 ? "valid" : "INVALID")); - Print(" fs_byte_order = %#08x (%s)\n", (int)superBlock->fs_byte_order, get_tupel(superBlock->fs_byte_order)); - Print(" block_size = %u\n", (unsigned)superBlock->block_size); - Print(" block_shift = %u\n", (unsigned)superBlock->block_shift); - Print(" num_blocks = %Lu\n", superBlock->num_blocks); - Print(" used_blocks = %Lu\n", superBlock->used_blocks); - Print(" inode_size = %u\n", (unsigned)superBlock->inode_size); - Print(" magic2 = %#08x (%s) %s\n", (int)superBlock->magic2, get_tupel(superBlock->magic2), (superBlock->magic2 == (int)SUPER_BLOCK_MAGIC2 ? "valid" : "INVALID")); - Print(" blocks_per_ag = %u\n", (unsigned)superBlock->blocks_per_ag); - Print(" ag_shift = %u (%ld bytes)\n", (unsigned)superBlock->ag_shift, 1L << superBlock->ag_shift); - Print(" num_ags = %u\n", (unsigned)superBlock->num_ags); - Print(" flags = %#08x (%s)\n", (int)superBlock->flags, get_tupel(superBlock->flags)); + Print(" magic1 = %#08x (%s) %s\n", (int)superBlock->Magic1(), + get_tupel(superBlock->magic1), + (superBlock->magic1 == SUPER_BLOCK_MAGIC1 ? "valid" : "INVALID")); + Print(" fs_byte_order = %#08x (%s)\n", (int)superBlock->fs_byte_order, + get_tupel(superBlock->fs_byte_order)); + Print(" block_size = %u\n", (unsigned)superBlock->BlockSize()); + Print(" block_shift = %u\n", (unsigned)superBlock->BlockShift()); + Print(" num_blocks = %Lu\n", superBlock->NumBlocks()); + Print(" used_blocks = %Lu\n", superBlock->UsedBlocks()); + Print(" inode_size = %u\n", (unsigned)superBlock->InodeSize()); + Print(" magic2 = %#08x (%s) %s\n", (int)superBlock->Magic2(), + get_tupel(superBlock->magic2), + (superBlock->magic2 == (int)SUPER_BLOCK_MAGIC2 ? "valid" : "INVALID")); + Print(" blocks_per_ag = %u\n", + (unsigned)superBlock->BlocksPerAllocationGroup()); + Print(" ag_shift = %u (%ld bytes)\n", + (unsigned)superBlock->AllocationGroupShift(), + 1L << superBlock->AllocationGroupShift()); + Print(" num_ags = %u\n", (unsigned)superBlock->AllocationGroups()); + Print(" flags = %#08x (%s)\n", (int)superBlock->Flags(), + get_tupel(superBlock->Flags())); dump_block_run(" log_blocks = ", superBlock->log_blocks); - Print(" log_start = %Lu\n", superBlock->log_start); - Print(" log_end = %Lu\n", superBlock->log_end); - Print(" magic3 = %#08x (%s) %s\n", (int)superBlock->magic3, get_tupel(superBlock->magic3), (superBlock->magic3 == SUPER_BLOCK_MAGIC3 ? "valid" : "INVALID")); + Print(" log_start = %Lu\n", superBlock->LogStart()); + Print(" log_end = %Lu\n", superBlock->LogEnd()); + Print(" magic3 = %#08x (%s) %s\n", (int)superBlock->Magic3(), + get_tupel(superBlock->magic3), + (superBlock->magic3 == SUPER_BLOCK_MAGIC3 ? "valid" : "INVALID")); dump_block_run(" root_dir = ", superBlock->root_dir); dump_block_run(" indices = ", superBlock->indices); } @@ -72,22 +85,25 @@ dump_data_stream(const data_stream *stream) Print("data_stream:\n"); for (int i = 0; i < NUM_DIRECT_BLOCKS; i++) { if (!stream->direct[i].IsZero()) { - Print(" direct[%02d] = ",i); - dump_block_run("",stream->direct[i]); + Print(" direct[%02d] = ", i); + dump_block_run("", stream->direct[i]); } } - Print(" max_direct_range = %Lu\n", stream->max_direct_range); + Print(" max_direct_range = %Lu\n", stream->MaxDirectRange()); if (!stream->indirect.IsZero()) dump_block_run(" indirect = ", stream->indirect); - Print(" max_indirect_range = %Lu\n", stream->max_indirect_range); + Print(" max_indirect_range = %Lu\n", stream->MaxIndirectRange()); - if (!stream->double_indirect.IsZero()) - dump_block_run(" double_indirect = ", stream->double_indirect); + if (!stream->double_indirect.IsZero()) { + dump_block_run(" double_indirect = ", + stream->double_indirect); + } - Print(" max_double_indirect_range = %Lu\n", stream->max_double_indirect_range); - Print(" size = %Lu\n", stream->size); + Print(" max_double_indirect_range = %Lu\n", + stream->MaxDoubleIndirectRange()); + Print(" size = %Lu\n", stream->Size()); } @@ -95,25 +111,26 @@ void dump_inode(const bfs_inode *inode) { Print("inode:\n"); - Print(" magic1 = %08x (%s) %s\n", (int)inode->magic1, - get_tupel(inode->magic1), (inode->magic1 == INODE_MAGIC1 ? "valid" : "INVALID")); + Print(" magic1 = %08x (%s) %s\n", (int)inode->Magic1(), + get_tupel(inode->magic1), + (inode->magic1 == INODE_MAGIC1 ? "valid" : "INVALID")); dump_block_run( " inode_num = ", inode->inode_num); - Print(" uid = %u\n", (unsigned)inode->uid); - Print(" gid = %u\n", (unsigned)inode->gid); - Print(" mode = %08x\n", (int)inode->mode); - Print(" flags = %08x\n", (int)inode->flags); - Print(" create_time = %Ld (%Ld)\n", inode->create_time, - inode->create_time >> INODE_TIME_SHIFT); - Print(" last_modified_time = %Ld (%Ld)\n", inode->last_modified_time, - inode->last_modified_time >> INODE_TIME_SHIFT); + Print(" uid = %u\n", (unsigned)inode->UserID()); + Print(" gid = %u\n", (unsigned)inode->GroupID()); + Print(" mode = %08x\n", (int)inode->Mode()); + Print(" flags = %08x\n", (int)inode->Flags()); + Print(" create_time = %Ld (%Ld)\n", inode->CreateTime(), + inode->CreateTime() >> INODE_TIME_SHIFT); + Print(" last_modified_time = %Ld (%Ld)\n", inode->LastModifiedTime(), + inode->LastModifiedTime() >> INODE_TIME_SHIFT); dump_block_run( " parent = ", inode->parent); dump_block_run( " attributes = ", inode->attributes); - Print(" type = %u\n", (unsigned)inode->type); - Print(" inode_size = %u\n", (unsigned)inode->inode_size); + Print(" type = %u\n", (unsigned)inode->Type()); + Print(" inode_size = %u\n", (unsigned)inode->InodeSize()); Print(" etc = %#08x\n", (int)inode->etc); Print(" short_symlink = %s\n", - S_ISLNK(inode->mode) && (inode->flags & INODE_LONG_SYMLINK) == 0 ? - inode->short_symlink : "-"); + S_ISLNK(inode->Mode()) && (inode->Flags() & INODE_LONG_SYMLINK) == 0 + ? inode->short_symlink : "-"); dump_data_stream(&(inode->data)); Print(" --\n pad[0] = %08x\n", (int)inode->pad[0]); Print(" pad[1] = %08x\n", (int)inode->pad[1]); @@ -126,14 +143,16 @@ void dump_bplustree_header(const bplustree_header *header) { Print("bplustree_header:\n"); - Print(" magic = %#08x (%s) %s\n", (int)header->magic, - get_tupel(header->magic), (header->magic == BPLUSTREE_MAGIC ? "valid" : "INVALID")); - Print(" node_size = %u\n", (unsigned)header->node_size); - Print(" max_number_of_levels = %u\n", (unsigned)header->max_number_of_levels); - Print(" data_type = %u\n", (unsigned)header->data_type); - Print(" root_node_pointer = %Ld\n", header->root_node_pointer); - Print(" free_node_pointer = %Ld\n", header->free_node_pointer); - Print(" maximum_size = %Lu\n", header->maximum_size); + Print(" magic = %#08x (%s) %s\n", (int)header->Magic(), + get_tupel(header->magic), + (header->magic == BPLUSTREE_MAGIC ? "valid" : "INVALID")); + Print(" node_size = %u\n", (unsigned)header->NodeSize()); + Print(" max_number_of_levels = %u\n", + (unsigned)header->MaxNumberOfLevels()); + Print(" data_type = %u\n", (unsigned)header->DataType()); + Print(" root_node_pointer = %Ld\n", header->RootNode()); + Print(" free_node_pointer = %Ld\n", header->FreeNode()); + Print(" maximum_size = %Lu\n", header->MaximumSize()); } @@ -279,11 +298,16 @@ dump_volume(int argc, char **argv) Volume *volume = (Volume *)parse_expression(argv[1]); - kprintf("root node: %p\n", volume->RootNode()); + kprintf("block cache: %p\n", volume->BlockCache()); + kprintf("root node: %p\n", volume->RootNode()); kprintf("indices node: %p\n", volume->IndicesNode()); dump_super_block(&volume->SuperBlock()); + set_debug_variable("_cache", (addr_t)volume->BlockCache()); + set_debug_variable("_root", (addr_t)volume->RootNode()); + set_debug_variable("_indices", (addr_t)volume->IndicesNode()); + return 0; } @@ -332,6 +356,7 @@ remove_debugger_commands() { remove_debugger_command("bfs_inode", dump_inode); remove_debugger_command("bfs_allocator", dump_block_allocator); + remove_debugger_command("bfs_journal", dump_journal); remove_debugger_command("bfs_btree_header", dump_bplustree_header); remove_debugger_command("bfs_btree_node", dump_bplustree_node); remove_debugger_command("bfs", dump_volume); @@ -344,6 +369,8 @@ add_debugger_commands() add_debugger_command("bfs_inode", dump_inode, "dump an Inode object"); add_debugger_command("bfs_allocator", dump_block_allocator, "dump a BFS block allocator"); + add_debugger_command("bfs_journal", dump_journal, + "dump the journal log entries"); add_debugger_command("bfs_btree_header", dump_bplustree_header, "dump a BFS B+tree header"); add_debugger_command("bfs_btree_node", dump_bplustree_node, diff --git a/src/add-ons/kernel/file_systems/bfs/Journal.cpp b/src/add-ons/kernel/file_systems/bfs/Journal.cpp index 364dca68d9..a63041eced 100644 --- a/src/add-ons/kernel/file_systems/bfs/Journal.cpp +++ b/src/add-ons/kernel/file_systems/bfs/Journal.cpp @@ -65,15 +65,75 @@ class LogEntry : public DoublyLinkedListLinkImpl { uint32 Start() const { return fStart; } uint32 Length() const { return fLength; } +#ifdef BFS_DEBUGGER_COMMANDS + void SetTransactionID(int32 id) { fTransactionID = id; } + int32 TransactionID() const { return fTransactionID; } +#endif + Journal *GetJournal() { return fJournal; } private: Journal *fJournal; uint32 fStart; uint32 fLength; +#ifdef BFS_DEBUGGER_COMMANDS + int32 fTransactionID; +#endif }; +#if defined(BFS_TRACING) && !defined(BFS_SHELL) && !defined(_BOOT_MODE) +namespace BFSJournalTracing { + +class LogEntry : public AbstractTraceEntry { + public: + LogEntry(::LogEntry* entry, off_t logPosition, bool started) + : + fEntry(entry), +#ifdef BFS_DEBUGGER_COMMANDS + fTransactionID(entry->TransactionID()), +#endif + fStart(entry->Start()), + fLength(entry->Length()), + fLogPosition(logPosition), + fStarted(started) + { + Initialized(); + } + + virtual void AddDump(TraceOutput& out) + { +#ifdef BFS_DEBUGGER_COMMANDS + out.Print("bfs:j:%s entry %p id %ld, start %lu, length %lu, log %s " + "%lu\n", fStarted ? "Started" : "Written", fEntry, + fTransactionID, fStart, fLength, + fStarted ? "end" : "start", fLogPosition); +#else + out.Print("bfs:j:%s entry %p start %lu, length %lu, log %s %lu\n", + fStarted ? "Started" : "Written", fEntry, fStart, fLength, + fStarted ? "end" : "start", fLogPosition); +#endif + } + + private: + ::LogEntry* fEntry; +#ifdef BFS_DEBUGGER_COMMANDS + int32 fTransactionID; +#endif + uint32 fStart; + uint32 fLength; + uint32 fLogPosition; + bool fStarted; +}; + +} // namespace BFSJournalTracing + +# define T(x) new(std::nothrow) BFSJournalTracing::x; +#else +# define T(x) ; +#endif + + // #pragma mark - @@ -516,8 +576,9 @@ Journal::ReplayLog() } PRINT(("replaying worked fine!\n")); - fVolume->SuperBlock().log_start = fVolume->LogEnd(); - fVolume->LogStart() = fVolume->LogEnd(); + fVolume->SuperBlock().log_start = HOST_ENDIAN_TO_BFS_INT64( + fVolume->LogEnd()); + fVolume->LogStart() = HOST_ENDIAN_TO_BFS_INT64(fVolume->LogEnd()); fVolume->SuperBlock().flags = SUPER_BLOCK_DISK_CLEAN; return fVolume->WriteSuperBlock(); @@ -543,20 +604,24 @@ Journal::_TransactionWritten(int32 transactionID, int32 event, void *_logEntry) bool update = false; // Set log_start pointer if possible... - // TODO: this is not endian safe! journal->fEntriesLock.Lock(); if (logEntry == journal->fEntries.First()) { LogEntry *next = journal->fEntries.GetNext(logEntry); - if (next != NULL) - superBlock.log_start = next->Start() % journal->fLogSize; - else - superBlock.log_start = journal->fVolume->LogEnd(); + if (next != NULL) { + superBlock.log_start = HOST_ENDIAN_TO_BFS_INT64(next->Start() + % journal->fLogSize); + } else { + superBlock.log_start = HOST_ENDIAN_TO_BFS_INT64( + journal->fVolume->LogEnd()); + } update = true; } + T(LogEntry(logEntry, superBlock.LogStart(), false)); + journal->fUsed -= logEntry->Length(); journal->fEntries.Remove(logEntry); journal->fEntriesLock.Unlock(); @@ -575,14 +640,14 @@ Journal::_TransactionWritten(int32 transactionID, int32 event, void *_logEntry) strerror(status))); } - journal->fVolume->LogStart() = superBlock.log_start; + journal->fVolume->LogStart() = superBlock.LogStart(); } } /*! Listens to TRANSACTION_IDLE events, and flushes the log when that happens */ /*static*/ void -Journal::_TransactionListener(int32 transactionID, int32 event, void *_journal) +Journal::_TransactionIdle(int32 transactionID, int32 event, void *_journal) { // The current transaction seems to be idle - flush it @@ -747,14 +812,20 @@ Journal::_WriteTransactionToLog() return B_NO_MEMORY; } +#ifdef BFS_DEBUGGER_COMMANDS + logEntry->SetTransactionID(fTransactionID); +#endif + // Update the log end pointer in the super block fVolume->SuperBlock().flags = SUPER_BLOCK_DISK_DIRTY; - fVolume->SuperBlock().log_end = logPosition; - fVolume->LogEnd() = logPosition; + fVolume->SuperBlock().log_end = HOST_ENDIAN_TO_BFS_INT64(logPosition); status = fVolume->WriteSuperBlock(); + fVolume->LogEnd() = logPosition; + T(LogEntry(logEntry, fVolume->LogEnd(), true)); + // We need to flush the drives own cache here to ensure // disk consistency. // If that call fails, we can't do anything about it anyway @@ -858,7 +929,7 @@ Journal::Lock(Transaction *owner) } cache_add_transaction_listener(fVolume->BlockCache(), fTransactionID, - TRANSACTION_IDLE, _TransactionListener, this); + TRANSACTION_IDLE, _TransactionIdle, this); return B_OK; } @@ -924,6 +995,48 @@ Journal::_TransactionDone(bool success) } +// #pragma mark - debugger commands + + +#ifdef BFS_DEBUGGER_COMMANDS + +void +Journal::Dump() +{ + kprintf("log start: %ld\n", fVolume->LogStart()); + kprintf("log end: %ld\n", fVolume->LogEnd()); + kprintf("entries:\n"); + kprintf(" address id start length\n"); + + LogEntryList::Iterator iterator = fEntries.GetIterator(); + + while (iterator.HasNext()) { + LogEntry *entry = iterator.Next(); + + kprintf(" %p %6ld %6lu %6lu\n", entry, entry->TransactionID(), + entry->Start(), entry->Length()); + } +} + + +int +dump_journal(int argc, char **argv) +{ + if (argc != 2 || !strcmp(argv[1], "--help")) { + kprintf("usage: %s \n", argv[0]); + return 0; + } + + Volume *volume = (Volume *)parse_expression(argv[1]); + Journal *journal = volume->GetJournal(0); + + journal->Dump(); + return 0; +} + +#endif // BFS_DEBUGGER_COMMANDS + + // #pragma mark - Transaction diff --git a/src/add-ons/kernel/file_systems/bfs/Journal.h b/src/add-ons/kernel/file_systems/bfs/Journal.h index 3101c6407d..d6857d6243 100644 --- a/src/add-ons/kernel/file_systems/bfs/Journal.h +++ b/src/add-ons/kernel/file_systems/bfs/Journal.h @@ -50,6 +50,10 @@ class Journal { inline uint32 FreeLogBlocks() const; +#ifdef BFS_DEBUGGER_COMMANDS + void Dump(); +#endif + private: bool _HasSubTransaction() { return fHasSubtransaction; } status_t _FlushLog(bool canWait, bool flushBlocks); @@ -61,7 +65,7 @@ class Journal { static void _TransactionWritten(int32 transactionID, int32 event, void *_logEntry); - static void _TransactionListener(int32 transactionID, int32 event, + static void _TransactionIdle(int32 transactionID, int32 event, void *_journal); Volume *fVolume; @@ -176,4 +180,8 @@ class Transaction { Journal *fJournal; }; +#ifdef BFS_DEBUGGER_COMMANDS +int dump_journal(int argc, char **argv); +#endif + #endif /* JOURNAL_H */ diff --git a/src/add-ons/kernel/file_systems/bfs/Volume.cpp b/src/add-ons/kernel/file_systems/bfs/Volume.cpp index 1a00c1772c..8b821c42f2 100644 --- a/src/add-ons/kernel/file_systems/bfs/Volume.cpp +++ b/src/add-ons/kernel/file_systems/bfs/Volume.cpp @@ -509,7 +509,6 @@ Volume::AllocateForInode(Transaction &transaction, const Inode *parent, status_t Volume::WriteSuperBlock() { - // TODO: this assumes a block size of 512 bytes of the underlying device if (write_pos(fDevice, 512, &fSuperBlock, sizeof(disk_super_block)) != sizeof(disk_super_block)) return B_IO_ERROR;