From 4822dd427779abe03cc9e961d6db6162754434d7 Mon Sep 17 00:00:00 2001 From: Lee Danilek Date: Fri, 27 Dec 2024 10:52:31 -0500 Subject: [PATCH] log metric on calling UDF as a js function (#32643) GitOrigin-RevId: 6d857a7d2467ab02a188c8754eb383375d716aee --- crates/isolate/src/metrics.rs | 20 +++++++++++++++++++ crates/isolate/src/ops/console.rs | 8 +++++++- crates/isolate/src/tests/adversarial.rs | 6 +++++- .../src/server/impl/registration_impl.ts | 2 +- 4 files changed, 33 insertions(+), 3 deletions(-) diff --git a/crates/isolate/src/metrics.rs b/crates/isolate/src/metrics.rs index dcc4ce21..b2b66a46 100644 --- a/crates/isolate/src/metrics.rs +++ b/crates/isolate/src/metrics.rs @@ -257,6 +257,26 @@ pub fn op_timer(op_name: &str) -> StatusTimer { t } +register_convex_counter!( + ISOLATE_DIRECT_FUNCTION_CALL_TOTAL, + "Number of calls to registered UDFs as js functions" +); +fn log_direct_function_call() { + log_counter(&ISOLATE_DIRECT_FUNCTION_CALL_TOTAL, 1); +} + +pub fn log_log_line(line: &str) { + // We log a console.warn line containing this link when a function is called + // directly. These are potentially problematic because it looks like arg and + // return values are being validated, and a new isolate is running the UDF, + // but actually the plain JS function is being called. If the non-isolated, + // non-validated behavior is intended, the helper function should be explicit. + if line.contains("https://docs.convex.dev/production/best-practices/#use-helper-functions-to-write-shared-code") { + tracing::warn!("Direct function call detected: '{line}'"); + log_direct_function_call(); + } +} + register_convex_histogram!( UDF_SYSCALL_SECONDS, "Duration of UDF syscall", diff --git a/crates/isolate/src/ops/console.rs b/crates/isolate/src/ops/console.rs index ba7b538c..7087f53d 100644 --- a/crates/isolate/src/ops/console.rs +++ b/crates/isolate/src/ops/console.rs @@ -7,7 +7,10 @@ use common::{ log_lines::LogLevel, }; -use super::OpProvider; +use super::{ + metrics, + OpProvider, +}; #[convex_macro::v8_op] pub fn op_console_message<'b, P: OpProvider<'b>>( @@ -15,6 +18,9 @@ pub fn op_console_message<'b, P: OpProvider<'b>>( level: String, messages: Vec, ) -> anyhow::Result<()> { + for message in messages.iter() { + metrics::log_log_line(message); + } provider.trace(level.parse()?, messages)?; Ok(()) } diff --git a/crates/isolate/src/tests/adversarial.rs b/crates/isolate/src/tests/adversarial.rs index 9d0a8eb8..846a346e 100644 --- a/crates/isolate/src/tests/adversarial.rs +++ b/crates/isolate/src/tests/adversarial.rs @@ -920,6 +920,10 @@ async fn test_invoke_function_directly(rt: TestRuntime) -> anyhow::Result<()> { .pop() .unwrap() .to_pretty_string_test_only(); - assert_contains(&log_line, "[WARN] 'Do not call Convex functions directly."); + assert_contains( + &log_line, + "[WARN] 'Convex functions should not directly call other Convex functions. Consider \ + calling a helper function instead.", + ); Ok(()) } diff --git a/npm-packages/convex/src/server/impl/registration_impl.ts b/npm-packages/convex/src/server/impl/registration_impl.ts index 4ac0eebe..69846d66 100644 --- a/npm-packages/convex/src/server/impl/registration_impl.ts +++ b/npm-packages/convex/src/server/impl/registration_impl.ts @@ -90,7 +90,7 @@ function dontCallDirectly( ) { return (ctx: any, args: any) => { globalThis.console.warn( - "Do not call Convex functions directly. " + + "Convex functions should not directly call other Convex functions. Consider calling a helper function instead. " + `e.g. \`export const foo = ${funcType}(...); await foo(ctx);\` is not supported. ` + "See https://docs.convex.dev/production/best-practices/#use-helper-functions-to-write-shared-code", );