Skip to content

Commit 7a01c4d

Browse files
dipinhoradipinhora
authored
Add ability to trace runtime events in chromium json format (ponylang#4649)
Runtime tracing is helpful in understanding how the runtime works and for debugging issues with the runtime. The implementation hopefully is flexible and extensible in order to be able to add more events for tracing as needed. The tracing can either write to file in the background or work in a "flight recorder" mode where events are stored into in memory circular buffers and written to stderr in case of abnormal program behavior (SIGILL, SIGSEGV, SIGBUS, etc). Chromium json format is documented at: https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview?tab=t.0 and trace files can be viewed with the perfetto trace viewer: https://perfetto.dev/ inspired by golang's tracing and verona's flight recorder.
1 parent c411b33 commit 7a01c4d

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

43 files changed

+3413
-99
lines changed

‎.github/workflows/pr.yml

+3
Original file line numberDiff line numberDiff line change
@@ -454,6 +454,9 @@ jobs:
454454
- image: ghcr.io/ponylang/ponyc-ci-x86-64-unknown-linux-ubuntu24.04-builder:20250115
455455
debugger: lldb
456456
directives: runtimestats
457+
- image: ghcr.io/ponylang/ponyc-ci-x86-64-unknown-linux-ubuntu24.04-builder:20250115
458+
debugger: lldb
459+
directives: runtime_tracing
457460

458461
name: use ${{ matrix.directives }}
459462
container:

‎.release-notes/4649.md

+11
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,11 @@
1+
## Add ability to trace runtime events in chromium json format #4649
2+
3+
We have added the ability to trace runtime events for pony applications. Runtime tracing is helpful in understanding how the runtime works and for debugging issues with the runtime.
4+
5+
The tracing can either write to file in the background or work in a "flight recorder" mode where events are stored into in memory circular buffers and written to stderr in case of abnormal program behavior (SIGILL, SIGSEGV, SIGBUS, etc).
6+
7+
Traces are written in chromium json format and trace files can be viewed with the perfetto trace viewer.
8+
9+
Links:
10+
[Chromium json format](https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview?tab=t.0)
11+
[perfetto trace viewer](https://perfetto.dev/)

‎CMakeLists.txt

+5
Original file line numberDiff line numberDiff line change
@@ -104,6 +104,11 @@ if(PONY_USE_POOL_MEMALIGN)
104104
add_compile_options(-DUSE_POOL_MEMALIGN)
105105
endif()
106106

107+
if(PONY_USE_RUNTIME_TRACING)
108+
set(PONY_OUTPUT_SUFFIX "${PONY_OUTPUT_SUFFIX}-runtime_tracing")
109+
add_compile_options(-DUSE_RUNTIME_TRACING)
110+
endif()
111+
107112
# LibPonyC tests assume that our outputs are two directories above the root directory.
108113
set(CMAKE_RUNTIME_OUTPUT_DIRECTORY_DEBUG "${CMAKE_BINARY_DIR}/../debug${PONY_OUTPUT_SUFFIX}")
109114
set(CMAKE_RUNTIME_OUTPUT_DIRECTORY_RELEASE "${CMAKE_BINARY_DIR}/../release${PONY_OUTPUT_SUFFIX}")

‎Makefile

+2
Original file line numberDiff line numberDiff line change
@@ -148,6 +148,8 @@ define USE_CHECK
148148
PONY_USES += -DPONY_USE_RUNTIMESTATS_MESSAGES=true
149149
else ifeq ($1,pool_memalign)
150150
PONY_USES += -DPONY_USE_POOL_MEMALIGN=true
151+
else ifeq ($1,runtime_tracing)
152+
PONY_USES += -DPONY_USE_RUNTIME_TRACING=true
151153
else
152154
$$(error ERROR: Unknown use option specified: $1)
153155
endif

‎src/libponyc/ast/ast.c

+12
Original file line numberDiff line numberDiff line change
@@ -2099,6 +2099,10 @@ static pony_type_t ast_signature_pony =
20992099
0,
21002100
0,
21012101
NULL,
2102+
#if defined(USE_RUNTIME_TRACING)
2103+
NULL,
2104+
NULL,
2105+
#endif
21022106
NULL,
21032107
ast_signature_serialise_trace,
21042108
ast_signature_serialise,
@@ -2179,6 +2183,10 @@ static pony_type_t ast_nominal_pkg_id_signature_pony =
21792183
0,
21802184
0,
21812185
NULL,
2186+
#if defined(USE_RUNTIME_TRACING)
2187+
NULL,
2188+
NULL,
2189+
#endif
21822190
NULL,
21832191
ast_nominal_pkg_id_signature_serialise_trace,
21842192
ast_nominal_pkg_id_signature_serialise,
@@ -2443,6 +2451,10 @@ static pony_type_t ast_pony =
24432451
0,
24442452
0,
24452453
NULL,
2454+
#if defined(USE_RUNTIME_TRACING)
2455+
NULL,
2456+
NULL,
2457+
#endif
24462458
NULL,
24472459
ast_serialise_trace,
24482460
ast_serialise,

‎src/libponyc/ast/source.c

+4
Original file line numberDiff line numberDiff line change
@@ -116,6 +116,10 @@ static pony_type_t source_pony =
116116
0,
117117
0,
118118
NULL,
119+
#if defined(USE_RUNTIME_TRACING)
120+
NULL,
121+
NULL,
122+
#endif
119123
NULL,
120124
source_serialise_trace,
121125
source_serialise,

‎src/libponyc/ast/stringtab.c

+8
Original file line numberDiff line numberDiff line change
@@ -136,6 +136,10 @@ static __pony_thread_local struct _pony_type_t string_pony =
136136
0,
137137
0,
138138
NULL,
139+
#if defined(USE_RUNTIME_TRACING)
140+
NULL,
141+
NULL,
142+
#endif
139143
NULL,
140144
NULL,
141145
string_serialise,
@@ -223,6 +227,10 @@ static pony_type_t strlist_pony =
223227
0,
224228
0,
225229
NULL,
230+
#if defined(USE_RUNTIME_TRACING)
231+
NULL,
232+
NULL,
233+
#endif
226234
NULL,
227235
strlist_serialise_trace,
228236
strlist_serialise,

‎src/libponyc/ast/symtab.c

+4
Original file line numberDiff line numberDiff line change
@@ -391,6 +391,10 @@ static pony_type_t symbol_pony =
391391
0,
392392
0,
393393
NULL,
394+
#if defined(USE_RUNTIME_TRACING)
395+
NULL,
396+
NULL,
397+
#endif
394398
NULL,
395399
symbol_serialise_trace,
396400
symbol_serialise,

‎src/libponyc/ast/token.c

+12
Original file line numberDiff line numberDiff line change
@@ -416,6 +416,10 @@ static pony_type_t token_signature_pony =
416416
0,
417417
0,
418418
NULL,
419+
#if defined(USE_RUNTIME_TRACING)
420+
NULL,
421+
NULL,
422+
#endif
419423
NULL,
420424
token_signature_serialise_trace,
421425
token_signature_serialise,
@@ -471,6 +475,10 @@ static pony_type_t token_docstring_signature_pony =
471475
0,
472476
0,
473477
NULL,
478+
#if defined(USE_RUNTIME_TRACING)
479+
NULL,
480+
NULL,
481+
#endif
474482
NULL,
475483
token_docstring_signature_serialise_trace,
476484
token_docstring_signature_serialise,
@@ -560,6 +568,10 @@ static pony_type_t token_pony =
560568
0,
561569
0,
562570
NULL,
571+
#if defined(USE_RUNTIME_TRACING)
572+
NULL,
573+
NULL,
574+
#endif
563575
NULL,
564576
token_serialise_trace,
565577
token_serialise,

‎src/libponyc/codegen/codegen.c

+7
Original file line numberDiff line numberDiff line change
@@ -236,6 +236,13 @@ static void init_runtime(compile_t* c)
236236
params[1] = c->ptr;
237237
c->custom_deserialise_fn = LLVMFunctionType(c->void_type, params, 2, false);
238238

239+
#if defined(USE_RUNTIME_TRACING)
240+
// get_behavior_name
241+
// void (*)(i8*, __object*, $message*)
242+
params[0] = c->i32;
243+
c->get_behavior_name_fn = LLVMFunctionType(c->ptr, params, 1, false);
244+
#endif
245+
239246
// dispatch
240247
// void (*)(i8*, __object*, $message*)
241248
params[0] = c->ptr;

‎src/libponyc/codegen/codegen.h

+3
Original file line numberDiff line numberDiff line change
@@ -197,6 +197,9 @@ typedef struct compile_t
197197
LLVMTypeRef trace_fn;
198198
LLVMTypeRef serialise_fn;
199199
LLVMTypeRef dispatch_fn;
200+
#if defined(USE_RUNTIME_TRACING)
201+
LLVMTypeRef get_behavior_name_fn;
202+
#endif
200203
LLVMTypeRef final_fn;
201204
LLVMTypeRef custom_serialise_space_fn;
202205
LLVMTypeRef custom_deserialise_fn;

‎src/libponyc/codegen/gendesc.c

+45
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,31 @@
1010
#include "ponyassert.h"
1111
#include <string.h>
1212

13+
#if defined(USE_RUNTIME_TRACING)
14+
#define DESC_ID 0
15+
#define DESC_SIZE 1
16+
#define DESC_SERIALISEID 2
17+
#define DESC_FIELD_COUNT 3
18+
#define DESC_FIELD_OFFSET 4
19+
#define DESC_INSTANCE 5
20+
#define DESC_NAME 6
21+
#define DESC_GET_BEHAVIOR_NAME 7
22+
#define DESC_TRACE 8
23+
#define DESC_SERIALISE_TRACE 9
24+
#define DESC_SERIALISE 10
25+
#define DESC_DESERIALISE 11
26+
#define DESC_CUSTOM_SERIALISE_SPACE 12
27+
#define DESC_CUSTOM_DESERIALISE 13
28+
#define DESC_DISPATCH 14
29+
#define DESC_FINALISE 15
30+
#define DESC_EVENT_NOTIFY 16
31+
#define DESC_MIGHT_REFERENCE_ACTOR 17
32+
#define DESC_TRAITS 18
33+
#define DESC_FIELDS 19
34+
#define DESC_VTABLE 20
35+
36+
#define DESC_LENGTH 21
37+
#else
1338
#define DESC_ID 0
1439
#define DESC_SIZE 1
1540
#define DESC_SERIALISEID 2
@@ -31,6 +56,7 @@
3156
#define DESC_VTABLE 18
3257

3358
#define DESC_LENGTH 19
59+
#endif
3460

3561
static LLVMValueRef make_unbox_function(compile_t* c, reach_type_t* t,
3662
reach_method_t* m)
@@ -195,6 +221,13 @@ static LLVMValueRef make_trait_bitmap(compile_t* c, reach_type_t* t)
195221
return global;
196222
}
197223

224+
#if defined(USE_RUNTIME_TRACING)
225+
static LLVMValueRef make_name(compile_t* c, reach_type_t* t)
226+
{
227+
return codegen_string(c, t->name, strlen(t->name));
228+
}
229+
#endif
230+
198231
static LLVMValueRef make_field_count(compile_t* c, reach_type_t* t)
199232
{
200233
if(t->underlying != TK_TUPLETYPE)
@@ -335,6 +368,10 @@ void gendesc_basetype(compile_t* c, LLVMTypeRef desc_type)
335368
params[DESC_FIELD_COUNT] = c->i32;
336369
params[DESC_FIELD_OFFSET] = c->i32;
337370
params[DESC_INSTANCE] = c->ptr;
371+
#if defined(USE_RUNTIME_TRACING)
372+
params[DESC_NAME] = c->ptr;
373+
params[DESC_GET_BEHAVIOR_NAME] = c->ptr;
374+
#endif
338375
params[DESC_TRACE] = c->ptr;
339376
params[DESC_SERIALISE_TRACE] = c->ptr;
340377
params[DESC_SERIALISE] = c->ptr;
@@ -383,6 +420,10 @@ void gendesc_type(compile_t* c, reach_type_t* t)
383420
params[DESC_FIELD_COUNT] = c->i32;
384421
params[DESC_FIELD_OFFSET] = c->i32;
385422
params[DESC_INSTANCE] = c->ptr;
423+
#if defined(USE_RUNTIME_TRACING)
424+
params[DESC_NAME] = c->ptr;
425+
params[DESC_GET_BEHAVIOR_NAME] = c->ptr;
426+
#endif
386427
params[DESC_TRACE] = c->ptr;
387428
params[DESC_SERIALISE_TRACE] = c->ptr;
388429
params[DESC_SERIALISE] = c->ptr;
@@ -421,6 +462,10 @@ void gendesc_init(compile_t* c, reach_type_t* t)
421462
args[DESC_FIELD_COUNT] = make_field_count(c, t);
422463
args[DESC_FIELD_OFFSET] = make_field_offset(c, t);
423464
args[DESC_INSTANCE] = make_desc_ptr(c, c_t->instance);
465+
#if defined(USE_RUNTIME_TRACING)
466+
args[DESC_NAME] = make_name(c, t);
467+
args[DESC_GET_BEHAVIOR_NAME] = make_desc_ptr(c, c_t->get_behavior_name_fn);
468+
#endif
424469
args[DESC_TRACE] = make_desc_ptr(c, c_t->trace_fn);
425470
args[DESC_SERIALISE_TRACE] = make_desc_ptr(c, c_t->serialise_trace_fn);
426471
args[DESC_SERIALISE] = make_desc_ptr(c, c_t->serialise_fn);

‎src/libponyc/codegen/genexe.c

+5
Original file line numberDiff line numberDiff line change
@@ -192,6 +192,11 @@ LLVMValueRef gen_main(compile_t* c, reach_type_t* t_main, reach_type_t* t_env)
192192
args[4] = LLVMConstInt(c->i1, 1, false);
193193
gencall_runtime(c, "pony_sendv_single", args, 5, "");
194194

195+
// unbecome the main actor before starting the runtime to set sched->ctx.current = NULL
196+
args[0] = ctx;
197+
args[1] = LLVMConstNull(c->ptr);
198+
gencall_runtime(c, "ponyint_become", args, 2, "");
199+
195200
// Start the runtime.
196201
args[0] = LLVMConstInt(c->i1, 0, false);
197202
args[1] = LLVMConstNull(c->ptr);

‎src/libponyc/codegen/genfun.c

+32
Original file line numberDiff line numberDiff line change
@@ -328,6 +328,28 @@ static void make_prototype(compile_t* c, reach_type_t* t,
328328
}
329329
}
330330

331+
#if defined(USE_RUNTIME_TRACING)
332+
static void add_get_behavior_name_case(compile_t* c, reach_type_t* t,
333+
const char* be_name, uint32_t index)
334+
{
335+
// Add a case to the get behavior name function to handle this message type.
336+
compile_type_t* c_t = (compile_type_t*)t->c_type;
337+
codegen_startfun(c, c_t->get_behavior_name_fn, NULL, NULL, NULL, false);
338+
LLVMBasicBlockRef block = codegen_block(c, "handler");
339+
LLVMValueRef id = LLVMConstInt(c->i32, index, false);
340+
LLVMAddCase(c_t->get_behavior_name_switch, id, block);
341+
342+
LLVMPositionBuilderAtEnd(c->builder, block);
343+
344+
// hack to get the behavior name since it's always a "tag_" prefix
345+
const char* name = genname_behavior_name(t->name, be_name + 4);
346+
347+
LLVMValueRef ret = codegen_string(c, name, strlen(name));
348+
genfun_build_ret(c, ret);
349+
codegen_finishfun(c);
350+
}
351+
#endif
352+
331353
static void add_dispatch_case(compile_t* c, reach_type_t* t,
332354
reach_param_t* params, uint32_t index, LLVMValueRef handler,
333355
LLVMTypeRef fun_type, LLVMTypeRef msg_type)
@@ -561,6 +583,11 @@ static bool genfun_be(compile_t* c, reach_type_t* t, reach_method_t* m)
561583
add_dispatch_case(c, t, m->params, m->vtable_index, c_m->func_handler,
562584
c_m->func_type, c_m->msg_type);
563585

586+
#if defined(USE_RUNTIME_TRACING)
587+
// Add the get behavior name case.
588+
add_get_behavior_name_case(c, t, m->name, m->vtable_index);
589+
#endif
590+
564591
return true;
565592
}
566593

