![]() ![]() |
VeenaMithare |
![]() |
This post was updated on .
Hi ,
If I stop and start a client application that is connected to a 3 node server cluster within the failure detection timeout, I see a lot of these messages on the console : INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection The count of these messages varies between 600 to 800 . I did not see these messages coming in 2.7.6. Why are they showing up in 2.8.1. Do I need to tune anything to avoid this ? A sample of the same below : 2020-08-28 08:43:03,614 [main] INFO com.company.project.projectstore.client.ListenerClient [] - Test message 2020-08-28 08:43:03,644 [grid-nio-worker-tcp-comm-15-#87%client-null-igniteclient-SINGLE%] INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection [locAddr=/127.0.0.1:47105, rmtAddr=/127.0.0.1:52883] 2020-08-28 08:43:03,644 [grid-nio-worker-tcp-comm-0-#72%client-null-igniteclient-SINGLE%] INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection [locAddr=/127.0.0.1:47105, rmtAddr=/127.0.0.1:52884] 2020-08-28 08:43:03,695 [grid-nio-worker-tcp-comm-1-#73%client-null-igniteclient-SINGLE%] INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection [locAddr=/127.0.0.1:47105, rmtAddr=/127.0.0.1:52885] 2020-08-28 08:43:03,695 [grid-nio-worker-tcp-comm-2-#74%client-null-igniteclient-SINGLE%] INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection [locAddr=/127.0.0.1:47105, rmtAddr=/127.0.0.1:52886] 2020-08-28 08:43:03,747 [grid-nio-worker-tcp-comm-3-#75%client-null-igniteclient-SINGLE%] INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection [locAddr=/127.0.0.1:47105, rmtAddr=/127.0.0.1:52887] 2020-08-28 08:43:03,748 [grid-nio-worker-tcp-comm-4-#76%client-null-igniteclient-SINGLE%] INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection [locAddr=/127.0.0.1:47105, rmtAddr=/127.0.0.1:52888] regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() |
Hello Veena,
It would make sense to check for the other node logs, because it's the other node that tries to initiate communication connection with this one. The clue for the reason why is it trying to connect might be in other node log. Best regards, Anton -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
VeenaMithare |
![]() |
HI Anton,
The setup I am working on is as below : server nodes : 3 client : 1 I get these logs when I start the client node within 10 secs of stopping it. There is no clue on the server nodes as to why these logs are printed. It looks as if the client node that was killed, is trying to join back , since it was not marked as DEAD yet by the servers. It is very easy to reproduce this. Stop and start any client node within 10 seconds of stopping it. regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! Can you please perhaps share a reproducer project? Regards, -- Ilya Kasnacheev вт, 29 сент. 2020 г. в 19:34, VeenaMithare <[hidden email]>: HI Anton, |
![]() ![]() |
VeenaMithare |
![]() |
Hi Ilya,
This is easy to reproduce. Have a server node and a client node in a cluster. Stop and start the client immediately so that the start happens within the failure detection timeout ( 10 sec typically ). You will see these messages in the client log as it is starting up the second time. Let me know if you still need a reproducer. regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! We have a lot of tests which do exactly that, and they don't seem to exhibit that behavior. Please provide a reproducer. Regards, -- Ilya Kasnacheev вт, 3 нояб. 2020 г. в 11:13, VeenaMithare <[hidden email]>: Hi Ilya, |
![]() ![]() |
VeenaMithare |
![]() |
In reply to this post by ilya.kasnacheev
Hi Ilya,
Please find the reproducer project attached. Steps to reproduce : 1. Run the server.java 2. Run the ListenerClient.java. Wait till it starts fully. 3. Stop and start the client again ( within the failuredetectiontimeout of 10 secs. ) You will see these logs on the console. Another thing I noticed today is that , the logs seem to be connected to this code in Server.java ignite.active(true); addPersistentCacheConfiguration( ignite); If I comment out the above lines and try the steps above, I dont get those logs. regards, Veena. ClientConnectProject.zip <http://apache-ignite-users.70518.x6.nabble.com/file/t2757/ClientConnectProject.zip> -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
VeenaMithare |
![]() |
Hi Ilya,
Did you get a chance to look in to this ..? regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
VeenaMithare |
![]() |
This issue is also observed if two different clients exist on the same box.
Steps to reproduce : 1. Both the clients are not running 2. Start the client1 3. Stop the client 1 and start client 2 . 4. The huge set of logs are visible on client 2 logs. regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! Maybe it's some kind of Windows thing or otherwise depends on your environment? I have tried to run your reproducer, but I never get these exceptions. Instead, I will only see: янв 13, 2021 6:38:56 PM org.apache.ignite.logger.java.JavaLogger info INFO: Accepted incoming communication connection [locAddr=/0:0:0:0:0:0:0:1:47100, rmtAddr=/0:0:0:0:0:0:0:1:34890] Once on the server node after client restart. Regards, -- Ilya Kasnacheev вт, 12 янв. 2021 г. в 18:11, VeenaMithare <[hidden email]>: This issue is also observed if two different clients exist on the same box. |
![]() ![]() |
VeenaMithare |
![]() |
This post was updated on .
Kindly confirm the below :
a. Are you on :2.8.1 b. Is this code uncommented : ignite.active(true); addPersistentCacheConfiguration( ignite); c. using both server and client on the reproducer? d. Did the client start and stop happen within in 10 secs. I get this on all env. ( even in our linux env. ) Also I am able to reproduce this consistently on the attached reproducer. The only time I dont get this is when ignite.active or control.sh --activate is not invoked ( Since ignite.active(true); is deprecated, a manual activation can be done as well . This issue is observed even with a manual activation ) -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! I am using your reproducer and I did not change dependencies, so I assume it's on 2.8.1 if your reproducer uses it. Yes, I'm running both server and client from the reproducer. Maybe you could record a screencast where you run it and get the result that you describe? Regards, -- Ilya Kasnacheev ср, 13 янв. 2021 г. в 19:14, VeenaMithare <[hidden email]>: Kindly confirm the below : |
![]() ![]() |
VeenaMithare |
![]() |
Hi Ilya,
Please find the video recording of the issue I face. https://drive.google.com/file/d/1fDqxmgjiL3o_eenHoUosdiYlMMBJ4xVj/view?usp=sharing regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! It's interesting, but I still can't reproduce the issue. Does not seem to happen to me. Maybe somebody else will chime in. Regards, -- Ilya Kasnacheev чт, 14 янв. 2021 г. в 20:47, VeenaMithare <[hidden email]>: Hi Ilya, |
![]() ![]() |
VeenaMithare |
![]() |
The reproducer code works fine on my home mac ( I dont see the 100s of logs)
- so not sure if the issue is because of a. Change in OS - at home I use mac and office it is windows/linux. b. Change in the network ( between my home and office ) Any thoughts on how I can debug further ? -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
ilya.kasnacheev |
![]() |
Hello! Network may be relevant here. Can you try disconnect from your network (turn off wi/fi, unplug ethernet) and re-try? Regards, -- Ilya Kasnacheev вт, 19 янв. 2021 г. в 12:45, VeenaMithare <[hidden email]>: The reproducer code works fine on my home mac ( I dont see the 100s of logs) |
![]() ![]() |
VeenaMithare |
![]() |
Unfortunately , will be difficult to try this - since we are working from
home and are connected to office network through citrix . -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
alexey.plotnik |
![]() |
In reply to this post by VeenaMithare
Hi there. It's reproduced both in Intellij Idea and from cmd on Win 10. It's NOT reproduced on Linux cli. What happens here: server node does not receive TcpDiscoveryNodeLeftMessage to let client node left the cluster. Instead client app is killed, server node understands it and try to reconnect, client node continues stay in topology and if yo start it in short time you will see in server logs a lot of handshake errors DEBUG org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Client creation failed [addr=/127.0.0.1:47101, err=class org.apache.ignite.spi.communication.tcp.internal.HandshakeException: Remote node ID is not as expected [expected=f3038b2c-78d1-4a9d-80ef-800f06a92a8b, rcvd=bc6ae633-b643-44ba-afab-321dbf01aaf1]]and in client log a lot of INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Accepted incoming communication connection ... INFO org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Sending local node ID (bc6ae633-b643-44ba-afab-321dbf01aaf1 to newly accepted session ... DEBUG org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi [] - Remote client closed connection ...You can see client node sends old Node ID. It looks like server node does not receive "TcpDiscoveryNodeLeftMessage" message from client when you stop the client app. When stopped from Idea or by closing CMD window the target process does not receive SIGINT signal. You can try to stop the client app on windows with "Ctrl-C" shortcut, then client will send left node message, you will see it in client logs: [INFO ][Thread-4][G] Invoking shutdown hook...then in server logs: [TcpDiscoverySpi] Message has been received: TcpDiscoveryNodeLeftMessageWhen using IDEA please try to run client app in debug mode, it sends SIGINT signal to app when you click "Stop" button. Anyway when running on Linux I cant reproduce the same behaviour when stopping the client process with something like "kill -9". I'll try the situation whne number of client nodes is more than one.
Alexey Plotnik
Sent from the Apache Ignite Users mailing list archive at Nabble.com.
Alexey Plotnik
|
![]() ![]() |
VeenaMithare |
![]() |
Hi Alexey,
I am able to reproduce this on my linux env. by doing a kill -9 . Please find the logs from my linux env. attached. temp.log <http://apache-ignite-users.70518.x6.nabble.com/file/t2757/temp.log> Also note in our linux env. we have dual ip for our boxes - not sure if that contributes to this issue. Also I do not see this log in the INFO mode in our client logs : Sending local node ID (bc6ae633-b643-44ba-afab-321dbf01aaf1 to newly accepted session ... I will try shutting down the client with ctrl+c on windows and check if that helps. regards, Veena. -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/ |
![]() ![]() |
alexey.plotnik |
![]() |
Could you plz attach DEBUG log of the server node running on Linux machine
from the moment server starts until client re-connect after being stopped? So, full logs basically ----- Alexey Plotnik -- Sent from: http://apache-ignite-users.70518.x6.nabble.com/
Alexey Plotnik
|
Free forum by Nabble | Edit this page |