Skip to content

Commit

Permalink
Add request_id to aws lambda invocation (#23616)
Browse files Browse the repository at this point in the history
This will make it easier to match logs from backend with logs from AWS.

GitOrigin-RevId: f7cd98db3adbc5dac3c58302ed4e85934b35c28a
  • Loading branch information
Preslav Le authored and Convex, Inc. committed Mar 20, 2024
1 parent 1bfca5b commit 27ab48f
Show file tree
Hide file tree
Showing 2 changed files with 18 additions and 22 deletions.
39 changes: 17 additions & 22 deletions crates/node_executor/src/executor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -117,6 +117,7 @@ pub trait NodeExecutor: Sync + Send {
pub struct InvokeResponse {
pub response: JsonValue,
pub memory_used_in_mb: u64,
pub aws_request_id: Option<String>,
}

#[derive(Clone)]
Expand Down Expand Up @@ -211,6 +212,7 @@ impl Actions {
let InvokeResponse {
response,
memory_used_in_mb,
aws_request_id,
} = self.executor.invoke(request, log_line_sender).await?;
let execute_result = ExecuteResponse::try_from(response.clone()).map_err(|e| {
anyhow::anyhow!(
Expand All @@ -220,34 +222,17 @@ impl Actions {
)
})?;

// TODO - remove this trace once we've stabilized perf a bit. Don't need
// to spawn info logs for every action invocation.
tracing::info!(
"Total:{:?}, executor:{:?}, download:{:?}, import:{:?}, udf:{:?}, env_invocations:{:?}",
"Total:{:?}, executor:{:?}, download:{:?}, import:{:?}, udf:{:?}, \
env_invocations:{:?}, aws_request_id:{:?}",
timer.elapsed(),
execute_result.total_executor_time,
execute_result.download_time,
execute_result.import_time,
execute_result.udf_time,
execute_result.num_invocations,
aws_request_id,
);
// Debug print out in a prettier way with indentation showing subsections
tracing::debug!(
#[rustfmt::skip]
" Execute action took {:?}\n\
| - total executor time {:?}\n\
| - download time {:?}\n\
| - import time {:?}\n\
| - udf time {:?}\n\
Env Invocations: {:?}",
timer.elapsed(),
execute_result.total_executor_time,
execute_result.download_time,
execute_result.import_time,
execute_result.udf_time,
execute_result.num_invocations,
);

let total_time = timer.finish();
if let Some(download_time) = execute_result.download_time {
log_download_time(download_time);
Expand Down Expand Up @@ -303,6 +288,7 @@ impl Actions {
let InvokeResponse {
response,
memory_used_in_mb: _,
aws_request_id,
} = self.executor.invoke(request, log_line_sender).await?;
let response: BuildDepsResponse =
serde_json::from_value(response.clone()).map_err(|e| {
Expand Down Expand Up @@ -339,7 +325,11 @@ impl Actions {
},
};

tracing::info!("build_deps took {:?}", timer.elapsed());
tracing::info!(
"build_deps took {:?}. aws_request_id={:?}",
timer.elapsed(),
aws_request_id
);
timer.finish();

result
Expand All @@ -357,6 +347,7 @@ impl Actions {
let InvokeResponse {
response,
memory_used_in_mb: _,
aws_request_id,
} = self.executor.invoke(request, log_line_sender).await?;
let response: AnalyzeResponse = serde_json::from_value(response.clone()).map_err(|e| {
anyhow::anyhow!(
Expand All @@ -365,7 +356,11 @@ impl Actions {
response
)
})?;
tracing::info!("Analyze took {:?}", timer.elapsed());
tracing::info!(
"Analyze took {:?}. aws_request_id={:?}",
timer.elapsed(),
aws_request_id
);
timer.finish();

let modules = match response {
Expand Down
1 change: 1 addition & 0 deletions crates/node_executor/src/local.rs
Original file line number Diff line number Diff line change
Expand Up @@ -169,6 +169,7 @@ impl NodeExecutor for LocalNodeExecutor {
response,
// constant is good enough for measuring local executor
memory_used_in_mb: 512,
aws_request_id: None,
})
}

Expand Down

0 comments on commit 27ab48f

Please sign in to comment.