target/xtensa: avoid IHI for writes to non-executable memory
[openocd.git] / src / helper / log.c
index 27fa8317aa6e0526037257affc9e14d1a3a8ddfa..471069adee713d380b1a7d510f9957438f88d4eb 100644 (file)
@@ -1,35 +1,26 @@
+// SPDX-License-Identifier: GPL-2.0-or-later
+
 /***************************************************************************
  *   Copyright (C) 2005 by Dominic Rath                                    *
  *   Dominic.Rath@gmx.de                                                   *
  *                                                                         *
- *   Copyright (C) 2007,2008 Øyvind Harboe                                 *
+ *   Copyright (C) 2007-2010 Øyvind Harboe                                 *
  *   oyvind.harboe@zylin.com                                               *
  *                                                                         *
  *   Copyright (C) 2008 by Spencer Oliver                                  *
  *   spen@spen-soft.co.uk                                                  *
- *                                                                         *
- *   This program is free software; you can redistribute it and/or modify  *
- *   it under the terms of the GNU General Public License as published by  *
- *   the Free Software Foundation; either version 2 of the License, or     *
- *   (at your option) any later version.                                   *
- *                                                                         *
- *   This program is distributed in the hope that it will be useful,       *
- *   but WITHOUT ANY WARRANTY; without even the implied warranty of        *
- *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the         *
- *   GNU General Public License for more details.                          *
- *                                                                         *
- *   You should have received a copy of the GNU General Public License     *
- *   along with this program; if not, write to the                         *
- *   Free Software Foundation, Inc.,                                       *
- *   59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.             *
  ***************************************************************************/
+
 #ifdef HAVE_CONFIG_H
 #include "config.h"
 #endif
 
+#include "log.h"
+#include "command.h"
+#include "replacements.h"
 #include "time_support.h"
-// @todo the inclusion of server.h here is a layering violation
-#include "server.h"
+#include <server/gdb_server.h>
+#include <server/server.h>
 
 #include <stdarg.h>
 
 #endif
 #endif
 
-int debug_level = -1;
+int debug_level = LOG_LVL_INFO;
 
-static FILElog_output;
-static struct log_callback *log_callbacks = NULL;
+static FILE *log_output;
+static struct log_callback *log_callbacks;
 
-static long long last_time;
-static long long current_time;
+static int64_t last_time;
 
-static long long start;
+static int64_t start;
 
