Reconsider Profiling

[andre-merzky]

The number of entries in our profiles is becoming unwieldy - it is increasingly difficult to compute the required performance metrics (durations, utilizations) from those profiles.

Here is a proposal on how to reduce the number of events, the size of events, and the required computational effort.

Current profile entries are structured like this:

#time,event,comp,thread,uid,state,msg
1613997951.7516530,sync_abs,agent_scheduling.0000,MainThread,,,rivendell:10.0.0.10:1613997951.7515883:1613997951.7526543:ntp
1613997951.7522063,comp_start,agent_scheduling.0000,MainThread,agent_scheduling.0000,,
#time,event,comp,thread,uid,state,msg
1613997951.8680129,sync_abs,agent_scheduling.0000,MainThread,,,rivendell:10.0.0.10:1613997951.8679616:1613997951.8690276:ntp
1613997951.8680527,init1,agent_scheduling.0000,MainThread,agent_scheduling.0000,,/mnt/home/merzky/radical.pilot.sandbox/rp.session.rivendell.merzky.018680.0003/pilot.0000
1613997951.8737974,component_init,agent_scheduling.0000,Thread-1,,,
1613997960.4819086,advance,agent_scheduling.0000,Thread-1,task.000000,AGENT_SCHEDULING,
1613997960.4819086,advance,agent_scheduling.0000,Thread-1,task.000001,AGENT_SCHEDULING,
1613997960.4819086,advance,agent_scheduling.0000,Thread-1,task.000002,AGENT_SCHEDULING,
1613997960.4850802,schedule_ok,agent_scheduling.0000,Thread-1,task.000002,,
1613997960.4851284,schedule_ok,agent_scheduling.0000,Thread-1,task.000001,,
1613997960.4851627,schedule_ok,agent_scheduling.0000,Thread-1,task.000000,,
1613997960.4851806,schedule_first,agent_scheduling.0000,Thread-1,task.000002,,
1613997960.4851928,schedule_first,agent_scheduling.0000,Thread-1,task.000001,,
1613997960.4852021,schedule_first,agent_scheduling.0000,Thread-1,task.000000,,
1613997960.4852118,advance,agent_scheduling.0000,Thread-1,task.000002,AGENT_EXECUTING_PENDING,
1613997960.4852118,advance,agent_scheduling.0000,Thread-1,task.000001,AGENT_EXECUTING_PENDING,
1613997960.4852118,advance,agent_scheduling.0000,Thread-1,task.000000,AGENT_EXECUTING_PENDING,
1613997960.6172616,unschedule_stop,agent_scheduling.0000,Thread-1,task.000002,,

Some observations:

• we never use the component or thread information (we know where any specific event originates)
• we almost never use the component level events (comp_*), and are only interested in events for stateful entities (pilot, tasks, pipelines, stages, requests, etc)
• analysis often mixes times for state transitions and times for other events, but they are handled differently in profiles

I would suggest to reduce the above profile to this format:

1613997951.7516530,sync_abs,,rivendell:10.0.0.10:1613997951.7515883:1613997951.7526543:ntp
1613997960.4819086,AGENT_SCHEDULING,task.000000,
1613997960.4819086,AGENT_SCHEDULING,task.000001,
1613997960.4819086,AGENT_SCHEDULING,task.000002,
1613997960.4850802,schedule_ok,task.000002,
1613997960.4851284,schedule_ok,task.000001,
1613997960.4851627,schedule_ok,task.000000,
1613997960.4851806,schedule_first,task.000002,
1613997960.4851928,schedule_first,task.000001,
1613997960.4852021,schedule_first,task.000000,
1613997960.4852118,advance,task.000002,
1613997960.4852118,advance,task.000001,
1613997960.4852118,advance,task.000000,
1613997960.6172616,unschedule_stop,task.000002,

and thus limit the recorded fields to [time, event, uid, msg] where uid and msg are optional, and entries w/o uid's should be rare. State transitions are special named events, so it is easier to address them in the same analysis:

print(entity.duration([`AGENT_SCHEDULING`, `scheduling_ok`])

[mturilli]

As we previously discussed, I would use the opportunity to change the way in which we record and write to disk events in RCT at runtime. The idea would be to have a centralized 'tracer' component that get all the events from all the other components via ZMQ. This would have multiple benefits, notably: reducing/eliminating the overhead of component-level profiler; avoiding to have to deal with 'thread-safety' issues when writing to disk the traces; and, relevant to this discussion, enable configurable events for each component.

[andre-merzky]

Comment from Mikhail: partition IDs may be important in the future

[andre-merzky]

• consider / measure queue vs. pubsub
• consider dashboard as direct consumer
• need some profiling on queue / pubsub
• database backend not a priority