UNSOLVED How to get the render time from picture viewer

kng_ito

Hi,

Is there any way to get the render information in picture viewer, mainly the render time?
The purpose is to visualize the time taken to render each frame in a graph, to determine the average render time, etc.

I would like to know if it is possible in python, c++ only, or neither.
Any help would be greatly appreciated!

ferdinand

Hello @kng_ito,

Thank you for reaching out to us. No, that is not possible, the Picture Viewer is as all managers not being exposed in our APIs.

However, there are three other paths you could take:

Use Team Renderer logs. Team Render can spit out quite detailed logs for its renderings, including timings. I am not sure though if it can also track per frame timings. You would have to ask that user support. If you wanted to then make use of that data, you would have either parse such logs or simply collect the data manually.
The atom message MSG_MULTI_RENDERNOTIFICATION is being sent to nodes when a rendering starts and ends. You could track with that manually the time a rendering takes. This will be slightly imprecise (e ⪅ 0.05 sec) and won't be able to track each frame individually in the rendering of an animation. This could be done very cheaply even with a Python Programming tag. The solution I did provide there is a bit hacky, in practice you should implement this either as a TagData in Python or better as a ScenHookData in C++ (there you would not have to add the tag to scene first). See end of posting for an example with a Python Programming tag.
You could write a VideoPostData plugin (only available in the C++ API) which does more or less the same as option two, tracking the timings manually. Here you can track individual frames or even more granular things as sub-frames, lines, or pixels. To then track the timings of a rendering, you would have had to add the video post to the render settings of the rendering you want to track. This is certainly the most complex solution.

Cheers,
Ferdinand

The scene file: track_render.c4d
An example output:

Rendering for <c4d.documents.BaseDocument object called  with ID 110059 at 2502775112192> finished: 0.07 sec.
Rendering for <c4d.documents.BaseDocument object called  with ID 110059 at 2502775084928> finished: 0.071 sec.
Rendering for <c4d.documents.BaseDocument object called  with ID 110059 at 2502775152000> finished: 0.066 sec.
Rendering for <c4d.documents.BaseDocument object called  with ID 110059 at 2502775139200> finished: 4.443 sec.

The code:

"""Example for measuring the time of renderings with the help of MSG_MULTI_RENDERNOTIFICATION.

This solution here is flawed in to ways:

    1. Python Programming tag modules, e.g., the content of this file, can be volatile. Cinema 4D
       can 'forget' its content/state until it is time to call it again. Which means you cannot
       store anything in this module. I am solving this here by injecting data into the sys module.
       Which is not a very nice thing to do, boo on me I guess :) We could also inject data into
       the document, which would be a bit nicer, but also not really good. This should be solved
       properly with a TagData plugin (C++/Python) or better a SceneHookData plugin (C++) as there
       we can attach our data to the plugin.
    2. You are inherently unable to track frames of a rendering with MSG_MULTI_RENDERNOTIFICATION,
       as the message is only being sent for the start and end of a rendering. To solve this you
       must pick other solutions as using Team Render or implementing this as a VideoPostData plugin
       (C++ only).
"""

import c4d
import sys
import typing
import time

# Some messages which can be printed.
MSG_MALFORMED_DATA: str = "Stepping over malformed render notification data."
MSG_HASH_COLLISION: str = ("Rendering for the document is already being tracked. "
                           "Cannot track more than one rendering per document.")
MSG_UNTRACKED_RENDERING: str = "An untracked rendering has finished, no time information available."
MSG_RENDER_TIME: str = "Rendering for {} finished: {} sec."

# The name of the attribute which we are going to attach to #sys (to store our data)
ID_DATA_CONTAINER: str = "c4d_render_data"

def main() -> None:
    """The tag does nothing on execution.
    """
    pass

def message(mid: int, data: object) -> bool:
    """Called by Cinema 4D to propagate messages to nodes. 
    """
    # This is a message for a rendering being started or closed.
    if mid == c4d.MSG_MULTI_RENDERNOTIFICATION:
        # The message data are in some shape or form malformed.
        if not isinstance(data, dict):
            print (MSG_MALFORMED_DATA)
            return True
        
        # True for the start of a rendering, False for the end.
        isStart: bool = data.get("start", None)
        # The render document.
        renderDoc: c4d.documents.BaseDocument = data.get("doc", None)
        if None in (isStart, renderDoc):
            print (MSG_MALFORMED_DATA)
            return True 

        # We could attach the render document to sys, but that would be a REALLY bad idea. So, we
        # are going to identify the renderings/render documents via their UUID.
        renderUUID: typing.Optional[memoryview] = renderDoc.FindUniqueID(c4d.MAXON_CREATOR_ID)
        if renderUUID is None:
            print (MSG_MALFORMED_DATA)
            return True
        # Since we want to insert the UUID into a dict (hashmap) we must make it hashable by casting
        # it to bytes.
        renderHash: bytes = bytes(renderUUID)

        # Get our makeshift data container attached to #sys or attach one when there is none. The
        # container looks like this:
        #
        # {
        #     bytes_hash: start_of_rednering_in_unix_epoche_time,
        #     ...,
        #     bytes_hash: start_of_rednering_in_unix_epoche_time
        # }
        #
        # But it will only contain ongoing renderings. So, usually there will only be one 
        # rendering in it.
        dataContainer: dict = getattr(sys, ID_DATA_CONTAINER, None)
        if dataContainer is None:
            dataContainer = {}
            setattr(sys, ID_DATA_CONTAINER, dataContainer)

        # Is true when #renderDoc, its hash, is in #dataContainer.
        isTracked: bool = isinstance(dataContainer.get(renderHash, None), bytes)

        # A second rendering has been started for this document, we won't have any of this and just
        # skip it. With some finesse it would be possible to solve this, but I did not here. This 
        # can only track one rendering per document.
        if isStart and isTracked:
            print (MSG_HASH_COLLISION)
        # A rendering hash finished where we did not witness its start. Spooky :)
        elif not isStart and isTracked:
            print (MSG_UNTRACKED_RENDERING)
        # A rendering has been started. We put the start time under the document hash into our data 
        # container.
        elif isStart:
            dataContainer[renderHash] = time.time()
        # A rendering has finished. We get its stating time from the data container, report the
        # time difference and remove the item from the data container.
        elif not isStart:
            tRender: int = time.time() - dataContainer[renderHash]
            print (MSG_RENDER_TIME.format(renderDoc, round(tRender, 3)))
            dataContainer.pop(renderHash)

    return True

kng_ito

Hi @ferdinand,

Thank you as always for your detailed answer and even the sample scene file!
It seems like a lot of work with my current level of understanding, but your answer is a great hint.

I'll try to do a little research on my own. Thank you very much.