1 /* FreeTDS - Library of routines accessing Sybase and Microsoft databases
2 * Copyright (C) 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005 Brian Bruns
3 * Copyright (C) 2006-2015 Frediano Ziglio
4 *
5 * This library is free software; you can redistribute it and/or
6 * modify it under the terms of the GNU Library General Public
7 * License as published by the Free Software Foundation; either
8 * version 2 of the License, or (at your option) any later version.
9 *
10 * This library is distributed in the hope that it will be useful,
11 * but WITHOUT ANY WARRANTY; without even the implied warranty of
12 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
13 * Library General Public License for more details.
14 *
15 * You should have received a copy of the GNU Library General Public
16 * License along with this library; if not, write to the
17 * Free Software Foundation, Inc., 59 Temple Place - Suite 330,
18 * Boston, MA 02111-1307, USA.
19 */
20
21 #include <config.h>
22
23 #include <stdarg.h>
24
25 #include <freetds/time.h>
26
27 #include <assert.h>
28 #include <ctype.h>
29 #include <limits.h>
30 #include <stdio.h>
31
32 #if HAVE_STDLIB_H
33 #include <stdlib.h>
34 #endif /* HAVE_STDLIB_H */
35
36 #if HAVE_STRING_H
37 #include <string.h>
38 #endif /* HAVE_STRING_H */
39
40 #if HAVE_UNISTD_H
41 #include <unistd.h>
42 #endif /* HAVE_UNISTD_H */
43
44 #ifdef _WIN32
45 # include <process.h>
46 #endif
47
48 #include <freetds/tds.h>
49 #include <freetds/checks.h>
50 #include <freetds/thread.h>
51 #include <freetds/utils.h>
52
53 /* for now all messages go to the log */
54 int tds_debug_flags = TDS_DBGFLAG_ALL | TDS_DBGFLAG_SOURCE;
55 int tds_g_append_mode = 0;
56 static char *g_dump_filename = NULL;
57 /** Tell if TDS debug logging is turned on or off */
58 int tds_write_dump = 0;
59 /** List of threads excluded from logging, used to exclude some sensitive data */
60 static TDSDUMP_OFF_ITEM *off_list;
61 static FILE *g_dumpfile = NULL; /* file pointer for dump log */
62 static tds_mutex g_dump_mutex = TDS_MUTEX_INITIALIZER;
63
64 static FILE* tdsdump_append(void);
65
66 #ifdef TDS_ATTRIBUTE_DESTRUCTOR
67 static void __attribute__((destructor))
tds_util_deinit(void)68 tds_util_deinit(void)
69 {
70 tdsdump_close();
71 }
72 #endif
73
74 /**
75 * Temporarily turn off logging for current thread.
76 * @param off_item List item to be used by the function.
77 * The item will be initialized by the function.
78 * It's retained till is removed with tdsdump_on so it must be kept alive.
79 */
80 void
tdsdump_off(TDSDUMP_OFF_ITEM * off_item)81 tdsdump_off(TDSDUMP_OFF_ITEM *off_item)
82 {
83 /* if already off don't add current thread to exclude list to make it faster */
84 if (!tds_write_dump)
85 return;
86
87 off_item->thread_id = tds_thread_get_current_id();
88 tds_mutex_lock(&g_dump_mutex);
89 off_item->next = off_list;
90 off_list = off_item;
91 tds_mutex_unlock(&g_dump_mutex);
92 } /* tdsdump_off() */
93
94
95 /**
96 * Turn logging back on for current thread.
97 * @param off_item List item to remove from global list.
98 * Previously used by tdsdump_off().
99 */
100 void
tdsdump_on(TDSDUMP_OFF_ITEM * off_item)101 tdsdump_on(TDSDUMP_OFF_ITEM *off_item)
102 {
103 TDSDUMP_OFF_ITEM **curr;
104
105 tds_mutex_lock(&g_dump_mutex);
106 for (curr = &off_list; *curr != NULL; curr = &(*curr)->next) {
107 if (*curr == off_item) {
108 *curr = (*curr)->next;
109 break;
110 }
111 }
112 tds_mutex_unlock(&g_dump_mutex);
113 }
114
115 int
tdsdump_isopen()116 tdsdump_isopen()
117 {
118 return g_dumpfile || g_dump_filename;
119 }
120
121
122 /**
123 * Create and truncate a human readable dump file for the TDS
124 * traffic. The name of the file is specified by the filename
125 * parameter. If that is given as NULL or an empty string,
126 * any existing log file will be closed.
127 *
128 * \return true if the file was opened, false if it couldn't be opened.
129 */
130 int
tdsdump_open(const char * filename)131 tdsdump_open(const char *filename)
132 {
133 int result; /* really should be a boolean, not an int */
134
135 tds_mutex_lock(&g_dump_mutex);
136
137 /* same append file */
138 if (tds_g_append_mode && filename != NULL && g_dump_filename != NULL && strcmp(filename, g_dump_filename) == 0) {
139 tds_mutex_unlock(&g_dump_mutex);
140 return 1;
141 }
142
143 tds_write_dump = 0;
144
145 /* free old one */
146 if (g_dumpfile != NULL && g_dumpfile != stdout && g_dumpfile != stderr)
147 fclose(g_dumpfile);
148 g_dumpfile = NULL;
149 if (g_dump_filename)
150 TDS_ZERO_FREE(g_dump_filename);
151
152 /* required to close just log ?? */
153 if (filename == NULL || filename[0] == '\0') {
154 tds_mutex_unlock(&g_dump_mutex);
155 return 1;
156 }
157
158 result = 1;
159 if (tds_g_append_mode) {
160 g_dump_filename = strdup(filename);
161 /* if mutex are available do not reopen file every time */
162 #ifdef TDS_HAVE_MUTEX
163 g_dumpfile = tdsdump_append();
164 #endif
165 } else if (!strcmp(filename, "stdout")) {
166 g_dumpfile = stdout;
167 } else if (!strcmp(filename, "stderr")) {
168 g_dumpfile = stderr;
169 } else if (NULL == (g_dumpfile = fopen(filename, "w"))) {
170 result = 0;
171 }
172
173 if (result)
174 tds_write_dump = 1;
175 tds_mutex_unlock(&g_dump_mutex);
176
177 if (result) {
178 char today[64];
179 struct tm res;
180 time_t t;
181
182 time(&t);
183 today[0] = 0;
184 if (tds_localtime_r(&t, &res))
185 strftime(today, sizeof(today), "%Y-%m-%d %H:%M:%S", &res);
186
187 tdsdump_log(TDS_DBG_INFO1, "Starting log file for FreeTDS %s\n"
188 "\ton %s with debug flags 0x%x.\n", VERSION, today, tds_debug_flags);
189 }
190 return result;
191 } /* tdsdump_open() */
192
193 static FILE*
tdsdump_append(void)194 tdsdump_append(void)
195 {
196 if (!g_dump_filename)
197 return NULL;
198
199 if (!strcmp(g_dump_filename, "stdout")) {
200 return stdout;
201 } else if (!strcmp(g_dump_filename, "stderr")) {
202 return stderr;
203 }
204 return fopen(g_dump_filename, "a");
205 }
206
207
208 /**
209 * Close the TDS dump log file.
210 */
211 void
tdsdump_close(void)212 tdsdump_close(void)
213 {
214 tds_mutex_lock(&g_dump_mutex);
215 tds_write_dump = 0;
216 if (g_dumpfile != NULL && g_dumpfile != stdout && g_dumpfile != stderr)
217 fclose(g_dumpfile);
218 g_dumpfile = NULL;
219 if (g_dump_filename)
220 TDS_ZERO_FREE(g_dump_filename);
221 tds_mutex_unlock(&g_dump_mutex);
222 } /* tdsdump_close() */
223
224 static void
tdsdump_start(FILE * file,const char * fname,int line)225 tdsdump_start(FILE *file, const char *fname, int line)
226 {
227 char buf[128], *pbuf;
228 int started = 0;
229
230 /* write always time before log */
231 if (tds_debug_flags & TDS_DBGFLAG_TIME) {
232 fputs(tds_timestamp_str(buf, 127), file);
233 started = 1;
234 }
235
236 pbuf = buf;
237 if (tds_debug_flags & TDS_DBGFLAG_PID) {
238 if (started)
239 *pbuf++ = ' ';
240 pbuf += sprintf(pbuf, "%d", (int) getpid());
241 started = 1;
242 }
243
244 if ((tds_debug_flags & TDS_DBGFLAG_SOURCE) && fname && line) {
245 const char *p;
246 p = strrchr(fname, '/');
247 if (p)
248 fname = p + 1;
249 p = strrchr(fname, '\\');
250 if (p)
251 fname = p + 1;
252 if (started)
253 pbuf += sprintf(pbuf, " (%s:%d)", fname, line);
254 else
255 pbuf += sprintf(pbuf, "%s:%d", fname, line);
256 started = 1;
257 }
258 if (started)
259 *pbuf++ = ':';
260 *pbuf = 0;
261 fputs(buf, file);
262 }
263
264 /**
265 * Check if current thread is in the list of excluded threads
266 * g_dump_mutex must be held.
267 */
268 static bool
current_thread_is_excluded(void)269 current_thread_is_excluded(void)
270 {
271 TDSDUMP_OFF_ITEM *curr_off;
272
273 tds_mutex_check_owned(&g_dump_mutex);
274
275 for (curr_off = off_list; curr_off; curr_off = curr_off->next)
276 if (tds_thread_is_current(curr_off->thread_id))
277 return true;
278
279 return false;
280 }
281
282 #undef tdsdump_dump_buf
283 /**
284 * Dump the contents of data into the log file in a human readable format.
285 * \param file source file name
286 * \param level_line line and level combined. This and file are automatically computed by
287 * TDS_DBG_* macros.
288 * \param msg message to print before dump
289 * \param buf buffer to dump
290 * \param length number of bytes in the buffer
291 */
292 void
tdsdump_dump_buf(const char * file,unsigned int level_line,const char * msg,const void * buf,size_t length)293 tdsdump_dump_buf(const char* file, unsigned int level_line, const char *msg, const void *buf, size_t length)
294 {
295 size_t i, j;
296 #define BYTES_PER_LINE 16
297 const unsigned char *data = (const unsigned char *) buf;
298 const int debug_lvl = level_line & 15;
299 const int line = level_line >> 4;
300 char line_buf[BYTES_PER_LINE * 8 + 16], *p;
301 FILE *dumpfile;
302
303 if (((tds_debug_flags >> debug_lvl) & 1) == 0 || !tds_write_dump)
304 return;
305
306 if (!g_dumpfile && !g_dump_filename)
307 return;
308
309 tds_mutex_lock(&g_dump_mutex);
310
311 if (current_thread_is_excluded()) {
312 tds_mutex_unlock(&g_dump_mutex);
313 return;
314 }
315
316 dumpfile = g_dumpfile;
317 #ifdef TDS_HAVE_MUTEX
318 if (tds_g_append_mode && dumpfile == NULL)
319 dumpfile = g_dumpfile = tdsdump_append();
320 #else
321 if (tds_g_append_mode)
322 dumpfile = tdsdump_append();
323 #endif
324
325 if (dumpfile == NULL) {
326 tds_mutex_unlock(&g_dump_mutex);
327 return;
328 }
329
330 tdsdump_start(dumpfile, file, line);
331
332 fprintf(dumpfile, "%s\n", msg);
333
334 for (i = 0; i < length; i += BYTES_PER_LINE) {
335 p = line_buf;
336 /*
337 * print the offset as a 4 digit hex number
338 */
339 p += sprintf(p, "%04x", ((unsigned int) i) & 0xffffu);
340
341 /*
342 * print each byte in hex
343 */
344 for (j = 0; j < BYTES_PER_LINE; j++) {
345 if (j == BYTES_PER_LINE / 2)
346 *p++ = '-';
347 else
348 *p++ = ' ';
349 if (j + i >= length)
350 p += sprintf(p, " ");
351 else
352 p += sprintf(p, "%02x", data[i + j]);
353 }
354
355 /*
356 * skip over to the ascii dump column
357 */
358 p += sprintf(p, " |");
359
360 /*
361 * print each byte in ascii
362 */
363 for (j = i; j < length && (j - i) < BYTES_PER_LINE; j++) {
364 if (j - i == BYTES_PER_LINE / 2)
365 *p++ = ' ';
366 p += sprintf(p, "%c", (isprint(data[j])) ? data[j] : '.');
367 }
368 strcpy(p, "|\n");
369 fputs(line_buf, dumpfile);
370 }
371 fputs("\n", dumpfile);
372
373 fflush(dumpfile);
374
375 #ifndef TDS_HAVE_MUTEX
376 if (tds_g_append_mode) {
377 if (dumpfile != stdout && dumpfile != stderr)
378 fclose(dumpfile);
379 }
380 #endif
381
382 tds_mutex_unlock(&g_dump_mutex);
383
384 } /* tdsdump_dump_buf() */
385 #define tdsdump_dump_buf TDSDUMP_BUF_FAST
386
387
388 #undef tdsdump_log
389 /**
390 * Write a message to the debug log.
391 * \param file name of the log file
392 * \param level_line kind of detail to be included
393 * \param fmt printf-like format string
394 */
395 void
tdsdump_log(const char * file,unsigned int level_line,const char * fmt,...)396 tdsdump_log(const char* file, unsigned int level_line, const char *fmt, ...)
397 {
398 const int debug_lvl = level_line & 15;
399 const int line = level_line >> 4;
400 va_list ap;
401 FILE *dumpfile;
402
403 if (((tds_debug_flags >> debug_lvl) & 1) == 0 || !tds_write_dump)
404 return;
405
406 if (!g_dumpfile && !g_dump_filename)
407 return;
408
409 tds_mutex_lock(&g_dump_mutex);
410
411 if (current_thread_is_excluded()) {
412 tds_mutex_unlock(&g_dump_mutex);
413 return;
414 }
415
416 dumpfile = g_dumpfile;
417 #ifdef TDS_HAVE_MUTEX
418 if (tds_g_append_mode && dumpfile == NULL)
419 dumpfile = g_dumpfile = tdsdump_append();
420 #else
421 if (tds_g_append_mode)
422 dumpfile = tdsdump_append();
423 #endif
424
425 if (dumpfile == NULL) {
426 tds_mutex_unlock(&g_dump_mutex);
427 return;
428 }
429
430 tdsdump_start(dumpfile, file, line);
431
432 va_start(ap, fmt);
433
434 vfprintf(dumpfile, fmt, ap);
435 va_end(ap);
436
437 fflush(dumpfile);
438
439 #ifndef TDS_HAVE_MUTEX
440 if (tds_g_append_mode) {
441 if (dumpfile != stdout && dumpfile != stderr)
442 fclose(dumpfile);
443 }
444 #endif
445 tds_mutex_unlock(&g_dump_mutex);
446 } /* tdsdump_log() */
447 #define tdsdump_log TDSDUMP_LOG_FAST
448
449
450 /**
451 * Write a column value to the debug log.
452 * \param col column to dump
453 */
454 void
tdsdump_col(const TDSCOLUMN * col)455 tdsdump_col(const TDSCOLUMN *col)
456 {
457 const char* type_name;
458 char* data;
459 TDS_SMALLINT type;
460
461 assert(col);
462 assert(col->column_data);
463
464 type_name = tds_prtype(col->column_type);
465 type = tds_get_conversion_type(col->column_type, col->column_size);
466
467 switch(type) {
468 case SYBCHAR:
469 case SYBVARCHAR:
470 if (col->column_cur_size >= 0) {
471 data = tds_new0(char, 1 + col->column_cur_size);
472 if (!data) {
473 tdsdump_log(TDS_DBG_FUNC, "no memory to log data for type %s\n", type_name);
474 return;
475 }
476 memcpy(data, col->column_data, col->column_cur_size);
477 tdsdump_log(TDS_DBG_FUNC, "type %s has value \"%s\"\n", type_name, data);
478 free(data);
479 } else {
480 tdsdump_log(TDS_DBG_FUNC, "type %s has value NULL\n", type_name);
481 }
482 break;
483 case SYBINT1:
484 tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_TINYINT*)col->column_data);
485 break;
486 case SYBINT2:
487 tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_SMALLINT*)col->column_data);
488 break;
489 case SYBINT4:
490 tdsdump_log(TDS_DBG_FUNC, "type %s has value %d\n", type_name, (int)*(TDS_INT*)col->column_data);
491 break;
492 case SYBREAL:
493 tdsdump_log(TDS_DBG_FUNC, "type %s has value %f\n", type_name, (double)*(TDS_REAL*)col->column_data);
494 break;
495 case SYBFLT8:
496 tdsdump_log(TDS_DBG_FUNC, "type %s has value %f\n", type_name, (double)*(TDS_FLOAT*)col->column_data);
497 break;
498 default:
499 tdsdump_log(TDS_DBG_FUNC, "cannot log data for type %s\n", type_name);
500 break;
501 }
502 }
503