[
https://issues.apache.org/jira/browse/DISPATCH-2183?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17378239#comment-17378239
]
Charles E. Rolke commented on DISPATCH-2183:
--------------------------------------------
While investigating the SERVER-PYTHON inversion this table emerged. The test
program counts the lines of UNLOCK output as they are processed and further
counts how many times each individual lock stack is encountered. Locks stacks
with only one lock (i.e. lock is taken and released without taking any other
lock) are not processed other than counting the 54+ million of them.
This is generated by the full self test suite.
{code:java}
Lock stacks
===========
Found 69785766 lines total
Found 69785766 UNLOCK lines
Found 135 lock stacks len >= 2 to process
Found 54202664 lock stacks len == 1 to ignore
ALLOC_INIT,ENTITY_CACHE : n= 6661 :
CONN_ACTIVATION,LOG : n= 154 :
CONN_ACTIVATION,LOG,qd_log_entry_t : n= 126 :
CONN_ACTIVATION,SERVER : n= 1 :
CONN_ACTIVATION,qd_connection_t : n= 3536 :
CONN_ACTIVATION,qd_log_entry_t : n= 156 :
CONN_WORK,ALLOC_INIT : n= 256 :
CONN_WORK,ALLOC_INIT,ENTITY_CACHE : n= 256 :
CONN_WORK,CORE_ACTION : n= 38 :
CONN_WORK,LOG : n= 757792 :
CONN_WORK,LOG,qd_log_entry_t : n= 746164 :
CONN_WORK,qd_buffer_t : n= 810 :
CONN_WORK,qd_iterator_t : n= 810 :
CONN_WORK,qd_log_entry_t : n= 758580 :
CONN_WORK,qdr_action_t : n= 40 :
CONN_WORK,qdr_delivery_cleanup_t : n= 330 :
CONN_WORK,qdr_delivery_ref_t : n= 165289 :
CONN_WORK,qdr_delivery_t : n= 330 :
CONN_WORK,qdr_error_t : n= 487 :
CONN_WORK,qdr_field_t : n= 810 :
CONN_WORK,qdr_link_ref_t : n= 353081 :
CONN_WORK,qdr_link_work_t : n= 179491 :
CORE_ACTION,qdr_action_t : n= 76257 :
HTTP1_ADAPTOR,CORE_ACTION : n= 8 :
HTTP1_ADAPTOR,SERVER : n= 503 :
HTTP1_ADAPTOR,qdr_action_t : n= 8 :
LOG,ENTITY_CACHE : n= 1760 :
LOG,qd_log_entry_t : n= 6887152 :
MSG_CONTENT,ALLOC_INIT : n= 20 :
MSG_CONTENT,ALLOC_INIT,ENTITY_CACHE : n= 20 :
MSG_CONTENT,qd_buffer_t : n= 4211906 :
MSG_CONTENT,qd_message_stream_data_t : n= 12361 :
PYTHON,ALLOC_INIT : n= 5452 :
PYTHON,ALLOC_INIT,ENTITY_CACHE : n= 5452 :
PYTHON,CONTAINER : n= 336 :
PYTHON,CONTAINER,ALLOC_INIT : n= 336 :
PYTHON,CONTAINER,ALLOC_INIT,ENTITY_CACHE : n= 336 :
PYTHON,CONTAINER,qd_hash_item_t : n= 1008 :
PYTHON,CORE_ACTION : n= 11763 :
PYTHON,CORE_ID : n= 14 :
PYTHON,HTTP1_ADAPTOR : n= 20 :
PYTHON,HTTP1_ADAPTOR,CORE_ACTION : n= 1 :
PYTHON,HTTP1_ADAPTOR,SERVER : n= 9 :
PYTHON,HTTP1_ADAPTOR,qdr_action_t : n= 1 :
PYTHON,HTTP2_ADAPTOR : n= 1 :
PYTHON,LOG : n= 62096 :
PYTHON,LOG,ENTITY_CACHE : n= 5392 :
PYTHON,LOG,qd_log_entry_t : n= 14941 :
PYTHON,LWS_WORK_QUEUE : n= 24 :
PYTHON,MSG_CONTENT : n= 7696 :
PYTHON,POLICY_TREE : n= 7 :
PYTHON,POLICY_TREE,LOG : n= 10 :
PYTHON,POLICY_TREE,qd_hash_handle_t : n= 8 :
PYTHON,POLICY_TREE,qd_hash_item_t : n= 4 :
PYTHON,POLICY_TREE,qd_log_entry_t : n= 8 :
PYTHON,POLICY_TREE,qd_parse_node_t : n= 6 :
PYTHON,ROUTER : n= 1314 :
PYTHON,ROUTER,ENTITY_CACHE : n= 1314 :
PYTHON,ROUTER,ENTITY_CACHE,LOG : n= 15731 :
PYTHON,ROUTER,ENTITY_CACHE,LOG,qd_log_entry_t : n= 863 :
PYTHON,ROUTER,ENTITY_CACHE,POLICY_STATS : n= 978 :
PYTHON,ROUTER,ENTITY_CACHE,bridge_stats_lock : n= 145 :
PYTHON,ROUTER,ENTITY_CACHE,connector : n= 402 :
PYTHON,ROUTER,ENTITY_CACHE,qd_log_entry_t : n= 16624 :
PYTHON,SERVER : n= 371 :
PYTHON,SERVER,qd_timer_t : n= 11 :
PYTHON,TRACE_MASK : n= 640 :
PYTHON,TRACE_MASK,ALLOC_INIT : n= 128 :
PYTHON,TRACE_MASK,ALLOC_INIT,ENTITY_CACHE : n= 128 :
PYTHON,TRACE_MASK,qd_hash_handle_t : n= 387 :
PYTHON,TRACE_MASK,qd_hash_item_t : n= 387 :
PYTHON,TRACE_MASK,qdtm_router_t : n= 463 :
PYTHON,bridge_stats_lock : n= 121 :
PYTHON,connector : n= 369 :
PYTHON,connector,CONN_ACTIVATION : n= 7 :
PYTHON,connector,CONN_DEFERRED_CALL : n= 7 :
PYTHON,connector,SERVER : n= 181 :
PYTHON,qd_bitmask_t : n= 2286 :
PYTHON,qd_buffer_t : n= 74510 :
PYTHON,qd_composed_field_t : n= 47848 :
PYTHON,qd_composite_t : n= 125918 :
PYTHON,qd_connector_t : n= 495 :
PYTHON,qd_deferred_call_t : n= 19 :
PYTHON,qd_hash_handle_t : n= 1825 :
PYTHON,qd_hash_item_t : n= 1397 :
PYTHON,qd_http_connector_t : n= 25 :
PYTHON,qd_http_listener_t : n= 25 :
PYTHON,qd_iterator_t : n= 599462 :
PYTHON,qd_listener_t : n= 1228 :
PYTHON,qd_log_entry_t : n= 49078 :
PYTHON,qd_message_content_t : n= 9062 :
PYTHON,qd_message_t : n= 23200 :
PYTHON,qd_node_t : n= 1008 :
PYTHON,qd_parse_node_t : n= 2201 :
PYTHON,qd_parse_tree_t : n= 2056 :
PYTHON,qd_parsed_field_t : n= 265820 :
PYTHON,qd_tcp_bridge_t : n= 130 :
PYTHON,qd_tcp_connector_t : n= 37 :
PYTHON,qd_tcp_listener_t : n= 119 :
PYTHON,qd_timer_t : n= 1903 :
PYTHON,qdr_action_t : n= 12648 :
PYTHON,qdr_address_t : n= 1700 :
PYTHON,qdr_connection_info_t : n= 59 :
PYTHON,qdr_connection_t : n= 59 :
PYTHON,qdr_core_timer_t : n= 1511 :
PYTHON,qdr_field_t : n= 11172 :
PYTHON,qdr_http1_connection_t : n= 21 :
PYTHON,qdr_http2_connection_t : n= 3 :
PYTHON,qdr_http2_session_data_t : n= 3 :
PYTHON,qdr_http2_stream_data_t : n= 3 :
PYTHON,qdr_link_t : n= 38 :
PYTHON,qdr_query_t : n= 935 :
PYTHON,qdr_tcp_connection_t : n= 35 :
PYTHON,qdr_terminus_t : n= 52 :
SERVER,LOG : n= 3985 :
SERVER,LOG,qd_log_entry_t : n= 2424 :
SERVER,POLICY_STATS : n= 6793 :
SERVER,PYTHON : n= 462 :
SERVER,qd_log_entry_t : n= 4197 :
SERVER,qd_timer_t : n= 1180 :
TCP_ACTIVATION,LOG : n= 1281 :
TCP_ACTIVATION,LOG,qd_log_entry_t : n= 1161 :
TCP_ACTIVATION,qd_log_entry_t : n= 1287 :
TRACE_MASK,qd_hash_handle_t : n= 187 :
TRACE_MASK,qd_hash_item_t : n= 187 :
TRACE_MASK,qdtm_router_t : n= 275 :
connector,LOG : n= 255 :
connector,LOG,qd_log_entry_t : n= 31 :
connector,SERVER : n= 376 :
connector,qd_log_entry_t : n= 431 :
delivery-405,qd_delivery_state_t : n= 2 :
delivery-407,qd_delivery_state_t : n= 2 :
delivery-409,qd_delivery_state_t : n= 3 :
delivery-411,qd_delivery_state_t : n= 6 :
delivery-431,qd_delivery_state_t : n= 1 :
Possible deadlocks
==================
Inversion PYTHON and SERVER
Inversion ENTITY_CACHE and LOG
Inversion LOG and ENTITY_CACHE
Inversion SERVER and PYTHON
SERVER,PYTHON : n= 462 :
./tests/system_test.dir/system_tests_authz_service_plugin/AuthServicePluginAuthzTest/setUpClass/router-3.out:619102552328
TID: 0x1180190 UNLOCK SERVER PYTHON <== [0xe73a08
UNLOCK acquire_uS 0 use 227 total 227
stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46bebc],
stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c3b4],
stack_2: qdrouterd(qd_python_unlock+0x21) [0x46f4b0],
stack_3: qdrouterd(qd_policy_socket_close+0x15c) [0x465428],
stack_4: qdrouterd(qd_connection_free+0x201) [0x4b86b4],
stack_5: qdrouterd(thread_run+0x119) [0x4b9053],
stack_6: qdrouterd() [0x46cf6c],
stack_7: /lib64/libpthread.so.0(+0x93f9) [0x7f795e6ed3f9],
stack_8: /lib64/libc.so.6(clone+0x43) [0x7f795e2004c3], ]
PYTHON,SERVER : n= 371 :
./tests/system_test.dir/system_tests_qdmanage/QdmanageTest/setUpClass/test_router_1-2.out:618541611189
TID: 0x514580 UNLOCK PYTHON SERVER <== [0x1a64548
UNLOCK acquire_uS 0 use 156 total 156
stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46bebc],
stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c3b4],
stack_2: qdrouterd(qd_timer_schedule+0x3ee) [0x4bbd19],
stack_3: qdrouterd(qd_router_setup_late+0xfa) [0x4b3e58],
stack_4: /lib64/libffi.so.6(ffi_call_unix64+0x4c) [0x7f19c31ecb10],
stack_5: /lib64/libffi.so.6(ffi_call+0x1c3) [0x7f19c31ec0a3],
stack_6:
/usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x12b94)
[0x7f19c2e7db94],
stack_7:
/usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x121a0)
[0x7f19c2e7d1a0],
stack_8: /lib64/libpython3.9.so.1.0(_PyObject_MakeTpCall+0x83)
[0x7f19d1674ee3],
stack_9: /lib64/libpython3.9.so.1.0(_PyEval_EvalFrameDefault+0x599b)
[0x7f19d1671b3b], ]
PYTHON,SERVER,qd_timer_t : n= 11 :
./tests/system_test.dir/system_tests_qdmanage/QdmanageTest/setUpClass/test_router_1-2.out:618608318235
TID: 0x514580 UNLOCK PYTHON SERVER qd_timer_t
<== [0x1c7f708 UNLOCK acquire_uS 1 use 210 total 211
stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46bebc],
stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c3b4],
stack_2: qdrouterd(qd_dealloc+0x23a) [0x4448c7],
stack_3: qdrouterd(free_qd_timer_t+0x30) [0x4bb38f],
stack_4: qdrouterd() [0x4bb6ac],
stack_5: qdrouterd(qd_timer_free+0xee) [0x4bb87b],
stack_6: qdrouterd(qd_connection_manager_delete_connector+0xf8) [0x44c6e8],
stack_7: /lib64/libffi.so.6(ffi_call_unix64+0x4c) [0x7f19c31ecb10],
stack_8: /lib64/libffi.so.6(ffi_call+0x1c3) [0x7f19c31ec0a3], stack_9:
/usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x12b94)
[0x7f19c2e7db94], ]
{code}
> Thread locking analysis
> -----------------------
>
> Key: DISPATCH-2183
> URL: https://issues.apache.org/jira/browse/DISPATCH-2183
> Project: Qpid Dispatch
> Issue Type: Test
> Components: Router Node
> Affects Versions: 1.16.0
> Reporter: Charles E. Rolke
> Assignee: Charles E. Rolke
> Priority: Major
> Labels: performance
> Attachments:
> DISPATCH-2183_3f2bd_router-mesh_three-router-test_routerb.txt,
> DISPATCH-2183_85f805_topology-disposition-routerA.txt
>
>
> This issue holds files related to thread locking analysis tracked in
> [https://github.com/apache/qpid-dispatch/pull/1261|PR-1261]. As the PR
> progresses analysis results will be posted here.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
