1 /* This file is part of the Spring engine (GPL v2 or later), see LICENSE.html */
2 
3 
4 #ifdef SYNCDEBUG
5 
6 #include <assert.h>
7 #include <errno.h>
8 #include <stdarg.h>
9 #include <string.h>
10 #include <sstream>
11 #include <time.h>
12 #include <sys/types.h>
13 #include <sys/stat.h>
14 #include "Logger.h"
15 #include "System/Util.h"
16 #include "System/SafeCStrings.h"
17 
18 
19 #ifdef WIN32
20 // msvcrt doesn't have thread safe ctime_r
21 # define ctime_r(tm, buf) ctime(tm)
22 # ifdef _MSC_VER
23 // MSVC doesn't have popen/pclose, but it's not needed anyway,
24 // as addr2line isn't available for MSVC compiled executables.
25 #  define popen(cmd, mode) (NULL)
26 #  define pclose(p)
27 # endif
28 #endif
29 
30 extern "C" void get_executable_name(char *output, int size);
31 
32 
33 /**
34  * @brief name of the addr2line binary
35  */
36 #define ADDR2LINE "addr2line"
37 
38 
39 /**
40  * @brief name of the c++filt binary
41  *
42  * Only used on MinGW to work around an addr2line bug.
43  */
44 #define CPPFILT "c++filt"
45 
46 
47 /**
48  * @brief log function
49  *
50  * Write a printf-style formatted message to the temporary logfile buffer.
51  * (which is later to be filtered through addr2line)
52  *
53  * The filtering is done by taking everything between { and } as being a
54  * hexadecimal address into the executable. This address is literally passed
55  * to addr2line, which converts it to a function, filename & line number.
56  * The "{...}" string is then fully replaced by "function [filename:lineno]".
57  */
AddLine(const char * fmt,...)58 void CLogger::AddLine(const char* fmt, ...)
59 {
60 	boost::mutex::scoped_lock scoped_lock(logmutex);
61 	char buf[500]; // same size as buffer in infolog
62 
63 	va_list argp;
64 	va_start(argp, fmt);
65 	VSNPRINTF(buf, sizeof(buf), fmt, argp);
66 	buf[sizeof(buf) - 1] = 0;
67 	va_end(argp);
68 
69 	buffer.push_back(buf);
70 
71 	// Buffer size is 2900 because that makes about the largest commandline
72 	// we can pass to addr2line on systems limiting the commandline to 32k
73 	// characters. (11 bytes per hexadecimal address gives 2900*11 = 31900)
74 	if (buffer.size() >= 2900)
75 		FlushBuffer();
76 }
77 
78 
79 /**
80  * @brief close one logging session
81  *
82  * Writes the buffered data to file after filtering it through addr2line.
83  */
CloseSession()84 void CLogger::CloseSession()
85 {
86 	boost::mutex::scoped_lock scoped_lock(logmutex);
87 
88 	if (logfile || !buffer.empty()) {
89 		FlushBuffer();
90 		fclose(logfile);
91 		logfile = NULL;
92 	}
93 }
94 
95 
96 /**
97  * @brief flushes the buffer
98  *
99  * This is the actual worker function. It opens the log file if it wasn't yet
100  * open, composes the addr2line commandline, pipes the buffer through it and
101  * writes the output of that - after some formatting - to the real logfile.
102  */
FlushBuffer()103 void CLogger::FlushBuffer()
104 {
105 	char buf1[4096], buf2[4096];
106 	char* nl;
107 
108 	// Open logfile if it's not open.
109 
110 	if (!logfile) {
111 		assert(filename);
112 		if (!(logfile = fopen(filename, "a")))
113 			return;
114 
115 		time_t t;
116 		time(&t);
117 		char* ct = ctime_r(&t, buf1);
118 		if ((nl = strchr(ct, '\n'))) *nl = 0;
119 		fprintf(logfile, "\n===> %s <===\n", ct);
120 	}
121 
122 	// Get executable name if we didn't have it yet.
123 
124 	if (exename.empty()) {
125 		get_executable_name(buf1, sizeof(buf1));
126 		int len = strlen(buf1);
127 		strncpy(buf2, buf1, sizeof(buf2));
128 		buf2[sizeof(buf2)-1] = '\0'; // make sure the string is terminated
129 		if (len > 4 && buf2[len-4] == '.')
130 			buf2[len-4] = 0;
131 		// NOTE STRCAT_T: will always terminate destination with '/0'
132 		//   2nd param: destination buffer size
133 		STRCAT_T(buf2, sizeof(buf2), ".dbg");
134 
135 		fprintf(logfile, "trying debug symbols file: '%s'\n", buf2);
136 
137 		struct stat tmp;
138 		if (stat(buf2, &tmp) == 0) {
139 			exename = buf2;
140 		} else {
141 			exename = buf1;
142 		}
143 
144 		if (exename.empty())
145 			return;
146 		fprintf(logfile, "executable name: '%s'\n", exename.c_str());
147 	}
148 
149 	// Compose addr2line command.
150 
151 	std::stringstream command;
152 	std::vector<std::string>::iterator it;
153 	bool runTheCommand = false;
154 
155 	command << ADDR2LINE << " \"--exe=" << exename << "\" --functions --demangle --inline";
156 
157 	for (it = buffer.begin(); it != buffer.end(); ++it) {
158 		const int open = it->find('{');
159 		const int close = it->find('}', open + 1);
160 		if (open != std::string::npos && close != std::string::npos) {
161 			command << " " << it->substr(open + 1, close - open - 1);
162 			runTheCommand = true;
163 		}
164 	}
165 
166 	if (runTheCommand) {
167 		// We got some addresses, so run the addr2line command.
168 		// (This is usually the branch taken by the host)
169 
170 		fprintf(logfile, "addr2line command : '%s'\n", command.str().c_str());
171 
172 		// Open pipe to the addr2line command.
173 
174 		FILE* p = popen(command.str().c_str(), "r");
175 
176 		if (!p) {
177 			fprintf(logfile, "  %s\n", strerror(errno));
178 			runTheCommand = false;
179 		} else {
180 			// Pipe the buffer through the addr2line command.
181 			for (it = buffer.begin(); it != buffer.end(); ++it) {
182 				const int open = it->find('{');
183 				const int close = it->find('}', open + 1);
184 				if (open != std::string::npos && close != std::string::npos) {
185 					fgets(buf1, sizeof(buf1), p);
186 					fgets(buf2, sizeof(buf2), p);
187 					CppFilt(buf1, sizeof(buf1));
188 					if ((nl = strchr(buf1, '\n'))) *nl = 0;
189 					if ((nl = strchr(buf2, '\n'))) *nl = 0;
190 					fprintf(logfile, "%s%s [%s]%s\n", it->substr(0, open).c_str(), buf1, buf2, it->substr(close + 1).c_str());
191 				} else {
192 					fprintf(logfile, "%s\n", it->c_str());
193 				}
194 			}
195 
196 			// Close pipe & clear buffer.
197 			pclose(p);
198 		}
199 	}
200 
201 	if (!runTheCommand) {
202 		// Just dump the buffer to the file.
203 		// (this is usually the branch taken by the clients)
204 		for (it = buffer.begin(); it != buffer.end(); ++it) {
205 			fprintf(logfile, "%s\n", it->c_str());
206 		}
207 	}
208 
209 	buffer.clear();
210 }
211 
212 
213 /**
214  * @brief demangles sym
215  *
216  * On MinGW, checks if sym needs demangling by some very simple heuristic and
217  * filters it through c++filt if it needs to be demangled.
218  *
219  * It's a workaround for MinGW GNU addr2line 2.15.91, which somehow strips
220  * underscores from the symbol before trying to demangle them, resulting
221  * no demangling ever happening.
222  */
CppFilt(char * sym,int size)223 void CLogger::CppFilt(char* sym, int size)
224 {
225 #ifdef __MINGW32__
226 
227 	// The heuristic :-)
228 	if (sym[0] != 'Z')
229 		return;
230 
231 	// Compose command & add the missing underscore
232 	std::stringstream command;
233 	command << CPPFILT << " \"_" << sym << '"';
234 
235 	// Do the filtering. Silently ignore any errors.
236 	FILE* p = popen(command.str().c_str(), "r");
237 	if (p) {
238 		fgets(sym, size, p);
239 		pclose(p);
240 	}
241 
242 #endif // __MINGW32__
243 }
244 
245 #endif // SYNCDEBUG
246