Upstream metadata expiry breaks lockboxes?

Hi @jeremias.tx,

This is somewhat delayed, but we updated TorizonCore Builder to 3.13.0 and rebuilt our offline updater lockboxes and OS install image. We’ve found that this does correctly include updated root metadata with expiration dates in the future. However, when we install the OS on a fresh systems (using easy installer), we get the following error in the aktualizr logs when it attempts to auto-provision:

Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Bootstrap empty SQL storage
Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Bootstraping DB to version 26
Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Couldn`t import data: empty path received
Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Couldn't import client certificate: "/var/sota/import/client.pem" doesn't exist.
Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Couldn't import client TLS key: "/var/sota/import/pkey.pem" doesn't exist.
Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Imported initial image root keys from "/var/sota/import/repo/root.json"
Aug 28 19:51:44 HOSTNAME aktualizr-torizon[1218]: Imported initial director root keys from "/var/sota/import/director/root.json"
Aug 28 19:51:45 HOSTNAME aktualizr-torizon[1218]: Initializing docker-compose Secondaries...
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: created: /var/sota/storage/docker-compose
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: created: /var/sota/storage/docker-compose/metadata
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: Bootstrap empty SQL storage
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: Bootstraping DB to version 26
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: No valid Director metadata found in storage: Could not load latest root
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: No valid Image metadata found in storage: Could not load latest root
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: Adding Secondary with ECU serial: 2b8b88c224054fb6511f4a560584152056504fc16922bfa5923181b4645cc1b8 with hardware ID: docker-compose
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: Initializing torizon-generic Secondaries...
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: created: /var/sota/storage/bootloader
Aug 28 19:51:47 HOSTNAME aktualizr-torizon[1218]: created: /var/sota/storage/bootloader/metadata

I suspect that this may be because the root metadata included in the OS install is now version 5 of the JSON scheme vs. the version 3 that was previously generated. (That is the signed.version field in provisioning-data.tar.gz/import/director/root.json.)

Have you seen other errors like this? Do you have any recommendations for how to resolve this issue?

Thank you,
Colin Gavin

Hi @cgrgen

Have you seen other errors like this? Do you have any recommendations for how to resolve this issue?

I’m confused, what is the error you are referring to exactly? In the snippet of your Aktualizr logs I don’t see any lines that indicate an error. Are offline updates not working?

I just provisioned a fresh device myself to compare the logs:

May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Bootstrap empty SQL storage
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Bootstraping DB to version 27
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Couldn`t import data: empty path received
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Couldn't import client certificate: "/var/sota/import/client.pem" doesn't exist.
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Couldn't import client TLS key: "/var/sota/import/pkey.pem" doesn't exist.
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Imported initial image root keys from "/var/sota/import/repo/root.json"
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Invalid role in root.json
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Imported initial director root keys from "/var/sota/import/director/root.json"
May 29 18:51:59 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Initializing docker-compose Secondaries...
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: created: /var/sota/storage/docker-compose/metadata
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Bootstrap empty SQL storage
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Bootstraping DB to version 27
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: No valid Director metadata found in storage: Could not load latest root
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: No valid Image metadata found in storage: Could not load latest root
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Adding Secondary with ECU serial: a55f1d641c0f7b0b2614f70d3062035a73c7c4695353d5b68d54686e2ea07b3c with hardware ID: docker-compose
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: Initializing torizon-generic Secondaries...
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: created: /var/sota/storage/bootloader
May 29 18:52:00 verdin-imx8mp-06849059 aktualizr-torizon[1276]: created: /var/sota/storage/bootloader/metadata

As you can see my logs are very similar to your logs. From here I was able to perform an offline update and it worked. So again I’m not really sure what error you are referring to.

I suspect that this may be because the root metadata included in the OS install is now version 5 of the JSON scheme vs. the version 3 that was previously generated.

I’m not sure why this would matter. As long as the root metadata that you used to provision on the device side is the same as the root metadata that is found in the Lockboxes used to perform offline updates. For example you say you’re using version 5 now. That just means that your Lockboxes should have the exact same version 5 metadata as well.

Best Regards,
Jeremias

Hi @jeremias.tx,

We had interpreted No valid Director metadata found in storage: Could not load latest root as an error; however, that appears not to be the case. It does appear that offline updates generated with the updated TCB version are working. Thanks for your help!

Best,
Colin

We had interpreted No valid Director metadata found in storage: Could not load latest root as an error

Oh that line is purely informational. It does not indicate any critical error has occurred. Unless Aktualizr hard crashes/exits or an update explicitly fails because of Aktualizr, then most logs are simply just informing what is occurring in the update client.

1 Like

Yes, Aktualizr’s logging style definitely leaves something to be desired. This won’t be the first time we’ve run into issues trying to interpret whether a message is simply informational or an actual problem that is preventing something from working.

That’s understandable. Though it would admittedly take quite an effort and time to review all the log output from Aktualizr, then possibly revise it.

Similar to the Linux kernel, Aktualizr typically leans towards being more verbose with logs at the cost of being less “clear” to non-Aktualizr developers. Again, I would just suggest that if a log appears concerning, try to see if there is actually a feature that is failing or not working right. If everything works as expected, there’s an almost certain chance that the log can be ignored.

Best Regards,
Jeremias