Adjust some log in aktualizr_secondary #1609

xcheng-here · 2020-03-20T11:02:16Z

No description provided.

xcheng-here · 2020-03-20T11:15:05Z

I haven't modify below 3 lines log:
Could not find primary ecu serial, defaulting to empty serial: unknown error
Could not find hardware_id for serial : unknown error
No valid and pending Director targets to be applied

The reason is the first 2 lines are from libaktualizr, describing the status of database, so if we want it don't output for secondary, it means maybe we need to modify some interfaces of libaktualizr. I think maybe we don't want to modify so much to remove those 2 lines log.
The third one is from aktualizr_secondary, but the problem is similar as above, it's describing the status of database, I'm not sure whether we really want to add code to check if it's the first time launching.

codecov-io · 2020-03-20T11:18:16Z

Codecov Report

Merging #1609 into master will decrease coverage by 0.06%.
The diff coverage is 87.5%.

@@            Coverage Diff             @@
##           master    #1609      +/-   ##
==========================================
- Coverage   82.54%   82.47%   -0.07%     
==========================================
  Files         189      189              
  Lines       11991    11996       +5     
==========================================
- Hits         9898     9894       -4     
- Misses       2093     2102       +9

Impacted Files	Coverage Δ
src/aktualizr_secondary/aktualizr_secondary.cc	`77.44% <100%> (+0.69%)`	⬆️
src/aktualizr_secondary/secondary_tcp_server.cc	`90% <85%> (+0.07%)`	⬆️
src/libaktualizr/storage/sqlstorage_base.h	`60% <0%> (-40%)`	⬇️
src/libaktualizr/storage/sql_utils.h	`85.89% <0%> (-1.29%)`	⬇️
src/libaktualizr/crypto/crypto.cc	`85.21% <0%> (-0.78%)`	⬇️
src/libaktualizr/storage/sqlstorage_base.cc	`75.83% <0%> (-0.68%)`	⬇️
src/libaktualizr/storage/sqlstorage.cc	`77.4% <0%> (-0.29%)`	⬇️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update fdafed8...f02c298. Read the comment docs.

pattivacek

The reason is the first 2 lines are from libaktualizr, describing the status of database, so if we want it don't output for secondary, it means maybe we need to modify some interfaces of libaktualizr. I think maybe we don't want to modify so much to remove those 2 lines log.

Fair point, but actually the Primary has the same problem.

The third one is from aktualizr_secondary, but the problem is similar as above, it's describing the status of database, I'm not sure whether we really want to add code to check if it's the first time launching.

How hard is it to fix this (and the other two)? If it requires a bunch of work, it might not be worth it, but it seems like we ought to be able to do better here.

pattivacek · 2020-03-20T16:34:31Z

src/aktualizr_secondary/aktualizr_secondary.cc

@@ -101,6 +101,7 @@ bool AktualizrSecondary::sendFirmware(const std::string& firmware) {
    return false;
  }

+  LOG_INFO << "Download successful.";


Can you add the name of the target?

src/aktualizr_secondary/aktualizr_secondary.cc

xcheng-here · 2020-03-23T06:32:05Z

How hard is it to fix this (and the other two)? If it requires a bunch of work, it might not be worth it, but it seems like we ought to be able to do better here.

IMHO, it's doable but maybe not worthy because those log also indicating some invalid status for both of primary and secondary. If I don't want to put some ugly code into our source, I will need to change some interfaces and maybe add something into database.

pattivacek

IMHO, it's doable but maybe not worthy because those log also indicating some invalid status for both of primary and secondary. If I don't want to put some ugly code into our source, I will need to change some interfaces and maybe add something into database.

Fair enough. I'll look into it some more and think about it, but it doesn't have to block the rest of this.

pattivacek · 2020-03-23T08:11:30Z

src/aktualizr_secondary/secondary_tcp_server.cc

