This is an automated email from the ASF dual-hosted git repository. vipulrahane 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 dc14e33 net/osdp Add logging prefixes new debc8b2 Merge pull request #2634 from vikrant-proxy/osdp-logs dc14e33 is described below commit dc14e33e23a9fa465a37ee3a6a88956a662da92f Author: Vikrant More <vikr...@proxy.com> AuthorDate: Sat Jun 26 12:47:02 2021 -0700 net/osdp Add logging prefixes --- net/osdp/src/osdp.c | 2 +- net/osdp/src/osdp_common.c | 10 +++--- net/osdp/src/osdp_cp.c | 84 +++++++++++++++++++++++----------------------- net/osdp/src/osdp_pd.c | 66 ++++++++++++++++++------------------ net/osdp/src/osdp_sc.c | 2 +- 5 files changed, 82 insertions(+), 82 deletions(-) diff --git a/net/osdp/src/osdp.c b/net/osdp/src/osdp.c index 05d799e..b6293fe 100644 --- a/net/osdp/src/osdp.c +++ b/net/osdp/src/osdp.c @@ -277,5 +277,5 @@ osdp_init(osdp_pd_info_t *info, uint8_t *scbk) os_callout_reset(&osdp_refresh_timer, OSDP_REFRESH_INTERVAL); - OSDP_LOG_INFO("OSDP OK\n"); + OSDP_LOG_INFO("osdp: init OK\n"); } diff --git a/net/osdp/src/osdp_common.c b/net/osdp/src/osdp_common.c index 3d749a4..b5d1b09 100644 --- a/net/osdp/src/osdp_common.c +++ b/net/osdp/src/osdp_common.c @@ -79,7 +79,7 @@ osdp_encrypt(uint8_t *key, uint8_t *iv, uint8_t *data, int len) len, /* inlen: input len */ iv, /* iv: IV start */ &s) == TC_CRYPTO_FAIL) { - OSDP_LOG_ERROR("CBC ENCRYPT - Failed"); + OSDP_LOG_ERROR("osdp: sc: CBC ENCRYPT - Failed"); } /* copy ciphertext from offset */ @@ -87,7 +87,7 @@ osdp_encrypt(uint8_t *key, uint8_t *iv, uint8_t *data, int len) } else { if (tc_aes_encrypt(data, data, &s) == TC_CRYPTO_FAIL) { - OSDP_LOG_ERROR("ECB ENCRYPT - Failed\n"); + OSDP_LOG_ERROR("osdp: sc: ECB ENCRYPT - Failed\n"); } } } @@ -116,13 +116,13 @@ osdp_decrypt(uint8_t *key, uint8_t *iv, uint8_t *data, int len) len + TC_AES_BLOCK_SIZE, /* inlen: total length of input, iv + buffer length */ scratch_buf1, /* iv: offset to IV in input buffer */ &s) == TC_CRYPTO_FAIL) { - OSDP_LOG_ERROR("CBC DECRYPT - Failed\n"); + OSDP_LOG_ERROR("osdp: sc: CBC DECRYPT - Failed\n"); } /* Copy decrypted data into output buffer */ memcpy(data, scratch_buf1, len); } else { if (tc_aes_decrypt(data, data, &s) == TC_CRYPTO_FAIL) { - OSDP_LOG_ERROR("ECB DECRYPT - Failed\n"); + OSDP_LOG_ERROR("osdp: sc: ECB DECRYPT - Failed\n"); } } } @@ -137,7 +137,7 @@ osdp_get_rand(uint8_t *buf, int len) #elif MYNEWT_VAL(TRNG) trng = (struct trng_dev *) os_dev_open("trng", OS_WAIT_FOREVER, NULL); if (trng == NULL) { - OSDP_LOG_ERROR("Could not open TRNG\n"); + OSDP_LOG_ERROR("osdp: sc: Could not open TRNG\n"); buf = NULL; } diff --git a/net/osdp/src/osdp_cp.c b/net/osdp/src/osdp_cp.c index 0d48748..52b5e02 100644 --- a/net/osdp/src/osdp_cp.c +++ b/net/osdp/src/osdp_cp.c @@ -82,7 +82,7 @@ cp_cmd_queue_init(struct osdp_pd *pd, uint16_t num) pd->cmd.pool_buf, pool_names[num]); if (rc != OS_OK) { - OSDP_LOG_ERROR("Failed to initialize command pool\n"); + OSDP_LOG_ERROR("osdp: cp: Failed to initialize command pool\n"); return rc; } @@ -101,7 +101,7 @@ cp_cmd_alloc(struct osdp_pd *pd) cmd = os_memblock_get(&pd->cmd.pool); if (cmd == NULL) { - OSDP_LOG_ERROR("Command pool allocation failed\n"); + OSDP_LOG_ERROR("osdp: cp: Command pool allocation failed\n"); return NULL; } @@ -244,7 +244,7 @@ cp_channel_release(struct osdp_pd *pd) struct osdp *ctx = TO_CTX(pd); if (ctx->cp->channel_lock[pd->offset] != pd->channel.id) { - OSDP_LOG_ERROR("Attempt to release another PD's channel lock\n"); + OSDP_LOG_ERROR("osdp: cp: Attempt to release another PD's channel lock\n"); return -1; } ctx->cp->channel_lock[pd->offset] = 0; @@ -272,7 +272,7 @@ cp_build_command(struct osdp_pd *pd, uint8_t *buf, int max_len) #define ASSERT_BUF_LEN(need) \ if (max_len < need) { \ - OSDP_LOG_ERROR("OOM at build CMD(%02x) - have:%d, need:%d\n", \ + OSDP_LOG_ERROR("osdp: cp: OOM at build CMD(%02x) - have:%d, need:%d\n", \ pd->cmd_id, max_len, need); \ return OSDP_CP_ERR_GENERIC; \ } @@ -405,7 +405,7 @@ cp_build_command(struct osdp_pd *pd, uint8_t *buf, int max_len) break; case CMD_KEYSET: if (!ISSET_FLAG(pd, PD_FLAG_SC_ACTIVE)) { - OSDP_LOG_ERROR("Can not perform a KEYSET without SC!\n"); + OSDP_LOG_ERROR("osdp: cp: Can not perform a KEYSET without SC!\n"); return -1; } cmd = (struct osdp_cmd *)pd->ephemeral_data; @@ -447,7 +447,7 @@ cp_build_command(struct osdp_pd *pd, uint8_t *buf, int max_len) ret = 0; break; default: - OSDP_LOG_ERROR("Unknown/Unsupported CMD(%02x)\n", pd->cmd_id); + OSDP_LOG_ERROR("osdp: cp: Unknown/Unsupported CMD(%02x)\n", pd->cmd_id); return OSDP_CP_ERR_GENERIC; } @@ -462,7 +462,7 @@ cp_build_command(struct osdp_pd *pd, uint8_t *buf, int max_len) } if (ret < 0) { - OSDP_LOG_ERROR("Unable to build CMD(%02x)\n", pd->cmd_id); + OSDP_LOG_ERROR("osdp: cp: Unable to build CMD(%02x)\n", pd->cmd_id); return OSDP_CP_ERR_GENERIC; } @@ -482,7 +482,7 @@ cp_decode_response(struct osdp_pd *pd, uint8_t *buf, int len) #define ASSERT_LENGTH(got, exp) \ if (got != exp) { \ - OSDP_LOG_ERROR("REPLY(%02x) length error! Got:%d, Exp:%d\n", \ + OSDP_LOG_ERROR("osdp: cp: REPLY(%02x) length error! Got:%d, Exp:%d\n", \ pd->reply_id, got, exp); \ return OSDP_CP_ERR_GENERIC; \ } @@ -494,7 +494,7 @@ cp_decode_response(struct osdp_pd *pd, uint8_t *buf, int len) break; case REPLY_NAK: ASSERT_LENGTH(len, REPLY_NAK_DATA_LEN); - OSDP_LOG_WARN("PD replied with NAK(%d) for CMD(%02x)", + OSDP_LOG_WARN("osdp: cp: PD replied with NAK(%d) for CMD(%02x)", buf[pos], pd->cmd_id); ret = OSDP_CP_ERR_NONE; break; @@ -519,7 +519,7 @@ cp_decode_response(struct osdp_pd *pd, uint8_t *buf, int len) break; case REPLY_PDCAP: if ((len % REPLY_PDCAP_ENTITY_LEN) != 0) { - OSDP_LOG_ERROR("PDCAP response length is not a multiple of 3", + OSDP_LOG_ERROR("osdp: cp: PDCAP response length is not a multiple of 3", buf[pos], pd->cmd_id); return OSDP_CP_ERR_GENERIC; } @@ -571,7 +571,7 @@ cp_decode_response(struct osdp_pd *pd, uint8_t *buf, int len) temp32 |= buf[pos++] << 8; temp32 |= buf[pos++] << 16; temp32 |= buf[pos++] << 24; - OSDP_LOG_WARN("COMSET responded with ID:%d Baud:%d\n", t1, temp32); + OSDP_LOG_WARN("osdp: cp: COMSET responded with ID:%d Baud:%d\n", t1, temp32); pd->address = t1; pd->baud_rate = temp32; ret = OSDP_CP_ERR_NONE; @@ -668,7 +668,7 @@ cp_decode_response(struct osdp_pd *pd, uint8_t *buf, int len) } osdp_compute_session_keys(TO_CTX(pd)); if (osdp_verify_pd_cryptogram(pd) != 0) { - OSDP_LOG_ERROR("Failed to verify PD cryptogram\n"); + OSDP_LOG_ERROR("osdp: cp: Failed to verify PD cryptogram\n"); return OSDP_CP_ERR_GENERIC; } ret = OSDP_CP_ERR_NONE; @@ -682,18 +682,18 @@ cp_decode_response(struct osdp_pd *pd, uint8_t *buf, int len) ret = OSDP_CP_ERR_NONE; break; default: - OSDP_LOG_DEBUG("Unexpected REPLY(%02x)\n", pd->reply_id); + OSDP_LOG_DEBUG("osdp: cp: Unexpected REPLY(%02x)\n", pd->reply_id); return OSDP_CP_ERR_GENERIC; } if (ret == OSDP_CP_ERR_GENERIC) { - OSDP_LOG_ERROR("Format error in REPLY(%02x) for CMD(%02x)", + OSDP_LOG_ERROR("osdp: cp: Format error in REPLY(%02x) for CMD(%02x)", pd->reply_id, pd->cmd_id); return OSDP_CP_ERR_GENERIC; } if (pd->cmd_id != CMD_POLL) { - OSDP_LOG_DEBUG("CMD(%02x) REPLY(%02x)\n", pd->cmd_id, pd->reply_id); + OSDP_LOG_DEBUG("osdp: cp: CMD(%02x) REPLY(%02x)\n", pd->cmd_id, pd->reply_id); } return ret; @@ -730,7 +730,7 @@ cp_send_command(struct osdp_pd *pd) ret = pd->channel.send(pd->channel.data, pd->rx_buf, len); if (ret != len) { - OSDP_LOG_ERROR("Channel send for %d bytes failed! ret: %d\n", len, ret); + OSDP_LOG_ERROR("osdp: cp: Channel send for %d bytes failed! ret: %d\n", len, ret); return OSDP_CP_ERR_GENERIC; } @@ -845,7 +845,7 @@ cp_phy_state_update(struct osdp_pd *pd) /* fall-thru */ case OSDP_CP_PHY_STATE_SEND_CMD: if ((cp_send_command(pd)) < 0) { - OSDP_LOG_ERROR("Failed to send CMD(%d)\n", pd->cmd_id); + OSDP_LOG_ERROR("osdp: cp: Failed to send CMD(%d)\n", pd->cmd_id); pd->phy_state = OSDP_CP_PHY_STATE_ERR; ret = OSDP_CP_ERR_GENERIC; break; @@ -862,7 +862,7 @@ cp_phy_state_update(struct osdp_pd *pd) break; } if (rc == OSDP_CP_ERR_RETRY_CMD) { - OSDP_LOG_INFO("PD busy; retry last command\n"); + OSDP_LOG_INFO("osdp: cp: PD busy; retry last command\n"); pd->phy_tstamp = osdp_millis_now(); pd->phy_state = OSDP_CP_PHY_STATE_WAIT; break; @@ -870,7 +870,7 @@ cp_phy_state_update(struct osdp_pd *pd) if (rc == OSDP_CP_ERR_GENERIC || osdp_millis_since(pd->phy_tstamp) > MYNEWT_VAL(OSDP_RESP_TOUT_MS)) { if (rc != OSDP_CP_ERR_GENERIC) { - OSDP_LOG_ERROR("Response timeout for CMD(%02x)", + OSDP_LOG_ERROR("osdp: cp: Response timeout for CMD(%02x)", pd->cmd_id); } pd->rx_buf_len = 0; @@ -957,7 +957,7 @@ state_update(struct osdp_pd *pd) ISSET_FLAG(pd, PD_FLAG_SC_CAPABLE) == true && ISSET_FLAG(ctx, FLAG_SC_DISABLED) == false && osdp_millis_since(pd->sc_tstamp) > OSDP_PD_SC_RETRY_MS) { - OSDP_LOG_INFO("Retry SC after retry timeout\n"); + OSDP_LOG_INFO("osdp: cp: Retry SC after retry timeout\n"); cp_set_state(pd, OSDP_CP_STATE_SC_INIT); break; } @@ -982,7 +982,7 @@ state_update(struct osdp_pd *pd) break; } if (pd->reply_id != REPLY_PDID) { - OSDP_LOG_ERROR("Unexpected REPLY(%02x) for cmd " + OSDP_LOG_ERROR("osdp: cp: Unexpected REPLY(%02x) for cmd " STR(CMD_CAP), pd->reply_id); cp_set_offline(pd); break; @@ -994,7 +994,7 @@ state_update(struct osdp_pd *pd) break; } if (pd->reply_id != REPLY_PDCAP) { - OSDP_LOG_ERROR("Unexpected REPLY(%02x) for cmd " + OSDP_LOG_ERROR("osdp: cp: Unexpected REPLY(%02x) for cmd " STR(CMD_CAP), pd->reply_id); cp_set_offline(pd); break; @@ -1007,7 +1007,7 @@ state_update(struct osdp_pd *pd) break; } if (ISSET_FLAG(pd, OSDP_FLAG_ENFORCE_SECURE)) { - OSDP_LOG_INFO("SC disabled or not capable. Set PD offline due " + OSDP_LOG_INFO("osdp: cp: SC disabled or not capable. Set PD offline due " "to ENFORCE_SECURE\n"); cp_set_offline(pd); } else { @@ -1024,13 +1024,13 @@ state_update(struct osdp_pd *pd) } if (phy_state < 0) { if (ISSET_FLAG(pd, OSDP_FLAG_ENFORCE_SECURE)) { - OSDP_LOG_INFO("SC Failed. Set PD offline due to " + OSDP_LOG_INFO("osdp: cp: SC Failed. Set PD offline due to " "ENFORCE_SECURE\n"); cp_set_offline(pd); break; } if (ISSET_FLAG(pd, PD_FLAG_SC_SCBKD_DONE)) { - OSDP_LOG_INFO("SC Failed. Online without SC\n"); + OSDP_LOG_INFO("osdp: cp: SC Failed. Online without SC\n"); pd->sc_tstamp = osdp_millis_now(); cp_set_online(pd); break; @@ -1039,16 +1039,16 @@ state_update(struct osdp_pd *pd) SET_FLAG(pd, PD_FLAG_SC_SCBKD_DONE); cp_set_state(pd, OSDP_CP_STATE_SC_INIT); pd->phy_state = 0; /* soft reset phy state */ - OSDP_LOG_WARN("SC Failed. Retry with SCBK-D\n"); + OSDP_LOG_WARN("osdp: cp: SC Failed. Retry with SCBK-D\n"); break; } if (pd->reply_id != REPLY_CCRYPT) { if (ISSET_FLAG(pd, OSDP_FLAG_ENFORCE_SECURE)) { - OSDP_LOG_ERROR("CHLNG failed. Set PD offline due to " + OSDP_LOG_ERROR("osdp: cp: CHLNG failed. Set PD offline due to " "ENFORCE_SECURE\n"); cp_set_offline(pd); } else { - OSDP_LOG_ERROR("CHLNG failed. Online without SC\n"); + OSDP_LOG_ERROR("osdp: cp: CHLNG failed. Online without SC\n"); pd->sc_tstamp = osdp_millis_now(); osdp_phy_state_reset(pd); cp_set_online(pd); @@ -1063,11 +1063,11 @@ state_update(struct osdp_pd *pd) } if (pd->reply_id != REPLY_RMAC_I) { if (ISSET_FLAG(pd, OSDP_FLAG_ENFORCE_SECURE)) { - OSDP_LOG_ERROR("SCRYPT failed. Set PD offline due to " + OSDP_LOG_ERROR("osdp: cp: SCRYPT failed. Set PD offline due to " "ENFORCE_SECURE\n"); cp_set_offline(pd); } else { - OSDP_LOG_ERROR("SCRYPT failed. Online without SC\n"); + OSDP_LOG_ERROR("osdp: cp: SCRYPT failed. Online without SC\n"); osdp_phy_state_reset(pd); pd->sc_tstamp = osdp_millis_now(); cp_set_online(pd); @@ -1075,11 +1075,11 @@ state_update(struct osdp_pd *pd) break; } if (ISSET_FLAG(pd, PD_FLAG_SC_USE_SCBKD)) { - OSDP_LOG_WARN("SC ACtive with SCBK-D. Set SCBK\n"); + OSDP_LOG_WARN("osdp: cp: SC ACtive with SCBK-D. Set SCBK\n"); cp_set_state(pd, OSDP_CP_STATE_SET_SCBK); break; } - OSDP_LOG_INFO("SC Active\n"); + OSDP_LOG_INFO("osdp: cp: SC Active\n"); pd->sc_tstamp = osdp_millis_now(); cp_set_online(pd); break; @@ -1089,17 +1089,17 @@ state_update(struct osdp_pd *pd) } if (pd->reply_id == REPLY_NAK) { if (ISSET_FLAG(pd, OSDP_FLAG_ENFORCE_SECURE)) { - OSDP_LOG_ERROR("Failed to set SCBK; " + OSDP_LOG_ERROR("osdp: cp: Failed to set SCBK; " "Set PD offline due to ENFORCE_SECURE\n"); cp_set_offline(pd); } else { - OSDP_LOG_WARN("Failed to set SCBK; " + OSDP_LOG_WARN("osdp: cp: Failed to set SCBK; " "Continue with SCBK-D\n"); cp_set_state(pd, OSDP_CP_STATE_ONLINE); } break; } - OSDP_LOG_INFO("SCBK set; restarting SC to verify new SCBK\n"); + OSDP_LOG_INFO("osdp: cp: SCBK set; restarting SC to verify new SCBK\n"); CLEAR_FLAG(pd, PD_FLAG_SC_USE_SCBKD); CLEAR_FLAG(pd, PD_FLAG_SC_ACTIVE); cp_set_state(pd, OSDP_CP_STATE_SC_INIT); @@ -1119,7 +1119,7 @@ osdp_cp_send_command_keyset(osdp_t *ctx, struct osdp_cmd_keyset *p) struct osdp_pd *pd; if (osdp_get_sc_status_mask(ctx) != PD_MASK(ctx)) { - OSDP_LOG_WARN("CMD_KEYSET can be sent only when all PDs are " + OSDP_LOG_WARN("osdp: cp: CMD_KEYSET can be sent only when all PDs are " "ONLINE and SC_ACTIVE.\n"); return 1; } @@ -1157,7 +1157,7 @@ osdp_cp_setup(struct osdp_ctx *osdp_ctx, int num_pd, osdp_pd_info_t *info, if (master_key != NULL) { memcpy(ctx->sc_master_key, master_key, 16); } else { - OSDP_LOG_WARN("Master key not available! SC Disabled.\n"); + OSDP_LOG_WARN("osdp: cp: Master key not available! SC Disabled.\n"); SET_FLAG(ctx, FLAG_SC_DISABLED); } @@ -1193,7 +1193,7 @@ osdp_cp_setup(struct osdp_ctx *osdp_ctx, int num_pd, osdp_pd_info_t *info, } memset(cp->channel_lock, 0, sizeof(int) * num_pd); SET_CURRENT_PD(ctx, 0); - OSDP_LOG_INFO("CP setup complete\n"); + OSDP_LOG_INFO("osdp: cp: CP setup complete\n"); return (osdp_t *) ctx; error: @@ -1263,11 +1263,11 @@ osdp_cp_send_command(osdp_t *ctx, int pd, struct osdp_cmd *p) int cmd_id; if (pd < 0 || pd >= NUM_PD(ctx)) { - OSDP_LOG_ERROR("Invalid PD number\n"); + OSDP_LOG_ERROR("osdp: cp: Invalid PD number\n"); return -1; } if (TO_PD(ctx, pd)->state != OSDP_CP_STATE_ONLINE) { - OSDP_LOG_WARN("PD not online\n"); + OSDP_LOG_WARN("osdp: cp: PD not online\n"); return -1; } @@ -1291,11 +1291,11 @@ osdp_cp_send_command(osdp_t *ctx, int pd, struct osdp_cmd *p) cmd_id = CMD_MFG; break; case OSDP_CMD_KEYSET: - OSDP_LOG_INFO("Master KEYSET is a global command; " + OSDP_LOG_INFO("osdp: cp: Master KEYSET is a global command; " "all connected PDs will be affected.\n"); return osdp_cp_send_command_keyset(ctx, &p->keyset); default: - OSDP_LOG_ERROR("Invalid CMD_ID:%d\n", p->id); + OSDP_LOG_ERROR("osdp: cp: Invalid CMD_ID:%d\n", p->id); return -1; } diff --git a/net/osdp/src/osdp_pd.c b/net/osdp/src/osdp_pd.c index 3c9baf0..d24d51b 100644 --- a/net/osdp/src/osdp_pd.c +++ b/net/osdp/src/osdp_pd.c @@ -74,7 +74,7 @@ pd_event_queue_init(struct osdp_pd *pd) pd->event.pool_buf, "pd_event_pool"); if (rc != OS_OK) { - OSDP_LOG_ERROR("Failed to initialize command pool\n"); + OSDP_LOG_ERROR("osdp: pd: Failed to initialize command pool\n"); return rc; } @@ -94,7 +94,7 @@ pd_event_alloc(struct osdp_pd *pd) event = os_memblock_get(&pd->event.pool); if (event == NULL) { - OSDP_LOG_ERROR("Event pool allocation failed\n"); + OSDP_LOG_ERROR("osdp: pd: Event pool allocation failed\n"); return NULL; } @@ -160,7 +160,7 @@ pd_translate_event(struct osdp_event *event, uint8_t *data) } else if (event->cardread.format == OSDP_CARD_FMT_ASCII) { reply_code = REPLY_FMT; } else { - OSDP_LOG_ERROR("Event: cardread; Error: unknown format\n"); + OSDP_LOG_ERROR("osdp: pd: Event: cardread; Error: unknown format\n"); break; } break; @@ -168,7 +168,7 @@ pd_translate_event(struct osdp_event *event, uint8_t *data) reply_code = REPLY_KEYPPAD; break; default: - OSDP_LOG_ERROR("Unknown event type %d\n", event->type); + OSDP_LOG_ERROR("osdp: pd: Unknown event type %d\n", event->type); break; } if (reply_code == 0) { @@ -249,7 +249,7 @@ pd_cmd_cap_ok(struct osdp_pd *pd, struct osdp_cmd *cmd) case CMD_OUT: cap = &pd->cap[OSDP_PD_CAP_OUTPUT_CONTROL]; if (cmd->output.output_no + 1 > cap->num_items) { - OSDP_LOG_DEBUG("CAP check: output_no(%d) > cap->num_items(%d)\n", + OSDP_LOG_DEBUG("osdp: pd: CAP check: output_no(%d) > cap->num_items(%d)\n", cmd->output.output_no + 1, cap->num_items); break; } @@ -260,7 +260,7 @@ pd_cmd_cap_ok(struct osdp_pd *pd, struct osdp_cmd *cmd) case CMD_LED: cap = &pd->cap[OSDP_PD_CAP_READER_LED_CONTROL]; if (cmd->led.led_number + 1 > cap->num_items) { - OSDP_LOG_DEBUG("CAP check: LED(%d) > cap->num_items(%d)\n", + OSDP_LOG_DEBUG("osdp: pd: CAP check: LED(%d) > cap->num_items(%d)\n", cmd->led.led_number + 1, cap->num_items); break; } @@ -317,7 +317,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) */ if (pd->cmd_id != CMD_ID && pd->cmd_id != CMD_CAP && pd->cmd_id != CMD_CHLNG && pd->cmd_id != CMD_SCRYPT) { - OSDP_LOG_ERROR("CMD(%02x) not allowed due to ENFORCE_SECURE\n", + OSDP_LOG_ERROR("osdp: pd: CMD(%02x) not allowed due to ENFORCE_SECURE\n", pd->cmd_id); pd->reply_id = REPLY_NAK; pd->ephemeral_data[0] = OSDP_PD_NAK_RECORD; @@ -328,7 +328,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) /* helper macro, can be called from switch cases below */ #define PD_CMD_CAP_CHECK(pd, cmd) \ if (!pd_cmd_cap_ok(pd, cmd)) { \ - OSDP_LOG_INFO("PD is not capable of handling CMD(%02x); " \ + OSDP_LOG_INFO("osdp: pd: PD is not capable of handling CMD(%02x); " \ "Reply with NAK_CMD_UNKNOWN\n", pd->cmd_id); \ ret = OSDP_PD_ERR_REPLY; \ break; \ @@ -336,7 +336,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) #define ASSERT_LENGTH(got, exp) \ if (got != exp) { \ - OSDP_LOG_ERROR("CMD(%02x) length error! Got:%d, Exp:%d\n", \ + OSDP_LOG_ERROR("osdp: pd: CMD(%02x) length error! Got:%d, Exp:%d\n", \ pd->cmd_id, got, exp); \ return OSDP_PD_ERR_GENERIC; \ } @@ -508,7 +508,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) (cmd.comset.baud_rate != 9600 && cmd.comset.baud_rate != 38400 && cmd.comset.baud_rate != 115200)) { - OSDP_LOG_ERROR("COMSET Failed! command discarded\n"); + OSDP_LOG_ERROR("osdp: pd: COMSET Failed! command discarded\n"); cmd.comset.address = pd->address; cmd.comset.baud_rate = pd->baud_rate; } @@ -534,7 +534,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) cmd.mfg.command = buf[pos++]; cmd.mfg.length = len - CMD_MFG_DATA_LEN; if (cmd.mfg.length > OSDP_CMD_MFG_MAX_DATALEN) { - OSDP_LOG_ERROR("cmd length error\n"); + OSDP_LOG_ERROR("osdp: pd: cmd length error\n"); break; } for (i = 0; i < cmd.mfg.length; i++) { @@ -565,12 +565,12 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) if (ISSET_FLAG(pd, PD_FLAG_SC_ACTIVE) == 0) { pd->reply_id = REPLY_NAK; pd->ephemeral_data[0] = OSDP_PD_NAK_SC_COND; - OSDP_LOG_ERROR("Keyset with SC inactive\n"); + OSDP_LOG_ERROR("osdp: pd: Keyset with SC inactive\n"); break; } /* only key_type == 1 (SCBK) and key_len == 16 is supported */ if (buf[pos] != 1 || buf[pos + 1] != 16) { - OSDP_LOG_ERROR("Keyset invalid len/type: %d/%d\n", + OSDP_LOG_ERROR("osdp: pd: Keyset invalid len/type: %d/%d\n", buf[pos], buf[pos + 1]); break; } @@ -584,7 +584,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) ret = pd->command_callback(pd->command_callback_arg, &cmd); } else { - OSDP_LOG_WARN("Keyset without command callback trigger\n"); + OSDP_LOG_WARN("osdp: pd: Keyset without command callback trigger\n"); } if (ret != 0) { pd->reply_id = REPLY_NAK; @@ -618,7 +618,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) ret = OSDP_PD_ERR_NONE; break; default: - OSDP_LOG_ERROR("Unknown command ID %02x\n", pd->cmd_id); + OSDP_LOG_ERROR("osdp: pd: Unknown command ID %02x\n", pd->cmd_id); pd->reply_id = REPLY_NAK; pd->ephemeral_data[0] = OSDP_PD_NAK_CMD_UNKNOWN; ret = OSDP_PD_ERR_NONE; @@ -626,7 +626,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) } if (ret != 0 && ret != OSDP_PD_ERR_REPLY) { - OSDP_LOG_ERROR("Invalid command structure. CMD: %02x, Len: %d ret: %d\n", + OSDP_LOG_ERROR("osdp: pd: Invalid command structure. CMD: %02x, Len: %d ret: %d\n", pd->cmd_id, len, ret); pd->reply_id = REPLY_NAK; pd->ephemeral_data[0] = OSDP_PD_NAK_CMD_LEN; @@ -634,7 +634,7 @@ pd_decode_command(struct osdp_pd *pd, uint8_t *buf, int len) } if (pd->cmd_id != CMD_POLL) { - OSDP_LOG_DEBUG("CMD: %02x REPLY: %02x\n", pd->cmd_id, pd->reply_id); + OSDP_LOG_DEBUG("osdp: pd: CMD: %02x REPLY: %02x\n", pd->cmd_id, pd->reply_id); } return ret; @@ -660,7 +660,7 @@ pd_build_reply(struct osdp_pd *pd, uint8_t *buf, int max_len) #define ASSERT_BUF_LEN(need) \ if (max_len < need) { \ - OSDP_LOG_ERROR("OOM at build REPLY(%02x) - have:%d, need:%d\n", \ + OSDP_LOG_ERROR("osdp: pd: OOM at build REPLY(%02x) - have:%d, need:%d\n", \ pd->reply_id, max_len, need); \ return OSDP_PD_ERR_GENERIC; \ } @@ -700,7 +700,7 @@ pd_build_reply(struct osdp_pd *pd, uint8_t *buf, int max_len) continue; } if (max_len < REPLY_PDCAP_ENTITY_LEN) { - OSDP_LOG_ERROR("Out of buffer space!\n"); + OSDP_LOG_ERROR("osdp: pd: Out of buffer space!\n"); break; } buf[len++] = i; @@ -779,7 +779,7 @@ pd_build_reply(struct osdp_pd *pd, uint8_t *buf, int max_len) pd->address = (int)cmd->comset.address; pd->baud_rate = (int)cmd->comset.baud_rate; - OSDP_LOG_INFO("COMSET Succeeded! New PD-Addr: %d; Baud: %d\n", + OSDP_LOG_INFO("osdp: pd: COMSET Succeeded! New PD-Addr: %d; Baud: %d\n", pd->address, pd->baud_rate); ret = OSDP_PD_ERR_NONE; break; @@ -842,13 +842,13 @@ pd_build_reply(struct osdp_pd *pd, uint8_t *buf, int max_len) SET_FLAG(pd, PD_FLAG_SC_ACTIVE); pd->sc_tstamp = osdp_millis_now(); if (ISSET_FLAG(pd, PD_FLAG_SC_USE_SCBKD)) { - OSDP_LOG_WARN("SC Active with SCBK-D\n"); + OSDP_LOG_WARN("osdp: pd: SC Active with SCBK-D\n"); } else { - OSDP_LOG_INFO("SC Active\n"); + OSDP_LOG_INFO("osdp: pd: SC Active\n"); } } else { smb[2] = 0; /* CP auth failed */ - OSDP_LOG_WARN("failed to verify CP_crypt\n"); + OSDP_LOG_WARN("osdp: pd: failed to verify CP_crypt\n"); } ret = OSDP_PD_ERR_NONE; break; @@ -861,7 +861,7 @@ pd_build_reply(struct osdp_pd *pd, uint8_t *buf, int max_len) if (ret != 0) { /* catch all errors and report it as a RECORD error to CP */ - OSDP_LOG_ERROR("Failed to build REPLY(%02x); Sending NAK instead!\n", + OSDP_LOG_ERROR("osdp: pd: Failed to build REPLY(%02x); Sending NAK instead!\n", pd->reply_id); ASSERT_BUF_LEN(REPLY_NAK_LEN); buf[0] = REPLY_NAK; @@ -909,7 +909,7 @@ pd_send_reply(struct osdp_pd *pd) ret = pd->channel.send(pd->channel.data, pd->rx_buf, len); if (ret != len) { - OSDP_LOG_ERROR("Channel send for %d bytes failed! ret: %d\n", len, ret); + OSDP_LOG_ERROR("osdp: pd: Channel send for %d bytes failed! ret: %d\n", len, ret); return OSDP_PD_ERR_GENERIC; } @@ -992,13 +992,13 @@ osdp_update(struct osdp_pd *pd) case OSDP_PD_STATE_IDLE: if (ISSET_FLAG(pd, PD_FLAG_SC_ACTIVE) && osdp_millis_since(pd->sc_tstamp) > MYNEWT_VAL(OSDP_PD_SC_TIMEOUT_MS)) { - OSDP_LOG_INFO("PD SC session timeout!\n"); + OSDP_LOG_INFO("osdp: pd: PD SC session timeout!\n"); CLEAR_FLAG(pd, PD_FLAG_SC_ACTIVE); } /* When secure mode is inactive check if CP is polling */ if (ISSET_FLAG(pd, PD_FLAG_CP_POLL_ACTIVE) && osdp_millis_since(pd->tstamp) > MYNEWT_VAL(OSDP_PD_IDLE_TIMEOUT_MS)) { - OSDP_LOG_INFO("PD CP-poll timeout!\n"); + OSDP_LOG_INFO("osdp: pd: PD CP-poll timeout!\n"); CLEAR_FLAG(pd, PD_FLAG_CP_POLL_ACTIVE); } ret = pd->channel.recv(pd->channel.data, pd->rx_buf, @@ -1017,7 +1017,7 @@ osdp_update(struct osdp_pd *pd) break; } if (ret != OSDP_PD_ERR_NONE && ret != OSDP_PD_ERR_REPLY) { - OSDP_LOG_ERROR("CMD receive error/timeout - err:%d\n", ret); + OSDP_LOG_ERROR("osdp: pd: CMD receive error/timeout - err:%d\n", ret); pd->state = OSDP_PD_STATE_ERR; break; } @@ -1109,14 +1109,14 @@ osdp_pd_setup(struct osdp_ctx *osdp_ctx, osdp_pd_info_t *info, uint8_t *scbk) if (scbk == NULL) { if (ISSET_FLAG(pd, OSDP_FLAG_ENFORCE_SECURE)) { - OSDP_LOG_ERROR("SCBK must be provided in ENFORCE_SECURE\n"); + OSDP_LOG_ERROR("osdp: pd: SCBK must be provided in ENFORCE_SECURE\n"); goto error; } if (!ISSET_FLAG(pd, OSDP_FLAG_NON_SECURE_MODE)) { - OSDP_LOG_WARN("SCBK not provided. PD is in INSTALL_MODE\n"); + OSDP_LOG_WARN("osdp: pd: SCBK not provided. PD is in INSTALL_MODE\n"); SET_FLAG(pd, OSDP_FLAG_INSTALL_MODE); } else { - OSDP_LOG_WARN("Setting up in non-secure mode\n"); + OSDP_LOG_WARN("osdp: pd: Setting up in non-secure mode\n"); /* Non secure mode */ } } else { @@ -1125,7 +1125,7 @@ osdp_pd_setup(struct osdp_ctx *osdp_ctx, osdp_pd_info_t *info, uint8_t *scbk) /* Set secure capability based on non-secure flag */ if (!ISSET_FLAG(pd, OSDP_FLAG_NON_SECURE_MODE)) { - OSDP_LOG_INFO("PD is SC capable!\n"); + OSDP_LOG_INFO("osdp: pd: PD is SC capable!\n"); SET_FLAG(pd, PD_FLAG_SC_CAPABLE); } @@ -1141,7 +1141,7 @@ osdp_pd_setup(struct osdp_ctx *osdp_ctx, osdp_pd_info_t *info, uint8_t *scbk) osdp_pd_set_command_callback(ctx, info->pd_cb, NULL); - OSDP_LOG_INFO("PD setup complete\n"); + OSDP_LOG_INFO("osdp: pd: PD setup complete\n"); return (osdp_t *) ctx; error: diff --git a/net/osdp/src/osdp_sc.c b/net/osdp/src/osdp_sc.c index e98ff17..4566df6 100644 --- a/net/osdp/src/osdp_sc.c +++ b/net/osdp/src/osdp_sc.c @@ -155,7 +155,7 @@ osdp_decrypt_data(struct osdp_pd *pd, int is_cmd, uint8_t *data, int length) uint8_t iv[16]; if (length % 16 != 0) { - OSDP_LOG_ERROR(TAG "decrypt_pkt invalid len:%d\n", length); + OSDP_LOG_ERROR("osdp: sc: decrypt_pkt invalid len:%d\n", length); return -1; }