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.
 
 
 
 
 
 

487 lines
12 KiB

  1. /***************************************************************************
  2. * Copyright (C) 2005 by Dominic Rath *
  3. * Dominic.Rath@gmx.de *
  4. * *
  5. * Copyright (C) 2007-2010 Ø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 "time_support.h"
  30. // @todo the inclusion of server.h here is a layering violation
  31. #include <server/server.h>
  32. #include <stdarg.h>
  33. #ifdef _DEBUG_FREE_SPACE_
  34. #ifdef HAVE_MALLOC_H
  35. #include <malloc.h>
  36. #else
  37. #error "malloc.h is required to use --enable-malloc-logging"
  38. #endif
  39. #endif
  40. int debug_level = -1;
  41. static FILE* log_output;
  42. static struct log_callback *log_callbacks = NULL;
  43. static long long last_time;
  44. static long long current_time;
  45. static long long start;
  46. static char *log_strings[5] =
  47. {
  48. "User : ",
  49. "Error: ",
  50. "Warn : ", /* want a space after each colon, all same width, colons aligned */
  51. "Info : ",
  52. "Debug: "
  53. };
  54. static int count = 0;
  55. static struct store_log_forward * log_head = NULL;
  56. static int log_forward_count = 0;
  57. struct store_log_forward
  58. {
  59. struct store_log_forward * next;
  60. const char * file;
  61. int line;
  62. const char * function;
  63. const char * string;
  64. };
  65. /* either forward the log to the listeners or store it for possible forwarding later */
  66. static void log_forward(const char *file, unsigned line, const char *function, const char *string)
  67. {
  68. if (log_forward_count==0)
  69. {
  70. struct log_callback *cb, *next;
  71. cb = log_callbacks;
  72. /* DANGER!!!! the log callback can remove itself!!!! */
  73. while (cb)
  74. {
  75. next = cb->next;
  76. cb->fn(cb->priv, file, line, function, string);
  77. cb = next;
  78. }
  79. } else
  80. {
  81. struct store_log_forward *log = malloc(sizeof (struct store_log_forward));
  82. log->file = strdup(file);
  83. log->line = line;
  84. log->function = strdup(function);
  85. log->string = strdup(string);
  86. log->next = NULL;
  87. if (log_head==NULL)
  88. log_head = log;
  89. else
  90. {
  91. /* append to tail */
  92. struct store_log_forward * t;
  93. t = log_head;
  94. while (t->next!=NULL)
  95. {
  96. t = t->next;
  97. }
  98. t->next = log;
  99. }
  100. }
  101. }
  102. /* The log_puts() serves to somewhat different goals:
  103. *
  104. * - logging
  105. * - feeding low-level info to the user in GDB or Telnet
  106. *
  107. * The latter dictates that strings without newline are not logged, lest there
  108. * will be *MANY log lines when sending one char at the time(e.g.
  109. * target_request.c).
  110. *
  111. */
  112. static void log_puts(enum log_levels level, const char *file, int line, const char *function, const char *string)
  113. {
  114. char *f;
  115. if (level == LOG_LVL_OUTPUT)
  116. {
  117. /* do not prepend any headers, just print out what we were given and return */
  118. fputs(string, log_output);
  119. fflush(log_output);
  120. return;
  121. }
  122. f = strrchr(file, '/');
  123. if (f != NULL)
  124. file = f + 1;
  125. if (strlen(string) > 0)
  126. {
  127. if (debug_level >= LOG_LVL_DEBUG)
  128. {
  129. /* print with count and time information */
  130. int t = (int)(timeval_ms()-start);
  131. #ifdef _DEBUG_FREE_SPACE_
  132. struct mallinfo info;
  133. info = mallinfo();
  134. #endif
  135. fprintf(log_output, "%s%d %d %s:%d %s()"
  136. #ifdef _DEBUG_FREE_SPACE_
  137. " %d"
  138. #endif
  139. ": %s", log_strings[level + 1], count, t, file, line, function,
  140. #ifdef _DEBUG_FREE_SPACE_
  141. info.fordblks,
  142. #endif
  143. string);
  144. }
  145. else
  146. {
  147. /* if we are using gdb through pipes then we do not want any output
  148. * to the pipe otherwise we get repeated strings */
  149. fprintf(log_output, "%s%s",
  150. (level > LOG_LVL_USER)?log_strings[level + 1]:"", string);
  151. }
  152. } else
  153. {
  154. /* Empty strings are sent to log callbacks to keep e.g. gdbserver alive, here we do nothing. */
  155. }
  156. fflush(log_output);
  157. /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
  158. if (level <= LOG_LVL_INFO)
  159. {
  160. log_forward(file, line, function, string);
  161. }
  162. }
  163. void log_printf(enum log_levels level, const char *file, unsigned line, const char *function, const char *format, ...)
  164. {
  165. char *string;
  166. va_list ap;
  167. count++;
  168. if (level > debug_level)
  169. return;
  170. va_start(ap, format);
  171. string = alloc_vprintf(format, ap);
  172. if (string != NULL)
  173. {
  174. log_puts(level, file, line, function, string);
  175. free(string);
  176. }
  177. va_end(ap);
  178. }
  179. void log_printf_lf(enum log_levels level, const char *file, unsigned line, const char *function, const char *format, ...)
  180. {
  181. char *string;
  182. va_list ap;
  183. count++;
  184. if (level > debug_level)
  185. return;
  186. va_start(ap, format);
  187. string = alloc_vprintf(format, ap);
  188. if (string != NULL)
  189. {
  190. strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */
  191. log_puts(level, file, line, function, string);
  192. free(string);
  193. }
  194. va_end(ap);
  195. }
  196. /* change the current debug level on the fly
  197. * 0: only ERRORS
  198. * 1: + WARNINGS
  199. * 2: + INFORMATIONAL MSGS
  200. * 3: + DEBUG MSGS
  201. */
  202. COMMAND_HANDLER(handle_debug_level_command)
  203. {
  204. if (CMD_ARGC == 1)
  205. {
  206. unsigned new_level;
  207. COMMAND_PARSE_NUMBER(uint, CMD_ARGV[0], new_level);
  208. debug_level = MIN(new_level, LOG_LVL_DEBUG);
  209. }
  210. else if (CMD_ARGC > 1)
  211. return ERROR_COMMAND_SYNTAX_ERROR;
  212. command_print(CMD_CTX, "debug_level: %i", debug_level);
  213. return ERROR_OK;
  214. }
  215. COMMAND_HANDLER(handle_log_output_command)
  216. {
  217. if (CMD_ARGC == 1)
  218. {
  219. FILE* file = fopen(CMD_ARGV[0], "w");
  220. if (file)
  221. {
  222. log_output = file;
  223. }
  224. }
  225. return ERROR_OK;
  226. }
  227. static struct command_registration log_command_handlers[] = {
  228. {
  229. .name = "log_output",
  230. .handler = handle_log_output_command,
  231. .mode = COMMAND_ANY,
  232. .help = "redirect logging to a file (default: stderr)",
  233. .usage = "file_name",
  234. },
  235. {
  236. .name = "debug_level",
  237. .handler = handle_debug_level_command,
  238. .mode = COMMAND_ANY,
  239. .help = "Sets the verbosity level of debugging output. "
  240. "0 shows errors only; 1 adds warnings; "
  241. "2 (default) adds other info; 3 adds debugging.",
  242. .usage = "number",
  243. },
  244. COMMAND_REGISTRATION_DONE
  245. };
  246. int log_register_commands(struct command_context *cmd_ctx)
  247. {
  248. return register_commands(cmd_ctx, NULL, log_command_handlers);
  249. }
  250. void log_init(void)
  251. {
  252. /* set defaults for daemon configuration,
  253. * if not set by cmdline or cfgfile */
  254. if (debug_level == -1)
  255. debug_level = LOG_LVL_INFO;
  256. char *debug_env = getenv("OPENOCD_DEBUG_LEVEL");
  257. if (NULL != debug_env)
  258. {
  259. int value;
  260. int retval = parse_int(debug_env, &value);
  261. if (ERROR_OK == retval &&
  262. debug_level >= LOG_LVL_SILENT &&
  263. debug_level <= LOG_LVL_DEBUG)
  264. {
  265. debug_level = value;
  266. }
  267. }
  268. if (log_output == NULL)
  269. log_output = stderr;
  270. start = last_time = timeval_ms();
  271. }
  272. int set_log_output(struct command_context *cmd_ctx, FILE *output)
  273. {
  274. log_output = output;
  275. return ERROR_OK;
  276. }
  277. /* add/remove log callback handler */
  278. int log_add_callback(log_callback_fn fn, void *priv)
  279. {
  280. struct log_callback *cb;
  281. /* prevent the same callback to be registered more than once, just for sure */
  282. for (cb = log_callbacks; cb; cb = cb->next)
  283. {
  284. if (cb->fn == fn && cb->priv == priv)
  285. return ERROR_INVALID_ARGUMENTS;
  286. }
  287. /* alloc memory, it is safe just to return in case of an error, no need for the caller to check this */
  288. if ((cb = malloc(sizeof(struct log_callback))) == NULL)
  289. return ERROR_BUF_TOO_SMALL;
  290. /* add item to the beginning of the linked list */
  291. cb->fn = fn;
  292. cb->priv = priv;
  293. cb->next = log_callbacks;
  294. log_callbacks = cb;
  295. return ERROR_OK;
  296. }
  297. int log_remove_callback(log_callback_fn fn, void *priv)
  298. {
  299. struct log_callback *cb, **p;
  300. for (p = &log_callbacks; (cb = *p); p = &(*p)->next)
  301. {
  302. if (cb->fn == fn && cb->priv == priv)
  303. {
  304. *p = cb->next;
  305. free(cb);
  306. return ERROR_OK;
  307. }
  308. }
  309. /* no such item */
  310. return ERROR_INVALID_ARGUMENTS;
  311. }
  312. /* return allocated string w/printf() result */
  313. char *alloc_vprintf(const char *fmt, va_list ap)
  314. {
  315. va_list ap_copy;
  316. int len;
  317. char *string;
  318. /* determine the length of the buffer needed */
  319. va_copy(ap_copy, ap);
  320. len = vsnprintf(NULL, 0, fmt, ap_copy);
  321. va_end(ap_copy);
  322. /* allocate and make room for terminating zero. */
  323. /* FIXME: The old version always allocated at least one byte extra and
  324. * other code depend on that. They should be probably be fixed, but for
  325. * now reserve the extra byte. */
  326. string = malloc(len + 2);
  327. if (string == NULL)
  328. return NULL;
  329. /* do the real work */
  330. vsnprintf(string, len + 1, fmt, ap);
  331. return string;
  332. }
  333. char *alloc_printf(const char *format, ...)
  334. {
  335. char *string;
  336. va_list ap;
  337. va_start(ap, format);
  338. string = alloc_vprintf(format, ap);
  339. va_end(ap);
  340. return string;
  341. }
  342. /* Code must return to the server loop before 1000ms has returned or invoke
  343. * this function.
  344. *
  345. * The GDB connection will time out if it spends >2000ms and you'll get nasty
  346. * error messages from GDB:
  347. *
  348. * Ignoring packet error, continuing...
  349. * Reply contains invalid hex digit 116
  350. *
  351. * While it is possible use "set remotetimeout" to more than the default 2000ms
  352. * in GDB, OpenOCD guarantees that it sends keep-alive packages on the
  353. * GDB protocol and it is a bug in OpenOCD not to either return to the server
  354. * loop or invoke keep_alive() every 1000ms.
  355. *
  356. * This function will send a keep alive packet if >500ms has passed since last time
  357. * it was invoked.
  358. *
  359. * Note that this function can be invoked often, so it needs to be relatively
  360. * fast when invoked more often than every 500ms.
  361. *
  362. */
  363. void keep_alive()
  364. {
  365. current_time = timeval_ms();
  366. if (current_time-last_time > 1000)
  367. {
  368. extern int gdb_actual_connections;
  369. if (gdb_actual_connections)
  370. LOG_WARNING("keep_alive() was not invoked in the "
  371. "1000ms timelimit. GDB alive packet not "
  372. "sent! (%lld). Workaround: increase "
  373. "\"set remotetimeout\" in GDB",
  374. current_time-last_time);
  375. else
  376. LOG_DEBUG("keep_alive() was not invoked in the "
  377. "1000ms timelimit (%lld). This may cause "
  378. "trouble with GDB connections.",
  379. current_time-last_time);
  380. }
  381. if (current_time-last_time > 500)
  382. {
  383. /* this will keep the GDB connection alive */
  384. LOG_USER_N("%s", "");
  385. /* DANGER!!!! do not add code to invoke e.g. target event processing,
  386. * jim timer processing, etc. it can cause infinite recursion +
  387. * jim event callbacks need to happen at a well defined time,
  388. * not anywhere keep_alive() is invoked.
  389. *
  390. * These functions should be invoked at a well defined spot in server.c
  391. */
  392. last_time = current_time;
  393. }
  394. }
  395. /* reset keep alive timer without sending message */
  396. void kept_alive()
  397. {
  398. current_time = timeval_ms();
  399. last_time = current_time;
  400. }
  401. /* if we sleep for extended periods of time, we must invoke keep_alive() intermittantly */
  402. void alive_sleep(uint64_t ms)
  403. {
  404. uint64_t napTime = 10;
  405. for (uint64_t i = 0; i < ms; i += napTime)
  406. {
  407. uint64_t sleep_a_bit = ms - i;
  408. if (sleep_a_bit > napTime)
  409. sleep_a_bit = napTime;
  410. usleep(sleep_a_bit * 1000);
  411. keep_alive();
  412. }
  413. }
  414. void busy_sleep(uint64_t ms)
  415. {
  416. uint64_t then = timeval_ms();
  417. while (timeval_ms() - then < ms)
  418. {
  419. /* busy wait */
  420. }
  421. }