Changeset cc305b5


Ignore:
Timestamp:
May 30, 2011, 10:27:31 PM (13 years ago)
Author:
Adam Glasgall <glasgall@mit.edu>
Branches:
master, release-1.10, release-1.8, release-1.9
Children:
6376af1, 28cd43f9, 83a4af3
Parents:
44976fe
git-author:
Adam Glasgall <adam@crossproduct.net> (02/28/11 11:33:59)
git-committer:
Adam Glasgall <glasgall@mit.edu> (05/30/11 22:27:31)
Message:
Move log-writing onto a background thread.

Currently, Barnowl writes message logs on the same thread as the UI
and other I/O. This means that if writing log files is very slow
(e.g. if logpath or classlogpath point to somewhere in AFS and the
fileserver that volume relies on is very slow to respond), barnowl
freezes up until the write completes. This patch creates a background
logging thread as part of initialization and runs a main loop on that
thread. Logging is then accomplished by posting tasks that write to
log files to that thread, a la how other threads can post tasks to the
UI thread's main loop.

Post a quit task to the logging thread's mainloop instead of quitting directly

Calling g_main_quit() on the main thread to quit the logging thread could resultin log tasks still in its queue getting lost. Instead, after we've shut down
everything that could log messages, post a quit task to the log thread so that
it'll only get run after everything outstanding has been processed.
Files:
2 edited

Legend:

