Check out the latest version of Routino: svn co http://routino.org/svn/trunk routino
Contents of /trunk/src/logging.c
Parent Directory
|
Revision Log
Revision 1600 -
(show annotations)
(download)
(as text)
Fri Oct 10 18:21:44 2014 UTC (10 years, 5 months ago) by amb
File MIME type: text/x-csrc
File size: 12434 byte(s)
Fri Oct 10 18:21:44 2014 UTC (10 years, 5 months ago) by amb
File MIME type: text/x-csrc
File size: 12434 byte(s)
Add the '--logtime' and '--logmemory' options to the router to report the time and maximum memory in use (allocated and mapped files) during each step of the routing.
1 | /*************************************** |
2 | Functions to handle logging functions. |
3 | |
4 | Part of the Routino routing software. |
5 | ******************/ /****************** |
6 | This file Copyright 2008-2014 Andrew M. Bishop |
7 | |
8 | This program is free software: you can redistribute it and/or modify |
9 | it under the terms of the GNU Affero General Public License as published by |
10 | the Free Software Foundation, either version 3 of the License, or |
11 | (at your option) any later version. |
12 | |
13 | This program is distributed in the hope that it will be useful, |
14 | but WITHOUT ANY WARRANTY; without even the implied warranty of |
15 | MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the |
16 | GNU Affero General Public License for more details. |
17 | |
18 | You should have received a copy of the GNU Affero General Public License |
19 | along with this program. If not, see <http://www.gnu.org/licenses/>. |
20 | ***************************************/ |
21 | |
22 | |
23 | #include <stdio.h> |
24 | #include <stdarg.h> |
25 | #include <stdlib.h> |
26 | #include <string.h> |
27 | #include <errno.h> |
28 | #include <sys/time.h> |
29 | |
30 | #include "logging.h" |
31 | |
32 | |
33 | /* Global variables */ |
34 | |
35 | /*+ The option to print the output in a way that allows logging to a file. +*/ |
36 | int option_loggable=0; |
37 | |
38 | /*+ The option to print timestamps with the output. +*/ |
39 | int option_logtime=0; |
40 | |
41 | /*+ The option to print timestamps with the output. +*/ |
42 | int option_logmemory=0; |
43 | |
44 | |
45 | /*+ A structure to contain the list of allocated memory. +*/ |
46 | struct mallocinfo |
47 | { |
48 | void *address; /*+ The address of the allocated memory. +*/ |
49 | size_t size; /*+ The size of the allocated memory. +*/ |
50 | }; |
51 | |
52 | /*+ The list of allocated memory. +*/ |
53 | static struct mallocinfo *mallocedmem; |
54 | |
55 | /*+ The number of allocated memory blocks. +*/ |
56 | static int nmallocedmem=0; |
57 | |
58 | |
59 | /* Local functions */ |
60 | |
61 | static void vfprintf_first(FILE *file,const char *format,va_list ap); |
62 | static void vfprintf_middle(FILE *file,const char *format,va_list ap); |
63 | static void vfprintf_last(FILE *file,const char *format,va_list ap); |
64 | |
65 | static void fprintf_elapsed_time(FILE *file,struct timeval *start); |
66 | static void fprintf_max_memory(FILE *file,size_t max_alloc,size_t max_mmap); |
67 | |
68 | |
69 | /* Local variables */ |
70 | |
71 | /*+ The time that program_start() was called. +*/ |
72 | static struct timeval program_start_time; |
73 | |
74 | /*+ The time that printf_first() was called. +*/ |
75 | static struct timeval function_start_time; |
76 | |
77 | /*+ The length of the string printed out last time. +*/ |
78 | static int printed_length=0; |
79 | |
80 | /*+ The maximum amount of memory allocated and memory mapped since starting the program. +*/ |
81 | static size_t program_max_alloc=0,program_max_mmap=0; |
82 | |
83 | /*+ The maximum amount of memory allocated and memory mapped since starting the function. +*/ |
84 | static size_t function_max_alloc=0,function_max_mmap=0; |
85 | |
86 | /*+ The current amount of memory allocated and memory mapped. +*/ |
87 | static size_t current_alloc=0,current_mmap=0; |
88 | |
89 | |
90 | /*++++++++++++++++++++++++++++++++++++++ |
91 | Record the time that the program started. |
92 | ++++++++++++++++++++++++++++++++++++++*/ |
93 | |
94 | void printf_program_start(void) |
95 | { |
96 | gettimeofday(&program_start_time,NULL); |
97 | |
98 | program_max_alloc=program_max_mmap=0; |
99 | } |
100 | |
101 | |
102 | /*++++++++++++++++++++++++++++++++++++++ |
103 | Record the time that the program started. |
104 | ++++++++++++++++++++++++++++++++++++++*/ |
105 | |
106 | void printf_program_end(void) |
107 | { |
108 | if(option_logtime || option_logmemory) |
109 | { |
110 | printf("\n"); |
111 | |
112 | if(option_logtime) |
113 | fprintf_elapsed_time(stdout,&program_start_time); |
114 | |
115 | if(option_logmemory) |
116 | fprintf_max_memory(stdout,program_max_alloc,program_max_mmap); |
117 | |
118 | printf("Complete\n"); |
119 | fflush(stdout); |
120 | } |
121 | } |
122 | |
123 | |
124 | /*++++++++++++++++++++++++++++++++++++++ |
125 | Print the first message in an overwriting sequence (to stdout). |
126 | |
127 | const char *format The format string. |
128 | |
129 | ... The other arguments. |
130 | ++++++++++++++++++++++++++++++++++++++*/ |
131 | |
132 | void printf_first(const char *format, ...) |
133 | { |
134 | va_list ap; |
135 | |
136 | if(option_logtime) |
137 | gettimeofday(&function_start_time,NULL); |
138 | |
139 | if(option_logmemory) |
140 | { |
141 | function_max_alloc=current_alloc; |
142 | function_max_mmap=current_mmap; |
143 | } |
144 | |
145 | if(option_loggable) |
146 | return; |
147 | |
148 | va_start(ap,format); |
149 | |
150 | vfprintf_first(stdout,format,ap); |
151 | |
152 | va_end(ap); |
153 | } |
154 | |
155 | |
156 | /*++++++++++++++++++++++++++++++++++++++ |
157 | Print the middle message in an overwriting sequence (to stdout). |
158 | |
159 | const char *format The format string. |
160 | |
161 | ... The other arguments. |
162 | ++++++++++++++++++++++++++++++++++++++*/ |
163 | |
164 | void printf_middle(const char *format, ...) |
165 | { |
166 | va_list ap; |
167 | |
168 | if(option_loggable) |
169 | return; |
170 | |
171 | va_start(ap,format); |
172 | |
173 | vfprintf_middle(stdout,format,ap); |
174 | |
175 | va_end(ap); |
176 | } |
177 | |
178 | |
179 | /*++++++++++++++++++++++++++++++++++++++ |
180 | Print the last message in an overwriting sequence (to stdout). |
181 | |
182 | const char *format The format string. |
183 | |
184 | ... The other arguments. |
185 | ++++++++++++++++++++++++++++++++++++++*/ |
186 | |
187 | void printf_last(const char *format, ...) |
188 | { |
189 | va_list ap; |
190 | |
191 | va_start(ap,format); |
192 | |
193 | vfprintf_last(stdout,format,ap); |
194 | |
195 | va_end(ap); |
196 | } |
197 | |
198 | |
199 | /*++++++++++++++++++++++++++++++++++++++ |
200 | Print the first message in an overwriting sequence to a specified file. |
201 | |
202 | FILE *file The file to write to. |
203 | |
204 | const char *format The format string. |
205 | |
206 | ... The other arguments. |
207 | ++++++++++++++++++++++++++++++++++++++*/ |
208 | |
209 | void fprintf_first(FILE *file,const char *format, ...) |
210 | { |
211 | va_list ap; |
212 | |
213 | if(option_logtime) |
214 | gettimeofday(&function_start_time,NULL); |
215 | |
216 | if(option_logmemory) |
217 | function_max_alloc=function_max_mmap=0; |
218 | |
219 | if(option_loggable) |
220 | return; |
221 | |
222 | va_start(ap,format); |
223 | |
224 | vfprintf_first(file,format,ap); |
225 | |
226 | va_end(ap); |
227 | } |
228 | |
229 | |
230 | /*++++++++++++++++++++++++++++++++++++++ |
231 | Print the middle message in an overwriting sequence to a specified file. |
232 | |
233 | FILE *file The file to write to. |
234 | |
235 | const char *format The format string. |
236 | |
237 | ... The other arguments. |
238 | ++++++++++++++++++++++++++++++++++++++*/ |
239 | |
240 | void fprintf_middle(FILE *file,const char *format, ...) |
241 | { |
242 | va_list ap; |
243 | |
244 | if(option_loggable) |
245 | return; |
246 | |
247 | va_start(ap,format); |
248 | |
249 | vfprintf_middle(file,format,ap); |
250 | |
251 | va_end(ap); |
252 | } |
253 | |
254 | |
255 | /*++++++++++++++++++++++++++++++++++++++ |
256 | Print the last message in an overwriting sequence to a specified file. |
257 | |
258 | FILE *file The file to write to. |
259 | |
260 | const char *format The format string. |
261 | |
262 | ... The other arguments. |
263 | ++++++++++++++++++++++++++++++++++++++*/ |
264 | |
265 | void fprintf_last(FILE *file,const char *format, ...) |
266 | { |
267 | va_list ap; |
268 | |
269 | va_start(ap,format); |
270 | |
271 | vfprintf_last(file,format,ap); |
272 | |
273 | va_end(ap); |
274 | } |
275 | |
276 | |
277 | /*++++++++++++++++++++++++++++++++++++++ |
278 | Record the memory allocations (record the amount in use). |
279 | |
280 | void *address The address that has been allocated. |
281 | |
282 | size_t size The size of the memory that has been allocated. |
283 | ++++++++++++++++++++++++++++++++++++++*/ |
284 | |
285 | void log_malloc(void *address,size_t size) |
286 | { |
287 | int i; |
288 | |
289 | if(!option_logmemory) |
290 | return; |
291 | |
292 | /* Store the information about the allocated memory */ |
293 | |
294 | for(i=0;i<nmallocedmem;i++) |
295 | if(mallocedmem[i].address==address) |
296 | { |
297 | size=size-mallocedmem[i].size; |
298 | mallocedmem[i].size+=size; |
299 | break; |
300 | } |
301 | |
302 | if(i==nmallocedmem) |
303 | { |
304 | mallocedmem=(struct mallocinfo*)realloc((void*)mallocedmem,(nmallocedmem+1)*sizeof(struct mallocinfo)); |
305 | |
306 | mallocedmem[nmallocedmem].address=address; |
307 | mallocedmem[nmallocedmem].size=size; |
308 | |
309 | nmallocedmem++; |
310 | } |
311 | |
312 | /* Increase the sum of allocated memory */ |
313 | |
314 | current_alloc+=size; |
315 | |
316 | if(current_alloc>function_max_alloc) |
317 | function_max_alloc=current_alloc; |
318 | |
319 | if(current_alloc>program_max_alloc) |
320 | program_max_alloc=current_alloc; |
321 | } |
322 | |
323 | |
324 | /*++++++++++++++++++++++++++++++++++++++ |
325 | Record the memory de-allocations. |
326 | |
327 | void *address The address that has been freed. |
328 | ++++++++++++++++++++++++++++++++++++++*/ |
329 | |
330 | void log_free(void *address) |
331 | { |
332 | size_t size=0; |
333 | int i; |
334 | |
335 | if(!option_logmemory) |
336 | return; |
337 | |
338 | /* Remove the information about the allocated memory */ |
339 | |
340 | for(i=0;i<nmallocedmem;i++) |
341 | if(mallocedmem[i].address==address) |
342 | { |
343 | size=mallocedmem[i].size; |
344 | break; |
345 | } |
346 | |
347 | logassert(i!=nmallocedmem,"Memory freed with log_free() was not allocated with log_[cm]alloc()"); |
348 | |
349 | nmallocedmem--; |
350 | |
351 | if(nmallocedmem>i) |
352 | memmove(&mallocedmem[i],&mallocedmem[i+1],(nmallocedmem-i)*sizeof(struct mallocinfo)); |
353 | |
354 | /* Reduce the sum of allocated memory */ |
355 | |
356 | current_alloc-=size; |
357 | } |
358 | |
359 | |
360 | /*++++++++++++++++++++++++++++++++++++++ |
361 | Record the amount of memory that has been mapped into files. |
362 | |
363 | size_t size The size of the file that has been mapped. |
364 | ++++++++++++++++++++++++++++++++++++++*/ |
365 | |
366 | void log_mmap(size_t size) |
367 | { |
368 | if(!option_logmemory) |
369 | return; |
370 | |
371 | current_mmap+=size; |
372 | |
373 | if(current_mmap>function_max_mmap) |
374 | function_max_mmap=current_mmap; |
375 | |
376 | if(current_mmap>program_max_mmap) |
377 | program_max_mmap=current_mmap; |
378 | } |
379 | |
380 | |
381 | /*++++++++++++++++++++++++++++++++++++++ |
382 | Record the amount of memory that has been unmapped from files. |
383 | |
384 | size_t size The size of the file that has been unmapped. |
385 | ++++++++++++++++++++++++++++++++++++++*/ |
386 | |
387 | void log_munmap(size_t size) |
388 | { |
389 | if(!option_logmemory) |
390 | return; |
391 | |
392 | current_mmap-=size; |
393 | } |
394 | |
395 | |
396 | /*++++++++++++++++++++++++++++++++++++++ |
397 | Do the work to print the first message in an overwriting sequence. |
398 | |
399 | FILE *file The file to write to. |
400 | |
401 | const char *format The format string. |
402 | |
403 | va_list ap The other arguments. |
404 | ++++++++++++++++++++++++++++++++++++++*/ |
405 | |
406 | static void vfprintf_first(FILE *file,const char *format,va_list ap) |
407 | { |
408 | int retval; |
409 | |
410 | if(option_logtime) |
411 | fprintf_elapsed_time(file,&function_start_time); |
412 | |
413 | if(option_logmemory) |
414 | fprintf_max_memory(file,function_max_alloc,function_max_mmap); |
415 | |
416 | retval=vfprintf(file,format,ap); |
417 | fflush(file); |
418 | |
419 | if(retval>0) |
420 | printed_length=retval; |
421 | } |
422 | |
423 | |
424 | /*++++++++++++++++++++++++++++++++++++++ |
425 | Do the work to print the middle message in an overwriting sequence. |
426 | |
427 | FILE *file The file to write to. |
428 | |
429 | const char *format The format string. |
430 | |
431 | va_list ap The other arguments. |
432 | ++++++++++++++++++++++++++++++++++++++*/ |
433 | |
434 | static void vfprintf_middle(FILE *file,const char *format,va_list ap) |
435 | { |
436 | int retval; |
437 | |
438 | fputc('\r',file); |
439 | |
440 | if(option_logtime) |
441 | fprintf_elapsed_time(file,&function_start_time); |
442 | |
443 | if(option_logmemory) |
444 | fprintf_max_memory(file,function_max_alloc,function_max_mmap); |
445 | |
446 | retval=vfprintf(file,format,ap); |
447 | fflush(file); |
448 | |
449 | if(retval>0) |
450 | { |
451 | int new_printed_length=retval; |
452 | |
453 | while(retval++<printed_length) |
454 | fputc(' ',file); |
455 | |
456 | printed_length=new_printed_length; |
457 | } |
458 | } |
459 | |
460 | |
461 | /*++++++++++++++++++++++++++++++++++++++ |
462 | Do the work to print the last message in an overwriting sequence. |
463 | |
464 | FILE *file The file to write to. |
465 | |
466 | const char *format The format string. |
467 | |
468 | va_list ap The other arguments. |
469 | ++++++++++++++++++++++++++++++++++++++*/ |
470 | |
471 | static void vfprintf_last(FILE *file,const char *format,va_list ap) |
472 | { |
473 | int retval; |
474 | |
475 | if(!option_loggable) |
476 | fputc('\r',file); |
477 | |
478 | if(option_logtime) |
479 | fprintf_elapsed_time(file,&function_start_time); |
480 | |
481 | if(option_logmemory) |
482 | fprintf_max_memory(file,function_max_alloc,function_max_mmap); |
483 | |
484 | retval=vfprintf(file,format,ap); |
485 | |
486 | if(retval>0) |
487 | while(retval++<printed_length) |
488 | fputc(' ',file); |
489 | |
490 | fputc('\n',file); |
491 | fflush(file); |
492 | } |
493 | |
494 | |
495 | /*++++++++++++++++++++++++++++++++++++++ |
496 | Print the elapsed time without a following newline. |
497 | |
498 | FILE *file The file to print to. |
499 | |
500 | struct timeval *start The start time from which the elapsed time is to be printed. |
501 | ++++++++++++++++++++++++++++++++++++++*/ |
502 | |
503 | static void fprintf_elapsed_time(FILE *file,struct timeval *start) |
504 | { |
505 | struct timeval finish,elapsed; |
506 | |
507 | gettimeofday(&finish,NULL); |
508 | |
509 | elapsed.tv_sec =finish.tv_sec -start->tv_sec; |
510 | elapsed.tv_usec=finish.tv_usec-start->tv_usec; |
511 | if(elapsed.tv_usec<0) |
512 | { |
513 | elapsed.tv_sec -=1; |
514 | elapsed.tv_usec+=1000000; |
515 | } |
516 | |
517 | fprintf(file,"[%2ld:%02ld.%03ld] ",elapsed.tv_sec/60,elapsed.tv_sec%60,elapsed.tv_usec/1000); |
518 | } |
519 | |
520 | |
521 | /*++++++++++++++++++++++++++++++++++++++ |
522 | Print the maximum used memory without a following newline. |
523 | |
524 | FILE *file The file to print to. |
525 | |
526 | size_t max_alloc The maximum amount of allocated memory. |
527 | |
528 | size_t max_mmap The maximum amount of memory mapped memory. |
529 | ++++++++++++++++++++++++++++++++++++++*/ |
530 | |
531 | static void fprintf_max_memory(FILE *file,size_t max_alloc,size_t max_mmap) |
532 | { |
533 | fprintf(file,"[%3d, %3d MB] ",max_alloc/(1024*1024),max_mmap/(1024*1024)); |
534 | } |
535 | |
536 | |
537 | /*++++++++++++++++++++++++++++++++++++++ |
538 | Log a fatal error and exit |
539 | |
540 | const char *message The error message. |
541 | |
542 | const char *file The file in which the error occured. |
543 | |
544 | int line The line number in the file at which the error occured. |
545 | ++++++++++++++++++++++++++++++++++++++*/ |
546 | |
547 | void _logassert(const char *message,const char *file,int line) |
548 | { |
549 | fprintf(stderr,"Routino Fatal Error (%s:%d): %s\n",file,line,message); |
550 | |
551 | exit(EXIT_FAILURE); |
552 | } |