Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

fix(data.service): correctly stopping reconnection thread #5058

Merged
merged 1 commit into from
Dec 14, 2023
Merged

fix(data.service): correctly stopping reconnection thread #5058

merged 1 commit into from
Dec 14, 2023

Conversation

sfiorani
Copy link
Contributor

This PR fixes a problem related to the management of the reconnection executor created by enabling the Connection Schedule option in the Data Service section of the Cloud Connections tab.

Before this change, when an update of the section was performed, no one stopped the reconnection executor, so the CloudConnection continously tried to reconnect with the old parameters, and could happen that the scheduled connections overlap, making the general behaviour not coherent with the expected one.

Related Issue:

Description of the solution adopted: This PR adds the correct stopping of the executor, which is then correctly update, so the next scheduled connections are coherent with the CRON expression set in the related option.

Screenshots:

Manual Tests:

  1. Configure the CloudConnections MqttDataTransport tab with parameters that would let a succesful cloud connection, then enable the Connect Auto-on-startup option, enable the Scheduled Connection of DataService tab under CloudConnections with a CRON expression 0/30 0/1 * 1/1 * ? * and Apply.
  2. Copy the content of the Message Store Provider Service PID and changed it to a fake one fake.pid and Apply.
  3. Wait that the Disconnection, then set the Pid as the correct one and Apply.
  4. The connection should be scheduled and only in that moment the system should try reconnection (it's not necessary that the time is perfectly matched, couple of seconds delay is acceptable).
  5. Logger should print a line like "Reconnect task running. Stopping it"

Any side note on the changes made:

@mattdibi mattdibi self-requested a review December 13, 2023 15:52
mattdibi
mattdibi approved these changes Dec 13, 2023
View reviewed changes
Copy link
Contributor

@mattdibi mattdibi left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was the best review I ever did 😭

@mattdibi
Copy link
Contributor

@sfiorani BTW does this spawn from a failed QA test? If so, can you review the test to comply with the modification added into this PR?

@mattdibi
Copy link
Contributor

Tested on RPi 64bit, all good

org.eclipse.kura.KuraStoreException: "Error performing operation on store. Message store instance not connected, not connecting"
	at org.eclipse.kura.core.data.DataServiceImpl$ReconnectTask.run(DataServiceImpl.java:902)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:840)
