Debugging¶
Explains how to find errors in Python code for Cinema 4D with the mxutils debug tools, and how to track down crashes caused by threading violations.
Python code in Cinema 4D mostly runs inside the application, and often in callbacks which Cinema 4D calls on its own schedule and on a thread of its choosing, see Scene Execution. This makes classic step debugging inconvenient, and at the moment impossible, see below. This manual describes what remains: inspecting scene data with the mxutils debug tools, failing early with type checks, tracing and timing calls, building reproducible test scenes, and tracking down crashes that are caused by violating the threading restrictions.
Warning
The VS Code debugger is currently broken. Setting breakpoints in scripts or plugins with the Cinema 4D Connector or
debugpy, as described in Working with the SDK, does not work at the moment, and debugging
c4dpy with F5 does not work out of the box either. Until this is fixed,
use the techniques of this manual, none of which depend on an IDE.
Overview¶
Question |
Tool |
|---|---|
What is in this container, node, or scene? |
|
What is different between these two nodes? |
|
Is this value what I think it is? |
|
Was my function called, how often, and how long did it take? |
|
I need a scene to test my code with. |
|
Cinema 4D crashes or hangs, but not always. |
Threading violations and |
The output of all tools ends up in the Python Console. Call c4d.ClearPythonConsole() at the start of a script to
keep it readable, and print behind a flag such as IS_DEBUG in code that runs often, e.g., in callbacks which are called for
every update. Very large trees, e.g., of a whole document, can exceed what the console prints in one go. Print them in
slices, or write them to a file.
Inspecting Scene Data¶
The class mxutils.DebugPrint converts data of the Cinema API into trees of mxutils.DebugNode. Each
kind of data has up to three functions: Get returns the tree, Print prints it, and Diff returns the
differences of two inputs as a unified diff.
Data |
Get |
Diff |
|
|---|---|---|---|
Parameters of a |
|||
Bit and NBit flags of a node |
|||
Parameters and flags combined |
|||
Scene graph below a node |
The functions do not modify the scene, but they walk descriptions, containers, and graphs, which is expensive. Do not call them unconditionally in code that runs often.
Debug Trees¶
A DebugNode has a label, a parent, and children. DebugNode.ToString()
renders the tree below it as text. You can also build your own reports with DebugNode.Add(),
or from an indented string with DebugNode.FromString():
report: mxutils.DebugNode = mxutils.DebugNode("Report")
objects: mxutils.DebugNode = mxutils.DebugNode("Objects")
report.Add(objects)
objects.Add(mxutils.DebugNode("Cube"))
objects.Add(mxutils.DebugNode("Sphere"))
report.Add(mxutils.DebugNode("Tags"))
print(report.ToString())
# Report
# ├── Objects
# │ ├── Cube
# │ └── Sphere
# └── Tags
For arbitrary tree-like data, DebugPrint.GetTreeString() prints any node type
that either stores its children in an attribute, or that can be navigated with a GetDown and GetNext function,
and accepts a callback to customize the label of each node.
Containers¶
GetContainer() prints the entries of a container with their data type. Container IDs are
integers, so the function can resolve them to symbols when you give it a regular expression as a hint, e.g.,
'^BFM_' to only consider symbols that start with BFM_. When there is no symbol or more than one for an ID, the
number is printed instead:
bc: c4d.BaseContainer = c4d.BaseContainer()
bc[1000] = "Hello"
bc[1001] = 42
sub: c4d.BaseContainer = c4d.BaseContainer()
sub[1000] = "Sub"
bc[1002] = sub
mxutils.DebugPrint.PrintContainer(bc)
# Root (None , id = -1):
# ├── 1000 (DTYPE_STRING): Hello
# ├── 1001 (DTYPE_LONG): 42
# └── 1002 (DTYPE_SUBCONTAINER , id = -1):
# └── 1000 (DTYPE_STRING): Sub
Warning
Resolving a container ID to a symbol is ambiguous, as the same number is used by many symbols in different contexts. A resolved symbol is correct numerically, but can imply a different meaning than the entry has. Only use hints when you know which family of symbols to expect.
Parameters¶
For the parameters of a node, GetParameters() is the better choice, as it reads the
description of the node and with that always shows the correct symbols, names, and data types. The output is large, so
the function can be narrowed down with whiteList and blackList, which take parameter or group IDs, and
with the show... arguments:
cube: c4d.BaseObject = mxutils.CheckType(c4d.BaseObject(c4d.Ocube))
cube[c4d.PRIM_CUBE_LEN] = c4d.Vector(300, 200, 100)
cube[c4d.PRIM_CUBE_SUBX] = 4
# Only show the parameters of the Object Properties group.
mxutils.DebugPrint.PrintParameters(cube, whiteList=(c4d.ID_OBJECTPROPERTIES,), showDescId=False)
# 'Cube' (Ocube)' object at 0x00000213AC962240 with the parameters:
# └── 'Object Properties (ID_OBJECTPROPERTIES)' - type: DTYPE_GROUP
# ├── 'Size (PRIM_CUBE_LEN)' - type: DTYPE_VECTOR, value: Vector(300, 200, 100)
# ├── 'Segments X (PRIM_CUBE_SUBX)' - type: DTYPE_LONG, value: 4
# ├── 'Segments Y (PRIM_CUBE_SUBY)' - type: DTYPE_LONG, value: 1
# ├── 'Segments Z (PRIM_CUBE_SUBZ)' - type: DTYPE_LONG, value: 1
# ├── 'Separate Surfaces (PRIM_CUBE_SEP)' - type: DTYPE_BOOL, value: 0
# ├── 'Fillet (PRIM_CUBE_DOFILLET)' - type: DTYPE_BOOL, value: 0
# ├── 'Fillet Radius (PRIM_CUBE_FRAD)' - type: DTYPE_REAL, value: 3.0
# └── 'Fillet Subdivision (PRIM_CUBE_SUBF)' - type: DTYPE_LONG, value: 3
By default, groups and separators without a name are hidden, as they do not matter for data access. Pass
hideLayoutElements=False when you need the true parameter tree. Setting showDefaultValues=False only shows
parameters which differ from their description default, parameters without such a default are always shown.
Flags¶
GetFlags() prints the state of the BIT_ and NBIT_ flags of a node. hint is a regular
expression which filters the flag symbols, and showSetOnly hides all flags which are not set. Use this to find out
which flags a node has, e.g., after a user action in the Object Manager:
mxutils.DebugPrint.PrintFlags(cube, showBit=False, showSetOnly=True)
# Cube (BaseObject)
# ├── NBIT_OHIDE: 1
# └── NBIT_OM1_FOLD: 1
GetBaseList() returns the parameters and the flags of a node in one tree with the branches
Parameters and Flags.
Scene Graphs¶
GetGraph() prints the hierarchy, the caches, and the branches below a node, e.g., a document,
an object, or a material. It is the quickest way to see what a generator has built, and which tags a cache holds. See
Scene Structure for an explanation of the output.
Comparing Two Nodes¶
A frequent question while debugging is why a node A does not behave like a node B. Instead of searching for the
difference by eye, the Diff functions compare the output of the matching Get function and return only the
differences as a unified diff. They accept the same arguments as their Get counterpart. The following examples compare
two cubes a and b, where the Size and Segments X parameters of a have been changed, and the Object Manager
fold and hide flags of b have been set:
print(mxutils.DebugPrint.DiffParameters(
a, b, whiteList=(c4d.ID_OBJECTPROPERTIES,), showDescId=False, showType=False))
# --- first
# +++ second
# @@ -1,7 +1,7 @@
# -'Cube' (Ocube)' object at 0x0000025AD4D9C3C0 with the parameters:
# +'Cube.1' (Ocube)' object at 0x0000025AD4D9B040 with the parameters:
# └── 'Object Properties (ID_OBJECTPROPERTIES)'
# - ├── 'Size (PRIM_CUBE_LEN)' - value: Vector(300, 200, 100)
# - ├── 'Segments X (PRIM_CUBE_SUBX)' - value: 4
# + ├── 'Size (PRIM_CUBE_LEN)' - value: Vector(200, 200, 200)
# + ├── 'Segments X (PRIM_CUBE_SUBX)' - value: 1
# ├── 'Segments Y (PRIM_CUBE_SUBY)' - value: 1
# ├── 'Segments Z (PRIM_CUBE_SUBZ)' - value: 1
# ├── 'Separate Surfaces (PRIM_CUBE_SEP)' - value: 0
print(mxutils.DebugPrint.DiffFlags(a, b, showBit=False, hint="OM|OHIDE"))
# --- first
# +++ second
# @@ -1,7 +1,7 @@
# -Cube (BaseObject)
# +Cube.1 (BaseObject)
# ├── NBIT_IS_FROM_HOST: 0
# -├── NBIT_OHIDE: 0
# -├── NBIT_OM1_FOLD: 0
# +├── NBIT_OHIDE: 1
# +├── NBIT_OM1_FOLD: 1
# ├── NBIT_OM2_FOLD: 0
# ├── NBIT_OM3_FOLD: 0
# ├── NBIT_OM4_FOLD: 0
The first line of a diff always differs, as it contains the name of the node. DiffGraph()
compares the scene graphs of two nodes, and DiffBaseList() parameters and flags in one go.
DiffContainer() does the same for containers, e.g., to find out what a user action has changed
in the data container of a node. See mxutils_debugprint for all functions in action.
Checking Assumptions¶
Many errors surface long after they have been caused. A failed allocation returns None, and the script then fails
ten lines later with a message that points at the wrong place. mxutils.CheckType() and
mxutils.CheckIterable() move the failure to the cause. They return the value when the check passes, so they can be
used inline, and they name the checked expression in the error message:
# Fails here and not in the next line, when the allocation fails.
cube: c4d.BaseObject = mxutils.CheckType(c4d.BaseObject(c4d.Ocube))
data: list[str | int] = ["1", 2]
mxutils.CheckIterable(data, str)
# TypeError: Expected iterable 'data' to be composed of type <class 'str'>. Found item of type: <class 'int'>
The symbol of the checked expression can only be discovered in saved files, in the Script Manager and in the console you will see a generic message. Checking every element of a large iterable is expensive, check function arguments and results, not data in loops. See mxutils_checktype for more cases.
Tracing and Timing¶
The decorator mxutils.REPORT() prints the name of a function when it is called, with a rule underneath, and an empty
line when it returns. For methods it also prints the memory address of the object. This helps to follow call chains
without setting breakpoints:
@mxutils.REPORT()
def Foo(msg: str) -> None:
print(f"{msg = }")
Foo("Hello World!")
# Running 'Foo':
# ----------------------------------------------------------------------------------------------------
# msg = 'Hello World!'
mxutils.TIMEIT() measures how long a call takes and prints it. It takes a flag as its first argument, and when the
flag is False the function is returned unchanged, so decorators can stay in your code, controlled by an IS_DEBUG
constant. The decorator can also print the arguments and the result, and profile the call with cProfile instead of
timing it:
IS_DEBUG: bool = True
@mxutils.TIMEIT(IS_DEBUG, showArgs=True, showResult=True)
def Factorial(n: int) -> int:
return 1 if n == 0 else n * Factorial(n - 1)
Note
Profiling has a high impact on the runtime of a function, timing a low one. Neither should ship in released code.
For recursive functions, inCallProtection=True only reports the outermost call, but this protection is not
thread-safe.
mxutils.GetMemoryAddress() returns the address of an object in the format Python uses in its default repr. It
is useful for __str__ methods of your own classes, and to find out if two callbacks operate on the same
instance. See mxutils_decorators for more decorator examples.
Test Scenes¶
Bugs are easiest to fix when they can be reproduced in a small scene. mxutils.SceneFaker, available as the
global instance mxutils.g_scene_faker, creates objects, materials, tags, layers, render data, and animation tracks
for development and testing purposes. SceneFaker.AddHierarchyFromString()
builds an object hierarchy from an indented string, where :: followed by an object type ID selects the type, and
objects without one are Null objects:
objects: list[c4d.BaseObject] = mxutils.g_scene_faker.AddHierarchyFromString(doc, f"""
A
B::{c4d.Ocube}
C::{c4d.Osphere}
D
E
""")
mxutils.DebugPrint.PrintGraph(objects[0]) # Check that the scene is what the test needs.
The AddRandom... methods add content to an existing scene, and RandomizeScene fills a document with random
content. Pass your own seeded mxutils.Random to a new SceneFaker instance to get the same
content on every run. Because the faker builds caches, it must run on the main thread, e.g., in a Script Manager script.
See traversal for a scene that has been built this way.
Threading Violations¶
Ignoring the threading restrictions is the most common reason for crashes of Python plugins and scripting elements. It is also the hardest to debug, because the result is undefined behavior: Cinema 4D does not raise an error at the faulty line, it is left with a dangling pointer which is dereferenced later, in another place, or on another thread.
Typical signs of a threading violation are:
Cinema 4D terminates without a Python traceback, or stops responding.
The crash only happens sometimes, or in specific situations, e.g., during playback, while rendering, while the Object Manager is open and showing the affected nodes, or after the scene has been edited for a while.
The code works when it is executed from the Script Manager, but not as a plugin or scripting element, because a script always runs on the main thread, while a callback does not.
The crash location, if there is one, does not match the code that caused it.
Find Out Where the Code Runs¶
Start with the facts. Log the context of the suspicious callbacks and everything they call.
c4d.threading.GeIsMainThreadAndNoDrawThread() is True when the code runs on the main thread and that thread
is not currently executing drawing code, while c4d.threading.GeIsMainThread() is also True during drawing:
import functools
import c4d
def GetContext() -> str:
"""Returns a description of the thread context the caller is running in."""
if c4d.threading.GeIsMainThreadAndNoDrawThread():
return "main thread"
if c4d.threading.GeIsMainThread():
return "main thread (drawing)"
return "threaded context"
def LogContext(func):
"""Prints the context a function is called in."""
@functools.wraps(func)
def wrapper(*args, **kwargs):
print(f"{func.__qualname__}: {GetContext()}")
return func(*args, **kwargs)
return wrapper
Decorate the callbacks and the helper functions which they call. The violation is often not in the callback itself, but in a helper function that was written for a script and later reused in a callback. Callbacks are called often, so remove the logging once you know the answer.
Turn Violations into Errors¶
Once you know which operations are not allowed in the context of a callback, replace the silent undefined behavior with a
Python exception while you debug. A guard like the following raises an error with a traceback at the offending line,
instead of crashing Cinema 4D later. mxutils.SceneFaker uses the same technique to protect its cache building:
IS_DEBUG: bool = True
def AssertMainThread() -> None:
"""Raises an error when called from a threaded context, instead of risking a crash."""
if IS_DEBUG and not c4d.threading.GeIsMainThreadAndNoDrawThread():
raise RuntimeError("Main thread only code has been called from a threaded context.")
class MyGenerator(c4d.plugins.ObjectData):
def GetVirtualObjects(self, op: c4d.BaseObject, hh: object) -> c4d.BaseObject | None:
doc: c4d.documents.BaseDocument = op.GetDocument()
AssertMainThread() # Not allowed here, this will raise an error and not crash.
doc.InsertObject(c4d.BaseObject(c4d.Onull))
return None
Place the guard in front of each operation which the restrictions table marks as forbidden in a threaded context: inserting, moving, or removing nodes of a document, modifying the parameters or matrices of the own node, creating or modifying materials, creating undo steps, and anything that touches the user interface. Do not leave a guard as the fix. It only tells you where the code is wrong, the fix is to move the work to the main thread.
Capture the Crash¶
When there is no traceback, Python’s faulthandler module can still write one. When enabled, it dumps the Python
stack of the crashing thread, and optionally of all other threads, if the process receives a fatal error such as an
access violation. The first entry of the stack is the Python line that made the call into the Cinema API which crashed.
As the violation can have happened earlier, this is a starting point and not always the cause, but the log tells you
which callback and which thread were involved.
Enable it at the start of your plugin module, and keep the file object alive for as long as the handler is enabled:
import faulthandler
import os
# The file object must stay open as long as faulthandler is enabled.
g_crashLog = open(os.path.join(os.path.dirname(__file__), "crash.log"), "w")
faulthandler.enable(file=g_crashLog, all_threads=True)
After a crash, the file contains an entry like the following:
Fatal Python error: Segmentation fault
Current thread 0x0001c38c (most recent call first):
File "C:\plugins\py_obj_example\py_obj_example.pyp", line 52 in BuildCache
File "C:\plugins\py_obj_example\py_obj_example.pyp", line 38 in GetVirtualObjects
The same module also helps with hangs, which are the other symptom of threading problems, e.g., when a lock is held while
calling into the Cinema API. faulthandler.dump_traceback_later() writes the stacks of all threads to the log when
your code has not finished after a given number of seconds:
faulthandler.dump_traceback_later(10, repeat=False, file=g_crashLog)
# ... run the code that hangs ...
faulthandler.cancel_dump_traceback_later()
Note
This has been verified for the standalone interpreter c4dpy, where a deliberate fault produced the entry shown
above. In the Cinema 4D application, its own crash handling is involved. Test the setup once with a deliberate crash
in a scratch session, e.g., with faulthandler._sigsegv(), which terminates Cinema 4D immediately, before you rely
on it.
Reduce and Reproduce¶
A crash that happens “sometimes” is only fixed when it can be provoked. Because threading violations need another thread
that uses the same data at the same time, make Cinema 4D busy while the code under test is running: play the timeline,
start a render in the Picture Viewer, open the Object Manager and the Attribute Manager with the affected nodes, and
change parameters while a slider is being dragged. Combine this with a small test scene built with
mxutils.SceneFaker, and remove parts of the callback until the crash disappears. The last part that was removed
contains the violation. When the fix is done, run the same procedure again, as a violation that does not crash proves
nothing.
Fix the Violation¶
A callback cannot modify the document on its own. Move the work to the main thread, either with a core message and a
c4d.plugins.MessageData plugin, or in the Message method of a node, as described in the section Deferring
Workloads of Scene Execution. Also do not use Python’s threading module to access Cinema 4D data, see the section
Python and Threads in the same manual.