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

Add more logging levels

Browse Source
This commit is contained in:
freywar
2026-08-10 21:01:39 +03:00
parent 4813725cf3
commit e4b9a79a5f
7 changed files with 215 additions and 169 deletions
Download Patch File Download Diff File Expand all files Collapse all files
build.sh
+10 -1
View File
@@ -3,7 +3,16 @@ set -euo pipefail
export CC=clang
meson setup build --reconfigure
LOG_LEVEL=1
for arg in "${@}"; do
case "${arg}" in
-v) LOG_LEVEL=2 ;;
-vv) LOG_LEVEL=3 ;;
-vvv) LOG_LEVEL=4 ;;
esac
done
meson setup build --reconfigure -Dc_args="-DLOG_LEVEL=${LOG_LEVEL}"
meson compile -v -C build
sector_size=512
src/kernel/log.h
+40 -14
View File
@@ -6,6 +6,15 @@
extern stream_t *kernel_log;
#ifndef LOG_LEVEL
#define LOG_LEVEL 1
#endif
#define LOG_LEVEL_INFO 1
#define LOG_LEVEL_STEP 2
#define LOG_LEVEL_DATA 3
#define LOG_LEVEL_TRACE 4
#define PRINT(stream, fmt, ...) \
do { \
uint64_t _size = string_length(fmt) * 10; \
@@ -13,7 +22,7 @@ extern stream_t *kernel_log;
_size = string_format(fmt, _size, _string, ##__VA_ARGS__); \
stream->write(stream, _string, _size); \
memory_free(_string); \
} while (0)
} while (0);
#define PRINT_LN(stream, fmt, ...) \
do { \
@@ -25,22 +34,39 @@ extern stream_t *kernel_log;
stream->write(stream, _string, _size); \
stream->write(stream, "\n", 1); \
memory_free(_string); \
} while (0)
} while (0);
#define LOG(fmt, ...) PRINT(kernel_log, fmt, ##__VA_ARGS__)
#define PRINT_VAL(stream, v, f) PRINT_LN(#v = f, v)
#define TRACE(fmt, ...)
#define LOG_INFO(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_INFO) \
PRINT(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_STEP(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_STEP) \
PRINT(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_DATA(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_DATA) \
PRINT(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_TRACE(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_TRACE) \
PRINT(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_LN(fmt, ...) PRINT_LN(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_LN_INFO(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_INFO) \
PRINT_LN(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_LN_STEP(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_STEP) \
PRINT_LN(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_LN_DATA(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_DATA) \
PRINT_LN(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_LN_TRACE(fmt, ...) \
if (LOG_LEVEL >= LOG_LEVEL_TRACE) \
PRINT_LN(kernel_log, fmt, ##__VA_ARGS__)
#define LOG_VAL(v) LOG_LN(#v "=%x")
#define LOG_VAL_F(v, f) LOG_LN(#v "=" f, v)
#define TRACE_LN(fmt, ...)
#define TRACE_VAL(v) TRACE_LN(#v "=%lx")
#define TRACE_VAL_F(v, f) TRACE_LN(#v "=" f, v)
#define LOG_VAL_INFO(v, f) LOG_LN_INFO(#v "=" f, v)
#define LOG_VAL_STEP(v, f) LOG_LN_STEP(#v "=" f, v)
#define LOG_VAL_DATA(v, f) LOG_LN_DATA(#v "=" f, v)
#define LOG_VAL_TRACE(v, f) LOG_LN_TRACE(#v "=" f, v)
void log_init(stream_t *log);
src/kernel/memory.c
+7 -7
View File
@@ -67,10 +67,10 @@ void memory_page_map(uint64_t *pml4, void *virt, void *phys, uint64_t flags) {
const uint64_t pd_index = (ivirt >> 21) & 0x1FF;
const uint64_t pt_index = (ivirt >> 12) & 0x1FF;
TRACE_LN("Mapping physical %lx to virtual %lx / [%u, %u, %u, %u]...", phys, virt, pml4_index, pdpt_index, pd_index, pt_index);
LOG_LN_TRACE("Mapping physical %lx to virtual %lx / [%u, %u, %u, %u]...", phys, virt, pml4_index, pdpt_index, pd_index, pt_index);
if (!(pml4[pml4_index] & PAGE_PRESENT)) {
TRACE_LN("PML4 entry %u does not exist, creating...", pml4_index);
LOG_LN_TRACE("PML4 entry %u does not exist, creating...", pml4_index);
uint64_t *pdpt = memory_page_allocate();
memory_set(0, PAGE_SIZE, PHYS_TO_VIRT(pdpt));
pml4[pml4_index] = (uint64_t)pdpt | PAGE_PRESENT | PAGE_WRITABLE | PAGE_USER;
@@ -78,7 +78,7 @@ void memory_page_map(uint64_t *pml4, void *virt, void *phys, uint64_t flags) {
uint64_t *pdpt = PHYS_TO_VIRT(pml4[pml4_index] & ~(uint64_t)0xFFF);
if (!(pdpt[pdpt_index] & PAGE_PRESENT)) {
TRACE_LN("PDPT entry %u does not exist, creating...", pdpt_index);
LOG_LN_TRACE("PDPT entry %u does not exist, creating...", pdpt_index);
uint64_t *pd = memory_page_allocate();
memory_set(0, PAGE_SIZE, PHYS_TO_VIRT(pd));
pdpt[pdpt_index] = (uint64_t)pd | PAGE_PRESENT | PAGE_WRITABLE | PAGE_USER;
@@ -87,7 +87,7 @@ void memory_page_map(uint64_t *pml4, void *virt, void *phys, uint64_t flags) {
uint64_t *pd = PHYS_TO_VIRT(pdpt[pdpt_index] & ~(uint64_t)0xFFF);
ASSERT(!(pd[pd_index] & 0x80), "memory_page_map: Huge page in PD.");
if (!(pd[pd_index] & PAGE_PRESENT)) {
TRACE_LN("PD entry %u does not exist, creating...", pd_index);
LOG_LN_TRACE("PD entry %u does not exist, creating...", pd_index);
uint64_t *pt = memory_page_allocate();
memory_set(0, PAGE_SIZE, PHYS_TO_VIRT(pt));
pd[pd_index] = (uint64_t)pt | PAGE_PRESENT | PAGE_WRITABLE | PAGE_USER;
@@ -97,11 +97,11 @@ void memory_page_map(uint64_t *pml4, void *virt, void *phys, uint64_t flags) {
ASSERT(!(pt[pt_index] & PAGE_PRESENT), "memory_page_map: Page already mapped.")
TRACE_LN("PT entry %u does not exist, creating...", pt_index);
LOG_LN_TRACE("PT entry %u does not exist, creating...", pt_index);
pt[pt_index] = (uint64_t)phys | flags | PAGE_PRESENT;
TRACE_VAL(pt[pt_index]);
LOG_VAL_TRACE(pt[pt_index], "%lx");
TRACE_LN("Done.");
LOG_LN_TRACE("Done.");
}
void memory_page_unmap(uint64_t *pml4, void *virt) {
src/kernel/nvme.c
+58 -58
View File
@@ -89,118 +89,118 @@ static uint16_t io_cq_head = 0;
static void admin_exec_sync(nvme_sqe_t *cmd) {
cmd->cid = admin_sq_tail;
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");
LOG_LN_STEP("Queueing submission...");
LOG_VAL_TRACE(cmd->opc, "%hhx");
LOG_VAL_TRACE(cmd->nsid, "%x");
LOG_VAL_TRACE(cmd->cdw10, "%x");
LOG_VAL_TRACE(cmd->cdw11, "%x");
LOG_VAL_TRACE(cmd->cdw12, "%x");
LOG_VAL_TRACE(cmd->prp1, "%lx");
LOG_VAL_TRACE(cmd->prp2, "%lx");
memory_copy(cmd, sizeof(nvme_sqe_t), &admin_sq[admin_sq_tail]);
TRACE_LN("Advancing submission doorbell...");
LOG_LN_STEP("Advancing submission doorbell...");
db_regs[0] = admin_sq_tail = (admin_sq_tail + 1) % QUEUE_DEPTH;
TRACE_VAL_F(admin_sq_tail, "%u");
LOG_VAL_TRACE(admin_sq_tail, "%u");
TRACE_LN("Waiting for completion...");
LOG_LN_STEP("Waiting for completion...");
nvme_cqe_t *cmp = &admin_cq[admin_cq_head];
while (NVME_CQE_P(cmp) != admin_cq_phase)
;
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");
LOG_LN_STEP("Received completion...");
LOG_VAL_TRACE(cmp->dw0, "%x");
LOG_VAL_TRACE(cmp->reserved, "%x");
LOG_VAL_TRACE(cmp->sqhd, "%hx");
LOG_VAL_TRACE(cmp->sqid, "%hx");
LOG_VAL_TRACE(cmp->cid, "%hx");
LOG_VAL_TRACE(cmp->status, "%hx");
ASSERT(NVME_CQE_STATUS(cmp) == 0, "admin_exec_sync: NVMe command failed.");
TRACE_LN("Advancing completion doorbell...");
LOG_LN_STEP("Advancing completion doorbell...");
db_regs[1] = admin_cq_head = (admin_cq_head + 1) % QUEUE_DEPTH;
admin_cq_phase ^= (admin_cq_head == 0);
TRACE_LN("Done.");
LOG_LN_STEP("Done.");
}
static void io_exec_sync(nvme_sqe_t *cmd) {
cmd->cid = io_sq_tail;
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");
LOG_LN_STEP("Queueing submission...");
LOG_VAL_TRACE(cmd->opc, "%hhx");
LOG_VAL_TRACE(cmd->nsid, "%x");
LOG_VAL_TRACE(cmd->cdw10, "%x");
LOG_VAL_TRACE(cmd->cdw11, "%x");
LOG_VAL_TRACE(cmd->cdw12, "%x");
LOG_VAL_TRACE(cmd->prp1, "%x");
LOG_VAL_TRACE(cmd->prp2, "%x");
memory_copy(cmd, sizeof(nvme_sqe_t), &io_sq[io_sq_tail]);
TRACE_LN("Advancing submission doorbell...");
LOG_LN_STEP("Advancing submission doorbell...");
db_regs[2] = io_sq_tail = (io_sq_tail + 1) % QUEUE_DEPTH;
TRACE_LN("Waiting for completion...");
LOG_LN_STEP("Waiting for completion...");
nvme_cqe_t *cmp = &io_cq[io_cq_head];
while (NVME_CQE_P(cmp) != io_cq_phase)
;
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");
LOG_LN_STEP("Received completion...");
LOG_VAL_TRACE(cmp->dw0, "%x");
LOG_VAL_TRACE(cmp->reserved, "%x");
LOG_VAL_TRACE(cmp->sqhd, "%hx");
LOG_VAL_TRACE(cmp->sqid, "%hx");
LOG_VAL_TRACE(cmp->cid, "%hx");
LOG_VAL_TRACE(cmp->status, "%hx");
ASSERT(NVME_CQE_STATUS(cmp) == 0, "io_exec_sync: NVMe command failed.");
TRACE_LN("Advancing completion doorbell...");
LOG_LN_STEP("Advancing completion doorbell...");
db_regs[3] = io_cq_head = (io_cq_head + 1) % QUEUE_DEPTH;
io_cq_phase ^= (io_cq_head == 0);
TRACE_LN("Done.");
LOG_LN_STEP("Done.");
}
void nvme_init() {
TRACE_LN("Searching for suitable device...");
LOG_LN_INFO("Searching for suitable device...");
pci_bdf_t bdf = pci_find_by_class(NVME_PCI_CLASS, NVME_PCI_SUBCLASS, NUL);
ASSERT(bdf, "nvme_init: No suitable devices found.");
TRACE_LN("Mapping device to virtual memory...");
LOG_LN_INFO("Mapping device to virtual memory...");
pci_map(bdf, regs, 4);
ASSERT(NVME_REGS_NVME_CS_SUPPORTED(regs), "nvme_init: NVM command set not supported.");
ASSERT(QUEUE_DEPTH <= NVME_REGS_MQES(regs), "nvme_init: Command queues are too big.")
TRACE_LN("Disabling device...");
LOG_LN_INFO("Disabling device...");
regs->cc = 0;
TRACE_VAL_F(regs->cc, "%lx");
LOG_VAL_DATA(regs->cc, "%lx");
while (NVME_REGS_RDY(regs))
;
TRACE_VAL_F(regs->cc, "%lx");
LOG_VAL_DATA(regs->cc, "%lx");
TRACE_LN("Configuring device...");
LOG_LN_INFO("Configuring device...");
NVME_REGS_ASQS_W(regs, QUEUE_DEPTH - 1);
regs->asq = (uint64_t)(VIRT_TO_PHYS(admin_sq));
NVME_REGS_ACQS_W(regs, QUEUE_DEPTH - 1);
regs->acq = (uint64_t)(VIRT_TO_PHYS(admin_cq));
TRACE_VAL_F(regs->asq, "%lx");
TRACE_VAL_F(regs->acq, "%lx");
TRACE_VAL_F(regs->aqa, "%lx");
LOG_VAL_DATA(regs->asq, "%lx");
LOG_VAL_DATA(regs->acq, "%lx");
LOG_VAL_DATA(regs->aqa, "%lx");
TRACE_LN("Enabling device...");
LOG_LN_INFO("Enabling device...");
NVME_REGS_IOCQES_W(regs, 4);
NVME_REGS_IOSQES_W(regs, 6);
NVME_REGS_CSS_W(regs, 0);
NVME_REGS_EN_W(regs, 1);
TRACE_VAL_F(regs->cc, "%lx");
LOG_VAL_DATA(regs->cc, "%lx");
while (!NVME_REGS_RDY(regs))
;
TRACE_VAL_F(regs->cc, "%lx");
LOG_VAL_DATA(regs->cc, "%lx");
TRACE_LN("Creating I/O completion queue...");
LOG_LN_INFO("Creating I/O completion queue...");
nvme_sqe_t create_io_cq = {
.opc = 0x05,
.prp1 = (uint64_t)VIRT_TO_PHYS(io_cq),
@@ -209,7 +209,7 @@ void nvme_init() {
};
admin_exec_sync(&create_io_cq);
TRACE_LN("Creating I/O submission queue...");
LOG_LN_INFO("Creating I/O submission queue...");
nvme_sqe_t create_io_sq = {
.opc = 0x01,
.prp1 = (uint64_t)VIRT_TO_PHYS(io_sq),
@@ -218,11 +218,11 @@ void nvme_init() {
};
admin_exec_sync(&create_io_sq);
TRACE_LN("Done.");
LOG_LN_INFO("Done.");
}
void nvme_read_sectors(uint32_t index, uint8_t count, void *to) {
TRACE_LN("Reading %u sectors at %u...", count, index);
LOG_LN_STEP("Reading %u sectors at %u...", count, index);
while (count) {
uint64_t remainder = PAGE_SIZE - (uint64_t)to % PAGE_SIZE;
@@ -246,11 +246,11 @@ void nvme_read_sectors(uint32_t index, uint8_t count, void *to) {
to = (void *)((uint8_t *)to + i_count * SECTOR_SIZE);
}
TRACE_LN("Done.");
LOG_LN_STEP("Done.");
}
void nvme_write_sectors(uint32_t index, uint8_t count, const void *from) {
TRACE_LN("Writing %u sectors at %u...", count, index);
LOG_LN_STEP("Writing %u sectors at %u...", count, index);
while (count) {
uint64_t remainder = PAGE_SIZE - (uint64_t)from % PAGE_SIZE;
@@ -274,5 +274,5 @@ void nvme_write_sectors(uint32_t index, uint8_t count, const void *from) {
from = (void *)((uint8_t *)from + i_count * SECTOR_SIZE);
}
TRACE_LN("Done.");
LOG_LN_STEP("Done.");
}
src/kernel/pci.c
+6 -6
View File
@@ -46,9 +46,9 @@ static void pci_write(pci_bdf_t bdf, uint8_t offset, uint32_t value) {
}
void pci_init() {
LOG_LN("Scanning devices...");
PRINT_LN(kernel_log, "Scanning devices...");
pci_enumerate(kernel_log);
LOG_LN("Done.");
PRINT_LN(kernel_log, "Done.");
}
void pci_enumerate(stream_t *out) {
@@ -60,8 +60,8 @@ void pci_enumerate(stream_t *out) {
continue;
}
uint32_t class = pci_read(PCI_BDF(b, d, f), PCI_OFFSET_CLASS_REVISION);
PRINT_LN(out, "%hx:%hx class=%hhx subclass=%hhx iface=%hhx.", PCI_VENDOR(id), PCI_DEVICE(id), PCI_CLASS(class),
PCI_SUBCLASS(class), PCI_INTERFACE(class));
PRINT_LN(out, "%hx:%hx class=%hhx subclass=%hhx iface=%hhx.", PCI_VENDOR(id), PCI_DEVICE(id), PCI_CLASS(class), PCI_SUBCLASS(class),
PCI_INTERFACE(class));
}
}
}
@@ -93,7 +93,7 @@ void pci_map(pci_bdf_t bdf, volatile void *virt, uint8_t pages) {
uint64_t bar = ((uint64_t)pci_read(bdf, PCI_OFFSET_BAR_1) << 32) | (pci_read(bdf, PCI_OFFSET_BAR_0) & 0xFFFFFFF0);
LOG_LN("Mapping BAR to memory, phys %lx <-> virt %lx...", bar, virt);
LOG_LN_STEP("Mapping BAR to memory, phys %lx <-> virt %lx...", bar, virt);
for (uint8_t i = 0; i < pages; i++) {
memory_page_map((void *)KERNEL_VIRTUAL_PML4, (void *)((uint8_t *)virt + i * PAGE_SIZE), (void *)((uint8_t *)bar + i * PAGE_SIZE),
PAGE_WRITABLE | PAGE_PCD | PAGE_USER);
@@ -101,7 +101,7 @@ void pci_map(pci_bdf_t bdf, volatile void *virt, uint8_t pages) {
}
void pci_unmap(pci_bdf_t bdf, volatile void *virt, uint8_t pages) {
LOG_LN("Unmapping BAR from memory, virt %lx...", virt);
LOG_LN_STEP("Unmapping BAR from memory, virt %lx...", virt);
for (uint8_t i = 0; i < pages; i++) {
memory_page_unmap((void *)KERNEL_VIRTUAL_PML4, (void *)((uint8_t *)virt + i * PAGE_SIZE));
}
src/kernel/usb.c
+2 -2
View File
@@ -23,9 +23,9 @@ typedef struct __attribute__((packed)) {
static usb_device_descriptor_t device_descriptor __attribute__((aligned(64)));
void usb_init() {
LOG_LN("Enumerating devices...");
PRINT_LN(kernel_log, "Enumerating devices...");
usb_enumerate(kernel_log);
LOG_LN("Done.");
PRINT_LN(kernel_log, "Done.");
}
void usb_enumerate(stream_t *out) {
src/kernel/xhci.c
+92 -81
View File
@@ -199,10 +199,10 @@ static uint8_t tr_i = 0;
static xhci_trb_t tr[RING_LENGTH + 1] __attribute__((aligned(PAGE_SIZE)));
static const xhci_trb_t *command_exec_sync(const xhci_trb_t *cmd) {
LOG_LN("Queueing command TRB...");
LOG_VAL_F(cmd->parameter, "%lx");
LOG_VAL_F(cmd->status, "%x");
LOG_VAL_F(cmd->control, "%x");
LOG_LN_STEP("Queueing command TRB...");
LOG_VAL_TRACE(cmd->parameter, "%lx");
LOG_VAL_TRACE(cmd->status, "%x");
LOG_VAL_TRACE(cmd->control, "%x");
xhci_trb_t *cre = &cr[cr_i];
@@ -213,12 +213,12 @@ static const xhci_trb_t *command_exec_sync(const xhci_trb_t *cmd) {
XHCI_TRB_CYCLE_W((&cr[RING_LENGTH]), cr_cycle);
cr_cycle ^= (cr_i == 0);
LOG_LN("Ringing command doorbell...");
LOG_VAL_F(op_regs->usbsts, "%x");
LOG_LN_STEP("Ringing command doorbell...");
LOG_VAL_TRACE(op_regs->usbsts, "%x");
db_regs[0] = 0;
LOG_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_TRACE(op_regs->usbsts, "%x");
LOG_LN("Waiting for completion...");
LOG_LN_STEP("Waiting for completion...");
while (1) {
xhci_trb_t *cmp = &er[er_i];
while (XHCI_TRB_CYCLE_R(cmp) != er_cycle)
@@ -229,75 +229,77 @@ static const xhci_trb_t *command_exec_sync(const xhci_trb_t *cmd) {
er_cycle ^= (er_i == 0);
if (XHCI_TRB_TRB_TYPE_R(cmp) != XHCI_TRB_TYPE_EVENT_COMMAND_COMPLETION || (void *)cmp->parameter != VIRT_TO_PHYS(cre)) {
LOG_LN("Received irrelevant event, skipping...");
LOG_LN_STEP("Received irrelevant event, skipping...");
} else {
LOG_LN("Received command completion event...");
LOG_LN_STEP("Received command completion event...");
LOG_VAL_F(cmp->parameter, "%lx");
LOG_VAL_F(cmp->status, "%x");
LOG_VAL_F(cmp->control, "%x");
LOG_VAL_TRACE(cmp->parameter, "%lx");
LOG_VAL_TRACE(cmp->status, "%x");
LOG_VAL_TRACE(cmp->control, "%x");
ASSERT(XHCI_TRB_COMPLETION_CODE(cmp) == 1, "command_exec_sync: Command failed.");
LOG_LN_STEP("Done.");
return cmp;
}
}
}
void xhci_init() {
TRACE_LN("Searching for suitable controller...");
LOG_LN_INFO("Searching for suitable controller...");
pci_bdf_t bdf = pci_find_by_class(XHCI_PCI_CLASS, XHCI_PCI_SUBCLASS, XHCI_PCI_INTERFACE);
ASSERT(bdf, "xhci_init: No suitable controllers found.");
TRACE_LN("Mapping controller to virtual memory...");
LOG_LN_INFO("Mapping controller to virtual memory...");
pci_map(bdf, cap_regs, 4);
op_regs = (xhci_op_regs_t *)((uint8_t *)cap_regs + cap_regs->caplength);
port_regs = (xhci_port_regs_t *)((uint8_t *)cap_regs + cap_regs->caplength + 0x400);
intr_regs = (xhci_intr_regs_t *)((uint8_t *)cap_regs + cap_regs->rtsoff + 0x20);
db_regs = (uint32_t *)((uint8_t *)cap_regs + cap_regs->dboff);
TRACE_VAL_F(cap_regs->caplength, "%hhx");
TRACE_VAL_F(cap_regs->hciversion, "%hx");
TRACE_VAL_F(cap_regs->hcsparams1, "%x");
TRACE_VAL_F(cap_regs->hcsparams2, "%x");
TRACE_VAL_F(cap_regs->hcsparams3, "%x");
TRACE_VAL_F(cap_regs->hccparams1, "%x");
TRACE_VAL_F(cap_regs->dboff, "%x");
TRACE_VAL_F(cap_regs->rtsoff, "%x");
TRACE_VAL_F(cap_regs->hccparams2, "%x");
LOG_VAL_DATA(cap_regs->caplength, "%hhx");
LOG_VAL_DATA(cap_regs->hciversion, "%hx");
LOG_VAL_DATA(cap_regs->hcsparams1, "%x");
LOG_VAL_DATA(cap_regs->hcsparams2, "%x");
LOG_VAL_DATA(cap_regs->hcsparams3, "%x");
LOG_VAL_DATA(cap_regs->hccparams1, "%x");
LOG_VAL_DATA(cap_regs->dboff, "%x");
LOG_VAL_DATA(cap_regs->rtsoff, "%x");
LOG_VAL_DATA(cap_regs->hccparams2, "%x");
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
TRACE_VAL_F(op_regs->pagesize, "%x");
TRACE_VAL_F(op_regs->dnctrl, "%x");
TRACE_VAL_F(op_regs->crcr, "%lx");
TRACE_VAL_F(op_regs->dcbaap, "%lx");
TRACE_VAL_F(op_regs->config, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->pagesize, "%x");
LOG_VAL_DATA(op_regs->dnctrl, "%x");
LOG_VAL_DATA(op_regs->crcr, "%lx");
LOG_VAL_DATA(op_regs->dcbaap, "%lx");
LOG_VAL_DATA(op_regs->config, "%x");
TRACE_LN("Stopping controller...");
LOG_LN_INFO("Stopping controller...");
XHCI_OP_REGS_RS_W(op_regs, 0);
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
while (!XHCI_OP_REGS_HCH(op_regs))
;
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
TRACE_LN("Resetting controller...");
LOG_LN_INFO("Resetting controller...");
XHCI_OP_REGS_EINT_W(op_regs, 0);
XHCI_OP_REGS_HCRST_W(op_regs, 1);
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
while (XHCI_OP_REGS_HCRST_R(op_regs))
;
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
while (XHCI_OP_REGS_CNR(op_regs))
;
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
TRACE_LN("Setting up command ring...");
LOG_LN_INFO("Setting up command ring...");
xhci_trb_t *wrapper = &cr[RING_LENGTH];
wrapper->parameter = (uint64_t)VIRT_TO_PHYS(cr);
wrapper->status = 0;
@@ -305,7 +307,7 @@ void xhci_init() {
XHCI_TRB_TOGGLE_CYCLE_W(wrapper, 1);
XHCI_TRB_CYCLE_W(wrapper, cr_cycle);
TRACE_LN("Configuring controller...");
LOG_LN_INFO("Configuring controller...");
XHCI_OP_REGS_MAX_SLOTS_EN_W(op_regs, MAX_SLOTS);
op_regs->dcbaap = (uint64_t)VIRT_TO_PHYS(dcbaa);
op_regs->crcr = (uint64_t)VIRT_TO_PHYS(cr) | cr_cycle;
@@ -315,30 +317,29 @@ void xhci_init() {
intr_regs->erstba = (uint64_t)VIRT_TO_PHYS(erst);
intr_regs->erdp = erst[0].base;
TRACE_VAL_F(op_regs->config, "%x");
TRACE_VAL_F(op_regs->dcbaap, "%lx");
TRACE_VAL_F(op_regs->crcr, "%lx");
TRACE_VAL_F(intr_regs->erstba, "%lx");
TRACE_VAL_F(intr_regs->erstsz, "%x");
TRACE_VAL_F(intr_regs->erdp, "%lx");
TRACE_VAL_F(erst[0].size, "%hx");
TRACE_VAL_F(erst[0].base, "%lx");
LOG_VAL_DATA(op_regs->config, "%x");
LOG_VAL_DATA(op_regs->dcbaap, "%lx");
LOG_VAL_DATA(op_regs->crcr, "%lx");
LOG_VAL_DATA(intr_regs->erstba, "%lx");
LOG_VAL_DATA(intr_regs->erstsz, "%x");
LOG_VAL_DATA(intr_regs->erdp, "%lx");
LOG_VAL_DATA(erst[0].size, "%hx");
LOG_VAL_DATA(erst[0].base, "%lx");
TRACE_LN("Starting controller...");
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_LN_INFO("Starting controller...");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
XHCI_OP_REGS_RS_W(op_regs, 1);
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
while (XHCI_OP_REGS_HCH(op_regs))
;
TRACE_VAL_F(op_regs->usbcmd, "%x");
TRACE_VAL_F(op_regs->usbsts, "%x");
LOG_VAL_DATA(op_regs->usbcmd, "%x");
LOG_VAL_DATA(op_regs->usbsts, "%x");
LOG_LN("Enumerating ports...");
PRINT_LN(kernel_log, "Enumerating ports...");
xhci_enumerate(kernel_log);
LOG_LN("Done.");
PRINT_LN(kernel_log, "Done.");
}
void xhci_enumerate(stream_t *out) {
@@ -357,6 +358,8 @@ uint8_t xhci_port_connected(uint8_t port) {
}
xhci_slot_t xhci_attach(uint8_t port) {
LOG_LN_STEP("Attaching port %d ...", port);
ASSERT(!tr_attached_slot, "xhci_attach: Can only attach one port at a time.")
ASSERT(XHCI_PORT_REGS_CCS(&port_regs[port]), "xhci_attach: Port is not connected.");
@@ -364,21 +367,21 @@ xhci_slot_t xhci_attach(uint8_t port) {
tr_i = 0;
tr_cycle = 1;
LOG_LN("Resetting device...");
LOG_LN_STEP("Resetting device...");
port_regs[port].portsc = 1 << 4;
while (XHCI_PORT_REGS_PR_R(&port_regs[port]))
;
while (!XHCI_PORT_REGS_PED(&port_regs[port]))
;
TRACE_VAL_F(XHCI_PORT_REGS_PED(&port_regs[port]), "%hhx");
LOG_VAL_TRACE(XHCI_PORT_REGS_PED(&port_regs[port]), "%hhx");
LOG_LN("Enabling a slot...");
LOG_LN_STEP("Enabling a slot...");
xhci_trb_t cmd_es;
memory_set(0, sizeof(xhci_trb_t), &cmd_es);
XHCI_TRB_TRB_TYPE_W(&cmd_es, XHCI_TRB_TYPE_COMMAND_ENABLE_SLOT);
xhci_slot_t slot = XHCI_TRB_SLOT_ID_R(command_exec_sync(&cmd_es));
LOG_LN("Addressing device...");
LOG_LN_STEP("Addressing device...");
memory_set(0, sizeof(input_ctx), &input_ctx);
input_ctx.control.add_flags = 0b11;
XHCI_SLOT_CTX_CTX_ENTRIES_W(&input_ctx.slot, 1);
@@ -399,13 +402,15 @@ xhci_slot_t xhci_attach(uint8_t port) {
tr_attached_slot = slot;
LOG_LN_STEP("Done.");
return slot;
}
uint64_t xhci_control_transfer(xhci_slot_t slot, uint64_t setup, void *data, uint16_t length) {
ASSERT(tr_attached_slot == slot, "xhci_control_transfer: Can only attach one port at a time.");
LOG_LN("Queueing transfer TRBs...");
LOG_LN_STEP("Queueing transfer TRBs...");
tr[tr_i].parameter = setup;
tr[tr_i].status = sizeof(setup);
@@ -414,9 +419,9 @@ uint64_t xhci_control_transfer(xhci_slot_t slot, uint64_t setup, void *data, uin
BITS_W(tr[tr_i].control, 6, 6, 1);
XHCI_TRB_CYCLE_W(&tr[tr_i], tr_cycle);
LOG_VAL_F(tr[tr_i].parameter, "%lx");
LOG_VAL_F(tr[tr_i].status, "%x");
LOG_VAL_F(tr[tr_i].control, "%x");
LOG_VAL_TRACE(tr[tr_i].parameter, "%lx");
LOG_VAL_TRACE(tr[tr_i].status, "%x");
LOG_VAL_TRACE(tr[tr_i].control, "%x");
tr_i = (tr_i + 1) % RING_LENGTH;
XHCI_TRB_CYCLE_W(&tr[RING_LENGTH], tr_cycle);
@@ -428,9 +433,9 @@ uint64_t xhci_control_transfer(xhci_slot_t slot, uint64_t setup, void *data, uin
BITS_W(tr[tr_i].control, 16, 16, 1);
XHCI_TRB_CYCLE_W(&tr[tr_i], tr_cycle);
LOG_VAL_F(tr[tr_i].parameter, "%lx");
LOG_VAL_F(tr[tr_i].status, "%x");
LOG_VAL_F(tr[tr_i].control, "%x");
LOG_VAL_TRACE(tr[tr_i].parameter, "%lx");
LOG_VAL_TRACE(tr[tr_i].status, "%x");
LOG_VAL_TRACE(tr[tr_i].control, "%x");
tr_i = (tr_i + 1) % RING_LENGTH;
XHCI_TRB_CYCLE_W(&tr[RING_LENGTH], tr_cycle);
@@ -447,10 +452,10 @@ uint64_t xhci_control_transfer(xhci_slot_t slot, uint64_t setup, void *data, uin
XHCI_TRB_CYCLE_W(&tr[RING_LENGTH], tr_cycle);
tr_cycle ^= (tr_i == 0);
LOG_LN("Ringing slot doorbell...");
LOG_LN_STEP("Ringing slot doorbell...");
db_regs[tr_attached_slot] = 1;
LOG_LN("Waiting for completion...");
LOG_LN_STEP("Waiting for completion...");
while (1) {
xhci_trb_t *cmp = &er[er_i];
while (XHCI_TRB_CYCLE_R(cmp) != er_cycle)
@@ -461,22 +466,26 @@ uint64_t xhci_control_transfer(xhci_slot_t slot, uint64_t setup, void *data, uin
er_cycle ^= (er_i == 0);
if (XHCI_TRB_TRB_TYPE_R(cmp) != XHCI_TRB_TYPE_EVENT_TRANSFER_COMPLETION || (void *)cmp->parameter != VIRT_TO_PHYS(tre)) {
LOG_LN("Received irrelevant event, skipping...");
LOG_LN_STEP("Received irrelevant event, skipping...");
} else {
LOG_LN("Received transfer completion event...");
LOG_LN_STEP("Received transfer completion event...");
LOG_VAL_F(cmp->parameter, "%lx");
LOG_VAL_F(cmp->status, "%x");
LOG_VAL_F(cmp->control, "%x");
LOG_VAL_TRACE(cmp->parameter, "%lx");
LOG_VAL_TRACE(cmp->status, "%x");
LOG_VAL_TRACE(cmp->control, "%x");
ASSERT(XHCI_TRB_COMPLETION_CODE(cmp) == 1, "xhci_control_transfer: Transfer failed.");
LOG_LN_STEP("Done.");
return length - (cmp->status & 0xFFFFFF);
}
}
}
void xhci_detach(xhci_slot_t slot) {
LOG_LN_STEP("Detaching slot %d...", slot);
ASSERT(tr_attached_slot == slot, "xhci_detach: Slot not attached.");
xhci_trb_t cmd_ds;
@@ -487,4 +496,6 @@ void xhci_detach(xhci_slot_t slot) {
dcbaa[slot] = 0;
tr_attached_slot = 0;
LOG_LN_STEP("Done.");
}