2023-12-14T08:20:41,681 [qtp2122338132-2754] INFO  o.e.k.c.c.ConfigurationServiceImpl - Loading init configurations from: 1702538418830...
2023-12-14T08:20:41,706 [qtp2122338132-2754] INFO  o.e.k.c.c.ConfigurationServiceImpl - Merging configuration for pid: org.eclipse.kura.data.DataService
2023-12-14T08:20:41,736 [qtp2122338132-2754] INFO  o.e.k.c.c.ConfigurationServiceImpl - Updating Configuration of ConfigurableComponent org.eclipse.kura.data.DataService ... Done.
2023-12-14T08:20:41,754 [ConfigurationListener Event Queue] INFO  o.e.k.c.d.DataServiceImpl - Updating org.eclipse.kura.data.DataService...
2023-12-14T08:20:41,756 [ConfigurationListener Event Queue] INFO  o.e.k.c.d.DataServiceImpl - Reconnect task running. Stopping it
2023-12-14T08:20:41,757 [ConfigurationListener Event Queue] INFO  o.e.k.c.d.DataServiceImpl - Get Throttle with burst length 1 and send a message every 1000000000 nanoseconds
2023-12-14T08:20:41,759 [ConfigurationListener Event Queue] INFO  o.e.k.c.d.DataServiceImpl - Message store instance found
2023-12-14T08:20:41,777 [qtp2122338132-2754] INFO  o.e.k.c.c.ConfigurationServiceImpl - Writing snapshot - Saving /opt/eclipse/kura/user/snapshots/snapshot_1702538441737.xml...
2023-12-14T08:20:41,783 [DataServiceImpl:Submit] INFO  o.e.k.c.d.DataServiceImpl - DataPublisherService not connected
2023-12-14T08:20:41,808 [pool-32-thread-1] INFO  o.e.k.c.d.ScheduleStrategy - Connection scheduled at 2023-12-14T08:21:00.000+0100 in 18193 ms
2023-12-14T08:20:41,822 [qtp2122338132-2754] INFO  o.e.k.c.c.ConfigurationServiceImpl - Writing snapshot - Saving /opt/eclipse/kura/user/snapshots/snapshot_1702538441737.xml... Done.
2023-12-14T08:20:42,762 [HouseKeeperTask] INFO  o.e.k.c.d.s.HouseKeeperTask - HouseKeeperTask started.
2023-12-14T08:20:42,763 [HouseKeeperTask] INFO  o.e.k.c.d.s.HouseKeeperTask - HouseKeeperTask: Delete confirmed messages...
2023-12-14T08:20:42,778 [HouseKeeperTask] INFO  o.e.k.c.d.s.HouseKeeperTask - HouseKeeperTask ended.
2023-12-14T08:21:00,005 [pool-32-thread-1] INFO  o.e.k.c.d.ScheduleStrategy - State change: AwaitConnectTime -> AwaitConnect
2023-12-14T08:21:00,007 [pool-32-thread-1] INFO  o.e.k.c.d.DataServiceImpl - Starting reconnect task with initial delay 8
2023-12-14T08:21:08,008 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.DataServiceImpl - Connecting...
2023-12-14T08:21:08,009 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - # ------------------------------------------------------------
2023-12-14T08:21:08,009 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  Connection Properties
2023-12-14T08:21:08,009 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  broker    = 
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  clientId  = 
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  username  = mattia_dal_ben
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  password  = XXXXXXXXXXXXXX
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  keepAlive = 30
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  timeout   = 20
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  cleanSession    = true
2023-12-14T08:21:08,010 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  MQTT version    = 3.1.1
2023-12-14T08:21:08,011 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  willDestination = 
2023-12-14T08:21:08,011 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  willMessage     =
2023-12-14T08:21:08,011 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #
2023-12-14T08:21:08,011 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  Connecting...
2023-12-14T08:21:08,013 [pool-14-thread-1] INFO  o.e.k.c.s.r.LogStatusRunnable - Notification LED fast blinking
2023-12-14T08:21:09,201 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - #  Connected!
2023-12-14T08:21:09,201 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - # ------------------------------------------------------------
2023-12-14T08:21:09,201 [pool-14-thread-1] INFO  o.e.k.c.s.r.LogStatusRunnable - Notification LED slow blinking
2023-12-14T08:21:09,201 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.DataServiceImpl - Notified connected
2023-12-14T08:21:09,201 [pool-14-thread-1] INFO  o.e.k.c.s.r.LogStatusRunnable - Notification LED on
2023-12-14T08:21:09,201 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.DataServiceImpl - New session established. Unpublishing all in-flight messages. Disregarding the QoS level, this may cause duplicate messages.
2023-12-14T08:21:09,206 [pool-32-thread-1] INFO  o.e.k.c.d.ScheduleStrategy - State change: AwaitConnect -> AwaitDisconnectTime
2023-12-14T08:21:09,464 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.DataServiceImpl - Storing message on topic: $EDC/#account-name/#client-id/MQTT/BIRTH, priority: 0
2023-12-14T08:21:09,469 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.DataServiceImpl - Stored message on topic: $EDC/#account-name/#client-id/MQTT/BIRTH, priority: 0
2023-12-14T08:21:09,479 [DataServiceImpl:Submit] INFO  o.e.k.c.d.t.m.MqttDataTransport - Publishing message on topic:  with QoS: 1
2023-12-14T08:21:09,486 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.t.m.MqttDataTransport - Subscribing to topic:  with QoS: 1
2023-12-14T08:21:09,664 [MQTT Call: DC:A6:32:E0:54:F0] INFO  o.e.k.c.d.DataServiceImpl - Confirmed message ID: 3 to store
2023-12-14T08:21:09,807 [DataServiceImpl:ReconnectTask:org.eclipse.kura.data.DataService] INFO  o.e.k.c.d.DataServiceImpl - Connected. Reconnect task will be terminated.

@mattdibi mattdibi merged commit 94ea937 into eclipse-kura:develop Dec 14, 2023
3 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@mattdibi mattdibi mattdibi approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@sfiorani @mattdibi