I remember trying this some time ago, and the the way it interacted with xdist meant that the time reported was CPU time - but in most cases we care about response time.
On Tue, Feb 21, 2017 at 11:57 AM, David Knupp <[email protected]> wrote: > The information in the docs is scant: > > duration profiling: new “–duration=N” option showing the N slowest > test execution or setup/teardown calls. This is most useful if you want to > find out where your slowest test code is. > > My guess is that this is wall clock time, from test setup to teardown. > >> Alex Behm <mailto:[email protected]> >> February 21, 2017 at 11:31 AM >> Is this response time or CPU time? >> >> >> David Knupp <mailto:[email protected]> >> February 21, 2017 at 11:29 AM >> >> I just discovered on Friday that pytest allows for a --durations=N >> parameter, which will output the time it takes to execute the slowest N >> tests to the console, so I ran both a core and exhaustive private build >> over the weekend, and clocked the slowest 50 for each grouping of tests. >> These are the results, tidied up to be more legible. (Since it's long, I'll >> send another email with the slowest exhaustive tests.) >> >> This was a question that had been asked recently. I wonder we should add >> this to the default pytest args in run-all-tests.sh, to track where most of >> our test time is being spent? Since it adds noise to the log, we could pick >> a number smaller than 50. >> >> >> ------------------------------------------------------------ >> ------------------------------------------------------------ >> TIME TABLE FORMAT Slowest Core Parallel Tests >> ------------------------------------------------------------ >> ------------------------------------------------------------ >> 214.71s text/none data/test_compute_stats.py::T >> estComputeStats::test_compute_ >> 194.68s text/none-unique_database0 data/test_ddl.py::TestDdlState >> ments::test_alter_tab >> 193.79s text/none query_test/test_exprs.py::Tes >> tExprs::test_expr >> 185.03s parquet/none query_test/test_queries.py::Te >> stQueries::test_analytic_fn >> 164.04s text/none data/test_show_create_table.p >> y::TestShowCreateTable::test_show_create_tab >> 157.15s parquet/none query_test/test_nested_types.p >> y::TestNestedTypes::test_tpch >> 153.68s parquet/none query_test/test_queries.py::Te >> stHdfsQueries::test_analytic_fn >> 143.73s text/none query_test/test_kudu.py::Test >> KuduOperations::test_kudu_partition_dd >> 137.51s parquet/none query_test/test_join_queries.p >> y::TestTPCHJoinQueries::test_outer_join >> 133.13s text/none query_test/test_exprs.py::Tes >> tExprs::test_expr >> 125.87s text/none query_test/test_insert_permut >> ation.py::TestInsertQueriesWithPermutation::test_insert_permutation >> 119.45s text/gzip/block query_test/test_hdfs_caching. >> py::TestHdfsCaching::test_cache_cancellation >> 118.59s parquet/none query_test/test_runtime_filter >> s.py::TestRuntimeRowFilters::test_row_filter >> 117.99s text/none query_test/test_hdfs_caching. >> py::TestHdfsCaching::test_cache_cancellation >> 104.71s text/none data/test_compute_stats.py::T >> estComputeStats::test_compute_stats_incremen >> 95.86s avro/snap/block query_test/test_runtime_filte >> rs.py::TestRuntimeFilters::test_basic_filter >> 89.58s rc/snap/block query_test/test_runtime_filte >> rs.py::TestRuntimeFilters::test_basic_filter >> 88.74s text/none query_test/test_kudu.py::Test >> KuduOperations::test_kudu_d >> 88.68s parquet/none query_test/test_sort.py::TestQ >> ueryFullSort::test_multiple_mem_limits_full_outpu >> 83.88s seq/snap/block query_test/test_scanners.py::T >> estScannersAllTableFormatsWithLimit::test_limi >> 83.45s text/none query_test/test_kudu.py::Test >> KuduOperations::test_kudu_inser >> 83.00s text/none query_test/test_runtime_filte >> rs.py::TestRuntimeFilters::test_basic_filter >> 79.15s text/none query_test/test_scanners.py:: >> TestScannersAllTableFormatsWithLimit::test_limi >> 79.15s parquet/none query_test/test_runtime_filter >> s.py::TestRuntimeFilters::test_basic_filter >> 78.20s seq/snap/block query_test/test_runtime_filter >> s.py::TestRuntimeFilters::test_basic_filter >> 76.24s text/none query_test/test_udfs.py::Test >> UdfExecution::test_ir_function >> 74.27s parquet/none query_test/test_sort.py::TestQ >> ueryFullSort::test_multiple_mem_limi >> 73.40s parquet/none query_test/test_insert_parquet >> .py::TestInsertParquetQueries::test_insert_parqu >> 72.62s rc/snap/block query_test/test_scanners.py:: >> TestScannersAllTableFormatsWithLimit::test_limi >> 71.21s text/none data/test_partition_metadata. >> py::TestPartitionMetadata::test_partition_metadata_compatibility >> 70.15s parquet/none query_test/test_insert_parquet >> .py::TestInsertParquetQueries::test_insert_parqu >> 68.99s parquet/none query_test/test_nested_types.p >> y::TestNestedTypes::test_subplan >> 68.08s text/none query_test/test_udfs.py::Test >> UdfExecution::test_native_function >> 67.68s parquet/none query_test/test_sort.py::TestQ >> ueryFullSort::test_sort_union >> 65.39s text/none query_test/test_udfs.py::Test >> UdfExecution::test_ir_function >> 64.80s text/none query_test/test_udfs.py::Test >> UdfExecution::test_ir_function >> 63.34s parquet/none query_test/test_scanners.py::T >> estScannersAllTableFormatsWithLimit::test_limi >> 63.16s text/none query_test/test_errorlog.py:: >> TestErrorLogs::test_errorlog >> 63.10s text/none query_test/test_udfs.py::Test >> UdfExecution::test_native_function >> 63.08s text/none-unique_database0 data/test_ddl.py::TestDdlState >> ments::test_views_dd >> 62.97s parquet/none query_test/test_insert_parquet >> .py::TestInsertParquetQueries::test_insert_parqu >> 61.12s text/none query_test/test_kudu.py::Test >> KuduOperations::test_kudu_upser >> 61.10s parquet/none query_test/test_insert_parquet >> .py::TestInsertParquetQueries::test_insert_parqu >> 61.05s text/none query_test/test_kudu.py::Test >> KuduOperations::test_kudu_scan_nod >> 60.96s avro/snap/block query_test/test_scanners.py:: >> TestScannersAllTableFormatsWithLimit::test_limi >> 58.63s text/none query_test/test_aggregation.p >> y::TestAggregationQueries::test_aggregation >> 58.59s text/none query_test/test_udfs.py::Test >> UdfExecution::test_native_function >> 58.42s text/none query_test/test_udfs.py::Test >> UdfExecution::test_native_function >> 58.27s parquet/none query_test/test_scanners_fuzz. >> py::TestScannersFuzzing::test_fuzz_allty >> 57.90s avro/snap/block query_test/test_scanners_ >> fuzz.py::TestScannersFuzzing::test_fuzz_allty >> >> >> ------------------------------------------------------------ >> ------------------------------------------------------------ >> TIME TABLE FORMAT Slowest Core Serial Tests >> ------------------------------------------------------------ >> ------------------------------------------------------------ >> 301.99s parquet/none query_test/test_queries.py::Te >> stQueriesParquetTables::test_very_large_string >> 142.72s text/none query_test/test_insert.py::Te >> stInsertQueries::test_inser >> 109.29s text/none data/test_metadata_query_stat >> ements.py::TestMetadataQueryStatements::test_describe_db >> 83.58s text/none query_test/test_hdfs_caching. >> py::TestHdfsCachingDdl::test_cache_reload_validation >> 65.20s text/none query_test/test_chars.py::Tes >> tStringQueries::test_varchar >> 63.93s data/test_hdfs_encryption.py: >> :TestHdfsEncryption::test_drop_partition_encry >> 52.34s text/none data/test_hms_integration.py: >> :TestHmsIntegrationSanity::test_sanity >> 52.33s text/none query_test/test_hdfs_caching. >> py::TestHdfsCachingDdl::test_caching_dd >> 50.18s query_test/test_insert_behavi >> our.py::TestInsertBehaviour::test_insert_select_with_empty_resu >> 49.66s text/none query_test/test_hdfs_caching. >> py::TestHdfsCachingDdl::test_caching_ddl_drop_datab >> 45.89s text/none query_test/test_kudu.py::Test >> KuduOperations::test_kudu_alter_tab >> 44.39s parquet/none catalog_service/test_hms_failu >> re.py::TestHiveMetaStoreFailure::test_hms_service_di >> 41.62s text/none query_test/test_insert.py::Te >> stInsertPartKey::test_insert_part_key >> 36.80s parquet/none query_test/test_tpcds_queries. >> py::TestTpcdsQuery::test_tpcds_coun >> 33.72s text/none data/test_hdfs_encryption.py: >> :TestHdfsEncryption::test_load_d >> 31.41s text/none query_test/test_insert.py::Te >> stInsertNullQueries::test_insert_nu >> 30.68s text/none data/test_ddl.py::TestLibCach >> e::test_create_drop_data_src >> 29.40s data/test_hdfs_encryption.py: >> :TestHdfsEncryption::test_drop_table_encry >> 29.22s text/none data/test_hdfs_encryption.py: >> :TestHdfsEncryption::test_load_d >> 27.41s text/none query_test/test_chars.py::Tes >> tStringQueries::test_varchar >> 24.98s hs2/test_hs2.py::TestHS2::tes >> t_concurrent_session_mixed_idle_timeou >> 18.77s hbase/none query_test/test_hbase_queries. >> py::TestHBaseQueries::test_hbase_inser >> 18.04s text/none data/test_compute_stats.py::T >> estComputeStats::test_compute_stats_keyword >> 17.65s text/none query_test/test_insert.py::Te >> stInsertQueries::test_insert_overwri >> 14.16s parquet/none query_test/test_cancellation.p >> y::TestCancellationSerial::test_cancel_inser >> 13.58s text/none failure/test_failpoints.py::T >> estFailpoints::test_failpoin >> 13.34s hell/test_shell_commandline.p >> y::TestImpalaShell::test_config_fi >> 11.77s kudu/none failure/test_failpoints.py::T >> estFailpoints::test_failpoin >> 11.13s hell/test_shell_interactive.p >> y::TestImpalaShellInteractive::test_ddl_queries_are_closed >> 10.72s hell/test_shell_commandline.p >> y::TestImpalaShell::test_queries_closed >> 10.58s hell/test_shell_interactive.p >> y::TestImpalaShellInteractive::test_cancellation >> 10.02s kudu/none failure/test_failpoints.py::T >> estFailpoints::test_failpoin >> 9.99s seq/snap/block query_test/test_cancellation.p >> y::TestCancellationSerial::test_cancel_inser >> 9.97s text/gzip/block query_test/test_cancellation. >> py::TestCancellationSerial::test_cancel_inser >> 9.63s hs2/test_fetch_first.py::Test >> FetchFirst::test_query_stmts_v1 >> 9.01s text/none query_test/test_cancellation. >> py::TestCancellationSerial::test_cancel_inser >> 9.01s avro/snap/block query_test/test_cancellation. >> py::TestCancellationSerial::test_cancel_inser >> 8.95s avro/none query_test/test_cancellation. >> py::TestCancellationSerial::test_cancel_inser >> >> >> ------------------------------------------------------------ >> ------------------------------------------------------------ >> TIME TABLE FORMAT Slowest Core Custom Cluster Tests >> ------------------------------------------------------------ >> ------------------------------------------------------------ >> 685.22s custom_cluster/test_ >> permanent_udfs.py::TestUdfPersistence::test_java_udfs_hive_integration >> 667.85s parquet/none custom_cluster/test_spilling.p >> y::TestSpilling::test_spilling >> 117.89s custom_cluster/test_ >> permanent_udfs.py::TestUdfPersistence::test_java_udfs_from_i >> 100.75s text/none uthorization/test_grant_revok >> e.py::TestGrantRevoke::test_grant_revok >> 53.79s custom_cluster/test_ >> redaction.py::TestRedaction::test_very_verbose_logging >> 49.12s custom_cluster/test_ >> permanent_udfs.py::TestUdfPersistence::test_permanent_udf >> 41.84s text/none custom_cluster/test_scratch_d >> isk.py::TestScratchDir::test_write_error_failover >> 39.62s text/none custom_cluster/test_scratch_d >> isk.py::TestScratchDir::test_non_writable_dir >> 39.55s text/none custom_cluster/test_scratch_d >> isk.py::TestScratchDir::test_multiple_dir >> 39.53s text/none custom_cluster/test_scratch_d >> isk.py::TestScratchDir::test_no_dir >> 38.73s text/none custom_cluster/test_scratch_d >> isk.py::TestScratchDir::test_non_existing_dir >> 37.12s text/none custom_cluster/test_ >> admission_controller.py::TestAdmissionControllerStress:: >> test_admission_controller_with_flag >> 33.42s text/none custom_cluster/test_ >> admission_controller.py::TestAdmissionControllerStress:: >> test_admission_controller_with_config >> 33.19s custom_cluster/test_ >> redaction.py::TestRedaction::test_redacted >> 32.50s text/none custom_cluster/test_ >> admission_controller.py::TestAdmissionControllerStress::test_mem_limi >> 26.87s custom_cluster/test_ >> redaction.py::TestRedaction::test_unredacted >> 22.28s text/none custom_cluster/test_exchange_ >> delays.py::TestExchangeDelays::test_exchange_large_delay >> 22.02s text/none custom_cluster/test_alloc_fai >> l.py::TestAllocFail::test_alloc_fail_ini >> 20.30s text/none custom_cluster/test_exchange_ >> delays.py::TestExchangeDelays::test_exchange_small_delay >> 18.07s custom_cluster/test_ >> redaction.py::TestRedaction::test_bad_ru >> >> >> > -- > David Knupp > Software Engineer > Cloudera > 415-312-1049 > <https://www.postbox-inc.com/?utm_source=email&utm_medium=si > glink&utm_campaign=reach> >
