Skip to content
This repository has been archived by the owner on May 21, 2024. It is now read-only.

Feat/better logging #1555

Merged
merged 4 commits into from
Feb 13, 2020
Merged

Feat/better logging #1555

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
d364271
Print basic device information when starting aktualizr.
pattivacek Feb 12, 2020
b64fe4d
Also print basic device certificate information to the log.
pattivacek Feb 12, 2020
b7adc45
Specify some NOLINTs to prevent masking other problems.
pattivacek Feb 13, 2020
c9cf301
Attempt to support pre-1.1.0 openssl.
pattivacek Feb 13, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions src/aktualizr_primary/secondary.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -51,8 +51,8 @@ void initSecondaries(Aktualizr& aktualizr, const boost::filesystem::path& config
Secondaries secondaries = createSecondaries(*config);

for (const auto& secondary : secondaries) {
LOG_INFO << "Adding Secondary to Aktualizr."
<< "HW_ID: " << secondary->getHwId() << " Serial: " << secondary->getSerial();
LOG_INFO << "Adding Secondary with ECU serial: " << secondary->getSerial()
Copy link
Collaborator

@mike-sul mike-sul Feb 13, 2020 •
edited
Loading

Choose a reason for hiding this comment

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

mixing metadata/values with message text might not be optimal as you need to search for values between text. The best practice here is to separate a static part of a log message from its variable part. For example,
`
Adding Secondary:

serial: <serial>
hardware ID: <hwid>

`

but it's not critical here as there are just two variable elements here, it's rather important when there are more of them

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I'm not quite sure I follow. All I did was rephrase it and swap the serial and hardware ID.

<< " with hardware ID: " << secondary->getHwId();
aktualizr.AddSecondary(secondary);
}
} catch (const std::exception& exc) {
Expand Down
6 changes: 4 additions & 2 deletions src/cert_provider/main.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -249,7 +249,8 @@ bool generateAndSign(const std::string& cacert_path, const std::string& capkey_p
std::cerr << "PEM_write_RSAPrivateKey" << std::endl;
return false;
}
auto privkey_len = BIO_get_mem_data(privkey_file.get(), &privkey_buf); // NOLINT
// NOLINTNEXTLINE(cppcoreguidelines-pro-type-cstyle-cast)
auto privkey_len = BIO_get_mem_data(privkey_file.get(), &privkey_buf);
*pkey = std::string(privkey_buf, static_cast<size_t>(privkey_len));

// serialize certificate
Expand All @@ -264,7 +265,8 @@ bool generateAndSign(const std::string& cacert_path, const std::string& capkey_p
std::cerr << "PEM_write_X509" << std::endl;
return false;
}
auto cert_len = BIO_get_mem_data(cert_file.get(), &cert_buf); // NOLINT
// NOLINTNEXTLINE(cppcoreguidelines-pro-type-cstyle-cast)
auto cert_len = BIO_get_mem_data(cert_file.get(), &cert_buf);
*cert = std::string(cert_buf, static_cast<size_t>(cert_len));

return true;
Expand Down
13 changes: 8 additions & 5 deletions src/libaktualizr/crypto/crypto.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -274,7 +274,7 @@ bool Crypto::parseP12(BIO *p12_bio, const std::string &p12_password, std::string
PEM_write_bio_PrivateKey(pkey_pem_sink.get(), pkey.get(), nullptr, nullptr, 0, nullptr, nullptr);

char *pkey_buf;
auto pkey_len = BIO_get_mem_data(pkey_pem_sink.get(), &pkey_buf); // NOLINT
auto pkey_len = BIO_get_mem_data(pkey_pem_sink.get(), &pkey_buf); // NOLINT(cppcoreguidelines-pro-type-cstyle-cast)
*out_pkey = std::string(pkey_buf, static_cast<size_t>(pkey_len));

char *cert_buf;
Expand All @@ -299,10 +299,12 @@ bool Crypto::parseP12(BIO *p12_bio, const std::string &p12_password, std::string
PEM_write_bio_X509(ca_sink.get(), ca_cert);
PEM_write_bio_X509(cert_sink.get(), ca_cert);
}
ca_len = static_cast<size_t>(BIO_get_mem_data(ca_sink.get(), &ca_buf)); // NOLINT
// NOLINTNEXTLINE(cppcoreguidelines-pro-type-cstyle-cast)
ca_len = static_cast<size_t>(BIO_get_mem_data(ca_sink.get(), &ca_buf));
*out_ca = std::string(ca_buf, ca_len);

cert_len = static_cast<size_t>(BIO_get_mem_data(cert_sink.get(), &cert_buf)); // NOLINT
// NOLINTNEXTLINE(cppcoreguidelines-pro-type-cstyle-cast)
cert_len = static_cast<size_t>(BIO_get_mem_data(cert_sink.get(), &cert_buf));
*out_cert = std::string(cert_buf, cert_len);

return true;
Expand Down Expand Up @@ -394,7 +396,7 @@ bool Crypto::generateRSAKeyPair(KeyType key_type, std::string *public_key, std::
if (ret != 1) {
return false;
}
auto pubkey_len = BIO_get_mem_data(pubkey_sink.get(), &pubkey_buf); // NOLINT
auto pubkey_len = BIO_get_mem_data(pubkey_sink.get(), &pubkey_buf); // NOLINT(cppcoreguidelines-pro-type-cstyle-cast)
*public_key = std::string(pubkey_buf, static_cast<size_t>(pubkey_len));

char *privkey_buf;
Expand All @@ -408,7 +410,8 @@ bool Crypto::generateRSAKeyPair(KeyType key_type, std::string *public_key, std::
if (ret != 1) {
return false;
}
auto privkey_len = BIO_get_mem_data(privkey_sink.get(), &privkey_buf); // NOLINT
// NOLINTNEXTLINE(cppcoreguidelines-pro-type-cstyle-cast)
auto privkey_len = BIO_get_mem_data(privkey_sink.get(), &privkey_buf);
*private_key = std::string(privkey_buf, static_cast<size_t>(privkey_len));
return true;
}
Expand Down
69 changes: 67 additions & 2 deletions src/libaktualizr/crypto/keymanager.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,10 +1,11 @@
#include "keymanager.h"

#include <stdexcept>
#include <utility>

#include <boost/scoped_array.hpp>
#include <utility>

#include "crypto/openssl_compat.h"
#include "storage/invstorage.h"
#include "utilities/types.h"

Expand Down Expand Up @@ -192,10 +193,74 @@ std::string KeyManager::getCN() const {
}
boost::scoped_array<char> buf(new char[len + 1]);
X509_NAME_get_text_by_NID(X509_get_subject_name(x.get()), NID_commonName, buf.get(), len + 1);
std::string cn(buf.get());
const std::string cn(buf.get());
return cn;
}

void KeyManager::getCertInfo(std::string *subject, std::string *issuer, std::string *not_before,
std::string *not_after) const {
std::string not_found_cert_message = "Certificate is not found, can't extract device certificate";
std::string cert;
if (config_.tls_cert_source == CryptoSource::kFile || config_.tls_cert_source == CryptoSource::kAndroid) {
if (!backend_->loadTlsCert(&cert)) {
throw std::runtime_error(not_found_cert_message);
}
} else { // CryptoSource::kPkcs11
if (!built_with_p11) {
throw std::runtime_error("Aktualizr was built without PKCS#11 support, can't extract device certificate");
}
if (!(*p11_)->readTlsCert(&cert)) {
throw std::runtime_error(not_found_cert_message);
}
}

StructGuard<BIO> bio(BIO_new_mem_buf(const_cast<char *>(cert.c_str()), static_cast<int>(cert.size())), BIO_vfree);
StructGuard<X509> x(PEM_read_bio_X509(bio.get(), nullptr, nullptr, nullptr), X509_free);
if (x == nullptr) {
throw std::runtime_error("Could not parse certificate");
}

StructGuard<BIO> subj_bio(BIO_new(BIO_s_mem()), BIO_vfree);
X509_NAME_print_ex(subj_bio.get(), X509_get_subject_name(x.get()), 1, 0);
Copy link
Contributor

Choose a reason for hiding this comment

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

The docs I've found are not really helpful but are we sure that this call or the next (BIO_get_mem_data) can't fail and we end up creating a string from an uninitialized pointer (subj_buf).

Maybe a simple precaution:

char *subj_buf = nullptr;
...
if (subj_buf == nullptr) {
    throw xxx;
}
*subject = std::string(subj_buf, ...);

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Yeah I was annoyed that the SSL docs don't even mention the return value of X509_NAME_print_ex. However, https://manpages.debian.org/unstable/libssl-doc/X509_NAME_print_ex.3ssl.en.html says that "X509_NAME_print_ex() and X509_NAME_print_ex_fp() return 1 on success or 0 on error if the XN_FLAG_COMPAT is set, which is the same as X509_NAME_print(). Otherwise, it returns -1 on error or other values on success." Lovely. I'll play around with this a bit and try to be a bit more careful.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

I'm a bit scared of the return value mess so I ended up just taking your advice literally.

char *subj_buf = nullptr;
auto subj_len = BIO_get_mem_data(subj_bio.get(), &subj_buf); // NOLINT(cppcoreguidelines-pro-type-cstyle-cast)
if (subj_buf == nullptr) {
throw std::runtime_error("Could not parse certificate subject");
}
*subject = std::string(subj_buf, static_cast<size_t>(subj_len));

StructGuard<BIO> issuer_bio(BIO_new(BIO_s_mem()), BIO_vfree);
X509_NAME_print_ex(issuer_bio.get(), X509_get_issuer_name(x.get()), 1, 0);
char *issuer_buf = nullptr;
auto issuer_len = BIO_get_mem_data(issuer_bio.get(), &issuer_buf); // NOLINT(cppcoreguidelines-pro-type-cstyle-cast)
if (issuer_buf == nullptr) {
throw std::runtime_error("Could not parse certificate issuer");
}
*issuer = std::string(issuer_buf, static_cast<size_t>(issuer_len));

#if AKTUALIZR_OPENSSL_PRE_11
const ASN1_TIME *nb_asn1 = X509_get_notBefore(x.get());
#else
const ASN1_TIME *nb_asn1 = X509_get0_notBefore(x.get());
#endif
StructGuard<BIO> nb_bio(BIO_new(BIO_s_mem()), BIO_vfree);
ASN1_TIME_print(nb_bio.get(), nb_asn1);
char *nb_buf;
auto nb_len = BIO_get_mem_data(nb_bio.get(), &nb_buf); // NOLINT(cppcoreguidelines-pro-type-cstyle-cast)
*not_before = std::string(nb_buf, static_cast<size_t>(nb_len));

#if AKTUALIZR_OPENSSL_PRE_11
const ASN1_TIME *na_asn1 = X509_get_notAfter(x.get());
#else
const ASN1_TIME *na_asn1 = X509_get0_notAfter(x.get());
#endif
StructGuard<BIO> na_bio(BIO_new(BIO_s_mem()), BIO_vfree);
ASN1_TIME_print(na_bio.get(), na_asn1);
char *na_buf;
auto na_len = BIO_get_mem_data(na_bio.get(), &na_buf); // NOLINT(cppcoreguidelines-pro-type-cstyle-cast)
*not_after = std::string(na_buf, static_cast<size_t>(na_len));
}

void KeyManager::copyCertsToCurl(HttpInterface &http) {
std::string pkey = getPkey();
std::string cert = getCert();
Expand Down
1 change: 1 addition & 0 deletions src/libaktualizr/crypto/keymanager.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ class KeyManager {
std::string getCert() const;
std::string getCa() const;
std::string getCN() const;
void getCertInfo(std::string *subject, std::string *issuer, std::string *not_before, std::string *not_after) const;
bool isOk() const { return ((getPkey().size() != 0u) && (getCert().size() != 0u) && (getCa().size() != 0u)); }
std::string generateUptaneKeyPair();
KeyType getUptaneKeyType() const { return config_.uptane_key_type; }
Expand Down
25 changes: 21 additions & 4 deletions src/libaktualizr/primary/sotauptaneclient.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,7 @@ void SotaUptaneClient::finalizeAfterReboot() {
// TODO: consider bringing checkAndUpdatePendingSecondaries and the following functionality
// to the common denominator
if (!hasPendingUpdates()) {
LOG_INFO << "No any pending update, continue with initialization";
LOG_DEBUG << "No pending updates, continuing with initialization";
return;
}

Expand All @@ -90,7 +90,7 @@ void SotaUptaneClient::finalizeAfterReboot() {
storage->loadInstalledVersions(primary_ecu_serial.ToString(), nullptr, &pending_target);

if (!pending_target) {
LOG_ERROR << "No any pending update for Primary ECU is found, continue with initialization";
LOG_ERROR << "No pending update for Primary ECU found, continuing with initialization";
return;
}

Expand All @@ -100,7 +100,7 @@ void SotaUptaneClient::finalizeAfterReboot() {

if (install_res.result_code == data::ResultCode::Numeric::kNeedCompletion) {
LOG_INFO << "Pending update for Primary ECU was not applied because reboot was not detected, "
"continue with initialization";
"continuing with initialization";
return;
}

Expand Down Expand Up @@ -279,10 +279,27 @@ void SotaUptaneClient::initialize() {
uptane_manifest = std::make_shared<Uptane::ManifestIssuer>(keys, serials[0].first);
primary_ecu_serial_ = serials[0].first;
hw_ids.insert(serials[0]);
LOG_INFO << "Primary ECU serial: " << primary_ecu_serial_ << " with hardware ID: " << serials[0].second;

verifySecondaries();
LOG_DEBUG << "... provisioned OK";

std::string device_id;
if (!storage->loadDeviceId(&device_id)) {
throw std::runtime_error("Unable to load device ID after device registration.");
}
LOG_INFO << "Device ID: " << device_id;
LOG_INFO << "Device Gateway URL: " << config.tls.server;

std::string subject;
std::string issuer;
std::string not_before;
std::string not_after;
keys->getCertInfo(&subject, &issuer, &not_before, &not_after);
LOG_INFO << "Certificate subject: " << subject;
LOG_INFO << "Certificate issuer: " << issuer;
LOG_INFO << "Certificate valid from: " << not_before << " until: " << not_after;

LOG_DEBUG << "... provisioned OK";
finalizeAfterReboot();
}

Expand Down