Page 1 of 1

SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Thu Jul 24, 2025 4:44 pm
by rannnnnddiddddd
Hello, I added SMP support a while ago, but now that I started to use threads I'm discovering weird issues. Recently I tried to move net packet processing outside virtio interrupt handler, but then sometimes some random exceptions occur. This is the networking code:

Code: Select all


buffer_q_complete g_net_buffer_queue = {};
spinlock_t __virtio_net_lock;

void initialize_net_buffer() { ... }

void initialize_processing_thread() { ... }

void process_net_packet()
{
    net_buf *net_buffer = (net_buf *)liballoc_malloc(sizeof(net_buf));
    tthread *cur = NULL;
    uint32_t cpu_id;

    while (1) {
        cpu_id = lapic_get_id();
        cur = tthread_cpu[cpu_id];

        spinlock_acquire(&g_net_buffer_queue.buffer_queue_start_lock);

        if (atomic_load(&g_net_buffer_queue.size) == 0) {
            spinlock_release(&g_net_buffer_queue.buffer_queue_start_lock);
            tscheduler_yield(cur);
            continue;
        }

        if (g_net_buffer_queue.buffer_queue_bool[g_net_buffer_queue.buffer_start] == 0) {
            spinlock_release(&g_net_buffer_queue.buffer_queue_start_lock);
            tscheduler_yield(cur);
            continue;
        }

        int start = g_net_buffer_queue.buffer_start;
        g_net_buffer_queue.buffer_start = (g_net_buffer_queue.buffer_start + 1) % BUFFER_QUEUE_SIZE;
       
        net_buffer->start = g_net_buffer_queue.buffer_queue[start].data;
        net_buffer->end = g_net_buffer_queue.buffer_queue[start].data
            + g_net_buffer_queue.buffer_queue[start].data_size;
            
        spinlock_release(&g_net_buffer_queue.buffer_queue_start_lock);

        spinlock_acquire(&__virtio_net_lock);

        eth_recv(g_virtio_intf, net_buffer);

        spinlock_release(&__virtio_net_lock);
        
        spinlock_acquire(&g_net_buffer_queue.buffer_queue_start_lock);

        atomic_fetch_sub(&g_net_buffer_queue.size, 1);
        g_net_buffer_queue.buffer_queue_bool[start] = 0;
        
        spinlock_release(&g_net_buffer_queue.buffer_queue_start_lock);

        tscheduler_yield(cur);
    }
}

This tiggers on virtio interrupt:

Code: Select all

static uint64_t __virtio_net_interrupts_served_per_cpu[128];
static uint64_t __virtio_net_currently_serving_interrupt[128];
static uint32_t __virtio_net_last_cpu = -1;

registers *interrupt_virtio_net_handler(registers *r)
{
    uint32_t cpu_id = lapic_get_id();
    uint32_t next_cpu = (__virtio_net_last_cpu + 1) % g_acpi_cpu_count;

    // only try to get the lock if current cpu is next cpu or if next cpu is busy processing other
    // interrupts
    if (cpu_id == next_cpu || __virtio_net_currently_serving_interrupt[next_cpu]) {
        spinlock_acquire(&g_virtio_lock);
        __virtio_net_last_cpu = cpu_id;
        __virtio_net_interrupts_served_per_cpu[cpu_id]++;
        __virtio_net_currently_serving_interrupt[cpu_id] = 1;

        LOG(LOG_TYPE_NET, "virtio_net: net interrupt");
        virtio_net_receive();

        __virtio_net_currently_serving_interrupt[cpu_id] = 0;
    }

    __acknowledge_interrupt();
    return r;
}
This is the function it calls:

Code: Select all

