Details

    • Test
    • Status: In Progress
    • Major
    • Resolution: Unresolved
    • 1.16.0
    • None
    • Router Node

    Description

      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.

      Attachments

        1. DISPATCH-2183_3f2bd_router-mesh_three-router-test_routerb.txt
          104 kB
          Charles E. Rolke
        2. DISPATCH-2183_80c84_PYTHON-locking-during-get-schema.txt
          317 kB
          Charles E. Rolke
        3. DISPATCH-2183_85f805_topology-disposition-routerA.txt
          282 kB
          Charles E. Rolke
        4. DISPATCH-2183_pr1261_at_80c84.txt
          31 kB
          Charles E. Rolke

        Activity

          Commit 3f2bd adds a few improvements the biggest of which is untangling the held_lock in the core thread condition wait. This commit also trims the system tests router logging to info level to get the log locks out of the picture (at the expense of having a bunch of tests that rely on logging fail).

          chug Charles E. Rolke added a comment - Commit 3f2bd adds a few improvements the biggest of which is untangling the held_lock in the core thread condition wait. This commit also trims the system tests router logging to info level to get the log locks out of the picture (at the expense of having a bunch of tests that rely on logging fail).

          Commit 2b7a4 adds

          • printouts of the router server start/stop times
          • deadlock analysis

          Two recurring deadlocks happen in multiple routers:

          CONNECTOR - ENTITY_CACHE

          This lock inversion occurs after startup and before shutdown and should be mitigated.

          371179227080 Server  begin time: 2021-07-06 14:22:59.698457, ticks: 371179227080
          371179227358 TID:       0x513580   LOCK        CONNECTOR       ALLOC_INIT     ENTITY_CACHE ==> [ LOCK acquire_uS 0 ]
          371179227407 TID:       0x513580 UNLOCK        CONNECTOR       ALLOC_INIT     ENTITY_CACHE <== [0x17bb488 UNLOCK acquire_uS 0 use 49 total  49 ]
          371228850930 TID:       0x513580   LOCK           PYTHON           ROUTER     ENTITY_CACHE        CONNECTOR ==> [ LOCK acquire_uS 0 ]
          371228850938 TID:       0x513580 UNLOCK           PYTHON           ROUTER     ENTITY_CACHE        CONNECTOR <== [0x1b1c848 UNLOCK acquire_uS 0 use 8 total  8 ]
          371229387480 Server    end time: 2021-07-06 14:23:49.858857, ticks: 371229387480
          

          LOG - ENTITY_CACHE

          This inversion appears less problematic as code holding the LOG lock and taking the ENTITY_CACHE lock happens only at startup.
          At runtime code holding the ENTITY_CACHE lock routinely takes the LOG lock.

          371179125586 TID:       0x513580   LOCK              LOG     ENTITY_CACHE ==> [ LOCK acquire_uS 0 ]
          371179125591 TID:       0x513580 UNLOCK              LOG     ENTITY_CACHE <== [0x17bb488 UNLOCK acquire_uS 0 use 5 total  5 ]
          371179220368 TID:       0x513580   LOCK           PYTHON              LOG     ENTITY_CACHE ==> [ LOCK acquire_uS 0 ]
          371179220372 TID:       0x513580 UNLOCK           PYTHON              LOG     ENTITY_CACHE <== [0x17bb488 UNLOCK acquire_uS 0 use 4 total  4 ]
          
          371179227080 Server  begin time: 2021-07-06 14:22:59.698457, ticks: 371179227080
          371228849932 TID:       0x513580   LOCK           PYTHON           ROUTER     ENTITY_CACHE              LOG ==> [ LOCK acquire_uS 1 ]
          371229387480 Server    end time: 2021-07-06 14:23:49.858857, ticks: 371229387480
          
          chug Charles E. Rolke added a comment - Commit 2b7a4 adds printouts of the router server start/stop times deadlock analysis Two recurring deadlocks happen in multiple routers: CONNECTOR - ENTITY_CACHE This lock inversion occurs after startup and before shutdown and should be mitigated. 371179227080 Server begin time: 2021-07-06 14:22:59.698457, ticks: 371179227080 371179227358 TID: 0x513580 LOCK CONNECTOR ALLOC_INIT ENTITY_CACHE ==> [ LOCK acquire_uS 0 ] 371179227407 TID: 0x513580 UNLOCK CONNECTOR ALLOC_INIT ENTITY_CACHE <== [0x17bb488 UNLOCK acquire_uS 0 use 49 total 49 ] 371228850930 TID: 0x513580 LOCK PYTHON ROUTER ENTITY_CACHE CONNECTOR ==> [ LOCK acquire_uS 0 ] 371228850938 TID: 0x513580 UNLOCK PYTHON ROUTER ENTITY_CACHE CONNECTOR <== [0x1b1c848 UNLOCK acquire_uS 0 use 8 total 8 ] 371229387480 Server end time: 2021-07-06 14:23:49.858857, ticks: 371229387480 LOG - ENTITY_CACHE This inversion appears less problematic as code holding the LOG lock and taking the ENTITY_CACHE lock happens only at startup. At runtime code holding the ENTITY_CACHE lock routinely takes the LOG lock. 371179125586 TID: 0x513580 LOCK LOG ENTITY_CACHE ==> [ LOCK acquire_uS 0 ] 371179125591 TID: 0x513580 UNLOCK LOG ENTITY_CACHE <== [0x17bb488 UNLOCK acquire_uS 0 use 5 total 5 ] 371179220368 TID: 0x513580 LOCK PYTHON LOG ENTITY_CACHE ==> [ LOCK acquire_uS 0 ] 371179220372 TID: 0x513580 UNLOCK PYTHON LOG ENTITY_CACHE <== [0x17bb488 UNLOCK acquire_uS 0 use 4 total 4 ] 371179227080 Server begin time: 2021-07-06 14:22:59.698457, ticks: 371179227080 371228849932 TID: 0x513580 LOCK PYTHON ROUTER ENTITY_CACHE LOG ==> [ LOCK acquire_uS 1 ] 371229387480 Server end time: 2021-07-06 14:23:49.858857, ticks: 371229387480

          PYTHON - SERVER

          Grepping all the self-test logs and out files reveals a third inversion pattern. This pattern is not a problem as it happens only during startup.

          chug Charles E. Rolke added a comment - PYTHON - SERVER Grepping all the self-test logs and out files reveals a third inversion pattern. This pattern is not a problem as it happens only during startup.

          After adding program stack backtrace to the lock analysis setup then the code causing the lock inversions are identified.

          connector-before-entity_cache when connector creates a new connection

          462473116894 TID:       0x513580   LOCK        connector       ALLOC_INIT     ENTITY_CACHE ==> [ LOCK acquire_uS 0
             stack_0: qdrouterd(_dump_locks_lock+0x15e) [0x46bbf9],
             stack_1: qdrouterd(sys_mutex_lock+0x13b) [0x46c283],
             stack_2: qdrouterd() [0x45230d],
             stack_3: qdrouterd(qd_entity_cache_add+0x25) [0x452439],
             stack_4: qdrouterd() [0x443f2e],
             stack_5: qdrouterd(qd_alloc+0x2a) [0x443f6a],
             stack_6: qdrouterd(new_qd_connection_t+0x20) [0x4b5420],
             stack_7: qdrouterd(qd_server_connection+0x15) [0x4b6e3c],
             stack_8: qdrouterd(try_open_lh+0x27) [0x4b90ce],
             stack_9: qdrouterd(try_open_cb+0x50) [0x4b9933], ]
          
          462473117172 TID:       0x513580 UNLOCK        connector       ALLOC_INIT     ENTITY_CACHE <== [0x1c7c488 UNLOCK acquire_uS 0 use 278 total  278
             stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46be90],
             stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c388],
             stack_2: qdrouterd() [0x45240f],
             stack_3: qdrouterd(qd_entity_cache_add+0x25) [0x452439],
             stack_4: qdrouterd() [0x443f2e],
             stack_5: qdrouterd(qd_alloc+0x2a) [0x443f6a],
             stack_6: qdrouterd(new_qd_connection_t+0x20) [0x4b5420],
             stack_7: qdrouterd(qd_server_connection+0x15) [0x4b6e3c],
             stack_8: qdrouterd(try_open_lh+0x27) [0x4b90ce],
             stack_9: qdrouterd(try_open_cb+0x50) [0x4b9933], ]
          

          entity_cache-before-connector during routine management refresh cycle

          462480493625 TID:      0x1df81c0   LOCK           PYTHON           ROUTER     ENTITY_CACHE        connector ==> [ LOCK acquire_uS 0
             stack_0: qdrouterd(_dump_locks_lock+0x15e) [0x46bbf9],
             stack_1: qdrouterd(sys_mutex_lock+0x13b) [0x46c283],
             stack_2: qdrouterd(qd_entity_refresh_connector+0x46) [0x44b6ef],
             stack_3: /lib64/libffi.so.6(ffi_call_unix64+0x4c) [0x7f3cae2f2b10],
             stack_4: /lib64/libffi.so.6(ffi_call+0x1c3) [0x7f3cae2f20a3],
             stack_5: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x12b94) [0x7f3cadf83b94],
             stack_6: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x121a0) [0x7f3cadf831a0],
             stack_7: /lib64/libpython3.9.so.1.0(_PyObject_MakeTpCall+0x83) [0x7f3cbc77aee3],
             stack_8: /lib64/libpython3.9.so.1.0(_PyEval_EvalFrameDefault+0x599b) [0x7f3cbc777b3b],
             stack_9: /lib64/libpython3.9.so.1.0(+0x118b1b) [0x7f3cbc77fb1b], ]
          
          462480493773 TID:      0x1df81c0 UNLOCK           PYTHON           ROUTER     ENTITY_CACHE        connector <== [0x1ff66c8 UNLOCK acquire_uS 0 use 148 total  148
             stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46be90],
             stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c388],
             stack_2: qdrouterd(qd_entity_refresh_connector+0x2c0) [0x44b969],
             stack_3: /lib64/libffi.so.6(ffi_call_unix64+0x4c) [0x7f3cae2f2b10],
             stack_4: /lib64/libffi.so.6(ffi_call+0x1c3) [0x7f3cae2f20a3],
             stack_5: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x12b94) [0x7f3cadf83b94],
             stack_6: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x121a0) [0x7f3cadf831a0],
             stack_7: /lib64/libpython3.9.so.1.0(_PyObject_MakeTpCall+0x83) [0x7f3cbc77aee3],
             stack_8: /lib64/libpython3.9.so.1.0(_PyEval_EvalFrameDefault+0x599b) [0x7f3cbc777b3b],
             stack_9: /lib64/libpython3.9.so.1.0(+0x118b1b) [0x7f3cbc77fb1b], ]
          
          chug Charles E. Rolke added a comment - After adding program stack backtrace to the lock analysis setup then the code causing the lock inversions are identified. connector-before-entity_cache when connector creates a new connection 462473116894 TID: 0x513580 LOCK connector ALLOC_INIT ENTITY_CACHE ==> [ LOCK acquire_uS 0 stack_0: qdrouterd(_dump_locks_lock+0x15e) [0x46bbf9], stack_1: qdrouterd(sys_mutex_lock+0x13b) [0x46c283], stack_2: qdrouterd() [0x45230d], stack_3: qdrouterd(qd_entity_cache_add+0x25) [0x452439], stack_4: qdrouterd() [0x443f2e], stack_5: qdrouterd(qd_alloc+0x2a) [0x443f6a], stack_6: qdrouterd(new_qd_connection_t+0x20) [0x4b5420], stack_7: qdrouterd(qd_server_connection+0x15) [0x4b6e3c], stack_8: qdrouterd(try_open_lh+0x27) [0x4b90ce], stack_9: qdrouterd(try_open_cb+0x50) [0x4b9933], ] 462473117172 TID: 0x513580 UNLOCK connector ALLOC_INIT ENTITY_CACHE <== [0x1c7c488 UNLOCK acquire_uS 0 use 278 total 278 stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46be90], stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c388], stack_2: qdrouterd() [0x45240f], stack_3: qdrouterd(qd_entity_cache_add+0x25) [0x452439], stack_4: qdrouterd() [0x443f2e], stack_5: qdrouterd(qd_alloc+0x2a) [0x443f6a], stack_6: qdrouterd(new_qd_connection_t+0x20) [0x4b5420], stack_7: qdrouterd(qd_server_connection+0x15) [0x4b6e3c], stack_8: qdrouterd(try_open_lh+0x27) [0x4b90ce], stack_9: qdrouterd(try_open_cb+0x50) [0x4b9933], ] entity_cache-before-connector during routine management refresh cycle 462480493625 TID: 0x1df81c0 LOCK PYTHON ROUTER ENTITY_CACHE connector ==> [ LOCK acquire_uS 0 stack_0: qdrouterd(_dump_locks_lock+0x15e) [0x46bbf9], stack_1: qdrouterd(sys_mutex_lock+0x13b) [0x46c283], stack_2: qdrouterd(qd_entity_refresh_connector+0x46) [0x44b6ef], stack_3: /lib64/libffi.so.6(ffi_call_unix64+0x4c) [0x7f3cae2f2b10], stack_4: /lib64/libffi.so.6(ffi_call+0x1c3) [0x7f3cae2f20a3], stack_5: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x12b94) [0x7f3cadf83b94], stack_6: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x121a0) [0x7f3cadf831a0], stack_7: /lib64/libpython3.9.so.1.0(_PyObject_MakeTpCall+0x83) [0x7f3cbc77aee3], stack_8: /lib64/libpython3.9.so.1.0(_PyEval_EvalFrameDefault+0x599b) [0x7f3cbc777b3b], stack_9: /lib64/libpython3.9.so.1.0(+0x118b1b) [0x7f3cbc77fb1b], ] 462480493773 TID: 0x1df81c0 UNLOCK PYTHON ROUTER ENTITY_CACHE connector <== [0x1ff66c8 UNLOCK acquire_uS 0 use 148 total 148 stack_0: qdrouterd(_dump_locks_unlock+0x1dd) [0x46be90], stack_1: qdrouterd(sys_mutex_unlock+0x102) [0x46c388], stack_2: qdrouterd(qd_entity_refresh_connector+0x2c0) [0x44b969], stack_3: /lib64/libffi.so.6(ffi_call_unix64+0x4c) [0x7f3cae2f2b10], stack_4: /lib64/libffi.so.6(ffi_call+0x1c3) [0x7f3cae2f20a3], stack_5: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x12b94) [0x7f3cadf83b94], stack_6: /usr/lib64/python3.9/lib-dynload/_ctypes.cpython-39-x86_64-linux-gnu.so(+0x121a0) [0x7f3cadf831a0], stack_7: /lib64/libpython3.9.so.1.0(_PyObject_MakeTpCall+0x83) [0x7f3cbc77aee3], stack_8: /lib64/libpython3.9.so.1.0(_PyEval_EvalFrameDefault+0x599b) [0x7f3cbc777b3b], stack_9: /lib64/libpython3.9.so.1.0(+0x118b1b) [0x7f3cbc77fb1b], ]

          The following lock stacks are observed while running the full suite of self tests

          Lock stacks
          ===========
          
          Found 139 lock stacks
          In each line the first held lock is on the left
          
          ALLOC_INIT,ENTITY_CACHE                         
          CONNECTOR,ALLOC_INIT                            
          CONNECTOR,ALLOC_INIT,ENTITY_CACHE               
          CONNECTOR,LOG                                   
          CONNECTOR,LOG,qd_log_entry_t                    
          CONNECTOR,SERVER                                
          CONNECTOR,qd_connection_t                       
          CONNECTOR,qd_log_entry_t                        
          CONN_ACTIVATION,LOG                             
          CONN_ACTIVATION,LOG,qd_log_entry_t              
          CONN_ACTIVATION,SERVER                          
          CONN_ACTIVATION,qd_connection_t                 
          CONN_ACTIVATION,qd_log_entry_t                  
          CONN_WORK,ALLOC_INIT                            
          CONN_WORK,ALLOC_INIT,ENTITY_CACHE               
          CONN_WORK,CORE_ACTION                           
          CONN_WORK,LOG                                   
          CONN_WORK,LOG,qd_log_entry_t                    
          CONN_WORK,qd_buffer_t                           
          CONN_WORK,qd_iterator_t                         
          CONN_WORK,qd_log_entry_t                        
          CONN_WORK,qdr_action_t                          
          CONN_WORK,qdr_delivery_cleanup_t                
          CONN_WORK,qdr_delivery_ref_t                    
          CONN_WORK,qdr_delivery_t                        
          CONN_WORK,qdr_error_t                           
          CONN_WORK,qdr_field_t                           
          CONN_WORK,qdr_link_ref_t                        
          CONN_WORK,qdr_link_work_t                       
          CORE_ACTION,qdr_action_t                        
          HTTP1_ADAPTOR,CORE_ACTION                       
          HTTP1_ADAPTOR,SERVER                            
          HTTP1_ADAPTOR,qdr_action_t                      
          LOG,ENTITY_CACHE                                
          LOG,qd_log_entry_t                              
          MSG_CONTENT,ALLOC_INIT                          
          MSG_CONTENT,ALLOC_INIT,ENTITY_CACHE             
          MSG_CONTENT,qd_buffer_t                         
          MSG_CONTENT,qd_message_stream_data_t            
          PYTHON,ALLOC_INIT                               
          PYTHON,ALLOC_INIT,ENTITY_CACHE                  
          PYTHON,CONNECTOR                                
          PYTHON,CONNECTOR,ALLOC_INIT                     
          PYTHON,CONNECTOR,ALLOC_INIT,ENTITY_CACHE        
          PYTHON,CONNECTOR,CONN_ACTIVATION                
          PYTHON,CONNECTOR,CONN_DEFERRED_CALL             
          PYTHON,CONNECTOR,SERVER                         
          PYTHON,CONNECTOR,qd_deferred_call_t             
          PYTHON,CONTAINER                                
          PYTHON,CONTAINER,ALLOC_INIT                     
          PYTHON,CONTAINER,ALLOC_INIT,ENTITY_CACHE        
          PYTHON,CONTAINER,qd_hash_item_t                 
          PYTHON,CORE_ACTION                              
          PYTHON,CORE_ID                                  
          PYTHON,HTTP1_ADAPTOR                            
          PYTHON,HTTP1_ADAPTOR,CORE_ACTION                
          PYTHON,HTTP1_ADAPTOR,SERVER                     
          PYTHON,HTTP1_ADAPTOR,qdr_action_t               
          PYTHON,HTTP2_ADAPTOR                            
          PYTHON,LOG                                      
          PYTHON,LOG,ENTITY_CACHE                         
          PYTHON,LOG,qd_log_entry_t                       
          PYTHON,LWS_WORK_QUEUE                           
          PYTHON,MSG_CONTENT                              
          PYTHON,POLICY_TREE                              
          PYTHON,POLICY_TREE,LOG                          
          PYTHON,POLICY_TREE,qd_hash_handle_t             
          PYTHON,POLICY_TREE,qd_hash_item_t               
          PYTHON,POLICY_TREE,qd_log_entry_t               
          PYTHON,POLICY_TREE,qd_parse_node_t              
          PYTHON,ROUTER                                   
          PYTHON,ROUTER,ENTITY_CACHE                      
          PYTHON,ROUTER,ENTITY_CACHE,CONNECTOR            
          PYTHON,ROUTER,ENTITY_CACHE,LOG                  
          PYTHON,ROUTER,ENTITY_CACHE,LOG,qd_log_entry_t   
          PYTHON,ROUTER,ENTITY_CACHE,POLICY_STATS         
          PYTHON,ROUTER,ENTITY_CACHE,bridge_stats_lock    
          PYTHON,ROUTER,ENTITY_CACHE,qd_log_entry_t       
          PYTHON,SERVER                                   
          PYTHON,SERVER,qd_timer_t                        
          PYTHON,TRACE_MASK                               
          PYTHON,TRACE_MASK,ALLOC_INIT                    
          PYTHON,TRACE_MASK,ALLOC_INIT,ENTITY_CACHE       
          PYTHON,TRACE_MASK,qd_hash_handle_t              
          PYTHON,TRACE_MASK,qd_hash_item_t                
          PYTHON,TRACE_MASK,qdtm_router_t                 
          PYTHON,bridge_stats_lock                        
          PYTHON,qd_bitmask_t                             
          PYTHON,qd_buffer_t                              
          PYTHON,qd_composed_field_t                      
          PYTHON,qd_composite_t                           
          PYTHON,qd_connector_t                           
          PYTHON,qd_hash_handle_t                         
          PYTHON,qd_hash_item_t                           
          PYTHON,qd_http_connector_t                      
          PYTHON,qd_http_listener_t                       
          PYTHON,qd_iterator_t                            
          PYTHON,qd_listener_t                            
          PYTHON,qd_log_entry_t                           
          PYTHON,qd_message_content_t                     
          PYTHON,qd_message_t                             
          PYTHON,qd_node_t                                
          PYTHON,qd_parse_node_t                          
          PYTHON,qd_parse_tree_t                          
          PYTHON,qd_parsed_field_t                        
          PYTHON,qd_tcp_bridge_t                          
          PYTHON,qd_tcp_connector_t                       
          PYTHON,qd_tcp_listener_t                        
          PYTHON,qd_timer_t                               
          PYTHON,qdr_action_t                             
          PYTHON,qdr_address_t                            
          PYTHON,qdr_connection_info_t                    
          PYTHON,qdr_connection_t                         
          PYTHON,qdr_core_timer_t                         
          PYTHON,qdr_field_t                              
          PYTHON,qdr_http1_connection_t                   
          PYTHON,qdr_http2_connection_t                   
          PYTHON,qdr_http2_session_data_t                 
          PYTHON,qdr_http2_stream_data_t                  
          PYTHON,qdr_link_t                               
          PYTHON,qdr_query_t                              
          PYTHON,qdr_tcp_connection_t                     
          PYTHON,qdr_terminus_t                           
          SERVER,LOG                                      
          SERVER,LOG,qd_log_entry_t                       
          SERVER,POLICY_STATS                             
          SERVER,PYTHON                                   
          SERVER,qd_log_entry_t                           
          SERVER,qd_timer_t                               
          TCP_ACTIVATION,LOG                              
          TCP_ACTIVATION,LOG,qd_log_entry_t               
          TCP_ACTIVATION,qd_log_entry_t                   
          TRACE_MASK,qd_hash_handle_t                     
          TRACE_MASK,qd_hash_item_t                       
          TRACE_MASK,qdtm_router_t                        
          delivery-433,qd_delivery_state_t                
          delivery-437,qd_delivery_state_t                
          delivery-439,qd_delivery_state_t                
          delivery-459,qd_delivery_state_t                
          
          chug Charles E. Rolke added a comment - The following lock stacks are observed while running the full suite of self tests Lock stacks =========== Found 139 lock stacks In each line the first held lock is on the left ALLOC_INIT,ENTITY_CACHE CONNECTOR,ALLOC_INIT CONNECTOR,ALLOC_INIT,ENTITY_CACHE CONNECTOR,LOG CONNECTOR,LOG,qd_log_entry_t CONNECTOR,SERVER CONNECTOR,qd_connection_t CONNECTOR,qd_log_entry_t CONN_ACTIVATION,LOG CONN_ACTIVATION,LOG,qd_log_entry_t CONN_ACTIVATION,SERVER CONN_ACTIVATION,qd_connection_t CONN_ACTIVATION,qd_log_entry_t CONN_WORK,ALLOC_INIT CONN_WORK,ALLOC_INIT,ENTITY_CACHE CONN_WORK,CORE_ACTION CONN_WORK,LOG CONN_WORK,LOG,qd_log_entry_t CONN_WORK,qd_buffer_t CONN_WORK,qd_iterator_t CONN_WORK,qd_log_entry_t CONN_WORK,qdr_action_t CONN_WORK,qdr_delivery_cleanup_t CONN_WORK,qdr_delivery_ref_t CONN_WORK,qdr_delivery_t CONN_WORK,qdr_error_t CONN_WORK,qdr_field_t CONN_WORK,qdr_link_ref_t CONN_WORK,qdr_link_work_t CORE_ACTION,qdr_action_t HTTP1_ADAPTOR,CORE_ACTION HTTP1_ADAPTOR,SERVER HTTP1_ADAPTOR,qdr_action_t LOG,ENTITY_CACHE LOG,qd_log_entry_t MSG_CONTENT,ALLOC_INIT MSG_CONTENT,ALLOC_INIT,ENTITY_CACHE MSG_CONTENT,qd_buffer_t MSG_CONTENT,qd_message_stream_data_t PYTHON,ALLOC_INIT PYTHON,ALLOC_INIT,ENTITY_CACHE PYTHON,CONNECTOR PYTHON,CONNECTOR,ALLOC_INIT PYTHON,CONNECTOR,ALLOC_INIT,ENTITY_CACHE PYTHON,CONNECTOR,CONN_ACTIVATION PYTHON,CONNECTOR,CONN_DEFERRED_CALL PYTHON,CONNECTOR,SERVER PYTHON,CONNECTOR,qd_deferred_call_t PYTHON,CONTAINER PYTHON,CONTAINER,ALLOC_INIT PYTHON,CONTAINER,ALLOC_INIT,ENTITY_CACHE PYTHON,CONTAINER,qd_hash_item_t PYTHON,CORE_ACTION PYTHON,CORE_ID PYTHON,HTTP1_ADAPTOR PYTHON,HTTP1_ADAPTOR,CORE_ACTION PYTHON,HTTP1_ADAPTOR,SERVER PYTHON,HTTP1_ADAPTOR,qdr_action_t PYTHON,HTTP2_ADAPTOR PYTHON,LOG PYTHON,LOG,ENTITY_CACHE PYTHON,LOG,qd_log_entry_t PYTHON,LWS_WORK_QUEUE PYTHON,MSG_CONTENT PYTHON,POLICY_TREE PYTHON,POLICY_TREE,LOG PYTHON,POLICY_TREE,qd_hash_handle_t PYTHON,POLICY_TREE,qd_hash_item_t PYTHON,POLICY_TREE,qd_log_entry_t PYTHON,POLICY_TREE,qd_parse_node_t PYTHON,ROUTER PYTHON,ROUTER,ENTITY_CACHE PYTHON,ROUTER,ENTITY_CACHE,CONNECTOR PYTHON,ROUTER,ENTITY_CACHE,LOG PYTHON,ROUTER,ENTITY_CACHE,LOG,qd_log_entry_t PYTHON,ROUTER,ENTITY_CACHE,POLICY_STATS PYTHON,ROUTER,ENTITY_CACHE,bridge_stats_lock PYTHON,ROUTER,ENTITY_CACHE,qd_log_entry_t PYTHON,SERVER PYTHON,SERVER,qd_timer_t PYTHON,TRACE_MASK PYTHON,TRACE_MASK,ALLOC_INIT PYTHON,TRACE_MASK,ALLOC_INIT,ENTITY_CACHE PYTHON,TRACE_MASK,qd_hash_handle_t PYTHON,TRACE_MASK,qd_hash_item_t PYTHON,TRACE_MASK,qdtm_router_t PYTHON,bridge_stats_lock PYTHON,qd_bitmask_t PYTHON,qd_buffer_t PYTHON,qd_composed_field_t PYTHON,qd_composite_t PYTHON,qd_connector_t PYTHON,qd_hash_handle_t PYTHON,qd_hash_item_t PYTHON,qd_http_connector_t PYTHON,qd_http_listener_t PYTHON,qd_iterator_t PYTHON,qd_listener_t PYTHON,qd_log_entry_t PYTHON,qd_message_content_t PYTHON,qd_message_t PYTHON,qd_node_t PYTHON,qd_parse_node_t PYTHON,qd_parse_tree_t PYTHON,qd_parsed_field_t PYTHON,qd_tcp_bridge_t PYTHON,qd_tcp_connector_t PYTHON,qd_tcp_listener_t PYTHON,qd_timer_t PYTHON,qdr_action_t PYTHON,qdr_address_t PYTHON,qdr_connection_info_t PYTHON,qdr_connection_t PYTHON,qdr_core_timer_t PYTHON,qdr_field_t PYTHON,qdr_http1_connection_t PYTHON,qdr_http2_connection_t PYTHON,qdr_http2_session_data_t PYTHON,qdr_http2_stream_data_t PYTHON,qdr_link_t PYTHON,qdr_query_t PYTHON,qdr_tcp_connection_t PYTHON,qdr_terminus_t SERVER,LOG SERVER,LOG,qd_log_entry_t SERVER,POLICY_STATS SERVER,PYTHON SERVER,qd_log_entry_t SERVER,qd_timer_t TCP_ACTIVATION,LOG TCP_ACTIVATION,LOG,qd_log_entry_t TCP_ACTIVATION,qd_log_entry_t TRACE_MASK,qd_hash_handle_t TRACE_MASK,qd_hash_item_t TRACE_MASK,qdtm_router_t delivery-433,qd_delivery_state_t delivery-437,qd_delivery_state_t delivery-439,qd_delivery_state_t delivery-459,qd_delivery_state_t

          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.

           

          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], ]
          
          chug Charles E. Rolke added a comment - 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.   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], ]

          People

            chug Charles E. Rolke
            chug Charles E. Rolke
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: