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