mirror of
https://github.com/RGBCube/serenity
synced 2025-07-24 22:57:35 +00:00
Kernel: Simplify some dbg() logging
We don't have to log the process name/PID/TID, dbg() automatically adds that as a prefix to every line. Also we don't have to do .characters() on Strings passed to dbg() :^)
This commit is contained in:
parent
c678b35043
commit
7cd1bdfd81
5 changed files with 38 additions and 43 deletions
|
@ -245,8 +245,8 @@ bool Ext2FS::write_block_list_for_inode(InodeIndex inode_index, ext2_inode& e2in
|
|||
}
|
||||
if (inode_dirty) {
|
||||
#ifdef EXT2_DEBUG
|
||||
dbg() << "Ext2FS: Writing " << min(EXT2_NDIR_BLOCKS, blocks.size()) << " direct block(s) to i_block array of inode " << inode_index;
|
||||
for (int i = 0; i < min(EXT2_NDIR_BLOCKS, blocks.size()); ++i)
|
||||
dbg() << "Ext2FS: Writing " << min((size_t)EXT2_NDIR_BLOCKS, blocks.size()) << " direct block(s) to i_block array of inode " << inode_index;
|
||||
for (size_t i = 0; i < min((size_t)EXT2_NDIR_BLOCKS, blocks.size()); ++i)
|
||||
dbg() << " + " << blocks[i];
|
||||
#endif
|
||||
write_ext2_inode(inode_index, e2inode);
|
||||
|
@ -875,7 +875,7 @@ bool Ext2FSInode::traverse_as_directory(Function<bool(const FS::DirectoryEntry&)
|
|||
while (entry < buffer.end_pointer()) {
|
||||
if (entry->inode != 0) {
|
||||
#ifdef EXT2_DEBUG
|
||||
dbg() << "Ext2Inode::traverse_as_directory: " << entry->inode << ", name_len: " << entry->name_len << ", rec_len: " << entry->rec_len << ", file_type: " << entry->file_type << ", name: " << String(entry->name, entry->name_len).characters();
|
||||
dbg() << "Ext2Inode::traverse_as_directory: " << entry->inode << ", name_len: " << entry->name_len << ", rec_len: " << entry->rec_len << ", file_type: " << entry->file_type << ", name: " << String(entry->name, entry->name_len);
|
||||
#endif
|
||||
if (!callback({ entry->name, entry->name_len, { fsid(), entry->inode }, entry->file_type }))
|
||||
break;
|
||||
|
@ -1384,7 +1384,7 @@ KResult Ext2FS::create_directory(InodeIdentifier parent_id, const String& name,
|
|||
auto& inode = inode_or_error.value();
|
||||
|
||||
#ifdef EXT2_DEBUG
|
||||
dbg() << "Ext2FS: create_directory: created new directory named '" << name.characters() << "' with inode " << inode->identifier().index();
|
||||
dbg() << "Ext2FS: create_directory: created new directory named '" << name << "' with inode " << inode->identifier();
|
||||
#endif
|
||||
|
||||
Vector<DirectoryEntry> entries;
|
||||
|
@ -1421,7 +1421,7 @@ KResultOr<NonnullRefPtr<Inode>> Ext2FS::create_inode(InodeIdentifier parent_id,
|
|||
return KResult(-ENOENT);
|
||||
|
||||
#ifdef EXT2_DEBUG
|
||||
dbg() << "Ext2FS: Adding inode '" << name.characters() << "' (mode " << String::format("%o", mode) << ") to parent directory " << parent_inode->identifier().index();
|
||||
dbg() << "Ext2FS: Adding inode '" << name << "' (mode " << String::format("%o", mode) << ") to parent directory " << parent_inode->identifier();
|
||||
#endif
|
||||
|
||||
size_t needed_blocks = ceil_div(size, block_size());
|
||||
|
|
|
@ -1093,14 +1093,14 @@ KResultOr<NonnullRefPtr<FileDescription>> Process::find_elf_interpreter_for_exec
|
|||
|
||||
auto elf_header = (Elf32_Ehdr*)first_page;
|
||||
if (!ELFImage::validate_elf_header(*elf_header, file_size)) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): File has invalid ELF header";
|
||||
dbg() << "exec(" << path << "): File has invalid ELF header";
|
||||
return KResult(-ENOEXEC);
|
||||
}
|
||||
|
||||
// Not using KResultOr here because we'll want to do the same thing in userspace in the RTLD
|
||||
String interpreter_path;
|
||||
if (!ELFImage::validate_program_headers(*elf_header, file_size, (u8*)first_page, nread, interpreter_path)) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): File has invalid ELF Program headers";
|
||||
dbg() << "exec(" << path << "): File has invalid ELF Program headers";
|
||||
return KResult(-ENOEXEC);
|
||||
}
|
||||
|
||||
|
@ -1109,10 +1109,10 @@ KResultOr<NonnullRefPtr<FileDescription>> Process::find_elf_interpreter_for_exec
|
|||
if (elf_header->e_type != ET_DYN)
|
||||
return KResult(-ENOEXEC);
|
||||
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): Using program interpreter " << interpreter_path.characters();
|
||||
dbg() << "exec(" << path << "): Using program interpreter " << interpreter_path;
|
||||
auto interp_result = VFS::the().open(interpreter_path, O_EXEC, 0, current_directory());
|
||||
if (interp_result.is_error()) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): Unable to open program interpreter " << interpreter_path.characters();
|
||||
dbg() << "exec(" << path << "): Unable to open program interpreter " << interpreter_path;
|
||||
return interp_result.error();
|
||||
}
|
||||
auto interpreter_description = interp_result.value();
|
||||
|
@ -1133,19 +1133,19 @@ KResultOr<NonnullRefPtr<FileDescription>> Process::find_elf_interpreter_for_exec
|
|||
|
||||
elf_header = (Elf32_Ehdr*)first_page;
|
||||
if (!ELFImage::validate_elf_header(*elf_header, interp_metadata.size)) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): Interpreter (" << interpreter_description->absolute_path().characters() << ") has invalid ELF header";
|
||||
dbg() << "exec(" << path << "): Interpreter (" << interpreter_description->absolute_path() << ") has invalid ELF header";
|
||||
return KResult(-ENOEXEC);
|
||||
}
|
||||
|
||||
// Not using KResultOr here because we'll want to do the same thing in userspace in the RTLD
|
||||
String interpreter_interpreter_path;
|
||||
if (!ELFImage::validate_program_headers(*elf_header, interp_metadata.size, (u8*)first_page, nread, interpreter_interpreter_path)) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): Interpreter (" << interpreter_description->absolute_path().characters() << ") has invalid ELF Program headers";
|
||||
dbg() << "exec(" << path << "): Interpreter (" << interpreter_description->absolute_path() << ") has invalid ELF Program headers";
|
||||
return KResult(-ENOEXEC);
|
||||
}
|
||||
|
||||
if (!interpreter_interpreter_path.is_empty()) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): Interpreter (" << interpreter_description->absolute_path().characters() << ") has its own interpreter (" << interpreter_interpreter_path.characters() << ")! No thank you!";
|
||||
dbg() << "exec(" << path << "): Interpreter (" << interpreter_description->absolute_path() << ") has its own interpreter (" << interpreter_interpreter_path << ")! No thank you!";
|
||||
return KResult(-ELOOP);
|
||||
}
|
||||
|
||||
|
@ -1165,7 +1165,7 @@ KResultOr<NonnullRefPtr<FileDescription>> Process::find_elf_interpreter_for_exec
|
|||
int Process::exec(String path, Vector<String> arguments, Vector<String> environment, int recursion_depth)
|
||||
{
|
||||
if (recursion_depth > 2) {
|
||||
dbg() << m_name.characters() << "(" << m_pid << ") exec(" << path.characters() << "): SHENANIGANS! recursed too far trying to find #! interpreter";
|
||||
dbg() << "exec(" << path << "): SHENANIGANS! recursed too far trying to find #! interpreter";
|
||||
return -ELOOP;
|
||||
}
|
||||
|
||||
|
@ -1513,9 +1513,9 @@ void Process::crash(int signal, u32 eip)
|
|||
|
||||
if (eip >= 0xc0000000 && ksyms_ready) {
|
||||
auto* ksym = ksymbolicate(eip);
|
||||
dbg() << "\033[31;1m" << String::format("%p", eip) << " " << (ksym ? demangle(ksym->name).characters() : "(k?)") << " +" << (ksym ? eip - ksym->address : 0) << "\033[0m\n";
|
||||
dbg() << "\033[31;1m" << String::format("%p", eip) << " " << (ksym ? demangle(ksym->name) : "(k?)") << " +" << (ksym ? eip - ksym->address : 0) << "\033[0m\n";
|
||||
} else if (m_elf_loader) {
|
||||
dbg() << "\033[31;1m" << String::format("%p", eip) << " " << m_elf_loader->symbolicate(eip).characters() << "\033[0m\n";
|
||||
dbg() << "\033[31;1m" << String::format("%p", eip) << " " << m_elf_loader->symbolicate(eip) << "\033[0m\n";
|
||||
} else {
|
||||
dbg() << "\033[31;1m" << String::format("%p", eip) << " (?)\033[0m\n";
|
||||
}
|
||||
|
@ -1683,7 +1683,7 @@ ssize_t Process::do_write(FileDescription& description, const u8* data, int data
|
|||
#endif
|
||||
if (!description.can_write()) {
|
||||
#ifdef IO_DEBUG
|
||||
dbg() << "block write on " << description.absolute_path().characters();
|
||||
dbg() << "block write on " << description.absolute_path();
|
||||
#endif
|
||||
if (Thread::current->block<Thread::WriteBlocker>(description) != Thread::BlockResult::WokeNormally) {
|
||||
if (nwritten == 0)
|
||||
|
@ -1716,7 +1716,7 @@ ssize_t Process::sys$write(int fd, const u8* data, ssize_t size)
|
|||
if (!validate_read(data, size))
|
||||
return -EFAULT;
|
||||
#ifdef DEBUG_IO
|
||||
dbg() << name().characters() << "(" << pid() << "): sys$write(" << fd << ", " << (void*)const_cast<u8*>(data) << ", " << String::format("%u", size) << ")";
|
||||
dbg() << "sys$write(" << fd << ", " << (const void*)(data) << ", " << size << ")";
|
||||
#endif
|
||||
auto description = file_description(fd);
|
||||
if (!description)
|
||||
|
@ -1737,7 +1737,7 @@ ssize_t Process::sys$read(int fd, u8* buffer, ssize_t size)
|
|||
if (!validate_write(buffer, size))
|
||||
return -EFAULT;
|
||||
#ifdef DEBUG_IO
|
||||
dbg() << name().characters() << "(" << pid() << ") sys$read(" << fd << ", " << (void*)buffer << ", " << size << ")";
|
||||
dbg() << "sys$read(" << fd << ", " << (const void*)buffer << ", " << size << ")";
|
||||
#endif
|
||||
auto description = file_description(fd);
|
||||
if (!description)
|
||||
|
@ -1762,7 +1762,7 @@ int Process::sys$close(int fd)
|
|||
REQUIRE_PROMISE(stdio);
|
||||
auto description = file_description(fd);
|
||||
#ifdef DEBUG_IO
|
||||
dbg() << name().characters() << "(" << pid() << ") sys$close(" << fd << ") " << description.ptr();
|
||||
dbg() << "sys$close(" << fd << ") " << description.ptr();
|
||||
#endif
|
||||
if (!description)
|
||||
return -EBADF;
|
||||
|
@ -2827,7 +2827,7 @@ int Process::sys$select(const Syscall::SC_select_params* params)
|
|||
return error;
|
||||
|
||||
#if defined(DEBUG_IO) || defined(DEBUG_POLL_SELECT)
|
||||
dbg() << name().characters() << "<" << pid() << "> selecting on (read:" << rfds.size() << ", write:" << wfds.size() << "), timeout=" << timeout;
|
||||
dbg() << "selecting on (read:" << rfds.size() << ", write:" << wfds.size() << "), timeout=" << timeout;
|
||||
#endif
|
||||
|
||||
if (!timeout || select_has_timeout) {
|
||||
|
@ -2888,7 +2888,7 @@ int Process::sys$poll(pollfd* fds, int nfds, int timeout)
|
|||
}
|
||||
|
||||
#if defined(DEBUG_IO) || defined(DEBUG_POLL_SELECT)
|
||||
dbg() << name().characters() << "<" << pid() << "> polling on (read:" << rfds.size() << ", write:" << wfds.size() << "), timeout=" << timeout;
|
||||
dbg() << "polling on (read:" << rfds.size() << ", write:" << wfds.size() << "), timeout=" << timeout;
|
||||
#endif
|
||||
|
||||
if (has_timeout || timeout < 0) {
|
||||
|
@ -3695,7 +3695,7 @@ void Process::terminate_due_to_signal(u8 signal)
|
|||
{
|
||||
ASSERT_INTERRUPTS_DISABLED();
|
||||
ASSERT(signal < 32);
|
||||
dbg() << "terminate_due_to_signal " << name().characters() << "(" << pid() << ") <- " << signal;
|
||||
dbg() << "Terminating due to signal " << signal;
|
||||
m_termination_status = 0;
|
||||
m_termination_signal = signal;
|
||||
die();
|
||||
|
|
|
@ -343,7 +343,7 @@ bool Scheduler::pick_next()
|
|||
auto name = process.name();
|
||||
auto pid = process.pid();
|
||||
auto exit_status = Process::reap(process);
|
||||
dbg() << "reaped unparented process " << name.characters() << "(" << pid << "), exit status: " << exit_status.si_status;
|
||||
dbg() << "Scheduler: Reaped unparented process " << name << "(" << pid << "), exit status: " << exit_status.si_status;
|
||||
}
|
||||
return IterationDecision::Continue;
|
||||
}
|
||||
|
@ -374,7 +374,7 @@ bool Scheduler::pick_next()
|
|||
if (thread.dispatch_one_pending_signal() == ShouldUnblockThread::No)
|
||||
return IterationDecision::Continue;
|
||||
if (was_blocked) {
|
||||
dbg() << "Unblock " << thread.process().name().characters() << "(" << thread.pid() << ") due to signal";
|
||||
dbg() << "Unblock " << thread << " due to signal";
|
||||
ASSERT(thread.m_blocker != nullptr);
|
||||
thread.m_blocker->set_interrupted_by_signal();
|
||||
thread.unblock();
|
||||
|
@ -385,13 +385,13 @@ bool Scheduler::pick_next()
|
|||
#ifdef SCHEDULER_RUNNABLE_DEBUG
|
||||
dbg() << "Non-runnables:";
|
||||
Scheduler::for_each_nonrunnable([](Thread& thread) -> IterationDecision {
|
||||
dbg() << " " << String::format("%-12s", thread.state_string()) << " " << thread.name().characters() << "(" << thread.pid() << ":" << thread.tid() << ") @ " << String::format("%w", thread.tss().cs) << ":" << String::format("%x", thread.tss().eip);
|
||||
dbg() << " " << String::format("%-12s", thread.state_string()) << " " << thread << " @ " << String::format("%w", thread.tss().cs) << ":" << String::format("%x", thread.tss().eip);
|
||||
return IterationDecision::Continue;
|
||||
});
|
||||
|
||||
dbg() << "Runnables:";
|
||||
Scheduler::for_each_runnable([](Thread& thread) -> IterationDecision {
|
||||
dbg() << " " << String::format("%3u", thread.effective_priority()) << "/" << String::format("%2u", thread.priority()) << " " << String::format("%-12s", thread.state_string()) << " " << thread.name().characters() << "(" << thread.pid() << ":" << thread.tid() << ") @ " << String::format("%w", thread.tss().cs) << ":" << String::format("%x", thread.tss().eip);
|
||||
dbg() << " " << String::format("%3u", thread.effective_priority()) << "/" << String::format("%2u", thread.priority()) << " " << String::format("%-12s", thread.state_string()) << " " << thread << " @ " << String::format("%w", thread.tss().cs) << ":" << String::format("%x", thread.tss().eip);
|
||||
return IterationDecision::Continue;
|
||||
});
|
||||
#endif
|
||||
|
@ -426,7 +426,7 @@ bool Scheduler::pick_next()
|
|||
thread_to_schedule = g_colonel;
|
||||
|
||||
#ifdef SCHEDULER_DEBUG
|
||||
dbg() << "switch to " << thread_to_schedule->name().characters() << " (" << thread_to_schedule->pid() << ":" << thread_to_schedule->tid() << ") @ " << String::format("%w", thread_to_schedule->tss().cs) << ":" << String::format("%x", thread_to_schedule->tss().eip);
|
||||
dbg() << "Scheduler: Switch to " << *thread_to_schedule << " @ " << String::format("%04x:%08x", thread_to_schedule->tss().cs, thread_to_schedule->tss().eip);
|
||||
#endif
|
||||
|
||||
return context_switch(*thread_to_schedule);
|
||||
|
@ -445,7 +445,7 @@ bool Scheduler::donate_to(Thread* beneficiary, const char* reason)
|
|||
|
||||
unsigned ticks_to_donate = min(ticks_left - 1, time_slice_for(*beneficiary));
|
||||
#ifdef SCHEDULER_DEBUG
|
||||
dbg() << Process::current->name().characters() << "(" << Process::current->pid() << ":" << Thread::current->tid() << ") donating " << ticks_to_donate << " ticks to " << beneficiary->process().name().characters() << " (" << beneficiary->pid() << ":" << beneficiary->tid() << "), reason=" << reason;
|
||||
dbg() << "Scheduler: Donating " << ticks_to_donate << " ticks to " << *beneficiary << ", reason=" << reason;
|
||||
#endif
|
||||
context_switch(*beneficiary);
|
||||
beneficiary->set_ticks_left(ticks_to_donate);
|
||||
|
@ -496,7 +496,7 @@ bool Scheduler::context_switch(Thread& thread)
|
|||
: "=m"(Thread::current->fpu_state()));
|
||||
|
||||
#ifdef LOG_EVERY_CONTEXT_SWITCH
|
||||
dbg() << "Scheduler: " << Process::current->name().characters() << " (" << Process::current->pid() << ":" << Thread::current->tid() << ") -> " << thread.process().name().characters() << "(" << thread.process().pid() << ":" << thread.tid() << ") [" << thread.priority() << "] " << String::format("%w", thread.tss().cs) << ":" << String::format("%x", thread.tss().eip);
|
||||
dbg() << "Scheduler: " << *Thread::current << " -> " << thread << " [" << thread.priority() << "] " << String::format("%w", thread.tss().cs) << ":" << String::format("%x", thread.tss().eip);
|
||||
#endif
|
||||
}
|
||||
|
||||
|
|
|
@ -348,16 +348,16 @@ void Thread::send_signal(u8 signal, [[maybe_unused]] Process* sender)
|
|||
// FIXME: Figure out what to do for masked signals. Should we also ignore them here?
|
||||
if (should_ignore_signal(signal)) {
|
||||
#ifdef SIGNAL_DEBUG
|
||||
dbg() << "signal " << signal << " was ignored by " << process();
|
||||
dbg() << "Signal " << signal << " was ignored by " << process();
|
||||
#endif
|
||||
return;
|
||||
}
|
||||
|
||||
#ifdef SIGNAL_DEBUG
|
||||
if (sender)
|
||||
dbg() << "signal: " << sender->name().characters() << "(" << sender->pid() << ") sent " << signal << " to " << process().name().characters() << "(" << pid() << ")";
|
||||
dbg() << "Signal: " << *sender << " sent " << signal << " to " << process();
|
||||
else
|
||||
dbg() << "signal: kernel sent " << signal << " to " << process().name().characters() << "(" << pid() << ")";
|
||||
dbg() << "Signal: Kernel sent " << signal << " to " << process();
|
||||
#endif
|
||||
|
||||
m_pending_signals |= 1 << (signal - 1);
|
||||
|
|
|
@ -28,10 +28,10 @@
|
|||
#include <Kernel/Process.h>
|
||||
#include <Kernel/Thread.h>
|
||||
#include <Kernel/VM/AnonymousVMObject.h>
|
||||
#include <Kernel/VM/SharedInodeVMObject.h>
|
||||
#include <Kernel/VM/MemoryManager.h>
|
||||
#include <Kernel/VM/PageDirectory.h>
|
||||
#include <Kernel/VM/Region.h>
|
||||
#include <Kernel/VM/SharedInodeVMObject.h>
|
||||
|
||||
//#define MM_DEBUG
|
||||
//#define PAGE_FAULT_DEBUG
|
||||
|
@ -80,7 +80,7 @@ NonnullOwnPtr<Region> Region::clone()
|
|||
if (m_shared || vmobject().is_inode()) {
|
||||
ASSERT(!m_stack);
|
||||
#ifdef MM_DEBUG
|
||||
dbg() << Process::current->name().characters() << "<" << Process::current->pid() << "> Region::clone(): sharing " << m_name.characters() << " (V" << String::format("%p", vaddr().get()) << ")";
|
||||
dbg() << "Region::clone(): Sharing " << name() << " (" << vaddr() << ")";
|
||||
#endif
|
||||
// Create a new region backed by the same VMObject.
|
||||
auto region = Region::create_user_accessible(m_range, m_vmobject, m_offset_in_vmobject, m_name, m_access);
|
||||
|
@ -90,9 +90,7 @@ NonnullOwnPtr<Region> Region::clone()
|
|||
}
|
||||
|
||||
#ifdef MM_DEBUG
|
||||
// FIXME: If m_name.characters() is returning null pointer, the debug message will lead to a crash
|
||||
// For now we use String::format() to mitigate that.
|
||||
dbg() << Process::current->name().characters() << "<" << Process::current->pid() << "> Region::clone(): cowing " << String::format("%s", m_name.characters()) << " (V" << String::format("%p", vaddr().get()) << ")",
|
||||
dbg() << "Region::clone(): CoWing " << name() << " (" << vaddr() << ")";
|
||||
#endif
|
||||
// Set up a COW region. The parent (this) region becomes COW as well!
|
||||
ensure_cow_map().fill(true);
|
||||
|
@ -114,7 +112,7 @@ bool Region::commit()
|
|||
{
|
||||
InterruptDisabler disabler;
|
||||
#ifdef MM_DEBUG
|
||||
dbg() << "MM: commit " << vmobject().page_count() << " pages in Region " << this << " (VMO=" << &vmobject() << ") at V" << String::format("%p", vaddr().get());
|
||||
dbg() << "MM: Commit " << page_count() << " pages in Region " << this << " (VMO=" << &vmobject() << ") at " << vaddr();
|
||||
#endif
|
||||
for (size_t i = 0; i < page_count(); ++i) {
|
||||
if (!commit(i))
|
||||
|
@ -127,9 +125,6 @@ bool Region::commit(size_t page_index)
|
|||
{
|
||||
ASSERT(vmobject().is_anonymous() || vmobject().is_purgeable());
|
||||
InterruptDisabler disabler;
|
||||
#ifdef MM_DEBUG
|
||||
dbg() << "MM: commit single page" << String::format("%zu", page_index, vmobject().page_count()) << "in Region " << this << " (VMO=" << &vmobject() << ") at V" << String::format("%p", vaddr().get());
|
||||
#endif
|
||||
auto& vmobject_physical_page_entry = vmobject().physical_pages()[first_page_index() + page_index];
|
||||
if (!vmobject_physical_page_entry.is_null() && !vmobject_physical_page_entry->is_shared_zero_page())
|
||||
return true;
|
||||
|
|
Loading…
Add table
Add a link
Reference in a new issue