X-Git-Url: https://git.artsoft.org/?a=blobdiff_plain;f=src%2Flibgame%2Fmisc.c;h=0b70e206b6002424b9adf0b94254a77b44919ab9;hb=de49192b75b9ff43a8c2ed6cb200efb4240d8d6d;hp=c1450d4a7ab536e7751e7df69d92251b3f276f84;hpb=b641818c787e48bbf03ce2a0cd5b542c4c21e523;p=rocksndiamonds.git

diff --git a/src/libgame/misc.c b/src/libgame/misc.c
index c1450d4a..0b70e206 100644
--- a/src/libgame/misc.c
+++ b/src/libgame/misc.c
@@ -251,6 +251,195 @@ void PrintLineWithPrefix(char *prefix, char *line_chars, int line_length)
 }
 
 
+// ----------------------------------------------------------------------------
+// generic logging and error handling functions
+// ----------------------------------------------------------------------------
+
+enum log_levels
+{
+  LOG_UNKNOWN = 0,
+  LOG_DEBUG,
+  LOG_INFO,
+  LOG_WARN,
+  LOG_ERROR,
+  LOG_FATAL
+};
+
+static char *log_tokens[] =
+{
+  "UNKNOWN",
+  "DEBUG",
+  "INFO",
+  "WARN",
+  "ERROR",
+  "FATAL"
+};
+
+static void printf_log_prefix(int log_level, char *mode)
+{
+  if (log_level < 0 || log_level > LOG_FATAL)
+    return;
+
+  char *log_token = log_tokens[log_level];
+
+  if (log_level == LOG_DEBUG)
+    printf_log_nonewline("[%s] [%s] ", log_token, mode);
+  else
+    printf_log_nonewline("[%s] ", log_token);
+}
+
+static void vLog(int log_level, char *mode, char *format, va_list ap)
+{
+  if (log_level < 0 || log_level > LOG_FATAL)
+    return;
+
+  if (log_level == LOG_DEBUG)
+  {
+    // only show debug messages when in debug mode
+    if (!options.debug)
+      return;
+
+    // if optional debug mode specified, limit debug output accordingly
+    if (options.debug_mode != NULL &&
+	strstr(mode, options.debug_mode) == NULL)
+      return;
+  }
+  else if (log_level == LOG_WARN)
+  {
+    // only show warning messages when in verbose mode
+    if (!options.verbose)
+      return;
+  }
+
+#if defined(PLATFORM_ANDROID)
+  android_log_prio = (log_level == LOG_DEBUG ? ANDROID_LOG_DEBUG :
+		      log_level == LOG_INFO  ? ANDROID_LOG_INFO :
+		      log_level == LOG_WARN  ? ANDROID_LOG_WARN :
+		      log_level == LOG_ERROR ? ANDROID_LOG_ERROR :
+		      log_level == LOG_FATAL ? ANDROID_LOG_FATAL :
+		      ANDROID_LOG_UNKNOWN);
+#endif
+
+  static boolean last_line_was_separator = FALSE;
+  char *log_token = log_tokens[log_level];
+
+  if (strEqual(format, "===") ||
+      strEqual(format, "---"))
+  {
+    static char *mode_last = NULL;
+    char line_char[2] = { format[0], '\0' };
+    int line_length = 80 - strlen(log_token) - 3;
+
+    if (log_level == LOG_DEBUG)
+      line_length -= strlen(mode) + 3;
+
+    if (last_line_was_separator && strEqual(mode, mode_last))
+      return;
+
+    printf_log_prefix(log_level, mode);
+    printf_log_line(line_char, line_length);
+
+    if (!strEqual(mode, mode_last))
+      setString(&mode_last, mode);
+
+    last_line_was_separator = TRUE;
+
+    return;
+  }
+
+  last_line_was_separator = FALSE;
+
+  printf_log_prefix(log_level, mode);
+
+  vprintf_log(format, ap);
+}
+
+static void Log(int log_level, char *mode, char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(log_level, mode, format, ap);
+  va_end(ap);
+}
+
+void Debug(char *mode, char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(LOG_DEBUG, mode, format, ap);
+  va_end(ap);
+}
+
+void Info(char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(LOG_INFO, NULL, format, ap);
+  va_end(ap);
+}
+
+void Warn(char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(LOG_WARN, NULL, format, ap);
+  va_end(ap);
+}
+
+void Error(char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(LOG_ERROR, NULL, format, ap);
+  va_end(ap);
+}
+
+void Fail(char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(LOG_FATAL, NULL, format, ap);
+  va_end(ap);
+
+  if (!network.is_server_thread)
+  {
+    va_start(ap, format);
+    program.exit_message_function(format, ap);
+    va_end(ap);
+  }
+
+  Log(LOG_FATAL, NULL, "aborting");
+
+  // network server thread: normal exit
+  if (network.is_server_thread)
+    exit(1);
+
+  // main process: clean up stuff
+  program.exit_function(1);
+}
+
+void FailWithHelp(char *format, ...)
+{
+  va_list ap;
+
+  va_start(ap, format);
+  vLog(LOG_FATAL, NULL, format, ap);
+  va_end(ap);
+
+  Log(LOG_FATAL, NULL, "try option '--help' for more information");
+  Log(LOG_FATAL, NULL, "aborting");
+
+  // main process: clean up stuff
+  program.exit_function(1);
+}
+
+
 // ----------------------------------------------------------------------------
 // string functions
 // ----------------------------------------------------------------------------
