key4hep / k4FWCore

Core Components for the Gaudi-based Key4hep Framework
Apache License 2.0
10 stars 26 forks source link

Option to print timing info? #229

Closed alexandertuna closed 1 week ago

alexandertuna commented 2 weeks ago

Hi developers, @Lrozzy and I have a small question: is there an option to print timing information with k4run, either at the CL or in the algs? e.g. something like:

[MESSAGE "Marlin"]  Total: 2.096301e+02 s in 3 events  ==> 6.987670e+01 [ s/evt.]

I thought this feature existed, but I can't find it, so perhaps I imagined it. Do you know if this feature exists?

Thanks! Alex

jmcarcell commented 1 week ago

Try this, it seems to be accurate enough from my testing:

from Configurables import AuditorSvc, AlgTimingAuditor
auditor = AuditorSvc()
auditor.Auditors = [AlgTimingAuditor()]

and then you add auditor to the list of external services passed to ApplicationMgr like:

ApplicationMgr(
    TopAlg=[producer],
    EvtSel="NONE",
    EvtMax=10 if not args[0].second else 20,
    ExtSvc=[EventDataSvc("EventDataSvc"), auditor],
    OutputLevel=INFO,
)

Running an algorithm that sleeps for one second I get in the output:

AlgTimingAuditor     INFO -------------------------------------------------------------------
AlgTimingAuditor     INFO Algorithm                      | exec (ms) |   count   | total (s)
AlgTimingAuditor     INFO -------------------------------------------------------------------
AlgTimingAuditor     INFO EVENT LOOP                     |      1004 |        10 |     10.04
AlgTimingAuditor     INFO -------------------------------------------------------------------
m-fila commented 1 week ago

AlgTimingAuditor should be the way to go

But in case you'd like to later record some more information then there is also TimelineSvc that can output simple csv file with start and stop (ns) timestamps for each algorithm

from Configurables import TimelineSvc
TimelineSvc(RecordTimeline=True, DumpTimeline=True, TimelineFile="timeline.csv" )
alexandertuna commented 1 week ago

Thanks very much @jmcarcell and @m-fila ! Both of these suggestions look great. We'll use them.

I'm happy to close the issue now but please feel free to reopen in case something else comes to mind.