How do you profile molecule test matrix runs?

[timblaktu]

I understand how to configure profiling for the underlying ansible playbooks that get run during molecule converge, but I'm interested in profiling molecule itself. I care because in my current dev cycle, the overall molecule converge command is taking over 6 minutes (as reported by time command), but the task/role elapsed times reported by the ansible callbacks I've got configured (timer, profile_tasks, profile_roles) only sum up to just over a minute.

When I run a molecule command, e.g. molecule converge, I'd like to see the time it took to run each stage in the molecule test sequence, e.g. the in MM:SS.msec additions in the below molecule output:

INFO     deb10-headless scenario test matrix: dependency, create, prepare, converge
INFO     Performing prerun with role_name_check=0...
INFO     Running deb10-headless > dependency
INFO     Dependency completed successfully in MM:SS.msec
INFO     Running deb10-headless > create
WARNING  Skipping, instances already created.
INFO     Running deb10-headless > prepare
WARNING  Skipping, prepare playbook not configured.
INFO     Running deb10-headless > converge
INFO     Converge completed successfully in MM:SS.msec

I'm using molecule --debug and it's not even showing timestamps anywhere. The output I see is same as above proposal, sans the in MM:SS.msec bit.

[zhan9san]

Hi @timblaktu

This is a great idea.

Would you mind submitting a PR to address it?

I am glad to review it.