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 1610 -
(show annotations)
(download)
(as text)
Tue Oct 21 09:56:08 2014 UTC (10 years, 4 months ago) by amb
File MIME type: text/x-csrc
File size: 12928 byte(s)
Tue Oct 21 09:56:08 2014 UTC (10 years, 4 months ago) by amb
File MIME type: text/x-csrc
File size: 12928 byte(s)
Improve the message printed at the end when using --logtime or --logmemory.
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 | if(option_logtime) |
111 | fprintf_elapsed_time(stdout,&program_start_time); |
112 | |
113 | if(option_logmemory) |
114 | fprintf_max_memory(stdout,program_max_alloc,program_max_mmap); |
115 | |
116 | printf("Finish Program\n"); |
117 | |
118 | if(option_logtime==2) |
119 | printf("[ m:ss.micros] "); |
120 | else if(option_logtime==1) |
121 | printf("[ m:ss.mil] "); |
122 | |
123 | if(option_logmemory) |
124 | printf("[RAM,FILE MB] "); |
125 | |
126 | if(option_logtime) |
127 | printf("elapsed time"); |
128 | |
129 | if(option_logmemory) |
130 | { |
131 | if(option_logtime) |
132 | printf(", "); |
133 | printf("maximum memory"); |
134 | } |
135 | |
136 | printf("\n"); |
137 | |
138 | fflush(stdout); |
139 | } |
140 | } |
141 | |
142 | |
143 | /*++++++++++++++++++++++++++++++++++++++ |
144 | Print the first message in an overwriting sequence (to stdout). |
145 | |
146 | const char *format The format string. |
147 | |
148 | ... The other arguments. |
149 | ++++++++++++++++++++++++++++++++++++++*/ |
150 | |
151 | void printf_first(const char *format, ...) |
152 | { |
153 | va_list ap; |
154 | |
155 | if(option_logtime) |
156 | gettimeofday(&function_start_time,NULL); |
157 | |
158 | if(option_logmemory) |
159 | { |
160 | function_max_alloc=current_alloc; |
161 | function_max_mmap=current_mmap; |
162 | } |
163 | |
164 | if(option_loggable) |
165 | return; |
166 | |
167 | va_start(ap,format); |
168 | |
169 | vfprintf_first(stdout,format,ap); |
170 | |
171 | va_end(ap); |
172 | } |
173 | |
174 | |
175 | /*++++++++++++++++++++++++++++++++++++++ |
176 | Print the middle message in an overwriting sequence (to stdout). |
177 | |
178 | const char *format The format string. |
179 | |
180 | ... The other arguments. |
181 | ++++++++++++++++++++++++++++++++++++++*/ |
182 | |
183 | void printf_middle(const char *format, ...) |
184 | { |
185 | va_list ap; |
186 | |
187 | if(option_loggable) |
188 | return; |
189 | |
190 | va_start(ap,format); |
191 | |
192 | vfprintf_middle(stdout,format,ap); |
193 | |
194 | va_end(ap); |
195 | } |
196 | |
197 | |
198 | /*++++++++++++++++++++++++++++++++++++++ |
199 | Print the last message in an overwriting sequence (to stdout). |
200 | |
201 | const char *format The format string. |
202 | |
203 | ... The other arguments. |
204 | ++++++++++++++++++++++++++++++++++++++*/ |
205 | |
206 | void printf_last(const char *format, ...) |
207 | { |
208 | va_list ap; |
209 | |
210 | va_start(ap,format); |
211 | |
212 | vfprintf_last(stdout,format,ap); |
213 | |
214 | va_end(ap); |
215 | } |
216 | |
217 | |
218 | /*++++++++++++++++++++++++++++++++++++++ |
219 | Print the first message in an overwriting sequence to a specified file. |
220 | |
221 | FILE *file The file to write to. |
222 | |
223 | const char *format The format string. |
224 | |
225 | ... The other arguments. |
226 | ++++++++++++++++++++++++++++++++++++++*/ |
227 | |
228 | void fprintf_first(FILE *file,const char *format, ...) |
229 | { |
230 | va_list ap; |
231 | |
232 | if(option_logtime) |
233 | gettimeofday(&function_start_time,NULL); |
234 | |
235 | if(option_logmemory) |
236 | function_max_alloc=function_max_mmap=0; |
237 | |
238 | if(option_loggable) |
239 | return; |
240 | |
241 | va_start(ap,format); |
242 | |
243 | vfprintf_first(file,format,ap); |
244 | |
245 | va_end(ap); |
246 | } |
247 | |
248 | |
249 | /*++++++++++++++++++++++++++++++++++++++ |
250 | Print the middle message in an overwriting sequence to a specified file. |
251 | |
252 | FILE *file The file to write to. |
253 | |
254 | const char *format The format string. |
255 | |
256 | ... The other arguments. |
257 | ++++++++++++++++++++++++++++++++++++++*/ |
258 | |
259 | void fprintf_middle(FILE *file,const char *format, ...) |
260 | { |
261 | va_list ap; |
262 | |
263 | if(option_loggable) |
264 | return; |
265 | |
266 | va_start(ap,format); |
267 | |
268 | vfprintf_middle(file,format,ap); |
269 | |
270 | va_end(ap); |
271 | } |
272 | |
273 | |
274 | /*++++++++++++++++++++++++++++++++++++++ |
275 | Print the last message in an overwriting sequence to a specified file. |
276 | |
277 | FILE *file The file to write to. |
278 | |
279 | const char *format The format string. |
280 | |
281 | ... The other arguments. |
282 | ++++++++++++++++++++++++++++++++++++++*/ |
283 | |
284 | void fprintf_last(FILE *file,const char *format, ...) |
285 | { |
286 | va_list ap; |
287 | |
288 | va_start(ap,format); |
289 | |
290 | vfprintf_last(file,format,ap); |
291 | |
292 | va_end(ap); |
293 | } |
294 | |
295 | |
296 | /*++++++++++++++++++++++++++++++++++++++ |
297 | Record the memory allocations (record the amount in use). |
298 | |
299 | void *address The address that has been allocated. |
300 | |
301 | size_t size The size of the memory that has been allocated. |
302 | ++++++++++++++++++++++++++++++++++++++*/ |
303 | |
304 | void log_malloc(void *address,size_t size) |
305 | { |
306 | int i; |
307 | |
308 | if(!option_logmemory) |
309 | return; |
310 | |
311 | /* Store the information about the allocated memory */ |
312 | |
313 | for(i=0;i<nmallocedmem;i++) |
314 | if(mallocedmem[i].address==address) |
315 | { |
316 | size=size-mallocedmem[i].size; |
317 | mallocedmem[i].size+=size; |
318 | break; |
319 | } |
320 | |
321 | if(i==nmallocedmem) |
322 | { |
323 | mallocedmem=(struct mallocinfo*)realloc((void*)mallocedmem,(nmallocedmem+1)*sizeof(struct mallocinfo)); |
324 | |
325 | mallocedmem[nmallocedmem].address=address; |
326 | mallocedmem[nmallocedmem].size=size; |
327 | |
328 | nmallocedmem++; |
329 | } |
330 | |
331 | /* Increase the sum of allocated memory */ |
332 | |
333 | current_alloc+=size; |
334 | |
335 | if(current_alloc>function_max_alloc) |
336 | function_max_alloc=current_alloc; |
337 | |
338 | if(current_alloc>program_max_alloc) |
339 | program_max_alloc=current_alloc; |
340 | } |
341 | |
342 | |
343 | /*++++++++++++++++++++++++++++++++++++++ |
344 | Record the memory de-allocations. |
345 | |
346 | void *address The address that has been freed. |
347 | ++++++++++++++++++++++++++++++++++++++*/ |
348 | |
349 | void log_free(void *address) |
350 | { |
351 | size_t size=0; |
352 | int i; |
353 | |
354 | if(!option_logmemory) |
355 | return; |
356 | |
357 | /* Remove the information about the allocated memory */ |
358 | |
359 | for(i=0;i<nmallocedmem;i++) |
360 | if(mallocedmem[i].address==address) |
361 | { |
362 | size=mallocedmem[i].size; |
363 | break; |
364 | } |
365 | |
366 | logassert(i!=nmallocedmem,"Memory freed with log_free() was not allocated with log_[cm]alloc()"); |
367 | |
368 | nmallocedmem--; |
369 | |
370 | if(nmallocedmem>i) |
371 | memmove(&mallocedmem[i],&mallocedmem[i+1],(nmallocedmem-i)*sizeof(struct mallocinfo)); |
372 | |
373 | /* Reduce the sum of allocated memory */ |
374 | |
375 | current_alloc-=size; |
376 | } |
377 | |
378 | |
379 | /*++++++++++++++++++++++++++++++++++++++ |
380 | Record the amount of memory that has been mapped into files. |
381 | |
382 | size_t size The size of the file that has been mapped. |
383 | ++++++++++++++++++++++++++++++++++++++*/ |
384 | |
385 | void log_mmap(size_t size) |
386 | { |
387 | if(!option_logmemory) |
388 | return; |
389 | |
390 | current_mmap+=size; |
391 | |
392 | if(current_mmap>function_max_mmap) |
393 | function_max_mmap=current_mmap; |
394 | |
395 | if(current_mmap>program_max_mmap) |
396 | program_max_mmap=current_mmap; |
397 | } |
398 | |
399 | |
400 | /*++++++++++++++++++++++++++++++++++++++ |
401 | Record the amount of memory that has been unmapped from files. |
402 | |
403 | size_t size The size of the file that has been unmapped. |
404 | ++++++++++++++++++++++++++++++++++++++*/ |
405 | |
406 | void log_munmap(size_t size) |
407 | { |
408 | if(!option_logmemory) |
409 | return; |
410 | |
411 | current_mmap-=size; |
412 | } |
413 | |
414 | |
415 | /*++++++++++++++++++++++++++++++++++++++ |
416 | Do the work to print the first message in an overwriting sequence. |
417 | |
418 | FILE *file The file to write to. |
419 | |
420 | const char *format The format string. |
421 | |
422 | va_list ap The other arguments. |
423 | ++++++++++++++++++++++++++++++++++++++*/ |
424 | |
425 | static void vfprintf_first(FILE *file,const char *format,va_list ap) |
426 | { |
427 | int retval; |
428 | |
429 | if(option_logtime) |
430 | fprintf_elapsed_time(file,&function_start_time); |
431 | |
432 | if(option_logmemory) |
433 | fprintf_max_memory(file,function_max_alloc,function_max_mmap); |
434 | |
435 | retval=vfprintf(file,format,ap); |
436 | fflush(file); |
437 | |
438 | if(retval>0) |
439 | printed_length=retval; |
440 | } |
441 | |
442 | |
443 | /*++++++++++++++++++++++++++++++++++++++ |
444 | Do the work to print the middle message in an overwriting sequence. |
445 | |
446 | FILE *file The file to write to. |
447 | |
448 | const char *format The format string. |
449 | |
450 | va_list ap The other arguments. |
451 | ++++++++++++++++++++++++++++++++++++++*/ |
452 | |
453 | static void vfprintf_middle(FILE *file,const char *format,va_list ap) |
454 | { |
455 | int retval; |
456 | |
457 | fputc('\r',file); |
458 | |
459 | if(option_logtime) |
460 | fprintf_elapsed_time(file,&function_start_time); |
461 | |
462 | if(option_logmemory) |
463 | fprintf_max_memory(file,function_max_alloc,function_max_mmap); |
464 | |
465 | retval=vfprintf(file,format,ap); |
466 | fflush(file); |
467 | |
468 | if(retval>0) |
469 | { |
470 | int new_printed_length=retval; |
471 | |
472 | while(retval++<printed_length) |
473 | fputc(' ',file); |
474 | |
475 | printed_length=new_printed_length; |
476 | } |
477 | } |
478 | |
479 | |
480 | /*++++++++++++++++++++++++++++++++++++++ |
481 | Do the work to print the last message in an overwriting sequence. |
482 | |
483 | FILE *file The file to write to. |
484 | |
485 | const char *format The format string. |
486 | |
487 | va_list ap The other arguments. |
488 | ++++++++++++++++++++++++++++++++++++++*/ |
489 | |
490 | static void vfprintf_last(FILE *file,const char *format,va_list ap) |
491 | { |
492 | int retval; |
493 | |
494 | if(!option_loggable) |
495 | fputc('\r',file); |
496 | |
497 | if(option_logtime) |
498 | fprintf_elapsed_time(file,&function_start_time); |
499 | |
500 | if(option_logmemory) |
501 | fprintf_max_memory(file,function_max_alloc,function_max_mmap); |
502 | |
503 | retval=vfprintf(file,format,ap); |
504 | |
505 | if(retval>0) |
506 | while(retval++<printed_length) |
507 | fputc(' ',file); |
508 | |
509 | fputc('\n',file); |
510 | fflush(file); |
511 | } |
512 | |
513 | |
514 | /*++++++++++++++++++++++++++++++++++++++ |
515 | Print the elapsed time without a following newline. |
516 | |
517 | FILE *file The file to print to. |
518 | |
519 | struct timeval *start The start time from which the elapsed time is to be printed. |
520 | ++++++++++++++++++++++++++++++++++++++*/ |
521 | |
522 | static void fprintf_elapsed_time(FILE *file,struct timeval *start) |
523 | { |
524 | struct timeval finish,elapsed; |
525 | |
526 | gettimeofday(&finish,NULL); |
527 | |
528 | elapsed.tv_sec =finish.tv_sec -start->tv_sec; |
529 | elapsed.tv_usec=finish.tv_usec-start->tv_usec; |
530 | if(elapsed.tv_usec<0) |
531 | { |
532 | elapsed.tv_sec -=1; |
533 | elapsed.tv_usec+=1000000; |
534 | } |
535 | |
536 | if(option_logtime==2) |
537 | fprintf(file,"[%2ld:%02ld.%06ld] ",elapsed.tv_sec/60,elapsed.tv_sec%60,elapsed.tv_usec); |
538 | else |
539 | fprintf(file,"[%2ld:%02ld.%03ld] ",elapsed.tv_sec/60,elapsed.tv_sec%60,elapsed.tv_usec/1000); |
540 | } |
541 | |
542 | |
543 | /*++++++++++++++++++++++++++++++++++++++ |
544 | Print the maximum used memory without a following newline. |
545 | |
546 | FILE *file The file to print to. |
547 | |
548 | size_t max_alloc The maximum amount of allocated memory. |
549 | |
550 | size_t max_mmap The maximum amount of memory mapped memory. |
551 | ++++++++++++++++++++++++++++++++++++++*/ |
552 | |
553 | static void fprintf_max_memory(FILE *file,size_t max_alloc,size_t max_mmap) |
554 | { |
555 | fprintf(file,"[%3d, %3d MB] ",max_alloc/(1024*1024),max_mmap/(1024*1024)); |
556 | } |
557 | |
558 | |
559 | /*++++++++++++++++++++++++++++++++++++++ |
560 | Log a fatal error and exit |
561 | |
562 | const char *message The error message. |
563 | |
564 | const char *file The file in which the error occured. |
565 | |
566 | int line The line number in the file at which the error occured. |
567 | ++++++++++++++++++++++++++++++++++++++*/ |
568 | |
569 | void _logassert(const char *message,const char *file,int line) |
570 | { |
571 | fprintf(stderr,"Routino Fatal Error (%s:%d): %s\n",file,line,message); |
572 | |
573 | exit(EXIT_FAILURE); |
574 | } |