[jira] [Assigned] (PROTON-2680) [proton-c] PN_RAW_CONNECTION_DISCONNECTED event does not show up when client is disconnected

2023-02-16 Thread Ken Giusti (Jira) 


 [ 
https://issues.apache.org/jira/browse/PROTON-2680?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Ken Giusti reassigned PROTON-2680:
--

Assignee: Clifford Jansen  (was: Ken Giusti)

> [proton-c] PN_RAW_CONNECTION_DISCONNECTED event does not show up when client 
> is disconnected 
> -
>
> Key: PROTON-2680
> URL: https://issues.apache.org/jira/browse/PROTON-2680
> Project: Qpid Proton
>  Issue Type: Bug
>  Components: proton-c
>Reporter: Ganesh Murthy
>Assignee: Clifford Jansen
>Priority: Major
>
> Steps to reproduce
> Start the skupper-router with the following config -
> {noformat}
> router {
> mode: standalone
> }
> listener {
> host: 0.0.0.0
> port: amqp
> authenticatePeer: no
> saslMechanisms: ANONYMOUS
> }
> tcpConnector {
> name: echo-1
> host: 10.108.50.177
> port: 9090
> address: echo
> }
> tcpConnector {
> name: echo-2
> host: 10.108.50.177
> port: 9090
> address: echo
> }
> tcpListener {
> host: 0.0.0.0
> port: 9000
> address: echo
> }  
> log {
>     module: DEFAULT
>     enable: trace+
>     outputFile: tcp.log
> } {noformat}
>  
> Note that the ip address in the host field of the tcpConnector is bogus.
> Now connect a curl client to the tcpListener port  -
> {noformat}
> curl http://localhost:9000/api {noformat}
>  
> The curl client will hang. Terminate the curl client and look in the tcp.log 
> for logged proton events - the PN_RAW_CONNECTION_DISCONNECTED event will be 
> missing on connection C2
> Here is the full log of the relevant client connection
>  
> {noformat}
> 2023-02-01 16:51:57.069705 -0500 ROUTER_CORE (info) [C2] Connection Opened: 
> dir=in host=127.0.0.1:35348 encrypted=no auth=no user= 
> container_id=TcpAdaptor props={:"qd.adaptor"="tcp"}
> 2023-02-01 16:51:57.069793 -0500 ROUTER_CORE (trace) Core action 
> 'connection_opened'
> 2023-02-01 16:51:57.069986 -0500 TCP_ADAPTOR (info) [C2] 
> PN_RAW_CONNECTION_CONNECTED Listener ingress accepted to 0.0.0.0:9000 from 
> 127.0.0.1:35348 (global_id=127.0.0.1:35348)
> 2023-02-01 16:51:57.070015 -0500 ROUTER_CORE (trace) Core action 
> 'link_first_attach'
> 2023-02-01 16:51:57.070098 -0500 TCP_ADAPTOR (debug) [C2] 
> PN_RAW_CONNECTION_NEED_WRITE_BUFFERS listener
> 2023-02-01 16:51:57.070148 -0500 TCP_ADAPTOR (debug) [C2] 
> PN_RAW_CONNECTION_NEED_READ_BUFFERS listener
> 2023-02-01 16:51:57.070171 -0500 ROUTER_CORE (info) [C2][L4] Link attached: 
> dir=out source={(dyn) expire:link} target={ expire:link}
> 2023-02-01 16:51:57.070222 -0500 TCP_ADAPTOR (debug) [C2] 
> qdr_tcp_activate_CT: call pn_raw_connection_wake()
> 2023-02-01 16:51:57.070246 -0500 ROUTER_CORE (trace) Core action 
> 'link_first_attach'
> 2023-02-01 16:51:57.070273 -0500 TCP_ADAPTOR (debug) [C2][L4] (listener 
> outgoing) qdr_tcp_second_attach
> 2023-02-01 16:51:57.070347 -0500 DEFAULT (trace) Parse tree search for 'echo'
> 2023-02-01 16:51:57.070376 -0500 TCP_ADAPTOR (trace) [C2][L5] handle_incoming 
> qdr_tcp_second_attach for listener connection. read_closed:F, flow_enabled:F
> 2023-02-01 16:51:57.070404 -0500 DEFAULT (trace) Parse tree match not found
> 2023-02-01 16:51:57.070425 -0500 TCP_ADAPTOR (debug) [C2][L5] Waiting for 
> credit before initiating listener ingress stream message, returning
> 2023-02-01 16:51:57.070456 -0500 TCP_ADAPTOR (debug) [C2][L4] 
> qdr_tcp_get_credit: NOOP
> 2023-02-01 16:51:57.070517 -0500 TCP_ADAPTOR (trace) Listener 
> tcpListener/0.0.0.0:9000 (0.0.0.0:9000) service address echo consumer count 
> updates: local=1 in-process=0 remote=0
> 2023-02-01 16:51:57.070553 -0500 ROUTER_CORE (info) [C2][L5] Link attached: 
> dir=in source={ expire:link} target={echo expire:link}
> 2023-02-01 16:51:57.070583 -0500 ROUTER_CORE (trace) Core action 
> 'add_tcp_connection'
> 2023-02-01 16:51:57.070606 -0500 TCP_ADAPTOR (debug) [C2] 
> PN_RAW_CONNECTION_WAKE listener
> 2023-02-01 16:51:57.070646 -0500 TCP_ADAPTOR (debug) [C2] 
> qdr_add_tcp_connection_CT 0.0.0.0:9000 (1)
> 2023-02-01 16:51:57.070673 -0500 TCP_ADAPTOR (debug) [C2][L4] qdr_tcp_flow: 
> Flow enabled, credit=250
> 2023-02-01 16:51:57.070722 -0500 TCP_ADAPTOR (debug) [C2] 
> qdr_tcp_activate_CT: call pn_raw_connection_wake()
> 2023-02-01 16:51:57.070774 -0500 ROUTER_CORE (trace) Core action 'link_flow'
> 2023-02-01 16:51:57.070800 -0500 TCP_ADAPTOR (trace) [C2][L5] handle_incoming 
> qdr_tcp_flow for listener connection. read_closed:F, flow_enabled:T
> 2023-02-01 16:51:57.070831 -0500 TCP_ADAPTOR (debug) [C2] 
> handle_incoming_raw_read() returning with result=0
> 2023-02-01 16:51:57.071258 -0500 TCP_ADAPTOR (debug) [C2][L5] Initiating 
> listener (ingress) stream incoming link for listener connection to: echo 
> reply: amqp:/_topo/0/QDR.A/temp.rr__pKcuMowq3o4
>

[jira] [Assigned] (PROTON-2680) [proton-c] PN_RAW_CONNECTION_DISCONNECTED event does not show up when client is disconnected

2023-02-16 Thread Ken Giusti (Jira) 


 [ 
https://issues.apache.org/jira/browse/PROTON-2680?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Ken Giusti reassigned PROTON-2680:
--

Assignee: Ken Giusti

> [proton-c] PN_RAW_CONNECTION_DISCONNECTED event does not show up when client 
> is disconnected 
> -
>
> Key: PROTON-2680
> URL: https://issues.apache.org/jira/browse/PROTON-2680
> Project: Qpid Proton
>  Issue Type: Bug
>  Components: proton-c
>Reporter: Ganesh Murthy
>Assignee: Ken Giusti
>Priority: Major
>
> Steps to reproduce
> Start the skupper-router with the following config -
> {noformat}
> router {
> mode: standalone
> }
> listener {
> host: 0.0.0.0
> port: amqp
> authenticatePeer: no
> saslMechanisms: ANONYMOUS
> }
> tcpConnector {
> name: echo-1
> host: 10.108.50.177
> port: 9090
> address: echo
> }
> tcpConnector {
> name: echo-2
> host: 10.108.50.177
> port: 9090
> address: echo
> }
> tcpListener {
> host: 0.0.0.0
> port: 9000
> address: echo
> }  
> log {
>     module: DEFAULT
>     enable: trace+
>     outputFile: tcp.log
> } {noformat}
>  
> Note that the ip address in the host field of the tcpConnector is bogus.
> Now connect a curl client to the tcpListener port  -
> {noformat}
> curl http://localhost:9000/api {noformat}
>  
> The curl client will hang. Terminate the curl client and look in the tcp.log 
> for logged proton events - the PN_RAW_CONNECTION_DISCONNECTED event will be 
> missing on connection C2
> Here is the full log of the relevant client connection
>  
> {noformat}
> 2023-02-01 16:51:57.069705 -0500 ROUTER_CORE (info) [C2] Connection Opened: 
> dir=in host=127.0.0.1:35348 encrypted=no auth=no user= 
> container_id=TcpAdaptor props={:"qd.adaptor"="tcp"}
> 2023-02-01 16:51:57.069793 -0500 ROUTER_CORE (trace) Core action 
> 'connection_opened'
> 2023-02-01 16:51:57.069986 -0500 TCP_ADAPTOR (info) [C2] 
> PN_RAW_CONNECTION_CONNECTED Listener ingress accepted to 0.0.0.0:9000 from 
> 127.0.0.1:35348 (global_id=127.0.0.1:35348)
> 2023-02-01 16:51:57.070015 -0500 ROUTER_CORE (trace) Core action 
> 'link_first_attach'
> 2023-02-01 16:51:57.070098 -0500 TCP_ADAPTOR (debug) [C2] 
> PN_RAW_CONNECTION_NEED_WRITE_BUFFERS listener
> 2023-02-01 16:51:57.070148 -0500 TCP_ADAPTOR (debug) [C2] 
> PN_RAW_CONNECTION_NEED_READ_BUFFERS listener
> 2023-02-01 16:51:57.070171 -0500 ROUTER_CORE (info) [C2][L4] Link attached: 
> dir=out source={(dyn) expire:link} target={ expire:link}
> 2023-02-01 16:51:57.070222 -0500 TCP_ADAPTOR (debug) [C2] 
> qdr_tcp_activate_CT: call pn_raw_connection_wake()
> 2023-02-01 16:51:57.070246 -0500 ROUTER_CORE (trace) Core action 
> 'link_first_attach'
> 2023-02-01 16:51:57.070273 -0500 TCP_ADAPTOR (debug) [C2][L4] (listener 
> outgoing) qdr_tcp_second_attach
> 2023-02-01 16:51:57.070347 -0500 DEFAULT (trace) Parse tree search for 'echo'
> 2023-02-01 16:51:57.070376 -0500 TCP_ADAPTOR (trace) [C2][L5] handle_incoming 
> qdr_tcp_second_attach for listener connection. read_closed:F, flow_enabled:F
> 2023-02-01 16:51:57.070404 -0500 DEFAULT (trace) Parse tree match not found
> 2023-02-01 16:51:57.070425 -0500 TCP_ADAPTOR (debug) [C2][L5] Waiting for 
> credit before initiating listener ingress stream message, returning
> 2023-02-01 16:51:57.070456 -0500 TCP_ADAPTOR (debug) [C2][L4] 
> qdr_tcp_get_credit: NOOP
> 2023-02-01 16:51:57.070517 -0500 TCP_ADAPTOR (trace) Listener 
> tcpListener/0.0.0.0:9000 (0.0.0.0:9000) service address echo consumer count 
> updates: local=1 in-process=0 remote=0
> 2023-02-01 16:51:57.070553 -0500 ROUTER_CORE (info) [C2][L5] Link attached: 
> dir=in source={ expire:link} target={echo expire:link}
> 2023-02-01 16:51:57.070583 -0500 ROUTER_CORE (trace) Core action 
> 'add_tcp_connection'
> 2023-02-01 16:51:57.070606 -0500 TCP_ADAPTOR (debug) [C2] 
> PN_RAW_CONNECTION_WAKE listener
> 2023-02-01 16:51:57.070646 -0500 TCP_ADAPTOR (debug) [C2] 
> qdr_add_tcp_connection_CT 0.0.0.0:9000 (1)
> 2023-02-01 16:51:57.070673 -0500 TCP_ADAPTOR (debug) [C2][L4] qdr_tcp_flow: 
> Flow enabled, credit=250
> 2023-02-01 16:51:57.070722 -0500 TCP_ADAPTOR (debug) [C2] 
> qdr_tcp_activate_CT: call pn_raw_connection_wake()
> 2023-02-01 16:51:57.070774 -0500 ROUTER_CORE (trace) Core action 'link_flow'
> 2023-02-01 16:51:57.070800 -0500 TCP_ADAPTOR (trace) [C2][L5] handle_incoming 
> qdr_tcp_flow for listener connection. read_closed:F, flow_enabled:T
> 2023-02-01 16:51:57.070831 -0500 TCP_ADAPTOR (debug) [C2] 
> handle_incoming_raw_read() returning with result=0
> 2023-02-01 16:51:57.071258 -0500 TCP_ADAPTOR (debug) [C2][L5] Initiating 
> listener (ingress) stream incoming link for listener connection to: echo 
> reply: amqp:/_topo/0/QDR.A/temp.rr__pKcuMowq3o4
> 2023-02-01 16:51:57.071468 -0500