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