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

2023-08-14 Thread Clifford Jansen (Jira)


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

Clifford Jansen commented on PROTON-2680:
-

The test case should be retested against the code changes in

  https://issues.apache.org/jira/browse/PROTON-2748

once they have been finalized, approved and checked in.

Ultimately, it should be noted that the killed curl process does:

  connect to router
  send http request bytes on socket
  [ kill ]
  OS closes socket -> FIN

and nothing else except an ack to a FIN if the router ever sends one, or an RST 
if the router sends data.

>From the router's perspective, this is identical to some other client which 
>does:

  connect to router
  send http request bytes on socket
  wait some time
  half close socket (write side) -> FIN
  wait a long long time for the http response from the router

The latter is completely valid and should not result in a DISCONNECT.

The two are indistinguishable on the wire (or loopback).

> [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) 

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

2023-02-02 Thread Ganesh Murthy (Jira)


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

Ganesh Murthy commented on PROTON-2680:
---

Comment Clifford Jansen -

This looks to me like 2 bugs.  The first might be cascading to the one you are 
asking about.

The "other" bug is a PN_RAW_CONNECTION_READ with 0 bytes, which appears to 
contradict the docs.  It looks like this might result in the raw connection 
being in some state that prevents the detected PN_RAW_CONNECTION_CLOSED_READ to 
progress towards a disconnect.

It should suffice to raise a single Jira.

> [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
>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