[jira] [Commented] (PROTON-2680) [proton-c] PN_RAW_CONNECTION_DISCONNECTED event does not show up when client is disconnected
[ 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
[ 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