void virtio_net_receive()
{
    uint8_t isr = pmio_read_8(__virtio_net_dev.io_base + 0x13);
    // LOG(LOG_TYPE_NET, "isr %d", isr);

    virtio_queue *vq = &__virtio_net_dev.queues[0];
    vq->used->flags = 1;

    if (vq->last_used_index == vq->used->index) {
        spinlock_release(&g_virtio_lock);
        return;
    }

     ...
   
    uint8_t *buffer = (uint8_t *)(vq->buffers[buffer_index].address + sizeof(net_header));
    uint32_t cpu_id = lapic_get_id();
    LOG(LOG_TYPE_NET, "virtio_net: received package, size %d on core %d",
        vq->used->rings[index].length - sizeof(net_header), cpu_id);

    __net_bufs[cpu_id].start = buffer;
    __net_bufs[cpu_id].end = buffer + vq->used->rings[index].length - sizeof(net_header);

    // if the buffer is full it won't be processed
    if (atomic_load(&g_net_buffer_queue.size) == BUFFER_QUEUE_SIZE) {
        spinlock_release(&g_virtio_lock);
        return;
    }

    int end = g_net_buffer_queue.buffer_end;
    g_net_buffer_queue.buffer_end = (g_net_buffer_queue.buffer_end + 1) % BUFFER_QUEUE_SIZE;
    
    memcpy(g_net_buffer_queue.buffer_queue[end].data, buffer,
        vq->used->rings[index].length - sizeof(net_header));
    g_net_buffer_queue.buffer_queue[end].data_size
        = vq->used->rings[index].length - sizeof(net_header);
    g_net_buffer_queue.buffer_queue_bool[end] = 1;
    atomic_fetch_add(&g_net_buffer_queue.size, 1);
    
    spinlock_release(&g_virtio_lock);
}

uint64_t virtio_net_send(void *package, uint64_t package_size) // since whole NS has global lock this is fine without locks
{
    ...

    __virtio_send_buffer(&__virtio_net_dev, 1, __send_bi, 2);

    return package_size;
}
So sometimes when I run 100 tcp sockets with 10k req each, some exceptions occur. They do not occur when I call eth_recv() from inside interrupt handler. I suspect it might be something related to threads. If I alter process_net_packet

Code: Select all

        if (atomic_load(&g_net_buffer_queue.size) == 0) {
            spinlock_release(&g_net_buffer_queue.buffer_queue_start_lock);
            tscheduler_yield(cur);
            wait(1 ms);
            continue;
        }

        if (g_net_buffer_queue.buffer_queue_bool[g_net_buffer_queue.buffer_start] == 0) {
            spinlock_release(&g_net_buffer_queue.buffer_queue_start_lock);
            tscheduler_yield(cur);
            wait(1 ms);
            continue;
        }