-static char *log_strings[5] =
-{
+static const char * const log_strings[6] = {
        "User : ",
        "Error: ",
-       "Warn : ",  /* want a space after each colon, all same width, colons aligned */
+       "Warn : ",      /* want a space after each colon, all same width, colons aligned */
        "Info : ",
+       "Debug: ",
        "Debug: "
 };
 
+static int count;
 
-static int count = 0;
-
-
-static struct store_log_forward * log_head = NULL;
-static int log_forward_count = 0;
-
-struct store_log_forward
-{
-       struct store_log_forward * next;
-       const char * file;
-       int line;
-       const char * function;
-       const char * string;
-};
-
-/* either forward the log to the listeners or store it for possible forwarding later */
+/* forward the log to the listeners */
 static void log_forward(const char *file, unsigned line, const char *function, const char *string)
 {
-       if (log_forward_count==0)
-       {
-               struct log_callback *cb, *next;
-               cb = log_callbacks;
-               /* DANGER!!!! the log callback can remove itself!!!! */
-               while (cb)
-               {
-                       next = cb->next;
-                       cb->fn(cb->priv, file, line, function, string);
-                       cb = next;
-               }
-       } else
-       {
-               struct store_log_forward *log = malloc(sizeof (struct store_log_forward));
-               log->file = strdup(file);
-               log->line = line;
-               log->function = strdup(function);
-               log->string = strdup(string);
-               log->next = NULL;
-               if (log_head==NULL)
-                       log_head = log;
-               else
-               {
-                       /* append to tail */
-                       struct store_log_forward * t;
-                       t = log_head;
-                       while (t->next!=NULL)
-                       {
-                               t = t->next;
-                       }
-                       t->next = log;
-               }
-       }
-}
-
-void log_try(void)
-{
-       log_forward_count++;
-}
-
-void log_catch(void)
-{
-       assert(log_forward_count>0);
-       log_forward_count--;
-}
-
-void log_rethrow(void)
-{
-       log_catch();
-       if (log_forward_count==0)
-       {
-               struct store_log_forward *log;
-
-               log = log_head;
-               while (log != NULL)
-               {
-                       log_forward(log->file, log->line, log->function, log->string);
-
-                       struct store_log_forward *t=log;
-                       log = log->next;
-
-                       free((void *)t->file);
-                       free((void *)t->function);
-                       free((void *)t->string);
-                       free(t);
-
-               }
-
-               log_head = NULL;
+       struct log_callback *cb, *next;
+       cb = log_callbacks;
+       /* DANGER!!!! the log callback can remove itself!!!! */
+       while (cb) {
+               next = cb->next;
+               cb->fn(cb->priv, file, line, function, string);
+               cb = next;
        }
 }
 
-
-/* The log_puts() serves to somewhat different goals:
+/* The log_puts() serves two somewhat different goals:
  *
  * - logging
  * - feeding low-level info to the user in GDB or Telnet
@@ -162,11 +75,22 @@ void log_rethrow(void)
  * target_request.c).
  *
  */
-static void log_puts(enum log_levels level, const char *file, int line, const char *function, const char *string)
+static void log_puts(enum log_levels level,
+       const char *file,
+       int line,
+       const char *function,
+       const char *string)
 {
        char *f;
-       if (level == LOG_LVL_OUTPUT)
-       {
+
+       if (!log_output) {
+               /* log_init() not called yet; print on stderr */
+               fputs(string, stderr);
+               fflush(stderr);
+               return;
+       }
+
+       if (level == LOG_LVL_OUTPUT) {
                /* do not prepend any headers, just print out what we were given and return */
                fputs(string, log_output);
                fflush(log_output);
@@ -174,57 +98,45 @@ static void log_puts(enum log_levels level, const char *file, int line, const ch
        }
 
        f = strrchr(file, '/');
-       if (f != NULL)
+       if (f)
                file = f + 1;
 
-       if (strchr(string, '\n') != NULL)
-       {
-               if (debug_level >= LOG_LVL_DEBUG)
-               {
-                       /* print with count and time information */
-                       int t = (int)(timeval_ms()-start);
+       if (debug_level >= LOG_LVL_DEBUG) {
+               /* print with count and time information */
+               int64_t t = timeval_ms() - start;
 #ifdef _DEBUG_FREE_SPACE_
-                       struct mallinfo info;
-                       info = mallinfo();
+               struct mallinfo info;
+               info = mallinfo();
 #endif
-                       fprintf(log_output, "%s%d %d %s:%d %s()"
+               fprintf(log_output, "%s%d %" PRId64 " %s:%d %s()"
 #ifdef _DEBUG_FREE_SPACE_
-                                       " %d"
+                       " %d"
 #endif
-                                       ": %s", log_strings[level + 1], count, t, file, line, function,
+                       ": %s", log_strings[level + 1], count, t, file, line, function,
 #ifdef _DEBUG_FREE_SPACE_
-                                       info.fordblks,
+                       info.fordblks,
 #endif
-                                       string);
-               }
-               else if (server_use_pipes == 0)
-               {
-                       /* if we are using gdb through pipes then we do not want any output
-                        * to the pipe otherwise we get repeated strings */
-                       if (strcmp(string, "\n") != 0)
-                       {
-                               /* print human readable output - but skip empty lines */
-                               fprintf(log_output, "%s%s",
-                                               (level > LOG_LVL_USER)?log_strings[level + 1]:"", string);
-                       }
-               }
-       } else
-       {
-               /* only entire lines are logged. Otherwise it's
-                * single chars intended for the log callbacks. */
+                       string);
+       } else {
+               /* if we are using gdb through pipes then we do not want any output
+                * to the pipe otherwise we get repeated strings */
+               fprintf(log_output, "%s%s",
+                       (level > LOG_LVL_USER) ? log_strings[level + 1] : "", string);
        }
 
        fflush(log_output);
 
        /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
        if (level <= LOG_LVL_INFO)
-       {
                log_forward(file, line, function, string);
-       }
 }
 
-
-void log_printf(enum log_levels level, const char *file, unsigned line, const char *function, const char *format, ...)
+void log_printf(enum log_levels level,
+       const char *file,
+       unsigned line,
+       const char *function,
+       const char *format,
+       ...)
 {
        char *string;
        va_list ap;
@@ -236,8 +148,7 @@ void log_printf(enum log_levels level, const char *file, unsigned line, const ch
        va_start(ap, format);
 
        string = alloc_vprintf(format, ap);
-       if (string != NULL)
-       {
+       if (string) {
                log_puts(level, file, line, function, string);
                free(string);
        }
@@ -245,91 +156,105 @@ void log_printf(enum log_levels level, const char *file, unsigned line, const ch
        va_end(ap);
 }
 
-void log_printf_lf(enum log_levels level, const char *file, unsigned line, const char *function, const char *format, ...)
+void log_vprintf_lf(enum log_levels level, const char *file, unsigned line,
+               const char *function, const char *format, va_list args)
 {
-       char *string;
-       va_list ap;
+       char *tmp;
 
        count++;
+
        if (level > debug_level)
                return;
 
-       va_start(ap, format);
+       tmp = alloc_vprintf(format, args);
 
-       string = alloc_vprintf(format, ap);
-       if (string != NULL)
-       {
-               strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */
-               log_puts(level, file, line, function, string);
-               free(string);
-       }
+       if (!tmp)
+               return;
+
+       /*
+        * Note: alloc_vprintf() guarantees that the buffer is at least one
+        * character longer.
+        */
+       strcat(tmp, "\n");
+       log_puts(level, file, line, function, tmp);
+       free(tmp);
+}
 
+void log_printf_lf(enum log_levels level,
+       const char *file,
+       unsigned line,
+       const char *function,
+       const char *format,
+       ...)
+{
+       va_list ap;
+
+       va_start(ap, format);
+       log_vprintf_lf(level, file, line, function, format, ap);
        va_end(ap);
 }
 
-/* change the current debug level on the fly
- * 0: only ERRORS
- * 1: + WARNINGS
- * 2: + INFORMATIONAL MSGS
- * 3: + DEBUG MSGS
- */
 COMMAND_HANDLER(handle_debug_level_command)
 {
-       if (CMD_ARGC == 1)
-       {
-               unsigned new_level;
-               COMMAND_PARSE_NUMBER(uint, CMD_ARGV[0], new_level);
-               debug_level = MIN(new_level, LOG_LVL_DEBUG);
-       }
-       else if (CMD_ARGC > 1)
-               return ERROR_COMMAND_SYNTAX_ERROR;
-
-       if (debug_level >= LOG_LVL_DEBUG && server_use_pipes == 1)
-       {
-               /* if we are enabling debug info then we need to write to a log file
-                * otherwise the pipe will get full and cause issues with gdb */
-               FILE* file = fopen("openocd.log", "w");
-               if (file)
-               {
-                       log_output = file;
-                       LOG_WARNING("enabling log output as we are using pipes");
+       if (CMD_ARGC == 1) {
+               int new_level;
+               COMMAND_PARSE_NUMBER(int, CMD_ARGV[0], new_level);
+               if ((new_level > LOG_LVL_DEBUG_IO) || (new_level < LOG_LVL_SILENT)) {
+                       LOG_ERROR("level must be between %d and %d", LOG_LVL_SILENT, LOG_LVL_DEBUG_IO);
+                       return ERROR_COMMAND_SYNTAX_ERROR;
                }
-       }
+               debug_level = new_level;
+       } else if (CMD_ARGC > 1)
+               return ERROR_COMMAND_SYNTAX_ERROR;
 
-       command_print(CMD_CTX, "debug_level: %i", debug_level);
+       command_print(CMD, "debug_level: %i", debug_level);
 
        return ERROR_OK;
 }
 
 COMMAND_HANDLER(handle_log_output_command)
 {
-       if (CMD_ARGC == 1)
-       {
-               FILE* file = fopen(CMD_ARGV[0], "w");
+       if (CMD_ARGC > 1)
+               return ERROR_COMMAND_SYNTAX_ERROR;
 
-               if (file)
-               {
-                       log_output = file;
+       FILE *file;
+       if (CMD_ARGC == 1 && strcmp(CMD_ARGV[0], "default") != 0) {
+               file = fopen(CMD_ARGV[0], "w");
+               if (!file) {
+                       command_print(CMD, "failed to open output log \"%s\"", CMD_ARGV[0]);
+                       return ERROR_FAIL;
                }
+               command_print(CMD, "set log_output to \"%s\"", CMD_ARGV[0]);
+       } else {
+               file = stderr;
+               command_print(CMD, "set log_output to default");
        }
 
+       if (log_output != stderr && log_output) {
+               /* Close previous log file, if it was open and wasn't stderr. */
+               fclose(log_output);
+       }
+       log_output = file;
        return ERROR_OK;
 }
 
-static struct command_registration log_command_handlers[] = {
+static const struct command_registration log_command_handlers[] = {
        {
                .name = "log_output",
-               .handler = &handle_log_output_command,
+               .handler = handle_log_output_command,
                .mode = COMMAND_ANY,
                .help = "redirect logging to a file (default: stderr)",
-               .usage = "<file_name>",
+               .usage = "[file_name | 'default']",
        },
        {
                .name = "debug_level",
-               .handler = &handle_debug_level_command,
+               .handler = handle_debug_level_command,
                .mode = COMMAND_ANY,
-               .help = "sets the verbosity level of debugging output",
-               .usage = "<level:0-3>",
+               .help = "Sets the verbosity level of debugging output. "
+                       "0 shows errors only; 1 adds warnings; "
+                       "2 (default) adds other info; 3 adds debugging; "
+                       "4 adds extra verbose debugging.",
+               .usage = "number",
        },
        COMMAND_REGISTRATION_DONE
 };
@@ -343,19 +268,29 @@ void log_init(void)
 {
        /* set defaults for daemon configuration,
         * if not set by cmdline or cfgfile */
-       if (debug_level == -1)
-               debug_level = LOG_LVL_INFO;
+       char *debug_env = getenv("OPENOCD_DEBUG_LEVEL");
+       if (debug_env) {
+               int value;
+               int retval = parse_int(debug_env, &value);
+               if (retval == ERROR_OK &&
+                               debug_level >= LOG_LVL_SILENT &&
+                               debug_level <= LOG_LVL_DEBUG_IO)
+                               debug_level = value;
+       }
 
-       if (log_output == NULL)
+       if (!log_output)
                log_output = stderr;
 
        start = last_time = timeval_ms();
 }
 
-int set_log_output(struct command_context *cmd_ctx, FILE *output)
+void log_exit(void)
 {
-       log_output = output;
-       return ERROR_OK;
+       if (log_output && log_output != stderr) {
+               /* Close log file, if it was open and wasn't stderr. */
+               fclose(log_output);
+       }
+       log_output = NULL;
 }
 
 /* add/remove log callback handler */
@@ -364,14 +299,15 @@ int log_add_callback(log_callback_fn fn, void *priv)
        struct log_callback *cb;
 
        /* prevent the same callback to be registered more than once, just for sure */
-       for (cb = log_callbacks; cb; cb = cb->next)
-       {
+       for (cb = log_callbacks; cb; cb = cb->next) {
                if (cb->fn == fn && cb->priv == priv)
-                       return ERROR_INVALID_ARGUMENTS;
+                       return ERROR_COMMAND_SYNTAX_ERROR;
        }
 
-       /* alloc memory, it is safe just to return in case of an error, no need for the caller to check this */
-       if ((cb = malloc(sizeof(struct log_callback))) == NULL)
+       /* alloc memory, it is safe just to return in case of an error, no need for the caller to
+        *check this */
+       cb = malloc(sizeof(struct log_callback));
+       if (!cb)
                return ERROR_BUF_TOO_SMALL;
 
        /* add item to the beginning of the linked list */
@@ -387,10 +323,8 @@ int log_remove_callback(log_callback_fn fn, void *priv)
 {
        struct log_callback *cb, **p;
 
-       for (p = &log_callbacks; (cb = *p); p = &(*p)->next)
-       {
-               if (cb->fn == fn && cb->priv == priv)
-               {
+       for (p = &log_callbacks; (cb = *p); p = &(*p)->next) {
+               if (cb->fn == fn && cb->priv == priv) {
                        *p = cb->next;
                        free(cb);
                        return ERROR_OK;
@@ -398,7 +332,7 @@ int log_remove_callback(log_callback_fn fn, void *priv)
        }
 
        /* no such item */
-       return ERROR_INVALID_ARGUMENTS;
+       return ERROR_COMMAND_SYNTAX_ERROR;
 }
 
 /* return allocated string w/printf() result */
@@ -418,7 +352,7 @@ char *alloc_vprintf(const char *fmt, va_list ap)
         * other code depend on that. They should be probably be fixed, but for
         * now reserve the extra byte. */
        string = malloc(len + 2);
-       if (string == NULL)
+       if (!string)
                return NULL;
 
        /* do the real work */
@@ -458,29 +392,42 @@ char *alloc_printf(const char *format, ...)
  * fast when invoked more often than every 500ms.
  *
  */
-void keep_alive()
+#define KEEP_ALIVE_KICK_TIME_MS  500
+#define KEEP_ALIVE_TIMEOUT_MS   1000
+
+static void gdb_timeout_warning(int64_t delta_time)
 {
-       current_time = timeval_ms();
-       if (current_time-last_time > 1000)
-       {
-               extern int gdb_actual_connections;
-
-               if (gdb_actual_connections)
-                       LOG_WARNING("keep_alive() was not invoked in the "
-                               "1000ms timelimit. GDB alive packet not "
-                               "sent! (%lld). Workaround: increase "
-                               "\"set remotetimeout\" in GDB",
-                               current_time-last_time);
-               else
-                       LOG_DEBUG("keep_alive() was not invoked in the "
-                               "1000ms timelimit (%lld). This may cause "
-                               "trouble with GDB connections.",
-                               current_time-last_time);
+       if (gdb_get_actual_connections())
+               LOG_WARNING("keep_alive() was not invoked in the "
+                       "%d ms timelimit. GDB alive packet not "
+                       "sent! (%" PRId64 " ms). Workaround: increase "
+                       "\"set remotetimeout\" in GDB",
+                       KEEP_ALIVE_TIMEOUT_MS,
+                       delta_time);
+       else
+               LOG_DEBUG("keep_alive() was not invoked in the "
+                       "%d ms timelimit (%" PRId64 " ms). This may cause "
+                       "trouble with GDB connections.",
+                       KEEP_ALIVE_TIMEOUT_MS,
+                       delta_time);
+}
+
+void keep_alive(void)
+{
+       int64_t current_time = timeval_ms();
+       int64_t delta_time = current_time - last_time;
+
+       if (delta_time > KEEP_ALIVE_TIMEOUT_MS) {
+               last_time = current_time;
+
+               gdb_timeout_warning(delta_time);
        }
-       if (current_time-last_time > 500)
-       {
+
+       if (delta_time > KEEP_ALIVE_KICK_TIME_MS) {
+               last_time = current_time;
+
                /* this will keep the GDB connection alive */
-               LOG_USER_N("%s", "");
+               server_keep_clients_alive();
 
                /* DANGER!!!! do not add code to invoke e.g. target event processing,
                 * jim timer processing, etc. it can cause infinite recursion +
@@ -489,27 +436,30 @@ void keep_alive()
                 *
                 * These functions should be invoked at a well defined spot in server.c
                 */
-
-               last_time = current_time;
        }
 }
 
 /* reset keep alive timer without sending message */
-void kept_alive()
+void kept_alive(void)
 {
-       current_time = timeval_ms();
+       int64_t current_time = timeval_ms();
+
+       int64_t delta_time = current_time - last_time;
+
        last_time = current_time;
+
+       if (delta_time > KEEP_ALIVE_TIMEOUT_MS)
+               gdb_timeout_warning(delta_time);
 }
 
-/* if we sleep for extended periods of time, we must invoke keep_alive() intermittantly */
+/* if we sleep for extended periods of time, we must invoke keep_alive() intermittently */
 void alive_sleep(uint64_t ms)
 {
-       uint64_t napTime = 10;
-       for (uint64_t i = 0; i < ms; i += napTime)
-       {
+       uint64_t nap_time = 10;
+       for (uint64_t i = 0; i < ms; i += nap_time) {
                uint64_t sleep_a_bit = ms - i;
-               if (sleep_a_bit > napTime)
-                       sleep_a_bit = napTime;
+               if (sleep_a_bit > nap_time)
+                       sleep_a_bit = nap_time;
 
                usleep(sleep_a_bit * 1000);
                keep_alive();
@@ -519,8 +469,47 @@ void alive_sleep(uint64_t ms)
 void busy_sleep(uint64_t ms)
 {
        uint64_t then = timeval_ms();
-       while (timeval_ms() - then < ms)
-       {
-               /* busy wait */
+       while (timeval_ms() - then < ms) {
+               /*
+                * busy wait
+                */
+       }
+}
+
+/* Maximum size of socket error message retrieved from operation system */
+#define MAX_SOCKET_ERR_MSG_LENGTH 256
+
+/* Provide log message for the last socket error.
+   Uses errno on *nix and WSAGetLastError() on Windows */
+void log_socket_error(const char *socket_desc)
+{
+       int error_code;
+#ifdef _WIN32
+       error_code = WSAGetLastError();
+       char error_message[MAX_SOCKET_ERR_MSG_LENGTH];
+       error_message[0] = '\0';
+       DWORD retval = FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM, NULL, error_code, 0,
+               error_message, MAX_SOCKET_ERR_MSG_LENGTH, NULL);
+       error_message[MAX_SOCKET_ERR_MSG_LENGTH - 1] = '\0';
+       const bool have_message = (retval != 0) && (error_message[0] != '\0');
+       LOG_ERROR("Error on socket '%s': WSAGetLastError==%d%s%s.", socket_desc, error_code,
+               (have_message ? ", message: " : ""),
+               (have_message ? error_message : ""));
+#else
+       error_code = errno;
+       LOG_ERROR("Error on socket '%s': errno==%d, message: %s.", socket_desc, error_code, strerror(error_code));
+#endif
+}
+
+/**
+ * Find the first non-printable character in the char buffer, return a pointer to it.
+ * If no such character exists, return NULL.
+ */
+char *find_nonprint_char(char *buf, unsigned buf_len)
+{
+       for (unsigned int i = 0; i < buf_len; i++) {
+               if (!isprint(buf[i]))
+                       return buf + i;
        }
+       return NULL;
 }

Linking to existing account procedure

If you already have an account and want to add another login method you MUST first sign in with your existing account and then change URL to read https://review.openocd.org/login/?link to get to this page again but this time it'll work for linking. Thank you.

SSH host keys fingerprints

1024 SHA256:YKx8b7u5ZWdcbp7/4AeXNaqElP49m6QrwfXaqQGJAOk gerrit-code-review@openocd.zylin.com (DSA)
384 SHA256:jHIbSQa4REvwCFG4cq5LBlBLxmxSqelQPem/EXIrxjk gerrit-code-review@openocd.org (ECDSA)
521 SHA256:UAOPYkU9Fjtcao0Ul/Rrlnj/OsQvt+pgdYSZ4jOYdgs gerrit-code-review@openocd.org (ECDSA)
256 SHA256:A13M5QlnozFOvTllybRZH6vm7iSt0XLxbA48yfc2yfY gerrit-code-review@openocd.org (ECDSA)
256 SHA256:spYMBqEYoAOtK7yZBrcwE8ZpYt6b68Cfh9yEVetvbXg gerrit-code-review@openocd.org (ED25519)
+--[ED25519 256]--+
|=..              |
|+o..   .         |
|*.o   . .        |
|+B . . .         |
|Bo. = o S        |
|Oo.+ + =         |
|oB=.* = . o      |
| =+=.+   + E     |
|. .=o   . o      |
+----[SHA256]-----+
2048 SHA256:0Onrb7/PHjpo6iVZ7xQX2riKN83FJ3KGU0TvI0TaFG4 gerrit-code-review@openocd.zylin.com (RSA)