@@ -146,14 +146,15 @@ bool SecondaryTcpServer::HandleOneConnection(int socket) {
        r->result = ok ? AKInstallationResult_success : AKInstallationResult_failure;
      } break;
      case AKIpUptaneMes_PR_sendFirmwareReq: {
+        LOG_DEBUG << "Received sendFirmwareReq from Primary.";


Actually, this should probably be INFO level.

pattivacek · 2020-03-23T08:11:44Z

src/aktualizr_secondary/secondary_tcp_server.cc

      } break;
      case AKIpUptaneMes_PR_installReq: {
+        LOG_DEBUG << "Received installReq from Primary.";


This should also be INFO.

pattivacek · 2020-03-23T08:42:30Z

No valid and pending Director targets to be applied

@mike-sul Can you actually explain why this message is printed? I also note that after an update has been installed with aktualizr-secondary, I see "There is a valid and pending Director target to be applied" even after rebooting. I think there's a problem with how we are checking the Director metadata here. We are doing the right thing, but the logging is wrong. director_repo_.checkMetaOffline should only fail if there is no metadata, and then we have to do additional work to determine if there are pending Targets to apply.

ghost · 2020-03-23T08:54:14Z

Can you actually explain why this message is printed?

To inform that there is no target (or target metadata) verification and installation of which is currently in progress.

director_repo_.checkMetaOffline should only fail if there is no metadata, and then we have to do additional work to determine if there are pending Targets to apply.

I agree with this statement and I think the code is inline with it. Just after initPendingTargetIfAny() the following is called if (hasPendingUpdate()) {.

pattivacek · 2020-03-23T09:11:22Z

Can you actually explain why this message is printed?

To inform that there is no target (or target metadata) verification and installation of which is currently in progress.

director_repo_.checkMetaOffline should only fail if there is no metadata, and then we have to do additional work to determine if there are pending Targets to apply.

I agree with this statement and I think the code is inline with it. Just after initPendingTargetIfAny() the following is called if (hasPendingUpdate()) {.

The code works correctly, but I think the logging is misleading. First, director_repo_.checkMetaOffline failing or succeeding does not tell us anything about whether there are updates to install or apply. It only tells us whether we have valid metadata in the database. Second, the message "There is a valid and pending Director target to be applied" appears every time the Secondary is started even after the target has been applied.

ghost · 2020-03-23T09:26:00Z

Can you actually explain why this message is printed?

To inform that there is no target (or target metadata) verification and installation of which is currently in progress.

director_repo_.checkMetaOffline should only fail if there is no metadata, and then we have to do additional work to determine if there are pending Targets to apply.

I agree with this statement and I think the code is inline with it. Just after initPendingTargetIfAny() the following is called if (hasPendingUpdate()) {.

The code works correctly, but I think the logging is misleading. First, director_repo_.checkMetaOffline failing or succeeding does not tell us anything about whether there are updates to install or apply. It only tells us whether we have valid metadata in the database. Second, the message "There is a valid and pending Director target to be applied" appears every time the Secondary is started even after the target has been applied.

Oh, now I understand your point. Yes, the first log message is misleading for sure, it should be changed or removed at all.

The second one should be OK provided that the metadata are removed from DB just after successful installation, at least that was my plan. So, if the metadata are removed just after successful installation then this if (!director_repo_.checkMetaOffline(*storage_)) should be true and LOG_INFO << "There is a valid and pending Director target to be applied"; is never called.

src/aktualizr_secondary/aktualizr_secondary.cc

pattivacek · 2020-03-23T10:29:32Z

IMHO, it's doable but maybe not worthy because those log also indicating some invalid status for both of primary and secondary. If I don't want to put some ugly code into our source, I will need to change some interfaces and maybe add something into database.

Fair enough. I'll look into it some more and think about it, but it doesn't have to block the rest of this.

I've addressed these two issues in #1611.

Co-Authored-By: Patrick Vacek <patrickvacek@gmail.com> Signed-off-by: cheng.xiang <ext-cheng.xiang@here.com>

Read and print Uptane metadata in the expected order. Be clear about connection with the Primary. Don't print a message about a pending target unless there really is one to apply. Signed-off-by: Patrick Vacek <patrickvacek@gmail.com>

pattivacek · 2020-03-24T08:56:13Z

The second one should be OK provided that the metadata are removed from DB just after successful installation, at least that was my plan.

The metadata is not removed from the database, and it should not be. I've pushed another commit that address this issue as well as a few other minor things that were bugging me.

mike-sul · 2020-03-24T09:05:50Z

The metadata is not removed from the database, and it should not be

What for do we need to keep it in the DB after a target update has been installed and applied?

mike-sul · 2020-03-24T09:28:10Z

The metadata is not removed from the database, and it should not be

What for do we need to keep it in the DB after a target update has been installed and applied?

Got already answer to it :)

pattivacek

LGTM but we should probably get an approval from someone that didn't write one of the commits.

xcheng-here force-pushed the fix/OTA-4389/aktualizr-secondary_logging branch from 9654cbe to f2e276f Compare March 20, 2020 11:03

pattivacek reviewed Mar 20, 2020

View reviewed changes

xcheng-here force-pushed the fix/OTA-4389/aktualizr-secondary_logging branch from f2e276f to 6db9c20 Compare March 23, 2020 06:23

pattivacek reviewed Mar 23, 2020

View reviewed changes

xcheng-here force-pushed the fix/OTA-4389/aktualizr-secondary_logging branch from 6db9c20 to 1faa65b Compare March 23, 2020 10:09

pattivacek reviewed Mar 23, 2020

View reviewed changes

src/aktualizr_secondary/aktualizr_secondary.cc Outdated Show resolved Hide resolved

xcheng-here force-pushed the fix/OTA-4389/aktualizr-secondary_logging branch from d90d360 to f846587 Compare March 23, 2020 12:31

mike-sul previously approved these changes Mar 24, 2020

View reviewed changes

pattivacek dismissed mike-sul’s stale review via 2d87ab5 March 24, 2020 08:16

Adjust some log in aktualizr_secondary

4e9a0f7

Co-Authored-By: Patrick Vacek <patrickvacek@gmail.com> Signed-off-by: cheng.xiang <ext-cheng.xiang@here.com>

pattivacek force-pushed the fix/OTA-4389/aktualizr-secondary_logging branch from 2d87ab5 to 4e9a0f7 Compare March 24, 2020 08:17

Some more Secondary logging cleanup.

f02c298

Read and print Uptane metadata in the expected order. Be clear about connection with the Primary. Don't print a message about a pending target unless there really is one to apply. Signed-off-by: Patrick Vacek <patrickvacek@gmail.com>

pattivacek requested review from eu-siemann, kbushgit and lbonn March 24, 2020 09:46

pattivacek approved these changes Mar 24, 2020

View reviewed changes

mike-sul approved these changes Mar 24, 2020

View reviewed changes

pattivacek merged commit 4d9b41e into master Mar 24, 2020

pattivacek deleted the fix/OTA-4389/aktualizr-secondary_logging branch March 24, 2020 10:01

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Adjust some log in aktualizr_secondary #1609

Adjust some log in aktualizr_secondary #1609

xcheng-here commented Mar 20, 2020

xcheng-here commented Mar 20, 2020

codecov-io commented Mar 20, 2020 •

edited

Loading

pattivacek left a comment

pattivacek Mar 20, 2020

xcheng-here commented Mar 23, 2020

pattivacek left a comment

pattivacek Mar 23, 2020

pattivacek Mar 23, 2020

pattivacek commented Mar 23, 2020

ghost commented Mar 23, 2020

pattivacek commented Mar 23, 2020

ghost commented Mar 23, 2020

pattivacek commented Mar 23, 2020

pattivacek commented Mar 24, 2020

mike-sul commented Mar 24, 2020

mike-sul commented Mar 24, 2020

pattivacek left a comment

Adjust some log in aktualizr_secondary #1609

Adjust some log in aktualizr_secondary #1609

Conversation

xcheng-here commented Mar 20, 2020

xcheng-here commented Mar 20, 2020

codecov-io commented Mar 20, 2020 • edited Loading

Codecov Report

pattivacek left a comment

Choose a reason for hiding this comment

pattivacek Mar 20, 2020

Choose a reason for hiding this comment

xcheng-here commented Mar 23, 2020

pattivacek left a comment

Choose a reason for hiding this comment

pattivacek Mar 23, 2020

Choose a reason for hiding this comment

pattivacek Mar 23, 2020

Choose a reason for hiding this comment

pattivacek commented Mar 23, 2020

ghost commented Mar 23, 2020

pattivacek commented Mar 23, 2020

ghost commented Mar 23, 2020

pattivacek commented Mar 23, 2020

pattivacek commented Mar 24, 2020

mike-sul commented Mar 24, 2020

mike-sul commented Mar 24, 2020

pattivacek left a comment

Choose a reason for hiding this comment

codecov-io commented Mar 20, 2020 •

edited

Loading