From 8746a0b9480034c6dad06e1eaed2b3e3b4775918 Mon Sep 17 00:00:00 2001 From: Marijn Haverbeke Date: Thu, 7 Apr 2011 22:05:45 +0200 Subject: [PATCH] Move to macro-based logging checks in the C++ code No functions should be called for log statements that turn out to be inactive. --- src/rt/circular_buffer.cpp | 16 ++--- src/rt/rust.cpp | 4 +- src/rt/rust_builtin.cpp | 54 ++++++++-------- src/rt/rust_chan.cpp | 10 +-- src/rt/rust_crate.cpp | 2 +- src/rt/rust_crate_cache.cpp | 42 ++++++------- src/rt/rust_crate_reader.cpp | 55 ++++++++-------- src/rt/rust_dom.cpp | 45 +++++++------ src/rt/rust_dom.h | 5 ++ src/rt/rust_kernel.cpp | 27 ++++---- src/rt/rust_log.cpp | 5 -- src/rt/rust_log.h | 20 ++++++ src/rt/rust_port.cpp | 14 ++--- src/rt/rust_task.cpp | 60 +++++++++--------- src/rt/rust_task_list.cpp | 4 +- src/rt/rust_timer.cpp | 6 +- src/rt/rust_upcall.cpp | 118 +++++++++++++++++------------------ src/rt/rust_util.h | 4 +- 18 files changed, 254 insertions(+), 237 deletions(-) diff --git a/src/rt/circular_buffer.cpp b/src/rt/circular_buffer.cpp index a466724702caf..d5ba8e13c54ef 100644 --- a/src/rt/circular_buffer.cpp +++ b/src/rt/circular_buffer.cpp @@ -14,7 +14,7 @@ circular_buffer::circular_buffer(rust_dom *dom, size_t unit_sz) : A(dom, unit_sz, "Unit size must be larger than zero."); - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "new circular_buffer(buffer_sz=%d, unread=%d)" "-> circular_buffer=0x%" PRIxPTR, _buffer_sz, _unread, this); @@ -23,7 +23,7 @@ circular_buffer::circular_buffer(rust_dom *dom, size_t unit_sz) : } circular_buffer::~circular_buffer() { - dom->log(rust_log::MEM, "~circular_buffer 0x%" PRIxPTR, this); + DLOG(dom, rust_log::MEM, "~circular_buffer 0x%" PRIxPTR, this); I(dom, _buffer); W(dom, _unread == 0, "freeing circular_buffer with %d unread bytes", _unread); @@ -79,7 +79,7 @@ circular_buffer::enqueue(void *src) { grow(); } - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "circular_buffer enqueue " "unread: %d, next: %d, buffer_sz: %d, unit_sz: %d", _unread, _next, _buffer_sz, unit_sz); @@ -101,7 +101,7 @@ circular_buffer::enqueue(void *src) { memcpy(&_buffer[dst_idx], src, unit_sz); _unread += unit_sz; - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "circular_buffer pushed data at index: %d", dst_idx); } @@ -117,7 +117,7 @@ circular_buffer::dequeue(void *dst) { I(dom, _unread <= _buffer_sz); I(dom, _buffer); - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "circular_buffer dequeue " "unread: %d, next: %d, buffer_sz: %d, unit_sz: %d", _unread, _next, _buffer_sz, unit_sz); @@ -126,7 +126,7 @@ circular_buffer::dequeue(void *dst) { if (dst != NULL) { memcpy(dst, &_buffer[_next], unit_sz); } - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "shifted data from index %d", _next); _unread -= unit_sz; _next += unit_sz; @@ -144,7 +144,7 @@ void circular_buffer::grow() { size_t new_buffer_sz = _buffer_sz * 2; I(dom, new_buffer_sz <= MAX_CIRCULAR_BUFFER_SIZE); - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "circular_buffer is growing to %d bytes", new_buffer_sz); void *new_buffer = dom->malloc(new_buffer_sz); transfer(new_buffer); @@ -158,7 +158,7 @@ void circular_buffer::shrink() { size_t new_buffer_sz = _buffer_sz / 2; I(dom, initial_size() <= new_buffer_sz); - dom->log(rust_log::MEM | rust_log::COMM, + DLOG(dom, rust_log::MEM | rust_log::COMM, "circular_buffer is shrinking to %d bytes", new_buffer_sz); void *new_buffer = dom->malloc(new_buffer_sz); transfer(new_buffer); diff --git a/src/rt/rust.cpp b/src/rt/rust.cpp index 46fcb22ea0b10..9600b4d519b2d 100644 --- a/src/rt/rust.cpp +++ b/src/rt/rust.cpp @@ -87,10 +87,10 @@ rust_start(uintptr_t main_fn, rust_crate const *crate, int argc, rust_dom *dom = handle->referent(); command_line_args *args = new (dom) command_line_args(dom, argc, argv); - dom->log(rust_log::DOM, "startup: %d args in 0x%" PRIxPTR, + DLOG(dom, rust_log::DOM, "startup: %d args in 0x%" PRIxPTR, args->argc, (uintptr_t)args->args); for (int i = 0; i < args->argc; i++) { - dom->log(rust_log::DOM, + DLOG(dom, rust_log::DOM, "startup: arg[%d] = '%s'", i, args->argv[i]); } diff --git a/src/rt/rust_builtin.cpp b/src/rt/rust_builtin.cpp index e20cadeae49ac..9ef05ce0fece9 100644 --- a/src/rt/rust_builtin.cpp +++ b/src/rt/rust_builtin.cpp @@ -6,7 +6,7 @@ extern "C" CDECL rust_str* last_os_error(rust_task *task) { rust_dom *dom = task->dom; - task->log(rust_log::TASK, "last_os_error()"); + LOG(task, rust_log::TASK, "last_os_error()"); #if defined(__WIN32__) LPTSTR buf; @@ -91,7 +91,7 @@ extern "C" CDECL rust_vec* vec_alloc(rust_task *task, type_desc *t, type_desc *elem_t, size_t n_elts) { rust_dom *dom = task->dom; - task->log(rust_log::MEM | rust_log::STDLIB, + LOG(task, rust_log::MEM | rust_log::STDLIB, "vec_alloc %" PRIdPTR " elements of size %" PRIdPTR, n_elts, elem_t->size); size_t fill = n_elts * elem_t->size; @@ -126,7 +126,7 @@ vec_len(rust_task *task, type_desc *ty, rust_vec *v) extern "C" CDECL void vec_len_set(rust_task *task, type_desc *ty, rust_vec *v, size_t len) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, "vec_len_set(0x%" PRIxPTR ", %" PRIdPTR ") on vec with " "alloc = %" PRIdPTR ", fill = %" PRIdPTR @@ -139,7 +139,7 @@ vec_len_set(rust_task *task, type_desc *ty, rust_vec *v, size_t len) extern "C" CDECL void vec_print_debug_info(rust_task *task, type_desc *ty, rust_vec *v) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, "vec_print_debug_info(0x%" PRIxPTR ")" " with tydesc 0x%" PRIxPTR " (size = %" PRIdPTR ", align = %" PRIdPTR ")" @@ -154,7 +154,7 @@ vec_print_debug_info(rust_task *task, type_desc *ty, rust_vec *v) v->fill / ty->size); for (size_t i = 0; i < v->fill; ++i) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " %" PRIdPTR ": 0x%" PRIxPTR, i, v->data[i]); } @@ -306,7 +306,7 @@ task_sleep(rust_task *task, size_t time_in_us) { static void debug_tydesc_helper(rust_task *task, type_desc *t) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " size %" PRIdPTR ", align %" PRIdPTR ", stateful %" PRIdPTR ", first_param 0x%" PRIxPTR, t->size, t->align, t->is_stateful, t->first_param); @@ -315,19 +315,19 @@ debug_tydesc_helper(rust_task *task, type_desc *t) extern "C" CDECL void debug_tydesc(rust_task *task, type_desc *t) { - task->log(rust_log::STDLIB, "debug_tydesc"); + LOG(task, rust_log::STDLIB, "debug_tydesc"); debug_tydesc_helper(task, t); } extern "C" CDECL void debug_opaque(rust_task *task, type_desc *t, uint8_t *front) { - task->log(rust_log::STDLIB, "debug_opaque"); + LOG(task, rust_log::STDLIB, "debug_opaque"); debug_tydesc_helper(task, t); // FIXME may want to actually account for alignment. `front` may not // indeed be the front byte of the passed-in argument. for (uintptr_t i = 0; i < t->size; ++front, ++i) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " byte %" PRIdPTR ": 0x%" PRIx8, i, *front); } } @@ -340,14 +340,14 @@ struct rust_box : rc_base { extern "C" CDECL void debug_box(rust_task *task, type_desc *t, rust_box *box) { - task->log(rust_log::STDLIB, "debug_box(0x%" PRIxPTR ")", box); + LOG(task, rust_log::STDLIB, "debug_box(0x%" PRIxPTR ")", box); debug_tydesc_helper(task, t); - task->log(rust_log::STDLIB, " refcount %" PRIdPTR, + LOG(task, rust_log::STDLIB, " refcount %" PRIdPTR, box->ref_count == CONST_REFCOUNT ? CONST_REFCOUNT : box->ref_count - 1); // -1 because we ref'ed for this call for (uintptr_t i = 0; i < t->size; ++i) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " byte %" PRIdPTR ": 0x%" PRIx8, i, box->data[i]); } } @@ -360,13 +360,13 @@ struct rust_tag { extern "C" CDECL void debug_tag(rust_task *task, type_desc *t, rust_tag *tag) { - task->log(rust_log::STDLIB, "debug_tag"); + LOG(task, rust_log::STDLIB, "debug_tag"); debug_tydesc_helper(task, t); - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " discriminant %" PRIdPTR, tag->discriminant); for (uintptr_t i = 0; i < t->size - sizeof(tag->discriminant); ++i) - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " byte %" PRIdPTR ": 0x%" PRIx8, i, tag->variant[i]); } @@ -379,17 +379,17 @@ extern "C" CDECL void debug_obj(rust_task *task, type_desc *t, rust_obj *obj, size_t nmethods, size_t nbytes) { - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, "debug_obj with %" PRIdPTR " methods", nmethods); debug_tydesc_helper(task, t); - task->log(rust_log::STDLIB, " vtbl at 0x%" PRIxPTR, obj->vtbl); - task->log(rust_log::STDLIB, " body at 0x%" PRIxPTR, obj->body); + LOG(task, rust_log::STDLIB, " vtbl at 0x%" PRIxPTR, obj->vtbl); + LOG(task, rust_log::STDLIB, " body at 0x%" PRIxPTR, obj->body); for (uintptr_t *p = obj->vtbl; p < obj->vtbl + nmethods; ++p) - task->log(rust_log::STDLIB, " vtbl word: 0x%" PRIxPTR, *p); + LOG(task, rust_log::STDLIB, " vtbl word: 0x%" PRIxPTR, *p); for (uintptr_t i = 0; i < nbytes; ++i) - task->log(rust_log::STDLIB, + LOG(task, rust_log::STDLIB, " body byte %" PRIdPTR ": 0x%" PRIxPTR, i, obj->body->data[i]); } @@ -402,12 +402,12 @@ struct rust_fn { extern "C" CDECL void debug_fn(rust_task *task, type_desc *t, rust_fn *fn) { - task->log(rust_log::STDLIB, "debug_fn"); + LOG(task, rust_log::STDLIB, "debug_fn"); debug_tydesc_helper(task, t); - task->log(rust_log::STDLIB, " thunk at 0x%" PRIxPTR, fn->thunk); - task->log(rust_log::STDLIB, " closure at 0x%" PRIxPTR, fn->closure); + LOG(task, rust_log::STDLIB, " thunk at 0x%" PRIxPTR, fn->thunk); + LOG(task, rust_log::STDLIB, " closure at 0x%" PRIxPTR, fn->closure); if (fn->closure) { - task->log(rust_log::STDLIB, " refcount %" PRIdPTR, + LOG(task, rust_log::STDLIB, " refcount %" PRIdPTR, fn->closure->ref_count); } } @@ -418,9 +418,9 @@ debug_ptrcast(rust_task *task, type_desc *to_ty, void *ptr) { - task->log(rust_log::STDLIB, "debug_ptrcast from"); + LOG(task, rust_log::STDLIB, "debug_ptrcast from"); debug_tydesc_helper(task, from_ty); - task->log(rust_log::STDLIB, "to"); + LOG(task, rust_log::STDLIB, "to"); debug_tydesc_helper(task, to_ty); return ptr; } @@ -428,7 +428,7 @@ debug_ptrcast(rust_task *task, extern "C" CDECL void debug_trap(rust_task *task, rust_str *s) { - task->log(rust_log::STDLIB, "trapping: %s", s->data); + LOG(task, rust_log::STDLIB, "trapping: %s", s->data); // FIXME: x86-ism. __asm__("int3"); } diff --git a/src/rt/rust_chan.cpp b/src/rt/rust_chan.cpp index 9a6664535cfca..a88579607c48f 100644 --- a/src/rt/rust_chan.cpp +++ b/src/rt/rust_chan.cpp @@ -13,14 +13,14 @@ rust_chan::rust_chan(rust_task *task, if (port) { associate(port); } - task->log(rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::MEM | rust_log::COMM, "new rust_chan(task=0x%" PRIxPTR ", port=0x%" PRIxPTR ") -> chan=0x%" PRIxPTR, (uintptr_t) task, (uintptr_t) port, (uintptr_t) this); } rust_chan::~rust_chan() { - task->log(rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::MEM | rust_log::COMM, "del rust_chan(task=0x%" PRIxPTR ")", (uintptr_t) this); A(task->dom, is_associated() == false, @@ -33,7 +33,7 @@ rust_chan::~rust_chan() { void rust_chan::associate(maybe_proxy *port) { this->port = port; if (port->is_proxy() == false) { - task->log(rust_log::TASK, + LOG(task, rust_log::TASK, "associating chan: 0x%" PRIxPTR " with port: 0x%" PRIxPTR, this, port); this->port->referent()->chans.push(this); @@ -51,7 +51,7 @@ void rust_chan::disassociate() { A(task->dom, is_associated(), "Channel must be associated with a port."); if (port->is_proxy() == false) { - task->log(rust_log::TASK, + LOG(task, rust_log::TASK, "disassociating chan: 0x%" PRIxPTR " from port: 0x%" PRIxPTR, this, port->referent()); port->referent()->chans.swap_delete(this); @@ -84,7 +84,7 @@ void rust_chan::send(void *sptr) { } else { rust_port *target_port = port->referent(); if (target_port->task->blocked_on(target_port)) { - dom->log(rust_log::COMM, "dequeued in rendezvous_ptr"); + DLOG(dom, rust_log::COMM, "dequeued in rendezvous_ptr"); buffer.dequeue(target_port->task->rendezvous_ptr); target_port->task->rendezvous_ptr = 0; target_port->task->wakeup(target_port); diff --git a/src/rt/rust_crate.cpp b/src/rt/rust_crate.cpp index ced6aaf46a73e..23f01c0747fa7 100644 --- a/src/rt/rust_crate.cpp +++ b/src/rt/rust_crate.cpp @@ -41,7 +41,7 @@ rust_crate::mem_area::mem_area(rust_dom *dom, uintptr_t pos, size_t sz) base(pos), lim(pos + sz) { - dom->log(rust_log::MEM, "new mem_area [0x%" PRIxPTR ",0x%" PRIxPTR "]", + DLOG(dom, rust_log::MEM, "new mem_area [0x%" PRIxPTR ",0x%" PRIxPTR "]", base, lim); } diff --git a/src/rt/rust_crate_cache.cpp b/src/rt/rust_crate_cache.cpp index 9fc1ae1856d75..f9cc400d76bad 100644 --- a/src/rt/rust_crate_cache.cpp +++ b/src/rt/rust_crate_cache.cpp @@ -10,12 +10,12 @@ rust_crate_cache::lib::lib(rust_dom *dom, char const *name) #else handle = (uintptr_t)dlopen(name, RTLD_GLOBAL|RTLD_LAZY); #endif - dom->log(rust_log::CACHE, "loaded library '%s' as 0x%" PRIxPTR, + DLOG(dom, rust_log::CACHE, "loaded library '%s' as 0x%" PRIxPTR, name, handle); } rust_crate_cache::lib::~lib() { - dom->log(rust_log::CACHE, "~rust_crate_cache::lib(0x%" PRIxPTR ")", + DLOG(dom, rust_log::CACHE, "~rust_crate_cache::lib(0x%" PRIxPTR ")", handle); if (handle) { #if defined(__WIN32__) @@ -46,17 +46,17 @@ rust_crate_cache::c_sym::c_sym(rust_dom *dom, lib *library, char const *name) #else val = (uintptr_t)dlsym((void*)handle, name); #endif - dom->log(rust_log::CACHE, "resolved symbol '%s' to 0x%" PRIxPTR, + DLOG(dom, rust_log::CACHE, "resolved symbol '%s' to 0x%" PRIxPTR, name, val); } else { - dom->log(rust_log::CACHE | rust_log::ERR, + DLOG(dom, rust_log::CACHE | rust_log::ERR, "unresolved symbol '%s', null lib handle", name); } } rust_crate_cache::c_sym::~c_sym() { - dom->log(rust_log::CACHE, + DLOG(dom, rust_log::CACHE, "~rust_crate_cache::c_sym(0x%" PRIxPTR ")", val); library->deref(); } @@ -80,7 +80,7 @@ rust_crate_cache::rust_sym::rust_sym(rust_dom *dom, typedef rust_crate_reader::die die; rust_crate const *crate = (rust_crate*)crate_sym->get_val(); if (!crate) { - dom->log(rust_log::CACHE | rust_log::ERR, + DLOG(dom, rust_log::CACHE | rust_log::ERR, "failed to resolve symbol, null crate symbol"); return; } @@ -98,15 +98,15 @@ rust_crate_cache::rust_sym::rust_sym(rust_dom *dom, && !t1.is_null() && t1.find_child_by_name(crate_rel(curr_crate, *c), t2)); ++c, t1=t2) { - dom->log(rust_log::DWARF|rust_log::CACHE, + DLOG(dom, rust_log::DWARF|rust_log::CACHE, "matched die <0x%" PRIxPTR ">, child '%s' = die<0x%" PRIxPTR ">", t1.off, crate_rel(curr_crate, *c), t2.off); found_root = found_root || true; if (!*(c+1) && t2.find_num_attr(DW_AT_low_pc, val)) { - dom->log(rust_log::DWARF|rust_log::CACHE, + DLOG(dom, rust_log::DWARF|rust_log::CACHE, "found relative address: 0x%" PRIxPTR, val); - dom->log(rust_log::DWARF|rust_log::CACHE, + DLOG(dom, rust_log::DWARF|rust_log::CACHE, "plus image-base 0x%" PRIxPTR, crate->get_image_base()); val += crate->get_image_base(); @@ -118,15 +118,15 @@ rust_crate_cache::rust_sym::rust_sym(rust_dom *dom, break; } if (found_leaf) { - dom->log(rust_log::CACHE, "resolved symbol to 0x%" PRIxPTR, val); + DLOG(dom, rust_log::CACHE, "resolved symbol to 0x%" PRIxPTR, val); } else { - dom->log(rust_log::CACHE | rust_log::ERR, + DLOG(dom, rust_log::CACHE | rust_log::ERR, "failed to resolve symbol"); } } rust_crate_cache::rust_sym::~rust_sym() { - dom->log(rust_log::CACHE, + DLOG(dom, rust_log::CACHE, "~rust_crate_cache::rust_sym(0x%" PRIxPTR ")", val); crate_sym->deref(); } @@ -155,7 +155,7 @@ rust_crate_cache::get_c_sym(size_t n, lib *library, char const *name) { I(dom, n < crate->n_c_syms); c_sym *sym = c_syms[n]; - dom->log(rust_log::CACHE, "cached C symbol %s = 0x%" PRIxPTR, name, sym); + DLOG(dom, rust_log::CACHE, "cached C symbol %s = 0x%" PRIxPTR, name, sym); if (!sym) { sym = new (dom) c_sym(dom, library, name); c_syms[n] = sym; @@ -199,10 +199,10 @@ rust_crate_cache::get_type_desc(size_t size, size_t keysz = n_descs * sizeof(type_desc*); HASH_FIND(hh, this->type_descs, descs, keysz, td); if (td) { - dom->log(rust_log::CACHE, "rust_crate_cache::get_type_desc hit"); + DLOG(dom, rust_log::CACHE, "rust_crate_cache::get_type_desc hit"); return td; } - dom->log(rust_log::CACHE, "rust_crate_cache::get_type_desc miss"); + DLOG(dom, rust_log::CACHE, "rust_crate_cache::get_type_desc miss"); td = (type_desc*) dom->malloc(sizeof(type_desc) + keysz); if (!td) return NULL; @@ -214,7 +214,7 @@ rust_crate_cache::get_type_desc(size_t size, td->size = size; td->align = align; for (size_t i = 0; i < n_descs; ++i) { - dom->log(rust_log::CACHE, + DLOG(dom, rust_log::CACHE, "rust_crate_cache::descs[%" PRIdPTR "] = 0x%" PRIxPTR, i, descs[i]); td->descs[i] = descs[i]; @@ -249,11 +249,11 @@ rust_crate_cache::rust_crate_cache(rust_dom *dom, void rust_crate_cache::flush() { - dom->log(rust_log::CACHE, "rust_crate_cache::flush()"); + DLOG(dom, rust_log::CACHE, "rust_crate_cache::flush()"); for (size_t i = 0; i < crate->n_rust_syms; ++i) { rust_sym *s = rust_syms[i]; if (s) { - dom->log(rust_log::CACHE, + DLOG(dom, rust_log::CACHE, "rust_crate_cache::flush() deref rust_sym %" PRIdPTR " (rc=%" PRIdPTR ")", i, s->ref_count); s->deref(); @@ -264,7 +264,7 @@ rust_crate_cache::flush() { for (size_t i = 0; i < crate->n_c_syms; ++i) { c_sym *s = c_syms[i]; if (s) { - dom->log(rust_log::CACHE, + DLOG(dom, rust_log::CACHE, "rust_crate_cache::flush() deref c_sym %" PRIdPTR " (rc=%" PRIdPTR ")", i, s->ref_count); s->deref(); @@ -275,7 +275,7 @@ rust_crate_cache::flush() { for (size_t i = 0; i < crate->n_libs; ++i) { lib *l = libs[i]; if (l) { - dom->log(rust_log::CACHE, "rust_crate_cache::flush() deref lib %" + DLOG(dom, rust_log::CACHE, "rust_crate_cache::flush() deref lib %" PRIdPTR " (rc=%" PRIdPTR ")", i, l->ref_count); l->deref(); } @@ -285,7 +285,7 @@ rust_crate_cache::flush() { while (type_descs) { type_desc *d = type_descs; HASH_DEL(type_descs, d); - dom->log(rust_log::MEM, + DLOG(dom, rust_log::MEM, "rust_crate_cache::flush() tydesc %" PRIxPTR, d); dom->free(d); } diff --git a/src/rt/rust_crate_reader.cpp b/src/rt/rust_crate_reader.cpp index f0e6fa934cc14..edad0c2eeee86 100644 --- a/src/rt/rust_crate_reader.cpp +++ b/src/rt/rust_crate_reader.cpp @@ -92,7 +92,7 @@ rust_crate_reader::mem_reader::adv(size_t amt) ok = false; if (!ok) return; - // mem.dom->log(rust_log::MEM, "adv %d bytes", amt); + // mem.DLOG(dom, rust_log::MEM, "adv %d bytes", amt); pos += amt; ok &= !at_end(); I(mem.dom, at_end() || (mem.base <= pos && pos < mem.lim)); @@ -120,7 +120,7 @@ rust_crate_reader::abbrev_reader::abbrev_reader rust_dom *dom = mem.dom; while (is_ok() && !at_end()) { - // dom->log(rust_log::DWARF, "reading new abbrev at 0x%" PRIxPTR, + // DLOG(dom, rust_log::DWARF, "reading new abbrev at 0x%" PRIxPTR, // tell_off()); uintptr_t idx, tag; @@ -133,13 +133,13 @@ rust_crate_reader::abbrev_reader::abbrev_reader size_t body_off = tell_off(); while (is_ok() && step_attr_form_pair(attr, form)); - // dom->log(rust_log::DWARF, + // DLOG(dom, rust_log::DWARF, // "finished scanning attr/form pairs, pos=0x%" // PRIxPTR ", lim=0x%" PRIxPTR ", is_ok=%d, at_end=%d", // pos, mem.lim, is_ok(), at_end()); if (is_ok() || at_end()) { - dom->log(rust_log::DWARF, "read abbrev: %" PRIdPTR, idx); + DLOG(dom, rust_log::DWARF, "read abbrev: %" PRIdPTR, idx); I(dom, idx = abbrevs.length() + 1); abbrevs.push(new (dom) abbrev(dom, body_off, tell_off() - body_off, @@ -162,11 +162,11 @@ rust_crate_reader::abbrev_reader::step_attr_form_pair(uintptr_t &attr, { attr = 0; form = 0; - // mem.dom->log(rust_log::DWARF, "reading attr/form pair at 0x%" PRIxPTR, + // mem.DLOG(dom, rust_log::DWARF, "reading attr/form pair at 0x%" PRIxPTR, // tell_off()); get_uleb(attr); get_uleb(form); - // mem.dom->log(rust_log::DWARF, "attr 0x%" PRIxPTR ", form 0x%" PRIxPTR, + // mem.DLOG(dom, rust_log::DWARF, "attr 0x%" PRIxPTR ", form 0x%" PRIxPTR, // attr, form); return ! (attr == 0 && form == 0); } @@ -254,18 +254,19 @@ rust_crate_reader::die::die(die_reader *rdr, uintptr_t off) rdr->get_uleb(ab_idx); if (!ab_idx) { ab = NULL; - dom->log(rust_log::DWARF, "DIE <0x%" PRIxPTR "> (null)", off); - dom->get_log().outdent(); + DLOG(dom, rust_log::DWARF, "DIE <0x%" PRIxPTR "> (null)", off); + if (dom->get_log().is_tracing(rust_log::DWARF)) + dom->get_log().outdent(); } else { ab = rdr->abbrevs.get_abbrev(ab_idx); if (!ab) { - dom->log(rust_log::DWARF, " bad abbrev number: 0x%" + DLOG(dom, rust_log::DWARF, " bad abbrev number: 0x%" PRIxPTR, ab_idx); rdr->fail(); } else { - dom->log(rust_log::DWARF, "DIE <0x%" PRIxPTR "> abbrev 0x%" + DLOG(dom, rust_log::DWARF, "DIE <0x%" PRIxPTR "> abbrev 0x%" PRIxPTR, off, ab_idx); - dom->log(rust_log::DWARF, " tag 0x%x, has children: %d", + DLOG(dom, rust_log::DWARF, " tag 0x%x, has children: %d", ab->tag, ab->has_children); } } @@ -353,7 +354,7 @@ rust_crate_reader::die::step_attr(attr &a) const break; default: - rdr->mem.dom->log(rust_log::DWARF, " unknown dwarf form: 0x%" + DLOG(rdr->mem.dom, rust_log::DWARF, " unknown dwarf form: 0x%" PRIxPTR, a.form); rdr->fail(); break; @@ -473,16 +474,16 @@ rust_crate_reader::die::next() const while (step_attr(a)) { I(dom, !(a.is_numeric() && a.is_string())); if (a.is_numeric()) - dom->log(rust_log::DWARF, " attr num: 0x%" + DLOG(dom, rust_log::DWARF, " attr num: 0x%" PRIxPTR, a.get_num(dom)); else if (a.is_string()) - dom->log(rust_log::DWARF, " attr str: %s", + DLOG(dom, rust_log::DWARF, " attr str: %s", a.get_str(dom)); else - dom->log(rust_log::DWARF, " attr ??:"); + DLOG(dom, rust_log::DWARF, " attr ??:"); } } - if (has_children()) + if (has_children() && dom->get_log().is_tracing(rust_log::DWARF)) dom->get_log().indent(); } return die(rdr, rdr->tell_off()); @@ -493,12 +494,12 @@ rust_crate_reader::die::next_sibling() const { // FIXME: use DW_AT_sibling, when present. if (has_children()) { - // rdr->mem.dom->log(rust_log::DWARF, "+++ children of die 0x%" + // DLOG(rdr->mem.dom, rust_log::DWARF, "+++ children of die 0x%" // PRIxPTR, off); die child = next(); while (!child.is_null()) child = child.next_sibling(); - // rdr->mem.dom->log(rust_log::DWARF, "--- children of die 0x%" + // DLOG(rdr->mem.dom, rust_log::DWARF, "--- children of die 0x%" // PRIxPTR, off); return child.next(); } else { @@ -553,16 +554,16 @@ rust_crate_reader::die_reader::die_reader(rust_crate::mem_area &die_mem, get(sizeof_addr); if (is_ok()) { - dom->log(rust_log::DWARF, "new root CU at 0x%" PRIxPTR, die_mem.base); - dom->log(rust_log::DWARF, "CU unit length: %" PRId32, cu_unit_length); - dom->log(rust_log::DWARF, "dwarf version: %" PRId16, dwarf_vers); - dom->log(rust_log::DWARF, "CU abbrev off: %" PRId32, cu_abbrev_off); - dom->log(rust_log::DWARF, "size of address: %" PRId8, sizeof_addr); + DLOG(dom, rust_log::DWARF, "new root CU at 0x%" PRIxPTR, die_mem.base); + DLOG(dom, rust_log::DWARF, "CU unit length: %" PRId32, cu_unit_length); + DLOG(dom, rust_log::DWARF, "dwarf version: %" PRId16, dwarf_vers); + DLOG(dom, rust_log::DWARF, "CU abbrev off: %" PRId32, cu_abbrev_off); + DLOG(dom, rust_log::DWARF, "size of address: %" PRId8, sizeof_addr); I(dom, sizeof_addr == sizeof(uintptr_t)); I(dom, dwarf_vers >= 2); I(dom, cu_base + cu_unit_length == die_mem.lim - die_mem.base); } else { - dom->log(rust_log::DWARF, "failed to read root CU header"); + DLOG(dom, rust_log::DWARF, "failed to read root CU header"); } } @@ -579,9 +580,9 @@ rust_crate_reader::rust_crate_reader(rust_dom *dom, die_mem(crate->get_debug_info(dom)), dies(die_mem, abbrevs) { - dom->log(rust_log::MEM, "crate_reader on crate: 0x%" PRIxPTR, this); - dom->log(rust_log::MEM, "debug_abbrev: 0x%" PRIxPTR, abbrev_mem.base); - dom->log(rust_log::MEM, "debug_info: 0x%" PRIxPTR, die_mem.base); + DLOG(dom, rust_log::MEM, "crate_reader on crate: 0x%" PRIxPTR, this); + DLOG(dom, rust_log::MEM, "debug_abbrev: 0x%" PRIxPTR, abbrev_mem.base); + DLOG(dom, rust_log::MEM, "debug_info: 0x%" PRIxPTR, die_mem.base); // For now, perform diagnostics only. dies.dump(); } diff --git a/src/rt/rust_dom.cpp b/src/rt/rust_dom.cpp index 356e9fe49ba36..9512eeaa3cca4 100644 --- a/src/rt/rust_dom.cpp +++ b/src/rt/rust_dom.cpp @@ -23,7 +23,7 @@ rust_dom::rust_dom(rust_kernel *kernel, kernel(kernel), message_queue(message_queue) { - logptr("new dom", (uintptr_t)this); + LOGPTR(this, "new dom", (uintptr_t)this); isaac_init(this, &rctx); #ifndef __WIN32__ pthread_attr_init(&attr); @@ -34,8 +34,8 @@ rust_dom::rust_dom(rust_kernel *kernel, } rust_dom::~rust_dom() { - log(rust_log::MEM | rust_log::DOM, - "~rust_dom %s @0x%" PRIxPTR, name, (uintptr_t)this); + DLOG(this, rust_log::MEM | rust_log::DOM, + "~rust_dom %s @0x%" PRIxPTR, name, (uintptr_t)this); newborn_tasks.delete_all(); running_tasks.delete_all(); blocked_tasks.delete_all(); @@ -79,11 +79,6 @@ rust_dom::log(uint32_t type_bits, char const *fmt, ...) { } } -rust_log & -rust_dom::get_log() { - return _log; -} - void rust_dom::logptr(char const *msg, uintptr_t ptrval) { log(rust_log::MEM, "%s 0x%" PRIxPTR, msg, ptrval); @@ -156,7 +151,7 @@ rust_dom::free(void *mem) { void rust_dom::free(void *mem, memory_region::memory_region_type type) { - log(rust_log::MEM, "rust_dom::free(0x%" PRIxPTR ")", mem); + DLOG(this, rust_log::MEM, "rust_dom::free(0x%" PRIxPTR ")", mem); if (type == memory_region::LOCAL) { local_region.free(mem); } else if (type == memory_region::SYNCHRONIZED) { @@ -177,7 +172,8 @@ rust_dom::win32_require(LPCTSTR fn, BOOL ok) { NULL, err, MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT), (LPTSTR) &buf, 0, NULL ); - log(rust_log::ERR, "%s failed with error %ld: %s", fn, err, buf); + DLOG(this, rust_log::ERR, "%s failed with error %ld: %s", + fn, err, buf); LocalFree((HLOCAL)buf); I(this, ok); } @@ -199,7 +195,7 @@ rust_dom::reap_dead_tasks() { if (task->ref_count == 0) { I(this, task->tasks_waiting_to_join.is_empty()); dead_tasks.remove(task); - log(rust_log::TASK, + DLOG(this, rust_log::TASK, "deleting unreferenced dead task %s @0x%" PRIxPTR, task->name, task); delete task; @@ -215,7 +211,7 @@ rust_dom::reap_dead_tasks() { void rust_dom::drain_incoming_message_queue(bool process) { rust_message *message; while (message_queue->dequeue(&message)) { - log(rust_log::COMM, "<== receiving \"%s\" " PTR, + DLOG(this, rust_log::COMM, "<== receiving \"%s\" " PTR, message->label, message); if (process) { message->process(); @@ -292,8 +288,8 @@ rust_dom::start_main_loop() { // Make sure someone is watching, to pull us out of infinite loops. rust_timer timer(this); - log(rust_log::DOM, "started domain loop"); - log(rust_log::DOM | rust_log::MEM, + DLOG(this, rust_log::DOM, "started domain loop"); + DLOG(this, rust_log::DOM | rust_log::MEM, "activate glue: " PTR ", exit glue: " PTR, root_crate->get_activate_glue(), root_crate->get_exit_task_glue()); @@ -312,17 +308,17 @@ rust_dom::start_main_loop() { if (_log.is_tracing(rust_log::TASK)) { log_state(); } - log(rust_log::TASK, + DLOG(this, rust_log::TASK, "all tasks are blocked, scheduler yielding ..."); sync::sleep(100); - log(rust_log::TASK, + DLOG(this, rust_log::TASK, "scheduler resuming ..."); continue; } I(this, scheduled_task->running()); - log(rust_log::TASK, + DLOG(this, rust_log::TASK, "activating task %s 0x%" PRIxPTR ", sp=0x%" PRIxPTR ", ref_count=%d" @@ -337,7 +333,7 @@ rust_dom::start_main_loop() { activate(scheduled_task); - log(rust_log::TASK, + DLOG(this, rust_log::TASK, "returned from task %s @0x%" PRIxPTR " in state '%s', sp=0x%" PRIxPTR, scheduled_task->name, @@ -352,11 +348,12 @@ rust_dom::start_main_loop() { reap_dead_tasks(); } - log(rust_log::DOM, "terminated scheduler loop, reaping dead tasks ..."); + DLOG(this, rust_log::DOM, + "terminated scheduler loop, reaping dead tasks ..."); while (dead_tasks.length() > 0) { if (message_queue->is_empty()) { - log(rust_log::DOM, + DLOG(this, rust_log::DOM, "waiting for %d dead tasks to become dereferenced, " "scheduler yielding ...", dead_tasks.length()); @@ -370,14 +367,14 @@ rust_dom::start_main_loop() { reap_dead_tasks(); } - log(rust_log::DOM, "finished main-loop (dom.rval = %d)", rval); + DLOG(this, rust_log::DOM, "finished main-loop (dom.rval = %d)", rval); return rval; } rust_crate_cache * rust_dom::get_cache(rust_crate const *crate) { - log(rust_log::CACHE, + DLOG(this, rust_log::CACHE, "looking for crate-cache for crate 0x%" PRIxPTR, crate); rust_crate_cache *cache = NULL; for (size_t i = 0; i < caches.length(); ++i) { @@ -388,7 +385,7 @@ rust_dom::get_cache(rust_crate const *crate) { } } if (!cache) { - log(rust_log::CACHE, + DLOG(this, rust_log::CACHE, "making new crate-cache for crate 0x%" PRIxPTR, crate); cache = new (this) rust_crate_cache(this, crate); caches.push(cache); @@ -401,7 +398,7 @@ rust_task * rust_dom::create_task(rust_task *spawner, const char *name) { rust_task *task = new (this) rust_task (this, &newborn_tasks, spawner, name); - log(rust_log::TASK, "created task: " PTR ", spawner: %s, name: %s", + DLOG(this, rust_log::TASK, "created task: " PTR ", spawner: %s, name: %s", task, spawner ? spawner->name : "null", name); newborn_tasks.append(task); return task; diff --git a/src/rt/rust_dom.h b/src/rt/rust_dom.h index 8aa2419274798..be3ca2f9f18b0 100644 --- a/src/rt/rust_dom.h +++ b/src/rt/rust_dom.h @@ -88,6 +88,11 @@ struct rust_dom : public kernel_owned, rc_base rust_task *create_task(rust_task *spawner, const char *name); }; +inline rust_log & +rust_dom::get_log() { + return _log; +} + // // Local Variables: // mode: C++ diff --git a/src/rt/rust_kernel.cpp b/src/rt/rust_kernel.cpp index df6b655a45bcd..9b8347bc1f8a9 100644 --- a/src/rt/rust_kernel.cpp +++ b/src/rt/rust_kernel.cpp @@ -1,5 +1,10 @@ #include "rust_internal.h" +#define KLOG(...) \ + if (_log.is_tracing(rust_log::KERN)) { \ + log(rust_log::KERN, __VA_ARGS__); \ + } else + rust_kernel::rust_kernel(rust_srv *srv) : _region(&srv->local_region), _log(srv, NULL), @@ -20,9 +25,8 @@ rust_kernel::create_domain(const rust_crate *crate, const char *name) { message_queue->associate(handle); domains.append(dom); message_queues.append(message_queue); - log(rust_log::KERN | rust_log::TASK, - "created domain: " PTR ", name: %s, index: %d, domains %d", - dom, name, dom->list_index, domains.length()); + KLOG("created domain: " PTR ", name: %s, index: %d, domains %d", + dom, name, dom->list_index, domains.length()); _kernel_lock.signal_all(); _kernel_lock.unlock(); return handle; @@ -31,8 +35,7 @@ rust_kernel::create_domain(const rust_crate *crate, const char *name) { void rust_kernel::destroy_domain(rust_dom *dom) { _kernel_lock.lock(); - log(rust_log::KERN, - "deleting domain: " PTR ", name: %s, index: %d, domains %d", + KLOG("deleting domain: " PTR ", name: %s, index: %d, domains %d", dom, dom->name, dom->list_index, domains.length()); domains.remove(dom); dom->message_queue->disassociate(); @@ -98,12 +101,12 @@ rust_kernel::join_all_domains() { _kernel_lock.wait(); } _kernel_lock.unlock(); - log(rust_log::KERN, "joined domains"); + KLOG("joined domains"); } void rust_kernel::log_all_domain_state() { - log(rust_log::KERN, "log_all_domain_state: %d domains", domains.length()); + KLOG("log_all_domain_state: %d domains", domains.length()); for (uint32_t i = 0; i < domains.length(); i++) { domains[i]->log_state(); } @@ -155,14 +158,14 @@ rust_kernel::start_kernel_loop() { void rust_kernel::run() { - log(rust_log::KERN, "started kernel loop"); + KLOG("started kernel loop"); start_kernel_loop(); - log(rust_log::KERN, "finished kernel loop"); + KLOG("finished kernel loop"); } void rust_kernel::terminate_kernel_loop() { - log(rust_log::KERN, "terminating kernel loop"); + KLOG("terminating kernel loop"); _interrupt_kernel_loop = true; signal_kernel_lock(); join(); @@ -181,13 +184,13 @@ rust_kernel::~rust_kernel() { // messages. pump_message_queues(); - log(rust_log::KERN, "freeing handles"); + KLOG("freeing handles"); free_handles(_task_handles); free_handles(_port_handles); free_handles(_dom_handles); - log(rust_log::KERN, "freeing queues"); + KLOG("freeing queues"); rust_message_queue *queue = NULL; while (message_queues.pop(&queue)) { diff --git a/src/rt/rust_log.cpp b/src/rt/rust_log.cpp index bcd40c364b51b..3017b549263b2 100644 --- a/src/rt/rust_log.cpp +++ b/src/rt/rust_log.cpp @@ -204,11 +204,6 @@ rust_log::trace_ln(rust_task *task, ansi_color color, } } -bool -rust_log::is_tracing(uint32_t type_bits) { - return type_bits & _type_bit_mask; -} - void rust_log::indent() { _indent++; diff --git a/src/rt/rust_log.h b/src/rt/rust_log.h index 59aa504f6945b..8d3d4bcb9cadf 100644 --- a/src/rt/rust_log.h +++ b/src/rt/rust_log.h @@ -1,6 +1,21 @@ #ifndef RUST_LOG_H #define RUST_LOG_H +#define DLOG(dom, mask, ...) \ + if ((dom)->get_log().is_tracing(mask)) { \ + (dom)->log(mask, __VA_ARGS__); \ + } else +#define LOG(task, mask, ...) \ + DLOG((task)->dom, mask, __VA_ARGS__) +#define LOG_I(task, mask, ...) \ + if ((task)->dom->get_log().is_tracing(mask)) { \ + (task)->dom->get_log().reset_indent(0); \ + (task)->dom->log(mask, __VA_ARGS__); \ + (task)->dom->get_log().indent(); \ + } else +#define LOGPTR(dom, msg, ptrval) \ + DLOG(dom, rust_log::MEM, "%s 0x%" PRIxPTR, msg, ptrval) + class rust_dom; class rust_task; @@ -65,4 +80,9 @@ class rust_log { void trace_ln(rust_task *task, char *message); }; +inline bool +rust_log::is_tracing(uint32_t type_bits) { + return type_bits & _type_bit_mask; +} + #endif /* RUST_LOG_H */ diff --git a/src/rt/rust_port.cpp b/src/rt/rust_port.cpp index 82054687f2f6d..178b46a702bad 100644 --- a/src/rt/rust_port.cpp +++ b/src/rt/rust_port.cpp @@ -5,7 +5,7 @@ rust_port::rust_port(rust_task *task, size_t unit_sz) : maybe_proxy(this), task(task), unit_sz(unit_sz), writers(task->dom), chans(task->dom) { - task->log(rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::MEM | rust_log::COMM, "new rust_port(task=0x%" PRIxPTR ", unit_sz=%d) -> port=0x%" PRIxPTR, (uintptr_t)task, unit_sz, (uintptr_t)this); @@ -14,10 +14,10 @@ rust_port::rust_port(rust_task *task, size_t unit_sz) : } rust_port::~rust_port() { - task->log(rust_log::COMM | rust_log::MEM, + LOG(task, rust_log::COMM | rust_log::MEM, "~rust_port 0x%" PRIxPTR, (uintptr_t) this); - log_state(); + // log_state(); // Disassociate channels from this port. while (chans.is_empty() == false) { @@ -25,7 +25,7 @@ rust_port::~rust_port() { chan->disassociate(); if (chan->ref_count == 0) { - task->log(rust_log::COMM, + LOG(task, rust_log::COMM, "chan: 0x%" PRIxPTR " is dormant, freeing", chan); delete chan; } @@ -39,7 +39,7 @@ bool rust_port::receive(void *dptr) { rust_chan *chan = chans[i]; if (chan->buffer.is_empty() == false) { chan->buffer.dequeue(dptr); - task->log(rust_log::COMM, "<=== read data ==="); + LOG(task, rust_log::COMM, "<=== read data ==="); return true; } } @@ -47,12 +47,12 @@ bool rust_port::receive(void *dptr) { } void rust_port::log_state() { - task->log(rust_log::COMM, + LOG(task, rust_log::COMM, "rust_port: 0x%" PRIxPTR ", associated channel(s): %d", this, chans.length()); for (uint32_t i = 0; i < chans.length(); i++) { rust_chan *chan = chans[i]; - task->log(rust_log::COMM, + LOG(task, rust_log::COMM, "\tchan: 0x%" PRIxPTR ", size: %d, remote: %s", chan, chan->buffer.size(), diff --git a/src/rt/rust_task.cpp b/src/rt/rust_task.cpp index df7dd2a35311d..4f7bbda61c66a 100644 --- a/src/rt/rust_task.cpp +++ b/src/rt/rust_task.cpp @@ -24,10 +24,10 @@ new_stk(rust_dom *dom, size_t minsz) minsz = min_stk_bytes; size_t sz = sizeof(stk_seg) + minsz; stk_seg *stk = (stk_seg *)dom->malloc(sz); - dom->logptr("new stk", (uintptr_t)stk); + LOGPTR(dom, "new stk", (uintptr_t)stk); memset(stk, 0, sizeof(stk_seg)); stk->limit = (uintptr_t) &stk->data[minsz]; - dom->logptr("stk limit", stk->limit); + LOGPTR(dom, "stk limit", stk->limit); stk->valgrind_id = VALGRIND_STACK_REGISTER(&stk->data[0], &stk->data[minsz]); @@ -38,7 +38,7 @@ static void del_stk(rust_dom *dom, stk_seg *stk) { VALGRIND_STACK_DEREGISTER(stk->valgrind_id); - dom->logptr("freeing stk segment", (uintptr_t)stk); + LOGPTR(dom, "freeing stk segment", (uintptr_t)stk); dom->free(stk); } @@ -93,7 +93,7 @@ rust_task::rust_task(rust_dom *dom, rust_task_list *state, alarm(this), handle(NULL) { - dom->logptr("new task", (uintptr_t)this); + LOGPTR(dom, "new task", (uintptr_t)this); if (spawner == NULL) { ref_count = 0; @@ -102,24 +102,24 @@ rust_task::rust_task(rust_dom *dom, rust_task_list *state, rust_task::~rust_task() { - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "~rust_task %s @0x%" PRIxPTR ", refcnt=%d", name, (uintptr_t)this, ref_count); /* for (uintptr_t fp = get_fp(); fp; fp = get_previous_fp(fp)) { frame_glue_fns *glue_fns = get_frame_glue_fns(fp); - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "~rust_task, frame fp=0x%" PRIxPTR ", glue_fns=0x%" PRIxPTR, fp, glue_fns); if (glue_fns) { - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "~rust_task, mark_glue=0x%" PRIxPTR, glue_fns->mark_glue); - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "~rust_task, drop_glue=0x%" PRIxPTR, glue_fns->drop_glue); - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "~rust_task, reloc_glue=0x%" PRIxPTR, glue_fns->reloc_glue); } @@ -143,8 +143,8 @@ rust_task::start(uintptr_t exit_task_glue, uintptr_t args, size_t callsz) { - dom->logptr("exit-task glue", exit_task_glue); - dom->logptr("from spawnee", spawnee_fn); + LOGPTR(dom, "exit-task glue", exit_task_glue); + LOGPTR(dom, "from spawnee", spawnee_fn); // Set sp to last uintptr_t-sized cell of segment rust_sp -= sizeof(uintptr_t); @@ -266,7 +266,7 @@ rust_task::grow(size_t n_frame_bytes) uintptr_t old_bottom = (uintptr_t) &old_stk->data[0]; uintptr_t rust_sp_disp = old_top - this->rust_sp; size_t ssz = old_top - old_bottom; - dom->log(rust_log::MEM|rust_log::TASK|rust_log::UPCALL, + DLOG(dom, rust_log::MEM|rust_log::TASK|rust_log::UPCALL, "upcall_grow_task(%" PRIdPTR "), old size %" PRIdPTR " bytes (old lim: 0x%" PRIxPTR ")", @@ -276,13 +276,13 @@ rust_task::grow(size_t n_frame_bytes) ssz = n_frame_bytes; ssz = next_power_of_two(ssz); - dom->log(rust_log::MEM|rust_log::TASK, "upcall_grow_task growing stk 0x%" + DLOG(dom, rust_log::MEM|rust_log::TASK, "upcall_grow_task growing stk 0x%" PRIxPTR " to %d bytes", old_stk, ssz); stk_seg *nstk = new_stk(dom, ssz); uintptr_t new_top = (uintptr_t) &nstk->data[ssz]; size_t n_copy = old_top - old_bottom; - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "copying %d bytes of stack from [0x%" PRIxPTR ", 0x%" PRIxPTR "]" " to [0x%" PRIxPTR ", 0x%" PRIxPTR "]", n_copy, @@ -296,7 +296,7 @@ rust_task::grow(size_t n_frame_bytes) this->stk = nstk; this->rust_sp = new_top - rust_sp_disp; - dom->log(rust_log::MEM|rust_log::TASK, "processing relocations"); + DLOG(dom, rust_log::MEM|rust_log::TASK, "processing relocations"); // FIXME (issue #32): this is the most ridiculously crude // relocation scheme ever. Try actually, you know, writing out @@ -305,16 +305,16 @@ rust_task::grow(size_t n_frame_bytes) for (uintptr_t* p = (uintptr_t*)(new_top - n_copy); p < (uintptr_t*)new_top; ++p) { if (old_bottom <= *p && *p < old_top) { - //dom->log(rust_log::MEM, "relocating pointer 0x%" PRIxPTR + //DLOG(dom, rust_log::MEM, "relocating pointer 0x%" PRIxPTR // " by %d bytes", *p, (new_top - old_top)); n_relocs++; *p += (new_top - old_top); } } - dom->log(rust_log::MEM|rust_log::TASK, + DLOG(dom, rust_log::MEM|rust_log::TASK, "processed %d relocations", n_relocs); del_stk(dom, old_stk); - dom->logptr("grown stk limit", new_top); + LOGPTR(dom, "grown stk limit", new_top); #endif } @@ -342,7 +342,7 @@ rust_task::run_after_return(size_t nargs, uintptr_t glue) sp = align_down(sp - nargs * sizeof(uintptr_t)); uintptr_t *retpc = ((uintptr_t *) sp) - 1; - dom->log(rust_log::TASK|rust_log::MEM, + DLOG(dom, rust_log::TASK|rust_log::MEM, "run_after_return: overwriting retpc=0x%" PRIxPTR " @ runtime_sp=0x%" PRIxPTR " with glue=0x%" PRIxPTR, @@ -363,7 +363,7 @@ rust_task::run_on_resume(uintptr_t glue) // Inject glue as resume address in the suspended frame. uintptr_t* rsp = (uintptr_t*) rust_sp; rsp += n_callee_saves; - dom->log(rust_log::TASK|rust_log::MEM, + DLOG(dom, rust_log::TASK|rust_log::MEM, "run_on_resume: overwriting retpc=0x%" PRIxPTR " @ rust_sp=0x%" PRIxPTR " with glue=0x%" PRIxPTR, @@ -415,7 +415,7 @@ rust_task::kill() { void rust_task::fail(size_t nargs) { // See note in ::kill() regarding who should call this. - dom->log(rust_log::TASK, "task %s @0x%" PRIxPTR " failing", name, this); + DLOG(dom, rust_log::TASK, "task %s @0x%" PRIxPTR " failing", name, this); backtrace(); // Unblock the task so it can unwind. unblock(); @@ -423,7 +423,7 @@ rust_task::fail(size_t nargs) { dom->fail(); run_after_return(nargs, dom->root_crate->get_unwind_glue()); if (supervisor) { - dom->log(rust_log::TASK, + DLOG(dom, rust_log::TASK, "task %s @0x%" PRIxPTR " propagating failure to supervisor %s @0x%" PRIxPTR, name, this, supervisor->name, supervisor); @@ -434,7 +434,7 @@ rust_task::fail(size_t nargs) { void rust_task::gc(size_t nargs) { - dom->log(rust_log::TASK|rust_log::MEM, + DLOG(dom, rust_log::TASK|rust_log::MEM, "task %s @0x%" PRIxPTR " garbage collecting", name, this); run_after_return(nargs, dom->root_crate->get_gc_glue()); } @@ -442,7 +442,7 @@ rust_task::gc(size_t nargs) void rust_task::unsupervise() { - dom->log(rust_log::TASK, + DLOG(dom, rust_log::TASK, "task %s @0x%" PRIxPTR " disconnecting from supervisor %s @0x%" PRIxPTR, name, this, supervisor->name, supervisor); @@ -551,7 +551,7 @@ rust_task::malloc(size_t sz, type_desc *td) return mem; if (td) { gc_alloc *gcm = (gc_alloc*) mem; - dom->log(rust_log::TASK|rust_log::MEM|rust_log::GC, + DLOG(dom, rust_log::TASK|rust_log::MEM|rust_log::GC, "task %s @0x%" PRIxPTR " allocated %d GC bytes = 0x%" PRIxPTR, name, (uintptr_t)this, sz, gcm); @@ -575,7 +575,7 @@ rust_task::realloc(void *data, size_t sz, bool is_gc) unlink_gc(gcm); sz += sizeof(gc_alloc); gcm = (gc_alloc*) dom->realloc((void*)gcm, sz); - dom->log(rust_log::TASK|rust_log::MEM|rust_log::GC, + DLOG(dom, rust_log::TASK|rust_log::MEM|rust_log::GC, "task %s @0x%" PRIxPTR " reallocated %d GC bytes = 0x%" PRIxPTR, name, (uintptr_t)this, sz, gcm); @@ -598,7 +598,7 @@ rust_task::free(void *p, bool is_gc) if (is_gc) { gc_alloc *gcm = (gc_alloc*)(((char *)p) - sizeof(gc_alloc)); unlink_gc(gcm); - dom->log(rust_log::TASK|rust_log::MEM|rust_log::GC, + DLOG(dom, rust_log::TASK|rust_log::MEM|rust_log::GC, "task %s @0x%" PRIxPTR " freeing GC memory = 0x%" PRIxPTR, name, (uintptr_t)this, gcm); dom->free(gcm); @@ -610,7 +610,7 @@ rust_task::free(void *p, bool is_gc) void rust_task::transition(rust_task_list *src, rust_task_list *dst) { I(dom, state == src); - dom->log(rust_log::TASK, + DLOG(dom, rust_log::TASK, "task %s " PTR " state change '%s' -> '%s'", name, (uintptr_t)this, src->name, dst->name); src->remove(this); @@ -658,14 +658,14 @@ rust_crate_cache * rust_task::get_crate_cache(rust_crate const *curr_crate) { if (cache && cache->crate != curr_crate) { - dom->log(rust_log::TASK, "switching task crate-cache to crate 0x%" + DLOG(dom, rust_log::TASK, "switching task crate-cache to crate 0x%" PRIxPTR, curr_crate); cache->deref(); cache = NULL; } if (!cache) { - dom->log(rust_log::TASK, "fetching cache for current crate"); + DLOG(dom, rust_log::TASK, "fetching cache for current crate"); cache = dom->get_cache(curr_crate); } return cache; diff --git a/src/rt/rust_task_list.cpp b/src/rt/rust_task_list.cpp index 635ee13667d82..dd6aaeb59af5b 100644 --- a/src/rt/rust_task_list.cpp +++ b/src/rt/rust_task_list.cpp @@ -7,10 +7,10 @@ rust_task_list::rust_task_list (rust_dom *dom, const char* name) : void rust_task_list::delete_all() { - dom->log(rust_log::TASK, "deleting all %s tasks", name); + DLOG(dom, rust_log::TASK, "deleting all %s tasks", name); while (is_empty() == false) { rust_task *task = pop_value(); - dom->log(rust_log::TASK, "deleting task " PTR, task); + DLOG(dom, rust_log::TASK, "deleting task " PTR, task); delete task; } } diff --git a/src/rt/rust_timer.cpp b/src/rt/rust_timer.cpp index e4fbd6a94f898..40044e03678a5 100644 --- a/src/rt/rust_timer.cpp +++ b/src/rt/rust_timer.cpp @@ -30,7 +30,7 @@ timer_loop(void *ptr) { // We were handed the rust_timer that owns us. rust_timer *timer = (rust_timer *)ptr; rust_dom *dom = timer->dom; - dom->log(rust_log::TIMER, "in timer 0x%" PRIxPTR, (uintptr_t)timer); + DLOG(dom, rust_log::TIMER, "in timer 0x%" PRIxPTR, (uintptr_t)timer); size_t ms = TIME_SLICE_IN_MS; while (!timer->exit_flag) { @@ -39,7 +39,7 @@ timer_loop(void *ptr) { #else usleep(ms * 1000); #endif - dom->log(rust_log::TIMER, "timer 0x%" PRIxPTR + DLOG(dom, rust_log::TIMER, "timer 0x%" PRIxPTR " interrupting domain 0x%" PRIxPTR, (uintptr_t) timer, (uintptr_t) dom); dom->interrupt_flag = 1; @@ -54,7 +54,7 @@ timer_loop(void *ptr) { rust_timer::rust_timer(rust_dom *dom) : dom(dom), exit_flag(0) { - dom->log(rust_log::TIMER, "creating timer for domain 0x%" PRIxPTR, dom); + DLOG(dom, rust_log::TIMER, "creating timer for domain 0x%" PRIxPTR, dom); #if defined(__WIN32__) thread = CreateThread(NULL, 0, timer_loop, this, 0, NULL); dom->win32_require("CreateThread", thread != NULL); diff --git a/src/rt/rust_upcall.cpp b/src/rt/rust_upcall.cpp index f5fa00f98bbb0..6318b6e249de9 100644 --- a/src/rt/rust_upcall.cpp +++ b/src/rt/rust_upcall.cpp @@ -4,23 +4,19 @@ #ifdef __GNUC__ #define LOG_UPCALL_ENTRY(task) \ - (task)->dom->get_log().reset_indent(0); \ - (task)->log(rust_log::UPCALL, \ - "> UPCALL %s - task: %s 0x%" PRIxPTR \ - " retpc: x%" PRIxPTR \ - " ref_count: %d", \ - __FUNCTION__, \ - (task)->name, (task), \ - __builtin_return_address(0), \ - (task->ref_count)); \ - (task)->dom->get_log().indent(); + LOG_I(task, rust_log::UPCALL, \ + "> UPCALL %s - task: %s 0x%" PRIxPTR \ + " retpc: x%" PRIxPTR \ + " ref_count: %d", \ + __FUNCTION__, \ + (task)->name, (task), \ + __builtin_return_address(0), \ + (task->ref_count)); #else #define LOG_UPCALL_ENTRY(task) \ - (task)->dom->get_log().reset_indent(0); \ - (task)->log(rust_log::UPCALL, \ - "> UPCALL task: %s @x%" PRIxPTR, \ - (task)->name, (task)); \ - (task)->dom->get_log().indent(); + LOG_I(task, rust_log::UPCALL, \ + "> UPCALL task: %s @x%" PRIxPTR, \ + (task)->name, (task)); #endif extern "C" CDECL char const * @@ -35,21 +31,21 @@ upcall_grow_task(rust_task *task, size_t n_frame_bytes) { extern "C" CDECL void upcall_log_int(rust_task *task, int32_t i) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::ULOG, - "rust: %" PRId32 " (0x%" PRIx32 ")", i, i); + LOG(task, rust_log::UPCALL | rust_log::ULOG, + "rust: %" PRId32 " (0x%" PRIx32 ")", i, i); } extern "C" CDECL void upcall_log_float(rust_task *task, float f) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::ULOG, - "rust: %12.12f", f); + LOG(task, rust_log::UPCALL | rust_log::ULOG, + "rust: %12.12f", f); } extern "C" CDECL void upcall_log_double(rust_task *task, double *f) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::ULOG, + LOG(task, rust_log::UPCALL | rust_log::ULOG, "rust: %12.12f", *f); } @@ -57,27 +53,27 @@ extern "C" CDECL void upcall_log_str(rust_task *task, rust_str *str) { LOG_UPCALL_ENTRY(task); const char *c = str_buf(task, str); - task->log(rust_log::UPCALL | rust_log::ULOG, "rust: %s", c); + LOG(task, rust_log::UPCALL | rust_log::ULOG, "rust: %s", c); } extern "C" CDECL void upcall_trace_word(rust_task *task, uintptr_t i) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::TRACE, "trace: 0x%" PRIxPTR "", i, + LOG(task, rust_log::UPCALL | rust_log::TRACE, "trace: 0x%" PRIxPTR "", i, i, (char) i); } extern "C" CDECL void upcall_trace_str(rust_task *task, char const *c) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::TRACE, "trace: %s", c); + LOG(task, rust_log::UPCALL | rust_log::TRACE, "trace: %s", c); } extern "C" CDECL rust_port* upcall_new_port(rust_task *task, size_t unit_sz) { LOG_UPCALL_ENTRY(task); rust_dom *dom = task->dom; - task->log(rust_log::UPCALL | rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::UPCALL | rust_log::MEM | rust_log::COMM, "upcall_new_port(task=0x%" PRIxPTR " (%s), unit_sz=%d)", (uintptr_t) task, task->name, unit_sz); return new (dom) rust_port(task, unit_sz); @@ -86,7 +82,7 @@ upcall_new_port(rust_task *task, size_t unit_sz) { extern "C" CDECL void upcall_del_port(rust_task *task, rust_port *port) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::UPCALL | rust_log::MEM | rust_log::COMM, "upcall del_port(0x%" PRIxPTR ")", (uintptr_t) port); I(task->dom, !port->ref_count); delete port; @@ -99,7 +95,7 @@ extern "C" CDECL rust_chan* upcall_new_chan(rust_task *task, rust_port *port) { LOG_UPCALL_ENTRY(task); rust_dom *dom = task->dom; - task->log(rust_log::UPCALL | rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::UPCALL | rust_log::MEM | rust_log::COMM, "upcall_new_chan(" "task=0x%" PRIxPTR " (%s), port=0x%" PRIxPTR ")", (uintptr_t) task, task->name, port); @@ -128,7 +124,7 @@ extern "C" CDECL void upcall_del_chan(rust_task *task, rust_chan *chan) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::MEM | rust_log::COMM, + LOG(task, rust_log::UPCALL | rust_log::MEM | rust_log::COMM, "upcall del_chan(0x%" PRIxPTR ")", (uintptr_t) chan); A(task->dom, chan->ref_count == 0, @@ -179,7 +175,7 @@ upcall_clone_chan(rust_task *task, maybe_proxy *target, rust_handle *handle = task->dom->kernel->get_port_handle(port->as_referent()); maybe_proxy *proxy = new rust_proxy (handle); - task->log(rust_log::MEM, "new proxy: " PTR, proxy); + LOG(task, rust_log::MEM, "new proxy: " PTR, proxy); port = proxy; target_task = target->as_proxy()->handle()->referent(); } @@ -189,16 +185,16 @@ upcall_clone_chan(rust_task *task, maybe_proxy *target, extern "C" CDECL void upcall_yield(rust_task *task) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::COMM, "upcall yield()"); + LOG(task, rust_log::UPCALL | rust_log::COMM, "upcall yield()"); task->yield(1); } extern "C" CDECL void upcall_sleep(rust_task *task, size_t time_in_us) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::TASK, "elapsed %d", + LOG(task, rust_log::UPCALL | rust_log::TASK, "elapsed %d", task->yield_timer.get_elapsed_time()); - task->log(rust_log::UPCALL | rust_log::TASK, "sleep %d us", time_in_us); + LOG(task, rust_log::UPCALL | rust_log::TASK, "sleep %d us", time_in_us); task->yield(2, time_in_us); } @@ -232,13 +228,13 @@ extern "C" CDECL void upcall_send(rust_task *task, rust_chan *chan, void *sptr) { LOG_UPCALL_ENTRY(task); chan->send(sptr); - task->log(rust_log::COMM, "=== sent data ===>"); + LOG(task, rust_log::COMM, "=== sent data ===>"); } extern "C" CDECL void upcall_recv(rust_task *task, uintptr_t *dptr, rust_port *port) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::COMM, + LOG(task, rust_log::UPCALL | rust_log::COMM, "port: 0x%" PRIxPTR ", dptr: 0x%" PRIxPTR ", size: 0x%" PRIxPTR ", chan_no: %d", (uintptr_t) port, (uintptr_t) dptr, port->unit_sz, @@ -252,7 +248,7 @@ upcall_recv(rust_task *task, uintptr_t *dptr, rust_port *port) { // on the port. Remember the rendezvous location so that any sender // task can write to it before waking up this task. - task->log(rust_log::COMM, "<=== waiting for rendezvous data ==="); + LOG(task, rust_log::COMM, "<=== waiting for rendezvous data ==="); task->rendezvous_ptr = dptr; task->block(port, "waiting for rendezvous data"); task->yield(3); @@ -264,7 +260,7 @@ upcall_fail(rust_task *task, char const *file, size_t line) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::ERR, + LOG(task, rust_log::UPCALL | rust_log::ERR, "upcall fail '%s', %s:%" PRIdPTR, expr, file, line); task->fail(4); if (getenv("RUST_TRAP_FAILURE")) { @@ -296,7 +292,7 @@ upcall_kill(rust_task *task, maybe_proxy *target) { extern "C" CDECL void upcall_exit(rust_task *task) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::TASK, + LOG(task, rust_log::UPCALL | rust_log::TASK, "task ref_count: %d", task->ref_count); A(task->dom, task->ref_count >= 0, "Task ref_count should not be negative on exit!"); @@ -309,12 +305,12 @@ extern "C" CDECL uintptr_t upcall_malloc(rust_task *task, size_t nbytes, type_desc *td) { LOG_UPCALL_ENTRY(task); - task->dom->log(rust_log::UPCALL|rust_log::MEM, + LOG(task, rust_log::UPCALL|rust_log::MEM, "upcall malloc(%" PRIdPTR ", 0x%" PRIxPTR ")" " with gc-chain head = 0x%" PRIxPTR, nbytes, td, task->gc_alloc_chain); void *p = task->malloc(nbytes, td); - task->dom->log(rust_log::UPCALL|rust_log::MEM, + LOG(task, rust_log::UPCALL|rust_log::MEM, "upcall malloc(%" PRIdPTR ", 0x%" PRIxPTR ") = 0x%" PRIxPTR " with gc-chain head = 0x%" PRIxPTR, @@ -329,7 +325,7 @@ extern "C" CDECL void upcall_free(rust_task *task, void* ptr, uintptr_t is_gc) { LOG_UPCALL_ENTRY(task); rust_dom *dom = task->dom; - dom->log(rust_log::UPCALL|rust_log::MEM, + DLOG(dom, rust_log::UPCALL|rust_log::MEM, "upcall free(0x%" PRIxPTR ", is_gc=%" PRIdPTR ")", (uintptr_t)ptr, is_gc); task->free(ptr, (bool) is_gc); @@ -343,7 +339,7 @@ upcall_mark(rust_task *task, void* ptr) { if (ptr) { gc_alloc *gcm = (gc_alloc*) (((char*)ptr) - sizeof(gc_alloc)); uintptr_t marked = (uintptr_t) gcm->mark(); - dom->log(rust_log::UPCALL|rust_log::MEM|rust_log::GC, + DLOG(dom, rust_log::UPCALL|rust_log::MEM|rust_log::GC, "upcall mark(0x%" PRIxPTR ") = %" PRIdPTR, (uintptr_t)gcm, marked); return marked; @@ -362,7 +358,7 @@ upcall_new_str(rust_task *task, char const *s, size_t fill) { return NULL; } rust_str *st = new (mem) rust_str(dom, alloc, fill, (uint8_t const *) s); - task->log(rust_log::UPCALL | rust_log::MEM, + LOG(task, rust_log::UPCALL | rust_log::MEM, "upcall new_str('%s', %" PRIdPTR ") = 0x%" PRIxPTR, s, fill, st); return st; @@ -372,7 +368,7 @@ extern "C" CDECL rust_vec * upcall_new_vec(rust_task *task, size_t fill, type_desc *td) { LOG_UPCALL_ENTRY(task); rust_dom *dom = task->dom; - dom->log(rust_log::UPCALL|rust_log::MEM, + DLOG(dom, rust_log::UPCALL|rust_log::MEM, "upcall new_vec(%" PRIdPTR ")", fill); size_t alloc = next_power_of_two(sizeof(rust_vec) + fill); @@ -382,7 +378,7 @@ upcall_new_vec(rust_task *task, size_t fill, type_desc *td) { return NULL; } rust_vec *v = new (mem) rust_vec(dom, alloc, 0, NULL); - task->log(rust_log::UPCALL | rust_log::MEM, + LOG(task, rust_log::UPCALL | rust_log::MEM, "upcall new_vec(%" PRIdPTR ") = 0x%" PRIxPTR, fill, v); return v; } @@ -396,7 +392,7 @@ upcall_vec_grow(rust_task *task, { LOG_UPCALL_ENTRY(task); rust_dom *dom = task->dom; - task->log(rust_log::UPCALL | rust_log::MEM, + LOG(task, rust_log::UPCALL | rust_log::MEM, "upcall vec_grow(0x%" PRIxPTR ", %" PRIdPTR "), alloc=%" PRIdPTR ", fill=%" PRIdPTR ", need_copy=0x%" PRIxPTR, @@ -409,12 +405,12 @@ upcall_vec_grow(rust_task *task, // Fastest path: already large enough. if (v->alloc >= alloc) { - task->log(rust_log::UPCALL | rust_log::MEM, "no-growth path"); + LOG(task, rust_log::UPCALL | rust_log::MEM, "no-growth path"); return v; } // Second-fastest path: can at least realloc. - task->log(rust_log::UPCALL | rust_log::MEM, "realloc path"); + LOG(task, rust_log::UPCALL | rust_log::MEM, "realloc path"); v = (rust_vec*) task->realloc(v, alloc, td->is_stateful); if (!v) { task->fail(4); @@ -436,7 +432,7 @@ upcall_vec_grow(rust_task *task, * need_copy outparam flag to indicate to our caller (vec-copy glue) * that we need the copies performed for us. */ - task->log(rust_log::UPCALL | rust_log::MEM, "new vec path"); + LOG(task, rust_log::UPCALL | rust_log::MEM, "new vec path"); void *mem = task->malloc(alloc, td); if (!mem) { task->fail(4); @@ -476,23 +472,23 @@ upcall_require_rust_sym(rust_task *task, LOG_UPCALL_ENTRY(task); rust_dom *dom = task->dom; - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "upcall require rust sym: lib #%" PRIdPTR " = %s, c_sym #%" PRIdPTR ", rust_sym #%" PRIdPTR ", curr_crate = 0x%" PRIxPTR, lib_num, library, c_sym_num, rust_sym_num, curr_crate); for (char const **c = crate_rel(curr_crate, path); *c; ++c) { - task->log(rust_log::UPCALL, " + %s", crate_rel(curr_crate, *c)); + LOG(task, rust_log::UPCALL, " + %s", crate_rel(curr_crate, *c)); } - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "require C symbol 'rust_crate' from lib #%" PRIdPTR, lib_num); rust_crate_cache::c_sym *c = fetch_c_sym(task, curr_crate, lib_num, c_sym_num, library, "rust_crate"); - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "require rust symbol inside crate"); rust_crate_cache::rust_sym *s = task->cache->get_rust_sym(rust_sym_num, dom, @@ -501,10 +497,10 @@ upcall_require_rust_sym(rust_task *task, uintptr_t addr = s->get_val(); if (addr) { - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "found-or-cached addr: 0x%" PRIxPTR, addr); } else { - task->log(rust_log::UPCALL | rust_log::CACHE | rust_log::ERR, + LOG(task, rust_log::UPCALL | rust_log::CACHE | rust_log::ERR, "failed to resolve symbol"); task->fail(7); } @@ -520,7 +516,7 @@ upcall_require_c_sym(rust_task *task, char const *symbol) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "upcall require c sym: lib #%" PRIdPTR " = %s, c_sym #%" PRIdPTR " = %s" @@ -532,10 +528,10 @@ upcall_require_c_sym(rust_task *task, uintptr_t addr = c->get_val(); if (addr) { - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "found-or-cached addr: 0x%" PRIxPTR, addr); } else { - task->log(rust_log::UPCALL | rust_log::CACHE | rust_log::ERR, + LOG(task, rust_log::UPCALL | rust_log::CACHE | rust_log::ERR, "failed to resolve symbol %s in %s", symbol, library); task->fail(6); } @@ -550,13 +546,13 @@ upcall_get_type_desc(rust_task *task, size_t n_descs, type_desc const **descs) { LOG_UPCALL_ENTRY(task); - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "upcall get_type_desc with size=%" PRIdPTR ", align=%" PRIdPTR ", %" PRIdPTR " descs", size, align, n_descs); rust_crate_cache *cache = task->get_crate_cache(curr_crate); type_desc *td = cache->get_type_desc(size, align, n_descs, descs); - task->log(rust_log::UPCALL | rust_log::CACHE, + LOG(task, rust_log::UPCALL | rust_log::CACHE, "returning tydesc 0x%" PRIxPTR, td); return td; } @@ -579,7 +575,7 @@ upcall_start_task(rust_task *spawner, LOG_UPCALL_ENTRY(spawner); rust_dom *dom = spawner->dom; - dom->log(rust_log::UPCALL | rust_log::MEM | rust_log::TASK, + DLOG(dom, rust_log::UPCALL | rust_log::MEM | rust_log::TASK, "upcall start_task(task %s @0x%" PRIxPTR " exit_task_glue 0x%" PRIxPTR ", spawnee 0x%" PRIxPTR @@ -602,7 +598,7 @@ upcall_new_thread(rust_task *task, const char *name) { kernel->create_domain(parent_dom->root_crate, name); rust_handle *child_task_handle = kernel->get_task_handle(child_dom_handle->referent()->root_task); - task->log(rust_log::UPCALL | rust_log::MEM, + LOG(task, rust_log::UPCALL | rust_log::MEM, "child name: %s, child_dom_handle: " PTR ", child_task_handle: " PTR, name, child_dom_handle, child_task_handle); @@ -645,7 +641,7 @@ upcall_start_thread(rust_task *task, LOG_UPCALL_ENTRY(task); rust_dom *parenet_dom = task->dom; rust_handle *child_task_handle = child_task_proxy->handle(); - task->log(rust_log::UPCALL | rust_log::MEM | rust_log::TASK, + LOG(task, rust_log::UPCALL | rust_log::MEM | rust_log::TASK, "exit_task_glue: " PTR ", spawnee_fn " PTR ", callsz %" PRIdPTR ")", exit_task_glue, spawnee_fn, callsz); diff --git a/src/rt/rust_util.h b/src/rt/rust_util.h index 14a865bd3a474..b36b776372a57 100644 --- a/src/rt/rust_util.h +++ b/src/rt/rust_util.h @@ -24,7 +24,7 @@ ptr_vec::ptr_vec(rust_dom *dom) : data(new (dom) T*[alloc]) { I(dom, data); - dom->log(rust_log::MEM, + DLOG(dom, rust_log::MEM, "new ptr_vec(data=0x%" PRIxPTR ") -> 0x%" PRIxPTR, (uintptr_t)data, (uintptr_t)this); } @@ -33,7 +33,7 @@ template ptr_vec::~ptr_vec() { I(dom, data); - dom->log(rust_log::MEM, + DLOG(dom, rust_log::MEM, "~ptr_vec 0x%" PRIxPTR ", data=0x%" PRIxPTR, (uintptr_t)this, (uintptr_t)data); I(dom, fill == 0);