You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.
 
 
 
 
 
 

453 lines
11 KiB

  1. /***************************************************************************
  2. * Copyright (C) 2005 by Dominic Rath *
  3. * Dominic.Rath@gmx.de *
  4. * *
  5. * Copyright (C) 2007,2008 √ėyvind Harboe *
  6. * oyvind.harboe@zylin.com *
  7. * *
  8. * Copyright (C) 2008 by Spencer Oliver *
  9. * spen@spen-soft.co.uk *
  10. * *
  11. * This program is free software; you can redistribute it and/or modify *
  12. * it under the terms of the GNU General Public License as published by *
  13. * the Free Software Foundation; either version 2 of the License, or *
  14. * (at your option) any later version. *
  15. * *
  16. * This program is distributed in the hope that it will be useful, *
  17. * but WITHOUT ANY WARRANTY; without even the implied warranty of *
  18. * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the *
  19. * GNU General Public License for more details. *
  20. * *
  21. * You should have received a copy of the GNU General Public License *
  22. * along with this program; if not, write to the *
  23. * Free Software Foundation, Inc., *
  24. * 59 Temple Place - Suite 330, Boston, MA 02111-1307, USA. *
  25. ***************************************************************************/
  26. #ifdef HAVE_CONFIG_H
  27. #include "config.h"
  28. #endif
  29. #include "log.h"
  30. #include "time_support.h"
  31. // @todo the inclusion of server.h here is a layering violation
  32. #include "server.h"
  33. #include <stdarg.h>
  34. #ifdef _DEBUG_FREE_SPACE_
  35. #ifdef HAVE_MALLOC_H
  36. #include <malloc.h>
  37. #else
  38. #error "malloc.h is required to use --enable-malloc-logging"
  39. #endif
  40. #endif
  41. int debug_level = -1;
  42. static FILE* log_output;
  43. static log_callback_t *log_callbacks = NULL;
  44. static long long last_time;
  45. static long long current_time;
  46. static long long start;
  47. static char *log_strings[5] =
  48. {
  49. "User : ",
  50. "Error: ",
  51. "Warn : ", /* want a space after each colon, all same width, colons aligned */
  52. "Info : ",
  53. "Debug: "
  54. };
  55. static int count = 0;
  56. /* The log_puts() serves to somewhat different goals:
  57. *
  58. * - logging
  59. * - feeding low-level info to the user in GDB or Telnet
  60. *
  61. * The latter dictates that strings without newline are not logged, lest there
  62. * will be *MANY log lines when sending one char at the time(e.g.
  63. * target_request.c).
  64. *
  65. */
  66. static void log_puts(enum log_levels level, const char *file, int line, const char *function, const char *string)
  67. {
  68. char *f;
  69. if (level == LOG_LVL_OUTPUT)
  70. {
  71. /* do not prepend any headers, just print out what we were given and return */
  72. fputs(string, log_output);
  73. fflush(log_output);
  74. return;
  75. }
  76. f = strrchr(file, '/');
  77. if (f != NULL)
  78. file = f + 1;
  79. if (strchr(string, '\n')!=NULL)
  80. {
  81. if (debug_level >= LOG_LVL_DEBUG)
  82. {
  83. /* print with count and time information */
  84. int t=(int)(timeval_ms()-start);
  85. #ifdef _DEBUG_FREE_SPACE_
  86. struct mallinfo info;
  87. info = mallinfo();
  88. #endif
  89. fprintf(log_output, "%s%d %d %s:%d %s()"
  90. #ifdef _DEBUG_FREE_SPACE_
  91. " %d"
  92. #endif
  93. ": %s", log_strings[level+1], count, t, file, line, function,
  94. #ifdef _DEBUG_FREE_SPACE_
  95. info.fordblks,
  96. #endif
  97. string);
  98. }
  99. else if (server_use_pipes == 0)
  100. {
  101. /* if we are using gdb through pipes then we do not want any output
  102. * to the pipe otherwise we get repeated strings */
  103. if (strcmp(string, "\n") != 0)
  104. {
  105. /* print human readable output - but skip empty lines */
  106. fprintf(log_output, "%s%s",
  107. (level > LOG_LVL_USER)?log_strings[level+1]:"", string);
  108. }
  109. }
  110. } else
  111. {
  112. /* only entire lines are logged. Otherwise it's
  113. * single chars intended for the log callbacks. */
  114. }
  115. fflush(log_output);
  116. /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
  117. if (level <= LOG_LVL_INFO)
  118. {
  119. log_callback_t *cb, *next;
  120. cb = log_callbacks;
  121. /* DANGER!!!! the log callback can remove itself!!!! */
  122. while (cb)
  123. {
  124. next=cb->next;
  125. cb->fn(cb->priv, file, line, function, string);
  126. cb=next;
  127. }
  128. }
  129. }
  130. void log_printf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
  131. {
  132. char *string;
  133. va_list ap;
  134. count++;
  135. if (level > debug_level)
  136. return;
  137. va_start(ap, format);
  138. string = alloc_vprintf(format, ap);
  139. if (string != NULL)
  140. {
  141. log_puts(level, file, line, function, string);
  142. free(string);
  143. }
  144. va_end(ap);
  145. }
  146. void log_printf_lf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
  147. {
  148. char *string;
  149. va_list ap;
  150. count++;
  151. if (level > debug_level)
  152. return;
  153. va_start(ap, format);
  154. string = alloc_vprintf(format, ap);
  155. if (string != NULL)
  156. {
  157. strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */
  158. log_puts(level, file, line, function, string);
  159. free(string);
  160. }
  161. va_end(ap);
  162. }
  163. /* change the current debug level on the fly
  164. * 0: only ERRORS
  165. * 1: + WARNINGS
  166. * 2: + INFORMATIONAL MSGS
  167. * 3: + DEBUG MSGS
  168. */
  169. int handle_debug_level_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
  170. {
  171. if (argc == 1)
  172. {
  173. unsigned new_level;
  174. int retval = parse_uint(args[0], &new_level);
  175. if (ERROR_OK != retval)
  176. return retval;
  177. debug_level = MIN(new_level, LOG_LVL_DEBUG);
  178. }
  179. else if (argc > 1)
  180. return ERROR_COMMAND_SYNTAX_ERROR;
  181. if (debug_level >= LOG_LVL_DEBUG && server_use_pipes == 1)
  182. {
  183. /* if we are enabling debug info then we need to write to a log file
  184. * otherwise the pipe will get full and cause issues with gdb */
  185. FILE* file = fopen("openocd.log", "w");
  186. if (file)
  187. {
  188. log_output = file;
  189. LOG_WARNING("enabling log output as we are using pipes");
  190. }
  191. }
  192. command_print(cmd_ctx, "debug_level: %i", debug_level);
  193. return ERROR_OK;
  194. }
  195. int handle_log_output_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
  196. {
  197. if (argc == 1)
  198. {
  199. FILE* file = fopen(args[0], "w");
  200. if (file)
  201. {
  202. log_output = file;
  203. }
  204. }
  205. return ERROR_OK;
  206. }
  207. int log_register_commands(struct command_context_s *cmd_ctx)
  208. {
  209. start = timeval_ms();
  210. register_command(cmd_ctx, NULL, "log_output", handle_log_output_command,
  211. COMMAND_ANY, "redirect logging to <file> (default: stderr)");
  212. register_command(cmd_ctx, NULL, "debug_level", handle_debug_level_command,
  213. COMMAND_ANY, "adjust debug level <0-3>");
  214. return ERROR_OK;
  215. }
  216. int log_init(struct command_context_s *cmd_ctx)
  217. {
  218. /* set defaults for daemon configuration, if not set by cmdline or cfgfile */
  219. if (debug_level == -1)
  220. debug_level = LOG_LVL_INFO;
  221. if (log_output == NULL)
  222. {
  223. log_output = stderr;
  224. }
  225. start=last_time=timeval_ms();
  226. return ERROR_OK;
  227. }
  228. int set_log_output(struct command_context_s *cmd_ctx, FILE *output)
  229. {
  230. log_output = output;
  231. return ERROR_OK;
  232. }
  233. /* add/remove log callback handler */
  234. int log_add_callback(log_callback_fn fn, void *priv)
  235. {
  236. log_callback_t *cb;
  237. /* prevent the same callback to be registered more than once, just for sure */
  238. for (cb = log_callbacks; cb; cb = cb->next)
  239. {
  240. if (cb->fn == fn && cb->priv == priv)
  241. return ERROR_INVALID_ARGUMENTS;
  242. }
  243. /* alloc memory, it is safe just to return in case of an error, no need for the caller to check this */
  244. if ((cb = malloc(sizeof(log_callback_t))) == NULL)
  245. return ERROR_BUF_TOO_SMALL;
  246. /* add item to the beginning of the linked list */
  247. cb->fn = fn;
  248. cb->priv = priv;
  249. cb->next = log_callbacks;
  250. log_callbacks = cb;
  251. return ERROR_OK;
  252. }
  253. int log_remove_callback(log_callback_fn fn, void *priv)
  254. {
  255. log_callback_t *cb, **p;
  256. for (p = &log_callbacks; (cb = *p); p = &(*p)->next)
  257. {
  258. if (cb->fn == fn && cb->priv == priv)
  259. {
  260. *p = cb->next;
  261. free(cb);
  262. return ERROR_OK;
  263. }
  264. }
  265. /* no such item */
  266. return ERROR_INVALID_ARGUMENTS;
  267. }
  268. /* return allocated string w/printf() result */
  269. char *alloc_vprintf(const char *fmt, va_list ap)
  270. {
  271. /* no buffer at the beginning, force realloc to do the job */
  272. char *string = NULL;
  273. /* start with buffer size suitable for typical messages */
  274. int size = 128;
  275. for (;;)
  276. {
  277. char *t = string;
  278. va_list ap_copy;
  279. int ret;
  280. string = realloc(string, size);
  281. if (string == NULL)
  282. {
  283. if (t != NULL)
  284. free(t);
  285. return NULL;
  286. }
  287. va_copy(ap_copy, ap);
  288. ret = vsnprintf(string, size, fmt, ap_copy);
  289. /* NB! The result of the vsnprintf() might be an *EMPTY* string! */
  290. if ((ret >= 0) && ((ret + 1) < size))
  291. break;
  292. /* there was just enough or not enough space, allocate more in the next round */
  293. size *= 2; /* double the buffer size */
  294. }
  295. /* the returned buffer is by principle guaranteed to be at least one character longer */
  296. return string;
  297. }
  298. char *alloc_printf(const char *format, ...)
  299. {
  300. char *string;
  301. va_list ap;
  302. va_start(ap, format);
  303. string = alloc_vprintf(format, ap);
  304. va_end(ap);
  305. return string;
  306. }
  307. /* Code must return to the server loop before 1000ms has returned or invoke
  308. * this function.
  309. *
  310. * The GDB connection will time out if it spends >2000ms and you'll get nasty
  311. * error messages from GDB:
  312. *
  313. * Ignoring packet error, continuing...
  314. * Reply contains invalid hex digit 116
  315. *
  316. * While it is possible use "set remotetimeout" to more than the default 2000ms
  317. * in GDB, OpenOCD guarantees that it sends keep-alive packages on the
  318. * GDB protocol and it is a bug in OpenOCD not to either return to the server
  319. * loop or invoke keep_alive() every 1000ms.
  320. *
  321. * This function will send a keep alive packet if >500ms has passed since last time
  322. * it was invoked.
  323. *
  324. * Note that this function can be invoked often, so it needs to be relatively
  325. * fast when invoked more often than every 500ms.
  326. *
  327. */
  328. void keep_alive()
  329. {
  330. current_time=timeval_ms();
  331. if (current_time-last_time>1000)
  332. {
  333. extern int gdb_actual_connections;
  334. if (gdb_actual_connections)
  335. LOG_WARNING("keep_alive() was not invoked in the "
  336. "1000ms timelimit. GDB alive packet not "
  337. "sent! (%lld). Workaround: increase "
  338. "\"set remotetimeout\" in GDB",
  339. current_time-last_time);
  340. else
  341. LOG_DEBUG("keep_alive() was not invoked in the "
  342. "1000ms timelimit (%lld). This may cause "
  343. "trouble with GDB connections.",
  344. current_time-last_time);
  345. }
  346. if (current_time-last_time>500)
  347. {
  348. /* this will keep the GDB connection alive */
  349. LOG_USER_N("%s", "");
  350. /* DANGER!!!! do not add code to invoke e.g. target event processing,
  351. * jim timer processing, etc. it can cause infinite recursion +
  352. * jim event callbacks need to happen at a well defined time,
  353. * not anywhere keep_alive() is invoked.
  354. *
  355. * These functions should be invoked at a well defined spot in server.c
  356. */
  357. last_time=current_time;
  358. }
  359. }
  360. /* reset keep alive timer without sending message */
  361. void kept_alive()
  362. {
  363. current_time=timeval_ms();
  364. last_time=current_time;
  365. }
  366. /* if we sleep for extended periods of time, we must invoke keep_alive() intermittantly */
  367. void alive_sleep(int ms)
  368. {
  369. int i;
  370. int napTime=10;
  371. for (i=0; i<ms; i+=napTime)
  372. {
  373. int sleep_a_bit=ms-i;
  374. if (sleep_a_bit>napTime)
  375. {
  376. sleep_a_bit=napTime;
  377. }
  378. usleep(sleep_a_bit*1000);
  379. keep_alive();
  380. }
  381. }
  382. void busy_sleep(int ms)
  383. {
  384. long long then;
  385. then=timeval_ms();
  386. while ((timeval_ms()-then)<ms)
  387. {
  388. /* busy wait */
  389. }
  390. }