[7d4fbcd] | 1 | #include "owl.h" |
---|
[f271129] | 2 | #include <stdio.h> |
---|
[7d4fbcd] | 3 | |
---|
[cc305b5] | 4 | typedef struct _owl_log_entry { /* noproto */ |
---|
| 5 | char *filename; |
---|
| 6 | char *message; |
---|
| 7 | } owl_log_entry; |
---|
| 8 | |
---|
[4511ac3] | 9 | typedef struct _owl_log_options { /* noproto */ |
---|
| 10 | bool drop_failed_logs; |
---|
| 11 | bool display_initial_log_count; |
---|
| 12 | } owl_log_options; |
---|
[cc305b5] | 13 | |
---|
| 14 | static GMainContext *log_context; |
---|
| 15 | static GMainLoop *log_loop; |
---|
| 16 | static GThread *logging_thread; |
---|
[89e4294] | 17 | static bool defer_logs; /* to be accessed only on the disk-writing thread */ |
---|
[ec36247] | 18 | static GQueue *deferred_entry_queue; |
---|
[cc305b5] | 19 | |
---|
| 20 | static void owl_log_error_main_thread(gpointer data) |
---|
| 21 | { |
---|
| 22 | owl_function_error("%s", (const char*)data); |
---|
[42947f1] | 23 | } |
---|
| 24 | |
---|
[edb14cc] | 25 | static void owl_log_adminmsg_main_thread(gpointer data) |
---|
| 26 | { |
---|
| 27 | owl_function_adminmsg("Logging", (const char*)data); |
---|
| 28 | } |
---|
| 29 | |
---|
[565a43c] | 30 | static void owl_log_makemsg_main_thread(gpointer data) |
---|
| 31 | { |
---|
[f4287ad] | 32 | owl_function_makemsg("%s", (const char*)data); |
---|
[565a43c] | 33 | } |
---|
| 34 | |
---|
[e47e1b0] | 35 | static void G_GNUC_PRINTF(1, 2) owl_log_error(const char *fmt, ...) |
---|
[cc305b5] | 36 | { |
---|
[e47e1b0] | 37 | va_list ap; |
---|
| 38 | char *data; |
---|
| 39 | |
---|
| 40 | va_start(ap, fmt); |
---|
| 41 | data = g_strdup_vprintf(fmt, ap); |
---|
| 42 | va_end(ap); |
---|
| 43 | |
---|
[cc305b5] | 44 | owl_select_post_task(owl_log_error_main_thread, |
---|
[e47e1b0] | 45 | data, g_free, g_main_context_default()); |
---|
[42947f1] | 46 | } |
---|
| 47 | |
---|
[edb14cc] | 48 | static void G_GNUC_PRINTF(1, 2) owl_log_adminmsg(const char *fmt, ...) |
---|
| 49 | { |
---|
| 50 | va_list ap; |
---|
| 51 | char *data; |
---|
| 52 | |
---|
| 53 | va_start(ap, fmt); |
---|
| 54 | data = g_strdup_vprintf(fmt, ap); |
---|
| 55 | va_end(ap); |
---|
| 56 | |
---|
| 57 | owl_select_post_task(owl_log_adminmsg_main_thread, |
---|
| 58 | data, g_free, g_main_context_default()); |
---|
| 59 | } |
---|
| 60 | |
---|
[565a43c] | 61 | static void G_GNUC_PRINTF(1, 2) owl_log_makemsg(const char *fmt, ...) |
---|
| 62 | { |
---|
| 63 | va_list ap; |
---|
| 64 | char *data; |
---|
| 65 | |
---|
| 66 | va_start(ap, fmt); |
---|
| 67 | data = g_strdup_vprintf(fmt, ap); |
---|
| 68 | va_end(ap); |
---|
| 69 | |
---|
| 70 | owl_select_post_task(owl_log_makemsg_main_thread, |
---|
| 71 | data, g_free, g_main_context_default()); |
---|
| 72 | } |
---|
| 73 | |
---|
[ec36247] | 74 | static CALLER_OWN owl_log_entry *owl_log_new_entry(const char *buffer, const char *filename) |
---|
| 75 | { |
---|
| 76 | owl_log_entry *log_msg = g_slice_new(owl_log_entry); |
---|
| 77 | log_msg->message = g_strdup(buffer); |
---|
| 78 | log_msg->filename = g_strdup(filename); |
---|
| 79 | return log_msg; |
---|
| 80 | } |
---|
| 81 | |
---|
| 82 | static void owl_log_deferred_enqueue_message(const char *buffer, const char *filename) |
---|
| 83 | { |
---|
| 84 | g_queue_push_tail(deferred_entry_queue, owl_log_new_entry(buffer, filename)); |
---|
| 85 | } |
---|
| 86 | |
---|
[874fd19] | 87 | static void owl_log_deferred_enqueue_first_message(const char *buffer, const char *filename) |
---|
| 88 | { |
---|
| 89 | g_queue_push_head(deferred_entry_queue, owl_log_new_entry(buffer, filename)); |
---|
| 90 | } |
---|
| 91 | |
---|
[ec36247] | 92 | /* write out the entry if possible |
---|
| 93 | * return 0 on success, errno on failure to open |
---|
| 94 | */ |
---|
| 95 | static int owl_log_try_write_entry(owl_log_entry *msg) |
---|
[cc305b5] | 96 | { |
---|
| 97 | FILE *file = NULL; |
---|
| 98 | file = fopen(msg->filename, "a"); |
---|
| 99 | if (!file) { |
---|
[ec36247] | 100 | return errno; |
---|
[cc305b5] | 101 | } |
---|
| 102 | fprintf(file, "%s", msg->message); |
---|
| 103 | fclose(file); |
---|
[ec36247] | 104 | return 0; |
---|
[42947f1] | 105 | } |
---|
| 106 | |
---|
[0c059f0] | 107 | static void owl_log_entry_delete(void *data) |
---|
[cc305b5] | 108 | { |
---|
| 109 | owl_log_entry *msg = (owl_log_entry*)data; |
---|
[0c059f0] | 110 | g_free(msg->message); |
---|
| 111 | g_free(msg->filename); |
---|
| 112 | g_slice_free(owl_log_entry, msg); |
---|
[cc305b5] | 113 | } |
---|
| 114 | |
---|
[ec36247] | 115 | #if GLIB_CHECK_VERSION(2, 32, 0) |
---|
| 116 | #else |
---|
[0c059f0] | 117 | static void owl_log_entry_delete_gfunc(gpointer data, gpointer user_data) |
---|
[ec36247] | 118 | { |
---|
[0c059f0] | 119 | owl_log_entry_delete(data); |
---|
[ec36247] | 120 | } |
---|
| 121 | #endif |
---|
| 122 | |
---|
[253f37f] | 123 | static void owl_log_file_error(owl_log_entry *msg, int errnum) |
---|
[77beb3c] | 124 | { |
---|
| 125 | owl_log_error("Unable to open file for logging: %s (file %s)", |
---|
[253f37f] | 126 | g_strerror(errnum), |
---|
[77beb3c] | 127 | msg->filename); |
---|
| 128 | } |
---|
| 129 | |
---|
[ec36247] | 130 | /* If we are deferring log messages, enqueue this entry for writing. |
---|
| 131 | * Otherwise, try to write this log message, and, if it fails with |
---|
[e6f21ea] | 132 | * EPERM, EACCES, or ETIMEDOUT, go into deferred logging mode and |
---|
| 133 | * queue an admin message. If it fails with anything else, display an |
---|
[8a06468] | 134 | * error message, drop the log message, and do not go into deferred |
---|
| 135 | * logging mode. |
---|
[89e4294] | 136 | * |
---|
| 137 | * N.B. This function is called only on the disk-writing thread. */ |
---|
[ec36247] | 138 | static void owl_log_eventually_write_entry(gpointer data) |
---|
| 139 | { |
---|
| 140 | int ret; |
---|
| 141 | owl_log_entry *msg = (owl_log_entry*)data; |
---|
| 142 | if (defer_logs) { |
---|
| 143 | owl_log_deferred_enqueue_message(msg->message, msg->filename); |
---|
| 144 | } else { |
---|
| 145 | ret = owl_log_try_write_entry(msg); |
---|
[e6f21ea] | 146 | if (ret == EPERM || ret == EACCES || ret == ETIMEDOUT) { |
---|
[ec36247] | 147 | defer_logs = true; |
---|
| 148 | owl_log_error("Unable to open file for logging (%s): \n" |
---|
| 149 | "%s. \n" |
---|
| 150 | "Consider renewing your tickets. Logging has been \n" |
---|
| 151 | "suspended, and your messages will be saved. To \n" |
---|
| 152 | "resume logging, use the command :flush-logs.\n\n", |
---|
| 153 | msg->filename, |
---|
| 154 | g_strerror(ret)); |
---|
[874fd19] | 155 | /* If we were not in deferred logging mode, either the queue should be |
---|
| 156 | * empty, or we are attempting to log a message that we just popped off |
---|
| 157 | * the head of the queue. Either way, we should enqueue this message as |
---|
| 158 | * the first message in the queue, rather than the last, so that we |
---|
| 159 | * preserve message ordering. */ |
---|
| 160 | owl_log_deferred_enqueue_first_message(msg->message, msg->filename); |
---|
[ec36247] | 161 | } else if (ret != 0) { |
---|
[77beb3c] | 162 | owl_log_file_error(msg, ret); |
---|
[ec36247] | 163 | } |
---|
| 164 | } |
---|
| 165 | } |
---|
| 166 | |
---|
[89e4294] | 167 | /* tries to write the deferred log entries |
---|
| 168 | * |
---|
| 169 | * N.B. This function is called only on the disk-writing thread. */ |
---|
[ec36247] | 170 | static void owl_log_write_deferred_entries(gpointer data) |
---|
| 171 | { |
---|
| 172 | owl_log_entry *entry; |
---|
[4511ac3] | 173 | owl_log_options *opts = (owl_log_options *)data; |
---|
[77beb3c] | 174 | int ret; |
---|
[604303c] | 175 | int logged_message_count = 0; |
---|
[edb14cc] | 176 | bool all_succeeded = true; |
---|
[ec36247] | 177 | |
---|
[4511ac3] | 178 | if (opts->display_initial_log_count) { |
---|
| 179 | if (g_queue_is_empty(deferred_entry_queue)) { |
---|
| 180 | owl_log_makemsg("There are no logs to flush."); |
---|
| 181 | } else { |
---|
| 182 | owl_log_makemsg("Attempting to flush %u logs...", |
---|
| 183 | g_queue_get_length(deferred_entry_queue)); |
---|
| 184 | } |
---|
[565a43c] | 185 | } |
---|
| 186 | |
---|
[ec36247] | 187 | defer_logs = false; |
---|
| 188 | while (!g_queue_is_empty(deferred_entry_queue) && !defer_logs) { |
---|
[604303c] | 189 | logged_message_count++; |
---|
[ec36247] | 190 | entry = (owl_log_entry*)g_queue_pop_head(deferred_entry_queue); |
---|
[4511ac3] | 191 | if (!opts->drop_failed_logs) { |
---|
[874fd19] | 192 | /* Attempt to write the log entry. If it fails, re-queue the entry at |
---|
| 193 | * the head of the queue. */ |
---|
[77beb3c] | 194 | owl_log_eventually_write_entry(entry); |
---|
| 195 | } else { |
---|
[874fd19] | 196 | /* Attempt to write the log entry. If it fails, print an error message, |
---|
| 197 | * drop the log, and keep going through the queue. */ |
---|
[77beb3c] | 198 | ret = owl_log_try_write_entry(entry); |
---|
| 199 | if (ret != 0) { |
---|
[edb14cc] | 200 | all_succeeded = false; |
---|
[77beb3c] | 201 | owl_log_file_error(entry, ret); |
---|
| 202 | } |
---|
| 203 | } |
---|
[0c059f0] | 204 | owl_log_entry_delete(entry); |
---|
[ec36247] | 205 | } |
---|
[565a43c] | 206 | if (logged_message_count > 0) { |
---|
[4511ac3] | 207 | if (opts->display_initial_log_count) { |
---|
| 208 | /* first clear the "attempting to flush" message from the status bar */ |
---|
| 209 | owl_log_makemsg(""); |
---|
| 210 | } |
---|
[565a43c] | 211 | if (!defer_logs) { |
---|
| 212 | if (all_succeeded) { |
---|
| 213 | owl_log_adminmsg("Flushed %d logs and resumed logging.", |
---|
| 214 | logged_message_count); |
---|
| 215 | } else { |
---|
| 216 | owl_log_adminmsg("Flushed or dropped %d logs and resumed logging.", |
---|
| 217 | logged_message_count); |
---|
| 218 | } |
---|
| 219 | } else { |
---|
| 220 | owl_log_error("Attempted to flush %d logs; %u deferred logs remain.", |
---|
| 221 | logged_message_count, g_queue_get_length(deferred_entry_queue)); |
---|
| 222 | } |
---|
[edb14cc] | 223 | } |
---|
[ec36247] | 224 | } |
---|
| 225 | |
---|
[4511ac3] | 226 | void owl_log_flush_logs(bool drop_failed_logs, bool quiet) |
---|
[ec36247] | 227 | { |
---|
[4511ac3] | 228 | owl_log_options *data = g_new(owl_log_options, 1); |
---|
| 229 | data->drop_failed_logs = drop_failed_logs; |
---|
| 230 | data->display_initial_log_count = !quiet; |
---|
[77beb3c] | 231 | |
---|
| 232 | owl_select_post_task(owl_log_write_deferred_entries, |
---|
| 233 | data, |
---|
| 234 | g_free, |
---|
| 235 | log_context); |
---|
[ec36247] | 236 | } |
---|
| 237 | |
---|
[cc305b5] | 238 | void owl_log_enqueue_message(const char *buffer, const char *filename) |
---|
| 239 | { |
---|
[ec36247] | 240 | owl_log_entry *log_msg = owl_log_new_entry(buffer, filename); |
---|
| 241 | owl_select_post_task(owl_log_eventually_write_entry, log_msg, |
---|
[0c059f0] | 242 | owl_log_entry_delete, log_context); |
---|
[42947f1] | 243 | } |
---|
| 244 | |
---|
[24ccc01] | 245 | void owl_log_outgoing_zephyr_error(const owl_zwrite *zw, const char *text) |
---|
[2b86d14] | 246 | { |
---|
[5093c6f] | 247 | owl_message *m = g_slice_new(owl_message); |
---|
[e5da3fe] | 248 | /* recip_index = 0 because there can only be one recipient anyway */ |
---|
| 249 | owl_message_create_from_zwrite(m, zw, text, 0); |
---|
[5093c6f] | 250 | g_free(owl_perlconfig_call_with_message("BarnOwl::Logging::log_outgoing_error", m)); |
---|
[9bfab40] | 251 | owl_message_delete(m); |
---|
[2b86d14] | 252 | } |
---|
| 253 | |
---|
[cc305b5] | 254 | static gpointer owl_log_thread_func(gpointer data) |
---|
| 255 | { |
---|
[ec36247] | 256 | log_context = g_main_context_new(); |
---|
[cc305b5] | 257 | log_loop = g_main_loop_new(log_context, FALSE); |
---|
| 258 | g_main_loop_run(log_loop); |
---|
| 259 | return NULL; |
---|
| 260 | } |
---|
| 261 | |
---|
[ec36247] | 262 | void owl_log_init(void) |
---|
[cc305b5] | 263 | { |
---|
[0a9ffc5] | 264 | log_context = g_main_context_new(); |
---|
[0792d99] | 265 | #if GLIB_CHECK_VERSION(2, 31, 0) |
---|
| 266 | logging_thread = g_thread_new("logging", |
---|
| 267 | owl_log_thread_func, |
---|
| 268 | NULL); |
---|
| 269 | #else |
---|
| 270 | GError *error = NULL; |
---|
[cc305b5] | 271 | logging_thread = g_thread_create(owl_log_thread_func, |
---|
| 272 | NULL, |
---|
| 273 | TRUE, |
---|
| 274 | &error); |
---|
| 275 | if (error) { |
---|
| 276 | endwin(); |
---|
| 277 | fprintf(stderr, "Error spawning logging thread: %s\n", error->message); |
---|
| 278 | fflush(stderr); |
---|
| 279 | exit(1); |
---|
| 280 | } |
---|
[0792d99] | 281 | #endif |
---|
[ec36247] | 282 | |
---|
| 283 | deferred_entry_queue = g_queue_new(); |
---|
[cc305b5] | 284 | } |
---|
| 285 | |
---|
| 286 | static void owl_log_quit_func(gpointer data) |
---|
| 287 | { |
---|
[ec36247] | 288 | /* flush the deferred logs queue, trying to write the |
---|
[77beb3c] | 289 | * entries to the disk one last time. Drop any failed |
---|
[4511ac3] | 290 | * entries, and be quiet about it. */ |
---|
| 291 | owl_log_options opts; |
---|
| 292 | opts.drop_failed_logs = true; |
---|
| 293 | opts.display_initial_log_count = false; |
---|
| 294 | owl_log_write_deferred_entries(&opts); |
---|
[ec36247] | 295 | #if GLIB_CHECK_VERSION(2, 32, 0) |
---|
[0c059f0] | 296 | g_queue_free_full(deferred_entry_queue, owl_log_entry_delete); |
---|
[ec36247] | 297 | #else |
---|
[0c059f0] | 298 | g_queue_foreach(deferred_entry_queue, owl_log_entry_delete_gfunc, NULL); |
---|
[ec36247] | 299 | g_queue_free(deferred_entry_queue); |
---|
| 300 | #endif |
---|
| 301 | |
---|
[cc305b5] | 302 | g_main_loop_quit(log_loop); |
---|
| 303 | } |
---|
| 304 | |
---|
| 305 | void owl_log_shutdown(void) |
---|
| 306 | { |
---|
| 307 | owl_select_post_task(owl_log_quit_func, NULL, |
---|
| 308 | NULL, log_context); |
---|
| 309 | g_thread_join(logging_thread); |
---|
| 310 | } |
---|