mirror of
https://github.com/fluencelabs/aquavm
synced 2024-12-04 07:10:18 +00:00
feat(aquavm-air-cli,performance_metering): memory size in performance report (#600)
* chore(bench): update benchmark data After recent data format changes. * feat(aquavm-air-cli): send memory size to logger * feat(performance_metering): report memory size `performance_metering` collects memory sizes reported by `air run` and reports minimal and maximal values.
This commit is contained in:
Ivan Boldyrev
GitHub
parent
f11ee86baa
commit
93c6899429
1
Cargo.lock
generated
1
Cargo.lock
generated
@ -357,6 +357,7 @@ dependencies = [
|
||||
"serde",
|
||||
"serde_json",
|
||||
"termcolor",
|
||||
"tracing",
|
||||
"tracing-subscriber",
|
||||
]
|
||||
|
||||
|
||||
@ -1498,122 +1498,110 @@
|
||||
"benches": {
|
||||
"big_values_data": {
|
||||
"comment": "Loading a trace with huge values",
|
||||
"memory_sizes": [
|
||||
"58.000 MiB",
|
||||
"58.000 MiB"
|
||||
],
|
||||
"stats": {
|
||||
"air::runner::execute_air": {
|
||||
"common_prefix": "air",
|
||||
"duration": "34.61ms",
|
||||
"duration": "8.88ms",
|
||||
"nested": {
|
||||
"farewell_step::outcome::from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "10.10ms",
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "4.82ms",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "8.30ms",
|
||||
"air::preparation_step::preparation::make_exec_ctx": "22.00µs",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "4.70ms",
|
||||
"air_parser::parser::air_parser::parse": "26.00µs"
|
||||
}
|
||||
},
|
||||
"runner::execute": "16.00µs",
|
||||
"runner::farewell": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "3.81ms",
|
||||
"nested": {
|
||||
"from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "3.79ms",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "106.00µs",
|
||||
"to_vec(data)": "5.04ms"
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "3.75ms",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "12.00µs",
|
||||
"to_vec(data)": "2.54ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "20.83ms",
|
||||
"nested": {
|
||||
"air::preparation_step::preparation::make_exec_ctx": "1.56ms",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "13.87ms",
|
||||
"air_parser::parser::air_parser::parse": "2.05ms"
|
||||
}
|
||||
},
|
||||
"runner::execute": "126.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"total_time": "34.61ms"
|
||||
"total_time": "8.88ms"
|
||||
},
|
||||
"dashboard": {
|
||||
"comment": "big dashboard test",
|
||||
"memory_sizes": [
|
||||
"51.750 MiB",
|
||||
"51.750 MiB"
|
||||
],
|
||||
"stats": {
|
||||
"air::runner::execute_air": {
|
||||
"common_prefix": "air",
|
||||
"duration": "108.80ms",
|
||||
"duration": "28.45ms",
|
||||
"nested": {
|
||||
"farewell_step::outcome::from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "4.55ms",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "3.67ms",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "129.00µs",
|
||||
"to_vec(data)": "2.05ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "19.65ms",
|
||||
"duration": "852.00µs",
|
||||
"nested": {
|
||||
"air::preparation_step::preparation::make_exec_ctx": "2.13ms",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "8.52ms",
|
||||
"air_parser::parser::air_parser::parse": "6.38ms"
|
||||
"air::preparation_step::preparation::make_exec_ctx": "42.00µs",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "574.00µs",
|
||||
"air_parser::parser::air_parser::parse": "158.00µs"
|
||||
}
|
||||
},
|
||||
"runner::execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call",
|
||||
"duration": "80.74ms",
|
||||
"duration": "26.83ms",
|
||||
"nested": {
|
||||
"execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call::resolved_call",
|
||||
"duration": "68.82ms",
|
||||
"duration": "21.17ms",
|
||||
"nested": {
|
||||
"execute": {
|
||||
"common_prefix": "air::execution_step",
|
||||
"duration": "12.66ms",
|
||||
"common_prefix": "air::execution_step::instructions::call::resolved_call",
|
||||
"duration": "4.35ms",
|
||||
"nested": {
|
||||
"instructions::call::resolved_call::prepare_request_params": {
|
||||
"common_prefix": "air::execution_step",
|
||||
"duration": "1.14ms",
|
||||
"prepare_request_params": {
|
||||
"common_prefix": "air::execution_step::instructions::call::resolved_call::serde_json",
|
||||
"duration": "62.00µs",
|
||||
"nested": {
|
||||
"instructions::call::resolved_call::serde_json::to_string(tetraplets)": "187.00µs",
|
||||
"resolver::resolve::resolve_ast_variable": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "309.00µs",
|
||||
"nested": {
|
||||
"resolve_variable": "95.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"resolver::resolve::resolve_ast_variable": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "891.00µs",
|
||||
"nested": {
|
||||
"resolve_variable": "258.00µs"
|
||||
"to_string(tetraplets)": "18.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"new": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "39.46ms",
|
||||
"new": "3.90ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"runner::farewell": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "505.00µs",
|
||||
"nested": {
|
||||
"from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "485.00µs",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "435.00µs",
|
||||
"nested": {
|
||||
"resolve_ast_scalar": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "28.76ms",
|
||||
"nested": {
|
||||
"resolve_ast_variable": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "17.71ms",
|
||||
"nested": {
|
||||
"resolve_variable": "5.49ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
"to_vec(call_results)": "16.00µs",
|
||||
"to_vec(data)": "172.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
@ -1623,112 +1611,43 @@
|
||||
}
|
||||
}
|
||||
},
|
||||
"total_time": "108.80ms"
|
||||
"total_time": "28.45ms"
|
||||
},
|
||||
"long_data": {
|
||||
"comment": "Long data trace",
|
||||
"memory_sizes": [
|
||||
"52.875 MiB",
|
||||
"52.875 MiB"
|
||||
],
|
||||
"stats": {
|
||||
"air::runner::execute_air": {
|
||||
"common_prefix": "air",
|
||||
"duration": "25.93ms",
|
||||
"duration": "3.13ms",
|
||||
"nested": {
|
||||
"farewell_step::outcome::from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "6.53ms",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "4.85ms",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "92.00µs",
|
||||
"to_vec(data)": "2.27ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "15.86ms",
|
||||
"duration": "1.78ms",
|
||||
"nested": {
|
||||
"air::preparation_step::preparation::make_exec_ctx": "2.14ms",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "9.17ms",
|
||||
"air_parser::parser::air_parser::parse": "1.90ms"
|
||||
"air::preparation_step::preparation::make_exec_ctx": "40.00µs",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "1.64ms",
|
||||
"air_parser::parser::air_parser::parse": "26.00µs"
|
||||
}
|
||||
},
|
||||
"runner::execute": "121.00µs"
|
||||
}
|
||||
}
|
||||
},
|
||||
"total_time": "25.93ms"
|
||||
},
|
||||
"network_explore": {
|
||||
"comment": "5 peers of network are discovered",
|
||||
"stats": {
|
||||
"air::runner::execute_air": {
|
||||
"common_prefix": "air",
|
||||
"duration": "47.20ms",
|
||||
"nested": {
|
||||
"farewell_step::outcome::from_success_result": {
|
||||
"runner::execute": "16.00µs",
|
||||
"runner::farewell": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "4.91ms",
|
||||
"duration": "1.11ms",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "4.09ms",
|
||||
"from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "1.09ms",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "90.00µs",
|
||||
"to_vec(data)": "2.16ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "20.07ms",
|
||||
"nested": {
|
||||
"air::preparation_step::preparation::make_exec_ctx": "2.25ms",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "8.97ms",
|
||||
"air_parser::parser::air_parser::parse": "6.48ms"
|
||||
}
|
||||
},
|
||||
"runner::execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call",
|
||||
"duration": "18.57ms",
|
||||
"nested": {
|
||||
"execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call::resolved_call",
|
||||
"duration": "11.50ms",
|
||||
"nested": {
|
||||
"execute": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "5.08ms",
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "1.05ms",
|
||||
"nested": {
|
||||
"resolve_ast_variable": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "333.00µs",
|
||||
"nested": {
|
||||
"resolve_variable": "92.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"new": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "3.96ms",
|
||||
"nested": {
|
||||
"resolve_ast_scalar": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "2.54ms",
|
||||
"nested": {
|
||||
"resolve_ast_variable": {
|
||||
"common_prefix": "air::execution_step::resolver::resolve",
|
||||
"duration": "1.71ms",
|
||||
"nested": {
|
||||
"resolve_variable": "442.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
"to_vec(call_results)": "12.00µs",
|
||||
"to_vec(data)": "462.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
@ -1738,47 +1657,58 @@
|
||||
}
|
||||
}
|
||||
},
|
||||
"total_time": "47.20ms"
|
||||
"total_time": "3.13ms"
|
||||
},
|
||||
"parser_10000_100": {
|
||||
"comment": "Running very long AIR script with lot of variables and assignments",
|
||||
"network_explore": {
|
||||
"comment": "5 peers of network are discovered",
|
||||
"memory_sizes": [
|
||||
"51.500 MiB",
|
||||
"51.500 MiB"
|
||||
],
|
||||
"stats": {
|
||||
"air::runner::execute_air": {
|
||||
"common_prefix": "air",
|
||||
"duration": "46.04ms",
|
||||
"duration": "2.92ms",
|
||||
"nested": {
|
||||
"farewell_step::outcome::from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "3.87ms",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "3.00ms",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "92.00µs",
|
||||
"to_vec(data)": "1.56ms"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "31.76ms",
|
||||
"duration": "352.00µs",
|
||||
"nested": {
|
||||
"air::preparation_step::preparation::make_exec_ctx": "1.46ms",
|
||||
"air_parser::parser::air_parser::parse": "27.38ms"
|
||||
"air::preparation_step::preparation::make_exec_ctx": "27.00µs",
|
||||
"air_interpreter_data::interpreter_data::serde_json::from_slice": "165.00µs",
|
||||
"air_parser::parser::air_parser::parse": "78.00µs"
|
||||
}
|
||||
},
|
||||
"runner::execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call",
|
||||
"duration": "6.19ms",
|
||||
"duration": "2.05ms",
|
||||
"nested": {
|
||||
"execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call::resolved_call",
|
||||
"duration": "4.02ms",
|
||||
"duration": "1.57ms",
|
||||
"nested": {
|
||||
"execute": "2.42ms",
|
||||
"new": "435.00µs"
|
||||
"execute": "339.00µs",
|
||||
"new": "290.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"runner::farewell": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "282.00µs",
|
||||
"nested": {
|
||||
"from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "263.00µs",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "226.00µs",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "12.00µs",
|
||||
"to_vec(data)": "47.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
@ -1786,11 +1716,69 @@
|
||||
}
|
||||
}
|
||||
},
|
||||
"total_time": "46.04ms"
|
||||
"total_time": "2.92ms"
|
||||
},
|
||||
"parser_10000_100": {
|
||||
"comment": "Running very long AIR script with lot of variables and assignments",
|
||||
"memory_sizes": [
|
||||
"56.812 MiB",
|
||||
"56.812 MiB"
|
||||
],
|
||||
"stats": {
|
||||
"air::runner::execute_air": {
|
||||
"common_prefix": "air",
|
||||
"duration": "22.29ms",
|
||||
"nested": {
|
||||
"preparation_step::preparation::prepare": {
|
||||
"common_prefix": "",
|
||||
"duration": "20.70ms",
|
||||
"nested": {
|
||||
"air::preparation_step::preparation::make_exec_ctx": "22.00µs",
|
||||
"air_parser::parser::air_parser::parse": "20.64ms"
|
||||
}
|
||||
},
|
||||
"runner::execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call",
|
||||
"duration": "158.00µs",
|
||||
"nested": {
|
||||
"execute": {
|
||||
"common_prefix": "air::execution_step::instructions::call::resolved_call",
|
||||
"duration": "108.00µs",
|
||||
"nested": {
|
||||
"execute": "32.00µs",
|
||||
"new": "22.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"runner::farewell": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "256.00µs",
|
||||
"nested": {
|
||||
"from_success_result": {
|
||||
"common_prefix": "air::farewell_step::outcome",
|
||||
"duration": "236.00µs",
|
||||
"nested": {
|
||||
"populate_outcome_from_contexts": {
|
||||
"common_prefix": "air::farewell_step::outcome::serde_json",
|
||||
"duration": "203.00µs",
|
||||
"nested": {
|
||||
"to_vec(call_results)": "12.00µs",
|
||||
"to_vec(data)": "28.00µs"
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
},
|
||||
"total_time": "22.29ms"
|
||||
}
|
||||
},
|
||||
"datetime": "2023-03-29 16:46:52.960987+00:00",
|
||||
"platform": "macOS-13.2.1-arm64-arm-64bit",
|
||||
"datetime": "2023-05-19 12:28:41.064880+00:00",
|
||||
"platform": "macOS-13.3.1-arm64-arm-64bit",
|
||||
"version": "0.39.0"
|
||||
}
|
||||
}
|
||||
|
||||
@ -409,84 +409,77 @@ Machine c1f3ea5950db0a10b44da931c25774d64ab25084f47d504f72f311e694550ff1:
|
||||
execute: 29.00µs
|
||||
new: 38.00µs
|
||||
Machine d77ebe8481884bc3b2778c8083f1bf459e548e929edd87041beb14f6b868d35f:
|
||||
Platform: macOS-13.2.1-arm64-arm-64bit
|
||||
Timestamp: 2023-03-29 16:46:52.960987+00:00
|
||||
Platform: macOS-13.3.1-arm64-arm-64bit
|
||||
Timestamp: 2023-05-19 12:28:41.064880+00:00
|
||||
AquaVM version: 0.39.0
|
||||
Benches:
|
||||
big_values_data (34.61ms): Loading a trace with huge values
|
||||
air::runner::execute_air: 34.61ms
|
||||
farewell_step::outcome::from_success_result: 10.10ms
|
||||
populate_outcome_from_contexts: 8.30ms
|
||||
to_vec(call_results): 106.00µs
|
||||
to_vec(data): 5.04ms
|
||||
preparation_step::preparation::prepare: 20.83ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 1.56ms
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 13.87ms
|
||||
air_parser::parser::air_parser::parse: 2.05ms
|
||||
runner::execute: 126.00µs
|
||||
dashboard (108.80ms): big dashboard test
|
||||
air::runner::execute_air: 108.80ms
|
||||
farewell_step::outcome::from_success_result: 4.55ms
|
||||
populate_outcome_from_contexts: 3.67ms
|
||||
to_vec(call_results): 129.00µs
|
||||
to_vec(data): 2.05ms
|
||||
preparation_step::preparation::prepare: 19.65ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 2.13ms
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 8.52ms
|
||||
air_parser::parser::air_parser::parse: 6.38ms
|
||||
runner::execute: 80.74ms
|
||||
execute: 68.82ms
|
||||
execute: 12.66ms
|
||||
instructions::call::resolved_call::prepare_request_params: 1.14ms
|
||||
instructions::call::resolved_call::serde_json::to_string(tetraplets): 187.00µs
|
||||
resolver::resolve::resolve_ast_variable: 309.00µs
|
||||
resolve_variable: 95.00µs
|
||||
resolver::resolve::resolve_ast_variable: 891.00µs
|
||||
resolve_variable: 258.00µs
|
||||
new: 39.46ms
|
||||
resolve_ast_scalar: 28.76ms
|
||||
resolve_ast_variable: 17.71ms
|
||||
resolve_variable: 5.49ms
|
||||
long_data (25.93ms): Long data trace
|
||||
air::runner::execute_air: 25.93ms
|
||||
farewell_step::outcome::from_success_result: 6.53ms
|
||||
populate_outcome_from_contexts: 4.85ms
|
||||
to_vec(call_results): 92.00µs
|
||||
to_vec(data): 2.27ms
|
||||
preparation_step::preparation::prepare: 15.86ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 2.14ms
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 9.17ms
|
||||
air_parser::parser::air_parser::parse: 1.90ms
|
||||
runner::execute: 121.00µs
|
||||
network_explore (47.20ms): 5 peers of network are discovered
|
||||
air::runner::execute_air: 47.20ms
|
||||
farewell_step::outcome::from_success_result: 4.91ms
|
||||
populate_outcome_from_contexts: 4.09ms
|
||||
to_vec(call_results): 90.00µs
|
||||
to_vec(data): 2.16ms
|
||||
preparation_step::preparation::prepare: 20.07ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 2.25ms
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 8.97ms
|
||||
air_parser::parser::air_parser::parse: 6.48ms
|
||||
runner::execute: 18.57ms
|
||||
execute: 11.50ms
|
||||
execute: 5.08ms
|
||||
resolve_ast_variable: 333.00µs
|
||||
resolve_variable: 92.00µs
|
||||
new: 3.96ms
|
||||
resolve_ast_scalar: 2.54ms
|
||||
resolve_ast_variable: 1.71ms
|
||||
resolve_variable: 442.00µs
|
||||
parser_10000_100 (46.04ms): Running very long AIR script with lot of variables and assignments
|
||||
air::runner::execute_air: 46.04ms
|
||||
farewell_step::outcome::from_success_result: 3.87ms
|
||||
populate_outcome_from_contexts: 3.00ms
|
||||
to_vec(call_results): 92.00µs
|
||||
to_vec(data): 1.56ms
|
||||
preparation_step::preparation::prepare: 31.76ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 1.46ms
|
||||
air_parser::parser::air_parser::parse: 27.38ms
|
||||
runner::execute: 6.19ms
|
||||
execute: 4.02ms
|
||||
execute: 2.42ms
|
||||
new: 435.00µs
|
||||
big_values_data (8.88ms; 58.000 MiB, 58.000 MiB): Loading a trace with huge values
|
||||
air::runner::execute_air: 8.88ms
|
||||
preparation_step::preparation::prepare: 4.82ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 22.00µs
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 4.70ms
|
||||
air_parser::parser::air_parser::parse: 26.00µs
|
||||
runner::execute: 16.00µs
|
||||
runner::farewell: 3.81ms
|
||||
from_success_result: 3.79ms
|
||||
populate_outcome_from_contexts: 3.75ms
|
||||
to_vec(call_results): 12.00µs
|
||||
to_vec(data): 2.54ms
|
||||
dashboard (28.45ms; 51.750 MiB, 51.750 MiB): big dashboard test
|
||||
air::runner::execute_air: 28.45ms
|
||||
preparation_step::preparation::prepare: 852.00µs
|
||||
air::preparation_step::preparation::make_exec_ctx: 42.00µs
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 574.00µs
|
||||
air_parser::parser::air_parser::parse: 158.00µs
|
||||
runner::execute: 26.83ms
|
||||
execute: 21.17ms
|
||||
execute: 4.35ms
|
||||
prepare_request_params: 62.00µs
|
||||
to_string(tetraplets): 18.00µs
|
||||
new: 3.90ms
|
||||
runner::farewell: 505.00µs
|
||||
from_success_result: 485.00µs
|
||||
populate_outcome_from_contexts: 435.00µs
|
||||
to_vec(call_results): 16.00µs
|
||||
to_vec(data): 172.00µs
|
||||
long_data (3.13ms; 52.875 MiB, 52.875 MiB): Long data trace
|
||||
air::runner::execute_air: 3.13ms
|
||||
preparation_step::preparation::prepare: 1.78ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 40.00µs
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 1.64ms
|
||||
air_parser::parser::air_parser::parse: 26.00µs
|
||||
runner::execute: 16.00µs
|
||||
runner::farewell: 1.11ms
|
||||
from_success_result: 1.09ms
|
||||
populate_outcome_from_contexts: 1.05ms
|
||||
to_vec(call_results): 12.00µs
|
||||
to_vec(data): 462.00µs
|
||||
network_explore (2.92ms; 51.500 MiB, 51.500 MiB): 5 peers of network are discovered
|
||||
air::runner::execute_air: 2.92ms
|
||||
preparation_step::preparation::prepare: 352.00µs
|
||||
air::preparation_step::preparation::make_exec_ctx: 27.00µs
|
||||
air_interpreter_data::interpreter_data::serde_json::from_slice: 165.00µs
|
||||
air_parser::parser::air_parser::parse: 78.00µs
|
||||
runner::execute: 2.05ms
|
||||
execute: 1.57ms
|
||||
execute: 339.00µs
|
||||
new: 290.00µs
|
||||
runner::farewell: 282.00µs
|
||||
from_success_result: 263.00µs
|
||||
populate_outcome_from_contexts: 226.00µs
|
||||
to_vec(call_results): 12.00µs
|
||||
to_vec(data): 47.00µs
|
||||
parser_10000_100 (22.29ms; 56.812 MiB, 56.812 MiB): Running very long AIR script with lot of variables and assignments
|
||||
air::runner::execute_air: 22.29ms
|
||||
preparation_step::preparation::prepare: 20.70ms
|
||||
air::preparation_step::preparation::make_exec_ctx: 22.00µs
|
||||
air_parser::parser::air_parser::parse: 20.64ms
|
||||
runner::execute: 158.00µs
|
||||
execute: 108.00µs
|
||||
execute: 32.00µs
|
||||
new: 22.00µs
|
||||
runner::farewell: 256.00µs
|
||||
from_success_result: 236.00µs
|
||||
populate_outcome_from_contexts: 203.00µs
|
||||
to_vec(call_results): 12.00µs
|
||||
to_vec(data): 28.00µs
|
||||
|
||||
File diff suppressed because one or more lines are too long
File diff suppressed because one or more lines are too long
File diff suppressed because one or more lines are too long
File diff suppressed because one or more lines are too long
File diff suppressed because one or more lines are too long
File diff suppressed because one or more lines are too long
@ -22,6 +22,7 @@ clap = { version = "4.2.7", features = ["derive", "env"] }
|
||||
itertools = "0.10.5"
|
||||
serde = { version = "1.0.159", features = ["derive"] }
|
||||
serde_json = "1.0.95"
|
||||
tracing = "0.1.37"
|
||||
tracing-subscriber = { version = "0.3.17", default-features = false, features = [ "env-filter", "json", "smallvec", "time", "fmt" ] }
|
||||
atty = "0.2.14"
|
||||
termcolor = "1.2.0"
|
||||
|
||||
@ -33,7 +33,7 @@ impl AirRunner for WasmAvmRunner {
|
||||
tracing_params: String,
|
||||
tracing_output_mode: u8,
|
||||
) -> anyhow::Result<avm_interface::raw_outcome::RawAVMOutcome> {
|
||||
Ok(self.0.call_tracing(
|
||||
let call_tracing = self.0.call_tracing(
|
||||
air,
|
||||
prev_data,
|
||||
data,
|
||||
@ -44,7 +44,12 @@ impl AirRunner for WasmAvmRunner {
|
||||
call_results,
|
||||
tracing_params,
|
||||
tracing_output_mode,
|
||||
)?)
|
||||
);
|
||||
|
||||
let memory_stats = self.0.memory_stats();
|
||||
tracing::warn!(memory_size = memory_stats.memory_size);
|
||||
|
||||
Ok(call_tracing?)
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@ -19,7 +19,7 @@ import datetime
|
||||
import json
|
||||
import logging
|
||||
import platform
|
||||
from typing import Optional
|
||||
from typing import List, Optional
|
||||
|
||||
from .helpers import get_host_id, get_aquavm_version, intermediate_temp_file
|
||||
|
||||
@ -61,16 +61,25 @@ class Db:
|
||||
logging.warning("cannot open data at %r: %s", json_path, ex)
|
||||
self.data = {}
|
||||
|
||||
def record(self, bench, stats, total_time):
|
||||
def record(
|
||||
self, bench, stats, total_time, memory_sizes: Optional[List[str]]
|
||||
):
|
||||
"""Record the bench stats."""
|
||||
if self.host_id not in self.data:
|
||||
self.data[self.host_id] = {"benches": {}}
|
||||
bench_name = bench.get_name()
|
||||
|
||||
self.data[self.host_id]["benches"][bench_name] = {
|
||||
bench_info = {
|
||||
"stats": stats,
|
||||
"total_time": total_time,
|
||||
}
|
||||
if memory_sizes is not None:
|
||||
bench_info["memory_sizes"] = memory_sizes
|
||||
|
||||
comment = bench.get_comment()
|
||||
if comment is not None:
|
||||
bench_info["comment"] = comment
|
||||
self.data[self.host_id]["benches"][bench_name] = bench_info
|
||||
self.data[self.host_id]["platform"] = platform.platform()
|
||||
self.data[self.host_id]["datetime"] = str(
|
||||
datetime.datetime.now(datetime.timezone.utc)
|
||||
@ -79,10 +88,6 @@ class Db:
|
||||
AQUAVM_TOML_PATH
|
||||
)
|
||||
|
||||
comment = bench.get_comment()
|
||||
if comment is not None:
|
||||
self.data[self.host_id]["benches"][bench_name]["comment"] = comment
|
||||
|
||||
def save(self):
|
||||
"""Save the database to JSON."""
|
||||
with intermediate_temp_file(self.json_path) as out:
|
||||
|
||||
@ -90,3 +90,4 @@ def intermediate_temp_file(target_file: str):
|
||||
os.remove(out.name)
|
||||
except OSError:
|
||||
pass
|
||||
raise
|
||||
|
||||
@ -74,7 +74,8 @@ def run(args):
|
||||
|
||||
combined_stats = walker.to_json(args.repeat)
|
||||
total_time = walker.get_total_time(args.repeat)
|
||||
db.record(bench, combined_stats, total_time)
|
||||
memory_sizes = walker.get_memory_sizes(args.repeat)
|
||||
db.record(bench, combined_stats, total_time, memory_sizes)
|
||||
|
||||
with (
|
||||
intermediate_temp_file(
|
||||
|
||||
@ -48,9 +48,17 @@ class TextReporter:
|
||||
bench_name, bench, indent=nested_indent, file=file)
|
||||
|
||||
def _save_bench(self, bench_name, bench, indent, file):
|
||||
bracketed_text = bench["total_time"]
|
||||
try:
|
||||
bracketed_text += '; {}'.format(', '.join(bench['memory_sizes']))
|
||||
except KeyError:
|
||||
pass
|
||||
_print_indent(
|
||||
"{} ({}): {}".format(
|
||||
bench_name, bench["total_time"], bench["comment"]),
|
||||
bench_name,
|
||||
bracketed_text,
|
||||
bench["comment"],
|
||||
),
|
||||
indent=indent, file=file)
|
||||
for fname, stats in _sorted_items(bench["stats"]):
|
||||
self._save_stats(fname, stats, indent + self.indent_step, file)
|
||||
|
||||
@ -18,7 +18,8 @@
|
||||
import datetime
|
||||
import logging
|
||||
from itertools import zip_longest
|
||||
from typing import Optional
|
||||
from typing import Optional, List
|
||||
import humanize
|
||||
|
||||
from .helpers import format_timedelta, parse_trace_timedelta
|
||||
|
||||
@ -132,32 +133,40 @@ class TraceWalker:
|
||||
# Maps from fully-qualified func name to a trace
|
||||
root: dict
|
||||
|
||||
memory_sizes: List[int]
|
||||
|
||||
def __init__(self):
|
||||
"""Create a walker."""
|
||||
self.stack = []
|
||||
self.root = {}
|
||||
self.memory_sizes = []
|
||||
|
||||
def process(self, records):
|
||||
"""With all input records, building a call tree in the `root` field."""
|
||||
for raw_rec in records:
|
||||
logger.debug("raw_rec %r", raw_rec)
|
||||
message = raw_rec["fields"]["message"]
|
||||
if message in ("enter", "close"):
|
||||
span = raw_rec["span"].get("name", "ERROR_missing_span.name")
|
||||
target = raw_rec.get("target", None)
|
||||
spans = [sp["name"] for sp in raw_rec.get("spans", [])]
|
||||
logger.debug("Message: %r", message)
|
||||
if message == "close":
|
||||
time_busy = raw_rec["fields"].get("time.busy")
|
||||
rec = self.stack.pop()
|
||||
logger.debug("Poped %r from %r", rec, self.stack)
|
||||
real_rec = self._get_closing_rec(rec)
|
||||
assert rec == real_rec, f"{rec!r} vs {real_rec!r}"
|
||||
rec.execution_time += parse_trace_timedelta(time_busy)
|
||||
elif message == "enter":
|
||||
assert span == spans[-1]
|
||||
rec = TraceRecord(message, span, target, None, spans[:-1])
|
||||
self._inject_enter_rec(rec)
|
||||
raw_fields = raw_rec["fields"]
|
||||
|
||||
if "message" in raw_fields:
|
||||
message = raw_fields["message"]
|
||||
if message in ("enter", "close"):
|
||||
span = raw_rec["span"].get("name", "ERROR_missing_span.name")
|
||||
target = raw_rec.get("target", None)
|
||||
spans = [sp["name"] for sp in raw_rec.get("spans", [])]
|
||||
logger.debug("Message: %r", message)
|
||||
if message == "close":
|
||||
time_busy = raw_rec["fields"].get("time.busy")
|
||||
rec = self.stack.pop()
|
||||
logger.debug("Poped %r from %r", rec, self.stack)
|
||||
real_rec = self._get_closing_rec(rec)
|
||||
assert rec == real_rec, f"{rec!r} vs {real_rec!r}"
|
||||
rec.execution_time += parse_trace_timedelta(time_busy)
|
||||
elif message == "enter":
|
||||
assert span == spans[-1]
|
||||
rec = TraceRecord(message, span, target, None, spans[:-1])
|
||||
self._inject_enter_rec(rec)
|
||||
if "memory_size" in raw_fields:
|
||||
self._handle_memory_stat(raw_fields["memory_size"])
|
||||
|
||||
def to_json(self, repeat: int):
|
||||
"""Convert to JSON."""
|
||||
@ -176,6 +185,19 @@ class TraceWalker:
|
||||
) / repeat
|
||||
return format_timedelta(root_time)
|
||||
|
||||
def get_memory_sizes(self, repeat: int) -> Optional[str]:
|
||||
"""Get average memory size."""
|
||||
def format_size(size):
|
||||
return humanize.naturalsize(size, binary=True, format="%.3f")
|
||||
|
||||
if self.memory_sizes:
|
||||
self.memory_sizes.sort()
|
||||
min_size = self.memory_sizes[0]
|
||||
max_size = self.memory_sizes[-1]
|
||||
return [format_size(min_size), format_size(max_size)]
|
||||
else:
|
||||
return None
|
||||
|
||||
def _find_parent(self, rec: TraceRecord) -> TraceRecord:
|
||||
parent = _RootStub(self.root)
|
||||
|
||||
@ -204,3 +226,6 @@ class TraceWalker:
|
||||
fname = rec.get_func_name()
|
||||
real_rec = parent.nested[fname]
|
||||
return real_rec
|
||||
|
||||
def _handle_memory_stat(self, size: int):
|
||||
self.memory_sizes.append(size)
|
||||
|
||||
@ -24,6 +24,7 @@ setup(name='aquavm_performance_metering',
|
||||
packages=['performance_metering'],
|
||||
zip_safe=True,
|
||||
install_requires=[
|
||||
'humanize',
|
||||
# python 3.11 use standard tomllib, but it is not yet available
|
||||
# everywhere.
|
||||
'toml',
|
||||
|
||||
Loading…
Reference in New Issue
Block a user