@@ -640,6 +667,11 @@ static bool genfun_newbe(compile_t* c, reach_type_t* t, reach_method_t* m)
640667
add_dispatch_case(c, t, m->params, m->vtable_index, c_m->func_handler,
641668
c_m->func_type, c_m->msg_type);
642669

670+
#if defined(USE_RUNTIME_TRACING)
671+
// Add the get behavior name case.
672+
add_get_behavior_name_case(c, t, m->name, m->vtable_index);
673+
#endif
674+
643675
return true;
644676
}
645677

‎src/libponyc/codegen/genname.c

+14
Original file line numberDiff line numberDiff line change
@@ -153,6 +153,20 @@ const char* genname_dispatch(const char* type)
153153
return stringtab_two(type, "Dispatch");
154154
}
155155

156+
#if defined(USE_RUNTIME_TRACING)
157+
const char* genname_get_behavior_name(const char* type)
158+
{
159+
return stringtab_two(type, "GetBehaviourName");
160+
}
161+
162+
const char* genname_behavior_name(const char* type, const char* name)
163+
{
164+
printbuf_t* buf = printbuf_new();
165+
printbuf(buf, "%s.%s", type, name);
166+
return stringtab_buf(buf);
167+
}
168+
#endif
169+
156170
const char* genname_descriptor(const char* type)
157171
{
158172
return stringtab_two(type, "Desc");

‎src/libponyc/codegen/genname.h

+6
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,12 @@ const char* genname_deserialise(const char* type);
2626

2727
const char* genname_dispatch(const char* type);
2828

29+
#if defined(USE_RUNTIME_TRACING)
30+
const char* genname_get_behavior_name(const char* type);
31+
32+
const char* genname_behavior_name(const char* type, const char* name);
33+
#endif
34+
2935
const char* genname_descriptor(const char* type);
3036

3137
const char* genname_instance(const char* type);

0 commit comments

Comments
 (0)