PDG node/workitem more detailed run times information?

   3134   7   2
User Avatar
Member
1694 posts
Joined: March 2020
Offline
Hi,


This might be a noob question, but is there any way to retrieve more detailed information about nodes and/or individual work items' run times? Like, when did a work item got launched, when did it finish, etc. I wouldn't mind having similar information for the entire graph I too (e.g. when did the entire graph started cooking, how long it took to cook / how long it's been cooking if it's in progress).

Right now if I use PDG for any longer job with a large graph (something that takes overnight) I quite often find myself in a situation where I have no way to pull up any information on how things went down in that regard. I know that I could get some of this info if I used the performance monitor, but it'd be great to have this as part of the regular MMB info on the workitems/nodes.

Are there outstanding RFEs for this? (I'm happy to write one if there isn't)

Thank you!
Cheers
Imre
Edited by riviera - Dec. 16, 2020 15:19:55
Imre Tuske
FX Supervisor | Senior FXTD @ Weta FX

qLib -- Houdini asset library
http://qlab.github.io/qLib/ [qlab.github.io]
https://www.facebook.com/qLibHoudini [www.facebook.com]
User Avatar
Staff
585 posts
Joined: May 2014
Offline
The performance monitor is the only real option right now, aside from the cook time on the work item itself. That sounds like a good RFE though -- we can definitely expose the start/end time, in addition to the cook time. It should also be possible for us log the time the first work item begins/last work item ends on a per node basis as well.

There isn't an outstanding RFE for your specific case, however there is a potentially related one for adding verbose PDG log output. Basically, enabling a toggle or env var to get a shell output with information like work item schedule/cook/finish events. That could be something that get timestamped as well.

If you can log an RFE with the specific things you're interested in, I can take a look and possibly tackle it at the same time as some of the other logging/status reporting changes.
User Avatar
Member
1694 posts
Joined: March 2020
Offline
Awesome, I'll log these, thanks!
Imre Tuske
FX Supervisor | Senior FXTD @ Weta FX

qLib -- Houdini asset library
http://qlab.github.io/qLib/ [qlab.github.io]
https://www.facebook.com/qLibHoudini [www.facebook.com]
User Avatar
Member
1694 posts
Joined: March 2020
Offline
Another random thing came to mind, it'd be great to have some way of catching work items that are for any reason frozen/hanging indefinitely, I'm pretty sure having start times would help in that (maybe have a timestamp info on a node telling when it received update from a work item last?)

Also, it'd be great if cook times were updated in regular intervals on running work items (although I'm on 18.0 now, this might be better in 18.5). In 18.0 it's common to see negative/random numbers for workitems that are being cooked (e.g. I'm looking at a workitem with Cook Time 1608276119.72 atm)
Edited by riviera - Dec. 18, 2020 04:05:33
Imre Tuske
FX Supervisor | Senior FXTD @ Weta FX

qLib -- Houdini asset library
http://qlab.github.io/qLib/ [qlab.github.io]
https://www.facebook.com/qLibHoudini [www.facebook.com]
User Avatar
Staff
585 posts
Joined: May 2014
Offline
There have been some recent changes to the MMB panel for displaying cook times (available in 18.5, but not 18.0):

  • The cook time value won't appear as negative or uninitialized anymore. If an item is in progress, the cook time displays the time since the time began cooking.
  • The cook time is now formatted with a limit on the number of decimal places.
  • Work items now store 4 different time stamps: The time at which the item was first queued with a PDG scheduler, when that scheduler submitted the item to the farm scheduler, when the item started cooking, and when it finished. These values can be seen by expanding the Cook Time section in the MMB.

Here's an example of the changes to the MMB showing the expanded cook time field:



The timestamps are just the time, not including the date -- that's easy enough to change as well, I wasn't sure how useful that information would be. We could for example display the date only if the time stamps and current time span multiple days?

The number in parenthesis at the end is the time delta between the previous stage. So for example, after the Scheduled time the second number describes how long the work item waited in the PDG scheduler's queue.

All of this extra information is also available through the Python API. There's a new pdg.WorkItem.stats() API method which returns an object that contains the various cook time stats, and can also expanded in the future to track other per-work item information.

Attachments:
cooktime.png (54.2 KB)

User Avatar
Member
7024 posts
Joined: July 2005
Offline
Imre, I assume you mean using LocalScheduler? Since I'm using Deadline, all that info is there in the Deadline Monitor, so this never occurred to me! However, glad this is in there now!
User Avatar
Member
1694 posts
Joined: March 2020
Offline
Hi Peter, sorry I just saw this, it was a combination of local and farm scheduler, and some of our PDG stuff doesn't translate in a well-readable way to our equivalent of the Deadline Monitor.
Imre Tuske
FX Supervisor | Senior FXTD @ Weta FX

qLib -- Houdini asset library
http://qlab.github.io/qLib/ [qlab.github.io]
https://www.facebook.com/qLibHoudini [www.facebook.com]
User Avatar
Member
7024 posts
Joined: July 2005
Offline
No worries, just curious mostly.
  • Quick Links