I’ve not been able to locate documentation to say this is or isn’t the expected behavior, so I am hoping someone can chime in. While the UI stdout displays timestamps of tasks, the downloadable version, and the version retrieved from the REST service do not. I’m on the latest Operator and AWX version, though I don’t recall that this wasn’t the same behavior in previous versions I’ve used as well. I did see an over two year old issue posted on GitHub with no responses about the downloadable version, but it’s not clear if this is just the intended behavior, but it would be nice to have the timestamps to match up to other events when you process the output externally.
Perhaps it is intended in the recent AWX implementation.
As an easy workaround, you can enable the ansible.posix.profile_tasks callback plugin by adding ANSIBLE_CALLBACKS_ENABLED environment variable under Settings > Jobs page.
This adds the timestamps per tasks in UTC. These timestamps are also included in the downloaded log files.
@kurokobo +1 cause I didn’t know that was a feature I needed.
It sounds like @netopsengineer already has that enabled, but that timestamp in the callback isn’t being included in the downloaded output (from clicking “Download Output”) or in the rest API.
This can be found in any given job ID. In my case, /api/v2/project_updates/831/ has "started" and "finished" fields, but there is also "canceled_on" and possibly other timestamp fields for different job states. The metadata can only be found through the UI or API though, not in the downloaded output.
Yep, as @kurokobo has in his last image, without having the profiling tasks and such it seems it is not required to be on to see timestamps in the output of the UI, but those do not show up in the API or downloads. I can turn on profile_tasks and see if that changes the situation, but I think its interesting that it already has the time stamps in the UI without that turned on, so one would expect you might should see them in the downloaded version, or the API output. Which led to is this a bug, or this intended behavior. Clearly AWX does have task level time stamps available out of the box, so I was leaning towards a bug that it wasn’t being exposed elsewhere. profile_tasks also spits out the per task performance at the end, which is helpful but not required in this situation, more of just the “this task ran at 17:05”, do I have a matching log entry, etc.
Looking at the output in a browser debug console, you can actually see that the timestamps you were referring to are actually separate elements from the actual output.
The timestamp is actually specifically an AWX feature, not an Ansible one. It isn’t from the stdout/stderr of the play, so of course it won’t be in the logged in the output. Might be unexpected at glance, but it does make some sense.
Satellite/TheForman have similar quirks to how plays are displayed in the UI verses what is actually returned by the runners.
Oh nice find on looking at the HTML elements, it certainly explains why we’re seeing it in one place, and not others if the front end itself is rendering adjacent to stdout. Thank you for the feedback @Denney-tech
