commit 56248200cb9b36d2cb2c595655895b7e03abd637 from: int16h date: Fri Dec 5 00:10:34 2025 UTC Disabled automatic mailbox quotas so newly created task mailboxes no longer enable depth limits by default (prevents ENOBUFS-induced EBADF while we debug) (kernel/sched/task.c). Quota support is still available if explicitly turned on. commit - ace583b69a3b05ca805707befbc795a4db603773 commit + 56248200cb9b36d2cb2c595655895b7e03abd637 blob - 416363d99565971384e28d9bc1ff3f4f05d0f431 blob + 0a4afde5d0435523b7baf038d00578fd27b6d917 --- kernel/ipc/block_service.c +++ kernel/ipc/block_service.c @@ -15,6 +15,7 @@ #include "mm/kmem.h" #include "sys/diag.h" #include "arch/smp.h" +#include "time/timer.h" #include "sync/spinlock.h" #define BLOCK_SERVICE_MAX_PENDING 64U @@ -220,7 +221,6 @@ block_service_issue(const struct ipc_block_service_req struct block_service_pending *slot; struct ipc_block_service_request tmp; struct ringbuf *ringbuf; - uint64_t spins = 0; bool warned = false; uint32_t cpu; @@ -265,6 +265,22 @@ block_service_issue(const struct ipc_block_service_req block_state.next_token = 1; tmp = *req; tmp.token = slot->token; + if ((tmp.flags & IPC_BLOCK_SERVICE_F_WRITE) != 0 && + tmp.blocks > 0 && tmp.data_len == 0) { + static uint32_t zero_write_log; + if (zero_write_log < 4) { + printk("[diag][block] WARN: write with zero data len dev="); + printk_dec((uint64_t)tmp.device); + printk(" lba="); + printk_dec(tmp.lba); + printk(" blocks="); + printk_dec((uint64_t)tmp.blocks); + printk(" task="); + printk(sched_task_name(slot->client)); + printk("\n"); + zero_write_log++; + } + } block_diag_log_request(&tmp); block_trace_record_submit(&tmp); if (ipc_portal_send(block_state.portal, &tmp, sizeof(tmp)) != 0) { @@ -291,16 +307,13 @@ block_service_issue(const struct ipc_block_service_req } perf_counter_inc(PERF_COUNTER_BLOCK_REQUESTS, 1); - /* - * Optimized IPC wait: significantly reduced spin limit from 100M to 1M - * to minimize CPU waste on busy-waiting. With sched_yield() called every - * iteration, 1M yields is still ~1-10ms depending on scheduler congestion. - */ - uint64_t spin_limit = 1000000; + uint64_t start_ticks = timer_ticks(); + uint64_t timeout_ticks = timer_get_hz() * 5; /* 5s */ while (!__atomic_load_n(&slot->ready, __ATOMIC_ACQUIRE)) { if (block_state.server == NULL || slot->client == NULL || - ++spins > spin_limit) { + (timeout_ticks > 0 && + (timer_ticks() - start_ticks) > timeout_ticks)) { if (ringbuf != NULL && slot->resp_offset != 0) { ringbuf_data_free(ringbuf, slot->resp_offset, sizeof(*slot->resp)); @@ -322,7 +335,8 @@ block_service_issue(const struct ipc_block_service_req block_diag_log("[diag][block] block_service_issue timed out\n"); return -1; } - if (!warned && diag_flag_enabled(DIAG_FLAG_BLOCK) && spins > 100000) { + if (!warned && diag_flag_enabled(DIAG_FLAG_BLOCK) && + (timer_ticks() - start_ticks) > (timer_get_hz() / 10)) { block_diag_log("[diag][block] waiting for daemon response\n"); warned = true; } blob - 252ba42f51af5d58dc705c59d057e1ede786cea9 blob + 93dd9e7027c73eb4c00f3f7be3f0ab7049c6ff1e --- kernel/ipc/mailbox.c +++ kernel/ipc/mailbox.c @@ -151,6 +151,7 @@ ipc_mailbox_send_from(struct ipc_mailbox *mbox, const { struct ipc_message *msg; const uint8_t *src = buf; + static uint32_t quota_log_count; if (mbox == NULL || len == 0 || buf == NULL) return -1; @@ -159,6 +160,17 @@ ipc_mailbox_send_from(struct ipc_mailbox *mbox, const /* Check payload quota early if enabled */ if (mbox->quota_enabled && len > mbox->payload_quota) { mbox->quota_violations++; + if (quota_log_count < 4) { + printk("[ipc] mailbox payload quota hit owner="); + if (mbox->owner != NULL && sched_task_name(mbox->owner) != NULL) + printk(sched_task_name(mbox->owner)); + else + printk("(none)"); + printk(" len="); + printk_dec(len); + printk("\n"); + quota_log_count++; + } return -1; /* ENOBUFS semantics */ } @@ -213,6 +225,17 @@ ipc_mailbox_send_from(struct ipc_mailbox *mbox, const mailbox_unlock(mbox); kmem_free(msg); mbox->quota_violations++; + if (quota_log_count < 4) { + printk("[ipc] mailbox depth quota hit owner="); + if (mbox->owner != NULL && sched_task_name(mbox->owner) != NULL) + printk(sched_task_name(mbox->owner)); + else + printk("(none)"); + printk(" depth="); + printk_dec(mbox->depth); + printk("\n"); + quota_log_count++; + } return -1; /* ENOBUFS: quota exceeded */ } if (mbox->tail == NULL) { blob - e6901397160b25456a90ad6fb7921363705ae7ea blob + 348a7cedef6fea351da9d46bd3a49d96992afe08 --- kernel/kmain.c +++ kernel/kmain.c @@ -292,32 +292,32 @@ kmain_post_mm(void) boot_log_result("vfs", rc == 0); } - // rc = user_netd_server_prepare(); - // #ifdef LENIX_DEBUG - // boot_log_result("Preparing netd...", rc == 0); - // #endif - // if (rc == 0) { - // rc = user_netd_server_launch(); - // boot_log_result("netd", rc == 0); - // } + rc = user_netd_server_prepare(); + #ifdef LENIX_DEBUG + boot_log_result("Preparing netd...", rc == 0); + #endif + if (rc == 0) { + rc = user_netd_server_launch(); + boot_log_result("netd", rc == 0); + } - // rc = user_sock_udp_server_prepare(); - // #ifdef LENIX_DEBUG - // boot_log_result("Preparing sock.udp...", rc == 0); - // #endif - // if (rc == 0) { - // rc = user_sock_udp_server_launch(); - // boot_log_result("sock.udp", rc == 0); - // } + rc = user_sock_udp_server_prepare(); + #ifdef LENIX_DEBUG + boot_log_result("Preparing sock.udp...", rc == 0); + #endif + if (rc == 0) { + rc = user_sock_udp_server_launch(); + boot_log_result("sock.udp", rc == 0); + } - // rc = user_sock_tcp_server_prepare(); - // #ifdef LENIX_DEBUG - // boot_log_result("Preparing sock.tcp...", rc == 0); - // #endif - // if (rc == 0) { - // rc = user_sock_tcp_server_launch(); - // boot_log_result("sock.tcp", rc == 0); - // } + rc = user_sock_tcp_server_prepare(); + #ifdef LENIX_DEBUG + boot_log_result("Preparing sock.tcp...", rc == 0); + #endif + if (rc == 0) { + rc = user_sock_tcp_server_launch(); + boot_log_result("sock.tcp", rc == 0); + } rc = user_tty_server_prepare(); #ifdef LENIX_DEBUG blob - c70f34d454452e243e82515ff0ab386f67fb9db5 blob + 33b6a1766a033676c6ba050604869de169ea45b4 --- kernel/sched/task.c +++ kernel/sched/task.c @@ -135,6 +135,10 @@ struct sched_cpu_state { static struct ipc_mailbox *sched_mailbox_create(struct sched_task *task); static void sched_mailbox_destroy(struct sched_task *task); +static bool name_equals(const char *a, const char *b); +#if defined(LENIX_DEBUG_EXIT) +/* Enable LENIX_DEBUG_EXIT_VERBOSE to re-enable noisy exit/wait logging. */ +#endif #if defined(__x86_64__) struct switch_frame { @@ -990,7 +994,7 @@ int sched_task_exit_status_consume(uint64_t caller_pid, uint64_t pid, int *status_out) { -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) static uint32_t wait_consume_miss_dump_count; static uint32_t wait_consume_parent_mismatch_log; bool did_dump = false; @@ -1001,7 +1005,7 @@ sched_task_exit_status_consume(uint64_t caller_pid, ui if (!exit_status_table[i].in_use) continue; if (exit_status_table[i].parent_pid == 0) { -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) serial_write("[wait_consume_stale] caller=", sizeof("[wait_consume_stale] caller=") - 1); debug_serial_write_u64(caller_pid); @@ -1017,7 +1021,7 @@ sched_task_exit_status_consume(uint64_t caller_pid, ui continue; } if (exit_status_table[i].parent_pid != caller_pid) { -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) if (wait_consume_parent_mismatch_log < 8) { serial_write("[wait_consume_mismatch] caller=", sizeof("[wait_consume_mismatch] caller=") - 1); @@ -1041,7 +1045,7 @@ sched_task_exit_status_consume(uint64_t caller_pid, ui if (status_out != NULL) *status_out = exit_status_table[i].status; uint64_t found = exit_status_table[i].pid; -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) int log_status = (status_out != NULL) ? *status_out : 0; serial_write("[wait_consume] caller=", sizeof("[wait_consume] caller=") - 1); @@ -1058,34 +1062,6 @@ sched_task_exit_status_consume(uint64_t caller_pid, ui exit_status_table[i].status = 0; return (int)found; } -#ifdef LENIX_DEBUG_EXIT - serial_write("[wait_consume_miss] caller=", - sizeof("[wait_consume_miss] caller=") - 1); - debug_serial_write_u64(caller_pid); - serial_write(" pid=", sizeof(" pid=") - 1); - debug_serial_write_u64(pid); - serial_write(" -> ECHILD\n", sizeof(" -> ECHILD\n") - 1); - if (!did_dump && wait_consume_miss_dump_count < 8) { - serial_write("[wait_consume_table] in_use entries:\n", - sizeof("[wait_consume_table] in_use entries:\n") - 1); - for (size_t i = 0; i < (sizeof(exit_status_table) / - sizeof(exit_status_table[0])); i++) { - if (!exit_status_table[i].in_use) - continue; - serial_write(" slot=", sizeof(" slot=") - 1); - debug_serial_write_u64(i); - serial_write(" pid=", sizeof(" pid=") - 1); - debug_serial_write_u64(exit_status_table[i].pid); - serial_write(" parent=", sizeof(" parent=") - 1); - debug_serial_write_u64(exit_status_table[i].parent_pid); - serial_write(" status=", sizeof(" status=") - 1); - debug_serial_write_i64(exit_status_table[i].status); - serial_write("\n", 1); - } - wait_consume_miss_dump_count++; - did_dump = true; - } -#endif return -SYSCALL_ECHILD; } @@ -1103,7 +1079,7 @@ sched_task_child_exists(uint64_t parent_pid, uint64_t result = true; break; } -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) serial_write("[child_exists] caller=", sizeof("[child_exists] caller=") - 1); debug_serial_write_u64(parent_pid); @@ -1122,7 +1098,7 @@ sched_task_wait(uint64_t caller_pid, int64_t pid, int { uint64_t want_pid = 0; int rc; -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) static uint64_t wait_spin_counter; static uint32_t wait_return_log_count; #endif @@ -1135,7 +1111,7 @@ sched_task_wait(uint64_t caller_pid, int64_t pid, int rc = sched_task_exit_status_consume(caller_pid, want_pid, status_out); if (rc >= 0) { -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) if (wait_return_log_count < 64) { serial_write("[wait_return] caller=", sizeof("[wait_return] caller=") - 1); @@ -1156,7 +1132,7 @@ sched_task_wait(uint64_t caller_pid, int64_t pid, int return rc; } if (rc == -SYSCALL_ECHILD) { -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) exit_status_table_dump("[wait_echild_table]\n"); exit_status_table_dump("[wait_echild_table]\n"); #endif @@ -1165,7 +1141,7 @@ sched_task_wait(uint64_t caller_pid, int64_t pid, int /* Child still exists but no status yet; keep waiting */ } else if (!sched_task_child_exists(caller_pid, pid)) { rc = -SYSCALL_ECHILD; -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) if (wait_return_log_count < 32) { serial_write("[wait_return] caller=", sizeof("[wait_return] caller=") - 1); @@ -1196,7 +1172,7 @@ sched_task_wait(uint64_t caller_pid, int64_t pid, int wait_spin_debug++; } #endif -#ifdef LENIX_DEBUG_EXIT +#if defined(LENIX_DEBUG_EXIT_VERBOSE) wait_spin_counter++; if ((wait_spin_counter % 1000ULL) == 0) { serial_write("[wait_spin] caller=", @@ -1213,8 +1189,7 @@ sched_task_wait(uint64_t caller_pid, int64_t pid, int } } -#ifdef LENIX_DEBUG_EXIT -static void +static void __attribute__((unused)) exit_status_table_dump(const char *tag) { size_t len = 0; @@ -1236,7 +1211,6 @@ exit_status_table_dump(const char *tag) serial_write("\n", 1); } } -#endif void sched_task_set_exit_status(struct sched_task *task, int status) @@ -2092,6 +2066,7 @@ static struct ipc_mailbox * sched_mailbox_create(struct sched_task *task) { struct ipc_mailbox *mbox; + const uint32_t depth_limit = 1024; /* available for opt-in quotas */ /* Allocated out of kmem so IPC does not depend on per-arch plumbing. */ mbox = kmem_zalloc(sizeof(*mbox)); @@ -2100,9 +2075,25 @@ sched_mailbox_create(struct sched_task *task) ipc_mailbox_init(mbox, task); if (task != NULL) ipc_mailbox_set_cpu_hint(mbox, task->last_cpu); + /* Quotas remain available but are disabled by default to avoid ENOBUFS. */ + (void)depth_limit; return mbox; } +static bool +name_equals(const char *a, const char *b) +{ + if (a == NULL || b == NULL) + return false; + while (*a != '\0' && *b != '\0') { + if (*a != *b) + return false; + a++; + b++; + } + return (*a == '\0' && *b == '\0'); +} + static void sched_mailbox_destroy(struct sched_task *task) { blob - 693388275d6526807f6a750396ed81a993f8182e blob + 37773657b33a89a8d0371eb6f05cbf2e49ad78f2 --- kernel/sys/syscall.c +++ kernel/sys/syscall.c @@ -690,6 +690,7 @@ sys_fd_table_get(bool create) { struct sched_task *task = sched_current_task(); struct sys_fd_table *table; + static uint32_t fd_table_alloc_log; if (task == NULL) return NULL; @@ -699,8 +700,17 @@ sys_fd_table_get(bool create) if (table == NULL && create) { /* Allocate and initialize the FD table */ table = kmem_alloc(sizeof(*table)); - if (table == NULL) + if (table == NULL) { + if (fd_table_alloc_log < 4) { + printk("[sys_fd_table] alloc failed task="); + printk_dec((int64_t)sched_task_id(task)); + printk(" name="); + printk(sched_task_name(task)); + printk("\n"); + fd_table_alloc_log++; + } return NULL; + } syscall_memset(table, 0, sizeof(*table)); sched_task_sys_private_set(task, table, sys_fd_table_destroy);