Re: Logging Library-GSOC

[Vincent Torri]

On Thu, Jul 16, 2020 at 8:30 AM Priyesh kumar <priyeshkkumar@gmail.com> wrote:
>
> Hi,
> I was trying profiling on the example program given @ here.
> I have used the profiling tool inbuilt in Visual Studios but was unable to
> extract useful information from it, therefore I have tried a solution provided
> on Stack Overflow @ here . It basically uses `clock()` function to calculate 
> the
> running time of the program.

you can use query performance counter/frequency on Windows. I find
them a bit more accurate than anything else :

static LARGE_INTEGER freq;
static LARGE_INTEGER count1;
static LARGE_INTEGER count2;

you call once, at the beginning :
QueryPerformanceFrequency(&freq);

before the code you want to profile :

QueryPerformanceCounter(&count1);

at the end :

QueryPerformanceCounter(&count2);

number of seconds (as a double ):
double t = (double)((count2.QuadPart - count1.QuadPart) / freq.QuadPart);

regards

Vincent Torri




> So, basically I have used two variables of type time_t one at the start and 
> one
> at the end of the program marking the clock time at those steps and in the end
> the program prints the time taken by the program in seconds.
> For averaging out the result I have used a  for loop running the example code 
> 10
> times every time the code is is executed and at the end of each iteration it 
> writes the difference
> between the start time and end time to a file in seconds.
> I have attached the file in which it writes the results.
> I have tested the above solution on Ubuntu 20.04 LTS and got the following 
> results:
> No Debugging mode (avg time: 0.0164531 sec)
> Debugging using FT_DEBUG_LEVEL_TRACE mode (avg time: 0.0988122 sec)
> Debugging using FT_LOGGING mode (avg time: 0.0512144)
>
> Please look into this and provide feedback...
>
> Thanks,
> Priyesh
>
>
>
> On Tue, Jul 14, 2020 at 4:43 PM Priyesh kumar <priyeshkkumar@gmail.com> wrote:
>>
>> Hi again,
>> I accidentally sent the previous mail
>> Continuing to the previous mail...
>> Also in the requirements, you told me to provide an option in MakeFile `make 
>> dist` to build the
>> external library. But dlg uses meson build system and I don't have any idea 
>> how to combine
>> meson build system with MakeFile, therefore could you provide me some 
>> references from where
>> I can read about doing this...
>>
>> Thanks,
>> Priyesh
>>
>> On Tue, Jul 14, 2020 at 4:37 PM Priyesh kumar <priyeshkkumar@gmail.com> 
>> wrote:
>>>
>>> Hi,
>>> I have added an option in `FT2_DEBUG` environment variable to 
>>> enable/disable the
>>> printing of FT_COMPONENT and Timestamp with a log message.
>>> The discussion related to dlg's features is still going, therefore in the 
>>> meantime I was
>>> thinking of extending the support on Windows.
>>> After looking: builds/windows/vc2010 , builds/windows/visualc and 
>>> builds/windows/visulace
>>> I can see that they all depend on builds/windows/ftdebug.c, therefore I 
>>> wanted to ask that
>>> Do I have to change only this file or there are some other files that I 
>>> have to take care of?
>>>
>>> Also in the requirements, you told me to provide an option in MakeFile 
>>> `make dist
>>>
>>> On Sun, Jul 12, 2020 at 2:50 PM Priyesh kumar <priyeshkkumar@gmail.com> 
>>> wrote:
>>>>
>>>> Hi armin,
>>>>
>>>> > This would print wrong-ish timestamps that couldn't really be used for 
>>>> > profiling (I mean, it could; you just have to know which timestamp 
>>>> > belongs to which message).  I would suggest to
>>>> > rather store a flag after reading `\n` and attach the timestamp to the 
>>>> > following message.
>>>>
>>>> I am also following this approach for printing timestamp and FT_COMPONENT.
>>>> Actually dlg uses a flag `dlg_features` in which different features like  
>>>> `dlg_output_timestamp`(for timestamps) and `dlg_output_tags`(for 
>>>> FT_COMPONENTS) are summed up using binary OR operator.
>>>> For the first log message, these flags are kept ON so that timestamp and 
>>>> FT_COMPONENT values are printed, and for the next coming log messages the 
>>>> following logic is used:
>>>> If the current log message contains a `\n` in it then the flags will be 
>>>> toggled ON for the next coming log message assuming that it is end of a 
>>>> log message,
>>>> and if the current log message doesn't contain `\n` then these flags are 
>>>> toggled OFF for the next coming log message assuming that it is in 
>>>> continuation of current log message.
>>>>
>>>> > Also, I would believe that `fmt[strlen(fmt) - 1] == '\n'` is rather 
>>>> > fast, esp. given that this is followed by an IO operation.  To be tested 
>>>> > though :)
>>>> OK
>>>>
>>>> > Writing this lead me to look for multi-linebreak traces (e.g. 
>>>> > src/pcf/pfcread.c:504) -- should that have one timestamp for the entire 
>>>> > statement or one timestamp per line?
>>>>
>>>> With the above logic for these types of logs, there will be one timestamp 
>>>> per line...
>>>>
>>>> Thanks,
>>>> Priyesh
>>>>
>>>> On Sun, Jul 12, 2020 at 2:02 PM <armin@hasitzka.com> wrote:
>>>>>
>>>>> > Since debugging isn't time critical it might be necessary to add an 
>>>>> > additional
>>>>> > step that scans tracing messages for newline characters, then massaging 
>>>>> > the
>>>>> > output by inserting the time stamp.  In other words, all occurrences of
>>>>> >
>>>>> >   `\n`
>>>>> >
>>>>> > should be replaced with
>>>>> >
>>>>> >   `\n[time stamp] `
>>>>> >
>>>>> > or something similar.
>>>>>
>>>>> This would print wrong-ish timestamps that couldn't really be used for 
>>>>> profiling (I mean, it could; you just have to know which timestamp 
>>>>> belongs to which message).  I would suggest to rather store a flag after 
>>>>> reading `\n` and attach the timestamp to the following message.  Also, I 
>>>>> would believe that `fmt[strlen(fmt) - 1] == '\n'` is rather fast, esp. 
>>>>> given that this is followed by an IO operation.  To be tested though :)
>>>>>
>>>>> Writing this lead me to look for multi-linebreak traces (e.g. 
>>>>> src/pcf/pfcread.c:504) -- should that have one timestamp for the entire 
>>>>> statement or one timestamp per line?
>>>>>
>>>>> Armin
>>>>>