nicer logging (always show pid, timestamp)

3 files changed, 38 insertions, 15 deletions

diff --git a/main.c b/main.c
index 8cdba9d..df50932 100644
--- a/main.c
+++ b/main.c
@@ -350,6 +350,8 @@ int main(int argc, char **argv) {
 		die("Not enough memory available to run ted.");
 	}
 	ted->last_save_time = -1e50;
+	ted->pid = process_get_id();
+	ted_update_time(ted);
 	
 	// make sure signal handler has access to ted.
 	error_signal_handler_ted = ted;
@@ -395,7 +397,6 @@ int main(int argc, char **argv) {
 
 	{
 		// open log file
-		FILE *log = NULL;
 		char log_filename[TED_PATH_MAX];
 		char log1_filename[TED_PATH_MAX];
 		strbuf_printf(log_filename, "%s/log.txt", ted->local_data_dir);
@@ -404,10 +405,8 @@ int main(int argc, char **argv) {
 			remove(log1_filename);
 			rename(log_filename, log1_filename);
 		}
-		log = fopen(log_filename, "a");
-		setbuf(log, NULL);
-		fprintf(log, "---- (starting ted, pid = %d) ----\n", process_get_id());
-		ted->log = log;
+		ted->log = fopen(log_filename, "a");
+		ted_log(ted, "starting ted\n");
 	}
 
 	{ // get current working directory
@@ -608,8 +607,8 @@ int main(int argc, char **argv) {
 	double scroll_wheel_text_size_change = 0.0;
 	
 	while (!ted->quit) {
-		double frame_start = time_get_seconds();
-		ted->frame_time = frame_start;
+		ted_update_time(ted);
+		double frame_start = ted->frame_time;
 
 		SDL_PumpEvents();
 		u32 key_modifier = ted_get_key_modifier(ted);		
@@ -906,7 +905,10 @@ int main(int argc, char **argv) {
 				case LSP_RESPONSE: {
 					LSPResponse *r = &message.response;
 					if (!lsp_string_is_empty(r->error)) {
-						ted_error(ted, "LSP error: %s", lsp_response_string(r, r->error));
+						ted_log(ted, "LSP error: %s\n", lsp_response_string(r, r->error));
+						// this is a bit spammy
+						// sometimes clang is just like "this request was cancelled cuz the cursor moved"
+						//ted_error(ted, "LSP error: %s", lsp_response_string(r, r->error));
 					} else {
 						// it's important that we send error responses here too.
 						// we don't want to be waiting around for a response that's never coming.
diff --git a/ted-internal.h b/ted-internal.h
index 0efa6b6..2a6eb27 100644
--- a/ted-internal.h
+++ b/ted-internal.h
@@ -265,6 +265,8 @@ struct Ted {
 	LSP *lsps[TED_LSP_MAX + 1];
 	/// current time (see time_get_seconds), as of the start of this frame
 	double frame_time;
+	/// current time as a human readable string (used for logs)
+	char frame_time_string[64];
 	
 	Macro *macros;
 	Macro *recording_macro;
@@ -345,6 +347,8 @@ struct Ted {
 	Usages *usages;
 	RenameSymbol *rename_symbol;
 	Formatting *formatting;
+	/// process ID
+	int pid;
 	
 	FILE *log;
 	
@@ -708,6 +712,8 @@ void syntax_quit(void);
 SymbolInfo *tags_get_symbols(Ted *ted);
 
 // === ted.c ===
+/// update `ted->frame_time`
+void ted_update_time(Ted *ted);
 /// set ted's active buffer to something nice
 void ted_reset_active_buffer(Ted *ted);
 /// set ted's error message to the buffer's error.
diff --git a/ted.c b/ted.c
index 3c09f01..d1db1fb 100644
--- a/ted.c
+++ b/ted.c
@@ -39,11 +39,19 @@ static void ted_vset_message(Ted *ted, MessageType type, const char *fmt, va_lis
 	vsnprintf(message, sizeof message - 1, fmt, args);
 	
 	// output error to log file
-	char tstr[256];
-	time_t t = time(NULL);
-	struct tm *tm = localtime(&t);
-	strftime(tstr, sizeof tstr, "%Y-%m-%d %H:%M:%S", tm);
-	ted_log(ted, "[ERROR %s] %s\n", tstr, message);
+	const char *type_str = "";
+	switch (type) {
+	case MESSAGE_ERROR:
+		type_str = "ERROR";
+		break;
+	case MESSAGE_WARNING:
+		type_str = "WARNING";
+		break;
+	case MESSAGE_INFO:
+		type_str = "INFO";
+		break;
+	}
+	ted_log(ted, "%s: %s\n", type_str, message);
 	
 	if (type >= ted->message_type) {
 		ted->message_type = type;
@@ -51,6 +59,13 @@ static void ted_vset_message(Ted *ted, MessageType type, const char *fmt, va_lis
 	}
 }
 
+void ted_update_time(Ted *ted) {
+	time_t t = time(NULL);
+	struct tm *tm = localtime(&t);
+	strftime(ted->frame_time_string, sizeof ted->frame_time_string, "%Y-%m-%d %H:%M:%S", tm);
+	ted->frame_time = time_get_seconds();
+}
+
 TextBuffer *ted_active_buffer(Ted *ted) {
 	return ted->active_buffer;
 }
@@ -146,8 +161,10 @@ void ted_log(Ted *ted, const char *fmt, ...) {
 	
 	va_list args;
 	va_start(args, fmt);
+	fprintf(ted->log, "[pid %d, %s] ", ted->pid, ted->frame_time_string);
 	vfprintf(ted->log, fmt, args);
 	va_end(args);
+	fflush(ted->log);
 }
 
 
@@ -796,7 +813,6 @@ static void mark_node_reachable(Ted *ted, Node *node, bool *reachable) {
 	if (i < 0) return;
 	if (reachable[i]) {
 		ted_error(ted, "Node %d reachable in 2 different ways\nThis should never happen.", i);
-		ted_log(ted, "Node %d reachable in 2 different ways\n", i);
 		node_close(ted, node);
 		return;
 	}
@@ -814,7 +830,6 @@ void ted_check_for_node_problems(Ted *ted) {
 	for (u32 i = 0; i < arr_len(ted->nodes); ++i) {
 		if (!reachable[i]) {
 			ted_error(ted, "ORPHANED NODE %u\nThis should never happen.", i);
-			ted_log(ted, "ORPHANED NODE %u\n", i);
 			node_close(ted, ted->nodes[i]);
 			--i;
 		}