History

Enable logging from exec for specific components. Remove trailing newlines from all existing logging calls.

arr committed 9 years ago

Commit dd0789c1 parent 3098fb816 files · +185 −112Browse files

Showing the changes to src (16 of 16 files). Show all

Unified · Split

16 files
  1. src/exec/main.cpp +69 −8
  2. src/include/runtime.h +4 −1
  3. src/vm/array.cpp +10 −10
  4. src/vm/channel.cpp +9 −9
  5. src/vm/execution_table.cpp +7 −7
  6. src/vm/garbage_collector.cpp +7 −7
  7. src/vm/list.cpp +2 −2
  8. src/vm/module_ref.cpp +4 −4
  9. src/vm/scheduler.cpp +12 −12
  10. src/vm/stack.cpp +8 −8
  11. src/vm/string.cpp +3 −3
  12. src/vm/sys/Sysmod.cpp +6 −6
  13. src/vm/thread.cpp +5 −5
  14. src/vm/vm.cpp +2 −2
  15. src/vm/vm_exception_handler.cpp +3 −3
  16. src/vm/vm_memory.cpp +34 −25
src/exec/main.cpp+69−8
@@ -231,14 +231,54 @@ void print_banner(const exec_options &options) · 230 unmodified lines
231231 void print_help()
232232 {
233233 std::cout
234− << "Usage: disvm-exec [-d[e|m|x]*] [-t <num>] [-q] [-?] <entry module> <args>*\n"
235− << " d - Enable debugger\n"
236− << " e - Break on entry\n"
237− << " m - Break on module load\n"
238− << " x - Break on exception (first chance)\n"
239− << " q - Suppress banner and configuration\n"
240− << " t - Specify the number of system threads to use (0 < x <= 4)\n"
241− << " ? - Print help\n";
234+ << "Usage: disvm-exec [-d[e|m|x]*] [-l[s|g|t|T|e|m]*] [-t <num>] [-q] [-?] <entry module> <args>*\n"
235+ " d - Enable debugger\n"
236+ " e - Break on entry\n"
237+ " m - Break on module load\n"
238+ " x - Break on exception (first chance)\n"
239+ " l - Enable logging in a component\n"
240+ " s - Scheduler\n"
241+ " g - Garbage collector\n"
242+ " t - Tool extensions\n"
243+ " T - Threads\n"
244+ " e - Exceptions\n"
245+ " m - Memory allocations (noisy)\n"
246+ " q - Suppress banner and configuration\n"
247+ " t - Specify the number of system threads to use (0 < x <= 4)\n"
248+ " ? - Print help\n";
249+}
250+
251+void log_callback(const debug::component_trace_t origin, const debug::log_level_t level, const char *msg_fmt, std::va_list args)
252+{
253+ std::stringstream ss;
254+
255+ switch (level)
256+ {
257+ case debug::log_level_t::warning:
258+ ss << "w: ";
259+ break;
260+ case debug::log_level_t::debug:
261+ ss << "d: ";
262+ break;
263+ }
264+
265+ std::array<char, 1024> buffer;
266+ const auto r = std::vsnprintf(buffer.data(), buffer.size(), msg_fmt, args);
267+ buffer[r] = '\0';
268+
269+ ss << buffer.data() << "\n";
270+ if (r == buffer.size() - 1)
271+ ss << " <Possible truncation>\n";
272+
273+ std::cout << ss.str();
274+}
275+
276+void enable_logging(debug::component_trace_t c)
277+{
278+ debug::set_component_tracing(c, true);
279+
280+ // Constantly setting the callback
281+ debug::set_logging_callback(log_callback);
242282 }
243283
244284 void process_arg(char* arg, std::function<char *()> next, exec_options &options)
@@ -289,6 +329,27 @@ void process_arg(char* arg, std::function<char *()> next, exec_options &options) · 44 unmodified lines
289329 }
290330 break;
291331
332+ case 'l':
333+ for (auto i = std::size_t{ 2 }; i < arg_len; ++i)
334+ {
335+ switch (arg[i])
336+ {
337+ case 's': enable_logging(debug::component_trace_t::scheduler);
338+ break;
339+ case 'g': enable_logging(debug::component_trace_t::garbage_collector);
340+ break;
341+ case 't': enable_logging(debug::component_trace_t::tool);
342+ break;
343+ case 'T': enable_logging(debug::component_trace_t::thread);
344+ break;
345+ case 'e': enable_logging(debug::component_trace_t::exception);
346+ break;
347+ case 'm': enable_logging(debug::component_trace_t::memory);
348+ break;
349+ }
350+ }
351+ break;
352+
292353 case 'q':
293354 options.quiet_start = true;
294355 break;
src/include/runtime.h+4−1
@@ -65,7 +65,7 @@ namespace disvm · 64 unmodified lines
6565 vm_alloc_instance_finalizer_t finalizer = type_descriptor_t::no_finalizer);
6666
6767 public:
68− type_descriptor_t(word_t size_in_bytes, word_t map_in_bytes, const byte_t * pointer_map, vm_alloc_instance_finalizer_t finalizer);
68+ type_descriptor_t(word_t size_in_bytes, word_t map_in_bytes, const byte_t * pointer_map, vm_alloc_instance_finalizer_t finalizer, const char *debug_name);
6969 type_descriptor_t(const type_descriptor_t&) = delete;
7070 type_descriptor_t& operator=(const type_descriptor_t&) = delete;
7171
@@ -73,6 +73,9 @@ namespace disvm · 1 unmodified line
7373 const word_t map_in_bytes;
7474 const byte_t * const pointer_map;
7575 const vm_alloc_instance_finalizer_t finalizer;
76+#ifndef NDEBUG
77+ const char *debug_type_name;
78+#endif
7679 };
7780
7881 // Access to type descriptors for VM intrinsic types
src/vm/array.cpp+10−10
@@ -27,20 +27,20 @@ vm_array_t::vm_array_t(std::shared_ptr<const type_descriptor_t> td, word_t lengt · 26 unmodified lines
2727 assert(_element_type != nullptr);
2828 assert(_length >= 0);
2929 _arr = alloc_memory<byte_t>(_length * _element_type->size_in_bytes);
30− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm array: %d\n", _length);
30+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm array: %d", _length);
3131
3232 // Initialize the array
3333 auto arr_local = _arr;
3434 const auto array_len = _length;
3535 const auto &element_type = *_element_type;
36− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "begin: init: elements: %d\n", array_len);
36+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "begin: init: elements: %d", array_len);
3737 for (word_t i = 0; i < array_len; ++i)
3838 {
3939 init_memory(element_type, arr_local);
4040 arr_local += element_type.size_in_bytes;
4141 }
4242
43− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "end: init: elements: %d\n", array_len);
43+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "end: init: elements: %d", array_len);
4444 }
4545
4646 vm_array_t::vm_array_t(std::shared_ptr<const type_descriptor_t> td, word_t length, const zero_memory_t&)
@@ -53,7 +53,7 @@ vm_array_t::vm_array_t(std::shared_ptr<const type_descriptor_t> td, word_t lengt · 6 unmodified lines
5353 assert(_element_type != nullptr);
5454 assert(_length >= 0);
5555 _arr = calloc_memory<byte_t>(_length * _element_type->size_in_bytes);
56− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "initz: vm array: %d\n", _length);
56+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "initz: vm array: %d", _length);
5757 }
5858
5959 vm_array_t::vm_array_t(vm_array_t *original, word_t begin_index, word_t length)
@@ -68,7 +68,7 @@ vm_array_t::vm_array_t(vm_array_t *original, word_t begin_index, word_t length) · 8 unmodified lines
6868 assert(_length >= 0 && (_length + begin_index) <= _original->get_length());
6969
7070 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
71− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm array: slice: %d %d\n", begin_index, _length);
71+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm array: slice: %d %d", begin_index, _length);
7272
7373 // Set the data to reference the original array
7474 _arr = _original->_arr + (begin_index * _element_type->size_in_bytes);
@@ -104,7 +104,7 @@ vm_array_t::vm_array_t(const vm_string_t *s) · 29 unmodified lines
104104 }
105105
106106 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
107− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm array: vm string: %d\n", _length);
107+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm array: vm string: %d", _length);
108108 }
109109
110110 vm_array_t::~vm_array_t()
@@ -118,7 +118,7 @@ vm_array_t::~vm_array_t() · 7 unmodified lines
118118 dec_ref_count_and_free(_original);
119119 debug::assign_debug_pointer(&_original);
120120
121− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm array: slice\n");
121+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm array: slice");
122122 }
123123 else
124124 {
@@ -126,19 +126,19 @@ vm_array_t::~vm_array_t() · 1 unmodified line
126126 auto arr_local = _arr;
127127 const auto array_len = _length;
128128 const auto &element_type = *_element_type;
129− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "begin: destroy: elements: %d\n", array_len);
129+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "begin: destroy: elements: %d", array_len);
130130 for (word_t i = 0; i < array_len; ++i)
131131 {
132132 destroy_memory(element_type, arr_local);
133133 arr_local += element_type.size_in_bytes;
134134 }
135− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "end: destroy: elements: %d\n", array_len);
135+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "end: destroy: elements: %d", array_len);
136136
137137 // Free array memory
138138 free_memory(_arr);
139139
140140 debug::assign_debug_pointer(&_arr);
141− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm array\n");
141+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm array");
142142 }
143143
144144 }
src/vm/channel.cpp+9−9
@@ -44,13 +44,13 @@ vm_channel_t::vm_channel_t( · 43 unmodified lines
4444 if (buffer_len > 0)
4545 _data_buffer = new vm_array_t{ td, buffer_len };
4646
47− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm channel\n");
47+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm channel");
4848 }
4949
5050 vm_channel_t::~vm_channel_t()
5151 {
5252 dec_ref_count_and_free(_data_buffer);
53− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm channel\n");
53+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm channel");
5454 }
5555
5656 std::shared_ptr<const type_descriptor_t> vm_channel_t::get_data_type() const
@@ -88,7 +88,7 @@ bool vm_channel_t::send_data(vm_channel_request_t &send_request) · 31 unmodified lines
8888 }
8989
9090 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
91− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: send: queue: %d\n", send_request.thread_id);
91+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: send: queue: %d", send_request.thread_id);
9292
9393 _data_senders.emplace_back(std::move(send_request));
9494 return false;
@@ -122,7 +122,7 @@ bool vm_channel_t::send_data(vm_channel_request_t &send_request) · 27 unmodified lines
122122 data_lock.unlock();
123123
124124 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
125− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: send: %d %d\n", send_request.thread_id, receiver.thread_id);
125+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: send: %d %d", send_request.thread_id, receiver.thread_id);
126126
127127 receiver.request_handled_callback(*this);
128128
@@ -159,7 +159,7 @@ bool vm_channel_t::receive_data(vm_channel_request_t &receive_request) · 30 unmodified lines
159159 }
160160
161161 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
162− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: receive: queue: %d\n", receive_request.thread_id);
162+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: receive: queue: %d", receive_request.thread_id);
163163
164164 _data_receivers.emplace_back(std::move(receive_request));
165165 return false;
@@ -201,7 +201,7 @@ bool vm_channel_t::receive_data(vm_channel_request_t &receive_request) · 35 unmodified lines
201201 _data_transfer(receive_request.data, sender.data, _data_type.get());
202202
203203 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
204− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: receive: %d %d\n", receive_request.thread_id, sender.thread_id);
204+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: receive: %d %d", receive_request.thread_id, sender.thread_id);
205205 }
206206
207207 // Release channel and pending request lock after data transfer
@@ -235,7 +235,7 @@ void vm_channel_t::cancel_request(uint32_t thread_id) · 27 unmodified lines
235235 }
236236
237237 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
238− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: cancel: request: %d\n", thread_id);
238+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: cancel: request: %d", thread_id);
239239 }
240240
241241 word_t vm_channel_t::get_buffer_size() const
@@ -267,7 +267,7 @@ bool vm_channel_t::try_send_to_buffer(vm_channel_request_t &send_request) · 25 unmodified lines
267267 send_request.request_mutex.get().pending_request = false;
268268
269269 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
270− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: send: buffer: %d\n", send_request.thread_id);
270+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: send: buffer: %d", send_request.thread_id);
271271
272272 return true;
273273 }
@@ -294,7 +294,7 @@ bool vm_channel_t::try_receive_from_buffer(vm_channel_request_t &receive_request · 20 unmodified lines
294294 receive_request.request_mutex.get().pending_request = false;
295295
296296 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
297− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: receive: buffer: %d\n", receive_request.thread_id);
297+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "channel: receive: buffer: %d", receive_request.thread_id);
298298
299299 return true;
300300 }
src/vm/execution_table.cpp+7−7
@@ -1279,7 +1279,7 @@ namespace · 1278 unmodified lines
12791279 r.request_mutex.pending_request = false;
12801280
12811281 if (debug::is_component_tracing_enabled<debug::component_trace_t::channel>())
1282− debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "alt: request: non-blocking\n");
1282+ debug::log_msg(debug::component_trace_t::channel, debug::log_level_t::debug, "alt: request: non-blocking");
12831283
12841284 // Cancel request in all channels.
12851285 for (auto i = word_t{ 0 }; i < channel_count; ++i)
@@ -1471,7 +1471,7 @@ namespace · 185 unmodified lines
14711471 r.current_thread_state = vm_thread_state_t::empty_stack;
14721472
14731473 if (debug::is_component_tracing_enabled<debug::component_trace_t::stack>())
1474− debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "exit: function\n");
1474+ debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "exit: function");
14751475 }
14761476
14771477 EXEC_DECL(call)
@@ -1488,7 +1488,7 @@ namespace · 10 unmodified lines
14881488
14891489 r.pc = vt_ref<vm_pc_t>(r.dest);
14901490
1491− debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "enter: function\n");
1491+ debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "enter: function");
14921492 }
14931493
14941494 EXEC_DECL(mcall)
@@ -1522,7 +1522,7 @@ namespace · 27 unmodified lines
15221522 debug::log_msg(
15231523 debug::component_trace_t::stack,
15241524 debug::log_level_t::debug,
1525− "enter: function: inter-module: %d >>%s<< %d %s\n",
1525+ "enter: function: inter-module: %d >>%s<< %d %s",
15261526 export_id,
15271527 target_module->module->module_name->str(),
15281528 function_pc,
@@ -1649,7 +1649,7 @@ namespace · 120 unmodified lines
16491649 exception_id = static_cast<vm_string_t *>(e);
16501650
16511651 if (debug::is_component_tracing_enabled<debug::component_trace_t::exception>())
1652− debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "raise: string: >>%s<<\n", exception_id->str());
1652+ debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "raise: string: >>%s<<", exception_id->str());
16531653 }
16541654 else
16551655 {
@@ -1661,7 +1661,7 @@ namespace · 5 unmodified lines
16611661 exception_id = at_val<vm_string_t>(content);
16621662
16631663 if (debug::is_component_tracing_enabled<debug::component_trace_t::exception>())
1664− debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "raise: exception: >>%s<<\n", exception_id->str());
1664+ debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "raise: exception: >>%s<<", exception_id->str());
16651665 }
16661666
16671667 // Check if the tool dispatcher has been supplied
@@ -1772,7 +1772,7 @@ namespace · 104 unmodified lines
17721772 }
17731773 catch (const vm_module_exception &e)
17741774 {
1775− debug::log_msg(debug::component_trace_t::module, debug::log_level_t::debug, "exception: load: >>%s<<\n", e.what());
1775+ debug::log_msg(debug::component_trace_t::module, debug::log_level_t::debug, "exception: load: >>%s<<", e.what());
17761776 assert(false && "Failure reading module");
17771777 return;
17781778 }
src/vm/garbage_collector.cpp+7−7
@@ -93,7 +93,7 @@ void default_garbage_collector_t::track_allocation(vm_alloc_t *alloc) · 92 unmodified lines
9393 assert(alloc != nullptr);
9494
9595 if (debug::is_component_tracing_enabled<debug::component_trace_t::garbage_collector>())
96− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: track: %#" PRIxPTR "\n", alloc);
96+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: track: %#" PRIxPTR, alloc);
9797
9898 alloc->add_ref();
9999 set_gc_colour(alloc, get_current_colour(_collection_epoch));
@@ -152,13 +152,13 @@ namespace · 52 unmodified lines
152152 const auto log_enabled = debug::is_component_tracing_enabled<debug::component_trace_t::garbage_collector>();
153153 if (log_enabled)
154154 {
155− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: roots found: %" PRIuPTR "\n", allocs.size());
155+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: roots found: %" PRIuPTR, allocs.size());
156156
157157 // If logging is enabled update the callback with logging
158158 add_pointer_to_queue = std::function<void(pointer_t p, std::size_t)>{ [&allocs](pointer_t p, std::size_t) -> void
159159 {
160160 auto a = vm_alloc_t::from_allocation(p);
161− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, " ref: %#" PRIxPTR "\n", a);
161+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, " ref: %#" PRIxPTR, a);
162162 allocs.push(a);
163163 } };
164164 }
@@ -170,7 +170,7 @@ namespace · 5 unmodified lines
170170 allocs.pop();
171171
172172 if (log_enabled)
173− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: mark: alloc: %#" PRIxPTR "\n", curr);
173+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: mark: alloc: %#" PRIxPTR, curr);
174174
175175 if (curr->alloc_type->map_in_bytes > 0)
176176 enum_pointer_fields(*curr->alloc_type, curr->get_allocation(), add_pointer_to_queue);
@@ -198,7 +198,7 @@ namespace · 21 unmodified lines
198198 }
199199
200200 if (debug::is_component_tracing_enabled<debug::component_trace_t::garbage_collector>())
201− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: sweep: %u\n", freed);
201+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: sweep: %u", freed);
202202 }
203203 }
204204
@@ -213,7 +213,7 @@ bool default_garbage_collector_t::collect(std::vector<std::shared_ptr<const vm_t · 8 unmodified lines
213213
214214 const auto log_enabled = debug::is_component_tracing_enabled<debug::component_trace_t::garbage_collector>();
215215 if (log_enabled)
216− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: begin: collect\n");
216+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: begin: collect");
217217
218218 const auto curr_colour = get_current_colour(_collection_epoch);
219219 mark(threads, curr_colour);
@@ -222,7 +222,7 @@ bool default_garbage_collector_t::collect(std::vector<std::shared_ptr<const vm_t · 2 unmodified lines
222222 sweep(_tracking_allocs, sweeper_colour);
223223
224224 if (log_enabled)
225− debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: end: collect\n");
225+ debug::log_msg(debug::component_trace_t::garbage_collector, debug::log_level_t::debug, "gc: end: collect");
226226
227227 ++_collection_epoch;
228228 return true;
src/vm/list.cpp+2−2
@@ -39,7 +39,7 @@ vm_list_t::vm_list_t(std::shared_ptr<const type_descriptor_t> td, vm_list_t *tai · 38 unmodified lines
3939 }
4040
4141 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
42− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm list\n");
42+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm list");
4343 }
4444
4545 vm_list_t::~vm_list_t()
@@ -60,7 +60,7 @@ vm_list_t::~vm_list_t() · 14 unmodified lines
6060 }
6161
6262 debug::assign_debug_pointer(&_mem.alloc);
63− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm list\n");
63+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm list");
6464 }
6565
6666 std::shared_ptr<const type_descriptor_t> vm_list_t::get_element_type() const
src/vm/module_ref.cpp+4−4
@@ -52,7 +52,7 @@ namespace · 51 unmodified lines
5252 debug::log_msg(
5353 debug::component_trace_t::module,
5454 debug::log_level_t::debug,
55− "export: %d %#08x >>%s<<\n",
55+ "export: %d %#08x >>%s<<",
5656 index,
5757 export_entry.sig,
5858 export_entry.name->str());
@@ -80,7 +80,7 @@ vm_module_ref_t::vm_module_ref_t(std::shared_ptr<const vm_module_t> module) · 21 unmodified lines
8080 mp_base = vm_alloc_t::copy(*module->original_mp);
8181
8282 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
83− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm module ref\n");
83+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm module ref");
8484 }
8585
8686 vm_module_ref_t::vm_module_ref_t(std::shared_ptr<const vm_module_t> module, const import_vm_module_t &imports)
@@ -98,7 +98,7 @@ vm_module_ref_t::vm_module_ref_t(std::shared_ptr<const vm_module_t> module, cons · 11 unmodified lines
9898 mp_base = vm_alloc_t::copy(*module->original_mp);
9999
100100 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
101− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm module ref: exported %d\n", _function_refs->get_length());
101+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm module ref: exported %d", _function_refs->get_length());
102102 }
103103
104104 vm_module_ref_t::~vm_module_ref_t()
@@ -109,7 +109,7 @@ vm_module_ref_t::~vm_module_ref_t() · 4 unmodified lines
109109 _function_refs->release();
110110
111111 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
112− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm module ref\n");
112+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm module ref");
113113 }
114114
115115 bool vm_module_ref_t::is_builtin_module() const
src/vm/scheduler.cpp+12−12
@@ -25,7 +25,7 @@ vm_scheduler_control_t::~vm_scheduler_control_t() · 24 unmodified lines
2525
2626 void default_scheduler_t::worker_main(default_scheduler_t &instance)
2727 {
28− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: start\n");
28+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: start");
2929
3030 auto current_thread = std::shared_ptr<thread_instance_t>{};
3131
@@ -36,12 +36,12 @@ void default_scheduler_t::worker_main(default_scheduler_t &instance) · 4 unmodified lines
3636 current_thread = instance.next_thread(std::move(current_thread));
3737 if (current_thread == nullptr)
3838 {
39− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: stop\n");
39+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: stop");
4040 break;
4141 }
4242
4343 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
44− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: execute: %d\n", current_thread->vm_thread->get_thread_id());
44+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: execute: %d", current_thread->vm_thread->get_thread_id());
4545
4646 current_thread->vm_thread->execute(instance._vm, instance._vm_thread_quanta);
4747 }
@@ -113,7 +113,7 @@ default_scheduler_t::~default_scheduler_t() · 65 unmodified lines
113113 for (auto &w : _worker_pool)
114114 w.join();
115115
116− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: shutdown\n");
116+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: shutdown");
117117 }
118118
119119 bool default_scheduler_t::is_idle() const
@@ -134,7 +134,7 @@ const vm_thread_t& default_scheduler_t::schedule_thread(std::unique_ptr<runtime: · 14 unmodified lines
134134 throw vm_system_exception{ "Scheduled thread in invalid state" };
135135
136136 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
137− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: scheduled: %d\n", thread->get_thread_id());
137+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: scheduled: %d", thread->get_thread_id());
138138
139139 std::unique_lock<std::mutex> lock{ _vm_threads_lock };
140140
@@ -249,7 +249,7 @@ void default_scheduler_t::enqueue_blocked_thread(uint32_t thread_id) · 108 unmodified lines
249249 _blocked_vm_thread_ids.erase(blocked_iter);
250250
251251 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
252− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: enqueue blocked: %d\n", thread_id);
252+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: enqueue blocked: %d", thread_id);
253253
254254 const bool runnable_thread = enqueue_thread_unsafe(std::move(thread_container), vm_thread_state_t::ready);
255255 if (runnable_thread)
@@ -344,7 +344,7 @@ std::shared_ptr<default_scheduler_t::thread_instance_t> default_scheduler_t::nex · 88 unmodified lines
344344
345345 if (!_all_vm_threads.empty() && _blocked_vm_thread_ids.size() == _all_vm_threads.size())
346346 {
347− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::warning, "scheduler: deadlock detected\n");
347+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::warning, "scheduler: deadlock detected");
348348 assert(false && "VM thread deadlock detected");
349349 }
350350
@@ -352,7 +352,7 @@ std::shared_ptr<default_scheduler_t::thread_instance_t> default_scheduler_t::nex · 1 unmodified line
352352 return{};
353353
354354 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
355− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: waiting\n");
355+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: worker: waiting");
356356
357357 _worker_event.wait(lock);
358358
@@ -402,7 +402,7 @@ bool default_scheduler_t::enqueue_thread_unsafe(std::shared_ptr<thread_instance_ · 43 unmodified lines
402402 _runnable_vm_thread_ids.push_back(thread_id);
403403
404404 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
405− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: enqueue: %d\n", thread_id);
405+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: enqueue: %d", thread_id);
406406
407407 return true;
408408 }
@@ -414,7 +414,7 @@ bool default_scheduler_t::enqueue_thread_unsafe(std::shared_ptr<thread_instance_ · 5 unmodified lines
414414 _blocked_vm_thread_ids.insert(thread_id);
415415
416416 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
417− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: blocked: %d\n", thread_id);
417+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: blocked: %d", thread_id);
418418
419419 break;
420420 }
@@ -423,7 +423,7 @@ bool default_scheduler_t::enqueue_thread_unsafe(std::shared_ptr<thread_instance_ · 2 unmodified lines
423423 case vm_thread_state_t::exiting:
424424 {
425425 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
426− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: exiting: %d\n", thread_id);
426+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: exiting: %d", thread_id);
427427
428428 // Remove the thread
429429 auto thread_to_remove = _all_vm_threads.find(thread_id);
@@ -436,7 +436,7 @@ bool default_scheduler_t::enqueue_thread_unsafe(std::shared_ptr<thread_instance_ · 6 unmodified lines
436436 case vm_thread_state_t::broken:
437437 {
438438 if (debug::is_component_tracing_enabled<debug::component_trace_t::scheduler>())
439− debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: broken: %d\n", thread_id);
439+ debug::log_msg(debug::component_trace_t::scheduler, debug::log_level_t::debug, "scheduler: broken: %d", thread_id);
440440
441441 auto err_msg = thread_instance->vm_thread->get_error_message();
442442 assert(err_msg != nullptr);
src/vm/stack.cpp+8−8
@@ -76,7 +76,7 @@ namespace · 75 unmodified lines
7676 top_page->page_limit_addr = reinterpret_cast<std::uintptr_t>(top_page)+stack_page_size;
7777
7878 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
79− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "alloc: vm stack alloc: %#" PRIxPTR " %#" PRIxPTR "\n", top_page, top_page->page_limit_addr);
79+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "alloc: vm stack alloc: %#" PRIxPTR " %#" PRIxPTR, top_page, top_page->page_limit_addr);
8080
8181 return top_page->stack_data();
8282 }
@@ -90,7 +90,7 @@ namespace · 7 unmodified lines
9090 free_memory(top_page);
9191
9292 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
93− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "free: vm stack alloc\n");
93+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "free: vm stack alloc");
9494
9595 // Set the top page
9696 top_page = current_stack_page;
@@ -111,7 +111,7 @@ vm_frame_t::vm_frame_t(std::shared_ptr<const type_descriptor_t> &td) · 14 unmodified lines
111111 prev_module_ref() = nullptr;
112112
113113 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
114− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm frame: %#" PRIxPTR " %d\n", this, frame_type->size_in_bytes);
114+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm frame: %#" PRIxPTR " %d", this, frame_type->size_in_bytes);
115115 }
116116
117117 vm_frame_t::~vm_frame_t()
@@ -121,7 +121,7 @@ vm_frame_t::~vm_frame_t() · 3 unmodified lines
121121 destroy_memory(*frame_type, base());
122122
123123 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
124− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm frame: %#" PRIxPTR "\n", this);
124+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm frame: %#" PRIxPTR, this);
125125 }
126126
127127 void vm_frame_t::copy_frame_contents(const vm_frame_t &other)
@@ -181,7 +181,7 @@ vm_stack_t::vm_stack_t(std::size_t stack_extent) · 53 unmodified lines
181181 : _mem{ std::make_unique<vm_stack_layout>(stack_extent) }
182182 {
183183 assert(0 < stack_extent && stack_extent < static_cast<std::size_t>(std::numeric_limits<word_t>::max()));
184− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm stack\n");
184+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm stack");
185185 }
186186
187187 vm_stack_t::~vm_stack_t()
@@ -195,7 +195,7 @@ vm_stack_t::~vm_stack_t() · 7 unmodified lines
195195 _mem->release();
196196 _mem.reset();
197197
198− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm stack\n");
198+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm stack");
199199 }
200200
201201 vm_frame_t *vm_stack_t::alloc_frame(std::shared_ptr<const type_descriptor_t> frame_type)
@@ -245,7 +245,7 @@ vm_frame_t *vm_stack_t::push_frame() · 43 unmodified lines
245245 layout->top_frame = new_top_frame;
246246
247247 if (debug::is_component_tracing_enabled<debug::component_trace_t::stack>())
248− debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "update: push vm frame: %#" PRIxPTR "\n", new_top_frame);
248+ debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "update: push vm frame: %#" PRIxPTR, new_top_frame);
249249
250250 return new_top_frame;
251251 }
@@ -285,7 +285,7 @@ vm_frame_t *vm_stack_t::pop_frame() · 33 unmodified lines
285285 }
286286
287287 if (debug::is_component_tracing_enabled<debug::component_trace_t::stack>())
288− debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "update: pop vm frame: %#" PRIxPTR "\n", current_frame);
288+ debug::log_msg(debug::component_trace_t::stack, debug::log_level_t::debug, "update: pop vm frame: %#" PRIxPTR, current_frame);
289289
290290 return current_frame;
291291 }
src/vm/string.cpp+3−3
@@ -222,7 +222,7 @@ vm_string_t::vm_string_t(std::size_t encoded_str_len, const uint8_t *encoded_str · 221 unmodified lines
222222 }
223223
224224 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
225− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm string: %d %d >>%s<<\n", _length, (_length_max * _character_size), dest);
225+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm string: %d %d >>%s<<", _length, (_length_max * _character_size), dest);
226226 }
227227
228228 vm_string_t::vm_string_t(const vm_string_t &s1, const vm_string_t &s2)
@@ -282,7 +282,7 @@ vm_string_t::vm_string_t(const vm_string_t &other, word_t begin_index, word_t en · 53 unmodified lines
282282
283283 // Copy over string content starting at the correct index (char vs. rune_t)
284284 std::memcpy(dest, (src + (begin_index * _character_size)), length_in_bytes);
285− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "copy: vm string: %#" PRIxPTR " %d %d %#" PRIxPTR "\n", &other, begin_index, end_index, this);
285+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "copy: vm string: %#" PRIxPTR " %d %d %#" PRIxPTR, &other, begin_index, end_index, this);
286286 }
287287
288288 vm_string_t::~vm_string_t()
@@ -301,7 +301,7 @@ vm_string_t::~vm_string_t() · 12 unmodified lines
301301 free_memory(_encoded_str);
302302 }
303303
304− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm string\n");
304+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm string");
305305
306306 debug::assign_debug_pointer(&_mem.alloc);
307307 debug::assign_debug_pointer(&_encoded_str);
src/vm/sys/Sysmod.cpp+6−6
@@ -90,7 +90,7 @@ namespace · 89 unmodified lines
9090 debug::log_msg(
9191 debug::component_trace_t::builtin,
9292 debug::log_level_t::debug,
93− "sys: fd: finalize: %d\n",
93+ "sys: fd: finalize: %d",
9494 fd->fd);
9595 }
9696
@@ -236,21 +236,21 @@ Sysmodinit(void) · 139 unmodified lines
236236 auto vm_stdin = vm_alloc_t::allocate(T_FD);
237237 const auto fd = sys::create_fd_record(vm_stdin);
238238 fd_stdin = ::new(vm_stdin->get_allocation())vm_fd_t{ fd, std::cin };
239− debug::log_msg(debug::component_trace_t::builtin, debug::log_level_t::debug, "sys: stdin: %d\n", fd);
239+ debug::log_msg(debug::component_trace_t::builtin, debug::log_level_t::debug, "sys: stdin: %d", fd);
240240 }
241241
242242 {
243243 auto vm_stdout = vm_alloc_t::allocate(T_FD);
244244 const auto fd = sys::create_fd_record(vm_stdout);
245245 fd_stdout = ::new(vm_stdout->get_allocation())vm_fd_t{ fd, std::cout };
246− debug::log_msg(debug::component_trace_t::builtin, debug::log_level_t::debug, "sys: stdout: %d\n", fd);
246+ debug::log_msg(debug::component_trace_t::builtin, debug::log_level_t::debug, "sys: stdout: %d", fd);
247247 }
248248
249249 {
250250 auto vm_stderr = vm_alloc_t::allocate(T_FD);
251251 const auto fd = sys::create_fd_record(vm_stderr);
252252 fd_stderr = ::new(vm_stderr->get_allocation())vm_fd_t{ fd, std::cerr };
253− debug::log_msg(debug::component_trace_t::builtin, debug::log_level_t::debug, "sys: stderr: %d\n", fd);
253+ debug::log_msg(debug::component_trace_t::builtin, debug::log_level_t::debug, "sys: stderr: %d", fd);
254254 }
255255 }
256256
@@ -390,7 +390,7 @@ Sys_create(vm_registers_t &r, vm_t &vm) · 133 unmodified lines
390390 debug::log_msg(
391391 debug::component_trace_t::builtin,
392392 debug::log_level_t::debug,
393− "sys: create: %d >>%s<< %#x %#x\n",
393+ "sys: create: %d >>%s<< %#x %#x",
394394 fd,
395395 path->str(),
396396 fp.mode,
@@ -542,7 +542,7 @@ Sys_open(vm_registers_t &r, vm_t &vm) · 145 unmodified lines
542542 debug::log_msg(
543543 debug::component_trace_t::builtin,
544544 debug::log_level_t::debug,
545− "sys: open: %d >>%s<< %#x\n",
545+ "sys: open: %d >>%s<< %#x",
546546 fd,
547547 path->str(),
548548 fp.mode);
src/vm/thread.cpp+5−5
@@ -34,7 +34,7 @@ namespace · 33 unmodified lines
3434 debug::log_msg(
3535 debug::component_trace_t::addressing,
3636 debug::log_level_t::debug,
37− "decode: registers: %d (%#" PRIxPTR " %#" PRIxPTR " %#" PRIxPTR ")\n",
37+ "decode: registers: %d (%#" PRIxPTR " %#" PRIxPTR " %#" PRIxPTR ")",
3838 inst.opcode,
3939 reg.src,
4040 reg.mid,
@@ -127,7 +127,7 @@ vm_thread_t::vm_thread_t( · 86 unmodified lines
127127 // Pushing the initial frame sets the FP register
128128 _registers.stack.push_frame();
129129
130− debug::log_msg(debug::component_trace_t::thread, debug::log_level_t::debug, "init: vm thread: %d %d\n", _thread_id, _parent_thread_id);
130+ debug::log_msg(debug::component_trace_t::thread, debug::log_level_t::debug, "init: vm thread: %d %d", _thread_id, _parent_thread_id);
131131 }
132132
133133 vm_thread_t::vm_thread_t(
@@ -157,13 +157,13 @@ vm_thread_t::vm_thread_t( · 23 unmodified lines
157157 current_frame->copy_frame_contents(initial_frame);
158158
159159 if (debug::is_component_tracing_enabled<debug::component_trace_t::thread>())
160− debug::log_msg(debug::component_trace_t::thread, debug::log_level_t::debug, "init: vm thread: %d %d\n", _thread_id, _parent_thread_id);
160+ debug::log_msg(debug::component_trace_t::thread, debug::log_level_t::debug, "init: vm thread: %d %d", _thread_id, _parent_thread_id);
161161 }
162162
163163 vm_thread_t::~vm_thread_t()
164164 {
165165 if (debug::is_component_tracing_enabled<debug::component_trace_t::thread>())
166− debug::log_msg(debug::component_trace_t::thread, debug::log_level_t::debug, "destroy: vm thread: %d %d\n", _thread_id, _parent_thread_id);
166+ debug::log_msg(debug::component_trace_t::thread, debug::log_level_t::debug, "destroy: vm thread: %d %d", _thread_id, _parent_thread_id);
167167
168168 free_memory(_error_message);
169169 debug::assign_debug_pointer(&_error_message);
@@ -267,7 +267,7 @@ vm_thread_state_t vm_thread_t::execute(vm_t &vm, const uint32_t quanta) · 97 unmodified lines
267267 debug::log_msg(
268268 debug::component_trace_t::thread,
269269 debug::log_level_t::debug,
270− "status: vm thread: execute: %d %d %d %d\n",
270+ "status: vm thread: execute: %d %d %d %d",
271271 _thread_id,
272272 (quanta - _registers.current_thread_quanta),
273273 quanta,
src/vm/vm.cpp+2−2
@@ -144,7 +144,7 @@ std::shared_ptr<runtime::vm_module_t> vm_t::load_module(const char *path) · 143 unmodified lines
144144
145145 iter->module = module;
146146
147− debug::log_msg(debug::component_trace_t::module, debug::log_level_t::debug, "reload: vm module: >>%s<<\n", path);
147+ debug::log_msg(debug::component_trace_t::module, debug::log_level_t::debug, "reload: vm module: >>%s<<", path);
148148 }
149149
150150 return module;
@@ -182,7 +182,7 @@ std::shared_ptr<runtime::vm_module_t> vm_t::load_module(const char *path) · 31 unmodified lines
182182 }
183183
184184 if (debug::is_component_tracing_enabled<debug::component_trace_t::module>())
185− debug::log_msg(debug::component_trace_t::module, debug::log_level_t::debug, "load: vm module: >>%s<<\n", path);
185+ debug::log_msg(debug::component_trace_t::module, debug::log_level_t::debug, "load: vm module: >>%s<<", path);
186186
187187 return new_module;
188188 }
src/vm/vm_exception_handler.cpp+3−3
@@ -26,7 +26,7 @@ std::tuple<const handler_t *, vm_frame_t *, vm_pc_t> disvm::runtime::find_except · 25 unmodified lines
2626
2727 while (current_frame != nullptr)
2828 {
29− debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "begin: handler: %d\n", unwind_depth);
29+ debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "begin: handler: %d", unwind_depth);
3030
3131 auto &handler_section = current_module->module->handler_section;
3232
@@ -42,12 +42,12 @@ std::tuple<const handler_t *, vm_frame_t *, vm_pc_t> disvm::runtime::find_except · 9 unmodified lines
4242 auto exception_name = exception.name.get();
4343 if (exception_id.compare_to(exception_name) == 0)
4444 {
45− debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "end: handler: match: %d\n", unwind_depth);
45+ debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "end: handler: match: %d", unwind_depth);
4646 return std::make_tuple(&handler, current_frame, exception.pc);
4747 }
4848 else if (exception_name == nullptr && exception.pc != runtime_constants::invalid_program_counter)
4949 {
50− debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "end: handler: fallback: %d\n", unwind_depth);
50+ debug::log_msg(debug::component_trace_t::exception, debug::log_level_t::debug, "end: handler: fallback: %d", unwind_depth);
5151 return std::make_tuple(&handler, current_frame, exception.pc);
5252 }
5353 }
src/vm/vm_memory.cpp+34−25
@@ -110,7 +110,7 @@ void *disvm::runtime::alloc_memory(std::size_t amount_in_bytes) · 109 unmodified lines
110110 throw vm_system_exception{ "Out of memory" };
111111
112112 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
113− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "alloc: %#" PRIxPTR " %d\n", memory, amount_in_bytes);
113+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "alloc: %#" PRIxPTR " %d", memory, amount_in_bytes);
114114
115115 return memory;
116116 }
@@ -124,7 +124,7 @@ void *disvm::runtime::calloc_memory(std::size_t amount_in_bytes) · 7 unmodified lines
124124 throw vm_system_exception{ "Out of memory" };
125125
126126 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
127− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "alloc: zeroed: %#" PRIxPTR " %d\n", memory, amount_in_bytes);
127+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "alloc: zeroed: %#" PRIxPTR " %d", memory, amount_in_bytes);
128128
129129 return memory;
130130 }
@@ -135,7 +135,7 @@ void disvm::runtime::free_memory(void *memory) · 4 unmodified lines
135135 return;
136136
137137 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
138− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "free: %#" PRIxPTR "\n", memory);
138+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "free: %#" PRIxPTR, memory);
139139
140140 std::free(memory);
141141 }
@@ -233,7 +233,7 @@ vm_alloc_t *vm_alloc_t::allocate(std::shared_ptr<const type_descriptor_t> td) · 91 unmodified lines
233233 // Initialize pointer types
234234 init_memory(*td, alloc->get_allocation());
235235
236− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm alloc: %d\n", td->size_in_bytes);
236+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: vm alloc: %d", td->size_in_bytes);
237237 return alloc;
238238 }
239239
@@ -247,7 +247,7 @@ vm_alloc_t *vm_alloc_t::allocate(std::shared_ptr<const type_descriptor_t> td, co · 7 unmodified lines
247247 auto mem = calloc_memory(sizeof(vm_alloc_t) + td->size_in_bytes);
248248 auto alloc = ::new(mem)vm_alloc_t{ td };
249249
250− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "initz: vm alloc: %d\n", td->size_in_bytes);
250+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "initz: vm alloc: %d", td->size_in_bytes);
251251 return alloc;
252252 }
253253
@@ -261,7 +261,7 @@ vm_alloc_t *vm_alloc_t::copy(const vm_alloc_t &other) · 7 unmodified lines
261261 // Ref count all dynamic allocations
262262 inc_ref_count_in_memory(*alloc_copy->alloc_type, alloc_copy->get_allocation());
263263
264− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "copy: vm alloc: %#" PRIxPTR " %#" PRIxPTR "\n", &other, alloc_copy);
264+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "copy: vm alloc: %#" PRIxPTR " %#" PRIxPTR, &other, alloc_copy);
265265 return alloc_copy;
266266 }
267267
@@ -291,7 +291,7 @@ vm_alloc_t::~vm_alloc_t() · 23 unmodified lines
291291
292292 // Free pointer types
293293 destroy_memory(*alloc_type, get_allocation());
294− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm alloc\n");
294+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: vm alloc");
295295 }
296296
297297 std::size_t vm_alloc_t::add_ref()
@@ -326,24 +326,28 @@ namespace · 28 unmodified lines
326326 {
327327 namespace hidden_type_desc
328328 {
329− const type_descriptor_t byte{ sizeof(byte_t), 0, nullptr, type_descriptor_t::no_finalizer };
330− const type_descriptor_t short_word{ sizeof(short_word_t), 0, nullptr, type_descriptor_t::no_finalizer };
331− const type_descriptor_t word{ sizeof(word_t), 0, nullptr, type_descriptor_t::no_finalizer };
332− const type_descriptor_t short_real{ sizeof(short_real_t), 0, nullptr, type_descriptor_t::no_finalizer };
333− const type_descriptor_t real{ sizeof(real_t), 0, nullptr, type_descriptor_t::no_finalizer };
334− const type_descriptor_t big{ sizeof(big_t), 0, nullptr, type_descriptor_t::no_finalizer };
329+#define TYPE_DESC(N,S,MS,M,F) const type_descriptor_t N{ S, MS, M, F, #N }
330+
331+ TYPE_DESC(byte, sizeof(byte_t), 0, nullptr, type_descriptor_t::no_finalizer);
332+ TYPE_DESC(short_word, sizeof(short_word_t), 0, nullptr, type_descriptor_t::no_finalizer);
333+ TYPE_DESC(word, sizeof(word_t), 0, nullptr, type_descriptor_t::no_finalizer);
334+ TYPE_DESC(short_real, sizeof(short_real_t), 0, nullptr, type_descriptor_t::no_finalizer);
335+ TYPE_DESC(real, sizeof(real_t), 0, nullptr, type_descriptor_t::no_finalizer);
336+ TYPE_DESC(big, sizeof(big_t), 0, nullptr, type_descriptor_t::no_finalizer);
335337
336338 const byte_t pointer_map[] = { 0x80 };
337− const type_descriptor_t pointer{ sizeof(pointer_t), (sizeof(pointer_map) / sizeof(pointer_map[0])), pointer_map, type_descriptor_t::no_finalizer };
339+ TYPE_DESC(pointer, sizeof(pointer_t), (sizeof(pointer_map) / sizeof(pointer_map[0])), pointer_map, type_descriptor_t::no_finalizer);
340+
341+ TYPE_DESC(vm_array, 0, 0, nullptr, type_descriptor_t::no_finalizer);
342+ TYPE_DESC(vm_list, 0, 0, nullptr, type_descriptor_t::no_finalizer);
343+ TYPE_DESC(vm_channel, 0, 0, nullptr, type_descriptor_t::no_finalizer);
344+ TYPE_DESC(vm_string, 0, 0, nullptr, type_descriptor_t::no_finalizer);
338345
339− const type_descriptor_t vm_array{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
340− const type_descriptor_t vm_list{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
341− const type_descriptor_t vm_channel{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
342− const type_descriptor_t vm_string{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
346+ TYPE_DESC(vm_module_ref, 0, 0, nullptr, type_descriptor_t::no_finalizer);
347+ TYPE_DESC(vm_stack, 0, 0, nullptr, type_descriptor_t::no_finalizer);
348+ TYPE_DESC(vm_thread, 0, 0, nullptr, type_descriptor_t::no_finalizer);
343349
344− const type_descriptor_t vm_module_ref{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
345− const type_descriptor_t vm_stack{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
346− const type_descriptor_t vm_thread{ 0, 0, nullptr, type_descriptor_t::no_finalizer };
350+#undef TYPE_DESC
347351
348352 struct
349353 {
@@ -480,7 +484,7 @@ std::shared_ptr<const type_descriptor_t> type_descriptor_t::create( · 130 unmodified lines
480484 debug::assign_debug_pointer(const_cast<byte_t **>(&td->pointer_map));
481485
482486 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
483− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: type descriptor\n");
487+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "destroy: type descriptor");
484488
485489 free_memory(td);
486490 }
@@ -496,7 +500,7 @@ std::shared_ptr<const type_descriptor_t> type_descriptor_t::create( · 9 unmodified lines
496500 pointer_map_local[i] = pointer_map[i];
497501 }
498502
499− auto new_type = ::new(new_type_memory) type_descriptor_t{ size_in_bytes, pointer_map_length, pointer_map_local, finalizer };
503+ auto new_type = ::new(new_type_memory) type_descriptor_t{ size_in_bytes, pointer_map_length, pointer_map_local, finalizer, "#" };
500504 return std::shared_ptr<type_descriptor_t>{ new_type, deleter };
501505 }
502506
@@ -504,12 +508,17 @@ type_descriptor_t::type_descriptor_t( · 1 unmodified line
504508 word_t size_in_bytes,
505509 word_t map_in_bytes,
506510 const byte_t * pointer_map,
507− vm_alloc_instance_finalizer_t finalizer)
511+ vm_alloc_instance_finalizer_t finalizer,
512+ const char *debug_name)
508513 : size_in_bytes{ size_in_bytes }
509514 , map_in_bytes{ map_in_bytes }
510515 , pointer_map{ pointer_map }
511516 , finalizer{ finalizer }
517+#ifndef NDEBUG
518+ , debug_type_name{ debug_name }
519+#endif
512520 {
521+ (void)debug_name;
513522 if (debug::is_component_tracing_enabled<debug::component_trace_t::memory>())
514− debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: type descriptor\n");
523+ debug::log_msg(debug::component_trace_t::memory, debug::log_level_t::debug, "init: type descriptor");
515524 }