@@ -453,10 +642,15 @@ void SkipUntilDelayReached(unsigned int *counter_var, unsigned int delay,
 
 #if 0
 #if DEBUG
-  printf("::: %d: %d ms", *loop_var, delay);
   if (skip_frames)
-    printf(" -> SKIP %d FRAME(S) [%d ms]", skip_frames, skip_frames * delay);
-  printf("\n");
+    Debug("internal:SkipUntilDelayReached",
+	  "%d: %d ms -> SKIP %d FRAME(S) [%d ms]",
+	  *loop_var, delay,
+	  skip_frames, skip_frames * delay);
+  else
+    Debug("internal:SkipUntilDelayReached",
+	  "%d: %d ms",
+	  *loop_var, delay);
 #endif
 #endif
 
@@ -876,7 +1070,7 @@ boolean strSuffix(char *s, char *suffix)
 	  s == NULL && suffix != NULL ? FALSE :
 	  s != NULL && suffix == NULL ? FALSE :
 	  strlen(s) < strlen(suffix)  ? FALSE :
-	  strncmp(&s[strlen(s) - strlen(suffix)], suffix, strlen(suffix)) == 0);
+	  strcmp(&s[strlen(s) - strlen(suffix)], suffix) == 0);
 }
 
 boolean strPrefixLower(char *s, char *prefix)
