Line data Source code
1 : #ifndef HEADER_fd_src_flamenco_log_collector_fd_log_collector_h
2 : #define HEADER_fd_src_flamenco_log_collector_fd_log_collector_h
3 :
4 : #include "fd_log_collector_base.h"
5 : #include "../runtime/context/fd_exec_instr_ctx.h"
6 : #include "../runtime/context/fd_exec_txn_ctx.h"
7 : #include "../../ballet/base58/fd_base58.h"
8 : #include "../../ballet/base64/fd_base64.h"
9 : #include <stdio.h>
10 : #include <stdarg.h>
11 :
12 : /* Log collector + stable log implementations.
13 : https://github.com/anza-xyz/agave/blob/v2.0.6/program-runtime/src/log_collector.rs
14 : https://github.com/anza-xyz/agave/blob/v2.0.6/program-runtime/src/stable_log.rs */
15 :
16 : /* INTERNALS
17 : Internal functions, don't use directly. */
18 :
19 12 : #define FD_EXEC_LITERAL(STR) ("" STR), (sizeof(STR)-1)
20 :
21 : /* fd_log_collector_private_push pushes a log (internal, don't use directly).
22 :
23 : This function stores a log msg of size msg_sz, serialized as protobuf.
24 : For the high-level functionality, see fd_log_collector_msg().
25 :
26 : Internally, each log msg is serialized as a 1 byte tag + 1 or 2 bytes
27 : msg_sz (variable int < 32768) + msg_sz bytes of the actual msg.
28 :
29 : | tag | msg_sz | msg |
30 : | 1-byte | 1-or-2 bytes | msg_sz bytes |
31 :
32 : The advantage of this representation is that when we have to store
33 : txn metadata in blockstore, we don't have to do any conversion for logs,
34 : just copy the entire buffer. */
35 : static inline void
36 : fd_log_collector_private_push( fd_log_collector_t * log,
37 : char const * msg,
38 15 : ulong msg_sz ) {
39 15 : uchar * buf = log->buf;
40 15 : ulong buf_sz = log->buf_sz;
41 :
42 : /* Store tag + msg_sz */
43 15 : ulong needs_2b = (msg_sz>0x7F);
44 15 : buf[ buf_sz ] = FD_LOG_COLLECTOR_PROTO_TAG;
45 15 : buf[ buf_sz+1 ] = (uchar)( (msg_sz&0x7F) | (needs_2b<<7) );
46 15 : buf[ buf_sz+2 ] = (uchar)( (msg_sz>>7) & 0x7F ); /* This gets overwritten if 0 */
47 :
48 : /* Copy msg and update total buf_sz */
49 15 : ulong msg_start = buf_sz + 2 + needs_2b;
50 15 : fd_memcpy( buf + msg_start, msg, msg_sz );
51 15 : log->buf_sz = (ushort)( msg_start + msg_sz );
52 15 : }
53 :
54 : /* fd_log_collector_private_debug prints all logs (internal, don't use directly). */
55 : static inline void
56 : fd_log_collector_private_debug( fd_log_collector_t const * log );
57 :
58 : FD_PROTOTYPES_BEGIN
59 :
60 : /* LOG COLLECTOR API
61 : Init, delete... */
62 :
63 : /* fd_log_collector_init initializes a log collector. */
64 : static inline void
65 12 : fd_log_collector_init( fd_log_collector_t * log, int enabled ) {
66 12 : log->buf_sz = 0;
67 12 : log->log_sz = 0;
68 12 : log->warn = 0;
69 12 : log->disabled = !enabled;
70 12 : }
71 :
72 : static inline ulong
73 : fd_log_collector_check_and_truncate( fd_log_collector_t * log,
74 27 : ulong msg_sz ) {
75 27 : ulong bytes_written = fd_ulong_sat_add( log->log_sz, msg_sz );
76 27 : int ret = bytes_written >= FD_LOG_COLLECTOR_MAX;
77 27 : if( FD_UNLIKELY( ret ) ) {
78 3 : if( FD_UNLIKELY( !log->warn ) ) {
79 3 : log->warn = 1;
80 3 : fd_log_collector_private_push( log, FD_EXEC_LITERAL( "Log truncated" ) );
81 3 : }
82 3 : return ULONG_MAX;
83 3 : }
84 24 : return bytes_written;
85 27 : }
86 :
87 : /* fd_log_collector_delete deletes a log collector. */
88 : static inline void
89 0 : fd_log_collector_delete( fd_log_collector_t const * log ) {
90 0 : (void)log;
91 0 : }
92 :
93 : /* LOG COLLECTOR MSG API
94 :
95 : Analogous of Agave's ic_msg!():
96 : https://github.com/anza-xyz/agave/blob/v2.0.6/program-runtime/src/log_collector.rs
97 :
98 : - fd_log_collector_msg
99 : - fd_log_collector_msg_literal
100 : - fd_log_collector_msg_many
101 : - fd_log_collector_printf_*
102 : */
103 :
104 : /* fd_log_collector_msg logs msg of size msg_sz.
105 : This is analogous to Agave's ic_msg!() / ic_logger_msg!().
106 :
107 : Logs are not recorded on-chain, and are therefore not
108 : consensus-critical, however, there exist 3rd party off-chain
109 : applications that parses logs, and expects logs to be equivalent to
110 : agave.
111 :
112 : msg is expected to be a valid utf8 string, it is the responsibility
113 : of the caller to enforce that. msg doesn't have to be \0 terminated
114 : and can contain \0 within. Most logs are cstr, base58/64, so
115 : they are utf8. For an example of log from user input, see the
116 : sol_log_() syscall where we use fd_utf8_verify().
117 :
118 : if msg is a cstr, for compatibility with rust, msg_sz is the msg
119 : length (not the size of the buffer), and the final \0 should not
120 : be included in logs. For literals, use
121 : fd_log_collector_msg_literal().
122 :
123 : msg_sz==0 is ok, however, it's important to understand that log
124 : collector is an interface to developers, not exposed to users.
125 : Users can, for example, log inside BPF programs using msg!(), that
126 : gets translated to the syscall sol_log_(), that in turn appends
127 : a log of the form "Program log: ...". So msg_sz, realistically,
128 : is never 0 nor small. This is important for our implementation,
129 : to keep serialization overhead low.
130 :
131 : When msg consists of multiple disjoint buffers, we should use
132 : fd_log_collector_msg_many(), and implement more variants as
133 : needed. The core idea is very simple: we know the total msg_sz,
134 : we decide if the log needs to be included or truncated, and
135 : if we include the logs we will copy the actual content
136 : from multiple places. This should be the correct and high
137 : performance way to log.
138 :
139 : For ease of development, and because logs in runtime, vm,
140 : syscalls, native programs, etc. are what they are, we also
141 : implemented fd_log_collector_printf_*(). These are
142 : dangerous to use, especially given the way we serialize
143 : logs on-the-fly. Prefer fd_log_collector_msg_* wherever
144 : possible. */
145 : static inline void
146 : fd_log_collector_msg( fd_exec_instr_ctx_t * ctx,
147 : char const * msg,
148 12 : ulong msg_sz ) {
149 12 : fd_log_collector_t * log = &ctx->txn_ctx->log_collector;
150 12 : if( FD_LIKELY( log->disabled ) ) {
151 0 : return;
152 0 : }
153 :
154 12 : ulong bytes_written = fd_log_collector_check_and_truncate( log, msg_sz );
155 12 : if( FD_LIKELY( bytes_written < ULONG_MAX ) ) {
156 12 : log->log_sz = (ushort)bytes_written;
157 12 : fd_log_collector_private_push( log, msg, msg_sz );
158 12 : }
159 12 : }
160 :
161 : /* fd_log_collector_msg_literal logs the literal (const cstr) msg,
162 : handling size. See fd_log_collector_msg() for details. */
163 9 : #define fd_log_collector_msg_literal( ctx, log ) fd_log_collector_msg( ctx, FD_EXEC_LITERAL( log ) )
164 :
165 : /* fd_log_collector_msg_many logs a msg supplied as many
166 : buffers. msg := msg0 | msg1 | ... | msgN
167 :
168 : num_buffers informs the number of (char const * msg, ulong sz) pairs
169 : in the function call.
170 : NOTE: you must explicitly pass in ulong values for sz, either by cast
171 : or with the UL literal. va_args behaves weirdly otherwise */
172 : static inline void
173 9 : fd_log_collector_msg_many( fd_exec_instr_ctx_t * ctx, int num_buffers, ... ) {
174 9 : fd_log_collector_t * log = &ctx->txn_ctx->log_collector;
175 9 : if( FD_LIKELY( log->disabled ) ) {
176 0 : return;
177 0 : }
178 :
179 9 : va_list args;
180 9 : va_start( args, num_buffers );
181 :
182 : /* Calculate the total message size and check for overflow */
183 9 : ulong msg_sz = 0;
184 27 : for( int i = 0; i < num_buffers; i++ ) {
185 18 : va_arg( args, char const * );
186 18 : ulong msg_sz_part = va_arg( args, ulong );
187 18 : msg_sz = fd_ulong_sat_add( msg_sz, msg_sz_part );
188 18 : }
189 9 : va_end( args );
190 9 : ulong bytes_written = fd_log_collector_check_and_truncate( log, msg_sz );
191 9 : if( FD_LIKELY( bytes_written < ULONG_MAX ) ) {
192 6 : log->log_sz = (ushort)bytes_written;
193 :
194 6 : uchar * buf = log->buf;
195 6 : ulong buf_sz = log->buf_sz;
196 :
197 : /* Store tag + msg_sz */
198 6 : ulong needs_2b = (msg_sz>0x7F);
199 6 : buf[ buf_sz ] = FD_LOG_COLLECTOR_PROTO_TAG;
200 6 : buf[ buf_sz+1 ] = (uchar)( (msg_sz&0x7F) | (needs_2b<<7) );
201 6 : buf[ buf_sz+2 ] = (uchar)( (msg_sz>>7) & 0x7F ); /* This gets overwritten if 0 */
202 :
203 : /* Copy all messages and update total buf_sz */
204 6 : ulong buf_start = buf_sz + 2 + needs_2b;
205 6 : ulong offset = buf_start;
206 :
207 6 : va_start(args, num_buffers); // Restart argument list traversal
208 18 : for (int i = 0; i < num_buffers; i++) {
209 12 : char const *msg = va_arg( args, char const * );
210 12 : ulong msg_sz_part = va_arg( args, ulong );
211 12 : fd_memcpy( buf + offset, msg, msg_sz_part );
212 12 : offset += msg_sz_part;
213 12 : }
214 6 : va_end(args);
215 6 : log->buf_sz = (ushort)offset;
216 6 : }
217 9 : }
218 :
219 3 : #define FD_LOG_COLLECTOR_PRINTF_MAX_1B 128
220 0 : #define FD_LOG_COLLECTOR_PRINTF_MAX_2B 2000
221 : FD_STATIC_ASSERT( 2*FD_LOG_COLLECTOR_PRINTF_MAX_2B <= FD_LOG_COLLECTOR_EXTRA, "Increase FD_LOG_COLLECTOR_EXTRA" );
222 :
223 : /* fd_log_collector_printf_dangerous_max_127() logs a message
224 : supplied as a formatting string with params.
225 :
226 : This is dangerous and should only be used when we can
227 : guarantee that the total log msg_sz <= 127.
228 :
229 : See also fd_log_collector_printf_dangerous_128_to_2k() for
230 : larger logs, and see fd_log_collector_program_return() for
231 : an example on how to deal with msg_sz.
232 :
233 : This implementation uses vsnprintf() to directly write into
234 : the log buf *before* deciding if the log should be included
235 : or not. As a result of vsnprintf() we get msg_sz, and then
236 : we can decide to actually insert the log or truncate. Since
237 : we serialize msg_sz as a variable int, we must guarantee
238 : that msg_sz <= 127, i.e. fits in 1 byte, otherwise we'd have
239 : to memmove the log msg. */
240 : __attribute__ ((format (printf, 2, 3)))
241 : static inline void
242 : fd_log_collector_printf_dangerous_max_127( fd_exec_instr_ctx_t * ctx,
243 3 : char const * fmt, ... ) {
244 3 : fd_log_collector_t * log = &ctx->txn_ctx->log_collector;
245 3 : if( FD_LIKELY( log->disabled ) ) {
246 0 : return;
247 0 : }
248 :
249 3 : uchar * buf = log->buf;
250 3 : ulong buf_sz = log->buf_sz;
251 :
252 : /* Store the log at buf_sz+2 (1 byte tag + 1 byte msg_sz), and retrieve
253 : the final msg_sz. */
254 3 : va_list ap;
255 3 : va_start( ap, fmt );
256 3 : int res = vsnprintf( (char *)(buf + buf_sz + 2), FD_LOG_COLLECTOR_PRINTF_MAX_1B, fmt, ap );
257 3 : va_end( ap );
258 :
259 : /* We use vsnprintf to protect against oob writes, however, it should
260 : never truncate. If truncate happens, it means that we're using
261 : fd_log_collector_printf_dangerous_max_127(), incorrectly for
262 : example with a "%s" and an unbound variable (user input, var that's
263 : not null-terminated cstr, ...).
264 : We MUST only use fd_log_collector_printf_dangerous_max_127()
265 : as a convenience method, when we can guarantee that the total
266 : msg_sz is bound by FD_LOG_COLLECTOR_PRINTF_MAX_1B. */
267 3 : FD_TEST_CUSTOM( res>=0 && res<FD_LOG_COLLECTOR_PRINTF_MAX_1B,
268 3 : "A transaction log was truncated unexpectedly. Please report to developers." );
269 :
270 : /* Decide if we should include the log or truncate. */
271 3 : ulong msg_sz = (ulong)res;
272 3 : ulong bytes_written = fd_log_collector_check_and_truncate( log, msg_sz );
273 3 : if( FD_LIKELY( bytes_written < ULONG_MAX ) ) {
274 : /* Insert log: store tag + msg_sz (1 byte) and update buf_sz */
275 3 : log->log_sz = (ushort)bytes_written;
276 3 : buf[ buf_sz ] = FD_LOG_COLLECTOR_PROTO_TAG;
277 3 : buf[ buf_sz+1 ] = (uchar)( msg_sz & 0x7F );
278 3 : log->buf_sz = (ushort)( buf_sz + msg_sz + 2 );
279 3 : }
280 3 : }
281 :
282 : /* fd_log_collector_printf_dangerous_128_to_2k() logs a message
283 : supplied as a formatting string with params.
284 :
285 : This is dangerous and should only be used when we can
286 : guarantee that the total log 128 <= msg_sz < 2,000.
287 :
288 : This implementation uses vsnprintf() to directly write into
289 : the log buf *before* deciding if the log should be included
290 : or not. As a result of vsnprintf() we get msg_sz, and then
291 : we can decide to actually insert the log or truncate. Since
292 : we serialize msg_sz as a variable int, we must guarantee
293 : that 128 <= msg_sz < 32758, i.e. fits in 2 byte, otherwise
294 : we'd have to memmove the log msg.
295 :
296 : Moreover, we need to guarantee that the log buf is big enough
297 : to fit the log msg. Hence we further limit msg_sz < 2000. */
298 : __attribute__ ((format (printf, 2, 3)))
299 : static inline void
300 : fd_log_collector_printf_dangerous_128_to_2k( fd_exec_instr_ctx_t * ctx,
301 0 : char const * fmt, ... ) {
302 0 : fd_log_collector_t * log = &ctx->txn_ctx->log_collector;
303 0 : if( FD_LIKELY( log->disabled ) ) {
304 0 : return;
305 0 : }
306 :
307 0 : uchar * buf = log->buf;
308 0 : ulong buf_sz = log->buf_sz;
309 :
310 : /* Store the log at buf_sz+3 (1 byte tag + 2 bytes msg_sz), and retrieve
311 : the final msg_sz. */
312 0 : va_list ap;
313 0 : va_start( ap, fmt );
314 0 : int res = vsnprintf( (char *)(buf + buf_sz + 3), FD_LOG_COLLECTOR_PRINTF_MAX_2B, fmt, ap );
315 0 : va_end( ap );
316 : /* We use vsnprintf to protect against oob writes, however it should
317 : never truncate. If truncate happens, it means that we're using
318 : fd_log_collector_printf_dangerous_max_127(), incorrectly for
319 : example with a "%s" and an unbound variable (user input, var that's
320 : not null-terminated cstr, ...).
321 : We MUST only use fd_log_collector_printf_dangerous_max_128_to_2k()
322 : as a convenience method, when we can guarantee that the total
323 : msg_sz is bound by FD_LOG_COLLECTOR_PRINTF_MAX_2B. */
324 0 : FD_TEST_CUSTOM( res>=FD_LOG_COLLECTOR_PRINTF_MAX_1B && res<FD_LOG_COLLECTOR_PRINTF_MAX_2B,
325 0 : "A transaction log was truncated unexpectedly. Please report to developers." );
326 :
327 : /* Decide if we should include the log or truncate. */
328 0 : ulong msg_sz = (ulong)res;
329 0 : ulong bytes_written = fd_log_collector_check_and_truncate( log, msg_sz );
330 0 : if( FD_LIKELY( bytes_written < ULONG_MAX ) ) {
331 : /* Insert log: store tag + msg_sz (2 bytes) and update buf_sz */
332 0 : log->log_sz = (ushort)bytes_written;
333 0 : buf[ buf_sz ] = FD_LOG_COLLECTOR_PROTO_TAG;
334 0 : buf[ buf_sz+1 ] = (uchar)( (msg_sz&0x7F) | (1<<7) );
335 0 : buf[ buf_sz+2 ] = (uchar)( (msg_sz>>7) & 0x7F );
336 0 : log->buf_sz = (ushort)( buf_sz + msg_sz + 3 );
337 0 : }
338 0 : }
339 :
340 : /* fd_log_collector_printf_inefficient_max_512() logs a message
341 : supplied as a formatting string with params.
342 :
343 : This is inefficient because it uses an external buffer and
344 : essentially does 2 memcpy instead of 1, however it reduces
345 : the complexity when msg_sz can be below or above 127, for
346 : example in many error messages where we have to print 2
347 : pubkeys. */
348 : __attribute__ ((format (printf, 2, 3)))
349 : static inline void
350 : fd_log_collector_printf_inefficient_max_512( fd_exec_instr_ctx_t * ctx,
351 0 : char const * fmt, ... ) {
352 0 : char msg[ 512 ];
353 :
354 0 : va_list ap;
355 0 : va_start( ap, fmt );
356 0 : int msg_sz = vsnprintf( msg, sizeof(msg), fmt, ap );
357 0 : va_end( ap );
358 :
359 0 : FD_TEST_CUSTOM( msg_sz>=0 && (ulong)msg_sz<sizeof(msg),
360 0 : "A transaction log was truncated unexpectedly. Please report to developers." );
361 :
362 0 : fd_log_collector_msg( ctx, msg, (ulong)msg_sz );
363 0 : }
364 :
365 : /* STABLE LOG
366 :
367 : Analogous of Agave's stable_log interface:
368 : https://github.com/anza-xyz/agave/blob/v2.0.6/program-runtime/src/stable_log.rs
369 :
370 : - program_invoke
371 : - program_log
372 : - program_data -- implemented in fd_vm_syscall_sol_log_data()
373 : - program_return
374 : - program_success
375 : - program_failure
376 : - program_consumed */
377 :
378 : /* fd_log_collector_program_invoke logs:
379 : "Program <ProgramIdBase58> invoke [<n>]"
380 :
381 : This function is called at the beginning of every instruction.
382 : Other logs (notably success/failure) also write <ProgramIdBase58>,
383 : so this function precomputes it and stores it inside the instr_ctx. */
384 : static inline void
385 0 : fd_log_collector_program_invoke( fd_exec_instr_ctx_t * ctx ) {
386 0 : if( FD_LIKELY( ctx->txn_ctx->log_collector.disabled ) ) {
387 0 : return;
388 0 : }
389 :
390 0 : fd_pubkey_t const * program_id_pubkey = &ctx->txn_ctx->account_keys[ ctx->instr->program_id ];
391 : /* Cache ctx->program_id_base58 */
392 0 : fd_base58_encode_32( program_id_pubkey->uc, NULL, ctx->program_id_base58 );
393 : /* Max msg_sz: 22 - 4 + 44 + 10 = 72 < 127 => we can use printf */
394 0 : fd_log_collector_printf_dangerous_max_127( ctx, "Program %s invoke [%u]", ctx->program_id_base58, ctx->txn_ctx->instr_stack_sz );
395 0 : }
396 :
397 : /* fd_log_collector_program_log logs:
398 : "Program log: <msg>"
399 :
400 : msg must be a valid utf8 string, it's responsibility of the caller to
401 : validate that. This is the implementation underlying the _sol_log()
402 : syscall. */
403 : static inline void
404 9 : fd_log_collector_program_log( fd_exec_instr_ctx_t * ctx, char const * msg, ulong msg_sz ) {
405 9 : fd_log_collector_msg_many( ctx, 2, "Program log: ", 13UL, msg, msg_sz );
406 9 : }
407 :
408 : /* fd_log_collector_program_return logs:
409 : "Program return: <ProgramIdBase58> <dataAsBase64>"
410 :
411 : Since return data is at most 1024 bytes, it's base64 representation is
412 : at most 1368 bytes and msg_sz is known in advance, thus we can use
413 : fd_log_collector_printf_*.
414 :
415 : TODO: implement based on fd_log_collector_msg_many(). */
416 : static inline void
417 0 : fd_log_collector_program_return( fd_exec_instr_ctx_t * ctx ) {
418 0 : if( FD_LIKELY( ctx->txn_ctx->log_collector.disabled ) ) {
419 0 : return;
420 0 : }
421 :
422 : /* ctx->txn_ctx->return_data is 1024 bytes max, so its base64 repr
423 : is at most (1024+2)/3*4 bytes, plus we use 1 byte for \0. */
424 0 : char return_base64[ (sizeof(ctx->txn_ctx->return_data.data)+2)/3*4+1 ];
425 0 : ulong sz = fd_base64_encode( return_base64, ctx->txn_ctx->return_data.data, ctx->txn_ctx->return_data.len );
426 0 : return_base64[ sz ] = 0;
427 : /* Max msg_sz: 21 - 4 + 44 + 1368 = 1429 < 1500 => we can use printf, but have to handle sz */
428 0 : ulong msg_sz = 17 + strlen(ctx->program_id_base58) + sz;
429 0 : if( msg_sz<=127 ) {
430 0 : fd_log_collector_printf_dangerous_max_127( ctx, "Program return: %s %s", ctx->program_id_base58, return_base64 );
431 0 : } else {
432 0 : fd_log_collector_printf_dangerous_128_to_2k( ctx, "Program return: %s %s", ctx->program_id_base58, return_base64 );
433 0 : }
434 0 : }
435 :
436 : /* fd_log_collector_program_success logs:
437 : "Program <ProgramIdBase58> success" */
438 : static inline void
439 0 : fd_log_collector_program_success( fd_exec_instr_ctx_t * ctx ) {
440 : /* Max msg_sz: 18 - 2 + 44 = 60 < 127 => we can use printf */
441 0 : fd_log_collector_printf_dangerous_max_127( ctx, "Program %s success", ctx->program_id_base58 );
442 0 : }
443 :
444 : /* fd_log_collector_program_success logs:
445 : "Program <ProgramIdBase58> failed: <err>"
446 :
447 : This function handles the logic to log the correct msg, based
448 : on the type of error (InstructionError, SyscallError...).
449 : https://github.com/anza-xyz/agave/blob/v2.0.6/program-runtime/src/invoke_context.rs#L535-L549
450 :
451 : The error msg is obtained by external functions, e.g. fd_vm_syscall_strerror(),
452 : and can be either a valid msg or an empty string. Empty string represents
453 : special handling of the error log, for example the syscall panic logs directly
454 : the result, and therefore can be skipped at this stage. */
455 : static inline void
456 0 : fd_log_collector_program_failure( fd_exec_instr_ctx_t * ctx ) {
457 0 : if( FD_LIKELY( ctx->txn_ctx->log_collector.disabled ) ) {
458 0 : return;
459 0 : }
460 :
461 0 : extern char const * fd_vm_ebpf_strerror( int err );
462 0 : extern char const * fd_vm_syscall_strerror( int err );
463 0 : extern char const * fd_executor_instr_strerror( int err );
464 :
465 0 : char custom_err[33] = { 0 };
466 0 : const char * err = custom_err;
467 0 : const fd_exec_txn_ctx_t * txn_ctx = ctx->txn_ctx;
468 0 : if( FD_UNLIKELY( txn_ctx->exec_err_kind==FD_EXECUTOR_ERR_KIND_INSTR &&
469 0 : txn_ctx->exec_err==FD_EXECUTOR_INSTR_ERR_CUSTOM_ERR ) ) {
470 : /* Max msg_sz = 32 <= 66 */
471 0 : snprintf( custom_err, sizeof(custom_err), "custom program error: 0x%x", txn_ctx->custom_err );
472 0 : } else if( txn_ctx->exec_err ) {
473 0 : switch( txn_ctx->exec_err_kind ) {
474 0 : case FD_EXECUTOR_ERR_KIND_SYSCALL:
475 0 : err = fd_vm_syscall_strerror( txn_ctx->exec_err );
476 0 : break;
477 0 : case FD_EXECUTOR_ERR_KIND_INSTR:
478 0 : err = fd_executor_instr_strerror( txn_ctx->exec_err );
479 0 : break;
480 0 : default:
481 0 : err = fd_vm_ebpf_strerror( txn_ctx->exec_err );
482 0 : }
483 0 : }
484 :
485 : /* Skip empty string, this means that the msg has already been logged. */
486 0 : if( FD_LIKELY( err[0] ) ) {
487 0 : char err_prefix[ 17+FD_BASE58_ENCODED_32_SZ ]; // 17==strlen("Program failed: ")
488 0 : int err_prefix_len = sprintf( err_prefix, "Program %s failed: ", ctx->program_id_base58 );
489 0 : if( err_prefix_len > 0 ) {
490 : /* Equivalent to: "Program %s failed: %s" */
491 0 : fd_log_collector_msg_many( ctx, 2, err_prefix, (ulong)err_prefix_len, err, (ulong)strlen(err) );
492 0 : }
493 0 : }
494 0 : }
495 :
496 : /* fd_log_collector_program_consumed logs:
497 : "Program <ProgramIdBase58> consumed <consumed> of <tota> compute units" */
498 : static inline void
499 0 : fd_log_collector_program_consumed( fd_exec_instr_ctx_t * ctx, ulong consumed, ulong total ) {
500 : /* Max msg_sz: 44 - 8 + 44 + 20 + 20 = 120 < 127 => we can use printf */
501 0 : fd_log_collector_printf_dangerous_max_127( ctx, "Program %s consumed %lu of %lu compute units", ctx->program_id_base58, consumed, total );
502 0 : }
503 :
504 : /* DEBUG
505 : Only used for testing (inefficient but ok). */
506 :
507 : static inline ushort
508 57 : fd_log_collector_debug_get_msg_sz( uchar const ** buf ) {
509 57 : uchar msg0 = (*buf)[1];
510 57 : uchar msg1 = (*buf)[2]; /* This is never oob */
511 57 : int needs_2b = (msg0>0x7F);
512 57 : ushort msg_sz = fd_ushort_if( needs_2b, (ushort)(((ushort)(msg1) << 7)|(msg0 & 0x7F)), (ushort)msg0 );
513 57 : *buf += 2 + needs_2b;
514 57 : return msg_sz;
515 57 : }
516 :
517 : static inline ulong
518 30 : fd_log_collector_debug_len( fd_log_collector_t const * log ) {
519 30 : ulong len = 0;
520 63 : for( uchar const * cur = log->buf; cur < log->buf + log->buf_sz; ) {
521 33 : ushort cur_sz = fd_log_collector_debug_get_msg_sz( &cur );
522 33 : cur += cur_sz;
523 33 : ++len;
524 33 : }
525 30 : return len;
526 30 : }
527 :
528 : static inline uchar const *
529 : fd_log_collector_debug_get( fd_log_collector_t const * log,
530 : ulong log_num,
531 : uchar const ** msg,
532 15 : ulong * msg_sz ) {
533 15 : uchar const * cur = log->buf;
534 15 : ushort cur_sz = 0;
535 :
536 15 : cur_sz = fd_log_collector_debug_get_msg_sz( &cur );
537 24 : while( log_num>0 ) {
538 9 : cur += cur_sz;
539 9 : cur_sz = fd_log_collector_debug_get_msg_sz( &cur );
540 9 : --log_num;
541 9 : }
542 15 : if( msg ) *msg = cur;
543 15 : if( msg_sz ) *msg_sz = cur_sz;
544 15 : return cur;
545 15 : }
546 :
547 : static inline ulong
548 : fd_log_collector_debug_sprintf( fd_log_collector_t const * log,
549 : char * out,
550 0 : int filter_zero ) {
551 0 : ulong out_sz = 0;
552 :
553 0 : ulong pos = 0;
554 0 : uchar const * buf = log->buf;
555 0 : while( pos < log->buf_sz ) {
556 : /* Read cur string sz */
557 0 : ushort cur_sz = fd_log_collector_debug_get_msg_sz( &buf );
558 :
559 : /* Copy string and add \n.
560 : Slow version of memcpy that skips \0, because a \0 can be in logs.
561 : Equivalent to:
562 : fd_memcpy( out + out_sz, buf, cur_sz ); out_sz += cur_sz; */
563 0 : if( filter_zero ) {
564 0 : for( ulong i=0; i<cur_sz; i++ ) {
565 0 : if( buf[i] ) {
566 0 : out[ out_sz++ ] = (char)buf[i];
567 0 : }
568 0 : }
569 0 : } else {
570 0 : fd_memcpy( out+out_sz, buf, cur_sz );
571 0 : out_sz += cur_sz;
572 0 : }
573 0 : out[ out_sz++ ] = '\n';
574 :
575 : /* Move to next str */
576 0 : buf += cur_sz;
577 0 : pos = (ulong)(buf - log->buf);
578 0 : }
579 :
580 : /* Remove the last \n, or return empty cstr */
581 0 : out_sz = out_sz ? out_sz-1 : 0;
582 0 : out[ out_sz ] = '\0';
583 0 : return out_sz;
584 0 : }
585 :
586 : static inline void
587 0 : fd_log_collector_private_debug( fd_log_collector_t const * log ) {
588 0 : char out[FD_LOG_COLLECTOR_MAX + FD_LOG_COLLECTOR_EXTRA];
589 0 : fd_log_collector_debug_sprintf( log, out, 1 );
590 0 : FD_LOG_WARNING(( "\n-----\n%s\n-----", out ));
591 0 : }
592 :
593 : FD_PROTOTYPES_END
594 :
595 : #endif /* HEADER_fd_src_flamenco_log_collector_fd_log_collector_h */
|
