diff --git a/artiq/runtime/analyzer.c b/artiq/runtime/analyzer.c index c6519eae0..a1b71b428 100644 --- a/artiq/runtime/analyzer.c +++ b/artiq/runtime/analyzer.c @@ -91,7 +91,7 @@ void analyzer_end(void) int analyzer_input(void *data, int length) { - log("no input should be received by analyzer, dropping connection"); + core_log("no input should be received by analyzer, dropping connection\n"); return -1; } diff --git a/artiq/runtime/clock.c b/artiq/runtime/clock.c index f1292e954..bbcf87d7c 100644 --- a/artiq/runtime/clock.c +++ b/artiq/runtime/clock.c @@ -60,7 +60,7 @@ int watchdog_set(int ms) break; } if(id < 0) { - log("WARNING: Failed to add watchdog"); + core_log("WARNING: Failed to add watchdog\n"); return id; } diff --git a/artiq/runtime/dds.c b/artiq/runtime/dds.c index 1e9d5cf16..396e652eb 100644 --- a/artiq/runtime/dds.c +++ b/artiq/runtime/dds.c @@ -95,7 +95,7 @@ static void dds_set_one(long long int now, long long int ref_time, unsigned int unsigned int channel_enc; if(channel >= CONFIG_DDS_CHANNEL_COUNT) { - log("Attempted to set invalid DDS channel"); + core_log("Attempted to set invalid DDS channel\n"); return; } #ifdef CONFIG_DDS_ONEHOT_SEL diff --git a/artiq/runtime/flash_storage.c b/artiq/runtime/flash_storage.c index 68a231716..dfa74906e 100644 --- a/artiq/runtime/flash_storage.c +++ b/artiq/runtime/flash_storage.c @@ -63,21 +63,24 @@ static int record_iter_next(struct iter_state *is, struct record *record, int *f return 0; if(record->size < 6) { - log("flash_storage might be corrupted: record size is %u (<6) at address %08x", record->size, record->raw_record); + core_log("flash_storage might be corrupted: record size is %u (<6) at address %08x\n", + record->size, record->raw_record); if(fatal) *fatal = 1; return 0; } if(is->seek > is->buf_len - sizeof(record->size) - 2) { /* 2 is the minimum key length */ - log("flash_storage might be corrupted: END_MARKER missing at the end of the storage sector"); + core_log("flash_storage might be corrupted: END_MARKER missing at the end of " + "the storage sector\n"); if(fatal) *fatal = 1; return 0; } if(record->size > is->buf_len - is->seek) { - log("flash_storage might be corrupted: invalid record_size %d at address %08x", record->size, record->raw_record); + core_log("flash_storage might be corrupted: invalid record_size %d at address %08x\n", + record->size, record->raw_record); if(fatal) *fatal = 1; return 0; @@ -87,7 +90,8 @@ static int record_iter_next(struct iter_state *is, struct record *record, int *f record->key_len = strnlen(record->key, record->size - sizeof(record->size)) + 1; if(record->key_len == record->size - sizeof(record->size) + 1) { - log("flash_storage might be corrupted: invalid key length at address %08x", record->raw_record); + core_log("flash_storage might be corrupted: invalid key length at address %08x\n", + record->raw_record); if(fatal) *fatal = 1; return 0; @@ -261,7 +265,7 @@ int fs_write(const char *key, const void *buffer, unsigned int buf_len) return 0; // Storage is definitely full. fatal_error: - log("fatal error: flash storage might be corrupted"); + core_log("fatal error: flash storage might be corrupted\n"); return 0; } @@ -292,7 +296,7 @@ unsigned int fs_read(const char *key, void *buffer, unsigned int buf_len, unsign } if(fatal) - log("fatal error: flash storage might be corrupted"); + core_log("fatal error: flash storage might be corrupted\n"); return read_length; } diff --git a/artiq/runtime/kloader.c b/artiq/runtime/kloader.c index 880050a70..65b7896d0 100644 --- a/artiq/runtime/kloader.c +++ b/artiq/runtime/kloader.c @@ -45,12 +45,12 @@ static int load_or_start_kernel(const void *library, int run_kernel) mailbox_acknowledge(); if(reply->type != MESSAGE_TYPE_LOAD_REPLY) { - log("BUG: unexpected reply to load/run request"); + core_log("BUG: unexpected reply to load/run request\n"); return 0; } if(reply->error != NULL) { - log("cannot load kernel: %s", reply->error); + core_log("cannot load kernel: %s\n", reply->error); return 0; } @@ -60,7 +60,7 @@ static int load_or_start_kernel(const void *library, int run_kernel) int kloader_load_library(const void *library) { if(!kernel_cpu_reset_read()) { - log("BUG: attempted to load kernel library while kernel CPU is running"); + core_log("BUG: attempted to load kernel library while kernel CPU is running\n"); return 0; } @@ -99,7 +99,7 @@ static int kloader_start_flash_kernel(char *key) return 0; if(remain) { - log("ERROR: kernel %s is too large", key); + core_log("ERROR: kernel %s is too large\n", key); return 0; } @@ -129,7 +129,7 @@ int kloader_validate_kpointer(void *p) { unsigned int v = (unsigned int)p; if((v < KERNELCPU_EXEC_ADDRESS) || (v > KERNELCPU_LAST_ADDRESS)) { - log("Received invalid pointer from kernel CPU: 0x%08x", v); + core_log("Received invalid pointer from kernel CPU: 0x%08x\n", v); return 0; } return 1; @@ -178,11 +178,7 @@ void kloader_service_essential_kmsg(void) case MESSAGE_TYPE_LOG: { struct msg_log *msg = (struct msg_log *)umsg; - if(msg->no_newline) { - lognonl_va(msg->fmt, msg->args); - } else { - log_va(msg->fmt, msg->args); - } + core_log_va(msg->fmt, msg->args); mailbox_acknowledge(); break; } diff --git a/artiq/runtime/ksupport.c b/artiq/runtime/ksupport.c index f9688d781..55adda177 100644 --- a/artiq/runtime/ksupport.c +++ b/artiq/runtime/ksupport.c @@ -102,8 +102,7 @@ static const struct symbol runtime_exports[] = { {"watchdog_set", &watchdog_set}, {"watchdog_clear", &watchdog_clear}, - {"log", &log}, - {"lognonl", &lognonl}, + {"core_log", &core_log}, {"send_rpc", &send_rpc}, {"recv_rpc", &recv_rpc}, @@ -164,7 +163,6 @@ int fprintf(FILE *stream, const char *fmt, ...) request.type = MESSAGE_TYPE_LOG; request.fmt = fmt; - request.no_newline = 1; va_start(request.args, fmt); mailbox_send_and_wait(&request); va_end(request.args); @@ -309,8 +307,8 @@ long long int now_init(void) reply = mailbox_wait_and_receive(); if(reply->type != MESSAGE_TYPE_NOW_INIT_REPLY) { - log("Malformed MESSAGE_TYPE_NOW_INIT_REQUEST reply type %d", - reply->type); + core_log("Malformed MESSAGE_TYPE_NOW_INIT_REQUEST reply type %d\n", + reply->type); while(1); } now = reply->now; @@ -345,8 +343,8 @@ int watchdog_set(int ms) reply = mailbox_wait_and_receive(); if(reply->type != MESSAGE_TYPE_WATCHDOG_SET_REPLY) { - log("Malformed MESSAGE_TYPE_WATCHDOG_SET_REQUEST reply type %d", - reply->type); + core_log("Malformed MESSAGE_TYPE_WATCHDOG_SET_REQUEST reply type %d\n", + reply->type); while(1); } id = reply->id; @@ -389,8 +387,8 @@ int recv_rpc(void *slot) { reply = mailbox_wait_and_receive(); if(reply->type != MESSAGE_TYPE_RPC_RECV_REPLY) { - log("Malformed MESSAGE_TYPE_RPC_RECV_REQUEST reply type %d", - reply->type); + core_log("Malformed MESSAGE_TYPE_RPC_RECV_REQUEST reply type %d\n", + reply->type); while(1); } @@ -458,8 +456,8 @@ struct artiq_list cache_get(const char *key) reply = mailbox_wait_and_receive(); if(reply->type != MESSAGE_TYPE_CACHE_GET_REPLY) { - log("Malformed MESSAGE_TYPE_CACHE_GET_REQUEST reply type %d", - reply->type); + core_log("Malformed MESSAGE_TYPE_CACHE_GET_REQUEST reply type %d\n", + reply->type); while(1); } @@ -479,8 +477,8 @@ void cache_put(const char *key, struct artiq_list value) reply = mailbox_wait_and_receive(); if(reply->type != MESSAGE_TYPE_CACHE_PUT_REPLY) { - log("Malformed MESSAGE_TYPE_CACHE_PUT_REQUEST reply type %d", - reply->type); + core_log("Malformed MESSAGE_TYPE_CACHE_PUT_REQUEST reply type %d\n", + reply->type); while(1); } @@ -491,25 +489,12 @@ void cache_put(const char *key, struct artiq_list value) } } -void lognonl(const char *fmt, ...) +void core_log(const char *fmt, ...) { struct msg_log request; request.type = MESSAGE_TYPE_LOG; request.fmt = fmt; - request.no_newline = 1; - va_start(request.args, fmt); - mailbox_send_and_wait(&request); - va_end(request.args); -} - -void log(const char *fmt, ...) -{ - struct msg_log request; - - request.type = MESSAGE_TYPE_LOG; - request.fmt = fmt; - request.no_newline = 0; va_start(request.args, fmt); mailbox_send_and_wait(&request); va_end(request.args); diff --git a/artiq/runtime/ksupport.h b/artiq/runtime/ksupport.h index 2194ef0db..c14128456 100644 --- a/artiq/runtime/ksupport.h +++ b/artiq/runtime/ksupport.h @@ -14,7 +14,6 @@ void send_rpc(int service, const char *tag, ...); int recv_rpc(void *slot); struct artiq_list cache_get(const char *key); void cache_put(const char *key, struct artiq_list value); -void lognonl(const char *fmt, ...); -void log(const char *fmt, ...); +void core_log(const char *fmt, ...); #endif /* __KSTARTUP_H */ diff --git a/artiq/runtime/log.c b/artiq/runtime/log.c index 6ac28fc1e..5779d8c94 100644 --- a/artiq/runtime/log.c +++ b/artiq/runtime/log.c @@ -7,18 +7,26 @@ #include "log.h" -static int buffer_index; +static int buffer_cursor; static char buffer[LOG_BUFFER_SIZE]; -void lognonl_va(const char *fmt, va_list args) +void core_log(const char *fmt, ...) +{ + va_list args; + + va_start(args, fmt); + core_log_va(fmt, args); + va_end(args); +} + +void core_log_va(const char *fmt, va_list args) { char outbuf[256]; - int i, len; + int len = vscnprintf(outbuf, sizeof(outbuf), fmt, args); - len = vscnprintf(outbuf, sizeof(outbuf), fmt, args); - for(i=0;ipayload, &reply, sizeof(struct monitor_reply)); @@ -112,7 +112,7 @@ static void moninj_ttlset(int channel, int mode) rtio_moninj_inj_value_write(1); break; default: - log("unknown TTL mode %d", mode); + core_log("unknown TTL mode %d\n", mode); break; } } @@ -143,7 +143,7 @@ void moninj_init(void) { listen_pcb = udp_new(); if(!listen_pcb) { - log("Failed to create UDP listening PCB"); + core_log("Failed to create UDP listening PCB\n"); return; } udp_bind(listen_pcb, IP_ADDR_ANY, 3250); diff --git a/artiq/runtime/rtiocrg.c b/artiq/runtime/rtiocrg.c index de56fde0d..260d5f3d1 100644 --- a/artiq/runtime/rtiocrg.c +++ b/artiq/runtime/rtiocrg.c @@ -17,17 +17,17 @@ void rtiocrg_init(void) clk = 0; fs_read("startup_clock", &b, 1, NULL); if(b == 'i') - log("Startup RTIO clock: internal"); + core_log("Startup RTIO clock: internal\n"); else if(b == 'e') { - log("Startup RTIO clock: external"); + core_log("Startup RTIO clock: external\n"); clk = 1; } else - log("ERROR: unrecognized startup_clock entry in flash storage"); + core_log("ERROR: unrecognized startup_clock entry in flash storage\n"); if(!rtiocrg_switch_clock(clk)) { - log("ERROR: startup RTIO clock failed"); - log("WARNING: this may cause the system initialization to fail"); - log("WARNING: fix clocking and reset the device"); + core_log("ERROR: startup RTIO clock failed\n"); + core_log("WARNING: this may cause the system initialization to fail\n"); + core_log("WARNING: fix clocking and reset the device\n"); } } diff --git a/artiq/runtime/session.c b/artiq/runtime/session.c index 94ed98591..5c4333480 100644 --- a/artiq/runtime/session.c +++ b/artiq/runtime/session.c @@ -95,8 +95,8 @@ static int in_packet_fill(uint8_t *data, int length) return -1; if(buffer_in_read_cursor < buffer_in_write_cursor) { - log("session.c: read underrun (%d bytes remaining)", - buffer_in_write_cursor - buffer_in_read_cursor); + core_log("session.c: read underrun (%d bytes remaining)\n", + buffer_in_write_cursor - buffer_in_read_cursor); } in_packet_reset(); @@ -109,9 +109,9 @@ static int in_packet_fill(uint8_t *data, int length) static void in_packet_chunk(void *ptr, int length) { if(buffer_in_read_cursor + length > buffer_in_write_cursor) { - log("session.c: read overrun while trying to read %d bytes" - " (%d remaining)", - length, buffer_in_write_cursor - buffer_in_read_cursor); + core_log("session.c: read overrun while trying to read %d bytes" + " (%d remaining)\n", + length, buffer_in_write_cursor - buffer_in_read_cursor); } if(ptr != NULL) @@ -153,7 +153,7 @@ static const char *in_packet_string() int length; const char *string = in_packet_bytes(&length); if(string[length - 1] != 0) { - log("session.c: string is not zero-terminated"); + core_log("session.c: string is not zero-terminated\n"); return ""; } return string; @@ -198,9 +198,9 @@ static void out_packet_extract(void **data, int *length) static void out_packet_advance_consumed(int length) { if(buffer_out_read_cursor + length > buffer_out_write_cursor) { - log("session.c: write underrun (consume) while trying to" - " acknowledge %d bytes (%d remaining)", - length, buffer_out_write_cursor - buffer_out_read_cursor); + core_log("session.c: write underrun (consume) while trying to" + " acknowledge %d bytes (%d remaining)\n", + length, buffer_out_write_cursor - buffer_out_read_cursor); return; } @@ -210,9 +210,9 @@ static void out_packet_advance_consumed(int length) static void out_packet_advance_sent(int length) { if(buffer_out_sent_cursor + length > buffer_out_write_cursor) { - log("session.c: write underrun (send) while trying to" - " acknowledge %d bytes (%d remaining)", - length, buffer_out_write_cursor - buffer_out_sent_cursor); + core_log("session.c: write underrun (send) while trying to" + " acknowledge %d bytes (%d remaining)\n", + length, buffer_out_write_cursor - buffer_out_sent_cursor); return; } @@ -224,9 +224,9 @@ static void out_packet_advance_sent(int length) static int out_packet_chunk(const void *ptr, int length) { if(buffer_out_write_cursor + length > BUFFER_OUT_SIZE) { - log("session.c: write overrun while trying to write %d bytes" - " (%d remaining)", - length, BUFFER_OUT_SIZE - buffer_out_write_cursor); + core_log("session.c: write overrun while trying to write %d bytes" + " (%d remaining)\n", + length, BUFFER_OUT_SIZE - buffer_out_write_cursor); return 0; } @@ -305,7 +305,7 @@ void session_startup_kernel(void) if(!kloader_start_startup_kernel()) return; - log("Startup kernel started"); + core_log("Startup kernel started\n"); while(1) { kloader_service_essential_kmsg(); @@ -318,21 +318,21 @@ void session_startup_kernel(void) if(umsg->type == MESSAGE_TYPE_FINISHED) break; else if(umsg->type == MESSAGE_TYPE_EXCEPTION) { - log("WARNING: startup kernel ended with exception"); + core_log("WARNING: startup kernel ended with exception\n"); break; } else { - log("ERROR: received invalid message type from kernel CPU"); + core_log("ERROR: received invalid message type from kernel CPU\n"); break; } } if(watchdog_expired()) { - log("WARNING: watchdog expired in startup kernel"); + core_log("WARNING: watchdog expired in startup kernel\n"); break; } } kloader_stop(); - log("Startup kernel terminated"); + core_log("Startup kernel terminated\n"); } void session_start(void) @@ -416,7 +416,7 @@ static int process_input(void) int clk = in_packet_int8(); if(user_kernel_state >= USER_KERNEL_RUNNING) { - log("Attempted to switch RTIO clock while kernel running"); + core_log("Attempted to switch RTIO clock while kernel running\n"); out_packet_empty(REMOTEMSG_TYPE_CLOCK_SWITCH_FAILED); break; } @@ -433,13 +433,13 @@ static int process_input(void) #error Output buffer cannot hold the log buffer #endif out_packet_start(REMOTEMSG_TYPE_LOG_REPLY); - log_get(&buffer_out.data[buffer_out_write_cursor]); + core_log_get(&buffer_out.data[buffer_out_write_cursor]); buffer_out_write_cursor += LOG_BUFFER_SIZE; out_packet_finish(); break; case REMOTEMSG_TYPE_LOG_CLEAR: - log_clear(); + core_log_clear(); out_packet_empty(REMOTEMSG_TYPE_LOG_REPLY); break; @@ -492,7 +492,7 @@ static int process_input(void) buffer_in_read_cursor = buffer_in_write_cursor; if(user_kernel_state >= USER_KERNEL_RUNNING) { - log("Attempted to load new kernel library while already running"); + core_log("Attempted to load new kernel library while already running\n"); out_packet_empty(REMOTEMSG_TYPE_LOAD_FAILED); break; } @@ -508,7 +508,7 @@ static int process_input(void) case REMOTEMSG_TYPE_RUN_KERNEL: if(user_kernel_state != USER_KERNEL_LOADED) { - log("Attempted to run kernel while not in the LOADED state"); + core_log("Attempted to run kernel while not in the LOADED state\n"); out_packet_empty(REMOTEMSG_TYPE_KERNEL_STARTUP_FAILED); break; } @@ -524,21 +524,21 @@ static int process_input(void) struct msg_rpc_recv_reply reply; if(user_kernel_state != USER_KERNEL_WAIT_RPC) { - log("Unsolicited RPC reply"); + core_log("Unsolicited RPC reply\n"); return 0; // restart session } request = mailbox_wait_and_receive(); if(request->type != MESSAGE_TYPE_RPC_RECV_REQUEST) { - log("Expected MESSAGE_TYPE_RPC_RECV_REQUEST, got %d", - request->type); + core_log("Expected MESSAGE_TYPE_RPC_RECV_REQUEST, got %d\n", + request->type); return 0; // restart session } const char *tag = in_packet_string(); void *slot = request->slot; if(!receive_rpc_value(&tag, &slot)) { - log("Failed to receive RPC reply"); + core_log("Failed to receive RPC reply\n"); return 0; // restart session } @@ -567,13 +567,13 @@ static int process_input(void) exception.function = in_packet_string(); if(user_kernel_state != USER_KERNEL_WAIT_RPC) { - log("Unsolicited RPC exception reply"); + core_log("Unsolicited RPC exception reply\n"); return 0; // restart session } request = mailbox_wait_and_receive(); if(request->type != MESSAGE_TYPE_RPC_RECV_REQUEST) { - log("Expected MESSAGE_TYPE_RPC_RECV_REQUEST, got %d", + core_log("Expected MESSAGE_TYPE_RPC_RECV_REQUEST, got %d\n", request->type); return 0; // restart session } @@ -588,8 +588,8 @@ static int process_input(void) } default: - log("Received invalid packet type %d from host", - buffer_in.header.type); + core_log("Received invalid packet type %d from host\n", + buffer_in.header.type); return 0; } @@ -657,7 +657,7 @@ static int sizeof_rpc_value(const char **tag) return sizeof_rpc_value(tag) * 3; default: - log("sizeof_rpc_value: unknown tag %02x", *((*tag) - 1)); + core_log("sizeof_rpc_value: unknown tag %02x\n", *((*tag) - 1)); return 0; } } @@ -674,8 +674,8 @@ static void *alloc_rpc_value(int size) request = mailbox_wait_and_receive(); if(request->type != MESSAGE_TYPE_RPC_RECV_REQUEST) { - log("Expected MESSAGE_TYPE_RPC_RECV_REQUEST, got %d", - request->type); + core_log("Expected MESSAGE_TYPE_RPC_RECV_REQUEST, got %d\n", + request->type); return NULL; } return request->slot; @@ -766,7 +766,7 @@ static int receive_rpc_value(const char **tag, void **slot) } default: - log("receive_rpc_value: unknown tag %02x", *((*tag) - 1)); + core_log("receive_rpc_value: unknown tag %02x\n", *((*tag) - 1)); return 0; } @@ -834,7 +834,7 @@ static int send_rpc_value(const char **tag, void **value) for(int i = 0; i < list->length; i++) { const char *tag_copy = *tag; if(!send_rpc_value(&tag_copy, &element)) { - log("failed to send list at element %d/%d", i, list->length); + core_log("failed to send list at element %d/%d\n", i, list->length); return 0; } } @@ -882,7 +882,7 @@ static int send_rpc_value(const char **tag, void **value) } default: - log("send_rpc_value: unknown tag %02x", *((*tag) - 1)); + core_log("send_rpc_value: unknown tag %02x\n", *((*tag) - 1)); return 0; } @@ -932,7 +932,7 @@ static int process_kmsg(struct msg_base *umsg) return 1; } if(user_kernel_state != USER_KERNEL_RUNNING) { - log("Received unexpected message from kernel CPU while not in running state"); + core_log("Received unexpected message from kernel CPU while not in running state\n"); return 0; } @@ -986,8 +986,8 @@ static int process_kmsg(struct msg_base *umsg) struct msg_rpc_send *msg = (struct msg_rpc_send *)umsg; if(!send_rpc_request(msg->service, msg->tag, msg->args)) { - log("Failed to send RPC request (service %d, tag %s)", - msg->service, msg->tag); + core_log("Failed to send RPC request (service %d, tag %s)\n", + msg->service, msg->tag); return 0; // restart session } @@ -1059,8 +1059,8 @@ static int process_kmsg(struct msg_base *umsg) } default: { - log("Received invalid message type %d from kernel CPU", - umsg->type); + core_log("Received invalid message type %d from kernel CPU\n", + umsg->type); return 0; } } @@ -1085,12 +1085,12 @@ void session_poll(void **data, int *length) { if(user_kernel_state == USER_KERNEL_RUNNING) { if(watchdog_expired()) { - log("Watchdog expired"); + core_log("Watchdog expired\n"); *length = -1; return; } if(!rtiocrg_check()) { - log("RTIO clock failure"); + core_log("RTIO clock failure\n"); *length = -1; return; }