@@ -932,6 +1126,7 @@ void GetOptions(int argc, char *argv[],
 
   options.execute_command = NULL;
   options.special_flags = NULL;
+  options.debug_mode = NULL;
 
   options.mytapes = FALSE;
   options.serveronly = FALSE;
@@ -963,7 +1158,7 @@ void GetOptions(int argc, char *argv[],
     int option_len = strlen(option);
 
     if (option_len >= MAX_OPTION_LEN)
-      Error(ERR_EXIT_HELP, "unrecognized option '%s'", option);
+      FailWithHelp("unrecognized option '%s'", option);
 
     strcpy(option_str, option);			// copy argument into buffer
     option = option_str;
@@ -981,14 +1176,14 @@ void GetOptions(int argc, char *argv[],
     {
       *option_arg++ = '\0';			// cut argument from option
       if (*option_arg == '\0')			// no argument after '='
-	Error(ERR_EXIT_HELP, "option '%s' has invalid argument", option_str);
+	FailWithHelp("option '%s' has invalid argument", option_str);
     }
 
     option_len = strlen(option);
 
     if (strEqual(option, "-"))
     {
-      Error(ERR_EXIT_HELP, "unrecognized option '%s'", option);
+      FailWithHelp("unrecognized option '%s'", option);
     }
     else if (strncmp(option, "-help", option_len) == 0)
     {
@@ -999,11 +1194,11 @@ void GetOptions(int argc, char *argv[],
     else if (strncmp(option, "-basepath", option_len) == 0)
     {
       if (option_arg == NULL)
-	Error(ERR_EXIT_HELP, "option '%s' requires an argument", option_str);
+	FailWithHelp("option '%s' requires an argument", option_str);
 
       // this should be extended to separate options for ro and rw data
-      options.ro_base_directory = ro_base_path = option_arg;
-      options.rw_base_directory = rw_base_path = option_arg;
+      options.ro_base_directory = ro_base_path = getStringCopy(option_arg);
+      options.rw_base_directory = rw_base_path = getStringCopy(option_arg);
       if (option_arg == next_option)
 	options_left++;
 
@@ -1018,36 +1213,36 @@ void GetOptions(int argc, char *argv[],
     else if (strncmp(option, "-levels", option_len) == 0)
     {
       if (option_arg == NULL)
-	Error(ERR_EXIT_HELP, "option '%s' requires an argument", option_str);
+	FailWithHelp("option '%s' requires an argument", option_str);
 
-      options.level_directory = option_arg;
+      options.level_directory = getStringCopy(option_arg);
       if (option_arg == next_option)
 	options_left++;
     }
     else if (strncmp(option, "-graphics", option_len) == 0)
     {
       if (option_arg == NULL)
-	Error(ERR_EXIT_HELP, "option '%s' requires an argument", option_str);
+	FailWithHelp("option '%s' requires an argument", option_str);
 
-      options.graphics_directory = option_arg;
+      options.graphics_directory = getStringCopy(option_arg);
       if (option_arg == next_option)
 	options_left++;
     }
     else if (strncmp(option, "-sounds", option_len) == 0)
     {
       if (option_arg == NULL)
-	Error(ERR_EXIT_HELP, "option '%s' requires an argument", option_str);
+	FailWithHelp("option '%s' requires an argument", option_str);
 
-      options.sounds_directory = option_arg;
+      options.sounds_directory = getStringCopy(option_arg);
       if (option_arg == next_option)
 	options_left++;
     }
     else if (strncmp(option, "-music", option_len) == 0)
     {
       if (option_arg == NULL)
-	Error(ERR_EXIT_HELP, "option '%s' requires an argument", option_str);
+	FailWithHelp("option '%s' requires an argument", option_str);
 
-      options.music_directory = option_arg;
+      options.music_directory = getStringCopy(option_arg);
       if (option_arg == next_option)
 	options_left++;
     }
@@ -1066,6 +1261,10 @@ void GetOptions(int argc, char *argv[],
     else if (strncmp(option, "-debug", option_len) == 0)
     {
       options.debug = TRUE;
+
+      // optionally, debug output can be limited to a specific debug mode
+      if (option_arg != next_option)
+	options.debug_mode = getStringCopy(option_arg);
     }
     else if (strncmp(option, "-verbose", option_len) == 0)
     {
@@ -1085,9 +1284,9 @@ void GetOptions(int argc, char *argv[],
     else if (strncmp(option, "-execute", option_len) == 0)
     {
       if (option_arg == NULL)
-	Error(ERR_EXIT_HELP, "option '%s' requires an argument", option_str);
+	FailWithHelp("option '%s' requires an argument", option_str);
 
-      options.execute_command = option_arg;
+      options.execute_command = getStringCopy(option_arg);
       if (option_arg == next_option)
 	options_left++;
 
@@ -1102,7 +1301,7 @@ void GetOptions(int argc, char *argv[],
 #endif
     else if (*option == '-')
     {
-      Error(ERR_EXIT_HELP, "unrecognized option '%s'", option_str);
+      FailWithHelp("unrecognized option '%s'", option_str);
     }
     else if (options.server_host == NULL)
     {
@@ -1112,10 +1311,10 @@ void GetOptions(int argc, char *argv[],
     {
       options.server_port = atoi(*options_left);
       if (options.server_port < 1024)
-	Error(ERR_EXIT_HELP, "bad port number '%d'", options.server_port);
+	FailWithHelp("bad port number '%d'", options.server_port);
     }
     else
-      Error(ERR_EXIT_HELP, "too many arguments");
+      FailWithHelp("too many arguments");
 
     options_left++;
   }
@@ -1145,91 +1344,6 @@ char *GetError(void)
   return internal_error;
 }
 
-void Error(int mode, char *format, ...)
-{
-  static boolean last_line_was_separator = FALSE;
-  char *process_name = "";
-
-  if (program.log_file[LOG_ERR_ID] == NULL)
-    return;
-
-#if defined(PLATFORM_ANDROID)
-  android_log_prio = (mode & ERR_DEBUG ? ANDROID_LOG_DEBUG :
-		      mode & ERR_INFO ? ANDROID_LOG_INFO :
-		      mode & ERR_WARN ? ANDROID_LOG_WARN :
-		      mode & ERR_EXIT ? ANDROID_LOG_FATAL :
-		      ANDROID_LOG_UNKNOWN);
-#endif
-
-  // display debug messages only when running in debug mode
-  if (mode & ERR_DEBUG && !options.debug)
-    return;
-
-  // display warnings only when running in verbose mode
-  if (mode & ERR_WARN && !options.verbose)
-    return;
-
-  if (mode == ERR_INFO_LINE)
-  {
-    if (!last_line_was_separator)
-      printf_log_line(format, 79);
-
-    last_line_was_separator = TRUE;
-
-    return;
-  }
-
-  last_line_was_separator = FALSE;
-
-  if (mode & ERR_SOUND_SERVER)
-    process_name = " sound server";
-  else if (mode & ERR_NETWORK_SERVER)
-    process_name = " network server";
-  else if (mode & ERR_NETWORK_CLIENT)
-    process_name = " network client **";
-
-  if (format)
-  {
-#if !defined(PLATFORM_ANDROID)
-    printf_log_nonewline("%s%s: ", program.command_basename, process_name);
-#endif
-
-    if (mode & ERR_WARN)
-      printf_log_nonewline("warning: ");
-
-    if (mode & ERR_EXIT)
-      printf_log_nonewline("fatal error: ");
-
-    va_list ap;
-
-    va_start(ap, format);
-    vprintf_log(format, ap);
-    va_end(ap);
-
-    if ((mode & ERR_EXIT) && !(mode & ERR_FROM_SERVER))
-    {
-      va_start(ap, format);
-      program.exit_message_function(format, ap);
-      va_end(ap);
-    }
-  }
-  
-  if (mode & ERR_HELP)
-    printf_log("%s: Try option '--help' for more information.",
-	       program.command_basename);
-
-  if (mode & ERR_EXIT)
-    printf_log("%s%s: aborting", program.command_basename, process_name);
-
-  if (mode & ERR_EXIT)
-  {
-    if (mode & ERR_FROM_SERVER)
-      exit(1);				// child process: normal exit
-    else
-      program.exit_function(1);		// main process: clean up stuff
-  }
-}
-
 
 // ----------------------------------------------------------------------------
 // checked memory allocation and freeing functions
@@ -1242,7 +1356,7 @@ void *checked_malloc(unsigned int size)
   ptr = malloc(size);
 
   if (ptr == NULL)
-    Error(ERR_EXIT, "cannot allocate %d bytes -- out of memory", size);
+    Fail("cannot allocate %d bytes -- out of memory", size);
 
   return ptr;
 }
@@ -1254,7 +1368,7 @@ void *checked_calloc(unsigned int size)
   ptr = calloc(1, size);
 
   if (ptr == NULL)
-    Error(ERR_EXIT, "cannot allocate %d bytes -- out of memory", size);
+    Fail("cannot allocate %d bytes -- out of memory", size);
 
   return ptr;
 }
@@ -1264,7 +1378,7 @@ void *checked_realloc(void *ptr, unsigned int size)
   ptr = realloc(ptr, size);
 
   if (ptr == NULL)
-    Error(ERR_EXIT, "cannot allocate %d bytes -- out of memory", size);
+    Fail("cannot allocate %d bytes -- out of memory", size);
 
   return ptr;
 }
@@ -1756,7 +1870,7 @@ static void translate_keyname(Key *keysym, char **x11name, char **name, int mode
     }
 
     if (key == KSYM_UNDEFINED)
-      Error(ERR_WARN, "getKeyFromKeyName(): not completely implemented");
+      Warn("getKeyFromKeyName(): not completely implemented");
 
     *keysym = key;
   }
@@ -2124,12 +2238,12 @@ static void dumpList(ListNode *node_first)
 
   while (node)
   {
-    printf("['%s' (%d)]\n", node->key,
-	   ((struct ListNodeInfo *)node->content)->num_references);
+    Debug("internal:dumpList", "['%s' (%d)]", node->key,
+	  ((struct ListNodeInfo *)node->content)->num_references);
     node = node->next;
   }
 
-  printf("[%d nodes]\n", getNumNodes(node_first));
+  Debug("internal:dumpList", "[%d nodes]", getNumNodes(node_first));
 }
 #endif
 
@@ -2818,13 +2932,14 @@ struct FileInfo *getFileListFromConfigList(struct ConfigInfo *config_list,
   num_file_list_entries_found = list_pos + 1;
   if (num_file_list_entries_found != num_file_list_entries)
   {
-    Error(ERR_INFO_LINE, "-");
-    Error(ERR_INFO, "inconsistant config list information:");
-    Error(ERR_INFO, "- should be:   %d (according to 'src/conf_xxx.h')",
+    Error("---");
+    Error("inconsistant config list information:");
+    Error("- should be:   %d (according to 'src/conf_xxx.h')",
 	  num_file_list_entries);
-    Error(ERR_INFO, "- found to be: %d (according to 'src/conf_xxx.c')",
+    Error("- found to be: %d (according to 'src/conf_xxx.c')",
 	  num_file_list_entries_found);
-    Error(ERR_EXIT,   "please fix");
+
+    Fail("please fix");
   }
 
   freeSetupFileHash(ignore_tokens_hash);
@@ -3275,53 +3390,53 @@ static void LoadArtworkConfigFromFilename(struct ArtworkListInfo *artwork_info,
 
     if (options.debug && dynamic_tokens_found)
     {
-      Error(ERR_INFO_LINE, "-");
-      Error(ERR_INFO, "dynamic token(s) found in config file:");
-      Error(ERR_INFO, "- config file: '%s'", filename);
+      Debug("config", "---");
+      Debug("config", "dynamic token(s) found in config file:");
+      Debug("config", "- config file: '%s'", filename);
 
       for (list = setup_file_list; list != NULL; list = list->next)
       {
 	char *value = getHashEntry(extra_file_hash, list->token);
 
 	if (value != NULL && strEqual(value, known_token_value))
-	  Error(ERR_INFO, "- dynamic token: '%s'", list->token);
+	  Debug("config", "- dynamic token: '%s'", list->token);
       }
 
-      Error(ERR_INFO_LINE, "-");
+      Debug("config", "---");
     }
 
     if (unknown_tokens_found)
     {
-      Error(ERR_INFO_LINE, "-");
-      Error(ERR_INFO, "warning: unknown token(s) found in config file:");
-      Error(ERR_INFO, "- config file: '%s'", filename);
+      Warn("---");
+      Warn("unknown token(s) found in config file:");
+      Warn("- config file: '%s'", filename);
 
       for (list = setup_file_list; list != NULL; list = list->next)
       {
 	char *value = getHashEntry(extra_file_hash, list->token);
 
 	if (value != NULL && !strEqual(value, known_token_value))
-	  Error(ERR_INFO, "- dynamic token: '%s'", list->token);
+	  Warn("- dynamic token: '%s'", list->token);
       }
 
-      Error(ERR_INFO_LINE, "-");
+      Warn("---");
     }
 
     if (undefined_values_found)
     {
-      Error(ERR_INFO_LINE, "-");
-      Error(ERR_INFO, "warning: undefined values found in config file:");
-      Error(ERR_INFO, "- config file: '%s'", filename);
+      Warn("---");
+      Warn("undefined values found in config file:");
+      Warn("- config file: '%s'", filename);
 
       for (list = setup_file_list; list != NULL; list = list->next)
       {
 	char *value = getHashEntry(empty_file_hash, list->token);
 
 	if (value != NULL)
-	  Error(ERR_INFO, "- undefined value for token: '%s'", list->token);
+	  Warn("- undefined value for token: '%s'", list->token);
       }
 
-      Error(ERR_INFO_LINE, "-");
+      Warn("---");
     }
 
     freeSetupFileList(setup_file_list);
@@ -3427,7 +3542,7 @@ static void replaceArtworkListEntry(struct ArtworkListInfo *artwork_info,
 
   if (filename == NULL)
   {
-    Error(ERR_WARN, "cannot find artwork file '%s'", basename);
+    Warn("cannot find artwork file '%s'", basename);
 
     basename = file_list_entry->default_filename;
 
@@ -3435,14 +3550,14 @@ static void replaceArtworkListEntry(struct ArtworkListInfo *artwork_info,
     if (file_list_entry->default_is_cloned &&
 	strEqual(basename, UNDEFINED_FILENAME))
     {
-      int error_mode = ERR_WARN;
+      void (*error_func)(char *, ...) = Warn;
 
       // we can get away without sounds and music, but not without graphics
       if (*listnode == NULL && artwork_info->type == ARTWORK_TYPE_GRAPHICS)
-	error_mode = ERR_EXIT;
+	error_func = Fail;
 
-      Error(error_mode, "token '%s' was cloned and has no default filename",
-	    file_list_entry->token);
+      error_func("token '%s' was cloned and has no default filename",
+		 file_list_entry->token);
 
       return;
     }
@@ -3453,19 +3568,19 @@ static void replaceArtworkListEntry(struct ArtworkListInfo *artwork_info,
 
     file_list_entry->fallback_to_default = TRUE;
 
-    Error(ERR_WARN, "trying default artwork file '%s'", basename);
+    Warn("trying default artwork file '%s'", basename);
 
     filename = getCustomArtworkFilename(basename, artwork_info->type);
 
     if (filename == NULL)
     {
-      int error_mode = ERR_WARN;
+      void (*error_func)(char *, ...) = Warn;
 
       // we can get away without sounds and music, but not without graphics
       if (*listnode == NULL && artwork_info->type == ARTWORK_TYPE_GRAPHICS)
-	error_mode = ERR_EXIT;
+	error_func = Fail;
 
-      Error(error_mode, "cannot find default artwork file '%s'", basename);
+      error_func("cannot find default artwork file '%s'", basename);
 
       return;
     }
@@ -3505,13 +3620,13 @@ static void replaceArtworkListEntry(struct ArtworkListInfo *artwork_info,
   }
   else
   {
-    int error_mode = ERR_WARN;
+    void (*error_func)(char *, ...) = Warn;
 
     // we can get away without sounds and music, but not without graphics
     if (artwork_info->type == ARTWORK_TYPE_GRAPHICS)
-      error_mode = ERR_EXIT;
+      error_func = Fail;
 
-    Error(error_mode, "cannot load artwork file '%s'", basename);
+    error_func("cannot load artwork file '%s'", basename);
 
     return;
   }
@@ -3611,8 +3726,8 @@ void OpenLogFiles(void)
     {
       program.log_file[i] = program.log_file_default[i];   // reset to default
 
-      Error(ERR_WARN, "cannot open file '%s' for writing: %s",
-	    program.log_filename[i], strerror(errno));
+      Warn("cannot open file '%s' for writing: %s",
+	   program.log_filename[i], strerror(errno));
     }
 
     // output should be unbuffered so it is not truncated in a crash
@@ -3710,9 +3825,9 @@ void debug_print_timestamp(int counter_nr, char *message)
   float timestamp_interval;
 
   if (counter_nr < 0)
-    Error(ERR_EXIT, "debugging: invalid negative counter");
+    Fail("debugging: invalid negative counter");
   else if (counter_nr >= DEBUG_NUM_TIMESTAMPS)
-    Error(ERR_EXIT, "debugging: increase DEBUG_NUM_TIMESTAMPS in misc.c");
+    Fail("debugging: increase DEBUG_NUM_TIMESTAMPS in misc.c");
 
 #if DEBUG_TIME_IN_MICROSECONDS
   static double counter[DEBUG_NUM_TIMESTAMPS][2];
@@ -3730,12 +3845,12 @@ void debug_print_timestamp(int counter_nr, char *message)
   counter[counter_nr][1] = counter[counter_nr][0];
 
   if (message)
-    Error(ERR_DEBUG, "%s%s%s %.3f %s",
-	   debug_print_timestamp_get_padding(counter_nr * indent_size),
-	   message,
-	   debug_print_timestamp_get_padding(padding_size - strlen(message)),
-	   timestamp_interval / 1000,
-	   unit);
+    Debug("time", "%s%s%s %.3f %s",
+	  debug_print_timestamp_get_padding(counter_nr * indent_size),
+	  message,
+	  debug_print_timestamp_get_padding(padding_size - strlen(message)),
+	  timestamp_interval / 1000,
+	  unit);
 }
 
 #if 0