Everything mostly works (sometimes there is exception right at the boot, but if that doesn't happen it works for all my tests). This is my threads code:

Code: Select all

typedef struct tthread
{
    uint64_t tid;
    uint32_t cpu_id;
    tthread_state state;
    void *stack;
} tthread;

typedef struct tt_swtch_stack
{
    uint64_t RBP;
    uint64_t RBX;
    uint64_t R12;
    uint64_t R13;
    uint64_t R14;
    uint64_t R15;
    uint64_t RBP2;
    uint64_t ret;
} __attribute__((packed)) tt_swtch_stack;

#define MAX_TSCHEDULER_QUEUE_SIZE 128
#define THREAD_STACK_SIZE 131072

typedef struct tscheduler_queue
{
    int front;
    int rear;
    int size;
    tthread *tthreads[MAX_TSCHEDULER_QUEUE_SIZE];
} tscheduler_queue;

extern tthread *tthread_cpu[128];

static uint64_t s_ttid = 0;

static spinlock_t tthread_lock;

spinlock_t tscheduler_lock;

static tscheduler_queue tq = {};

tthread *tthread_cpu[MAX_TSCHEDULER_QUEUE_SIZE] = {};

tthread *tscheduler_threads[4];

static void __tscheduler_init()
{
    spinlock_init(&tscheduler_lock);
    tq.front = 0;
    tq.rear = -1;
    tq.size = 0;
}

static int __tq_is_empty()

static int __tq_is_full(void)

static void __tq_enqueue(tthread *thread)

static tthread *__tq_dequeue()

void infi() { while (1) { } }

void initialize_tthreads()
{
    for (int cpu_id = 0; cpu_id < 4; cpu_id++) {
        tscheduler_threads[cpu_id] = liballoc_aligned_alloc(16, THREAD_STACK_SIZE);
        tscheduler_threads[cpu_id]->stack = (void *)((uint64_t)tscheduler_threads[cpu_id]
            + THREAD_STACK_SIZE - sizeof(tt_swtch_stack));
        tt_swtch_stack *stack = tscheduler_threads[cpu_id]->stack;
        stack->RBP = (uint64_t)&stack->RBP2;
        stack->ret = (uint64_t)infi;
    }

    spinlock_init(&tthread_lock);
    __tscheduler_init();
}

tthread *create_tthread(void (*func)(void))
{
    tthread *new = liballoc_aligned_alloc(64, THREAD_STACK_SIZE);

    if (!new) {
        return NULL;
    }

    spinlock_acquire(&tthread_lock);
    new->tid = s_ttid++;
    spinlock_release(&tthread_lock);

    new->cpu_id = 0;
    new->state = TTHREAD_READY;
    new->stack = (void *)((uint64_t)new + THREAD_STACK_SIZE - sizeof(tt_swtch_stack));

    tt_swtch_stack *stack = new->stack;
    stack->RBP = (uint64_t)&stack->RBP2;
    stack->ret = (uint64_t)func;

    return new;
}

void tscheduler_add_thread(tthread *thread)
{
    spinlock_acquire(&tscheduler_lock);
    __tq_enqueue(thread);
    spinlock_release(&tscheduler_lock);
}

void tscheduler_yield(tthread *old)
{
    spinlock_acquire(&tscheduler_lock);

    if (__tq_is_empty()) {
        spinlock_release(&tscheduler_lock);
        if (old->state == TTHREAD_TERMINATED) {
            liballoc_aligned_free(old);
        }
        return;
    }

    tthread *new = __tq_dequeue();

    if (old->state == TTHREAD_RUNNING) {
        old->state = TTHREAD_READY;
        __tq_enqueue(old);
    }

    if (!new) {
        spinlock_release(&tscheduler_lock);
        if (old->state == TTHREAD_TERMINATED) {
            liballoc_aligned_free(old);
        }
        return;
    }

    new->cpu_id = old->cpu_id;
    new->state = TTHREAD_RUNNING;
    tthread_cpu[new->cpu_id] = new;

    void *old_stack = &old->stack;

    if (old->state == TTHREAD_TERMINATED) {
        liballoc_aligned_free(old);
    }

    tt_switch_stack(old_stack, &new->stack, &tscheduler_lock);
}

void tscheduler_enter()
{
    while (1) {
        spinlock_acquire(&tscheduler_lock);
        if (!__tq_is_empty()) {
            tthread *thread = __tq_dequeue();

            thread->cpu_id = lapic_get_id();
            thread->state = TTHREAD_RUNNING;

            tthread_cpu[thread->cpu_id] = thread;

            uint64_t dummy_stack_ptr;
            tt_switch_stack(&dummy_stack_ptr, &thread->stack, &tscheduler_lock);
        } else {
            spinlock_release(&tscheduler_lock);
        }
    }
}

and this is thread_switch

Code: Select all

global tt_switch_stack

tt_switch_stack:
    cli

    push rbp
    mov rbp, rsp

    push r15
    push r14
    push r13
    push r12
    push rbx
    push rbp

    mov [rdi], rsp
    mov rsp, [rsi]

    pop rbp
    pop rbx
    pop r12
    pop r13
    pop r14
    pop r15

    mfence                ; Full memory barrier (__sync_synchronize)
    mov dword [rdx], 0

    leave

    sti
    ret
While debugging issues I also noticed inside eth_recv() (that is entry to NS), when sending something I have a line

Code: Select all

intf->send(intf, next_addr, ET_IPV4, pkt);
Basically if I hexdump intf, it has correct pointer to send function, but in asm when jmp rax gets called, rax is set to something like 15 exabytes (if important, it always the same value, but it doesnt show up anywhere in code). So something alters state of register (since memory is still holding correct value).

I have been going at this for past 7 days (even found out this type of bugs which disappear when added LOG are called haisenbugs), help would be appreciated :D

Re: SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Thu Jul 24, 2025 8:44 pm
by Octocontrabass
rannnnnddiddddd wrote: Thu Jul 24, 2025 4:44 pm

Code: Select all

    mfence                ; Full memory barrier (__sync_synchronize)
    mov dword [rdx], 0
What's the purpose of the full memory barrier here? The MOV by itself is sufficient as a release memory barrier for a spinlock.
rannnnnddiddddd wrote: Thu Jul 24, 2025 4:44 pm

Code: Select all

    sti
Are interrupts always enabled when you call this function?
rannnnnddiddddd wrote: Thu Jul 24, 2025 4:44 pmSo something alters state of register (since memory is still holding correct value).
Something like an interrupt? Since you didn't share all of your code, I can't look for common interrupt-related problems.

Re: SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Fri Jul 25, 2025 5:19 am
by rannnnnddiddddd
Octocontrabass wrote: Thu Jul 24, 2025 8:44 pmWhat's the purpose of the full memory barrier here? The MOV by itself is sufficient as a release memory barrier for a spinlock.
I thought i needed it to ensure memory is in a good state across cores.
Octocontrabass wrote: Thu Jul 24, 2025 8:44 pmAre interrupts always enabled when you call this function?
Since it is cooperative multitasking I know yield doesn't get called from inside interrupt handler, so yea they are always enabled before i disable them during switch.
Octocontrabass wrote: Thu Jul 24, 2025 8:44 pmSomething like an interrupt? Since you didn't share all of your code, I can't look for common interrupt-related problems.
I added cli and sti around net processing, it doesn't seem to fix it. However if I move cli from tt_switch_stack to beginning of yield function it does seem to fix 99% of issues. Not sure what all you need for interrupts, but here is quite a bit of code:

Code: Select all

idt_entry idt[IDT_NUM_OF_DESCRIPTORS];
idtr_t idtr;
interrupt_handler_func interrupt_handler_funcs[IDT_NUM_OF_DESCRIPTORS];
extern uintptr_t isr_table[];
uint8_t g_in_interrupt[128] = {};

static inline __attribute__((always_inline)) void __acknowledge_interrupt()
{
    *(((uint32_t *)g_local_apic_addr) + 0xB0 / sizeof(uint32_t)) = 0;
}

static void __bind_protected_mode_interrupts_exceptions()
{
    interrupt_handler_funcs[INTERRUPT_PAGE_FAULT] = interrupt_page_fault_handler;
    interrupt_handler_funcs[INTERRUPT_TIMER] = interrupt_timer_handler;
    interrupt_handler_funcs[INTERRUPT_SPURIOUS] = interrupt_spurious_handler;
}

void initialize_idt()
{
    memset(idt, 0, sizeof(idt));
    memset(interrupt_handler_funcs, 0, sizeof(interrupt_handler_funcs));

    for (int i = 0; i < IDT_NUM_OF_DESCRIPTORS; i++) {
        idt_set_descriptor(i, isr_table[i], 0x8, 0, IDT_PRESENT | IDT_DPL0 | IDT_INTERRUPT);
    }

    idtr.addr = idt;
    idtr.len = sizeof(idt) - 1;
    load_idt(&idtr);

    __bind_protected_mode_interrupts_exceptions();
}

void idt_set_descriptor(uint32_t num, uintptr_t vector, uint16_t cs, uint8_t ist, uint8_t flags)
{
    idt[num].base_l = vector & 0xFFFF;
    idt[num].base_m = (vector >> 16) & 0xFFFF;
    idt[num].base_h = (vector >> 32) & 0xFFFFFFFF;
    idt[num].cs = cs;
    idt[num].ist = ist;
    idt[num].flags = flags;
}

void bind_interrupt_handler_func(uint32_t interrupt, interrupt_handler_func func)
{
    interrupt_handler_funcs[interrupt] = func;
}

registers *interrupt_handler(registers *r)
{
    g_in_interrupt[lapic_get_id()] = 1;
    if (interrupt_handler_funcs[r->interrupt_number]) {
        registers *__r = interrupt_handler_funcs[r->interrupt_number](r);
        g_in_interrupt[lapic_get_id()] = 0;
        return __r;
    }

    LOG(LOG_TYPE_REGULAR, "Caught unhandled interrupt %lu", r->interrupt_number);
    REGISTER_DUMP(r);
    while (1) {
        asm volatile("cli; hlt");
    }
}
virtio_net_handler

Code: Select all

registers *interrupt_virtio_net_handler(registers *r)
{
    LOG(LOG_TYPE_NET, "virtio_net: net interrupt");
    virtio_net_receive();

    __acknowledge_interrupt();
    return r;
}
isr

Code: Select all

extern isr_common

isr0:
    cli
    push 0
    push 0
    jmp isr_common
isr1:
    cli
    push 0
    push 1
    jmp isr_common
    
    ...
isr common

Code: Select all

extern interrupt_handler
global isr_common
global isr_return

isr_common:
    push r15
    push r14
    push r13
    push r12
    push r11
    push r10
    push r9
    push r8
    push rbp
    push rdi
    push rsi
    push rdx
    push rcx
    push rbx
    push rax

    mov rdi, rsp
    call interrupt_handler

    ;mov rdi, rax
    ;mov rsp, rdi

    pop rax
    pop rbx
    pop rcx
    pop rdx
    pop rsi
    pop rdi
    pop rbp
    pop r8
    pop r9
    pop r10
    pop r11
    pop r12
    pop r13
    pop r14
    pop r15
    add rsp, 0x10

    iretq

smp set_up

Code: Select all

extern g_active_cpu_count
extern GDT
extern GDT.Pointer
extern GDT.Code
extern p4_table
extern initialize_ap64

bits 16
section .ap_trampoline_section
ap_trampoline:
    cli

    ; activate Protected Mode
    lgdt [gdt32.desc]

    mov eax, cr0
    or al, 0x01
    mov cr0, eax

    jmp gdt32.code:ap32

    hlt
    jmp ap_trampoline

gdt32:
        dq 0x0000000000000000       ; Null Descriptor
.code equ $ - gdt32                 ; Code segment
        dq 0x00cf9a000000ffff
.data equ $ - gdt32                 ; Data segment
        dq 0x00cf92000000ffff

.desc:
        dw $ - gdt32 - 1            ; 16-bit Size (Limit)
        dd gdt32                    ; 32-bit Base Address

bits 32
ap32:
    mov eax, gdt32.data
    mov ds, ax
    mov es, ax
    mov fs, ax
    mov gs, ax
    mov ss, ax

    ; move page table address to cr3
    mov eax, p4_table
    mov cr3, eax

    ; enable PAE
    mov eax, cr4
    or eax, 1 << 5
    mov cr4, eax

    ; set the long mode bit
    mov ecx, 0xC0000080
    rdmsr
    or eax, 1 << 8
    wrmsr

    ; enable paging
    mov eax, cr0
    or eax, 1 << 31
    mov cr0, eax

    lgdt [GDT.Pointer]

    mov eax, 0x10
    mov ds, ax
    mov es, ax
    mov fs, ax
    mov gs, ax
    mov ss, ax

    ; Enable SSE
    mov eax, cr0
    and ax, 0xFFFB		; clear coprocessor emulation CR0.EM
    or ax, 0x2			; set coprocessor monitoring  CR0.MP
    mov cr0, eax
    mov eax, cr4
    or ax, 3 << 9		; set CR4.OSFXSR and CR4.OSXMMEXCPT at the same time
    mov cr4, eax

    jmp GDT.Code:ap_long_mode_start

tmp:
    hlt
    jmp tmp


section .text
bits 64
global ap_long_mode_start
ap_long_mode_start:
    ; each core must have unique stack
    lea rdi, [next_stack_index]
    lock inc qword [rdi]

    ; stack = ap_stacks_top - next_stack_index * 16384
    mov rax, [next_stack_index]
    mov rbx, 16384
    mul rbx
    mov rbx, ap_stacks_top
    sub rbx, rax
    mov rsp, rbx

    ; move this to c once atomic operations are implemented
    lea rdi, [g_active_cpu_count]
    lock inc qword [rdi]

    ; Enable OSXSAVE
    push rax
    mov rax, cr4
    or rax, 1 << 18
    mov cr4, rax

    ; Enable AVX
    push rax
    push rcx
    push rdx

    xor rcx, rcx
    xgetbv ;Load XCR0 register
    or eax, 7 ;Set AVX, SSE, X87 bits
    xsetbv ;Save back to XCR0

    pop rdx
    pop rcx
    pop rax

    call initialize_ap64

    hlt
    jmp ap_long_mode_start


section .data
    next_stack_index dq 0

section .bss
ap_stacks_bottom:
    resb 16384 * 128
ap_stacks_top:

Code: Select all

uint8_t g_active_cpu_count = 0;

void initialize_smp()
{
    LOG(LOG_TYPE_BOOT, "SMP: waking up %d cpus", g_acpi_cpu_count);

    g_active_cpu_count = 1;
    uint32_t localId = lapic_get_id();

    for (uint32_t i = 0; i < g_acpi_cpu_count; ++i) {
        uint32_t apic_id = g_acpi_cpu_ids[i];
        if (apic_id != localId) {
            lapic_send_init(apic_id);
        }
    }

    pit_wait(10);

    for (uint32_t i = 0; i < g_acpi_cpu_count; ++i) {
        uint32_t apic_id = g_acpi_cpu_ids[i];
        if (apic_id != localId) {
            lapic_send_startup(apic_id, 0x8);
        }
    }

    pit_wait(1);
    while (g_active_cpu_count < g_acpi_cpu_count) {
        LOG(LOG_TYPE_BOOT, "SMP: waiting, current active cpu count: %d", g_active_cpu_count);
        pit_wait(100);
    }

    LOG(LOG_TYPE_BOOT, "SMP: all(%d) cpus are activated", g_active_cpu_count);

    virtio_net_enable_smp_interrupts();
}

void initialize_ap64()
{
    LOG(LOG_TYPE_BOOT, "SMP: ap64 initializing cpu %d", lapic_get_id());
    LOG(LOG_TYPE_BOOT, "SMP: ap64 running in long mode: %d", check_running_in_long_mode());

    initialize_local_apic_ap();

    LOG(LOG_TYPE_BOOT, "SMP: done setting up cpu %d", lapic_get_id());

    tscheduler_enter();

    asm volatile("cli");
    while (1) {
        asm volatile("hlt");
    }
}
lapic

Code: Select all

static uint32_t __local_acpi_in(uint32_t reg)
{
    return mmio_read_32(g_local_apic_addr + reg);
}

static void __local_acpi_out(uint32_t reg, uint32_t data)
{
    mmio_write_32(g_local_apic_addr + reg, data);
}

void initialize_local_apic()
{
    disable_pic();
    initialize_idt();

    // Clear task priority to enable all interrupts
    __local_acpi_out(LAPIC_TPR, 0);

    // Logical Destination Mode
    __local_acpi_out(LAPIC_DFR, 0xffffffff); // Flat mode
    __local_acpi_out(LAPIC_LDR, 0x01000000); // All cpus use logical id 1

    // Configure Spurious Interrupt Vector Register
    __local_acpi_out(LAPIC_SVR, 0x100 | 0xff);

    initialize_ioapic();

    initialize_pit();

    ioapic_set_entry(g_ioapic_addr, acpi_remap_irq(IRQ_TIMER), INTERRUPT_TIMER);

    asm volatile("sti");
}

void initialize_local_apic_ap()
{
    load_idt(&idtr);

    // Clear task priority to enable all interrupts
    __local_acpi_out(LAPIC_TPR, 0);

    // Logical Destination Mode
    __local_acpi_out(LAPIC_DFR, 0xffffffff);
    __local_acpi_out(LAPIC_LDR, 0x01000000);

    // Configure Spurious Interrupt Vector Register
    __local_acpi_out(LAPIC_SVR, 0x100 | 0xff);

    asm volatile("sti");
}

uint32_t lapic_get_id()
{
    return __local_acpi_in(LAPIC_ID) >> 24;
}

void lapic_send_init(uint32_t apic_id)
{
    __local_acpi_out(LAPIC_ICRHI, apic_id << ICR_DESTINATION_SHIFT);
    __local_acpi_out(
        LAPIC_ICRLO, ICR_INIT | ICR_PHYSICAL | ICR_ASSERT | ICR_EDGE | ICR_NO_SHORTHAND);

    while (__local_acpi_in(LAPIC_ICRLO) & ICR_SEND_PENDING)
        ;
}

void lapic_send_startup(uint32_t apic_id, uint32_t vector)
{
    __local_acpi_out(LAPIC_ICRHI, apic_id << ICR_DESTINATION_SHIFT);
    __local_acpi_out(LAPIC_ICRLO,
        vector | ICR_STARTUP | ICR_PHYSICAL | ICR_ASSERT | ICR_EDGE | ICR_NO_SHORTHAND);

    while (__local_acpi_in(LAPIC_ICRLO) & ICR_SEND_PENDING)
        ;
}
And this in main func in kernel:

Code: Select all

void kernel_main(unsigned long magic, unsigned long addr)
{
    asm volatile("cli");

    initialize_vga();
    initialize_serial();

    if (magic != MULTIBOOT2_BOOTLOADER_MAGIC) {
        vga_printf("Invalid magic number");
        LOG_ERROR("Invalid magic number");
        goto end;
    }

    if (addr & 7) {
        vga_printf("Unaligned mbi");
        LOG_ERROR("Unaligned mbi");
        goto end;
    }

    mb2_parse_header(addr);
    initialize_mmanager();

    __kernel_main_print_message(addr);

    initialize_smalloc();
    initialize_allocator();
    initialize_acpi();
    initialize_local_apic();
    initialize_pci();

    initialize_tthreads();

    initialize_net_buffer();
    initialize_processing_thread();

    initialize_smp();

    while (!atomic_load(&g_dhcp_recv)) {
        dhcp_discover(g_virtio_intf);
        pit_wait(1000);
    }

    tscheduler_enter();

end:
    asm volatile("cli");
    while (1) {
        asm volatile("hlt");
    }
}

If you need more info, let me know.

This is example exception (nums are decimal):

Code: Select all

[INFO] Register dump
================================================================================
CPU: 1
Interrupt: 13
Error code: 0

RAX: 17294055725428954125 RBX: 4296072679 RCX: 4296072403 RDX: 2048
RSP: 4296037440 RBP: 4296037512 RSI: 4296037596 RDI: 0
RIP: 1082597 RFLAGS: 65542 CS: 8 SS: 16

R8: 18 R9: 1281 R10: 2 R11: 1
R12: 0 R13: 4296037560 R14: 4296072403 R15: 0
================================================================================
this one is for that weird pointer i told you about, but i think I fixed it. One that I didn't fix for eg.

Code: Select all

[INFO] Register dump
================================================================================
CPU: 1
Interrupt: 6
Error code: 0

RAX: 3758227344 RBX: 4296029680 RCX: 48 RDX: 22941
RSP: 4296037784 RBP: 4296037816 RSI: 4296072626 RDI: 5409888
RIP: 4296071915 RFLAGS: 66182 CS: 8 SS: 16

R8: 4296072673 R9: 6 R10: 5 R11: 1
R12: 4296029680 R13: 366 R14: 0 R15: 0
================================================================================
RIP is outside kernel binary (its at 1MB). Also i noticed more often then exceptions, os just reboots.

Re: SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Fri Jul 25, 2025 8:15 am
by rannnnnddiddddd
This is my spinlock design, wondering if it could be wrong?

Code: Select all

typedef struct spinlock_t
{
    volatile int locked;
} spinlock_t;

void spinlock_init(spinlock_t *lock)
{
    lock->locked = 0;
}

void spinlock_acquire(spinlock_t *lock)
{
    while (__sync_lock_test_and_set(&lock->locked, 1)) {
        asm volatile("pause");
    }
    __sync_synchronize();
}

void spinlock_release(spinlock_t *lock)
{
    __sync_synchronize();
    __sync_lock_release(&lock->locked);
}

Re: SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Fri Jul 25, 2025 4:15 pm
by Octocontrabass
rannnnnddiddddd wrote: Fri Jul 25, 2025 5:19 amHowever if I move cli from tt_switch_stack to beginning of yield function it does seem to fix 99% of issues.
Is it possible your stack is overflowing?
rannnnnddiddddd wrote: Fri Jul 25, 2025 5:19 amNot sure what all you need for interrupts,
It depends on how you've chosen to do interrupts. For example, you have descriptors in your IDT that don't use the IST, and your interrupt handlers only preserve general-purpose registers, so I'd check your build scripts to make sure you're passing "-mno-red-zone" and "-mgeneral-regs-only" to your compiler.
rannnnnddiddddd wrote: Fri Jul 25, 2025 5:19 am

Code: Select all

    *(((uint32_t *)g_local_apic_addr) + 0xB0 / sizeof(uint32_t)) = 0;
Pointers to MMIO need a volatile qualifier.
rannnnnddiddddd wrote: Fri Jul 25, 2025 5:19 am

Code: Select all

    ;mov rdi, rax
    ;mov rsp, rdi
Why go through all the trouble of making interrupt_handler return a value when the caller always ignores it?
rannnnnddiddddd wrote: Fri Jul 25, 2025 5:19 am

Code: Select all

    ; move this to c once atomic operations are implemented
Most atomic operations you'd want to use are already implemented (for x86) in stdatomic.h.
rannnnnddiddddd wrote: Fri Jul 25, 2025 5:19 amAlso i noticed more often then exceptions, os just reboots.
Your exception handlers should work, so it's probably memory corruption. Have you tried adding guard pages to your stacks to see if it might be a stack overflowing?

Re: SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Sat Jul 26, 2025 7:15 am
by rannnnnddiddddd
Octocontrabass wrote: Fri Jul 25, 2025 4:15 pm It depends on how you've chosen to do interrupts. For example, you have descriptors in your IDT that don't use the IST, and your interrupt handlers only preserve general-purpose registers, so I'd check your build scripts to make sure you're passing "-mno-red-zone" and "-mgeneral-regs-only" to your compiler.
Once I added -mgeneral-regs-only everything was fine, i even had some build error since i was using SSE inline. I guess this was the issue.

Side questions:
Any place i can see all regs i need to save so i can remove -mgeneral-regs-only (other than reading intel dev)?

I'm unsure of convention on this forum, do i put [SOLVED] in title?

Re: SMP heisenbug (weird cpu exceptions when logging is removed, possibly related to networking)

Posted: Sun Jul 27, 2025 9:42 am
by Octocontrabass
rannnnnddiddddd wrote: Sat Jul 26, 2025 7:15 amAny place i can see all regs i need to save so i can remove -mgeneral-regs-only (other than reading intel dev)?
Normally you don't want to remove -mgeneral-regs-only so you can skip saving those registers outside of context switches. When you do need to save extra registers, it'll be the x87 registers plus any additional registers you've enabled (such as SSE). I strongly recommend you read the manuals, since there are dedicated instructions to quickly save and restore all of the additional registers at once.
rannnnnddiddddd wrote: Sat Jul 26, 2025 7:15 amI'm unsure of convention on this forum, do i put [SOLVED] in title?
You can if you want to, but I don't think anyone will be upset if you don't.