log_msg.c 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500
  1. /*
  2. * Copyright (c) 2018 Nordic Semiconductor ASA
  3. *
  4. * SPDX-License-Identifier: Apache-2.0
  5. */
  6. #include <kernel.h>
  7. #include <logging/log.h>
  8. #include <logging/log_msg.h>
  9. #include <logging/log_ctrl.h>
  10. #include <logging/log_core.h>
  11. #include <sys/__assert.h>
  12. #include <string.h>
  13. BUILD_ASSERT((sizeof(struct log_msg_ids) == sizeof(uint16_t)),
  14. "Structure must fit in 2 bytes");
  15. BUILD_ASSERT((sizeof(struct log_msg_generic_hdr) == sizeof(uint16_t)),
  16. "Structure must fit in 2 bytes");
  17. BUILD_ASSERT((sizeof(struct log_msg_std_hdr) == sizeof(uint16_t)),
  18. "Structure must fit in 2 bytes");
  19. BUILD_ASSERT((sizeof(struct log_msg_hexdump_hdr) == sizeof(uint16_t)),
  20. "Structure must fit in 2 bytes");
  21. BUILD_ASSERT((sizeof(union log_msg_head_data) ==
  22. sizeof(struct log_msg_ext_head_data)),
  23. "Structure must be same size");
  24. #ifndef CONFIG_LOG_BUFFER_SIZE
  25. #define CONFIG_LOG_BUFFER_SIZE 0
  26. #endif
  27. /* Define needed when CONFIG_LOG_BLOCK_IN_THREAD is disabled to satisfy
  28. * compiler. */
  29. #ifndef CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS
  30. #define CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS 0
  31. #endif
  32. #define MSG_SIZE sizeof(union log_msg_chunk)
  33. #define NUM_OF_MSGS (CONFIG_LOG_BUFFER_SIZE / MSG_SIZE)
  34. struct k_mem_slab log_msg_pool;
  35. static uint8_t __noinit __aligned(sizeof(void *))
  36. log_msg_pool_buf[CONFIG_LOG_BUFFER_SIZE];
  37. void log_msg_pool_init(void)
  38. {
  39. k_mem_slab_init(&log_msg_pool, log_msg_pool_buf, MSG_SIZE, NUM_OF_MSGS);
  40. }
  41. /* Return true if interrupts were unlocked in the context of this call. */
  42. static bool is_irq_unlocked(void)
  43. {
  44. unsigned int key = arch_irq_lock();
  45. bool ret = arch_irq_unlocked(key);
  46. arch_irq_unlock(key);
  47. return ret;
  48. }
  49. /* Check if context can be blocked and pend on available memory slab. Context
  50. * can be blocked if in a thread and interrupts are not locked.
  51. */
  52. static bool block_on_alloc(void)
  53. {
  54. if (!IS_ENABLED(CONFIG_LOG_BLOCK_IN_THREAD)) {
  55. return false;
  56. }
  57. return (!k_is_in_isr() && is_irq_unlocked());
  58. }
  59. union log_msg_chunk *log_msg_chunk_alloc(void)
  60. {
  61. union log_msg_chunk *msg = NULL;
  62. int err = k_mem_slab_alloc(&log_msg_pool, (void **)&msg,
  63. block_on_alloc()
  64. ? K_MSEC(CONFIG_LOG_BLOCK_IN_THREAD_TIMEOUT_MS)
  65. : K_NO_WAIT);
  66. if (err != 0) {
  67. msg = log_msg_no_space_handle();
  68. }
  69. return msg;
  70. }
  71. void log_msg_get(struct log_msg *msg)
  72. {
  73. atomic_inc(&msg->hdr.ref_cnt);
  74. }
  75. static void cont_free(struct log_msg_cont *cont)
  76. {
  77. struct log_msg_cont *next;
  78. while (cont != NULL) {
  79. next = cont->next;
  80. k_mem_slab_free(&log_msg_pool, (void **)&cont);
  81. cont = next;
  82. }
  83. }
  84. static void msg_free(struct log_msg *msg)
  85. {
  86. uint32_t nargs = log_msg_nargs_get(msg);
  87. /* Free any transient string found in arguments. */
  88. if (log_msg_is_std(msg) && nargs) {
  89. uint32_t i;
  90. uint32_t smask = 0U;
  91. for (i = 0U; i < nargs; i++) {
  92. void *buf = (void *)log_msg_arg_get(msg, i);
  93. if (log_is_strdup(buf)) {
  94. if (smask == 0U) {
  95. /* Do string arguments scan only when
  96. * string duplication candidate detected
  97. * since it is time consuming and free
  98. * can be called from any context when
  99. * log message is being dropped.
  100. */
  101. smask = z_log_get_s_mask(
  102. log_msg_str_get(msg),
  103. nargs);
  104. if (smask == 0U) {
  105. /* if no string argument is
  106. * detected then stop searching
  107. * for candidates.
  108. */
  109. break;
  110. }
  111. }
  112. if (smask & BIT(i)) {
  113. log_free(buf);
  114. }
  115. }
  116. }
  117. } else if (IS_ENABLED(CONFIG_USERSPACE) &&
  118. (log_msg_level_get(msg) != LOG_LEVEL_INTERNAL_RAW_STRING)) {
  119. /*
  120. * When userspace support is enabled, the hex message metadata
  121. * might be located in log_strdup() memory pool.
  122. */
  123. const char *str = log_msg_str_get(msg);
  124. if (log_is_strdup(str)) {
  125. log_free((void *)(str));
  126. }
  127. } else {
  128. /* Message does not contain any arguments that might be a transient
  129. * string. No action required.
  130. */
  131. ;
  132. }
  133. if (msg->hdr.params.generic.ext == 1) {
  134. cont_free(msg->payload.ext.next);
  135. }
  136. k_mem_slab_free(&log_msg_pool, (void **)&msg);
  137. }
  138. union log_msg_chunk *log_msg_no_space_handle(void)
  139. {
  140. union log_msg_chunk *msg = NULL;
  141. bool more;
  142. int err;
  143. if (IS_ENABLED(CONFIG_LOG_MODE_OVERFLOW)) {
  144. do {
  145. more = log_process(true);
  146. z_log_dropped();
  147. err = k_mem_slab_alloc(&log_msg_pool,
  148. (void **)&msg,
  149. K_NO_WAIT);
  150. } while ((err != 0) && more);
  151. } else {
  152. z_log_dropped();
  153. }
  154. return msg;
  155. }
  156. void log_msg_put(struct log_msg *msg)
  157. {
  158. atomic_dec(&msg->hdr.ref_cnt);
  159. if (msg->hdr.ref_cnt == 0) {
  160. msg_free(msg);
  161. }
  162. }
  163. uint32_t log_msg_nargs_get(struct log_msg *msg)
  164. {
  165. return msg->hdr.params.std.nargs;
  166. }
  167. static log_arg_t cont_arg_get(struct log_msg *msg, uint32_t arg_idx)
  168. {
  169. struct log_msg_cont *cont;
  170. if (arg_idx < LOG_MSG_NARGS_HEAD_CHUNK) {
  171. return msg->payload.ext.data.args[arg_idx];
  172. }
  173. cont = msg->payload.ext.next;
  174. arg_idx -= LOG_MSG_NARGS_HEAD_CHUNK;
  175. while (arg_idx >= ARGS_CONT_MSG) {
  176. arg_idx -= ARGS_CONT_MSG;
  177. cont = cont->next;
  178. }
  179. return cont->payload.args[arg_idx];
  180. }
  181. log_arg_t log_msg_arg_get(struct log_msg *msg, uint32_t arg_idx)
  182. {
  183. log_arg_t arg;
  184. /* Return early if requested argument not present in the message. */
  185. if (arg_idx >= msg->hdr.params.std.nargs) {
  186. return 0;
  187. }
  188. if (msg->hdr.params.std.nargs <= LOG_MSG_NARGS_SINGLE_CHUNK) {
  189. arg = msg->payload.single.args[arg_idx];
  190. } else {
  191. arg = cont_arg_get(msg, arg_idx);
  192. }
  193. return arg;
  194. }
  195. const char *log_msg_str_get(struct log_msg *msg)
  196. {
  197. return msg->str;
  198. }
  199. /** @brief Allocate chunk for extended standard log message.
  200. *
  201. * @details Extended standard log message is used when number of arguments
  202. * exceeds capacity of one chunk. Extended message consists of two
  203. * chunks. Such approach is taken to optimize memory usage and
  204. * performance assuming that log messages with more arguments
  205. * (@ref LOG_MSG_NARGS_SINGLE_CHUNK) are less common.
  206. *
  207. * @return Allocated chunk of NULL.
  208. */
  209. static struct log_msg *msg_alloc(uint32_t nargs)
  210. {
  211. struct log_msg_cont *cont;
  212. struct log_msg_cont **next;
  213. struct log_msg *msg = z_log_msg_std_alloc();
  214. int n = (int)nargs;
  215. if ((msg == NULL) || nargs <= LOG_MSG_NARGS_SINGLE_CHUNK) {
  216. return msg;
  217. }
  218. msg->hdr.params.std.nargs = 0U;
  219. msg->hdr.params.generic.ext = 1;
  220. n -= LOG_MSG_NARGS_HEAD_CHUNK;
  221. next = &msg->payload.ext.next;
  222. *next = NULL;
  223. while (n > 0) {
  224. cont = (struct log_msg_cont *)log_msg_chunk_alloc();
  225. if (cont == NULL) {
  226. msg_free(msg);
  227. return NULL;
  228. }
  229. *next = cont;
  230. cont->next = NULL;
  231. next = &cont->next;
  232. n -= ARGS_CONT_MSG;
  233. }
  234. return msg;
  235. }
  236. static void copy_args_to_msg(struct log_msg *msg, log_arg_t *args, uint32_t nargs)
  237. {
  238. struct log_msg_cont *cont = msg->payload.ext.next;
  239. if (nargs > LOG_MSG_NARGS_SINGLE_CHUNK) {
  240. (void)memcpy(msg->payload.ext.data.args, args,
  241. LOG_MSG_NARGS_HEAD_CHUNK * sizeof(log_arg_t));
  242. nargs -= LOG_MSG_NARGS_HEAD_CHUNK;
  243. args += LOG_MSG_NARGS_HEAD_CHUNK;
  244. } else {
  245. (void)memcpy(msg->payload.single.args, args,
  246. nargs * sizeof(log_arg_t));
  247. nargs = 0U;
  248. }
  249. while (nargs != 0U) {
  250. uint32_t cpy_args = MIN(nargs, ARGS_CONT_MSG);
  251. (void)memcpy(cont->payload.args, args,
  252. cpy_args * sizeof(log_arg_t));
  253. nargs -= cpy_args;
  254. args += cpy_args;
  255. cont = cont->next;
  256. }
  257. }
  258. struct log_msg *log_msg_create_n(const char *str, log_arg_t *args, uint32_t nargs)
  259. {
  260. __ASSERT_NO_MSG(nargs < LOG_MAX_NARGS);
  261. struct log_msg *msg = NULL;
  262. msg = msg_alloc(nargs);
  263. if (msg != NULL) {
  264. msg->str = str;
  265. msg->hdr.params.std.nargs = nargs;
  266. copy_args_to_msg(msg, args, nargs);
  267. }
  268. return msg;
  269. }
  270. struct log_msg *log_msg_hexdump_create(const char *str,
  271. const uint8_t *data,
  272. uint32_t length)
  273. {
  274. struct log_msg_cont **prev_cont;
  275. struct log_msg_cont *cont;
  276. struct log_msg *msg;
  277. uint32_t chunk_length;
  278. /* Saturate length. */
  279. length = (length > LOG_MSG_HEXDUMP_MAX_LENGTH) ?
  280. LOG_MSG_HEXDUMP_MAX_LENGTH : length;
  281. msg = (struct log_msg *)log_msg_chunk_alloc();
  282. if (msg == NULL) {
  283. return NULL;
  284. }
  285. /* all fields reset to 0, reference counter to 1 */
  286. msg->hdr.ref_cnt = 1;
  287. msg->hdr.params.hexdump.type = LOG_MSG_TYPE_HEXDUMP;
  288. msg->hdr.params.hexdump.length = length;
  289. msg->str = str;
  290. if (length > LOG_MSG_HEXDUMP_BYTES_SINGLE_CHUNK) {
  291. (void)memcpy(msg->payload.ext.data.bytes,
  292. data,
  293. LOG_MSG_HEXDUMP_BYTES_HEAD_CHUNK);
  294. msg->payload.ext.next = NULL;
  295. msg->hdr.params.generic.ext = 1;
  296. data += LOG_MSG_HEXDUMP_BYTES_HEAD_CHUNK;
  297. length -= LOG_MSG_HEXDUMP_BYTES_HEAD_CHUNK;
  298. } else {
  299. (void)memcpy(msg->payload.single.bytes, data, length);
  300. msg->hdr.params.generic.ext = 0;
  301. length = 0U;
  302. }
  303. prev_cont = &msg->payload.ext.next;
  304. while (length > 0) {
  305. cont = (struct log_msg_cont *)log_msg_chunk_alloc();
  306. if (cont == NULL) {
  307. msg_free(msg);
  308. return NULL;
  309. }
  310. *prev_cont = cont;
  311. cont->next = NULL;
  312. prev_cont = &cont->next;
  313. chunk_length = (length > HEXDUMP_BYTES_CONT_MSG) ?
  314. HEXDUMP_BYTES_CONT_MSG : length;
  315. (void)memcpy(cont->payload.bytes, data, chunk_length);
  316. data += chunk_length;
  317. length -= chunk_length;
  318. }
  319. return msg;
  320. }
  321. static void log_msg_hexdump_data_op(struct log_msg *msg,
  322. uint8_t *data,
  323. size_t *length,
  324. size_t offset,
  325. bool put_op)
  326. {
  327. uint32_t available_len = msg->hdr.params.hexdump.length;
  328. struct log_msg_cont *cont = NULL;
  329. uint8_t *head_data;
  330. uint32_t chunk_len;
  331. uint32_t req_len;
  332. uint32_t cpy_len;
  333. if (offset >= available_len) {
  334. *length = 0;
  335. return;
  336. }
  337. if ((offset + *length) > available_len) {
  338. *length = available_len - offset;
  339. }
  340. req_len = *length;
  341. if (available_len > LOG_MSG_HEXDUMP_BYTES_SINGLE_CHUNK) {
  342. chunk_len = LOG_MSG_HEXDUMP_BYTES_HEAD_CHUNK;
  343. head_data = msg->payload.ext.data.bytes;
  344. cont = msg->payload.ext.next;
  345. } else {
  346. head_data = msg->payload.single.bytes;
  347. chunk_len = available_len;
  348. }
  349. if (offset < chunk_len) {
  350. cpy_len = req_len > chunk_len ? chunk_len : req_len;
  351. if (put_op) {
  352. (void)memcpy(&head_data[offset], data, cpy_len);
  353. } else {
  354. (void)memcpy(data, &head_data[offset], cpy_len);
  355. }
  356. req_len -= cpy_len;
  357. data += cpy_len;
  358. } else {
  359. offset -= chunk_len;
  360. chunk_len = HEXDUMP_BYTES_CONT_MSG;
  361. if (cont == NULL) {
  362. cont = msg->payload.ext.next;
  363. }
  364. while (offset >= chunk_len) {
  365. cont = cont->next;
  366. offset -= chunk_len;
  367. }
  368. }
  369. while ((req_len > 0) && (cont != NULL)) {
  370. chunk_len = HEXDUMP_BYTES_CONT_MSG - offset;
  371. cpy_len = req_len > chunk_len ? chunk_len : req_len;
  372. if (put_op) {
  373. (void)memcpy(&cont->payload.bytes[offset],
  374. data, cpy_len);
  375. } else {
  376. (void)memcpy(data, &cont->payload.bytes[offset],
  377. cpy_len);
  378. }
  379. offset = 0;
  380. cont = cont->next;
  381. req_len -= cpy_len;
  382. data += cpy_len;
  383. }
  384. }
  385. void log_msg_hexdump_data_put(struct log_msg *msg,
  386. uint8_t *data,
  387. size_t *length,
  388. size_t offset)
  389. {
  390. log_msg_hexdump_data_op(msg, data, length, offset, true);
  391. }
  392. void log_msg_hexdump_data_get(struct log_msg *msg,
  393. uint8_t *data,
  394. size_t *length,
  395. size_t offset)
  396. {
  397. log_msg_hexdump_data_op(msg, data, length, offset, false);
  398. }
  399. uint32_t log_msg_mem_get_free(void)
  400. {
  401. return k_mem_slab_num_free_get(&log_msg_pool);
  402. }
  403. uint32_t log_msg_mem_get_used(void)
  404. {
  405. return k_mem_slab_num_used_get(&log_msg_pool);
  406. }
  407. uint32_t log_msg_mem_get_max_used(void)
  408. {
  409. return k_mem_slab_max_used_get(&log_msg_pool);
  410. }