Unmodified
Added
Removed

  • logging.c

    r7865479 rcc305b5  
    44#include <ctype.h>
    55#include <sys/param.h>
     6
     7typedef struct _owl_log_entry { /* noproto */
     8  char *filename;
     9  char *message;
     10} owl_log_entry;
     11
     12
     13static GMainContext *log_context;
     14static GMainLoop *log_loop;
     15static GThread *logging_thread;
    616
    717/* This is now the one function that should be called to log a
    … …  
    7080}
    7181
    72 void owl_log_zephyr(const owl_message *m, FILE *file) {
    73     char *tmp;
    74     tmp=short_zuser(owl_message_get_sender(m));
    75     fprintf(file, "Class: %s Instance: %s", owl_message_get_class(m), owl_message_get_instance(m));
    76     if (strcmp(owl_message_get_opcode(m), "")) fprintf(file, " Opcode: %s", owl_message_get_opcode(m));
    77     fprintf(file, "\n");
    78     fprintf(file, "Time: %s Host: %s\n", owl_message_get_timestr(m), owl_message_get_hostname(m));
    79     fprintf(file, "From: %s <%s>\n\n", owl_message_get_zsig(m), tmp);
    80     fprintf(file, "%s\n\n", owl_message_get_body(m));
     82char *owl_log_zephyr(const owl_message *m) {
     83    char *tmp = NULL;
     84    GString *buffer = NULL;
     85    buffer = g_string_new("");
     86    tmp = short_zuser(owl_message_get_sender(m));
     87    g_string_append_printf(buffer, "Class: %s Instance: %s",
     88                           owl_message_get_class(m),
     89                           owl_message_get_instance(m));
     90    if (strcmp(owl_message_get_opcode(m), "")) {
     91      g_string_append_printf(buffer, " Opcode: %s",
     92                             owl_message_get_opcode(m));
     93    }
     94    g_string_append_printf(buffer, "\n");
     95    g_string_append_printf(buffer, "Time: %s Host: %s\n",
     96                           owl_message_get_timestr(m),
     97                           owl_message_get_hostname(m));
     98    g_string_append_printf(buffer, "From: %s <%s>\n\n",
     99                           owl_message_get_zsig(m), tmp);
     100    g_string_append_printf(buffer, "%s\n\n", owl_message_get_body(m));
    81101    g_free(tmp);
    82 }
    83 
    84 void owl_log_aim(const owl_message *m, FILE *file) {
    85     fprintf(file, "From: <%s> To: <%s>\n", owl_message_get_sender(m), owl_message_get_recipient(m));
    86     fprintf(file, "Time: %s\n\n", owl_message_get_timestr(m));
    87     if (owl_message_is_login(m))
    88         fprintf(file, "LOGIN\n\n");
    89     else if (owl_message_is_logout(m))
    90         fprintf(file, "LOGOUT\n\n");
    91     else
    92         fprintf(file, "%s\n\n", owl_message_get_body(m));
    93 }
    94 
    95 void owl_log_jabber(const owl_message *m, FILE *file) {
    96     fprintf(file, "From: <%s> To: <%s>\n",owl_message_get_sender(m), owl_message_get_recipient(m));
    97     fprintf(file, "Time: %s\n\n", owl_message_get_timestr(m));
    98     fprintf(file, "%s\n\n",owl_message_get_body(m));
    99 }
    100 
    101 void owl_log_generic(const owl_message *m, FILE *file) {
    102     fprintf(file, "From: <%s> To: <%s>\n", owl_message_get_sender(m), owl_message_get_recipient(m));
    103     fprintf(file, "Time: %s\n\n", owl_message_get_timestr(m));
    104     fprintf(file, "%s\n\n", owl_message_get_body(m));
     102    return g_string_free(buffer, FALSE);
     103}
     104
     105char *owl_log_aim(const owl_message *m) {
     106    GString *buffer = NULL;
     107    buffer = g_string_new("");
     108    g_string_append_printf(buffer, "From: <%s> To: <%s>\n",
     109                           owl_message_get_sender(m), owl_message_get_recipient(m));
     110    g_string_append_printf(buffer, "Time: %s\n\n",
     111                           owl_message_get_timestr(m));
     112    if (owl_message_is_login(m)) {
     113        g_string_append_printf(buffer, "LOGIN\n\n");
     114    } else if (owl_message_is_logout(m)) {
     115        g_string_append_printf(buffer, "LOGOUT\n\n");
     116    } else {
     117        g_string_append_printf(buffer, "%s\n\n", owl_message_get_body(m));
     118    }
     119    return g_string_free(buffer, FALSE);
     120}
     121
     122char *owl_log_jabber(const owl_message *m) {
     123    GString *buffer = NULL;
     124    buffer = g_string_new("");
     125    g_string_append_printf(buffer, "From: <%s> To: <%s>\n",
     126                           owl_message_get_sender(m),
     127                           owl_message_get_recipient(m));
     128    g_string_append_printf(buffer, "Time: %s\n\n",
     129                           owl_message_get_timestr(m));
     130    g_string_append_printf(buffer, "%s\n\n", owl_message_get_body(m));
     131    return g_string_free(buffer, FALSE);
     132}
     133
     134char *owl_log_generic(const owl_message *m) {
     135    GString *buffer;
     136    buffer = g_string_new("");
     137    g_string_append_printf(buffer, "From: <%s> To: <%s>\n",
     138                           owl_message_get_sender(m),
     139                           owl_message_get_recipient(m));
     140    g_string_append_printf(buffer, "Time: %s\n\n",
     141                           owl_message_get_timestr(m));
     142    g_string_append_printf(buffer, "%s\n\n",
     143                           owl_message_get_body(m));
     144    return g_string_free(buffer, FALSE);
     145}
     146
     147static void owl_log_error_main_thread(gpointer data)
     148{
     149  owl_function_error("%s", (const char*)data);
     150}
     151
     152static void owl_log_error(const char *message)
     153{
     154  char *data = g_strdup(message);
     155  owl_select_post_task(owl_log_error_main_thread,
     156                       data, g_free, g_main_context_default());
     157}
     158
     159static void owl_log_write_entry(gpointer data)
     160{
     161  owl_log_entry *msg = (owl_log_entry*)data;
     162  FILE *file = NULL;
     163  file = fopen(msg->filename, "a");
     164  if (!file) {
     165    owl_log_error("Unable to open file for logging");
     166    return;
     167  }
     168  fprintf(file, "%s", msg->message);
     169  fclose(file);
     170}
     171
     172static void owl_log_entry_free(void *data)
     173{
     174  owl_log_entry *msg = (owl_log_entry*)data;
     175  if (msg) {
     176    g_free(msg->message);
     177    g_free(msg->filename);
     178    g_free(msg);
     179  }
     180}
     181
     182void owl_log_enqueue_message(const char *buffer, const char *filename)
     183{
     184  owl_log_entry *log_msg = NULL;
     185  log_msg = g_new(owl_log_entry,1);
     186  log_msg->message = g_strdup(buffer);
     187  log_msg->filename = g_strdup(filename);
     188  owl_select_post_task(owl_log_write_entry, log_msg,
     189                       owl_log_entry_free, log_context);
    105190}
    106191
    107192void owl_log_append(const owl_message *m, const char *filename) {
    108     FILE *file;
    109     file=fopen(filename, "a");
    110     if (!file) {
    111         owl_function_error("Unable to open file for logging");
    112         return;
    113     }
    114     if (owl_message_is_type_zephyr(m)) {
    115         owl_log_zephyr(m, file);
    116     } else if (owl_message_is_type_jabber(m)) {
    117         owl_log_jabber(m, file);
    118     } else if (owl_message_is_type_aim(m)) {
    119         owl_log_aim(m, file);
    120     } else {
    121         owl_log_generic(m, file);
    122     }
    123     fclose(file);
     193  char *buffer = NULL;
     194  if (owl_message_is_type_zephyr(m)) {
     195    buffer = owl_log_zephyr(m);
     196  } else if (owl_message_is_type_jabber(m)) {
     197    buffer = owl_log_jabber(m);
     198  } else if (owl_message_is_type_aim(m)) {
     199    buffer = owl_log_aim(m);
     200  } else {
     201    buffer = owl_log_generic(m);
     202  }
     203  owl_log_enqueue_message(buffer, filename);
     204  g_free(buffer);
    124205}
    125206
    … …  
    177258void owl_log_outgoing_zephyr_error(const owl_zwrite *zw, const char *text)
    178259{
    179   FILE *file;
    180260  char *filename, *logpath;
    181261  char *tobuff, *recip;
    182262  owl_message *m;
    183 
     263  GString *msgbuf;
    184264  /* create a present message so we can pass it to
    185265   * owl_log_shouldlog_message(void)
    … …  
    201281  /* expand ~ in path names */
    202282  logpath = owl_util_makepath(owl_global_get_logpath(&g));
    203 
    204283  filename = g_strdup_printf("%s/%s", logpath, tobuff);
    205   file=fopen(filename, "a");
    206   g_free(filename);
    207   if (!file) {
    208     owl_function_error("Unable to open file for outgoing logging");
    209     g_free(logpath);
    210     g_free(tobuff);
    211     return;
    212   }
    213   fprintf(file, "ERROR (owl): %s\n%s\n", tobuff, text);
    214   if (text[strlen(text)-1]!='\n') {
    215     fprintf(file, "\n");
    216   }
    217   fclose(file);
     284  msgbuf = g_string_new("");
     285  g_string_printf(msgbuf, "ERROR (owl): %s\n%s\n", tobuff, text);
     286  if (text[strlen(text)-1] != '\n') {
     287    g_string_append_printf(msgbuf, "\n");
     288  }
     289  owl_log_enqueue_message(msgbuf->str, filename);
     290  g_string_free(msgbuf, TRUE);
    218291
    219292  filename = g_strdup_printf("%s/all", logpath);
    220293  g_free(logpath);
    221   file=fopen(filename, "a");
    222   g_free(filename);
    223   if (!file) {
    224     owl_function_error("Unable to open file for outgoing logging");
    225     g_free(tobuff);
    226     return;
    227   }
    228   fprintf(file, "ERROR (owl): %s\n%s\n", tobuff, text);
    229   if (text[strlen(text)-1]!='\n') {
    230     fprintf(file, "\n");
    231   }
    232   fclose(file);
     294  msgbuf = g_string_new("");
     295  g_string_printf(msgbuf, "ERROR (owl): %s\n%s\n", tobuff, text);
     296  if (text[strlen(text)-1] != '\n') {
     297    g_string_append_printf(msgbuf, "\n");
     298  }
     299  owl_log_enqueue_message(msgbuf->str, filename);
     300  g_string_free(msgbuf, TRUE);
    233301
    234302  g_free(tobuff);
    … …  
    284352  } else if (owl_message_is_type_jabber(m)) {
    285353    if (personal) {
    286       from=frombuff=g_strdup_printf("jabber:%s",owl_message_get_sender(m));
    287     } else {
    288       from=frombuff=g_strdup_printf("jabber:%s",owl_message_get_recipient(m));
     354      from=frombuff=g_strdup_printf("jabber:%s",
     355                                    owl_message_get_sender(m));
     356    } else {
     357      from=frombuff=g_strdup_printf("jabber:%s",
     358                                    owl_message_get_recipient(m));
    289359    }
    290360  } else {
    … …  
    355425  g_free(logpath);
    356426}
     427
     428static gpointer owl_log_thread_func(gpointer data)
     429{
     430  log_context = g_main_context_new();
     431  log_loop = g_main_loop_new(log_context, FALSE);
     432  g_main_loop_run(log_loop);
     433  return NULL;
     434}
     435
     436void owl_log_init(void)
     437{
     438  GError *error = NULL;
     439  logging_thread = g_thread_create(owl_log_thread_func,
     440                                   NULL,
     441                                   TRUE,
     442                                   &error);
     443  if (error) {
     444    endwin();
     445    fprintf(stderr, "Error spawning logging thread: %s\n", error->message);
     446    fflush(stderr);
     447    exit(1);
     448  }
     449 
     450}
     451
     452static void owl_log_quit_func(gpointer data)
     453{
     454  g_main_loop_quit(log_loop);
     455}
     456
     457void owl_log_shutdown(void)
     458{
     459  owl_select_post_task(owl_log_quit_func, NULL,
     460                       NULL, log_context);
     461  g_thread_join(logging_thread);
     462}

  • owl.c

    r44976fe rcc305b5  
    611611  g_source_unref(source);
    612612
     613  owl_log_init();
     614
    613615  owl_function_debugmsg("startup: entering main loop");
    614616  owl_select_run_loop();
    … …  
    618620  owl_signal_shutdown();
    619621  owl_shutdown_curses();
     622  owl_log_shutdown();
    620623  return 0;
    621624}
Note: See TracChangeset for help on using the changeset viewer.