Routino SVN Repository Browser

Check out the latest version of Routino: svn co http://routino.org/svn/trunk routino

ViewVC logotype

Annotation of /trunk/src/logging.c

Parent Directory Parent Directory | Revision Log Revision Log


Revision 2001 - (hide annotations) (download) (as text)
Sun Jul 28 10:22:30 2019 UTC (5 years, 8 months ago) by amb
File MIME type: text/x-csrc
File size: 15703 byte(s)
Increase the number of digits allocated for elapsed time and allocated
memory when logging that information.

1 amb 520 /***************************************
2     Functions to handle logging functions.
3    
4     Part of the Routino routing software.
5     ******************/ /******************
6 amb 1999 This file Copyright 2008-2015, 2019 Andrew M. Bishop
7 amb 520
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 amb 804 #include <stdlib.h>
26     #include <string.h>
27     #include <errno.h>
28 amb 1680
29     #if defined(_MSC_VER)
30    
31     #include <WinSock2.h>
32     #include <stdint.h>
33    
34     static const uint64_t EPOCH = ((uint64_t) 116444736000000000ULL);
35    
36     int gettimeofday(struct timeval * tp, struct timezone * tzp)
37     {
38     FILETIME file_time;
39     SYSTEMTIME system_time;
40     ULARGE_INTEGER ularge;
41    
42     GetSystemTime(&system_time);
43     SystemTimeToFileTime(&system_time, &file_time);
44     ularge.LowPart = file_time.dwLowDateTime;
45     ularge.HighPart = file_time.dwHighDateTime;
46    
47     tp->tv_sec = (long) ((ularge.QuadPart - EPOCH) / 10000000L);
48     tp->tv_usec = (long) (system_time.wMilliseconds * 1000);
49     return 0;
50     }
51    
52     #else
53    
54 amb 982 #include <sys/time.h>
55 amb 520
56 amb 1680 #endif
57    
58 amb 520 #include "logging.h"
59    
60    
61 amb 680 /* Global variables */
62    
63 amb 520 /*+ The option to print the output in a way that allows logging to a file. +*/
64     int option_loggable=0;
65    
66 amb 1613 /*+ The option to print elapsed time with the output. +*/
67 amb 1019 int option_logtime=0;
68 amb 982
69 amb 1613 /*+ The option to print memory usage with the output. +*/
70 amb 1598 int option_logmemory=0;
71 amb 982
72 amb 1598
73 amb 1613 /* Local data types */
74    
75 amb 1598 /*+ A structure to contain the list of allocated memory. +*/
76     struct mallocinfo
77     {
78     void *address; /*+ The address of the allocated memory. +*/
79     size_t size; /*+ The size of the allocated memory. +*/
80     };
81    
82    
83 amb 520 /* Local functions */
84    
85     static void vfprintf_first(FILE *file,const char *format,va_list ap);
86     static void vfprintf_middle(FILE *file,const char *format,va_list ap);
87     static void vfprintf_last(FILE *file,const char *format,va_list ap);
88    
89 amb 1596 static void fprintf_elapsed_time(FILE *file,struct timeval *start);
90 amb 1598 static void fprintf_max_memory(FILE *file,size_t max_alloc,size_t max_mmap);
91 amb 982
92 amb 1596
93 amb 520 /* Local variables */
94    
95 amb 1398 /*+ The time that program_start() was called. +*/
96     static struct timeval program_start_time;
97 amb 982
98 amb 1398 /*+ The time that printf_first() was called. +*/
99     static struct timeval function_start_time;
100    
101 amb 1613 /*+ The list of allocated memory. +*/
102     static struct mallocinfo *mallocedmem;
103    
104     /*+ The number of allocated memory blocks. +*/
105     static int nmallocedmem=0;
106    
107 amb 648 /*+ The length of the string printed out last time. +*/
108 amb 520 static int printed_length=0;
109    
110 amb 1598 /*+ The maximum amount of memory allocated and memory mapped since starting the program. +*/
111     static size_t program_max_alloc=0,program_max_mmap=0;
112 amb 520
113 amb 1598 /*+ The maximum amount of memory allocated and memory mapped since starting the function. +*/
114     static size_t function_max_alloc=0,function_max_mmap=0;
115    
116     /*+ The current amount of memory allocated and memory mapped. +*/
117     static size_t current_alloc=0,current_mmap=0;
118    
119    
120 amb 520 /*++++++++++++++++++++++++++++++++++++++
121 amb 1398 Record the time that the program started.
122     ++++++++++++++++++++++++++++++++++++++*/
123    
124     void printf_program_start(void)
125     {
126 amb 1400 gettimeofday(&program_start_time,NULL);
127 amb 1598
128     program_max_alloc=program_max_mmap=0;
129 amb 1398 }
130    
131    
132     /*++++++++++++++++++++++++++++++++++++++
133     Record the time that the program started.
134     ++++++++++++++++++++++++++++++++++++++*/
135    
136     void printf_program_end(void)
137     {
138 amb 1598 if(option_logtime || option_logmemory)
139 amb 1398 {
140 amb 1598 if(option_logtime)
141     fprintf_elapsed_time(stdout,&program_start_time);
142    
143     if(option_logmemory)
144     fprintf_max_memory(stdout,program_max_alloc,program_max_mmap);
145    
146 amb 1610 printf("Finish Program\n");
147 amb 1601
148     if(option_logtime==2)
149 amb 2001 printf("[ m:ss.micros] ");
150 amb 1601 else if(option_logtime==1)
151 amb 2001 printf("[ m:ss.mil] ");
152 amb 1601
153     if(option_logmemory)
154 amb 2001 printf("[ RAM,FILE MB] ");
155 amb 1601
156 amb 1610 if(option_logtime)
157     printf("elapsed time");
158    
159     if(option_logmemory)
160     {
161     if(option_logtime)
162     printf(", ");
163     printf("maximum memory");
164     }
165    
166 amb 1601 printf("\n");
167    
168 amb 1398 fflush(stdout);
169     }
170     }
171    
172    
173     /*++++++++++++++++++++++++++++++++++++++
174 amb 680 Print the first message in an overwriting sequence (to stdout).
175 amb 520
176     const char *format The format string.
177    
178     ... The other arguments.
179     ++++++++++++++++++++++++++++++++++++++*/
180    
181     void printf_first(const char *format, ...)
182     {
183     va_list ap;
184    
185 amb 982 if(option_logtime)
186 amb 1398 gettimeofday(&function_start_time,NULL);
187 amb 982
188 amb 1598 if(option_logmemory)
189     {
190     function_max_alloc=current_alloc;
191     function_max_mmap=current_mmap;
192     }
193    
194 amb 520 if(option_loggable)
195     return;
196    
197     va_start(ap,format);
198    
199     vfprintf_first(stdout,format,ap);
200    
201     va_end(ap);
202     }
203    
204    
205     /*++++++++++++++++++++++++++++++++++++++
206 amb 680 Print the middle message in an overwriting sequence (to stdout).
207 amb 520
208     const char *format The format string.
209    
210     ... The other arguments.
211     ++++++++++++++++++++++++++++++++++++++*/
212    
213     void printf_middle(const char *format, ...)
214     {
215     va_list ap;
216    
217     if(option_loggable)
218     return;
219    
220     va_start(ap,format);
221    
222     vfprintf_middle(stdout,format,ap);
223    
224     va_end(ap);
225     }
226    
227    
228     /*++++++++++++++++++++++++++++++++++++++
229 amb 680 Print the last message in an overwriting sequence (to stdout).
230 amb 520
231     const char *format The format string.
232    
233     ... The other arguments.
234     ++++++++++++++++++++++++++++++++++++++*/
235    
236     void printf_last(const char *format, ...)
237     {
238     va_list ap;
239    
240     va_start(ap,format);
241    
242     vfprintf_last(stdout,format,ap);
243    
244     va_end(ap);
245     }
246    
247    
248     /*++++++++++++++++++++++++++++++++++++++
249 amb 680 Print the first message in an overwriting sequence to a specified file.
250 amb 520
251     FILE *file The file to write to.
252    
253     const char *format The format string.
254    
255     ... The other arguments.
256     ++++++++++++++++++++++++++++++++++++++*/
257    
258     void fprintf_first(FILE *file,const char *format, ...)
259     {
260     va_list ap;
261    
262 amb 982 if(option_logtime)
263 amb 1398 gettimeofday(&function_start_time,NULL);
264 amb 982
265 amb 1598 if(option_logmemory)
266 amb 1613 {
267     function_max_alloc=current_alloc;
268     function_max_mmap=current_mmap;
269     }
270 amb 1598
271 amb 520 if(option_loggable)
272     return;
273    
274     va_start(ap,format);
275    
276     vfprintf_first(file,format,ap);
277    
278     va_end(ap);
279     }
280    
281    
282     /*++++++++++++++++++++++++++++++++++++++
283 amb 680 Print the middle message in an overwriting sequence to a specified file.
284 amb 520
285     FILE *file The file to write to.
286    
287     const char *format The format string.
288    
289     ... The other arguments.
290     ++++++++++++++++++++++++++++++++++++++*/
291    
292     void fprintf_middle(FILE *file,const char *format, ...)
293     {
294     va_list ap;
295    
296     if(option_loggable)
297     return;
298    
299     va_start(ap,format);
300    
301     vfprintf_middle(file,format,ap);
302    
303     va_end(ap);
304     }
305    
306    
307     /*++++++++++++++++++++++++++++++++++++++
308 amb 680 Print the last message in an overwriting sequence to a specified file.
309 amb 520
310     FILE *file The file to write to.
311    
312     const char *format The format string.
313    
314     ... The other arguments.
315     ++++++++++++++++++++++++++++++++++++++*/
316    
317     void fprintf_last(FILE *file,const char *format, ...)
318     {
319     va_list ap;
320    
321     va_start(ap,format);
322    
323     vfprintf_last(file,format,ap);
324    
325     va_end(ap);
326     }
327    
328    
329     /*++++++++++++++++++++++++++++++++++++++
330 amb 1598 Record the memory allocations (record the amount in use).
331    
332     void *address The address that has been allocated.
333    
334     size_t size The size of the memory that has been allocated.
335     ++++++++++++++++++++++++++++++++++++++*/
336    
337     void log_malloc(void *address,size_t size)
338     {
339 amb 1600 int i;
340    
341     if(!option_logmemory)
342     return;
343    
344 amb 1598 /* Store the information about the allocated memory */
345    
346 amb 1600 for(i=0;i<nmallocedmem;i++)
347     if(mallocedmem[i].address==address)
348     {
349     size=size-mallocedmem[i].size;
350     mallocedmem[i].size+=size;
351     break;
352     }
353 amb 1598
354 amb 1600 if(i==nmallocedmem)
355     {
356     mallocedmem=(struct mallocinfo*)realloc((void*)mallocedmem,(nmallocedmem+1)*sizeof(struct mallocinfo));
357 amb 1598
358 amb 1600 mallocedmem[nmallocedmem].address=address;
359     mallocedmem[nmallocedmem].size=size;
360 amb 1598
361 amb 1600 nmallocedmem++;
362     }
363    
364 amb 1598 /* Increase the sum of allocated memory */
365    
366     current_alloc+=size;
367    
368     if(current_alloc>function_max_alloc)
369     function_max_alloc=current_alloc;
370    
371     if(current_alloc>program_max_alloc)
372     program_max_alloc=current_alloc;
373     }
374    
375    
376     /*++++++++++++++++++++++++++++++++++++++
377     Record the memory de-allocations.
378    
379     void *address The address that has been freed.
380     ++++++++++++++++++++++++++++++++++++++*/
381    
382     void log_free(void *address)
383     {
384     size_t size=0;
385     int i;
386    
387 amb 1600 if(!option_logmemory)
388     return;
389    
390 amb 1598 /* Remove the information about the allocated memory */
391    
392     for(i=0;i<nmallocedmem;i++)
393     if(mallocedmem[i].address==address)
394     {
395     size=mallocedmem[i].size;
396     break;
397     }
398    
399     logassert(i!=nmallocedmem,"Memory freed with log_free() was not allocated with log_[cm]alloc()");
400    
401     nmallocedmem--;
402    
403     if(nmallocedmem>i)
404     memmove(&mallocedmem[i],&mallocedmem[i+1],(nmallocedmem-i)*sizeof(struct mallocinfo));
405    
406     /* Reduce the sum of allocated memory */
407    
408     current_alloc-=size;
409     }
410    
411    
412     /*++++++++++++++++++++++++++++++++++++++
413     Record the amount of memory that has been mapped into files.
414    
415     size_t size The size of the file that has been mapped.
416     ++++++++++++++++++++++++++++++++++++++*/
417    
418     void log_mmap(size_t size)
419     {
420 amb 1600 if(!option_logmemory)
421     return;
422    
423 amb 1598 current_mmap+=size;
424    
425     if(current_mmap>function_max_mmap)
426     function_max_mmap=current_mmap;
427    
428     if(current_mmap>program_max_mmap)
429     program_max_mmap=current_mmap;
430     }
431    
432    
433     /*++++++++++++++++++++++++++++++++++++++
434     Record the amount of memory that has been unmapped from files.
435    
436     size_t size The size of the file that has been unmapped.
437     ++++++++++++++++++++++++++++++++++++++*/
438    
439     void log_munmap(size_t size)
440     {
441 amb 1600 if(!option_logmemory)
442     return;
443    
444 amb 1598 current_mmap-=size;
445     }
446    
447    
448     /*++++++++++++++++++++++++++++++++++++++
449 amb 680 Do the work to print the first message in an overwriting sequence.
450 amb 520
451     FILE *file The file to write to.
452    
453     const char *format The format string.
454    
455     va_list ap The other arguments.
456     ++++++++++++++++++++++++++++++++++++++*/
457    
458     static void vfprintf_first(FILE *file,const char *format,va_list ap)
459     {
460     int retval;
461    
462 amb 982 if(option_logtime)
463 amb 1398 fprintf_elapsed_time(file,&function_start_time);
464 amb 982
465 amb 1598 if(option_logmemory)
466     fprintf_max_memory(file,function_max_alloc,function_max_mmap);
467    
468 amb 520 retval=vfprintf(file,format,ap);
469     fflush(file);
470    
471     if(retval>0)
472     printed_length=retval;
473     }
474    
475    
476     /*++++++++++++++++++++++++++++++++++++++
477 amb 680 Do the work to print the middle message in an overwriting sequence.
478 amb 520
479     FILE *file The file to write to.
480    
481     const char *format The format string.
482    
483     va_list ap The other arguments.
484     ++++++++++++++++++++++++++++++++++++++*/
485    
486     static void vfprintf_middle(FILE *file,const char *format,va_list ap)
487     {
488     int retval;
489    
490 amb 1193 fputc('\r',file);
491 amb 982
492     if(option_logtime)
493 amb 1398 fprintf_elapsed_time(file,&function_start_time);
494 amb 982
495 amb 1598 if(option_logmemory)
496     fprintf_max_memory(file,function_max_alloc,function_max_mmap);
497    
498 amb 520 retval=vfprintf(file,format,ap);
499     fflush(file);
500    
501     if(retval>0)
502 amb 648 {
503     int new_printed_length=retval;
504    
505     while(retval++<printed_length)
506 amb 1193 fputc(' ',file);
507 amb 648
508     printed_length=new_printed_length;
509     }
510 amb 520 }
511    
512    
513     /*++++++++++++++++++++++++++++++++++++++
514 amb 680 Do the work to print the last message in an overwriting sequence.
515 amb 520
516     FILE *file The file to write to.
517    
518     const char *format The format string.
519    
520     va_list ap The other arguments.
521     ++++++++++++++++++++++++++++++++++++++*/
522    
523     static void vfprintf_last(FILE *file,const char *format,va_list ap)
524     {
525     int retval;
526    
527     if(!option_loggable)
528 amb 1193 fputc('\r',file);
529 amb 982
530     if(option_logtime)
531 amb 1398 fprintf_elapsed_time(file,&function_start_time);
532 amb 982
533 amb 1598 if(option_logmemory)
534     fprintf_max_memory(file,function_max_alloc,function_max_mmap);
535    
536 amb 520 retval=vfprintf(file,format,ap);
537    
538     if(retval>0)
539     while(retval++<printed_length)
540 amb 1193 fputc(' ',file);
541 amb 520
542 amb 1193 fputc('\n',file);
543 amb 520 fflush(file);
544     }
545 amb 804
546    
547     /*++++++++++++++++++++++++++++++++++++++
548 amb 982 Print the elapsed time without a following newline.
549    
550     FILE *file The file to print to.
551    
552     struct timeval *start The start time from which the elapsed time is to be printed.
553     ++++++++++++++++++++++++++++++++++++++*/
554    
555 amb 1596 static void fprintf_elapsed_time(FILE *file,struct timeval *start)
556 amb 982 {
557     struct timeval finish,elapsed;
558    
559     gettimeofday(&finish,NULL);
560    
561     elapsed.tv_sec =finish.tv_sec -start->tv_sec;
562     elapsed.tv_usec=finish.tv_usec-start->tv_usec;
563     if(elapsed.tv_usec<0)
564     {
565     elapsed.tv_sec -=1;
566     elapsed.tv_usec+=1000000;
567     }
568    
569 amb 1601 if(option_logtime==2)
570 amb 2001 fprintf(file,"[%3ld:%02ld.%06ld] ",elapsed.tv_sec/60,elapsed.tv_sec%60,elapsed.tv_usec);
571 amb 1601 else
572 amb 2001 fprintf(file,"[%3ld:%02ld.%03ld] ",elapsed.tv_sec/60,elapsed.tv_sec%60,elapsed.tv_usec/1000);
573 amb 982 }
574    
575    
576     /*++++++++++++++++++++++++++++++++++++++
577 amb 1598 Print the maximum used memory without a following newline.
578    
579     FILE *file The file to print to.
580    
581     size_t max_alloc The maximum amount of allocated memory.
582    
583     size_t max_mmap The maximum amount of memory mapped memory.
584     ++++++++++++++++++++++++++++++++++++++*/
585    
586     static void fprintf_max_memory(FILE *file,size_t max_alloc,size_t max_mmap)
587     {
588 amb 2001 fprintf(file,"[%4zu,%4zu MB] ",max_alloc/(1024*1024),max_mmap/(1024*1024));
589 amb 1598 }
590    
591    
592     /*++++++++++++++++++++++++++++++++++++++
593 amb 1166 Log a fatal error and exit
594    
595     const char *message The error message.
596    
597     const char *file The file in which the error occured.
598    
599     int line The line number in the file at which the error occured.
600     ++++++++++++++++++++++++++++++++++++++*/
601    
602     void _logassert(const char *message,const char *file,int line)
603     {
604     fprintf(stderr,"Routino Fatal Error (%s:%d): %s\n",file,line,message);
605    
606     exit(EXIT_FAILURE);
607     }
608 amb 1999
609    
610     /*++++++++++++++++++++++++++++++++++++++
611     Allocate some memory by calling calloc() and checking for failures.
612    
613     void *calloc_logassert Returns the newly allocated pointer.
614    
615     size_t nmemb The number of members in the array to allocate.
616    
617     size_t size The size of the array to allocate.
618    
619     const char *file The file in which the error occured.
620    
621     int line The line number in the file at which the error occured.
622     ++++++++++++++++++++++++++++++++++++++*/
623    
624     void *_calloc_logassert(size_t nmemb,size_t size,const char *file,int line)
625     {
626     void *temp=calloc(nmemb,size);
627    
628     if(!temp)
629     {
630     char string[64];
631    
632     sprintf(string,"Failed to allocate %zu bytes of memory",nmemb*size);
633    
634     _logassert(string,file,line);
635     }
636    
637     return temp;
638     }
639    
640    
641     /*++++++++++++++++++++++++++++++++++++++
642     Allocate some memory by calling malloc() and checking for failures.
643    
644     void *malloc_logassert Returns the newly allocated pointer.
645    
646     size_t size The size of the memory to allocate.
647    
648     const char *file The file in which the error occured.
649    
650     int line The line number in the file at which the error occured.
651     ++++++++++++++++++++++++++++++++++++++*/
652    
653     void *_malloc_logassert(size_t size,const char *file,int line)
654     {
655     void *temp=malloc(size);
656    
657     if(!temp)
658     {
659     char string[64];
660    
661     sprintf(string,"Failed to allocate %zu bytes of memory",size);
662    
663     _logassert(string,file,line);
664     }
665    
666     return temp;
667     }
668    
669    
670     /*++++++++++++++++++++++++++++++++++++++
671     Allocate some memory by calling realloc() and checking for failures.
672    
673     void *realloc_logassert Returns the newly allocated pointer.
674    
675     void *ptr An existing pointer to be reallocated.
676    
677     size_t size The size of the memory to allocate.
678    
679     const char *file The file in which the error occured.
680    
681     int line The line number in the file at which the error occured.
682     ++++++++++++++++++++++++++++++++++++++*/
683    
684     void *_realloc_logassert(void *ptr,size_t size,const char *file,int line)
685     {
686     void *temp=realloc(ptr,size);
687    
688     if(!temp)
689     {
690     char string[64];
691    
692     sprintf(string,"Failed to allocate %zu bytes of memory",size);
693    
694     _logassert(string,file,line);
695     }
696    
697     return temp;
698     }