diff --git a/docs/src/Functions.md b/docs/src/Functions.md index c37ace1..1f8ab9e 100644 --- a/docs/src/Functions.md +++ b/docs/src/Functions.md @@ -1,6 +1,9 @@ # Functions ```@docs +count_precompile_statements( + log::LambdaFunctionInvocationLog, + ) create_lambda_function( remote_image::RemoteImage; role::Union{AWSRole, Nothing} = nothing, @@ -103,8 +106,7 @@ run_local_image_test( ) run_lambda_function_test( func::LambdaFunction, - function_argument::Any = "", - expected_response::Any = nothing; + function_test_data::FunctionTestData; check_function_state::Bool = false, ) run_test( diff --git a/src/Jot.jl b/src/Jot.jl index f726bdc..be4f94c 100644 --- a/src/Jot.jl +++ b/src/Jot.jl @@ -46,6 +46,7 @@ export FunctionTestData export create_environment! export nest_quotes, create_sysimage export FunctionTestData +export count_precompile_statements # CONSTANTS const docker_hash_limit = 12 @@ -204,6 +205,7 @@ function add_scripts_to_build_dir( ) julia_args = [ "--project=.", + "--trace-compile=stderr", ] if package_compile julia_args = vcat(julia_args, ["--sysimage=$SYSIMAGE_FNAME"]) @@ -537,8 +539,7 @@ end """ run_lambda_function_test( func::LambdaFunction, - function_argument::Any = "", - expected_response::Any = nothing; + function_test_data::FunctionTestData; check_function_state::Bool = false, )::Tuple{Bool, Union{Missing, LambdaFunctionInvocationLog}} @@ -549,15 +550,14 @@ pass, establishing only that the function can be contacted. Returns a tuple of ` """ function run_lambda_function_test( func::LambdaFunction, - function_argument::Any = "", - expected_response::Any = nothing; + function_test_data::FunctionTestData; check_function_state::Bool = false, )::Tuple{Bool, Union{Missing, LambdaFunctionInvocationLog}} try actual_response, log = invoke_function_with_log( - function_argument, func; check_state = check_function_state + function_test_data.test_argument, func; check_state = check_function_state ) - passed = actual_response == expected_response + passed = actual_response == function_test_data.expected_response time_taken = get_invocation_run_time(log) passed && @info "Remote test passed in $time_taken ms; result received matched expected $actual_response" !passed && @info "Remote test failed; actual: $actual_response was not equal to expected: $expected_response" diff --git a/src/LambdaFunctionInvocationLog.jl b/src/LambdaFunctionInvocationLog.jl index 0e9ac7c..e92bc95 100644 --- a/src/LambdaFunctionInvocationLog.jl +++ b/src/LambdaFunctionInvocationLog.jl @@ -279,3 +279,20 @@ function get_invocation_run_time(report_event::LogEvent)::Float64 parse(Float64, duration_str) end +""" + count_precompile_statements( + log::LambdaFunctionInvocationLog, + )::Int64 + +Counts the number of precompilation statements that were emitted during the Julia +run-time. If the function has been precompiled or compiled with `PackageCompiler`, +this should be zero. +""" +function count_precompile_statements( + log::LambdaFunctionInvocationLog, + )::Int64 + precompile_events = filter(log.cloudwatch_log_events) do ev + startswith(ev.message, "precompile(") + end + length(precompile_events) +end diff --git a/test/runtests.jl b/test/runtests.jl index 00cf5f4..0accbc3 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -175,7 +175,7 @@ function run_example_simple_test(clean_up::Bool) # ... and test it to see if it's working OK @info "Testing lambda function" @test run_lambda_function_test( - increment_vector_lambda, [2,3,4], [3,4,5]; check_function_state=true + increment_vector_lambda, FunctionTestData([2,3,4], [3,4,5]); check_function_state=true ) |> first end if clean_up @@ -491,6 +491,7 @@ function run_multi_tests( test_data.test_state.remote_image, aws_role, test_data.responder_function_test_args, + test_data.create_local_image_args.use_function_test_data, skip_test_because_running_comparison_test_later, ) end @@ -627,15 +628,14 @@ end function compare_lambda_function_test_times( compiled::LambdaFunction, uncompiled::LambdaFunction, - test_arg::Any, - expected_response::Any, + function_test_data::FunctionTestData, repeat_num::Int64, )::Tuple{Float64, Float64} total_run_time = 0.0 # Throw away first result, it's unrepresentative - _, _ = run_lambda_function_test(compiled, test_arg, expected_response) + _, _ = run_lambda_function_test(compiled, function_test_data) for num = 1:repeat_num - _, test_log = run_lambda_function_test(compiled, test_arg, expected_response) + _, test_log = run_lambda_function_test(compiled, function_test_data) this_run_time = get_invocation_run_time(test_log) @info "Test run $num with compiled local image took $this_run_time" total_run_time += this_run_time @@ -644,9 +644,9 @@ function compare_lambda_function_test_times( @info "Average compiled run time was $average_compiled_run_time" total_run_time = 0.0 # Throw away first result, it's unrepresentative - _, _ = run_lambda_function_test(uncompiled, test_arg, expected_response) + _, _ = run_lambda_function_test(uncompiled, function_test_data) for num = 1:repeat_num - _, test_log = run_lambda_function_test(uncompiled, test_arg, expected_response) + _, test_log = run_lambda_function_test(uncompiled, function_test_data) this_run_time = get_invocation_run_time(test_log) @info "Test run $num with uncompiled local image took $this_run_time" total_run_time += this_run_time @@ -717,6 +717,7 @@ function test_lambda_function( remote_image::RemoteImage, aws_role::AWSRole, responder_function_test_args::ResponderFunctionTestArgs, + use_function_test_data::Bool, skip_test::Bool, )::LambdaFunction lambda_function = create_lambda_function(remote_image; role = aws_role) @@ -725,15 +726,27 @@ function test_lambda_function( # Check that we can find it @test lambda_function in Jot.get_all_lambda_functions() if !skip_test - # Invoke it + # First invocation is exceptional, discard it + _ = run_lambda_function_test( + lambda_function, + to_function_test_data(responder_function_test_args); + check_function_state=true + ) + sleep(5) + # Invoke it again (result, log) = run_lambda_function_test( lambda_function, - responder_function_test_args.good_arg, - responder_function_test_args.expected_response; + to_function_test_data(responder_function_test_args); check_function_state=true ) @test result @info "Lambda function ran in $(get_invocation_run_time(log))" + # Unless FunctionTestData was not passed, check that there are no precopmiles + if use_function_test_data + @test count_precompile_statements(log) == 0 + else + @test count_precompile_statements(log) > 0 + end # Create the same thing using a remote image @test lambda_function == create_lambda_function( remote_image; @@ -762,8 +775,7 @@ function test_compiled_lambda_function( (average_compiled_run_time, average_uncompiled_run_time) = compare_lambda_function_test_times( compiled_lambda_function, uncompiled_lambda_function, - responder_function_test_args.good_arg, - responder_function_test_args.expected_response, + to_function_test_data(responder_function_test_args), repeat_num, ) @test average_compiled_run_time < (average_uncompiled_run_time / 2)