Where is the time being spent?
<p>I have a xml file, that contains record element. I am converting data inside record element to PCAP format.  The code is shown below. Within the do loop, i am only spending 6 miliseconds, but when i take time exactly at the boundaries of loop, it shows i am spending 43 miliseconds.. where is this difference comming from?
Also, i am new'ing up the memory inside the loop. Is that acceptable practice or should i zero up the memory and reuse it? Will reuse give any performance gains?
The time within loop is as shown below</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466589,End Time:1030466589</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466590,End Time:1030466590</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466591,End Time:1030466591</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466591,End Time:1030466591</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466592,End Time:1030466592</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466593,End Time:1030466593</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466593,End Time:1030466593</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466594,End Time:1030466594</p>

<p>2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466595,End Time:1030466595</p>

<p>But time on boundary of do loop is
2012-05-14 07:26:48 ThreadID(19404) TRACE:start Time:1030466584,End Time:1030466627</p>

<pre><code>        static struct tms st_cpu;
        static struct tms et_cpu;
        clock_t end_time;
        clock_t start_time;
        char szData[100] = {0};
        clock_t st_total_time;
        clock_t et_total_time;
        static struct tms st_total_cpu;
        static struct tms et_total_cpu;
        st_total_time = times(&amp;st_total_cpu);
        do {
        char *pBuffer = new char[m_nBufferLen];
        memset(pBuffer,0,m_nBufferLen);
            if(fgets(pBuffer,m_nBufferLen,fpcap) != NULL)
            {
                    char *pRecord = NULL;
                    if((pRecord = strstr(pBuffer,"&lt;rec ")) != NULL)
                    {
                            start_time = times(&amp;st_cpu);
                            CXMLParser objXMLParser(pBuffer);
                            objXMLParser.ProcessRecord();
                            objPCAPGenerator.GeneratePCAPRecord(&amp;objXMLParser);
                            end_time = times(&amp;et_cpu);

                            sprintf(szData,"start Time:%ld,End Time:%ld",start_time,end_time);
                            CLog::PrintLog(DBG_TRACE,"%s",szData);


                            sprintf(szData,"Real Time: %ld,UserTime:%ld,SystemTime:%ld",
                                            end_time-start_time,
                                            (et_cpu.tms_utime + et_cpu.tms_cutime) - (st_cpu.tms_utime + st_cpu.tms_cutime),
                                            (et_cpu.tms_stime + et_cpu.tms_cstime) -(st_cpu.tms_stime + st_cpu.tms_cstime)
                                            );
                            CLog::PrintLog(DBG_TRACE,"%s",szData);
                    }
            }
            else
            {
                    bEnd = true;
            }
    }while(bEnd != true);

    et_total_time = times(&amp;et_total_cpu);

    sprintf(szData,"start Time:%ld,End Time:%ld",st_total_time,et_total_time);
    CLog::PrintLog(DBG_TRACE,"%s",szData);


    sprintf(szData,"Total Real Time: %ld,Total UserTime:%ld,Total SystemTime:%ld",
                    et_total_time-st_total_time,
                    (et_total_cpu.tms_utime + et_total_cpu.tms_cutime) - (st_total_cpu.tms_utime + st_total_cpu.tms_cutime),
                    (et_total_cpu.tms_stime + et_total_cpu.tms_cstime) -(st_total_cpu.tms_stime + st_total_cpu.tms_cstime)
                    );
    CLog::PrintLog(DBG_TRACE,"%s",szData);
</code></pre>
