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.

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

tedge service init session error message is not verbose enough #1912

Merged
merged 2 commits into from
May 4, 2023

Conversation

PradeepKiruvale
Copy link
Contributor

@PradeepKiruvale PradeepKiruvale commented Apr 13, 2023

Proposed changes

Update the log message that is published during init session (--init) if there is no mosquitto broker running.

For example

tedge-mapper -- --init c8y

The system config file '/etc/tedge/system.toml' doesn't exist. Use '/bin/systemctl' as a service manager.

2023-04-28T09:43:36.650664979Z  INFO flockfile::unix: Lockfile created "/run/lock/tedge-mapper-c8y.lock"
2023-04-28T09:43:36.650747634Z  INFO tedge_mapper::c8y::mapper: Initialize tedge mapper c8y
Error: Failed to initialize the session with MQTT Broker due to: I/O: Connection refused (os error 111) 

Types of changes

  • Bugfix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Improvement (general improvements like code refactoring that doesn't explicitly fix a bug or add any new functionality)
  • Documentation Update (if none of the other choices apply)
  • Breaking change (fix or feature that would cause existing functionality to not work as expected)

Paste Link to the issue

#1778

Checklist

  • I have read the CONTRIBUTING doc
  • I have signed the CLA (in all commits with git commit -s)
  • I ran cargo fmt as mentioned in CODING_GUIDELINES
  • I used cargo clippy as mentioned in CODING_GUIDELINES
  • I have added tests that prove my fix is effective or that my feature works
  • I have added necessary documentation (if appropriate)

Further comments

Comment on lines 43 to 48
eprintln!("Connection Error {}", err);
if err.to_string().contains("Connection refused") {
eprintln!("Couldn't connect to mqtt broker due to {}", err);
} else {
eprintln!("Connection Error {}", err);
}
Copy link
Contributor

Choose a reason for hiding this comment

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

As you are doing nothing specific to change the error message, why not simply:

                    eprintln!("Couldn't connect to mqtt broker due to {}", err);

Did you try to translate the error message using the actual message error? This will be less fragile and possibly more helpful. See:

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I went with this because I just wanted to address the mqtt connection issue when it refused. I feel now it makes sense to just have eprintln!("Couldn't connect to mqtt broker due to {}", err); for all the cases.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

If there is no mqtt broker during --init then the error thrown is rumqttc::ConnectionError::Io(_). So, the ConnectReturnCode is not useful.

Copy link
Contributor

Choose a reason for hiding this comment

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

Though since we will be supported authenticated mqtt brokers in the near future, we need to also handle the ConnectReturnCode style errors as well. For example if the broker requires authentication, then it is useful to know if the password is wrong or not, or if it is a protocol version issue etc. These kinds of errors are covered by ConnectReturnCode (as mentioned by @didier-wenzek)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Updated the error messages to use the ConnectReturnCode.

Copy link
Member

@rina23q rina23q left a comment

Choose a reason for hiding this comment

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

I believe just changing the message to less scary way like in this PR is the right direction like I suggested in #1778 (comment), however, we need to a feedback from @reubenmiller!

I already made some investigation how hard to address error patterns.
#1778 (comment)

@PradeepKiruvale PradeepKiruvale temporarily deployed to Test Pull Request April 24, 2023 05:45 — with GitHub Actions Inactive
@github-actions
Copy link
Contributor

github-actions bot commented Apr 24, 2023

Robot Results

✅ Passed ❌ Failed ⏭️ Skipped Total Pass %
191 0 5 191 100

Passed Tests

Name ⏱️ Duration Suite
Define Child device 1 ID 0.004 s C8Y Child Alarms Rpi
Normal case when the child device does not exist on c8y cloud 2.453 s C8Y Child Alarms Rpi
Normal case when the child device already exists 0.798 s C8Y Child Alarms Rpi
Reconciliation when the new alarm message arrives, restart the mapper 1.506 s C8Y Child Alarms Rpi
Reconciliation when the alarm that is cleared 6.012 s C8Y Child Alarms Rpi
Prerequisite Parent 74.492 s Child Conf Mgmt Plugin
Prerequisite Child 0.438 s Child Conf Mgmt Plugin
Child device bootstrapping 13.25 s Child Conf Mgmt Plugin
Snapshot from device 61.341 s Child Conf Mgmt Plugin
Child device config update 62.909 s Child Conf Mgmt Plugin
Configuration types should be detected on file change (without restarting service) 103.97 s Inotify Crate
Check lock file existence in default folder 0.849 s Lock File
Check PID number in lock file 0.856 s Lock File
Check PID number in lock file after restarting the services 1.714 s Lock File
Check starting same service twice 1.225 s Lock File
Switch off lock file creation 3.183 s Lock File
Set configuration when file exists 56.408 s Configuration Operation
Set configuration when file does not exist 5.395 s Configuration Operation
Set configuration with broken url 4.9 s Configuration Operation
Get configuration 5.554 s Configuration Operation
Get non existent configuration file 4.554 s Configuration Operation
Get non existent configuration type 4.941 s Configuration Operation
Update configuration plugin config via cloud 5.165 s Configuration Operation
Modify configuration plugin config via local filesystem modify inplace 2.137 s Configuration Operation
Modify configuration plugin config via local filesystem overwrite 4.475 s Configuration Operation
Update configuration plugin config via local filesystem copy 4.6690000000000005 s Configuration Operation
Update configuration plugin config via local filesystem move (different directory) 3.037 s Configuration Operation
Update configuration plugin config via local filesystem move (same directory) 3.2800000000000002 s Configuration Operation
Successful firmware operation 67.766 s Firmware Operation
Install with empty firmware name 40.879 s Firmware Operation
Prerequisite Parent 16.993 s Firmware Operation Child Device
Prerequisite Child 7.583 s Firmware Operation Child Device
Child device firmware update 5.799 s Firmware Operation Child Device
Child device firmware update with cache 5.583 s Firmware Operation Child Device
Firmware plugin supports restart via service manager #1932 4.96 s Firmware Operation Child Device Retry
Update Inventory data via inventory.json 1.1400000000000001 s Inventory Update
Retrieve a JWT tokens 112.178 s Jwt Request
Check running collectd 0.914 s Monitor Device Collectd
Is collectd publishing MQTT messages? 0.777 s Monitor Device Collectd
Check thin-edge monitoring 3.368 s Monitor Device Collectd
Check grouping of measurements 8.518 s Monitor Device Collectd
Main device registration 1.413 s Device Registration
Child device registration 1.8519999999999999 s Device Registration
Supports restarting the device 112.753 s Restart Device
Update tedge version from previous using Cumulocity 67.906 s Tedge Self Update
Test if all c8y services are up 100.12 s Service Monitoring
Test if all c8y services are down 106.517 s Service Monitoring
Test if all c8y services are using configured service type 145.468 s Service Monitoring
Test if all c8y services using default service type when service type configured as empty 85.945 s Service Monitoring
Check health status of tedge-mapper-c8y service on broker stop start 24.422 s Service Monitoring
Check health status of tedge-mapper-c8y service on broker restart 25.585 s Service Monitoring
Check health status of child device service 20.332 s Service Monitoring
Successful shell command with output 3.448 s Shell Operation
Check Successful shell command with literal double quotes output 3.061 s Shell Operation
Execute multiline shell command 3.356 s Shell Operation
Failed shell command 3.24 s Shell Operation
Software list should be populated during startup 30.701999999999998 s Software
Install software via Cumulocity 52.216 s Software
Software list should only show currently installed software and not candidates 39.173 s Software
Child devices support sending simple measurements 1.453 s Child Device Telemetry
Child devices support sending custom measurements 3.435 s Child Device Telemetry
Child devices support sending custom events 1.249 s Child Device Telemetry
Child devices support sending custom events overriding the type 1.066 s Child Device Telemetry
Child devices support sending custom alarms #1699 1.124 s Child Device Telemetry
Child devices support sending inventory data via c8y topic 0.99 s Child Device Telemetry
Main device support sending inventory data via c8y topic 1.229 s Child Device Telemetry
Child device supports sending custom child device measurements directly to c8y 1.324 s Child Device Telemetry
Main device supports sending custom child device measurements directly to c8y 1.328 s Child Device Telemetry
Check retained alarms 41.372 s Raise Alarms
Validate updated data path used by tedge-agent 0.804 s Data Path Config
Validate updated data path used by c8y-firmware-plugin 10.962 s Data Path Config
Stop tedge-agent service 0.309 s Log Path Config
Customize the log path 0.108 s Log Path Config
Initialize tedge-agent 0.163 s Log Path Config
Check created folders 0.105 s Log Path Config
Remove created custom folders 0.135 s Log Path Config
Install thin-edge via apt 43.077 s Install Apt
Install latest via script (from current branch) 28.163 s Install Tedge
Install specific version via script (from current branch) 23.002 s Install Tedge
Install latest tedge via script (from main branch) 19.131 s Install Tedge
Install then uninstall latest tedge via script (from main branch) 52.777 s Install Tedge
Support starting and stopping services 40.874 s Service-Control
Supports a reconnect 54.472 s Test-Commands
Supports disconnect then connect 34.254 s Test-Commands
Update unknown setting 35.218 s Test-Commands
Update known setting 29.926 s Test-Commands
Stop c8y-configuration-plugin 0.36 s Health C8Y-Configuration-Plugin
Update the service file 0.218 s Health C8Y-Configuration-Plugin
Reload systemd files 0.816 s Health C8Y-Configuration-Plugin
Start c8y-configuration-plugin 0.12 s Health C8Y-Configuration-Plugin
Start watchdog service 10.261 s Health C8Y-Configuration-Plugin
Check PID of c8y-configuration-plugin 0.101 s Health C8Y-Configuration-Plugin
Kill the PID 0.139 s Health C8Y-Configuration-Plugin
Recheck PID of c8y-configuration-plugin 6.41 s Health C8Y-Configuration-Plugin
Compare PID change 0.001 s Health C8Y-Configuration-Plugin
Stop watchdog service 0.124 s Health C8Y-Configuration-Plugin
Remove entry from service file 0.11 s Health C8Y-Configuration-Plugin
Stop c8y-log-plugin 0.186 s Health C8Y-Log-Plugin
Update the service file 0.153 s Health C8Y-Log-Plugin
Reload systemd files 0.524 s Health C8Y-Log-Plugin
Start c8y-log-plugin 0.189 s Health C8Y-Log-Plugin
Start watchdog service 10.297 s Health C8Y-Log-Plugin
Check PID of c8y-log-plugin 0.073 s Health C8Y-Log-Plugin
Kill the PID 0.196 s Health C8Y-Log-Plugin
Recheck PID of c8y-log-plugin 6.432 s Health C8Y-Log-Plugin
Compare PID change 0.004 s Health C8Y-Log-Plugin
Stop watchdog service 0.221 s Health C8Y-Log-Plugin
Remove entry from service file 0.126 s Health C8Y-Log-Plugin
Stop tedge-mapper 0.217 s Health Tedge Mapper C8Y
Update the service file 0.211 s Health Tedge Mapper C8Y
Reload systemd files 0.604 s Health Tedge Mapper C8Y
Start tedge-mapper 0.175 s Health Tedge Mapper C8Y
Start watchdog service 10.18 s Health Tedge Mapper C8Y
Check PID of tedge-mapper 0.124 s Health Tedge Mapper C8Y
Kill the PID 0.185 s Health Tedge Mapper C8Y
Recheck PID of tedge-mapper 6.3870000000000005 s Health Tedge Mapper C8Y
Compare PID change 0.001 s Health Tedge Mapper C8Y
Stop watchdog service 0.119 s Health Tedge Mapper C8Y
Remove entry from service file 0.112 s Health Tedge Mapper C8Y
Stop tedge-agent 0.267 s Health Tedge-Agent
Update the service file 0.146 s Health Tedge-Agent
Reload systemd files 0.648 s Health Tedge-Agent
Start tedge-agent 0.125 s Health Tedge-Agent
Start watchdog service 10.369 s Health Tedge-Agent
Check PID of tedge-mapper 0.107 s Health Tedge-Agent
Kill the PID 0.149 s Health Tedge-Agent
Recheck PID of tedge-agent 6.456 s Health Tedge-Agent
Compare PID change 0.001 s Health Tedge-Agent
Stop watchdog service 0.213 s Health Tedge-Agent
Remove entry from service file 0.191 s Health Tedge-Agent
Stop tedge-mapper-az 0.307 s Health Tedge-Mapper-Az
Update the service file 0.311 s Health Tedge-Mapper-Az
Reload systemd files 0.882 s Health Tedge-Mapper-Az
Start tedge-mapper-az 0.19 s Health Tedge-Mapper-Az
Start watchdog service 10.266 s Health Tedge-Mapper-Az
Check PID of tedge-mapper-az 0.064 s Health Tedge-Mapper-Az
Kill the PID 0.141 s Health Tedge-Mapper-Az
Recheck PID of tedge-agent 6.501 s Health Tedge-Mapper-Az
Compare PID change 0.001 s Health Tedge-Mapper-Az
Stop watchdog service 0.11 s Health Tedge-Mapper-Az
Remove entry from service file 0.101 s Health Tedge-Mapper-Az
Stop tedge-mapper-collectd 0.16 s Health Tedge-Mapper-Collectd
Update the service file 0.151 s Health Tedge-Mapper-Collectd
Reload systemd files 0.701 s Health Tedge-Mapper-Collectd
Start tedge-mapper-collectd 0.37 s Health Tedge-Mapper-Collectd
Start watchdog service 10.436 s Health Tedge-Mapper-Collectd
Check PID of tedge-mapper-collectd 0.08 s Health Tedge-Mapper-Collectd
Kill the PID 0.2 s Health Tedge-Mapper-Collectd
Recheck PID of tedge-mapper-collectd 6.298 s Health Tedge-Mapper-Collectd
Compare PID change 0.001 s Health Tedge-Mapper-Collectd
Stop watchdog service 0.088 s Health Tedge-Mapper-Collectd
Remove entry from service file 0.087 s Health Tedge-Mapper-Collectd
tedge-collectd-mapper health status 5.411 s Health Tedge-Mapper-Collectd
c8y-log-plugin health status 5.853 s MQTT health endpoints
c8y-configuration-plugin health status 5.392 s MQTT health endpoints
Publish on a local insecure broker 0.402 s Basic Pub Sub
Publish on a local secure broker 2.229 s Basic Pub Sub
Publish on a local secure broker with client authentication 2.141 s Basic Pub Sub
Check remote mqtt broker #1773 2.141 s Remote Mqtt Broker
Wrong package name 0.119 s Improve Tedge Apt Plugin Error Messages
Wrong version 0.134 s Improve Tedge Apt Plugin Error Messages
Wrong type 0.284 s Improve Tedge Apt Plugin Error Messages
tedge_connect_test_positive 0.39 s Tedge Connect Test
tedge_connect_test_negative 1.388 s Tedge Connect Test
tedge_connect_test_sm_services 7.058 s Tedge Connect Test
tedge_disconnect_test_sm_services 60.277 s Tedge Connect Test
Install thin-edge.io 10.378 s Call Tedge
call tedge -V 0.051 s Call Tedge
call tedge -h 0.055 s Call Tedge
call tedge -h -V 0.059 s Call Tedge
call tedge help 0.065 s Call Tedge
tedge config list 0.066 s Call Tedge Config List
tedge config list --all 0.049 s Call Tedge Config List
set/unset device.type 0.251 s Call Tedge Config List
set/unset device.key.path 0.219 s Call Tedge Config List
set/unset device.cert.path 0.232 s Call Tedge Config List
set/unset c8y.root.cert.path 0.311 s Call Tedge Config List
set/unset c8y.smartrest.templates 0.27 s Call Tedge Config List
set/unset az.root.cert.path 0.259 s Call Tedge Config List
set/unset az.mapper.timestamp 0.27 s Call Tedge Config List
set/unset mqtt.bind_address 0.304 s Call Tedge Config List
set/unset mqtt.port 0.413 s Call Tedge Config List
set/unset tmp.path 0.454 s Call Tedge Config List
set/unset logs.path 0.443 s Call Tedge Config List
set/unset run.path 0.605 s Call Tedge Config List
Get Put Delete 3.552 s Http File Transfer Api
Set keys should return value on stdout 0.101 s Tedge Config Get
Unset keys should not return anything on stdout and warnings on stderr 0.302 s Tedge Config Get
Invalid keys should not return anything on stdout and warnings on stderr 0.117 s Tedge Config Get
Set configuration via environment variables 0.548 s Tedge Config Get
Set unknown configuration via environment variables 0.052 s Tedge Config Get

Copy link
Contributor

@didier-wenzek didier-wenzek left a comment

Choose a reason for hiding this comment

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

Please derive an MqttConnectionError using thiserror. The error messages proposed by this PR are nice but must be returned as Error and not simply logged.

@@ -16,6 +16,7 @@ futures = "0.3"
rumqttc = "0.18"
thiserror = "1.0"
tokio = { version = "1.23", features = ["rt", "time"] }
tracing = "0.1.37"
Copy link
Contributor

Choose a reason for hiding this comment

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

Remove this dependency.

Comment on lines 43 to 48
eprintln!("Connection Error {}", err);
match err {
rumqttc::ConnectionError::ConnectionRefused(ConnectReturnCode::BadClientId) => {
warn!("Failed to initialize the session with MQTT Broker due to bad client id");
}
Copy link
Contributor

Choose a reason for hiding this comment

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

The init function is returning a Result<(), MqttError>, so it's weird to log the errors and to return ().

These error messages are a real improvement but they must be captured by an Error type.

Comment on lines 43 to 48
Err(err) => match err {
rumqttc::ConnectionError::ConnectionRefused(ConnectReturnCode::BadClientId) => {
return Err(MqttError::InitSessionError {
reason: "bad client id".to_string(),
});
}
rumqttc::ConnectionError::ConnectionRefused(
ConnectReturnCode::BadUserNamePassword,
) => {
return Err(MqttError::InitSessionError {
reason: "bad user name and password".to_string(),
});
}
rumqttc::ConnectionError::ConnectionRefused(ConnectReturnCode::NotAuthorized) => {
return Err(MqttError::InitSessionError {
reason: " not authorized".to_string(),
});
}
rumqttc::ConnectionError::ConnectionRefused(
ConnectReturnCode::RefusedProtocolVersion,
) => {
return Err(MqttError::InitSessionError {
reason: " protocol version mismatch".to_string(),
});
}
rumqttc::ConnectionError::ConnectionRefused(
ConnectReturnCode::ServiceUnavailable,
) => {
return Err(MqttError::InitSessionError {
reason: " service not available".to_string(),
});
}
rumqttc::ConnectionError::ConnectionRefused(ConnectReturnCode::Success) => {}
e => {
return Err(MqttError::InitSessionError {
reason: e.to_string(),
});
}
},
Copy link
Contributor

Choose a reason for hiding this comment

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

Nice. I would only move this code into an impl From<rumqttc::ConnectionError> for MqttError>.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Refactored this code introducing a function to convert/map the errors.

@@ -90,3 +94,37 @@ impl From<futures::channel::mpsc::SendError> for MqttError {
MqttError::SendOnClosedConnection
}
}

pub fn from_connection_error(err: rumqttc::ConnectionError) -> Result<(), MqttError> {
Copy link
Contributor

Choose a reason for hiding this comment

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

I would wrap this as an MqttError function so this will be invoked as MqttError::from_connection_error (otherwise the name sounds incomplete: what is built from the connection error?).

The type signature is also unusual for a from function. I read this as building a unit value with conversion error that are MqttError. While what you meant is building an MqttError.

Suggested change
pub fn from_connection_error(err: rumqttc::ConnectionError) -> Result<(), MqttError> {
impl MqttError {
pub fn from_connection_error(err: rumqttc::ConnectionError) -> MqttError {

I agree that there is a wart to address. This is the case of ConnectionError::ConnectionRefused(ConnectReturnCode::Success). I would simply treat this case as an error in the from_connection_error function and check this specific case in the init_session function.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I had to return the Result in an error conversion function because of the `Success code'. Now I refactored as suggested above.

Copy link
Contributor

@didier-wenzek didier-wenzek left a comment

Choose a reason for hiding this comment

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

Approved

Signed-off-by: Pradeep Kumar K J <pradeepkumar.kj@softwareag.com>
Signed-off-by: Pradeep Kumar K J <pradeepkumar.kj@softwareag.com>
@PradeepKiruvale PradeepKiruvale temporarily deployed to Test Pull Request May 4, 2023 08:48 — with GitHub Actions Inactive
@PradeepKiruvale PradeepKiruvale merged commit 55484fe into thin-edge:main May 4, 2023
15 checks passed
@gligorisaev
Copy link
Contributor

Tested and verified

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants