Open adamtracy opened 10 months ago
I wrote a script to repeatedly call test_create_accessioning_wf()
and followed the total number of rows accumulating in the generic_instance
relation. The objective was to get to 1M rows, however the script began to get progressively slower over time. I ruled out some cumulative memory/resource leak in the app code as restarting the python shell did not ameliorate the slowness. At this point I reinitiated the test with a profiler to see what parts of the application code were taking longest.
ncalls tottime percall cumtime percall filename:lineno(function)
10 0.005 0.000 1983.815 198.381 <ipython-input-3-03a06f60031b>:13(test_create_accessioning_wf)
90 0.012 0.000 1958.471 21.761 /home/ubuntu/bloom/bloom_lims/bdb.py:1676(do_action)
95613 0.392 0.000 1820.401 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1372(execute)
95613 0.419 0.000 1820.009 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/elements.py:507(_execute_on_connection)
95613 2.116 0.000 1819.590 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1589(_execute_clauseelement)
95619 1.177 0.000 1790.707 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1790(_execute_context)
282398 0.609 0.000 1785.628 0.006 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/attributes.py:552(__get__)
242356/97416 0.725 0.000 1785.182 0.018 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/attributes.py:1063(get)
81047/80636 0.299 0.000 1783.116 0.022 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/attributes.py:1108(_fire_loader_callables)
95619 1.540 0.000 1781.311 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1852(_exec_single_context)
95623 1769.883 0.019 1775.501 0.019 {method 'execute' of 'psycopg2.extensions.cursor' objects}
95619 0.289 0.000 1774.573 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/default.py:921(do_execute)
10 0.376 0.038 1768.347 176.835 /home/ubuntu/bloom/bloom_lims/bdb.py:2010(do_action_add_container_to_assay_q)
72875 1.187 0.000 1765.852 0.024 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/strategies.py:867(_load_for_state)
72875 3.777 0.000 1764.119 0.024 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/strategies.py:994(_emit_lazyload)
91229 0.350 0.000 1727.504 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:2247(execute)
91229 2.006 0.000 1727.154 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:2077(_execute_internal)
91227 0.639 0.000 1714.511 0.019 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/context.py:283(orm_execute_statement)
95777 0.332 0.000 130.381 0.001 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:4282(flush)
4360 0.189 0.000 129.615 0.030 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:4331(_flush)
4360 0.070 0.000 127.917 0.029 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/unitofwork.py:441(execute)
4370 0.026 0.000 123.396 0.028 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/unitofwork.py:640(execute)
4370 0.151 0.000 123.370 0.028 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py:40(save_obj)
150 0.007 0.000 113.897 0.759 /home/ubuntu/bloom/bloom_lims/bdb.py:674(create_instances)
20 0.021 0.001 103.910 5.195 /home/ubuntu/bloom/bloom_lims/bdb.py:1781(do_action_stamp_copy_plate)
150 0.053 0.000 103.310 0.689 /home/ubuntu/bloom/bloom_lims/bdb.py:755(_process_instantiation_layouts)
1000 0.044 0.000 89.805 0.090 /home/ubuntu/bloom/bloom_lims/bdb.py:823(_create_child_instance)
4370 0.155 0.000 75.946 0.017 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py:957(_emit_insert_statements)
40 0.001 0.000 71.235 1.781 /home/ubuntu/bloom/bloom_lims/bdb.py:670(create_instances_from_uuid)
85849 0.230 0.000 53.738 0.001 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/result.py:1778(all)
88801 1.160 0.000 53.709 0.001 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/result.py:549(_allrows)
85849 0.195 0.000 50.895 0.001 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/result.py:1692(_fetchall_impl)
85845 0.766 0.000 50.700 0.001 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/result.py:2289(_fetchall_impl)
182454 0.701 0.000 49.090 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:203(chunks)
960 0.053 0.000 48.838 0.051 /home/ubuntu/bloom/bloom_lims/bdb.py:792(create_generic_instance_lineage_by_euids)
1150 0.082 0.000 48.701 0.042 /home/ubuntu/bloom/bloom_lims/bdb.py:607(create_instance)
4370 0.077 0.000 46.588 0.011 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/persistence.py:725(_emit_update_statements)
146449/111379 0.730 0.000 41.701 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/state_changes.py:95(_go)
8210/7920 0.025 0.000 38.126 0.005 <string>:1(commit)
8210/7920 0.192 0.000 38.066 0.005 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:1249(commit)
10 0.002 0.000 37.981 3.798 /home/ubuntu/bloom/bloom_lims/bdb.py:1940(do_action_fill_plate_undirected)
3850 0.013 0.000 37.766 0.010 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:1933(commit)
12970 0.223 0.000 28.028 0.002 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/query.py:2671(all)
95613 0.715 0.000 26.291 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/elements.py:669(_compile_w_cache)
3470 0.036 0.000 25.382 0.007 /home/ubuntu/bloom/bloom_lims/bdb.py:931(get_by_euid)
12970 0.220 0.000 24.814 0.002 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/query.py:2842(_iter)
150470 0.699 0.000 24.530 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:1463(polymorphic_instance)
3470 0.248 0.000 24.490 0.007 /home/ubuntu/bloom/bloom_lims/bdb.py:1020(query_all_tables_by_euid)
91227 0.483 0.000 23.548 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/result.py:543(_raw_all_rows)
94183 0.227 0.000 23.244 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/cursor.py:2101(_fetchall_impl)
160 0.002 0.000 23.061 0.144 /home/ubuntu/bloom/bloom_lims/bdb.py:818(create_instance_by_code)
94183 0.411 0.000 23.017 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/cursor.py:1129(fetchall)
94203 0.714 0.000 22.979 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/util/langhelpers.py:1272(oneshot)
94203 0.318 0.000 22.265 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/cache_key.py:396(_generate_cache_key)
94203 0.735 0.000 21.947 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/cache_key.py:332(_generate_cache_key)
94183 2.161 0.000 21.582 0.000 {method 'fetchall' of 'psycopg2.extensions.cursor' objects}
169252 6.741 0.000 21.043 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:807(_instance_processor)
3670 0.012 0.000 20.736 0.006 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:2602(commit)
3670 0.031 0.000 20.725 0.006 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:2719(_do_commit)
3670 0.015 0.000 20.687 0.006 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:2694(_connection_commit_impl)
3670 0.027 0.000 20.672 0.006 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/base.py:1123(_commit_impl)
3670 0.028 0.000 20.641 0.006 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/default.py:694(do_commit)
3670 20.598 0.006 20.598 0.006 {method 'commit' of 'psycopg2.extensions.connection' objects}
783163/94203 10.226 0.000 20.500 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/cache_key.py:208(_gen_cache_key)
91227 0.987 0.000 19.784 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/context.py:555(orm_setup_cursor_result)
5222 0.074 0.000 18.717 0.004 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/state.py:779(_load_expired)
5222 0.126 0.000 18.535 0.004 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:1576(load_scalar_attributes)
91227 2.583 0.000 17.446 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:78(instances)
5382 0.187 0.000 16.809 0.003 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:522(load_on_pk_identity)
5222 0.117 0.000 16.359 0.003 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:483(load_on_ident)
72875 0.691 0.000 15.376 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/strategies.py:830(_generate_lazy_clause)
144940 1.396 0.000 14.685 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/mapper.py:3569(_get_state_attr_by_column)
10 0.001 0.000 13.937 1.394 /home/ubuntu/bloom/bloom_lims/bdb.py:1828(do_action_cfdna_quant)
165930 0.796 0.000 13.818 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/annotation.py:376(__eq__)
374068/166044 0.941 0.000 13.508 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/operators.py:583(__eq__)
155692 1.771 0.000 13.448 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:1046(_instance)
10 0.000 0.000 13.184 1.318 /home/ubuntu/bloom/bloom_lims/bdb.py:1561(do_action)
352964/310984 0.640 0.000 12.692 0.000 {built-in method _operator.eq}
10 0.001 0.000 12.667 1.267 /home/ubuntu/bloom/bloom_lims/bdb.py:1613(do_action_create_package_and_first_workflow_step)
166108 0.488 0.000 12.583 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/elements.py:1610(operate)
91227 0.686 0.000 12.145 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/context.py:2680(row_processor)
166108 0.907 0.000 11.327 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/type_api.py:186(operate)
191189 0.492 0.000 11.286 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/util/_collections.py:345(__missing__)
20 0.002 0.000 10.955 0.548 /home/ubuntu/bloom/bloom_lims/bdb.py:2086(do_action_create_child_container_and_link_child_workflow_step)
10 0.012 0.001 10.620 1.062 /home/ubuntu/bloom/bloom_lims/bdb.py:1724(_add_random_values_to_plate)
160128 0.448 0.000 10.614 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/psycopg2/_json.py:159(typecast_json)
78455 0.564 0.000 10.433 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/loading.py:1436(configure_subclass_mapper)
166098 1.348 0.000 10.418 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/sql/default_comparator.py:51(_boolean_compare)
155694 0.828 0.000 10.166 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/json/__init__.py:299(loads)
100 0.020 0.000 9.658 0.097 /home/ubuntu/bloom/bloom_lims/bdb.py:1319(_do_action_base)
3850 2.080 0.001 9.169 0.002 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:1082(_remove_snapshot)
155694 3.497 0.000 9.003 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/json/decoder.py:332(decode)
382390 1.089 0.000 8.808 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/psycopg2/extras.py:669(<lambda>)
3/2 0.004 0.001 8.488 4.244 /home/ubuntu/bloom/bloom_lims/bdb.py:461(__init__)
95613 2.093 0.000 8.028 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/engine/default.py:1274(_init_compiled)
382390 5.444 0.000 7.719 0.000 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/uuid.py:139(__init__)
10 0.002 0.000 7.594 0.759 /home/ubuntu/bloom/bloom_lims/bdb.py:1858(do_action_link_tubes_auto)
60 0.001 0.000 7.353 0.123 /home/ubuntu/bloom/bloom_lims/bdb.py:1121(create_instance_by_template_components)
8210/7920 0.020 0.000 7.136 0.001 <string>:1(_prepare_impl)
8210/7920 0.039 0.000 7.089 0.001 /home/ubuntu/anaconda3/envs/BLOOM/lib/python3.12/site-packages/sqlalchemy/orm/session.py:1214(_prepare_impl)
The profiling output clearly brackets do_action_add_container_to_assay_q()
where most of the time is spent waiting on postgres.
In the "real world", I would imagine the assay queue would have batches moving forward in the progression as opposed to this test where we're just accumulating more and more items into the queue. Why does it matter, though?
Summary
Assess performance of Bloom Db as number of rows scales
Approach
I'm running repeated invocations of
test_create_acceessioning_wf()
and monitoring the size of thegeneric_instance
table in a script. Evaluation to followEnvironment
Database
Application