[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 | { |
---|
| 32 | owl_function_makemsg((const char*)data); |
---|
| 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 | |
---|
[cc305b5] | 107 | static void owl_log_entry_free(void *data) |
---|
| 108 | { |
---|
| 109 | owl_log_entry *msg = (owl_log_entry*)data; |
---|
| 110 | if (msg) { |
---|
| 111 | g_free(msg->message); |
---|
| 112 | g_free(msg->filename); |
---|
[7dcef03] | 113 | g_slice_free(owl_log_entry, msg); |
---|
[cc305b5] | 114 | } |
---|
| 115 | } |
---|
| 116 | |
---|
[ec36247] | 117 | #if GLIB_CHECK_VERSION(2, 32, 0) |
---|
| 118 | #else |
---|
| 119 | static void owl_log_entry_free_gfunc(gpointer data, gpointer user_data) |
---|
| 120 | { |
---|
| 121 | owl_log_entry_free(data); |
---|
| 122 | } |
---|
| 123 | #endif |
---|
| 124 | |
---|
[253f37f] | 125 | static void owl_log_file_error(owl_log_entry *msg, int errnum) |
---|
[77beb3c] | 126 | { |
---|
| 127 | owl_log_error("Unable to open file for logging: %s (file %s)", |
---|
[253f37f] | 128 | g_strerror(errnum), |
---|
[77beb3c] | 129 | msg->filename); |
---|
| 130 | } |
---|
| 131 | |
---|
[ec36247] | 132 | /* If we are deferring log messages, enqueue this entry for writing. |
---|
| 133 | * Otherwise, try to write this log message, and, if it fails with |
---|
[e6f21ea] | 134 | * EPERM, EACCES, or ETIMEDOUT, go into deferred logging mode and |
---|
| 135 | * queue an admin message. If it fails with anything else, display an |
---|
[8a06468] | 136 | * error message, drop the log message, and do not go into deferred |
---|
| 137 | * logging mode. |
---|
[89e4294] | 138 | * |
---|
| 139 | * N.B. This function is called only on the disk-writing thread. */ |
---|
[ec36247] | 140 | static void owl_log_eventually_write_entry(gpointer data) |
---|
| 141 | { |
---|
| 142 | int ret; |
---|
| 143 | owl_log_entry *msg = (owl_log_entry*)data; |
---|
| 144 | if (defer_logs) { |
---|
| 145 | owl_log_deferred_enqueue_message(msg->message, msg->filename); |
---|
| 146 | } else { |
---|
| 147 | ret = owl_log_try_write_entry(msg); |
---|
[e6f21ea] | 148 | if (ret == EPERM || ret == EACCES || ret == ETIMEDOUT) { |
---|
[ec36247] | 149 | defer_logs = true; |
---|
| 150 | owl_log_error("Unable to open file for logging (%s): \n" |
---|
| 151 | "%s. \n" |
---|
| 152 | "Consider renewing your tickets. Logging has been \n" |
---|
| 153 | "suspended, and your messages will be saved. To \n" |
---|
| 154 | "resume logging, use the command :flush-logs.\n\n", |
---|
| 155 | msg->filename, |
---|
| 156 | g_strerror(ret)); |
---|
[874fd19] | 157 | /* If we were not in deferred logging mode, either the queue should be |
---|
| 158 | * empty, or we are attempting to log a message that we just popped off |
---|
| 159 | * the head of the queue. Either way, we should enqueue this message as |
---|
| 160 | * the first message in the queue, rather than the last, so that we |
---|
| 161 | * preserve message ordering. */ |
---|
| 162 | owl_log_deferred_enqueue_first_message(msg->message, msg->filename); |
---|
[ec36247] | 163 | } else if (ret != 0) { |
---|
[77beb3c] | 164 | owl_log_file_error(msg, ret); |
---|
[ec36247] | 165 | } |
---|
| 166 | } |
---|
| 167 | } |
---|
| 168 | |
---|
[89e4294] | 169 | /* tries to write the deferred log entries |
---|
| 170 | * |
---|
| 171 | * N.B. This function is called only on the disk-writing thread. */ |
---|
[ec36247] | 172 | static void owl_log_write_deferred_entries(gpointer data) |
---|
| 173 | { |
---|
| 174 | owl_log_entry *entry; |
---|
[4511ac3] | 175 | owl_log_options *opts = (owl_log_options *)data; |
---|
[77beb3c] | 176 | int ret; |
---|
[604303c] | 177 | int logged_message_count = 0; |
---|
[edb14cc] | 178 | bool all_succeeded = true; |
---|
[ec36247] | 179 | |
---|
[4511ac3] | 180 | if (opts->display_initial_log_count) { |
---|
| 181 | if (g_queue_is_empty(deferred_entry_queue)) { |
---|
| 182 | owl_log_makemsg("There are no logs to flush."); |
---|
| 183 | } else { |
---|
| 184 | owl_log_makemsg("Attempting to flush %u logs...", |
---|
| 185 | g_queue_get_length(deferred_entry_queue)); |
---|
| 186 | } |
---|
[565a43c] | 187 | } |
---|
| 188 | |
---|
[ec36247] | 189 | defer_logs = false; |
---|
| 190 | while (!g_queue_is_empty(deferred_entry_queue) && !defer_logs) { |
---|
[604303c] | 191 | logged_message_count++; |
---|
[ec36247] | 192 | entry = (owl_log_entry*)g_queue_pop_head(deferred_entry_queue); |
---|
[4511ac3] | 193 | if (!opts->drop_failed_logs) { |
---|
[874fd19] | 194 | /* Attempt to write the log entry. If it fails, re-queue the entry at |
---|
| 195 | * the head of the queue. */ |
---|
[77beb3c] | 196 | owl_log_eventually_write_entry(entry); |
---|
| 197 | } else { |
---|
[874fd19] | 198 | /* Attempt to write the log entry. If it fails, print an error message, |
---|
| 199 | * drop the log, and keep going through the queue. */ |
---|
[77beb3c] | 200 | ret = owl_log_try_write_entry(entry); |
---|
| 201 | if (ret != 0) { |
---|
[edb14cc] | 202 | all_succeeded = false; |
---|
[77beb3c] | 203 | owl_log_file_error(entry, ret); |
---|
| 204 | } |
---|
| 205 | } |
---|
[ec36247] | 206 | owl_log_entry_free(entry); |
---|
| 207 | } |
---|
[565a43c] | 208 | if (logged_message_count > 0) { |
---|
[4511ac3] | 209 | if (opts->display_initial_log_count) { |
---|
| 210 | /* first clear the "attempting to flush" message from the status bar */ |
---|
| 211 | owl_log_makemsg(""); |
---|
| 212 | } |
---|
[565a43c] | 213 | if (!defer_logs) { |
---|
| 214 | if (all_succeeded) { |
---|
| 215 | owl_log_adminmsg("Flushed %d logs and resumed logging.", |
---|
| 216 | logged_message_count); |
---|
| 217 | } else { |
---|
| 218 | owl_log_adminmsg("Flushed or dropped %d logs and resumed logging.", |
---|
| 219 | logged_message_count); |
---|
| 220 | } |
---|
| 221 | } else { |
---|
| 222 | owl_log_error("Attempted to flush %d logs; %u deferred logs remain.", |
---|
| 223 | logged_message_count, g_queue_get_length(deferred_entry_queue)); |
---|
| 224 | } |
---|
[edb14cc] | 225 | } |
---|
[ec36247] | 226 | } |
---|
| 227 | |
---|
[4511ac3] | 228 | void owl_log_flush_logs(bool drop_failed_logs, bool quiet) |
---|
[ec36247] | 229 | { |
---|
[4511ac3] | 230 | owl_log_options *data = g_new(owl_log_options, 1); |
---|
| 231 | data->drop_failed_logs = drop_failed_logs; |
---|
| 232 | data->display_initial_log_count = !quiet; |
---|
[77beb3c] | 233 | |
---|
| 234 | owl_select_post_task(owl_log_write_deferred_entries, |
---|
| 235 | data, |
---|
| 236 | g_free, |
---|
| 237 | log_context); |
---|
[ec36247] | 238 | } |
---|
| 239 | |
---|
[cc305b5] | 240 | void owl_log_enqueue_message(const char *buffer, const char *filename) |
---|
| 241 | { |
---|
[ec36247] | 242 | owl_log_entry *log_msg = owl_log_new_entry(buffer, filename); |
---|
| 243 | owl_select_post_task(owl_log_eventually_write_entry, log_msg, |
---|
[cc305b5] | 244 | owl_log_entry_free, log_context); |
---|
[42947f1] | 245 | } |
---|
| 246 | |
---|
[24ccc01] | 247 | void owl_log_outgoing_zephyr_error(const owl_zwrite *zw, const char *text) |
---|
[2b86d14] | 248 | { |
---|
[5093c6f] | 249 | owl_message *m = g_slice_new(owl_message); |
---|
[e5da3fe] | 250 | /* recip_index = 0 because there can only be one recipient anyway */ |
---|
| 251 | owl_message_create_from_zwrite(m, zw, text, 0); |
---|
[5093c6f] | 252 | g_free(owl_perlconfig_call_with_message("BarnOwl::Logging::log_outgoing_error", m)); |
---|
[9bfab40] | 253 | owl_message_delete(m); |
---|
[2b86d14] | 254 | } |
---|
| 255 | |
---|
[cc305b5] | 256 | static gpointer owl_log_thread_func(gpointer data) |
---|
| 257 | { |
---|
[ec36247] | 258 | log_context = g_main_context_new(); |
---|
[cc305b5] | 259 | log_loop = g_main_loop_new(log_context, FALSE); |
---|
| 260 | g_main_loop_run(log_loop); |
---|
| 261 | return NULL; |
---|
| 262 | } |
---|
| 263 | |
---|
[ec36247] | 264 | void owl_log_init(void) |
---|
[cc305b5] | 265 | { |
---|
[0a9ffc5] | 266 | log_context = g_main_context_new(); |
---|
[0792d99] | 267 | #if GLIB_CHECK_VERSION(2, 31, 0) |
---|
| 268 | logging_thread = g_thread_new("logging", |
---|
| 269 | owl_log_thread_func, |
---|
| 270 | NULL); |
---|
| 271 | #else |
---|
| 272 | GError *error = NULL; |
---|
[cc305b5] | 273 | logging_thread = g_thread_create(owl_log_thread_func, |
---|
| 274 | NULL, |
---|
| 275 | TRUE, |
---|
| 276 | &error); |
---|
| 277 | if (error) { |
---|
| 278 | endwin(); |
---|
| 279 | fprintf(stderr, "Error spawning logging thread: %s\n", error->message); |
---|
| 280 | fflush(stderr); |
---|
| 281 | exit(1); |
---|
| 282 | } |
---|
[0792d99] | 283 | #endif |
---|
[ec36247] | 284 | |
---|
| 285 | deferred_entry_queue = g_queue_new(); |
---|
[cc305b5] | 286 | } |
---|
| 287 | |
---|
| 288 | static void owl_log_quit_func(gpointer data) |
---|
| 289 | { |
---|
[ec36247] | 290 | /* flush the deferred logs queue, trying to write the |
---|
[77beb3c] | 291 | * entries to the disk one last time. Drop any failed |
---|
[4511ac3] | 292 | * entries, and be quiet about it. */ |
---|
| 293 | owl_log_options opts; |
---|
| 294 | opts.drop_failed_logs = true; |
---|
| 295 | opts.display_initial_log_count = false; |
---|
| 296 | owl_log_write_deferred_entries(&opts); |
---|
[ec36247] | 297 | #if GLIB_CHECK_VERSION(2, 32, 0) |
---|
| 298 | g_queue_free_full(deferred_entry_queue, owl_log_entry_free); |
---|
| 299 | #else |
---|
| 300 | g_queue_foreach(deferred_entry_queue, owl_log_entry_free_gfunc, NULL); |
---|
| 301 | g_queue_free(deferred_entry_queue); |
---|
| 302 | #endif |
---|
| 303 | |
---|
[cc305b5] | 304 | g_main_loop_quit(log_loop); |
---|
| 305 | } |
---|
| 306 | |
---|
| 307 | void owl_log_shutdown(void) |
---|
| 308 | { |
---|
| 309 | owl_select_post_task(owl_log_quit_func, NULL, |
---|
| 310 | NULL, log_context); |
---|
| 311 | g_thread_join(logging_thread); |
---|
| 312 | } |
---|