@@ -266,42 +266,19 @@ int32_t GPUReconstructionCPU::RunChains()
266266 std::vector<double > kernelStepTimes (gpudatatypes::N_RECO_STEPS, 0 .);
267267 std::ofstream timingCSVFile;
268268 if (!GetProcessingSettings ().timingCSV .empty ()) {
269- bool needHeader = true ;
270- {
271- std::ifstream timingCSVIn (GetProcessingSettings ().timingCSV );
272- needHeader = !timingCSVIn.good () || timingCSVIn.peek () == std::ifstream::traits_type::eof ();
273- }
274- timingCSVFile.open (GetProcessingSettings ().timingCSV , std::ios::out | std::ios::app);
275- if (!timingCSVFile.is_open ()) {
276- GPUError (" Could not open timing CSV file '%s' for writing" , GetProcessingSettings ().timingCSV .c_str ());
277- } else if (needHeader) {
278- timingCSVFile << " name,time,count,events\n " ;
279- }
269+ timingCSVFile.open (GetProcessingSettings ().timingCSV , std::ios::binary | std::ofstream::app);
270+ if (mNEventsProcessed == 1 ) timingCSVFile << " name,time,count,type\n " ;
271+ if (!timingCSVFile.is_open ()) GPUError (" Could not open timing CSV file '%s' for writing" , GetProcessingSettings ().timingCSV .c_str ());
280272 }
281- auto writeCSVString = [](std::ostream& out, const std::string& s) {
282- out << ' "' ;
283- for (char c : s) {
284- if (c == ' "' ) {
285- out << " \"\" " ;
286- } else {
287- out << c;
288- }
289- }
290- out << ' "' ;
291- };
292273
293274 if (GetProcessingSettings ().debugLevel >= 1 ) {
294275 for (uint32_t i = 0 ; i < mTimers .size (); i++) {
295276 double time = 0 ;
296- if (mTimers [i] == nullptr ) {
297- continue ;
298- }
277+ if (mTimers [i] == nullptr ) continue ;
299278 for (int32_t j = 0 ; j < mTimers [i]->num ; j++) {
300279 HighResTimer& timer = mTimers [i]->timer [j];
301280 time += timer.GetElapsedTime ();
302- if (GetProcessingSettings ().resetTimers ) {
303- timer.Reset ();
304- }
281+ if (GetProcessingSettings ().resetTimers ) timer.Reset ();
305282 }
306283
307284 uint32_t type = mTimers [i]->type ;
@@ -314,11 +291,9 @@ int32_t GPUReconstructionCPU::RunChains()
314291 if (mTimers [i]->memSize && mStatNEvents && time != 0 .) {
315292 snprintf (bandwidth, 256 , " (%8.3f GB/s - %'14zu bytes - %'14zu per call)" , mTimers [i]->memSize / time * 1e-9 , mTimers [i]->memSize / mStatNEvents , mTimers [i]->memSize / mStatNEvents / mTimers [i]->count );
316293 }
317- printf (" Execution Time: Task (%c %8ux): %50s Time: %'10.0f us%s\n " , type == 0 ? ' K' : ' C' , mTimers [i]->count , mTimers [i]->name .c_str (), time * 1000000 / mStatNEvents , bandwidth);
318- if (timingCSVFile.is_open ()) {
319- writeCSVString (timingCSVFile, mTimers [i]->name );
320- timingCSVFile << " ," << (time * 1000000 / mStatNEvents ) << " ," << mTimers [i]->count << " ," << mStatNEvents << " \n " ;
321- }
294+ double elapsedTime_ms = time * 1000000 / mStatNEvents ;
295+ printf (" Execution Time: Task (%c %8ux): %50s Time: %'10.0f us%s\n " , type == 0 ? ' K' : ' C' , mTimers [i]->count , mTimers [i]->name .c_str (), elapsedTime_ms, bandwidth);
296+ if (timingCSVFile.is_open ()) timingCSVFile << mTimers [i]->name << " ," << elapsedTime_ms << " ," << mTimers [i]->count << " ,Task\n " ;
322297 if (GetProcessingSettings ().resetTimers ) {
323298 mTimers [i]->count = 0 ;
324299 mTimers [i]->memSize = 0 ;
@@ -328,8 +303,10 @@ int32_t GPUReconstructionCPU::RunChains()
328303 if (GetProcessingSettings ().recoTaskTiming ) {
329304 for (int32_t i = 0 ; i < gpudatatypes::N_RECO_STEPS; i++) {
330305 if (kernelStepTimes[i] != 0 . || mTimersRecoSteps [i].timerTotal .GetElapsedTime () != 0 .) {
306+ double elapsedTime_ms = kernelStepTimes[i] * 1000000 / mStatNEvents ;
331307 printf (" Execution Time: Step : %11s %38s Time: %'10.0f us %64s ( Total Time : %'14.0f us, CPU Time : %'14.0f us, %'7.2fx )\n " , " Tasks" ,
332- gpudatatypes::RECO_STEP_NAMES[i], kernelStepTimes[i] * 1000000 / mStatNEvents , " " , mTimersRecoSteps [i].timerTotal .GetElapsedTime () * 1000000 / mStatNEvents , mTimersRecoSteps [i].timerCPU * 1000000 / mStatNEvents , mTimersRecoSteps [i].timerCPU / mTimersRecoSteps [i].timerTotal .GetElapsedTime ());
308+ gpudatatypes::RECO_STEP_NAMES[i], elapsedTime_ms, " " , mTimersRecoSteps [i].timerTotal .GetElapsedTime () * 1000000 / mStatNEvents , mTimersRecoSteps [i].timerCPU * 1000000 / mStatNEvents , mTimersRecoSteps [i].timerCPU / mTimersRecoSteps [i].timerTotal .GetElapsedTime ());
309+ if (timingCSVFile.is_open ()) timingCSVFile << gpudatatypes::RECO_STEP_NAMES[i] << " ," << elapsedTime_ms << " ,1,Step\n " ;
333310 }
334311 if (mTimersRecoSteps [i].bytesToGPU ) {
335312 printf (" Execution Time: Step (D %8ux): %11s %38s Time: %'10.0f us (%8.3f GB/s - %'14zu bytes - %'14zu per call)\n " , mTimersRecoSteps [i].countToGPU , " DMA to GPU" , gpudatatypes::RECO_STEP_NAMES[i], mTimersRecoSteps [i].timerToGPU .GetElapsedTime () * 1000000 / mStatNEvents ,
@@ -350,17 +327,22 @@ int32_t GPUReconstructionCPU::RunChains()
350327 }
351328 }
352329 for (int32_t i = 0 ; i < gpudatatypes::N_GENERAL_STEPS; i++) {
353- if (mTimersGeneralSteps [i].GetElapsedTime () != 0 .) {
354- printf (" Execution Time: General Step : %50s Time: %'10.0f us\n " , gpudatatypes::GENERAL_STEP_NAMES[i], mTimersGeneralSteps [i].GetElapsedTime () * 1000000 / mStatNEvents );
330+ double elapsedTime_ms = mTimersGeneralSteps [i].GetElapsedTime () * 1000000 / mStatNEvents ;
331+ if (elapsedTime_ms != 0 .) {
332+ printf (" Execution Time: General Step : %50s Time: %'10.0f us\n " , gpudatatypes::GENERAL_STEP_NAMES[i], elapsedTime_ms);
333+ if (timingCSVFile.is_open ()) timingCSVFile << gpudatatypes::GENERAL_STEP_NAMES[i] << " ," << elapsedTime_ms << " ,1,Step\n " ;
355334 }
356335 }
357336 if (GetProcessingSettings ().debugLevel >= 1 ) {
358337 mStatKernelTime = kernelTotal * 1000000 / mStatNEvents ;
359338 printf (" Execution Time: Total : %50s Time: %'10.0f us%s\n " , " Total Kernel" , mStatKernelTime , nEventReport.c_str ());
339+ if (timingCSVFile.is_open ()) timingCSVFile << " Total Kernel" << " ," << mStatKernelTime << " ,1,Total\n " ;
360340 }
361341 printf (" Execution Time: Total : %50s Time: %'10.0f us ( CPU Time : %'10.0f us, %7.2fx ) %s\n " , " Total Wall" , mStatWallTime , mStatCPUTime * 1000000 / mStatNEvents , mStatCPUTime / mTimerTotal .GetElapsedTime (), nEventReport.c_str ());
342+ if (timingCSVFile.is_open ()) timingCSVFile << " Total Wall" << " ," << mStatWallTime << " ,1,Total\n " ;
362343 } else if (GetProcessingSettings ().debugLevel >= 0 ) {
363344 GPUInfo (" Total Wall Time: %10.0f us%s" , mStatWallTime , nEventReport.c_str ());
345+ if (timingCSVFile.is_open ()) timingCSVFile << " Total Wall" << " ," << mStatWallTime << " ,1,Total\n " ;
364346 }
365347 if (GetProcessingSettings ().resetTimers ) {
366348 mStatNEvents = 0 ;
0 commit comments