You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mynewt.apache.org by cc...@apache.org on 2019/06/12 21:48:50 UTC
[mynewt-core] branch master updated: mgmt/imgmgr: Log image
management events
This is an automated email from the ASF dual-hosted git repository.
ccollins pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/mynewt-core.git
The following commit(s) were added to refs/heads/master by this push:
new e485d87 mgmt/imgmgr: Log image management events
e485d87 is described below
commit e485d87c3cb5b2d8a6965c5837d51179c9b7faf4
Author: Christopher Collins <cc...@apache.org>
AuthorDate: Tue Jun 4 10:38:36 2019 -0700
mgmt/imgmgr: Log image management events
This commit adds logging for four image management events (all events
are CBOR-encoded):
upstart:
When: upon receiving an upload request with an offset of 0.
Structure:
{
"ev": "upstart",
"rc": <mgmt-error-code (int)>
}
updone:
When: upon receiving an upload request containing the final chunk
of an image OR a failed upload request with a non-zero offset.
Structure:
{
"ev": "updone",
"rc": <mgmt-error-code (int)>
"hs": <image-hash (byte-string)> (only present on success)
}
pend:
When: upon receiving a non-permanent `set-pending` request.
Structure:
{
"ev": "pend",
"rc": <mgmt-error-code (int)>,
"hs": <image-hash (byte-string)>
}
conf:
When: upon receiving a `confirm` request OR a permanent
`set-pending` request.
Structure:
{
"ev": "conf",
"rc": <mgmt-error-code (int)>,
"hs": <image-hash (byte-string)> (only present for `set-pending`)
}
Here is a log snippet after an upload-test-reset-confirm cycle:
```
44518 1559419790601524us | CUSTOM (176) INFO (1) cbor {"ev":"upstart","rc":0}
46008 1559419842390600us | CUSTOM (176) INFO (1) cbor {"ev":"updone","hs":"ZEiw0Ttss5oSc/FUldJB1mFiw/wed+Tt1MBr8uo9aK8=","rc":0}
46085 1559419899070308us | CUSTOM (176) INFO (1) cbor {"ev":"pend","hs":"ZEiw0Ttss5oSc/FUldJB1mFiw/wed+Tt1MBr8uo9aK8=","rc":0}
46109 1559419964396732us | CUSTOM (176) INFO (1) cbor {"ev":"conf","rc":0}
```
Image management logging is disabled by default. To enable it:
1. Override `IMGMGR_LOG_LVL` with a value <= 1 (`LOG_LEVEL_INFO`)
2. Map the `IMGMGR_LOG_MOD` module to a log, e.g.,
```
rc = modlog_register(MYNEWT_VAL(IMGMGR_LOG_MOD), &my_log,
LOG_LEVEL_INFO, NULL);
assert(rc == 0);
```
---
mgmt/imgmgr/pkg.yml | 1 +
mgmt/imgmgr/src/imgmgr.c | 63 +++++++++--
mgmt/imgmgr/src/imgmgr_log.c | 142 +++++++++++++++++++++++++
mgmt/imgmgr/src/imgmgr_priv.h | 4 +
mgmt/imgmgr/src/imgmgr_state.c | 46 +++++---
mgmt/imgmgr/syscfg.yml | 12 +++
sys/log/common/include/log_common/log_common.h | 16 +++
7 files changed, 262 insertions(+), 22 deletions(-)
diff --git a/mgmt/imgmgr/pkg.yml b/mgmt/imgmgr/pkg.yml
index a535fd5..c3b8b40 100644
--- a/mgmt/imgmgr/pkg.yml
+++ b/mgmt/imgmgr/pkg.yml
@@ -28,6 +28,7 @@ pkg.deps:
- "@apache-mynewt-core/encoding/base64"
- "@apache-mynewt-core/mgmt/mgmt"
- "@apache-mynewt-core/sys/flash_map"
+ - "@apache-mynewt-core/sys/log/modlog"
pkg.req_apis:
- newtmgr
diff --git a/mgmt/imgmgr/src/imgmgr.c b/mgmt/imgmgr/src/imgmgr.c
index 33d63ed..81c2205 100644
--- a/mgmt/imgmgr/src/imgmgr.c
+++ b/mgmt/imgmgr/src/imgmgr.c
@@ -743,6 +743,45 @@ imgr_upload_good_rsp(struct mgmt_cbuf *cb)
return 0;
}
+/**
+ * Logs an upload request if necessary.
+ *
+ * @param is_first Whether the request includes the first chunk of
+ * the image.
+ * @param is_last Whether the request includes the last chunk of
+ * the image.
+ * @param status The result of processing the upload request
+ * (MGMT_ERR code).
+ *
+ * @return 0 on success; nonzero on failure.
+ */
+static int
+imgr_upload_log(bool is_first, bool is_last, int status)
+{
+ uint8_t hash[IMGMGR_HASH_LEN];
+ const uint8_t *hashp;
+ int rc;
+
+ if (is_first) {
+ return imgmgr_log_upload_start(status);
+ }
+
+ if (is_last || status != 0) {
+ /* Log the image hash if we know it. */
+ rc = imgr_read_info(1, NULL, hash, NULL);
+ if (rc != 0) {
+ hashp = NULL;
+ } else {
+ hashp = hash;
+ }
+
+ return imgmgr_log_upload_done(status, hashp);
+ }
+
+ /* Nothing to log. */
+ return 0;
+}
+
static int
imgr_upload(struct mgmt_cbuf *cb)
{
@@ -818,8 +857,8 @@ imgr_upload(struct mgmt_cbuf *cb)
if (imgr_upload_cb != NULL) {
rc = imgr_upload_cb(req.off, action.size, imgr_upload_arg);
if (rc != 0) {
- imgmgr_dfu_stopped();
- return imgr_error_rsp(cb, rc, imgmgr_err_str_app_reject);
+ errstr = imgmgr_err_str_app_reject;
+ goto end;
}
}
@@ -829,9 +868,9 @@ imgr_upload(struct mgmt_cbuf *cb)
rc = flash_area_open(imgr_state.area_id, &fa);
if (rc != 0) {
- imgmgr_dfu_stopped();
- return imgr_error_rsp(cb, MGMT_ERR_EUNKNOWN,
- imgmgr_err_str_flash_open_failed);
+ rc = MGMT_ERR_EUNKNOWN;
+ errstr = imgmgr_err_str_flash_open_failed;
+ goto end;
}
if (req.off == 0) {
@@ -873,13 +912,14 @@ imgr_upload(struct mgmt_cbuf *cb)
if (rc != 0) {
rc = MGMT_ERR_EUNKNOWN;
errstr = imgmgr_err_str_flash_erase_failed;
+ goto end;
}
}
#endif
}
/* Write the image data to flash. */
- if (rc == 0 && req.data_len != 0) {
+ if (req.data_len != 0) {
#if MYNEWT_VAL(IMGMGR_LAZY_ERASE)
/* erase as we cross sector boundaries */
if (imgr_erase_if_needed(fa, req.off, action.write_bytes) != 0) {
@@ -890,9 +930,9 @@ imgr_upload(struct mgmt_cbuf *cb)
#endif
rc = flash_area_write(fa, req.off, req.img_data, action.write_bytes);
if (rc != 0) {
- imgmgr_dfu_stopped();
rc = MGMT_ERR_EUNKNOWN;
errstr = imgmgr_err_str_flash_write_failed;
+ goto end;
} else {
imgr_state.off += action.write_bytes;
if (imgr_state.off == imgr_state.size) {
@@ -903,12 +943,15 @@ imgr_upload(struct mgmt_cbuf *cb)
}
}
-#if MYNEWT_VAL(IMGMGR_LAZY_ERASE)
end:
-#endif
- flash_area_close(fa);
+ if (fa != NULL) {
+ flash_area_close(fa);
+ }
+
+ imgr_upload_log(req.off == 0, imgr_state.off == imgr_state.size, rc);
if (rc != 0) {
+ imgmgr_dfu_stopped();
return imgr_error_rsp(cb, rc, errstr);
}
diff --git a/mgmt/imgmgr/src/imgmgr_log.c b/mgmt/imgmgr/src/imgmgr_log.c
new file mode 100644
index 0000000..81aba3e
--- /dev/null
+++ b/mgmt/imgmgr/src/imgmgr_log.c
@@ -0,0 +1,142 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+
+#include "os/mynewt.h"
+#include "modlog/modlog.h"
+#include "cborattr/cborattr.h"
+#include "imgmgr/imgmgr.h"
+#include "imgmgr_priv.h"
+
+/**
+ * Log event types (all events are CBOR-encoded):
+ *
+ * upstart:
+ * When: upon receiving an upload request with an offset of 0.
+ * Structure:
+ * {
+ * "ev": "upstart",
+ * "rc": <mgmt-error-code (int)>
+ * }
+ *
+ * updone:
+ * When: upon receiving an upload request containing the final chunk of an
+ * image OR a failed upload request with a non-zero offset.
+ * Structure:
+ * {
+ * "ev": "updone",
+ * "rc": <mgmt-error-code (int)>
+ * "hs": <image-hash (byte-string)> (only present on success)
+ * }
+ *
+ * pend:
+ * When: upon receiving a non-permanent `set-pending` request.
+ * Structure:
+ * {
+ * "ev": "pend",
+ * "rc": <mgmt-error-code (int)>,
+ * "hs": <image-hash (byte-string)>
+ * }
+ *
+ * conf:
+ * When: upon receiving a `confirm` request OR a permanent `set-pending`
+ * request.
+ * Structure:
+ * {
+ * "ev": "conf",
+ * "rc": <mgmt-error-code (int)>,
+ * "hs": <image-hash (byte-string)> (only present for `set-pending`)
+ * }
+ */
+
+#define IMGMGR_LOG_EV_UPSTART "upstart"
+#define IMGMGR_LOG_EV_UPDONE "updone"
+#define IMGMGR_LOG_EV_PEND "pend"
+#define IMGMGR_LOG_EV_CONF "conf"
+
+static int
+imgmgr_log_gen(const char *ev, int status, const uint8_t *hash)
+{
+#if MYNEWT_VAL(LOG_VERSION) > 2 && \
+ LOG_MOD_LEVEL_IS_ACTIVE(MYNEWT_VAL(IMGMGR_LOG_LVL), LOG_LEVEL_INFO)
+
+ struct os_mbuf *om;
+ int rc;
+
+ const struct cbor_out_attr_t attrs[] = {
+ {
+ .attribute = "ev",
+ .val = {
+ .type = CborAttrTextStringType,
+ .string = ev,
+ },
+ },
+ {
+ .attribute = "rc",
+ .val = {
+ .type = CborAttrIntegerType,
+ .integer = status,
+ },
+ },
+ {
+ .attribute = "hs",
+ .val = {
+ .type = CborAttrByteStringType,
+ .bytestring.data = hash,
+ .bytestring.len = IMGMGR_HASH_LEN,
+ },
+ .omit = hash == NULL,
+ },
+ { 0 }
+ };
+
+ rc = cbor_write_object_msys(attrs, &om);
+ if (rc != 0) {
+ return rc;
+ }
+
+ modlog_append_mbuf(MYNEWT_VAL(IMGMGR_LOG_MOD), LOG_LEVEL_INFO,
+ LOG_ETYPE_CBOR, om);
+#endif
+
+ return 0;
+}
+
+int
+imgmgr_log_upload_start(int status)
+{
+ return imgmgr_log_gen(IMGMGR_LOG_EV_UPSTART, status, NULL);
+}
+
+int
+imgmgr_log_upload_done(int status, const uint8_t *hash)
+{
+ return imgmgr_log_gen(IMGMGR_LOG_EV_UPDONE, 0, hash);
+}
+
+int
+imgmgr_log_pending(int status, const uint8_t *hash)
+{
+ return imgmgr_log_gen(IMGMGR_LOG_EV_PEND, status, hash);
+}
+
+int
+imgmgr_log_confirm(int status, const uint8_t *hash)
+{
+ return imgmgr_log_gen(IMGMGR_LOG_EV_CONF, status, hash);
+}
diff --git a/mgmt/imgmgr/src/imgmgr_priv.h b/mgmt/imgmgr/src/imgmgr_priv.h
index d318559..5954199 100644
--- a/mgmt/imgmgr/src/imgmgr_priv.h
+++ b/mgmt/imgmgr/src/imgmgr_priv.h
@@ -95,6 +95,10 @@ int imgmgr_state_write(struct mgmt_cbuf *njb);
int imgr_find_by_ver(struct image_version *find, uint8_t *hash);
int imgr_find_by_hash(uint8_t *find, struct image_version *ver);
int imgr_cli_register(void);
+int imgmgr_log_upload_start(int status);
+int imgmgr_log_upload_done(int status, const uint8_t *hash);
+int imgmgr_log_pending(int status, const uint8_t *hash);
+int imgmgr_log_confirm(int status, const uint8_t *hash);
#ifdef __cplusplus
}
diff --git a/mgmt/imgmgr/src/imgmgr_state.c b/mgmt/imgmgr/src/imgmgr_state.c
index 48f6b2b..ec1c309 100644
--- a/mgmt/imgmgr/src/imgmgr_state.c
+++ b/mgmt/imgmgr/src/imgmgr_state.c
@@ -142,25 +142,32 @@ imgmgr_state_set_pending(int slot, int permanent)
{
uint32_t image_flags;
uint8_t state_flags;
+ uint8_t hash[IMGMGR_HASH_LEN];
+ const uint8_t *hashp;
int split_app_active;
int rc;
state_flags = imgmgr_state_flags(slot);
split_app_active = split_app_active_get();
+ hashp = NULL;
+
/* Unconfirmed slots are always runable. A confirmed slot can only be
* run if it is a loader in a split image setup.
*/
if ((state_flags & IMGMGR_STATE_F_CONFIRMED) &&
(slot != 0 || !split_app_active)) {
- return MGMT_ERR_EBADSTATE;
+ rc = MGMT_ERR_EBADSTATE;
+ goto done;
}
- rc = imgr_read_info(slot, NULL, NULL, &image_flags);
+ rc = imgr_read_info(slot, NULL, hash, &image_flags);
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
+ hashp = hash;
if (!(image_flags & IMAGE_F_NON_BOOTABLE)) {
/* Unified image or loader. */
@@ -168,7 +175,8 @@ imgmgr_state_set_pending(int slot, int permanent)
/* No change in split status. */
rc = boot_set_pending(permanent);
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
} else {
/* Currently loader + app; testing loader-only. */
@@ -178,7 +186,8 @@ imgmgr_state_set_pending(int slot, int permanent)
rc = split_write_split(SPLIT_MODE_TEST_LOADER);
}
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
}
} else {
@@ -189,11 +198,18 @@ imgmgr_state_set_pending(int slot, int permanent)
rc = split_write_split(SPLIT_MODE_TEST_APP);
}
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
}
- return 0;
+done:
+ if (permanent) {
+ imgmgr_log_confirm(rc, hashp);
+ } else {
+ imgmgr_log_pending(rc, hashp);
+ }
+ return rc;
}
int
@@ -203,25 +219,29 @@ imgmgr_state_confirm(void)
/* Confirm disallowed if a test is pending. */
if (imgmgr_state_any_pending()) {
- return MGMT_ERR_EBADSTATE;
+ rc = MGMT_ERR_EBADSTATE;
+ goto done;
}
/* Confirm the unified image or loader in slot 0. */
rc = boot_set_confirmed();
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
/* If a split app in slot 1 is active, confirm it as well. */
if (split_app_active_get()) {
rc = split_write_split(SPLIT_MODE_APP);
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
} else {
rc = split_write_split(SPLIT_MODE_LOADER);
if (rc != 0) {
- return MGMT_ERR_EUNKNOWN;
+ rc = MGMT_ERR_EUNKNOWN;
+ goto done;
}
#if MYNEWT_VAL(LOG_FCB_SLOT1)
@@ -232,7 +252,9 @@ imgmgr_state_confirm(void)
imgmgr_dfu_confirmed();
- return 0;
+done:
+ imgmgr_log_confirm(rc, NULL);
+ return rc;
}
int
diff --git a/mgmt/imgmgr/syscfg.yml b/mgmt/imgmgr/syscfg.yml
index 17230b7..9ec9677 100644
--- a/mgmt/imgmgr/syscfg.yml
+++ b/mgmt/imgmgr/syscfg.yml
@@ -43,3 +43,15 @@ syscfg.defs:
description: >
Sysinit stage for image management functionality.
value: 500
+
+ IMGMGR_LOG_MOD:
+ description: 'Module ID for the image manager structured log.'
+ value: 176
+ IMGMGR_LOG_LVL:
+ description: 'Minimum level for the image manager structured log.'
+ value: 15 # Log disabled by default.
+
+syscfg.logs:
+ IMGMGR_LOG:
+ module: MYNEWT_VAL(IMGMGR_LOG_MOD)
+ level: MYNEWT_VAL(IMGMGR_LOG_LVL)
diff --git a/sys/log/common/include/log_common/log_common.h b/sys/log/common/include/log_common/log_common.h
index 7c2b5de..29a45bf 100644
--- a/sys/log/common/include/log_common/log_common.h
+++ b/sys/log/common/include/log_common/log_common.h
@@ -88,6 +88,22 @@ struct log;
#define LOG_SYSLEVEL ((uint8_t)MYNEWT_VAL_LOG_LEVEL)
#endif
+/**
+ * @brief Determines if a log module will accept an entry with a given level.
+ *
+ * A log entry is only accepted if its level is less than or equal to both:
+ * o Global log level setting (LOG_LEVEL), and
+ * o The specified module log level
+ *
+ * @param mod_level The module's minimum log level.
+ * @param entry_level The level of the entry to be logged.
+ *
+ * @return true if the entry would be logged;
+ * false otherwise.
+ */
+#define LOG_MOD_LEVEL_IS_ACTIVE(mod_level, entry_level) \
+ (LOG_LEVEL <= (entry_level) && (mod_level) <= (entry_level))
+
/* Newtmgr Log opcodes */
#define LOGS_NMGR_OP_READ (0)
#define LOGS_NMGR_OP_CLEAR (1)