freywar/freywaros
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Improve kernel logging

Browse Source 
Current function name is automatically prepended to all log entries.
Helper macros added to log local variables.
This commit is contained in:
freywar
2026-07-27 20:41:45 +03:00
parent 3b8125eb0c
commit 572cb7647f
6 changed files with 295 additions and 139 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/kernel/nvme.c
+64 -69
View File
@@ -5,7 +5,6 @@
#include "src/kernel/pci.h"
#include "src/lib/layout.h"
#include "src/lib/memory.h"
#include <stdint.h>
#define SECTOR_SIZE 512
@@ -67,89 +66,83 @@ static uint16_t io_cq_head = 0;
static void admin_exec_sync(nvme_sqe_t *cmd) {
cmd->cid = admin_sq_tail;
TRACE("admin_exec_sync: Queueing submission...\n");
TRACE("admin_exec_sync: opc=%x\n", cmd->opc);
TRACE("admin_exec_sync: nsid=%x\n", cmd->nsid);
TRACE("admin_exec_sync: cdw10=%x\n", cmd->cdw10);
TRACE("admin_exec_sync: cdw11=%x\n", cmd->cdw11);
TRACE("admin_exec_sync: cdw12=%x\n", cmd->cdw12);
TRACE("admin_exec_sync: prp1=%x\n", cmd->prp1);
TRACE("admin_exec_sync: prp2=%x\n", cmd->prp2);
TRACE_LN("Queueing submission...");
TRACE_VAL_F(cmd->opc, "%hhx");
TRACE_VAL_F(cmd->nsid, "%x");
TRACE_VAL_F(cmd->cdw10, "%x");
TRACE_VAL_F(cmd->cdw11, "%x");
TRACE_VAL_F(cmd->cdw12, "%x");
TRACE_VAL_F(cmd->prp1, "%lx");
TRACE_VAL_F(cmd->prp2, "%lx");
memory_copy(cmd, sizeof(nvme_sqe_t), &admin_sq[admin_sq_tail]);
TRACE("admin_exec_sync: Advancing submission doorbell...\n");
TRACE_LN("Advancing submission doorbell...");
*(volatile uint32_t *)((uint8_t *)regs + 0x1000) = admin_sq_tail = (admin_sq_tail + 1) % QUEUE_DEPTH;
TRACE_VAL_F(admin_sq_tail, "%u");
TRACE("admin_exec_sync: Waiting for completion...\n");
while ((admin_cq[admin_cq_head].status & 1) != admin_cq_phase)
TRACE_LN("Waiting for completion...");
nvme_cqe_t *cmp = &admin_cq[admin_cq_head];
while ((cmp->status & 1) != admin_cq_phase)
;
TRACE("admin_exec_sync: Received completion...\n");
TRACE("admin_exec_sync: dw0=%x\n", io_cq[io_cq_head].dw0);
TRACE("admin_exec_sync: reserved=%x\n", io_cq[io_cq_head].reserved);
TRACE("admin_exec_sync: sqhd=%x\n", io_cq[io_cq_head].sqhd);
TRACE("admin_exec_sync: sqid=%x\n", io_cq[io_cq_head].sqid);
TRACE("admin_exec_sync: cid=%x\n", io_cq[io_cq_head].cid);
TRACE("admin_exec_sync: status=%x\n", io_cq[io_cq_head].status);
TRACE_LN("Received completion...");
TRACE_VAL_F(cmp->dw0, "%x");
TRACE_VAL_F(cmp->reserved, "%x");
TRACE_VAL_F(cmp->sqhd, "%hx");
TRACE_VAL_F(cmp->sqid, "%hx");
TRACE_VAL_F(cmp->cid, "%hx");
TRACE_VAL_F(cmp->status, "%hx");
ASSERT((admin_cq[admin_cq_head].status >> 1) == 0, "admin_exec_sync: NVMe command failed.");
TRACE("admin_exec_sync: Advancing completion doorbell...\n");
TRACE_LN("Advancing completion doorbell...");
*(volatile uint32_t *)((uint8_t *)regs + 0x1004) = admin_cq_head = (admin_cq_head + 1) % QUEUE_DEPTH; // TODO Get offset from caps.
admin_cq_phase ^= (admin_cq_head == 0);
TRACE("admin_exec_sync: Done.\n");
TRACE_LN("Done.");
}
static void io_exec_sync(nvme_sqe_t *cmd) {
cmd->cid = io_sq_tail;
TRACE("io_exec_sync: Queueing submission...\n");
TRACE("io_exec_sync: opc=%x\n", cmd->opc);
TRACE("io_exec_sync: nsid=%x\n", cmd->nsid);
TRACE("io_exec_sync: cdw10=%x\n", cmd->cdw10);
TRACE("io_exec_sync: cdw11=%x\n", cmd->cdw11);
TRACE("io_exec_sync: cdw12=%x\n", cmd->cdw12);
TRACE("io_exec_sync: prp1=%x\n", cmd->prp1);
TRACE("io_exec_sync: prp2=%x\n", cmd->prp2);
TRACE_LN("Queueing submission...");
TRACE_VAL_F(cmd->opc, "%hhx");
TRACE_VAL_F(cmd->nsid, "%x");
TRACE_VAL_F(cmd->cdw10, "%x");
TRACE_VAL_F(cmd->cdw11, "%x");
TRACE_VAL_F(cmd->cdw12, "%x");
TRACE_VAL_F(cmd->prp1, "%x");
TRACE_VAL_F(cmd->prp2, "%x");
memory_copy(cmd, sizeof(nvme_sqe_t), &io_sq[io_sq_tail]);
TRACE("io_exec_sync: Advancing submission doorbell...\n");
TRACE_LN("Advancing submission doorbell...");
*(volatile uint32_t *)((uint8_t *)regs + 0x1008) = io_sq_tail = (io_sq_tail + 1) % QUEUE_DEPTH; // TODO Get offset from caps.
TRACE("io_exec_sync: Waiting for completion...\n");
while ((io_cq[io_cq_head].status & 1) != io_cq_phase)
TRACE_LN("Waiting for completion...");
nvme_cqe_t *cmp = &io_cq[io_cq_head];
while ((cmp->status & 1) != io_cq_phase)
;
TRACE("io_exec_sync: Received completion...\n");
TRACE("io_exec_sync: dw0=%x\n", io_cq[io_cq_head].dw0);
TRACE("io_exec_sync: reserved=%x\n", io_cq[io_cq_head].reserved);
TRACE("io_exec_sync: sqhd=%x\n", io_cq[io_cq_head].sqhd);
TRACE("io_exec_sync: sqid=%x\n", io_cq[io_cq_head].sqid);
TRACE("io_exec_sync: cid=%x\n", io_cq[io_cq_head].cid);
TRACE("io_exec_sync: status=%x\n", io_cq[io_cq_head].status);
TRACE_LN("Received completion...");
TRACE_VAL_F(cmp->dw0, "%x");
TRACE_VAL_F(cmp->reserved, "%x");
TRACE_VAL_F(cmp->sqhd, "%hx");
TRACE_VAL_F(cmp->sqid, "%hx");
TRACE_VAL_F(cmp->cid, "%hx");
TRACE_VAL_F(cmp->status, "%hx");
ASSERT((io_cq[io_cq_head].status >> 1) == 0, "io_exec_sync: NVMe command failed.");
TRACE("io_exec_sync: Advancing completion doorbell...\n");
ASSERT((cmp->status >> 1) == 0, "io_exec_sync: NVMe command failed.");
TRACE_LN("Advancing completion doorbell...");
*(volatile uint32_t *)((uint8_t *)regs + 0x100C) = io_cq_head = (io_cq_head + 1) % QUEUE_DEPTH; // TODO Get offset from caps.
io_cq_phase ^= (io_cq_head == 0);
TRACE("io_exec_sync: Done.\n");
TRACE_LN("Done.");
}
void nvme_init() {
LOG("nvme_init: Searching for suitable device...\n");
LOG_LN("Searching for suitable device...");
uint8_t found = 0;
for (uint16_t bus = 0; bus < 256 && !found; bus++) {
for (uint8_t device = 0; device < 32 && !found; device++) {
@@ -169,11 +162,12 @@ void nvme_init() {
uint32_t bar1 = pci_read((uint8_t)bus, device, function, 0x14);
uint64_t phys = ((uint64_t)bar1 << 32) | bar0;
LOG("nvme_init: Mapping device to memory, phys %x <-> virt %x\n", phys, regs);
LOG_LN("Mapping device to memory, phys %lx <-> virt %lx...", phys, regs);
for (uint8_t i = 0; i < 4; i++) {
memory_page_map((void *)KERNEL_VIRTUAL_PML4, (void *)((uint8_t *)regs + i * PAGE_SIZE), (void *)((uint8_t *)phys + i * PAGE_SIZE),
PAGE_WRITABLE | PAGE_PCD | PAGE_USER);
}
found = 1;
}
}
@@ -182,27 +176,29 @@ void nvme_init() {
ASSERT(found, "nvme_init: No suitable devices found.");
ASSERT(regs->cap & (1ULL << 37), "nvme_init: NVM command set not supported.");
LOG("nvme_init: Disabling device...\n");
LOG_LN("Disabling device...");
regs->cc = 0;
TRACE_VAL_F(regs->cc, "%lx");
while (regs->csts & 1)
;
TRACE_VAL_F(regs->cc, "%lx");
LOG("nvme_init: Configuring device...\n");
LOG_LN("Configuring device...");
regs->asq = (uint64_t)(VIRT_TO_PHYS(admin_sq));
TRACE("nvme_init: Setting ASQ, expected=%x, set=%x...\n", (uint64_t)(VIRT_TO_PHYS(admin_sq)), regs->asq);
regs->acq = (uint64_t)(VIRT_TO_PHYS(admin_cq));
TRACE("nvme_init: Setting ACQ, expected=%x, set=%x...\n", (uint64_t)(VIRT_TO_PHYS(admin_cq)), regs->acq);
regs->aqa = (QUEUE_DEPTH - 1) << 16 | (QUEUE_DEPTH - 1);
TRACE("nvme_init: Setting AQA, expected=%x, set=%x...\n", (QUEUE_DEPTH - 1) << 16 | (QUEUE_DEPTH - 1), regs->aqa);
TRACE_VAL_F(regs->asq, "%lx");
TRACE_VAL_F(regs->acq, "%lx");
TRACE_VAL_F(regs->aqa, "%lx");
LOG_LN("Enabling device...");
regs->cc = (4 << 20) | (6 << 16) | (0 << 4) | 1;
LOG("nvme_init: Enabling device, expected=%x, set=%x...\n", (4 << 20) | (6 << 16) | (0 << 4) | 1, regs->cc);
TRACE_VAL_F(regs->cc, "%lx");
while (!(regs->csts & 1))
;
TRACE_VAL_F(regs->cc, "%lx");
LOG("nvme_init: Creating I/O completion queue...\n");
LOG_LN("Creating I/O completion queue...");
nvme_sqe_t create_io_cq = {
.opc = 0x05,
.prp1 = (uint64_t)VIRT_TO_PHYS(io_cq),
@@ -211,8 +207,7 @@ void nvme_init() {
};
admin_exec_sync(&create_io_cq);
LOG("nvme_init: Creating I/O submission queue...\n");
LOG_LN("Creating I/O submission queue...");
nvme_sqe_t create_io_sq = {
.opc = 0x01,
.prp1 = (uint64_t)VIRT_TO_PHYS(io_sq),
@@ -221,11 +216,11 @@ void nvme_init() {
};
admin_exec_sync(&create_io_sq);
LOG("nvme_init: Done.\n");
LOG_LN("Done.");
}
void nvme_read_sectors(uint32_t index, uint8_t count, void *to) {
TRACE("nvme_read_sectors: Reading %u sectors at %u...\n", count, index);
TRACE_LN("Reading %u sectors at %u...", count, index);
while (count) {
uint64_t remainder = PAGE_SIZE - (uint64_t)to % PAGE_SIZE;
@@ -249,11 +244,11 @@ void nvme_read_sectors(uint32_t index, uint8_t count, void *to) {
to = (void *)((uint8_t *)to + i_count * SECTOR_SIZE);
}
TRACE("nvme_read_sectors: Done.\n", count, index);
TRACE_LN("Done.");
}
void nvme_write_sectors(uint32_t index, uint8_t count, const void *from) {
TRACE("nvme_write_sectors: Reading %u sectors at %u...\n", count, index);
TRACE_LN("Writing %u sectors at %u...", count, index);
while (count) {
uint64_t remainder = PAGE_SIZE - (uint64_t)from % PAGE_SIZE;
@@ -277,5 +272,5 @@ void nvme_write_sectors(uint32_t index, uint8_t count, const void *from) {
from = (void *)((uint8_t *)from + i_count * SECTOR_SIZE);
}
TRACE("nvme_write_sectors: Done.\n", count, index);
TRACE_LN("Done.");
}