diff --git a/doc/APIreference/APIglobals.rst b/doc/APIreference/APIglobals.rst index 2f6a4f69..67544787 100644 --- a/doc/APIreference/APIglobals.rst +++ b/doc/APIreference/APIglobals.rst @@ -32,10 +32,14 @@ you are simulating multiple models in parallel, they use the same set of callbac mju_user_error ~~~~~~~~~~~~~~ -This is called from within the main error function :ref:`mju_error`. When installed, this function overrides the default -error processing. Once it prints error messages (or whatever else the user wants to do), it must **exit** the program. -MuJoCo is written with the assumption that mju_error will not return. If it does, the behavior of the software is -undefined. +.. deprecated:: + Use :ref:`mju_setLogHandler` instead. See :ref:`siLogHandler`. + +Called by the default log handler when a fatal error occurs. If installed, this function overrides the default error +processing. It may ``longjmp`` out or return. MuJoCo is written with the assumption that error handlers will not +return; if they do, the behavior of the software is undefined. + +If a custom log handler is installed via :ref:`mju_setLogHandler`, this callback is not consulted. .. code-block:: C @@ -47,8 +51,11 @@ undefined. mju_user_warning ~~~~~~~~~~~~~~~~ -This is called from within the main warning function :ref:`mju_warning`. It is similar to the error handler, but instead -it must return without exiting the program. +.. deprecated:: + Use :ref:`mju_setLogHandler` instead. See :ref:`siLogHandler`. + +Called by the default log handler when a warning occurs. If a custom log handler is installed via +:ref:`mju_setLogHandler`, this callback is not consulted. .. code-block:: C @@ -185,9 +192,9 @@ mjcb_time ~~~~~~~~~ Installing this callback enables the built-in profiler, and keeps timing statistics in ``mjData.timer``. The return type -is mjtNum, while the time units are up to the user. :ref:`simulate.cc ` assumes the unit is 1 millisecond. -In order to be useful, the callback should use high-resolution timers with at least microsecond precision. This is -because the computations being timed are very fast. +is mjtNum, while the time units are up to the user. Both :ref:`simulate.cc ` and the ``mjTOPIC_TIME_STP`` +informational :ref:`topic ` assume the unit is 1 millisecond. In order to be useful, the callback should +use high-resolution timers with at least microsecond precision. .. code-block:: C diff --git a/doc/APIreference/APItypes.rst b/doc/APIreference/APItypes.rst index 355eb3a7..fd7b8a4a 100644 --- a/doc/APIreference/APItypes.rst +++ b/doc/APIreference/APItypes.rst @@ -540,6 +540,33 @@ Sleep state of an object. .. mujoco-include:: mjtSleepState +.. _tyLogEnums: + +Logging +~~~~~~~ + +.. _mjtLogLevel: + +mjtLogLevel +""""""""""" + +Log message severity level. + +.. mujoco-include:: mjtLogLevel + + +.. _mjtLogTopic: + +mjtLogTopic +""""""""""" + +Topic identifiers for informational messages. Used with :ref:`mju_info` for topic-based filtering. +Topic 0 (``mjTOPIC_NONE``) always passes through the default handler's filter. Other topics must be enabled in +the :ref:`mjLogConfig` bitmask. Since topics are 1-indexed, the bitmask for topic ``t`` is ``(1 << (t - 1))``. + +.. mujoco-include:: mjtLogTopic + + .. _tyVisEnums: Visualization @@ -1059,6 +1086,36 @@ Asset cache used by the compiler to avoid repeated slow recompilation. See :ref: .. mujoco-include:: mjCache +.. _tyLogStructure: + +Logging +^^^^^^^ + +.. _mjLogMessage: + +mjLogMessage +~~~~~~~~~~~~ + +Structured log message passed to :ref:`mjfLogHandler` callbacks. Contains the severity level, optional topic for +info messages, a one-line subject, an optional multi-line body, and optional source location (function name, file +name, line number). + +.. mujoco-include:: mjLogMessage + + +.. _mjLogConfig: + +mjLogConfig +~~~~~~~~~~~ + +Configuration for the default log handler. Controls whether messages are printed to the console and/or written to +a log file (default: ``MUJOCO_LOG.TXT``). The ``logto_file`` field enables file logging, while ``logfile`` specifies +the file path. The ``topics`` field is a bitmask of :ref:`mjtLogTopic` values: bit ``(topic - 1)`` enables +that topic. Topic 0 (``mjTOPIC_NONE``) always passes through. + +.. mujoco-include:: mjLogConfig + + .. _tyStatStructure: Sim statistics @@ -1836,6 +1893,26 @@ mjfCollision This is the function type of the callbacks in the collision table :ref:`mjCOLLISIONFUNC`. +.. _tyLogCallbacks: + +Log Callbacks +^^^^^^^^^^^^^ + +.. _mjfLogHandler: + +mjfLogHandler +~~~~~~~~~~~~~ + +.. code-block:: C + + typedef void (*mjfLogHandler)(const mjLogMessage*); + +This is the function type of the log handler callback installed via :ref:`mju_setLogHandler`. The handler receives +all errors, warnings and informational messages as structured :ref:`mjLogMessage` data. It must be thread-safe. + +It must not call :ref:`mju_error` from within the callback. + + .. _tyUICallbacks: UI Callbacks diff --git a/doc/APIreference/functions.rst b/doc/APIreference/functions.rst index 0a9e1dd7..0713d163 100644 --- a/doc/APIreference/functions.rst +++ b/doc/APIreference/functions.rst @@ -1971,7 +1971,9 @@ Error and memory .. mujoco-include:: mju_error -Main error function; does not return to caller. +Main error function. The error message is dispatched to the active log handler (see :ref:`mju_setLogHandler`). +Errors are always fatal: if the handler returns, the process is terminated with ``exit(EXIT_FAILURE)``. Handlers +wishing to recover must ``longjmp`` or otherwise transfer control before returning. .. _mju_warning: @@ -1980,7 +1982,7 @@ Main error function; does not return to caller. .. mujoco-include:: mju_warning -Main warning function; returns to caller. +Main warning function; returns to caller. The warning message is dispatched to the active log handler. .. _mju_clearHandlers: @@ -1989,7 +1991,114 @@ Main warning function; returns to caller. .. mujoco-include:: mju_clearHandlers -Clear user error and memory handlers. +Clear all user handlers and restore defaults. Resets the legacy error/warning/memory callbacks to ``NULL``, restores +the default log handler, and resets the log configuration to its defaults (console and file output enabled, all info +topics disabled). + +.. _mju_setLogHandler: + +`mju_setLogHandler <#mju_setLogHandler>`__ +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. mujoco-include:: mju_setLogHandler + +Set the active global log handler. Returns the previous handler (which is never ``NULL``), intended for save/restore +or callback chaining. If ``handler`` is ``NULL``, the default handler is restored. The handler receives all errors, +warnings and informational messages as a structured :ref:`mjLogMessage`. See :ref:`siLogHandler` for usage examples. + +.. _mju_getLogConfig: + +`mju_getLogConfig <#mju_getLogConfig>`__ +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. mujoco-include:: mju_getLogConfig + +Get the current default handler configuration. See :ref:`mjLogConfig`. + +.. _mju_setLogConfig: + +`mju_setLogConfig <#mju_setLogConfig>`__ +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. mujoco-include:: mju_setLogConfig + +Set the default handler configuration. Controls console output, file output, and info topic filtering. +See :ref:`mjLogConfig`. + +Example usage (disabling file output): + +.. code-block:: C + + mjLogConfig config = mju_getLogConfig(); + config.logto_file = false; + mju_setLogConfig(config); + +.. _mju_info: + +`mju_info <#mju_info>`__ +~~~~~~~~~~~~~~~~~~~~~~~~ + +.. mujoco-include:: mju_info + +Log an informational message with optional topic filtering. The ``topic`` argument is a :ref:`mjtLogTopic` value. +Topic 0 (``mjTOPIC_NONE``) always passes through. Other topics must be enabled in the default handler configuration +via :ref:`mju_setLogConfig`. Note that topic filtering is implemented in the default handler; custom handlers +receive all info messages regardless. + +.. _mju_message: + +`mju_message <#mju_message>`__ +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. mujoco-include:: mju_message + +Dispatch a structured :ref:`mjLogMessage` to the active log handler. This is the primary entry point for emitting +log messages with full control over all fields. The convenience functions :ref:`mju_error`, :ref:`mju_warning`, and +:ref:`mju_info` are thin wrappers that populate an ``mjLogMessage`` and call this function. + +The ``subject`` field is a one-line summary (up to 1024 bytes, inline in the struct). The ``body`` field is an +optional ``const char*`` pointer to multi-line detail text, owned by the caller. When ``body`` is ``NULL``, only the +subject line is printed. + +The default handler formats the output as follows: + +.. code-block:: text + + LEVEL FUNC (FILE:LINE) TIME: SUBJECT + BODY + +where: + +- ``LEVEL`` is ``ERROR``, ``WARNING``, ``INFO``, or ``DEBUG``. +- ``FUNC`` is present when the ``func`` field is set. +- ``(FILE:LINE)`` is present when the ``file`` and ``line`` fields are set. +- ``TIME`` is present when the ``timestamp`` field is set or file logging is active. +- ``SUBJECT`` is the contents of the ``subject`` field. +- ``BODY`` follows on the next line(s), printed raw without indentation or separators, only if non-NULL. + +The default handler appends a trailing blank line after ``ERROR``, ``WARNING``, and ``INFO`` messages for visual +separation. ``DEBUG`` messages are printed compactly without a trailing blank line. + +Example usage: + +.. code-block:: C + + mjLogMessage msg = { + .level = mjLOG_INFO, + .timestamp = true, + .body = " height: 0.001 m\n velocity: 0.000 m/s\n bounces: 47", + }; + snprintf(msg.subject, sizeof(msg.subject), "The ball has come to rest"); + mju_message(&msg); + +This produces: + +.. code-block:: text + + INFO Mon Jun 9 15:04:05 2026: The ball has come to rest + height: 0.001 m + velocity: 0.000 m/s + bounces: 47 .. _mju_malloc: diff --git a/doc/APIreference/functions_override.rst b/doc/APIreference/functions_override.rst index 1ca383fe..22ba38c4 100644 --- a/doc/APIreference/functions_override.rst +++ b/doc/APIreference/functions_override.rst @@ -463,6 +463,102 @@ time, while :ref:`mjui_update` is called only when changes in the UI take place. .. _Errorandmemory: +.. _mju_error: + +Main error function. The error message is dispatched to the active log handler (see :ref:`mju_setLogHandler`). +Errors are always fatal: if the handler returns, the process is terminated with ``exit(EXIT_FAILURE)``. Handlers +wishing to recover must ``longjmp`` or otherwise transfer control before returning. + +.. _mju_warning: + +Main warning function; returns to caller. The warning message is dispatched to the active log handler. + +.. _mju_clearHandlers: + +Clear all user handlers and restore defaults. Resets the legacy error/warning/memory callbacks to ``NULL``, restores +the default log handler, and resets the log configuration to its defaults (console and file output enabled, all info +topics disabled). + +.. _mju_setLogHandler: + +Set the active global log handler. Returns the previous handler (which is never ``NULL``), intended for save/restore +or callback chaining. If ``handler`` is ``NULL``, the default handler is restored. The handler receives all errors, +warnings and informational messages as a structured :ref:`mjLogMessage`. See :ref:`siLogHandler` for usage examples. + +.. _mju_getLogConfig: + +Get the current default handler configuration. See :ref:`mjLogConfig`. + +.. _mju_setLogConfig: + +Set the default handler configuration. Controls console output, file output, and info topic filtering. +See :ref:`mjLogConfig`. + +Example usage (disabling file output): + +.. code-block:: C + + mjLogConfig config = mju_getLogConfig(); + config.logto_file = false; + mju_setLogConfig(config); + +.. _mju_info: + +Log an informational message with optional topic filtering. The ``topic`` argument is a :ref:`mjtLogTopic` value. +Topic 0 (``mjTOPIC_NONE``) always passes through. Other topics must be enabled in the default handler configuration +via :ref:`mju_setLogConfig`. Note that topic filtering is implemented in the default handler; custom handlers +receive all info messages regardless. + +.. _mju_message: + +Dispatch a structured :ref:`mjLogMessage` to the active log handler. This is the primary entry point for emitting +log messages with full control over all fields. The convenience functions :ref:`mju_error`, :ref:`mju_warning`, and +:ref:`mju_info` are thin wrappers that populate an ``mjLogMessage`` and call this function. + +The ``subject`` field is a one-line summary (up to 1024 bytes, inline in the struct). The ``body`` field is an +optional ``const char*`` pointer to multi-line detail text, owned by the caller. When ``body`` is ``NULL``, only the +subject line is printed. + +The default handler formats the output as follows: + +.. code-block:: text + + LEVEL FUNC (FILE:LINE) TIME: SUBJECT + BODY + +where: + +- ``LEVEL`` is ``ERROR``, ``WARNING``, ``INFO``, or ``DEBUG``. +- ``FUNC`` is present when the ``func`` field is set. +- ``(FILE:LINE)`` is present when the ``file`` and ``line`` fields are set. +- ``TIME`` is present when the ``timestamp`` field is set or file logging is active. +- ``SUBJECT`` is the contents of the ``subject`` field. +- ``BODY`` follows on the next line(s), printed raw without indentation or separators, only if non-NULL. + +The default handler appends a trailing blank line after ``ERROR``, ``WARNING``, and ``INFO`` messages for visual +separation. ``DEBUG`` messages are printed compactly without a trailing blank line. + +Example usage: + +.. code-block:: C + + mjLogMessage msg = { + .level = mjLOG_INFO, + .timestamp = true, + .body = " height: 0.001 m\n velocity: 0.000 m/s\n bounces: 47", + }; + snprintf(msg.subject, sizeof(msg.subject), "The ball has come to rest"); + mju_message(&msg); + +This produces: + +.. code-block:: text + + INFO Mon Jun 9 15:04:05 2026: The ball has come to rest + height: 0.001 m + velocity: 0.000 m/s + bounces: 47 + .. _Standardmath: The "functions" in this section are preprocessor macros replaced with the corresponding C standard library math diff --git a/doc/changelog.rst b/doc/changelog.rst index d4f64dd2..dd5c5de6 100644 --- a/doc/changelog.rst +++ b/doc/changelog.rst @@ -10,6 +10,16 @@ General - Added :ref:`mju_threadpool`, a new function for creating a thread pool on an ``mjData`` instance. When a thread pool is initialized, parts of the simulation pipeline, such as collision detection and constraint solving across islands, are parallelized. The thread pool is automatically destroyed when the ``mjData`` is freed. +- Added a unified :ref:`logging API`: + + - All errors, warnings, and informational messages are now routed through a single :ref:`mjfLogHandler` callback + receiving a structured :ref:`mjLogMessage`. + - Users can install a custom handler via :ref:`mju_setLogHandler`, + configure the default handler's behavior (console/file output, topic filtering) via :ref:`mju_setLogConfig`. + - Messages can be emitted via :ref:`mju_info` and :ref:`mju_message`. + - New types: :ref:`mjtLogLevel`, :ref:`mjtLogTopic`, :ref:`mjLogMessage`, :ref:`mjLogConfig`. + - The legacy callbacks :ref:`mju_user_error` and :ref:`mju_user_warning` are deprecated but remain functional. + - Improved primal solver convergence under float32. Improvements initially proposed by :github:user:`n3b` in :issue:`2313` and :github:user:`denzeler-nvidia` in :doc:`MJWarp ` pull request `1374 `__. diff --git a/doc/includes/references.h b/doc/includes/references.h index fd213bc5..1a768253 100644 --- a/doc/includes/references.h +++ b/doc/includes/references.h @@ -2619,6 +2619,38 @@ typedef enum mjtSleepState_ { // sleep state of an object mjS_ASLEEP = 0, // object is asleep mjS_AWAKE = 1 // object is awake } mjtSleepState; +typedef enum mjtLogLevel_ { // log message severity + mjLOG_DEBUG = 0, // internal engine debug trace (opt-in via topic filtering) + mjLOG_INFO, // informational (opt-in via topic filtering) + mjLOG_WARNING, // warning + mjLOG_ERROR, // error +} mjtLogLevel; +typedef enum mjtLogTopic_ { // log topic identifiers + mjTOPIC_NONE = 0, // no topic (always passes filtering) + // INFO topics: + mjTOPIC_TIME_STP = 1, // timing diagnostics (step) + mjTOPIC_TIME_CMP = 2, // timing diagnostics (compile) + // DEBUG topics: + mjTOPIC_SLEEP = 3, // sleep/wake events + + mjNTOPIC = 3 // number of filterable topics +} mjtLogTopic; +typedef struct mjLogMessage_ { // structured log message + int level; // mjtLogLevel + int topic; // mjtLogTopic (0 for error/warning/user) + char subject[1024]; // message subject (one-liner, printf-formatted) + const char* body; // message body (multi-line detail, or NULL) + const char* func; // __func__ or NULL + const char* file; // __FILE__ or NULL + int line; // __LINE__ or 0 + mjtBool timestamp; // prepend timestamp to output +} mjLogMessage; +typedef struct mjLogConfig_ { // log handler default configuration + mjtBool logto_console; // print to console (default: true) + mjtBool logto_file; // print to log file (default: true) + char logfile[1024]; // log file path (default: "MUJOCO_LOG.TXT") + int topics; // enabled info topic bitmask (default: 0) +} mjLogConfig; typedef enum mjtButton_ { // mouse button mjBUTTON_NONE = 0, // no button mjBUTTON_LEFT, // left button @@ -3495,6 +3527,11 @@ void mjui_render(mjUI* ui, const mjuiState* state, const mjrContext* con); void mju_error(const char* msg, ...) mjPRINTFLIKE(1, 2); void mju_warning(const char* msg, ...) mjPRINTFLIKE(1, 2); void mju_clearHandlers(void); +mjfLogHandler mju_setLogHandler(mjfLogHandler handler); +mjLogConfig mju_getLogConfig(void); +void mju_setLogConfig(mjLogConfig config); +void mju_info(int topic, const char* msg, ...) mjPRINTFLIKE(2, 3); +void mju_message(const mjLogMessage* msg); void* mju_malloc(size_t size); void mju_free(void* ptr); void mj_warning(mjData* d, int warning, int info); diff --git a/doc/programming/simulation.rst b/doc/programming/simulation.rst index 2f636221..3fc0a393 100644 --- a/doc/programming/simulation.rst +++ b/doc/programming/simulation.rst @@ -886,20 +886,79 @@ and :ref:`mj_stackAllocByte` is provided for allocation of arbitrary number of b .. _siError: -Errors and warnings -~~~~~~~~~~~~~~~~~~~ +Errors, warnings, logging +~~~~~~~~~~~~~~~~~~~~~~~~~ -When a terminal error occurs, MuJoCo calls the function :ref:`mju_error` internally. Here is what mju_error does: +MuJoCo has a unified logging system for errors, warnings and informational messages. All log output is routed +through a single callback of type :ref:`mjfLogHandler`, which receives a structured :ref:`mjLogMessage` +containing the severity level, message text, and optional source location. Errors are fatal and terminate the +program by default. Warnings indicate problematic but non-fatal conditions. Informational messages provide +optional diagnostic output. -#. Append the error message at the end of the file MUJOCO_LOG.TXT in the program directory (create the file if it does - not exist). Also write the date and time along with the error message. -#. If the user error callback :ref:`mju_user_error` is installed, call that function with the error message as - argument. Otherwise, print the error message and "Press Enter to exit..." to standard output. Then wait for any - keyboard input, and then terminate the simulator with failure. +.. _siLogHandler: -If a user error callback is installed, it must **not** return, otherwise the behavior of the simulator is undefined. -The idea here is that if mju_error is called, the simulation cannot continue and the user is expected to make some -change such that the error condition is avoided. The error messages are self-explanatory. +Installing a handler +^^^^^^^^^^^^^^^^^^^^ + +Users who want to intercept and process MuJoCo's log output should install a log handler using +:ref:`mju_setLogHandler`. The handler receives all errors, warnings and info messages as a single structured +callback: + +.. code-block:: C + + void my_handler(const mjLogMessage* msg) { + // do something with msg, for example: + printf("%s\n", msg->subject); + } + + // install handler, save previous + mjfLogHandler prev = mju_setLogHandler(my_handler); + + // ... do work ... + + // restore previous handler + mju_setLogHandler(prev); + +:ref:`mju_setLogHandler` returns the previously installed handler (which is never ``NULL``; passing ``NULL`` restores +the default handler). The previous handler can be used in two ways: + +* **Save/restore**: A library or subsystem can temporarily install its own handler and later restore the previous one. +* **Chaining**: A custom handler can act as a pure observer by calling the previous handler at the end of its callback + to preserve existing behavior. Conversely, handlers intended to intercept and recover from errors (e.g., via + ``longjmp``) should not chain to the previous handler. + +When the handler is called with ``level == mjLOG_ERROR``, the error is always fatal: the :ref:`default handler +` terminates the process with ``exit(EXIT_FAILURE)`` (unless a legacy error handler is installed). +Handlers that wish to recover from errors (e.g., to throw a C++ exception or convert to a Python exception) must not +return — they should ``longjmp`` to a previously established recovery point or otherwise transfer control before +returning. This is how the compiler and Python bindings handle errors. MuJoCo is written with the assumption that +error handlers will not return; if they do, the behavior of the software is undefined. + +.. warning:: + Log handlers must not call :ref:`mju_error` from within the callback; this will cause infinite recursion. + +.. _siDefaultHandler: + +Default handler +^^^^^^^^^^^^^^^ + +If no custom handler is installed (or if ``NULL`` is passed to :ref:`mju_setLogHandler`), MuJoCo uses a default +handler that provides the following behavior: + +#. If a legacy handler (:ref:`mju_user_error` or :ref:`mju_user_warning`) is installed, it is called with the + formatted message text. This provides backward compatibility with existing code. +#. Otherwise, the message is written to the log file (default: ``MUJOCO_LOG.TXT``) and printed to the + console (``stderr`` for errors and warnings, ``stdout`` for info). +#. For errors, the program is terminated with ``exit(EXIT_FAILURE)`` (unless a legacy error handler is installed). + +The default handler's behavior can be configured using :ref:`mju_setLogConfig` and :ref:`mju_getLogConfig`, +which control whether output goes to the console, the log file path (or disabling file logging by setting it to +an empty string), and which info topics are enabled. + +.. _siErrorRecovery: + +Error recovery +^^^^^^^^^^^^^^ One situation where it is desirable to continue even after an error is an interactive simulator that fails to load a model file. This could be because the user provided the wrong file name, or because model compilation failed. This is @@ -909,26 +968,99 @@ operation fails, and there is no need to exit the program. In the case of mj_loa containing the parser or compiler error that caused the failure, while mj_loadModel generates corresponding warnings (see below). -Internally mj_loadXML actually uses the mju_error mechanism, by temporarily installing a "user" handler that triggers -a C++ exception, which is then intercepted. This is possible because the parser, compiler and runtime are compiled and -linked together, and use the same copy of the C/C++ memory manager and standard library. If the user implements an -error callback that triggers a C++ exception, this will be in their workspace which is not necessarily the same as the -MuJoCo library workspace, and so it is not clear what will happen; the outcome probably depends on the compiler and -platform. It is better to avoid this approach and simply exit when mju_error is called (which is the default behavior -in the absence of a user handler). +Internally mj_loadXML actually uses the mju_error mechanism, by temporarily installing a thread-local handler +(using the internal ``_mjPRIVATE_setTlsLogHandler``) that triggers a C++ exception, which is then intercepted. +This thread-local override takes priority over the global handler and affects only the calling thread. -MuJoCo can also generate warnings. They indicate conditions that are likely to cause numerical inaccuracies, but can -also indicate problems with loading a model and other problematic situations where the simulator is nevertheless able -to continue normal operation. The warning mechanism has two levels. The high-level is implemented with the function -:ref:`mj_warning`. It registers a warning in mjData as explained in more detail in the :ref:`diagnostics -` section below, and also calls the low-level function :ref:`mju_warning`. Alternatively, the low-level -function may be called directly (from within mj_loadModel for example) without registering a warning in mjData. This -is done in places where mjData is not available. +.. _siInfoMessages: -mju_warning does the following: if the user callback :ref:`mju_user_warning` is installed, it calls that callback. -Otherwise it appends the warning message to MUJOCO_LOG.TXT and also does a printf, similar to mju_error but without -exiting. When MuJoCo wrappers are developed for environments such as MATLAB, it makes sense to install a user callback -which prints warnings in the command window (with mexPrintf). +Informational messages +^^^^^^^^^^^^^^^^^^^^^^ + +MuJoCo provides two :ref:`levels` of opt-in diagnostic logging: informational messages (``mjLOG_INFO``) and +debug traces (``mjLOG_DEBUG``). Both use topic identifiers from the :ref:`mjtLogTopic` enum, but have a subtle +architectural distinction in how filtering is applied: + +* **INFO messages**: Emitted unconditionally by the engine. Filtering happens on the **consumer side** inside the + default handler. Custom handlers installed via :ref:`mju_setLogHandler` receive all INFO messages and + can implement their own filtering logic. + +* **DEBUG messages**: Designed for tight, high-frequency simulation loops where constructing strings would be a + performance bottleneck. Therefore, filtering happens on the **producer side** via :ref:`mju_isTopicEnabled`. If a + topic is disabled, the message is never constructed or dispatched. Consequently, custom handlers will only receive + DEBUG messages if the topic is explicitly enabled in the active :ref:`mjLogConfig`. + +In the default handler, INFO messages are followed by a blank line for readability, whereas high-frequency DEBUG traces +are printed compactly without trailing blank lines. + +To enable topics in the default handler configuration: + +.. code-block:: C + + // enable sleep/wake messages + mjLogConfig config = mju_getLogConfig(); + config.topics |= (1 << (mjTOPIC_SLEEP - 1)); + mju_setLogConfig(config); + +Topic 0 (``mjTOPIC_NONE``) always passes through, regardless of the topic configuration. + +Note that topics are 1-indexed, so the bitmask for topic ``t`` is ``(1 << (t - 1))``. This is also how the +``topics`` field of :ref:`mjLogConfig` is encoded. + +Topics can also be enabled via the environment variable ``MUJOCO_LOG_TOPICS``, which is read once at startup. +The value is a comma-separated list of topic names (case-insensitive), derived from the :ref:`mjtLogTopic` enum +by removing the ``mjTOPIC_`` prefix and lowercasing (e.g., ``mjTOPIC_SLEEP`` becomes ``sleep``). +For example: + +.. code-block:: shell + + export MUJOCO_LOG_TOPICS=sleep,time_stp + +This is equivalent to programmatically enabling the corresponding topic bits via :ref:`mju_setLogConfig`, and is +useful for enabling diagnostics without modifying code. + + +.. _siLogFrameworks: + +Frameworks and wrappers +^^^^^^^^^^^^^^^^^^^^^^^ + +Framework authors (e.g., those building Python bindings, MATLAB wrappers, or game engine integrations) should +install a custom log handler to route MuJoCo's output to their environment's logging system: + +.. code-block:: C + + // example: route to a framework's logging API + void framework_handler(const mjLogMessage* msg) { + if (msg->level == mjLOG_ERROR) { + framework_log_error(msg->subject); + framework_abort(); // must not return + } else if (msg->level == mjLOG_WARNING) { + framework_log_warning(msg->subject); + } else { + framework_log_info(msg->subject); + } + } + + mju_setLogHandler(framework_handler); + +The :ref:`mjLogMessage` struct also provides source location information (``func``, ``file``, ``line``) when +available, which can be useful for debugging. + +.. _siLogLegacy: + +Legacy handlers +^^^^^^^^^^^^^^^ + +The global function pointers :ref:`mju_user_error` and :ref:`mju_user_warning` are still supported for backward +compatibility, but are deprecated in favor of :ref:`mju_setLogHandler`. When both a custom log handler and legacy +handlers are installed, the custom log handler takes precedence. The legacy handlers are only consulted by the +*default* handler when no custom handler has been installed. + +.. _siLogMemory: + +Memory handlers +^^^^^^^^^^^^^^^ When MuJoCo allocates and frees memory on the heap, it always uses the functions :ref:`mju_malloc` and :ref:`mju_free`. These functions call the user callbacks :ref:`mju_user_malloc` and :ref:`mju_user_free` when diff --git a/include/mujoco/mjtype.h b/include/mujoco/mjtype.h index b3296824..c6d322aa 100644 --- a/include/mujoco/mjtype.h +++ b/include/mujoco/mjtype.h @@ -576,4 +576,47 @@ typedef enum mjtSleepState_ { // sleep state of an object mjS_AWAKE = 1 // object is awake } mjtSleepState; + + +//---------------------------------- logging ------------------------------------------------------- + +typedef enum mjtLogLevel_ { // log message severity + mjLOG_DEBUG = 0, // internal engine debug trace (opt-in via topic filtering) + mjLOG_INFO, // informational (opt-in via topic filtering) + mjLOG_WARNING, // warning + mjLOG_ERROR, // error +} mjtLogLevel; + +typedef enum mjtLogTopic_ { // log topic identifiers + mjTOPIC_NONE = 0, // no topic (always passes filtering) + // INFO topics: + mjTOPIC_TIME_STP = 1, // timing diagnostics (step) + mjTOPIC_TIME_CMP = 2, // timing diagnostics (compile) + // DEBUG topics: + mjTOPIC_SLEEP = 3, // sleep/wake events + + mjNTOPIC = 3 // number of filterable topics +} mjtLogTopic; + +typedef struct mjLogMessage_ { // structured log message + int level; // mjtLogLevel + int topic; // mjtLogTopic (0 for error/warning/user) + char subject[1024]; // message subject (one-liner, printf-formatted) + const char* body; // message body (multi-line detail, or NULL) + const char* func; // __func__ or NULL + const char* file; // __FILE__ or NULL + int line; // __LINE__ or 0 + mjtBool timestamp; // prepend timestamp to output +} mjLogMessage; + +typedef struct mjLogConfig_ { // log handler default configuration + mjtBool logto_console; // print to console (default: true) + mjtBool logto_file; // print to log file (default: true) + char logfile[1024]; // log file path (default: "MUJOCO_LOG.TXT") + int topics; // enabled info topic bitmask (default: 0) +} mjLogConfig; + +// function type for log handler callback; must be thread-safe, must not call mju_error +typedef void (*mjfLogHandler)(const mjLogMessage*); + #endif // MUJOCO_INCLUDE_MJTYPE_H_ diff --git a/include/mujoco/mujoco.h b/include/mujoco/mujoco.h index 91d59856..63b35d4f 100644 --- a/include/mujoco/mujoco.h +++ b/include/mujoco/mujoco.h @@ -41,12 +41,14 @@ extern "C" { #endif -// user error and memory handlers -MJAPI extern void (*mju_user_error)(const char*); -MJAPI extern void (*mju_user_warning)(const char*); +// user memory handlers MJAPI extern void* (*mju_user_malloc)(size_t); MJAPI extern void (*mju_user_free)(void*); +// legacy error/warning handlers (deprecated: prefer mju_setLogHandler) +MJAPI extern void (*mju_user_error)(const char*); +MJAPI extern void (*mju_user_warning)(const char*); + // callbacks extending computation pipeline MJAPI extern mjfGeneric mjcb_passive; @@ -71,6 +73,7 @@ MJAPI extern const char* mjLABELSTRING[mjNLABEL]; MJAPI extern const char* mjFRAMESTRING[mjNFRAME]; MJAPI extern const char* mjVISSTRING[mjNVISFLAG][3]; MJAPI extern const char* mjRNDSTRING[mjNRNDFLAG][3]; +MJAPI extern const char* mjTOPICSTRING[mjNTOPIC]; //---------------------------------- Virtual file system ------------------------------------------- @@ -978,6 +981,22 @@ MJAPI void mju_warning(const char* msg, ...) mjPRINTFLIKE(1, 2); // Clear user error and memory handlers. MJAPI void mju_clearHandlers(void); +// Set the active log handler; return the previous handler. +// If handler is NULL, restore the default handler. +MJAPI mjfLogHandler mju_setLogHandler(mjfLogHandler handler); + +// Get default handler configuration. +MJAPI mjLogConfig mju_getLogConfig(void); + +// Set default handler configuration. +MJAPI void mju_setLogConfig(mjLogConfig config); + +// Log an info message with optional topic filtering. +MJAPI void mju_info(int topic, const char* msg, ...) mjPRINTFLIKE(2, 3); + +// Dispatch a structured log message to the active handler. +MJAPI void mju_message(const mjLogMessage* msg); + // Allocate memory; byte-align on 64; pad size to multiple of 64. MJAPI void* mju_malloc(size_t size); diff --git a/python/mujoco/bindings_test.py b/python/mujoco/bindings_test.py index cd1ab24f..21e048ab 100644 --- a/python/mujoco/bindings_test.py +++ b/python/mujoco/bindings_test.py @@ -17,6 +17,7 @@ import contextlib import copy from etils import epath +import os import pickle import sys @@ -511,6 +512,54 @@ class MuJoCoBindingsTest(parameterized.TestCase): mujoco.mj_checkPos(self.model, self.data) self.assertEqual(warnings[mujoco.mjtWarning.mjWARN_BADQPOS].number, 1) + def test_mju_user_warning_callback_receives_warnings(self): + """Regression test: C warnings must reach Python mju_user_warning callbacks. + + The unified logging API routes all messages through a TLS log handler. + This test verifies that non-error messages are forwarded to the global + handler chain, where legacy mju_user_warning callbacks are invoked. + """ + warning_messages = [] + def warning_cb(msg): + warning_messages.append(msg) + old_cb = mujoco.get_mju_user_warning() + try: + mujoco.set_mju_user_warning(warning_cb) + # Trigger a C-level warning by setting qpos to NaN and calling mj_step. + model = mujoco.MjModel.from_xml_string(TEST_XML) + data = mujoco.MjData(model) + data.qpos[0] = float('NaN') + mujoco.mj_checkPos(model, data) + self.assertNotEmpty(warning_messages) + # The warning message should mention the bad QPOS value. + self.assertTrue( + any('QPOS' in msg for msg in warning_messages), warning_messages + ) + finally: + mujoco.set_mju_user_warning(old_cb) + + def test_mjtopic_time_cmp_logs_compile_time(self): + """Verifies MjLogConfig.get/set and info topic logging.""" + old_cfg = mujoco.MjLogConfig.get() + log_path = os.path.join( + absltest.get_default_test_tmpdir(), 'test_compile.log' + ) + os.makedirs(os.path.dirname(log_path), exist_ok=True) + try: + cfg = mujoco.MjLogConfig.get() + cfg.logto_file = True + cfg.logfile = log_path + cfg.topics |= (1 << (mujoco.mjtLogTopic.mjTOPIC_TIME_CMP - 1)) + cfg.set() + + mujoco.MjModel.from_xml_string(TEST_XML) + + with open(log_path, 'r') as f: + output = f.read() + self.assertIn('compile time', output) + finally: + old_cfg.set() + def test_mjcontact_can_copy(self): mujoco.mj_forward(self.model, self.data) diff --git a/python/mujoco/codegen/generate_cs_bindings.py b/python/mujoco/codegen/generate_cs_bindings.py index bc94dcca..0e0bacef 100644 --- a/python/mujoco/codegen/generate_cs_bindings.py +++ b/python/mujoco/codegen/generate_cs_bindings.py @@ -192,6 +192,7 @@ _ALLOWED_FIXED_ARRAYS = { _FUNCTION_POINTER_TYPES = { 'mjfItemEnable', + 'mjfLogHandler', } _STRUCT_NAME_OVERRIDES = {} diff --git a/python/mujoco/codegen/generate_function_traits.py b/python/mujoco/codegen/generate_function_traits.py index 5730d04a..a2fa4fe5 100644 --- a/python/mujoco/codegen/generate_function_traits.py +++ b/python/mujoco/codegen/generate_function_traits.py @@ -37,10 +37,8 @@ def main(argv: Sequence[str]) -> None: struct_decls = [] for func in FUNCTIONS.values(): - # Skip mju_error_{i,s} and mju_warning_{i,s} as these are not - # supported in the Python bindings, and Introspect currently - # doesn't support variadic functions. - if func.name.startswith('mju_error') or func.name == 'mju_warning': + # Skip variadic functions as Introspect currently doesn't support them. + if func.name in ('mju_error', 'mju_warning', 'mju_info'): continue # Modify some parameter types. diff --git a/python/mujoco/errors.h b/python/mujoco/errors.h index 5ff5022b..0f63f55d 100644 --- a/python/mujoco/errors.h +++ b/python/mujoco/errors.h @@ -15,12 +15,15 @@ #ifndef MUJOCO_PYTHON_ERRORS_H_ #define MUJOCO_PYTHON_ERRORS_H_ +#include #include +#include +#include #include #include #include -#include +#include #include "private.h" #include "util/crossplatform.h" #include "util/func_wrap.h" @@ -104,9 +107,28 @@ class ErrorBase : public pybind11::builtin_exception { static thread_local std::jmp_buf mju_error_jmp_buf; static thread_local std::array mju_error_msg{0}; -static inline void MjErrorHandler(const char* msg) { - std::strncpy(mju_error_msg.data(), msg, mju_error_msg.size() - 1); - mju_error_msg.data()[mju_error_msg.size() - 1] = '\0'; +// The handler to forward non-error messages to. Set by WrapFunc before each +// call into MuJoCo C code, pointing to either the previously installed TLS +// handler or the active global handler. +static thread_local mjfLogHandler mju_forward_handler = nullptr; + +static inline void MjErrorHandler(const mjLogMessage* msg) { + if (msg->level != mjLOG_ERROR) { + // Forward warnings, info, and debug messages to the previous handler so + // that legacy mju_user_warning callbacks and console output continue to + // work. + if (mju_forward_handler != nullptr) { + mju_forward_handler(msg); + } + return; + } + if (msg->func != nullptr) { + std::snprintf(mju_error_msg.data(), mju_error_msg.size(), "%s: %s", + msg->func, msg->subject); + } else { + std::strncpy(mju_error_msg.data(), msg->subject, mju_error_msg.size() - 1); + mju_error_msg.data()[mju_error_msg.size() - 1] = '\0'; + } std::longjmp(mju_error_jmp_buf, 1); } @@ -121,7 +143,17 @@ struct MjErrorIntercepter { #else return [callable](Args... args) MUJOCO_ALWAYS_INLINE_LAMBDA_MUTABLE { #endif - _mjPRIVATE__set_tls_error_fn(&MjErrorHandler); + mjfLogHandler prev_handler = _mjPRIVATE_setTlsLogHandler(&MjErrorHandler); + + // Determine the handler to forward non-error messages to. + // If there was a previously installed TLS handler, forward to it. + // Otherwise, probe the global handler via mju_setLogHandler. + mjfLogHandler old_forward = mju_forward_handler; + if (prev_handler != nullptr) { + mju_forward_handler = prev_handler; + } else { + mju_forward_handler = _mjPRIVATE_getGlobalLogHandler(); + } // DON'T MIX RAII WITH SETJMP! // From https://en.cppreference.com/w/cpp/utility/program/longjmp: @@ -131,16 +163,19 @@ struct MjErrorIntercepter { if (setjmp(mju_error_jmp_buf) == 0) { if constexpr (std::is_void_v) { callable(args...); - _mjPRIVATE__set_tls_error_fn(nullptr); + mju_forward_handler = old_forward; + _mjPRIVATE_setTlsLogHandler(prev_handler); } else { auto ret = callable(args...); static_assert(std::is_trivially_destructible_v); - _mjPRIVATE__set_tls_error_fn(nullptr); + mju_forward_handler = old_forward; + _mjPRIVATE_setTlsLogHandler(prev_handler); return ret; } } else { // This branch is entered via a longjmp back from our mju_error handler. - _mjPRIVATE__set_tls_error_fn(nullptr); + mju_forward_handler = old_forward; + _mjPRIVATE_setTlsLogHandler(prev_handler); { // Check if a Python callback has thrown an exception. // We cannot use a py::gil_scoped_acquire here: on Windows its diff --git a/python/mujoco/introspect/enums.py b/python/mujoco/introspect/enums.py index bd8338c4..f5b21971 100644 --- a/python/mujoco/introspect/enums.py +++ b/python/mujoco/introspect/enums.py @@ -609,6 +609,29 @@ ENUMS: Mapping[str, EnumDecl] = dict([ ('mjS_AWAKE', 1), ]), )), + ('mjtLogLevel', + EnumDecl( + name='mjtLogLevel', + declname='enum mjtLogLevel_', + values=dict([ + ('mjLOG_DEBUG', 0), + ('mjLOG_INFO', 1), + ('mjLOG_WARNING', 2), + ('mjLOG_ERROR', 3), + ]), + )), + ('mjtLogTopic', + EnumDecl( + name='mjtLogTopic', + declname='enum mjtLogTopic_', + values=dict([ + ('mjTOPIC_NONE', 0), + ('mjTOPIC_TIME_STP', 1), + ('mjTOPIC_TIME_CMP', 2), + ('mjTOPIC_SLEEP', 3), + ('mjNTOPIC', 3), + ]), + )), ('mjtGeomInertia', EnumDecl( name='mjtGeomInertia', diff --git a/python/mujoco/introspect/functions.py b/python/mujoco/introspect/functions.py index 800ed67c..8a0c2e7b 100644 --- a/python/mujoco/introspect/functions.py +++ b/python/mujoco/introspect/functions.py @@ -6309,6 +6309,69 @@ FUNCTIONS: Mapping[str, FunctionDecl] = dict([ parameters=(), doc='Clear user error and memory handlers.', )), + ('mju_setLogHandler', + FunctionDecl( + name='mju_setLogHandler', + return_type=ValueType(name='mjfLogHandler'), + parameters=( + FunctionParameterDecl( + name='handler', + type=ValueType(name='mjfLogHandler'), + ), + ), + doc='Set the active log handler; return the previous handler. If handler is NULL, restore the default handler.', # pylint: disable=line-too-long + )), + ('mju_getLogConfig', + FunctionDecl( + name='mju_getLogConfig', + return_type=ValueType(name='mjLogConfig'), + parameters=(), + doc='Get default handler configuration.', + )), + ('mju_setLogConfig', + FunctionDecl( + name='mju_setLogConfig', + return_type=ValueType(name='void'), + parameters=( + FunctionParameterDecl( + name='config', + type=ValueType(name='mjLogConfig'), + ), + ), + doc='Set default handler configuration.', + )), + ('mju_info', + FunctionDecl( + name='mju_info', + return_type=ValueType(name='void'), + parameters=( + FunctionParameterDecl( + name='topic', + type=ValueType(name='int'), + ), + FunctionParameterDecl( + name='msg', + type=PointerType( + inner_type=ValueType(name='char', is_const=True), + ), + ), + ), + doc='Log an info message with optional topic filtering.', + )), + ('mju_message', + FunctionDecl( + name='mju_message', + return_type=ValueType(name='void'), + parameters=( + FunctionParameterDecl( + name='msg', + type=PointerType( + inner_type=ValueType(name='mjLogMessage', is_const=True), + ), + ), + ), + doc='Dispatch a structured log message to the active handler.', + )), ('mju_malloc', FunctionDecl( name='mju_malloc', diff --git a/python/mujoco/introspect/structs.py b/python/mujoco/introspect/structs.py index f179dfda..420f15ee 100644 --- a/python/mujoco/introspect/structs.py +++ b/python/mujoco/introspect/structs.py @@ -28,6 +28,92 @@ from .ast_nodes import StructFieldDecl from .ast_nodes import ValueType STRUCTS: Mapping[str, StructDecl] = dict([ + ('mjLogMessage', + StructDecl( + name='mjLogMessage', + declname='struct mjLogMessage_', + fields=( + StructFieldDecl( + name='level', + type=ValueType(name='int'), + doc='mjtLogLevel', + ), + StructFieldDecl( + name='topic', + type=ValueType(name='int'), + doc='mjtLogTopic (0 for error/warning/user)', + ), + StructFieldDecl( + name='subject', + type=ArrayType( + inner_type=ValueType(name='char'), + extents=(1024,), + ), + doc='message subject (one-liner, printf-formatted)', + ), + StructFieldDecl( + name='body', + type=PointerType( + inner_type=ValueType(name='char', is_const=True), + ), + doc='message body (multi-line detail, or NULL)', + ), + StructFieldDecl( + name='func', + type=PointerType( + inner_type=ValueType(name='char', is_const=True), + ), + doc='__func__ or NULL', + ), + StructFieldDecl( + name='file', + type=PointerType( + inner_type=ValueType(name='char', is_const=True), + ), + doc='__FILE__ or NULL', + ), + StructFieldDecl( + name='line', + type=ValueType(name='int'), + doc='__LINE__ or 0', + ), + StructFieldDecl( + name='timestamp', + type=ValueType(name='mjtBool'), + doc='prepend timestamp to output', + ), + ), + )), + ('mjLogConfig', + StructDecl( + name='mjLogConfig', + declname='struct mjLogConfig_', + fields=( + StructFieldDecl( + name='logto_console', + type=ValueType(name='mjtBool'), + doc='print to console (default: true)', + ), + StructFieldDecl( + name='logto_file', + type=ValueType(name='mjtBool'), + doc='print to log file (default: true)', + ), + StructFieldDecl( + name='logfile', + type=ArrayType( + inner_type=ValueType(name='char'), + extents=(1024,), + ), + doc='log file path (default: "MUJOCO_LOG.TXT")', + ), + StructFieldDecl( + name='topics', + type=ValueType(name='int'), + doc='enabled info topic bitmask (default: 0)', + ), + ), + )), ('mjLROpt', StructDecl( name='mjLROpt', diff --git a/python/mujoco/private.h b/python/mujoco/private.h index 13a71b61..b616a2dc 100644 --- a/python/mujoco/private.h +++ b/python/mujoco/private.h @@ -17,11 +17,13 @@ #include #include +#include // DO NOT USE THESE FUNCTIONS ELSEWHERE. // They should be regarded as part of MuJoCo's internal implementation detail. extern "C" { -MJAPI void _mjPRIVATE__set_tls_error_fn(void (*h)(const char*)); +MJAPI mjfLogHandler _mjPRIVATE_setTlsLogHandler(mjfLogHandler handler); +MJAPI mjfLogHandler _mjPRIVATE_getGlobalLogHandler(void); MJAPI void* mj_arenaAllocByte(mjData* d, int bytes, int alignment); } diff --git a/python/mujoco/raw.h b/python/mujoco/raw.h index b0d71ae6..0d97d55a 100644 --- a/python/mujoco/raw.h +++ b/python/mujoco/raw.h @@ -19,6 +19,7 @@ #include #include #include +#include #include // Type aliases for MuJoCo C structs to allow us refer to consistently refer @@ -72,6 +73,8 @@ using MjVisualMap = decltype(::mjVisual::map); using MjVisualScale = decltype(::mjVisual::scale); using MjVisualRgba = decltype(::mjVisual::rgba); using MjWarningStat = ::mjWarningStat; +using MjLogConfig = ::mjLogConfig; +using MjLogMessage = ::mjLogMessage; // From mjrender.h using MjrRect = ::mjrRect; diff --git a/python/mujoco/structs.cc b/python/mujoco/structs.cc index 91395ec7..6b35b9c0 100644 --- a/python/mujoco/structs.cc +++ b/python/mujoco/structs.cc @@ -539,6 +539,96 @@ This is useful for example when the MJB is not available as a file on disk.)")); X(int, number); #undef X + // ==================== MJLOGCONFIG ========================================== + py::class_ mjLogConfig(m, "MjLogConfig"); + mjLogConfig.def(py::init<>()); + mjLogConfig.def("__copy__", [](const MjLogConfigWrapper& other) { + return MjLogConfigWrapper(other); + }); + mjLogConfig.def("__deepcopy__", + [](const MjLogConfigWrapper& other, py::dict) { + return MjLogConfigWrapper(other); + }); + DefineStructFunctions(mjLogConfig); + mjLogConfig.def_property( + "logto_console", + [](const MjLogConfigWrapper& d) { return d.get()->logto_console; }, + [](MjLogConfigWrapper& d, bool rhs) { d.get()->logto_console = rhs; }); + mjLogConfig.def_property( + "logto_file", + [](const MjLogConfigWrapper& d) { return d.get()->logto_file; }, + [](MjLogConfigWrapper& d, bool rhs) { d.get()->logto_file = rhs; }); + mjLogConfig.def_property( + "logfile", + [](const MjLogConfigWrapper& d) { return std::string(d.get()->logfile); }, + [](MjLogConfigWrapper& d, const std::string& rhs) { + std::strncpy(d.get()->logfile, rhs.c_str(), 1023); + d.get()->logfile[1023] = '\0'; + }); + mjLogConfig.def_property( + "topics", [](const MjLogConfigWrapper& d) { return d.get()->topics; }, + [](MjLogConfigWrapper& d, int rhs) { d.get()->topics = rhs; }); + mjLogConfig.def_static("get", []() { + MjLogConfigWrapper wrapper; + *wrapper.get() = mju_getLogConfig(); + return wrapper; + }); + mjLogConfig.def("set", [](const MjLogConfigWrapper& self) { + mju_setLogConfig(*self.get()); + }); + + // ==================== MJLOGMESSAGE ========================================= + py::class_ mjLogMessage(m, "MjLogMessage"); + mjLogMessage.def(py::init<>()); + mjLogMessage.def("__copy__", [](const MjLogMessageWrapper& other) { + return MjLogMessageWrapper(other); + }); + mjLogMessage.def("__deepcopy__", + [](const MjLogMessageWrapper& other, py::dict) { + return MjLogMessageWrapper(other); + }); + DefineStructFunctions(mjLogMessage); + mjLogMessage.def_property( + "level", [](const MjLogMessageWrapper& d) { return d.get()->level; }, + [](MjLogMessageWrapper& d, int rhs) { d.get()->level = rhs; }); + mjLogMessage.def_property( + "topic", [](const MjLogMessageWrapper& d) { return d.get()->topic; }, + [](MjLogMessageWrapper& d, int rhs) { d.get()->topic = rhs; }); + mjLogMessage.def_property( + "subject", + [](const MjLogMessageWrapper& d) { + return std::string(d.get()->subject); + }, + [](MjLogMessageWrapper& d, const std::string& rhs) { + std::strncpy(d.get()->subject, rhs.c_str(), 1023); + d.get()->subject[1023] = '\0'; + }); + mjLogMessage.def_property_readonly( + "body", + [](const MjLogMessageWrapper& d) -> py::object { + if (d.get()->body) return py::str(d.get()->body); + return py::none(); + }); + mjLogMessage.def_property_readonly( + "func", + [](const MjLogMessageWrapper& d) -> py::object { + if (d.get()->func) return py::str(d.get()->func); + return py::none(); + }); + mjLogMessage.def_property_readonly( + "file", + [](const MjLogMessageWrapper& d) -> py::object { + if (d.get()->file) return py::str(d.get()->file); + return py::none(); + }); + mjLogMessage.def_property( + "line", [](const MjLogMessageWrapper& d) { return d.get()->line; }, + [](MjLogMessageWrapper& d, int rhs) { d.get()->line = rhs; }); + mjLogMessage.def_property( + "timestamp", + [](const MjLogMessageWrapper& d) { return d.get()->timestamp; }, + [](MjLogMessageWrapper& d, bool rhs) { d.get()->timestamp = rhs; }); + // ==================== MJTIMERSTAT ========================================== py::class_ mjTimerStat(m, "MjTimerStat"); mjTimerStat.def(py::init<>()); @@ -960,18 +1050,22 @@ This is useful for example when the MJB is not available as a file on disk.)")); #undef X // ==================== MJRVERTEXATTRIBUTE =================================== - py::class_ mjrVertexAttribute(m, "MjrVertexAttribute"); + py::class_ mjrVertexAttribute(m, + "MjrVertexAttribute"); mjrVertexAttribute.def(py::init([](int usage, int type) { return raw::MjrVertexAttribute{nullptr, usage, type}; }), py::arg("usage") = 0, py::arg("type") = 0); - mjrVertexAttribute.def("__copy__", - [](const raw::MjrVertexAttribute& other) { return raw::MjrVertexAttribute(other); }); - mjrVertexAttribute.def("__deepcopy__", [](const raw::MjrVertexAttribute& other, py::dict) { + mjrVertexAttribute.def("__copy__", [](const raw::MjrVertexAttribute& other) { return raw::MjrVertexAttribute(other); }); + mjrVertexAttribute.def("__deepcopy__", + [](const raw::MjrVertexAttribute& other, py::dict) { + return raw::MjrVertexAttribute(other); + }); DefineStructFunctions(mjrVertexAttribute); -#define X(var) mjrVertexAttribute.def_readwrite(#var, &raw::MjrVertexAttribute::var) +#define X(var) \ + mjrVertexAttribute.def_readwrite(#var, &raw::MjrVertexAttribute::var) X(usage); X(type); #undef X diff --git a/python/mujoco/structs.h b/python/mujoco/structs.h index 4bf3dd98..2db39ff2 100644 --- a/python/mujoco/structs.h +++ b/python/mujoco/structs.h @@ -377,6 +377,38 @@ struct is_mj_struct_list { static constexpr bool value = true; }; +// ==================== MJLOGCONFIG ============================================ +template <> +class MjWrapper : public WrapperBase { + public: + MjWrapper(); + MjWrapper(const MjWrapper&); + MjWrapper(MjWrapper&&) = default; + MjWrapper(raw::MjLogConfig* ptr, pybind11::handle owner); + ~MjWrapper() = default; +}; + +using MjLogConfigWrapper = MjWrapper; + +template <> +struct enable_if_mj_struct { using type = void; }; + +// ==================== MJLOGMESSAGE =========================================== +template <> +class MjWrapper : public WrapperBase { + public: + MjWrapper(); + MjWrapper(const MjWrapper&); + MjWrapper(MjWrapper&&) = default; + MjWrapper(raw::MjLogMessage* ptr, pybind11::handle owner); + ~MjWrapper() = default; +}; + +using MjLogMessageWrapper = MjWrapper; + +template <> +struct enable_if_mj_struct { using type = void; }; + // ==================== MJTIMERSTAT ============================================ template <> class MjWrapper : public WrapperBase { @@ -977,6 +1009,8 @@ using _impl::MjVisualRgbaWrapper; using _impl::MjVisualWrapper; using _impl::MjStatisticWrapper; using _impl::MjWarningStatWrapper; +using _impl::MjLogConfigWrapper; +using _impl::MjLogMessageWrapper; using _impl::MjTimerStatWrapper; using _impl::MjSolverStatWrapper; using _impl::MjModelWrapper; diff --git a/python/mujoco/structs_wrappers.cc b/python/mujoco/structs_wrappers.cc index c5c8b6ca..3444ea6d 100644 --- a/python/mujoco/structs_wrappers.cc +++ b/python/mujoco/structs_wrappers.cc @@ -1019,6 +1019,28 @@ MjWarningStatList::MjStructList(MjWarningStatList& other, py::slice slice) : StructListBase(other, slice), X(int, lastinfo), X(int, number) {} #undef X +// ==================== MJLOGCONFIG ============================================ +MjLogConfigWrapper::MjWrapper() : WrapperBase(new raw::MjLogConfig{}) {} + +MjLogConfigWrapper::MjWrapper(raw::MjLogConfig* ptr, py::handle owner) + : WrapperBase(ptr, owner) {} + +MjLogConfigWrapper::MjWrapper(const MjLogConfigWrapper& other) + : MjLogConfigWrapper() { + *this->ptr_ = *other.ptr_; +} + +// ==================== MJLOGMESSAGE =========================================== +MjLogMessageWrapper::MjWrapper() : WrapperBase(new raw::MjLogMessage{}) {} + +MjLogMessageWrapper::MjWrapper(raw::MjLogMessage* ptr, py::handle owner) + : WrapperBase(ptr, owner) {} + +MjLogMessageWrapper::MjWrapper(const MjLogMessageWrapper& other) + : MjLogMessageWrapper() { + *this->ptr_ = *other.ptr_; +} + // ==================== MJTIMERSTAT ============================================ MjTimerStatWrapper::MjWrapper() : WrapperBase(new raw::MjTimerStat{}) {} diff --git a/sample/compile.cc b/sample/compile.cc index f39e13b9..d6fb141a 100644 --- a/sample/compile.cc +++ b/sample/compile.cc @@ -137,22 +137,13 @@ int main(int argc, char** argv) { } } - // print compiler timing diagnostics - auto print_timers = [](const mjSpec* s, const char* label) { - const double* timer = mjs_getTimer(const_cast(s)); - std::printf("\n%s:\n", label); - std::printf(" total: %8.1f ms\n", 1e3 * timer[mjCTIMER_TOTAL]); - std::printf(" assets: %8.1f ms (wall clock)\n", 1e3 * timer[mjCTIMER_ASSETS]); - std::printf(" load: %8.1f ms\n", 1e3 * timer[mjCTIMER_MESH_LOAD]); - std::printf(" hull: %8.1f ms\n", 1e3 * timer[mjCTIMER_MESH_HULL]); - std::printf(" poly: %8.1f ms\n", 1e3 * timer[mjCTIMER_MESH_POLYGON]); - std::printf(" inert: %8.1f ms\n", 1e3 * timer[mjCTIMER_MESH_INERTIA]); - std::printf(" bvh: %8.1f ms\n", 1e3 * timer[mjCTIMER_MESH_BVH]); - std::printf(" octr: %8.1f ms\n", 1e3 * timer[mjCTIMER_MESH_OCTREE]); - std::printf(" tex: %8.1f ms\n", 1e3 * timer[mjCTIMER_TEXTURE]); - std::printf(" other: %8.1f ms\n", - 1e3 * (timer[mjCTIMER_TOTAL] - timer[mjCTIMER_ASSETS])); - }; + // enable compile timing diagnostics + if (type2 == typeNONE) { + mjLogConfig config = mju_getLogConfig(); + config.logfile[0] = '\0'; + config.topics |= (1 << (mjTOPIC_TIME_CMP - 1)); + mju_setLogConfig(config); + } // load model mjSpec* s = nullptr; @@ -162,20 +153,19 @@ int main(int argc, char** argv) { return finish(error, EXIT_FAILURE); } + if (type2 == typeNONE) { + std::cout << "Compile 1 (cold cache)\n"; + } m = mj_compile(s, 0); if (!m) { mj_deleteSpec(s); return finish("Could not compile model", EXIT_FAILURE); } - print_timers(s, "Compile 1 (cold cache)"); - if (type2 == typeNONE) { mj_deleteModel(m); + std::cout << "Compile 2 (warm cache)\n"; m = mj_compile(s, 0); - if (m) { - print_timers(s, "Compile 2 (warm cache)"); - } } } else { m = mj_loadModel(argv[1], 0); @@ -201,5 +191,5 @@ int main(int argc, char** argv) { // finalize if (s) mj_deleteSpec(s); - return finish("\nDone.", EXIT_SUCCESS, m); + return finish("Done.", EXIT_SUCCESS, m); } diff --git a/simulate/simulate.cc b/simulate/simulate.cc index 61940816..bc473343 100644 --- a/simulate/simulate.cc +++ b/simulate/simulate.cc @@ -107,6 +107,7 @@ enum { SECT_RENDERING, SECT_VISUALIZATION, SECT_GROUP, + SECT_LOGGING, NSECT0, // right ui @@ -367,22 +368,27 @@ void UpdateProfiler(mj::Simulate* sim, const mjModel* m, const mjData* d) { } // get timers: total, collision, prepare, solve, other - mjtNum total = d->timer[mjTIMER_STEP].duration; - int number = d->timer[mjTIMER_STEP].number; + mjtNum total = d->timer[mjTIMER_STEP].duration - sim->timer_prev_[mjTIMER_STEP].duration; + int number = d->timer[mjTIMER_STEP].number - sim->timer_prev_[mjTIMER_STEP].number; + int prev_forward_number = sim->timer_prev_[mjTIMER_FORWARD].number; + mjtNum prev_forward_duration = sim->timer_prev_[mjTIMER_FORWARD].duration; if (!number) { - total = d->timer[mjTIMER_FORWARD].duration; - number = d->timer[mjTIMER_FORWARD].number; + total = d->timer[mjTIMER_FORWARD].duration - prev_forward_duration; + number = d->timer[mjTIMER_FORWARD].number - prev_forward_number; } - if (number) { // skip update if no measurements + if (number > 0) { // skip update if no measurements float tdata[5] = { - static_cast(total/number), - static_cast(d->timer[mjTIMER_POS_COLLISION].duration/number), - static_cast(d->timer[mjTIMER_POS_MAKE].duration/number) + - static_cast(d->timer[mjTIMER_POS_PROJECT].duration/number), - static_cast(d->timer[mjTIMER_CONSTRAINT].duration/number), - 0 - }; + static_cast(total / number), + static_cast((d->timer[mjTIMER_POS_COLLISION].duration - + sim->timer_prev_[mjTIMER_POS_COLLISION].duration) / number), + static_cast((d->timer[mjTIMER_POS_MAKE].duration - + sim->timer_prev_[mjTIMER_POS_MAKE].duration + + d->timer[mjTIMER_POS_PROJECT].duration - + sim->timer_prev_[mjTIMER_POS_PROJECT].duration) / number), + static_cast((d->timer[mjTIMER_CONSTRAINT].duration - + sim->timer_prev_[mjTIMER_CONSTRAINT].duration) / number), + 0}; tdata[4] = tdata[0] - tdata[1] - tdata[2] - tdata[3]; // update figtimer @@ -399,6 +405,10 @@ void UpdateProfiler(mj::Simulate* sim, const mjModel* m, const mjData* d) { } } + for (int i = 0; i < mjNTIMER; i++) { + sim->timer_prev_[i] = d->timer[i]; + } + // get total number of iterations and nonzeros mjtNum sqrt_nnz = 0; int solver_niter = 0; @@ -1154,6 +1164,35 @@ void MakeGroupSection(mj::Simulate* sim) { mjui_add(&sim->ui0, defGroup); } +// make logging section of UI +void MakeLoggingSection(mj::Simulate* sim) { + mjLogConfig cfg = mju_getLogConfig(); + sim->log_console = cfg.logto_console; + sim->log_file = cfg.logto_file; + for (int i = 0; i < mjNTOPIC; i++) { + sim->log_topics[i] = ((cfg.topics & (1 << i)) != 0); + } + + mjuiDef defLogging[] = { + {mjITEM_SECTION, "Logging", mjPRESERVE, nullptr, "AL"}, + {mjITEM_CHECKBYTE, "Console", 2, &sim->log_console, ""}, + {mjITEM_CHECKBYTE, "File", 2, &sim->log_file, ""}, + {mjITEM_SEPARATOR, "Info topics", 1}, + {mjITEM_END} + }; + mjui_add(&sim->ui0, defLogging); + + mjuiDef defTopic[] = { + {mjITEM_CHECKBYTE, "", 2, nullptr, ""}, + {mjITEM_END} + }; + for (int i = 0; i < mjNTOPIC; i++) { + mju::strcpy_arr(defTopic[0].name, mjTOPICSTRING[i]); + defTopic[0].pdata = sim->log_topics + i; + mjui_add(&sim->ui0, defTopic); + } +} + // make joint section of UI void MakeJointSection(mj::Simulate* sim) { mjuiDef defJoint[] = { @@ -1304,6 +1343,7 @@ void MakeUiSections(mj::Simulate* sim, const mjModel* m, const mjData* d) { MakeRenderingSection(sim, m); MakeVisualizationSection(sim, m); MakeGroupSection(sim); + MakeLoggingSection(sim); MakeJointSection(sim); MakeControlSection(sim); MakeEqualitySection(sim); @@ -1406,14 +1446,6 @@ mjtNum Timer() { return elapsed.count(); } -// clear all times -void ClearTimers(mjData* d) { - for (int i=0; itimer[i].duration = 0; - d->timer[i].number = 0; - } -} - // copy current camera to clipboard as MJCF specification void CopyCamera(mj::Simulate* sim) { mjvGLCamera* camera = sim->scn.camera; @@ -1479,6 +1511,28 @@ void UpdateSettings(mj::Simulate* sim, const mjModel* m) { if (old_camera != sim->camera) { sim->pending_.ui_update_rendering = true; } + + // logging flags + mjLogConfig cfg = mju_getLogConfig(); + bool logging_changed = false; + if (sim->log_console != cfg.logto_console) { + sim->log_console = cfg.logto_console; + logging_changed = true; + } + if (sim->log_file != cfg.logto_file) { + sim->log_file = cfg.logto_file; + logging_changed = true; + } + for (int i = 0; i < mjNTOPIC; i++) { + int enabled = ((cfg.topics & (1 << i)) != 0); + if (sim->log_topics[i] != enabled) { + sim->log_topics[i] = enabled; + logging_changed = true; + } + } + if (logging_changed) { + sim->pending_.ui_update_logging = true; + } } // Compute suitable font scale. @@ -1722,7 +1776,6 @@ void UiEvent(mjuiState* state) { // rendering section else if (it && it->sectionid==SECT_RENDERING) { - // only update the camera when the camera itself changed if (it->pdata == &sim->camera) { if (sim->camera==0) { @@ -1772,6 +1825,20 @@ void UiEvent(mjuiState* state) { } } + // logging section + else if (it && it->sectionid==SECT_LOGGING) { + mjLogConfig cfg = mju_getLogConfig(); + cfg.logto_console = sim->log_console; + cfg.logto_file = sim->log_file; + cfg.topics = 0; + for (int i = 0; i < mjNTOPIC; i++) { + if (sim->log_topics[i]) { + cfg.topics |= (1 << i); + } + } + mju_setLogConfig(cfg); + } + // stop if UI processed event if (it!=nullptr || (state->type==mjEVENT_KEY && state->key==0)) { return; @@ -1815,8 +1882,6 @@ void UiEvent(mjuiState* state) { case mjKEY_RIGHT: // step forward if (!sim->is_passive_ && sim->m_ && !sim->run) { - ClearTimers(sim->d_); - // currently in scrubber: increment scrub, load state, update slider UI if (sim->scrub_index < 0) { sim->scrub_index++; @@ -1839,7 +1904,6 @@ void UiEvent(mjuiState* state) { case mjKEY_LEFT: // step backward if (!sim->is_passive_ && sim->m_) { sim->run = 0; - ClearTimers(sim->d_); // decrement scrub, load state sim->scrub_index = mjMAX(sim->scrub_index - 1, 1 - sim->nhistory_); @@ -2184,6 +2248,7 @@ void Simulate::Sync(bool state_only) { if (pending_.reset) { mj_resetData(m_, d_); + memset(timer_prev_, 0, sizeof(timer_prev_)); mj_forward(m_, d_); load_error[0] = '\0'; update_profiler = true; @@ -2366,9 +2431,6 @@ void Simulate::Sync(bool state_only) { UpdateSensorImage(this, m_, d_); } - // clear timers once profiler info has been copied - ClearTimers(d_); - if (this->run || this->is_passive_) { // clear old perturbations, apply new mju_zero(d_->xfrc_applied, 6*m_->nbody); @@ -2689,6 +2751,13 @@ void Simulate::Render() { pending_.ui_update_visualization = false; } + if (pending_.ui_update_logging) { + if (this->ui0_enable && this->ui0.sect[SECT_LOGGING].state) { + mjui0_update_section(this, SECT_LOGGING); + } + pending_.ui_update_logging = false; + } + if (is_passive_) { if (this->ui0_enable && this->ui0.sect[SECT_RENDERING].state && (cam_prev_.type != cam.type || diff --git a/simulate/simulate.h b/simulate/simulate.h index acb218b5..6bc553b4 100644 --- a/simulate/simulate.h +++ b/simulate/simulate.h @@ -172,6 +172,7 @@ class Simulate { bool ui_update_joint; bool ui_update_ctrl; bool ui_update_equality; + bool ui_update_logging; bool ui_remake_ctrl; } pending_ = {}; @@ -257,6 +258,12 @@ class Simulate { int enable[mjNENABLE] = {0}; int enableactuator[mjNGROUP] = {0}; + // logging: need sync + mjtByte log_console = 0; + mjtByte log_file = 0; + mjtByte log_topics[mjNTOPIC] = {0}; + mjTimerStat timer_prev_[mjNTIMER] = {}; + // rendering: need sync int camera = 0; diff --git a/src/engine/engine_crossplatform.h b/src/engine/engine_crossplatform.h index 7fa8478b..2cf6dff9 100644 --- a/src/engine/engine_crossplatform.h +++ b/src/engine/engine_crossplatform.h @@ -33,6 +33,12 @@ #include #endif +// Environment variable handling. +#ifdef _WIN32 + #define setenv(name, value, overwrite) _putenv_s(name, value) + #define unsetenv(name) _putenv_s(name, "") +#endif + // Switch-case fallthrough annotation. #if defined(__cplusplus) #define mjFALLTHROUGH [[fallthrough]] diff --git a/src/engine/engine_io.c b/src/engine/engine_io.c index 47e3b366..0c455674 100644 --- a/src/engine/engine_io.c +++ b/src/engine/engine_io.c @@ -1069,6 +1069,9 @@ void mj_makeRawData(mjData** dest, const mjModel* m) { mjERROR("could not allocate mjData"); } + // prevent spurious timing print from mj_resetData before _resetData zeroes the struct + d->timer[mjTIMER_STEP].number = 0; + // compute buffer size d->nbuffer = 0; d->buffer = d->arena = NULL; @@ -1563,12 +1566,85 @@ static void _resetData(const mjModel* m, mjData* d, unsigned char debug_value) { } +// emit step timing diagnostics +static void mj_logTimingDiagnostics(const mjData* d) { + int nstep = d->timer[mjTIMER_STEP].number; + if (nstep <= 0) { + return; + } + + mjtNum tstep = d->timer[mjTIMER_STEP].duration / nstep; + if (tstep <= 0) { + return; + } + + char buf[2048]; + int pos = 0; + mjtNum components = 0; + + for (int i = mjTIMER_POSITION; i <= mjTIMER_ADVANCE; i++) { + if (d->timer[i].number > 0) { + mjtNum istep = d->timer[i].duration / d->timer[i].number; + components += istep; + pos += snprintf(buf + pos, sizeof(buf) - pos, + "%s %-15s %8.1f (%5.1f%%)", + pos > 0 ? "\n" : "", + mjTIMERSTRING[i], istep * 1000, 100 * istep / tstep); + + // position sub-breakdown + if (i == mjTIMER_POSITION) { + for (int p = mjTIMER_POS_KINEMATICS; p <= mjTIMER_POS_PROJECT; p++) { + if (d->timer[p].number > 0) { + mjtNum pstep = d->timer[p].duration / d->timer[p].number; + pos += snprintf(buf + pos, sizeof(buf) - pos, + "\n %-13s %8.1f (%5.1f%%)", + mjTIMERSTRING[p] + 4, pstep * 1000, 100 * pstep / tstep); + + // collision sub-breakdown + if (p == mjTIMER_POS_COLLISION) { + for (int c = mjTIMER_COL_BROAD; c <= mjTIMER_COL_NARROW; c++) { + if (d->timer[c].number > 0) { + mjtNum cstep = d->timer[c].duration / d->timer[c].number; + pos += snprintf(buf + pos, sizeof(buf) - pos, + "\n %-11s %8.1f (%5.1f%%)", + mjTIMERSTRING[c] + 4, cstep * 1000, 100 * cstep / tstep); + } + } + } + } + } + } + } + } + + mjtNum other = tstep - components; + pos += snprintf(buf + pos, sizeof(buf) - pos, + "%s %-15s %8.1f (%5.1f%%)", + pos > 0 ? "\n" : "", + "other", other * 1000, 100 * other / tstep); + + pos += snprintf(buf + pos, sizeof(buf) - pos, + "%s %-15s %8.1f", + pos > 0 ? "\n" : "", + "total", tstep * 1000); + + mjLogMessage msg = {.level = mjLOG_INFO, .topic = mjTOPIC_TIME_STP, .body = buf}; + snprintf(msg.subject, sizeof(msg.subject), + "average time per step (%d steps, units: \u00B5s)", nstep); + mju_message(&msg); +} + + // clear data, set data->qpos = model->qpos0 void mj_resetData(const mjModel* m, mjData* d) { + // emit step timing diagnostics before timers are cleared + mj_logTimingDiagnostics(d); + _resetData(m, d, 0); } + // clear data, set data->qpos = model->qpos0, fill with debug_value void mj_resetDataDebug(const mjModel* m, mjData* d, unsigned char debug_value) { _resetData(m, d, debug_value); diff --git a/src/engine/engine_sleep.c b/src/engine/engine_sleep.c index 55c9d732..93cbd55f 100644 --- a/src/engine/engine_sleep.c +++ b/src/engine/engine_sleep.c @@ -24,8 +24,6 @@ #include "engine/engine_util_errmem.h" #include "engine/engine_util_misc.h" -// uncomment to print sleep/wake events -// #define MJ_DEBUG_SLEEP //-------------------------------- update ---------------------------------------------------------- @@ -187,8 +185,14 @@ int mj_sleepCycle(const int* tree_asleep, int ntree, int i) { //-------------------------------- wake ------------------------------------------------------------ +// helper for pluralizing in log messages +static inline const char* plural(int n) { + return n > 1 ? "s" : ""; +} + + // wake tree i and its associated cycle, return number of woke trees -int mj_wakeTree(int* tree_asleep, int ntree, int i, int wakeval) { +int mj_wakeIsland(int* tree_asleep, int ntree, int i, int wakeval, const char* reason, mjtNum time) { int nwoke = 0; // i is invalid; SHOULD NOT OCCUR @@ -207,6 +211,7 @@ int mj_wakeTree(int* tree_asleep, int ntree, int i, int wakeval) { // tree i asleep: wake up tree and its island cycle else { int current = i; + int woke_trees[1024]; // buffer for woke tree indices do { // get the index of the next tree in the cycle int next = tree_asleep[current]; @@ -217,8 +222,9 @@ int mj_wakeTree(int* tree_asleep, int ntree, int i, int wakeval) { return 0; } - // wake the current tree, increment count, advance to next + // wake the current tree, record index, increment and advance to next tree_asleep[current] = wakeval; + if (nwoke < 1024) woke_trees[nwoke] = current; nwoke++; current = next; } while (current != i && nwoke < ntree); @@ -228,6 +234,21 @@ int mj_wakeTree(int* tree_asleep, int ntree, int i, int wakeval) { mjERROR("tree %d is not in a cycle", i); return 0; } + +#ifndef MJ_DISABLE_DEBUG_TRACING + if (reason && mju_isTopicEnabled(mjTOPIC_SLEEP)) { + int nprint = mjMIN(nwoke, 1024); + char buf[1024]; + int pos = snprintf(buf, sizeof(buf), "t=%6.3g, woke due to %s tree%s ", time, reason, plural(nprint)); + for (int j = 0; j < nprint; j++) { + pos += snprintf(buf + pos, sizeof(buf) - pos, "%d%s", woke_trees[j], + (j == nprint - 1) ? "" : " "); + } + mjLogMessage msg = {.level = mjLOG_DEBUG, .topic = mjTOPIC_SLEEP, .func = __func__}; + mju_strncpy(msg.subject, buf, sizeof(msg.subject)); + mju_message(&msg); + } +#endif } return nwoke; @@ -260,14 +281,7 @@ int mj_wake(const mjModel* m, mjData* d) { // if qpos mismatch or cannot sleep: wake up if (d->tree_awake[i] || !treeCanSleep(m, d, i, 0)) { - int woke = mj_wakeTree(d->tree_asleep, ntree, i, kAwake); - if (woke) { - nwoke += woke; - - #ifdef MJ_DEBUG_SLEEP - printf("woke tree %d due to perturbation at t=%g\n", i, d->time); - #endif - } + nwoke += mj_wakeIsland(d->tree_asleep, ntree, i, kAwake, "perturbation", d->time); } } @@ -340,11 +354,7 @@ int mj_wakeCollision(const mjModel* m, mjData* d) { // wake sleeping tree int sleeping_tree = awake1 ? tree2 : tree1; int wakeval = awake1 ? d->tree_asleep[tree1] : d->tree_asleep[tree2]; - nwoke += mj_wakeTree(d->tree_asleep, ntree, sleeping_tree, wakeval); - - #ifdef MJ_DEBUG_SLEEP - printf("woke tree %d due to contact at t=%g\n", sleeping_tree, d->time); - #endif + nwoke += mj_wakeIsland(d->tree_asleep, ntree, sleeping_tree, wakeval, "contact", d->time); } return nwoke; @@ -372,11 +382,8 @@ int mj_wakeTendon(const mjModel* m, mjData* d) { if (awake1 != awake2) { int sleeping_tree = awake1 ? tree2 : tree1; int wakeval = awake1 ? d->tree_asleep[tree1] : d->tree_asleep[tree2]; - nwoke += mj_wakeTree(d->tree_asleep, m->ntree, sleeping_tree, wakeval); - - #ifdef MJ_DEBUG_SLEEP - printf("woke tree %d due to tendon constraint at t=%g\n", sleeping_tree, d->time); - #endif + nwoke += mj_wakeIsland(d->tree_asleep, m->ntree, sleeping_tree, wakeval, + "tendon constraint", d->time); } } @@ -455,10 +462,8 @@ int mj_wakeEquality(const mjModel* m, mjData* d) { for (int j = 0; j < num; j++) { int treeid = m->body_treeid[bodyid[adr+j]]; if (treeid >= 0 && !d->tree_awake[treeid]) { - nwoke += mj_wakeTree(d->tree_asleep, m->ntree, treeid, wakeval); - #ifdef MJ_DEBUG_SLEEP - printf("woke tree %d due to flex equality %d at t=%g\n", treeid, i, d->time); - #endif + nwoke += mj_wakeIsland(d->tree_asleep, m->ntree, treeid, wakeval, + "flex equality", d->time); break; } } @@ -494,12 +499,8 @@ int mj_wakeEquality(const mjModel* m, mjData* d) { int cycle1 = mj_sleepCycle(d->tree_asleep, m->ntree, tree1); int cycle2 = mj_sleepCycle(d->tree_asleep, m->ntree, tree2); if (cycle1 != cycle2) { - int nwoke1 = mj_wakeTree(d->tree_asleep, m->ntree, tree1, kAwake); - int nwoke2 = mj_wakeTree(d->tree_asleep, m->ntree, tree2, kAwake); - - #ifdef MJ_DEBUG_SLEEP - printf("woke trees %d, %d due to equality %d at t=%g\n", tree1, tree2, i, d->time); - #endif + int nwoke1 = mj_wakeIsland(d->tree_asleep, m->ntree, tree1, kAwake, "equality", d->time); + int nwoke2 = mj_wakeIsland(d->tree_asleep, m->ntree, tree2, kAwake, "equality", d->time); nwoke += nwoke1 + nwoke2; } @@ -508,11 +509,7 @@ int mj_wakeEquality(const mjModel* m, mjData* d) { // one is asleep and one is awake, wake the sleeping tree int sleeping_tree = s1 == mjS_ASLEEP ? tree1 : tree2; - nwoke += mj_wakeTree(d->tree_asleep, m->ntree, sleeping_tree, kAwake); - - #ifdef MJ_DEBUG_SLEEP - printf("woke tree %d due to equality %d at t=%g\n", sleeping_tree, i, d->time); - #endif + nwoke += mj_wakeIsland(d->tree_asleep, m->ntree, sleeping_tree, kAwake, "equality", d->time); } return nwoke; @@ -522,7 +519,7 @@ int mj_wakeEquality(const mjModel* m, mjData* d) { //-------------------------------- sleep ----------------------------------------------------------- // put n trees to sleep (create cycle), set their velocity and acceleration to zero -static inline void sleepTrees(const mjModel* m, mjData* d, const int* tree, int n) { +static inline void mj_sleepTrees(const mjModel* m, mjData* d, const int* tree, int n) { for (int i=0; i < n; i++) { // create cycle int current = tree[i]; @@ -545,17 +542,18 @@ static inline void sleepTrees(const mjModel* m, mjData* d, const int* tree, int mju_zero(d->qacc+adr, num); } - #ifdef MJ_DEBUG_SLEEP - if (n == 1) { - printf("tree %d put to sleep at t=%g\n", tree[0], d->time); - } else if (n > 1) { - printf("trees "); +#ifndef MJ_DISABLE_DEBUG_TRACING + if (mju_isTopicEnabled(mjTOPIC_SLEEP)) { + char buf[1024]; + int pos = snprintf(buf, sizeof(buf), "t=%6.2g, slept tree%s ", d->time, plural(n)); for (int i = 0; i < n; i++) { - printf("%d%s", tree[i], (i == n - 1) ? "" : ", "); + pos += snprintf(buf + pos, sizeof(buf) - pos, "%d%s", tree[i], (i == n - 1) ? "" : " "); } - printf(" put to sleep at t=%g\n", d->time); + mjLogMessage msg = {.level = mjLOG_DEBUG, .topic = mjTOPIC_SLEEP, .func = __func__}; + mju_strncpy(msg.subject, buf, sizeof(msg.subject)); + mju_message(&msg); } - #endif +#endif } @@ -611,7 +609,7 @@ int mj_sleep(const mjModel* m, mjData* d) { if (can_sleep) { const int* tree = d->map_itree2tree + start; int n = d->island_ntree[i]; - sleepTrees(m, d, tree, n); + mj_sleepTrees(m, d, tree, n); nslept += n; } } @@ -621,7 +619,7 @@ int mj_sleep(const mjModel* m, mjData* d) { for (int j=start; j < ntree; j++) { int i = nisland ? d->map_itree2tree[j] : j; if (d->tree_asleep[i] == -1) { - sleepTrees(m, d, &i, 1); + mj_sleepTrees(m, d, &i, 1); nslept++; } } @@ -853,8 +851,3 @@ mjtSleepState mj_sleepState(const mjModel* m, const mjData* d, mjtObj type, int return mjS_AWAKE; } } - - -#ifdef MJ_DEBUG_SLEEP - #undef MJ_DEBUG_SLEEP -#endif diff --git a/src/engine/engine_sleep.h b/src/engine/engine_sleep.h index 5beb23f0..b3d6dbf7 100644 --- a/src/engine/engine_sleep.h +++ b/src/engine/engine_sleep.h @@ -18,6 +18,7 @@ #include #include #include +#include #ifdef __cplusplus extern "C" { @@ -32,11 +33,9 @@ MJAPI void mj_updateSleep(const mjModel* m, mjData* d); // return the first tree in the sleep cycle that starts at i, -1 if error int mj_sleepCycle(const int* tree_asleep, int ntree, int i); -// return the first tree in the sleep cycle that starts at i, -1 if error -int mj_sleepCycle(const int* tree_asleep, int ntree, int i); - // wake tree i and its related island cycle, return number of woke trees -MJAPI int mj_wakeTree(int* tree_asleep, int ntree, int i, int wakeval); +MJAPI int mj_wakeIsland(int* tree_asleep, int ntree, int i, int wakeval, + const char* reason, mjtNum time); // wake trees with nonzero velocity or external forces, return number of woke trees int mj_wake(const mjModel* m, mjData* d); diff --git a/src/engine/engine_support.c b/src/engine/engine_support.c index 1c1874e6..17fd70e7 100644 --- a/src/engine/engine_support.c +++ b/src/engine/engine_support.c @@ -102,6 +102,14 @@ const char* mjTIMERSTRING[mjNTIMER]= { }; +// names of log topics (index i corresponds to topic i+1) +const char* mjTOPICSTRING[mjNTOPIC] = { + "Step timing", + "Compile timing", + "Sleep/wake" +}; + + // size of contact data fields const int mjCONDATA_SIZE[mjNCONDATA] = { 1, // mjCONDATA_FOUND diff --git a/src/engine/engine_support.h b/src/engine/engine_support.h index 0f447608..700498ab 100644 --- a/src/engine/engine_support.h +++ b/src/engine/engine_support.h @@ -28,6 +28,7 @@ extern "C" { MJAPI extern const char* mjDISABLESTRING[mjNDISABLE]; MJAPI extern const char* mjENABLESTRING[mjNENABLE]; MJAPI extern const char* mjTIMERSTRING[mjNTIMER]; +MJAPI extern const char* mjTOPICSTRING[mjNTOPIC]; // arrays MJAPI extern const int mjCONDATA_SIZE[mjNCONDATA]; // TODO(tassa): expose in public header? diff --git a/src/engine/engine_util_errmem.c b/src/engine/engine_util_errmem.c index 07a6aed0..42768722 100644 --- a/src/engine/engine_util_errmem.c +++ b/src/engine/engine_util_errmem.c @@ -18,17 +18,29 @@ #include #include #include +#include #include #if defined (__unix__) || (defined (__APPLE__) && defined (__MACH__)) #include #endif -#include "engine/engine_array_safety.h" +#include "engine/engine_crossplatform.h" // IWYU pragma: keep #include "engine/engine_macro.h" //------------------------- cross-platform aligned malloc/free ------------------------------------- +// forward declaration for active log handler dispatch +static void mju_defaultLogHandler(const mjLogMessage* msg); + + +//------------------------------ malloc and free --------------------------------------------------- + +// user memory handlers +void* (*mju_user_malloc) (size_t) = 0; +void (*mju_user_free) (void*) = 0; + +// cross-platform aligned malloc static inline void* mju_alignedMalloc(size_t size, size_t align) { #ifdef _WIN32 return _aligned_malloc(size, align); @@ -37,6 +49,7 @@ static inline void* mju_alignedMalloc(size_t size, size_t align) { #endif } +// cross-platform aligned free static inline void mju_alignedFree(void* ptr) { #ifdef _WIN32 _aligned_free(ptr); @@ -45,98 +58,262 @@ static inline void mju_alignedFree(void* ptr) { #endif } +// allocate memory; byte-align on 64; pad size to multiple of 64 +void* mju_malloc(size_t size) { + void* ptr = 0; -//------------------------- default user handlers -------------------------------------------------- + if (mju_user_malloc) { + ptr = mju_user_malloc(size); + } else { + if (size > 0 && (size % 64)) { + size += 64 - (size % 64); + } + if (size > 0) { + ptr = mju_alignedMalloc(size, 64); + } + } -// define and clear handlers + if (!ptr && size > 0) { + mju_error("Could not allocate memory"); + } + return ptr; +} + +// free memory +void mju_free(void* ptr) { + if (!ptr) return; + if (mju_user_free) { + mju_user_free(ptr); + } else { + mju_alignedFree(ptr); + } +} + + +//------------------------------ logging configuration and handlers -------------------------------- + +// global log handler +static mjfLogHandler global_log_handler = mju_defaultLogHandler; + +// legacy error/warning handlers (deprecated) void (*mju_user_error) (const char*) = 0; void (*mju_user_warning) (const char*) = 0; -void* (*mju_user_malloc) (size_t) = 0; -void (*mju_user_free) (void*) = 0; +// default handler configuration +static mjLogConfig log_config = {.logto_console = true, + .logto_file = true, + .logfile = "MUJOCO_LOG.TXT", + .topics = 0}; +static mjtBool env_checked = 0; + +// parse MUJOCO_LOG_TOPICS env var to seed initial topic bitmask +// example: MUJOCO_LOG_TOPICS="time_stp,sleep" +static void mju_initLogTopicsFromEnv(void) { + const char* env = getenv("MUJOCO_LOG_TOPICS"); + if (!env) return; + + // mjTOPIC_X enum names with the mjTOPIC_ prefix stripped and lowercased; keep in sync with mjtLogTopic + static const char* topic_names[mjNTOPIC] = {"time_stp", "time_cmp", "sleep"}; + char buf[256]; + strncpy(buf, env, sizeof(buf) - 1); + buf[sizeof(buf) - 1] = '\0'; + + char* token = buf; + while (*token) { + while (*token == ' ' || *token == ',') token++; + if (!*token) break; + + char* end = token; + while (*end && *end != ',') end++; + bool trailing_comma = (*end == ','); + + char* tEnd = end - 1; + while (tEnd > token && *tEnd == ' ') tEnd--; + *(tEnd + 1) = '\0'; + + for (int i = 0; i < mjNTOPIC; i++) { + if (strcasecmp(token, topic_names[i]) == 0) { + log_config.topics |= (1 << i); + break; + } + } + token = trailing_comma ? end + 1 : end; + } +} + +// private pointer getter encapsulates lazy init with zero copy overhead +static const mjLogConfig* mju_getLogConfigPtr(void) { + if (!env_checked) { + mju_initLogTopicsFromEnv(); + env_checked = 1; + } + return &log_config; +} + +// check whether an info topic is enabled +mjtBool mju_isTopicEnabled(int topic) { + if (!topic) return 1; + const mjLogConfig* cfg = mju_getLogConfigPtr(); + return ((cfg->topics & (1 << (topic - 1))) != 0); +} + +// set the active log handler; return the previous handler +mjfLogHandler mju_setLogHandler(mjfLogHandler handler) { + mjfLogHandler prev = global_log_handler; + global_log_handler = handler ? handler : mju_defaultLogHandler; + return prev; +} + +// get default handler configuration +mjLogConfig mju_getLogConfig(void) { + return *mju_getLogConfigPtr(); +} + +// set default handler configuration +void mju_setLogConfig(mjLogConfig config) { + env_checked = 1; + log_config = config; +} // restore default processing void mju_clearHandlers(void) { + global_log_handler = mju_defaultLogHandler; + log_config = (mjLogConfig){.logto_console = true, + .logto_file = true, + .logfile = "MUJOCO_LOG.TXT", + .topics = 0}; + env_checked = 1; + mju_initLogTopicsFromEnv(); + mju_user_error = 0; mju_user_warning = 0; mju_user_malloc = 0; mju_user_free = 0; } -//------------------------- internal-only handlers ------------------------------------------------- - -typedef void (*callback_fn)(const char*); - -static mjTHREADLOCAL callback_fn _mjPRIVATE_tls_error_fn = NULL; -static mjTHREADLOCAL callback_fn _mjPRIVATE_tls_warning_fn = NULL; - -callback_fn _mjPRIVATE__get_tls_error_fn(void) { - return _mjPRIVATE_tls_error_fn; -} - -void _mjPRIVATE__set_tls_error_fn(callback_fn h) { - _mjPRIVATE_tls_error_fn = h; -} - -callback_fn _mjPRIVATE__get_tls_warning_fn(void) { - return _mjPRIVATE_tls_warning_fn; -} - -void _mjPRIVATE__set_tls_warning_fn(callback_fn h) { - _mjPRIVATE_tls_warning_fn = h; -} - -//------------------------------ error hadling ----------------------------------------------------- - -// write datetime, type: message to MUJOCO_LOG.TXT -void mju_writeLog(const char* type, const char* msg) { +// fill buffer with formatted local time string (thread-safe) +static void mju_localTimeStr(char* buf, int buf_sz) { time_t rawtime; struct tm timeinfo; - FILE* fp = fopen("MUJOCO_LOG.TXT", "a+t"); - if (fp) { - // get time - time(&rawtime); + time(&rawtime); #if defined(_POSIX_C_SOURCE) || defined(__APPLE__) || defined(__STDC_VERSION_TIME_H__) || defined(__EMSCRIPTEN__) - localtime_r(&rawtime, &timeinfo); + localtime_r(&rawtime, &timeinfo); #elif defined(_WIN32) - localtime_s(&timeinfo, &rawtime); + localtime_s(&timeinfo, &rawtime); #elif __STDC_LIB_EXT1__ - localtime_s(&rawtime, &timeinfo); + localtime_s(&rawtime, &timeinfo); #else - #error "Thread-safe version of `localtime` is not present in the standard C library" + #error "Thread-safe version of `localtime` is not present in the standard C library" #endif - // write to log file - fprintf(fp, "%s%s: %s\n\n", asctime(&timeinfo), type, msg); - fclose(fp); - } + strftime(buf, buf_sz, "%c", &timeinfo); } +// write formatted message to stream +static void mju_fprint_message(FILE* stream, const char* timestr, + const mjLogMessage* msg) { + const char* type = msg->level == mjLOG_ERROR ? "ERROR" : + msg->level == mjLOG_WARNING ? "WARNING" : + msg->level == mjLOG_INFO ? "INFO" : "DEBUG"; + fprintf(stream, "%s", type); + if (msg->func) fprintf(stream, " %s", msg->func); + if (msg->file && msg->line) fprintf(stream, " (%s:%d)", BaseName(msg->file), msg->line); + if (timestr[0]) fprintf(stream, " %s", timestr); + fprintf(stream, ": %s\n", msg->subject); + if (msg->body) fprintf(stream, "%s\n", msg->body); -void mju_error_raw(const char* msg) { - if (_mjPRIVATE_tls_error_fn) { - _mjPRIVATE_tls_error_fn(msg); - } else if (mju_user_error) { - mju_user_error(msg); - } else { - // write to log and console - mju_writeLog("ERROR", msg); - printf("ERROR: %s\n\n", msg); + // add blank line after message except for DEBUG, for compactness + if (msg->level != mjLOG_DEBUG) fprintf(stream, "\n"); +} - // exit +// format legacy adapter string: "func: subject" or just "subject" +static const char* mju_legacy_text(const mjLogMessage* msg, char* buf, int bufsz) { + if (msg->func) { + snprintf(buf, bufsz, "%s: %s", msg->func, msg->subject); + return buf; + } + return msg->subject; +} + +// default log handler: topic filtering, console/file output, legacy compat, exit on error +static void mju_defaultLogHandler(const mjLogMessage* msg) { + const mjLogConfig* cfg = mju_getLogConfigPtr(); + + if ((msg->level == mjLOG_INFO || msg->level == mjLOG_DEBUG) && !mju_isTopicEnabled(msg->topic)) { + return; + } + + if (msg->level == mjLOG_ERROR && mju_user_error) { + char buf[1024]; + mju_user_error(mju_legacy_text(msg, buf, sizeof(buf))); + return; + } + + if (msg->level == mjLOG_WARNING && mju_user_warning) { + char buf[1024]; + mju_user_warning(mju_legacy_text(msg, buf, sizeof(buf))); + return; + } + + char timestr[64] = ""; + if (msg->timestamp || (cfg->logto_file && cfg->logfile[0])) { + mju_localTimeStr(timestr, sizeof(timestr)); + } + + if (cfg->logto_file && cfg->logfile[0]) { + FILE* fp = fopen(cfg->logfile, "a+t"); + if (fp) { + mju_fprint_message(fp, timestr, msg); + fclose(fp); + } + } + + if (cfg->logto_console) { + FILE* stream = (msg->level >= mjLOG_WARNING) ? stderr : stdout; + mju_fprint_message(stream, msg->timestamp ? timestr : "", msg); + } + + if (msg->level == mjLOG_ERROR) { exit(EXIT_FAILURE); } } -void mju_error_v(const char* msg, va_list args) { - // Format msg into errmsg - char errmsg[1024]; - vsnprintf(errmsg, mjSIZEOFARRAY(errmsg), msg, args); - mju_error_raw(errmsg); +//------------------------------ public message logging -------------------------------------------- + +// thread-local log handler override +static mjTHREADLOCAL mjfLogHandler _mjPRIVATE_tls_log_handler = NULL; + +// recursion guard for log handler +static mjTHREADLOCAL bool in_log = false; + +// dispatch to active handler (TLS > global) +static inline mjfLogHandler mju_activeHandler(void) { + return _mjPRIVATE_tls_log_handler ? _mjPRIVATE_tls_log_handler : global_log_handler; } +// dispatch a structured log message to the active handler +void mju_message(const mjLogMessage* msg) { + // recursion guard: silently drop messages dispatched from within a handler + if (in_log) return; + + // error handlers are expected to not return (longjmp or exit); we cannot set in_log + // around the call because longjmp would leave it permanently true on this thread + if (msg->level != mjLOG_ERROR) { + in_log = true; + mju_activeHandler()(msg); + in_log = false; + } else { + mju_activeHandler()(msg); + } +} + +void mju_error_v(const char* msg, va_list args) { + mjLogMessage m = {.level = mjLOG_ERROR}; + vsnprintf(m.subject, sizeof(m.subject), msg, args); + mju_message(&m); +} // write message to logfile and console, pause and exit void mju_error(const char* msg, ...) { @@ -146,73 +323,50 @@ void mju_error(const char* msg, ...) { va_end(args); } - // write message to logfile and console void mju_warning(const char* msg, ...) { - char wrnmsg[1024]; - - // Format msg into wrnmsg + mjLogMessage m = {.level = mjLOG_WARNING}; va_list args; va_start(args, msg); - vsnprintf(wrnmsg, mjSIZEOFARRAY(wrnmsg), msg, args); + vsnprintf(m.subject, sizeof(m.subject), msg, args); va_end(args); + mju_message(&m); +} - if (_mjPRIVATE_tls_warning_fn) { - _mjPRIVATE_tls_warning_fn(wrnmsg); - } else if (mju_user_warning) { - mju_user_warning(wrnmsg); - } else { - // write to log file and console - mju_writeLog("WARNING", wrnmsg); - printf("WARNING: %s\n\n", wrnmsg); +// log an info message +void mju_info(int topic, const char* msg, ...) { + mjLogMessage m = {.level = mjLOG_INFO, .topic = topic}; + va_list args; + va_start(args, msg); + vsnprintf(m.subject, sizeof(m.subject), msg, args); + va_end(args); + mju_message(&m); +} + +// (deprecated) write datetime, type: message to MUJOCO_LOG.TXT +void mju_writeLog(const char* type, const char* msg) { + char timestr[64]; + mju_localTimeStr(timestr, sizeof(timestr)); + + FILE* fp = fopen("MUJOCO_LOG.TXT", "a+t"); + if (fp) { + fprintf(fp, "%s\n%s: %s\n\n", timestr, type, msg); + fclose(fp); } } -//------------------------------ malloc and free --------------------------------------------------- +//------------------------------ internal helpers -------------------------------------------------- -// allocate memory; byte-align on 64; pad size to multiple of 64 -void* mju_malloc(size_t size) { - void* ptr = 0; - - // user allocator - if (mju_user_malloc) { - ptr = mju_user_malloc(size); - } - - // default allocator - else { - // pad size to multiple of 64 - if (size > 0 && (size % 64)) { - size += 64 - (size % 64); - } - - // allocate - if (size > 0) { - ptr = mju_alignedMalloc(size, 64); - } - } - - // error if null pointer - if (!ptr && size > 0) { - mju_error("Could not allocate memory"); - } - - return ptr; +// set thread-local log handler; return previous +mjfLogHandler _mjPRIVATE_setTlsLogHandler(mjfLogHandler handler) { + mjfLogHandler prev = _mjPRIVATE_tls_log_handler; + _mjPRIVATE_tls_log_handler = handler; + return prev; } -// free memory -void mju_free(void* ptr) { - // return if null - if (!ptr) { - return; - } - - // free with user or built-in function - if (mju_user_free) { - mju_user_free(ptr); - } else { - mju_alignedFree(ptr); - } +// get the currently active global log handler (read-only, no modification) +mjfLogHandler _mjPRIVATE_getGlobalLogHandler(void) { + return global_log_handler; } diff --git a/src/engine/engine_util_errmem.h b/src/engine/engine_util_errmem.h index a1b791d2..3a1a623b 100644 --- a/src/engine/engine_util_errmem.h +++ b/src/engine/engine_util_errmem.h @@ -22,6 +22,7 @@ #include #include +#include #ifdef __cplusplus extern "C" { @@ -36,48 +37,6 @@ extern "C" { #endif // mjPRINTFLIKE -//------------------------------ user handlers ----------------------------------------------------- - -MJAPI extern void (*mju_user_error)(const char*); -MJAPI extern void (*mju_user_warning)(const char*); -MJAPI extern void* (*mju_user_malloc)(size_t); -MJAPI extern void (*mju_user_free)(void*); - -// clear user handlers; restore default processing -MJAPI void mju_clearHandlers(void); - -// gets/sets thread-local error/warning handlers for internal use -MJAPI void (*_mjPRIVATE__get_tls_error_fn(void))(const char*); -MJAPI void _mjPRIVATE__set_tls_error_fn(void (*h)(const char*)); -MJAPI void (*_mjPRIVATE__get_tls_warning_fn(void))(const char*); -MJAPI void _mjPRIVATE__set_tls_warning_fn(void (*h)(const char*)); - -//------------------------------ errors and warnings ----------------------------------------------- - -// errors -MJAPI void mju_error_raw(const char* msg); -MJAPI void mju_error(const char* msg, ...) mjPRINTFLIKE(1, 2); -MJAPI void mju_error_v(const char* msg, va_list args); - -// warnings -MJAPI void mju_warning(const char* msg, ...) mjPRINTFLIKE(1, 2); - -// write [datetime, type: message] to MUJOCO_LOG.TXT -MJAPI void mju_writeLog(const char* type, const char* msg); - -//------------------------------ internal error macros -------------------------------------------- - -// internal macro to prepend the calling function name to the error message -#pragma warning(disable : 4996) // needed to use strncpy with Visual Studio -#define mjERROR(...) \ -{ \ - char _errbuf[1024]; \ - size_t _funclen = strlen(__func__); \ - strncpy(_errbuf, __func__, sizeof(_errbuf)); \ - snprintf(_errbuf + _funclen, sizeof(_errbuf) - _funclen, ": " __VA_ARGS__); \ - mju_error_raw(_errbuf); \ -} - //------------------------------ malloc and free --------------------------------------------------- // allocate memory; byte-align on 8; pad size to multiple of 8 @@ -86,6 +45,94 @@ MJAPI void* mju_malloc(size_t size); // free memory with free() by default MJAPI void mju_free(void* ptr); +// user memory handlers +MJAPI extern void* (*mju_user_malloc)(size_t); +MJAPI extern void (*mju_user_free)(void*); + + +//------------------------------ logging configuration and handlers -------------------------------- + +// set the active log handler, return the previous handler +// if handler is NULL, restore the default handler +MJAPI mjfLogHandler mju_setLogHandler(mjfLogHandler handler); + +// set/get default handler configuration +MJAPI mjLogConfig mju_getLogConfig(void); +MJAPI void mju_setLogConfig(mjLogConfig config); + +// clear user handlers; restore default processing +MJAPI void mju_clearHandlers(void); + +// legacy error/warning handlers (deprecated: prefer mju_setLogHandler) +MJAPI extern void (*mju_user_error)(const char*); +MJAPI extern void (*mju_user_warning)(const char*); + + +//------------------------------ public message logging -------------------------------------------- + +// log a fatal error message, write to logfile and console, pause and exit +MJAPI void mju_error(const char* msg, ...) mjPRINTFLIKE(1, 2); +MJAPI void mju_error_v(const char* msg, va_list args); + +// log a warning message, write to logfile and console +MJAPI void mju_warning(const char* msg, ...) mjPRINTFLIKE(1, 2); + +// log an info message with optional topic filtering +MJAPI void mju_info(int topic, const char* msg, ...) mjPRINTFLIKE(2, 3); + +// dispatch a structured log message to the active handler +MJAPI void mju_message(const mjLogMessage* msg); + +// (deprecated) write [datetime, type: message] to MUJOCO_LOG.TXT +MJAPI void mju_writeLog(const char* type, const char* msg); + + +//------------------------------ internal helpers and macros --------------------------------------- + +// set thread-local log handler; return previous thread-local handler +MJAPI mjfLogHandler _mjPRIVATE_setTlsLogHandler(mjfLogHandler handler); + +// get the currently active global log handler (read-only, no modification) +MJAPI mjfLogHandler _mjPRIVATE_getGlobalLogHandler(void); + +// check whether an info topic is enabled +MJAPI mjtBool mju_isTopicEnabled(int topic); + +// strip directory from __FILE__ (cross-platform) +static inline const char* BaseName(const char* path) { + const char* slash = strrchr(path, '/'); + const char* bslash = strrchr(path, '\\'); + if (slash && bslash) return (slash > bslash ? slash : bslash) + 1; + if (slash) return slash + 1; + if (bslash) return bslash + 1; + return path; +} + +// internal macro to emit a structured error with source location +#define mjERROR(...) \ + { \ + mjLogMessage _msg = {.level = mjLOG_ERROR, \ + .func = __func__, \ + .file = __FILE__, \ + .line = __LINE__}; \ + snprintf(_msg.subject, sizeof(_msg.subject), __VA_ARGS__); \ + mju_message(&_msg); \ + } + +// internal macro to emit a structured debug trace with fast producer-side topic filtering +#ifndef MJ_DISABLE_DEBUG_TRACING +#define mjDEBUG(_topic, ...) \ + if (mju_isTopicEnabled(_topic)) { \ + mjLogMessage _msg = {.level = mjLOG_DEBUG, \ + .topic = _topic, \ + .func = __func__}; \ + snprintf(_msg.subject, sizeof(_msg.subject), __VA_ARGS__); \ + mju_message(&_msg); \ + } +#else +#define mjDEBUG(_topic, ...) ((void)0) +#endif + #ifdef __cplusplus } #endif diff --git a/src/user/user_api.cc b/src/user/user_api.cc index 0f657ff9..3c7f4580 100644 --- a/src/user/user_api.cc +++ b/src/user/user_api.cc @@ -32,6 +32,7 @@ #include #include "engine/engine_support.h" +#include "engine/engine_util_errmem.h" #include "user/user_cache.h" #include "user/user_flexcomp.h" #include "user/user_model.h" @@ -204,10 +205,53 @@ int mj_encode(const mjSpec* s, const mjModel* m, const char* filename, return nbytes; } +// helper function to log compile time diagnostics +static void LogCompileTime(const double* t) { + std::string body(1024, '\0'); + int n = std::snprintf(body.data(), body.size(), + " total: %8.1f (wall clock)\n" + " assets: %8.1f -\n" + " load: %8.1f (CPU time)\n" + " hull: %8.1f -\n" + " polygon: %8.1f -\n" + " inertia: %8.1f -\n" + " bvh: %8.1f -\n" + " octree: %8.1f -\n" + " texture: %8.1f -\n" + " other: %8.1f (wall clock)", + 1e3 * t[mjCTIMER_TOTAL], + 1e3 * t[mjCTIMER_ASSETS], + 1e3 * t[mjCTIMER_MESH_LOAD], + 1e3 * t[mjCTIMER_MESH_HULL], + 1e3 * t[mjCTIMER_MESH_POLYGON], + 1e3 * t[mjCTIMER_MESH_INERTIA], + 1e3 * t[mjCTIMER_MESH_BVH], + 1e3 * t[mjCTIMER_MESH_OCTREE], + 1e3 * t[mjCTIMER_TEXTURE], + 1e3 * (t[mjCTIMER_TOTAL] - t[mjCTIMER_ASSETS])); + if (n > 0 && n < body.size()) { + body.resize(n); + } + + // send log message + mjLogMessage msg = {.level = mjLOG_INFO, + .topic = mjTOPIC_TIME_CMP, + .subject = "compile time (ms)", + .body = body.c_str()}; + mju_message(&msg); +} + // compile model mjModel* mj_compile(mjSpec* s, const mjVFS* vfs) { mjCModel* modelC = static_cast(s->element); - return modelC->Compile(vfs); + mjModel* m = modelC->Compile(vfs); + + // log compile time if model was compiled successfully + if (m) { + LogCompileTime(modelC->timer); + } + + return m; } diff --git a/src/user/user_model.cc b/src/user/user_model.cc index b42b6282..f10cd4fd 100644 --- a/src/user/user_model.cc +++ b/src/user/user_model.cc @@ -4623,20 +4623,21 @@ void mjCModel::CheckRepeat(mjtObj type) { constexpr int kErrorBufferSize = 500; static thread_local std::jmp_buf error_jmp_buf; static thread_local char errortext[kErrorBufferSize] = ""; -static void errorhandler(const char* msg) { - mju::strcpy_arr(errortext, msg); - std::longjmp(error_jmp_buf, 1); -} // warning handler for low-level engine static thread_local char warningtext[kErrorBufferSize] = ""; // top-level warning buffer static thread_local std::string* local_warningtext_ptr = nullptr; // sub-thread warning buffer -static void warninghandler(const char* msg) { - if (local_warningtext_ptr) { - *local_warningtext_ptr = msg; - } else { - mju::strcpy_arr(warningtext, msg); +static void compilerLogHandler(const mjLogMessage* msg) { + if (msg->level == mjLOG_ERROR) { + mju::strcpy_arr(errortext, msg->subject); + std::longjmp(error_jmp_buf, 1); + } else if (msg->level == mjLOG_WARNING) { + if (local_warningtext_ptr) { + *local_warningtext_ptr = msg->subject; + } else { + mju::strcpy_arr(warningtext, msg->subject); + } } } @@ -4660,13 +4661,8 @@ mjModel* mjCModel::Compile(const mjVFS* vfs, mjModel** m) { mjModel* volatile model = (m && *m) ? *m : nullptr; mjData* volatile data = nullptr; - // save error and warning handlers - void (*save_error)(const char*) = _mjPRIVATE__get_tls_error_fn(); - void (*save_warning)(const char*) = _mjPRIVATE__get_tls_warning_fn(); - - // install error and warning handlers, clear error and warning - _mjPRIVATE__set_tls_error_fn(errorhandler); - _mjPRIVATE__set_tls_warning_fn(warninghandler); + // save log handler + mjfLogHandler save_handler = _mjPRIVATE_setTlsLogHandler(compilerLogHandler); errInfo = mjCError(); warningtext[0] = 0; @@ -4705,14 +4701,12 @@ mjModel* mjCModel::Compile(const mjVFS* vfs, mjModel** m) { } // restore handler, return 0 - _mjPRIVATE__set_tls_error_fn(save_error); - _mjPRIVATE__set_tls_warning_fn(save_warning); + _mjPRIVATE_setTlsLogHandler(save_handler); return nullptr; } - // restore error handler, mark as compiled, return mjModel - _mjPRIVATE__set_tls_error_fn(save_error); - _mjPRIVATE__set_tls_warning_fn(save_warning); + // restore log handler, mark as compiled, return mjModel + _mjPRIVATE_setTlsLogHandler(save_handler); compiled = true; return model; } @@ -4723,8 +4717,7 @@ static void CompileMesh(mjCMesh* mesh, const mjVFS* vfs, std::exception_ptr& exception, std::mutex& exception_mutex, std::string* warningtext) { local_warningtext_ptr = warningtext; - auto previous_handler = _mjPRIVATE__get_tls_warning_fn(); - _mjPRIVATE__set_tls_warning_fn(warninghandler); + auto previous_handler = _mjPRIVATE_setTlsLogHandler(compilerLogHandler); try { mesh->Compile(vfs); @@ -4735,7 +4728,7 @@ static void CompileMesh(mjCMesh* mesh, const mjVFS* vfs, } } - _mjPRIVATE__set_tls_warning_fn(previous_handler); + _mjPRIVATE_setTlsLogHandler(previous_handler); local_warningtext_ptr = nullptr; } @@ -4746,8 +4739,7 @@ static void CompileTexture(mjCTexture* texture, const mjVFS* vfs, using Clock = std::chrono::steady_clock; using Seconds = std::chrono::duration; local_warningtext_ptr = warningtext; - auto previous_handler = _mjPRIVATE__get_tls_warning_fn(); - _mjPRIVATE__set_tls_warning_fn(warninghandler); + auto previous_handler = _mjPRIVATE_setTlsLogHandler(compilerLogHandler); Clock::time_point t0 = Clock::now(); try { @@ -4760,7 +4752,7 @@ static void CompileTexture(mjCTexture* texture, const mjVFS* vfs, } texture->texture_time_ = Seconds(Clock::now() - t0).count(); - _mjPRIVATE__set_tls_warning_fn(previous_handler); + _mjPRIVATE_setTlsLogHandler(previous_handler); local_warningtext_ptr = nullptr; } @@ -4822,7 +4814,7 @@ void mjCModel::CompileMeshesAndTextures(const mjVFS* vfs) { for (int i = 0; i < nmesh; i++) { if (!mesh_warningtext[i].empty()) { if (has_warning) { - concatenated_warnings += "\n"; + concatenated_warnings += '\n'; } concatenated_warnings += mesh_warningtext[i]; has_warning = true; diff --git a/test/engine/engine_sleep_test.cc b/test/engine/engine_sleep_test.cc index f8b2e9c1..6cce34e0 100644 --- a/test/engine/engine_sleep_test.cc +++ b/test/engine/engine_sleep_test.cc @@ -185,38 +185,38 @@ TEST_F(SleepTest, MjSleepUpdate) { mj_deleteModel(m); } -TEST_F(SleepTest, MjWakeTree) { +TEST_F(SleepTest, MjWakeIsland) { // one awake tree and two cycles int asleep[] = {kAwake, 2, 1, 3}; - EXPECT_EQ(mj_wakeTree(asleep, 4, 0, kAwake), 0); + EXPECT_EQ(mj_wakeIsland(asleep, 4, 0, kAwake, nullptr, 0), 0); EXPECT_THAT(AsVector(asleep, 4), ElementsAre(kAwake, 2, 1, 3)); - EXPECT_EQ(mj_wakeTree(asleep, 4, 1, kAwake), 2); + EXPECT_EQ(mj_wakeIsland(asleep, 4, 1, kAwake, nullptr, 0), 2); EXPECT_THAT(AsVector(asleep, 4), ElementsAre(kAwake, kAwake, kAwake, 3)); - EXPECT_EQ(mj_wakeTree(asleep, 4, 3, kAwake), 1); + EXPECT_EQ(mj_wakeIsland(asleep, 4, 3, kAwake, nullptr, 0), 1); EXPECT_THAT(AsVector(asleep, 4), ElementsAre(kAwake, kAwake, kAwake, kAwake)); } -TEST_F(SleepTest, BadWakeTree) { +TEST_F(SleepTest, BadWakeIsland) { EXPECT_FATAL_FAILURE( ([] { int asleep_bad1[] = {-1, 0}; - mj_wakeTree(asleep_bad1, 2, 1, kAwake); + mj_wakeIsland(asleep_bad1, 2, 1, kAwake, nullptr, 0); }()), "invalid sleep state index -1 when waking tree 1"); EXPECT_FATAL_FAILURE( ([] { int asleep_bad2[] = {-1, 2}; - mj_wakeTree(asleep_bad2, 2, 1, kAwake); + mj_wakeIsland(asleep_bad2, 2, 1, kAwake, nullptr, 0); }()), "invalid sleep state index 2 when waking tree 1"); EXPECT_FATAL_FAILURE( ([] { int asleep_bad3[] = {1, 2, 1}; - mj_wakeTree(asleep_bad3, 3, 0, kAwake); + mj_wakeIsland(asleep_bad3, 3, 0, kAwake, nullptr, 0); }()), "tree 0 is not in a cycle"); } diff --git a/test/engine/engine_util_errmem_test.cc b/test/engine/engine_util_errmem_test.cc index 41754952..34b687b7 100644 --- a/test/engine/engine_util_errmem_test.cc +++ b/test/engine/engine_util_errmem_test.cc @@ -14,66 +14,603 @@ // Tests for engine/engine_util_errmem.c. +#include +#include #include #include +#include #include +#include +#include "src/engine/engine_crossplatform.h" // IWYU pragma: keep #include "src/engine/engine_util_errmem.h" +extern "C" { +MJAPI mjfLogHandler _mjPRIVATE_setTlsLogHandler(mjfLogHandler handler); +} + namespace mujoco { namespace { -constexpr int kBufferSize = 1024; +// ========================= test infrastructure ============================== -char* ErrorMessageBuffer() { - static char error_message[kBufferSize] = ""; - return error_message; -} - -char* WarningMessageBuffer() { - static char warning_message[kBufferSize] = ""; - return warning_message; -} - -void MjErrorHandler(const char* msg) { - if (strnlen(msg, kBufferSize) == kBufferSize) { - FAIL() << "mju_user_error message exceeds maximum length of " - << kBufferSize; - } - strncpy(ErrorMessageBuffer(), msg, kBufferSize); -} - -void MjWarningHandler(const char* msg) { - if (strnlen(msg, kBufferSize) == kBufferSize) { - FAIL() << "mju_user_warning message exceeds maximum length of " - << kBufferSize; - } - strncpy(WarningMessageBuffer(), msg, kBufferSize); -} - -void ClearErrorMessage() { ErrorMessageBuffer()[0] = '\0'; } - -void ClearWarningMessage() { WarningMessageBuffer()[0] = '\0'; } - -class MujocoErrorAndWarningTest : public ::testing::Test { - public: - MujocoErrorAndWarningTest() { - mju_user_error = MjErrorHandler; - mju_user_warning = MjWarningHandler; - } - - ~MujocoErrorAndWarningTest() { - mju_user_error = nullptr; - mju_user_warning = nullptr; - } +// captured log message +struct CapturedMsg { + int level; + int topic; + std::string subject; + std::string func; + std::string file; + int line; + std::string body; }; -TEST_F(MujocoErrorAndWarningTest, MjuErrorInternal) { - ClearErrorMessage(); - mjERROR("foobar %d", 123); - std::string funcname(__func__); - ASSERT_TRUE(funcname.length()); - EXPECT_EQ(std::string(ErrorMessageBuffer()), funcname + ": foobar 123"); +// thread-local capture state +static thread_local std::vector captured_msgs; +static thread_local bool capture_longjmp = false; +static thread_local std::jmp_buf capture_jmp_buf; + +// log handler that captures messages +void CapturingHandler(const mjLogMessage* msg) { + captured_msgs.push_back({ + .level = msg->level, + .topic = msg->topic, + .subject = msg->subject, + .func = msg->func ? msg->func : "", + .file = msg->file ? msg->file : "", + .line = msg->line, + .body = msg->body ? msg->body : "", + }); + // longjmp on error to prevent exit() + if (msg->level == mjLOG_ERROR && capture_longjmp) { + std::longjmp(capture_jmp_buf, 1); + } +} + +// RAII guard: installs capturing handler, restores previous on destruction +class ScopedCapture { + public: + ScopedCapture() { + captured_msgs.clear(); + capture_longjmp = true; + prev_ = _mjPRIVATE_setTlsLogHandler(CapturingHandler); + } + ~ScopedCapture() { + _mjPRIVATE_setTlsLogHandler(prev_); + capture_longjmp = false; + } + const std::vector& msgs() const { return captured_msgs; } + + private: + mjfLogHandler prev_; +}; + +// ========================= mju_setLogHandler tests ========================== + +TEST(LogHandlerTest, SetLogHandlerReturnsOldHandler) { + mjfLogHandler old = mju_setLogHandler(CapturingHandler); + EXPECT_NE(old, nullptr); // default handler is non-null + + mjfLogHandler prev = mju_setLogHandler(nullptr); + EXPECT_EQ(prev, CapturingHandler); + + // NULL restores default (non-null) + mjfLogHandler restored = mju_setLogHandler(nullptr); + EXPECT_NE(restored, nullptr); +} + +TEST(LogHandlerTest, CustomHandlerReceivesWarning) { + ScopedCapture cap; + mju_warning("test warning %d", 42); + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_WARNING); + EXPECT_EQ(cap.msgs()[0].subject, "test warning 42"); +} + +TEST(LogHandlerTest, CustomHandlerReceivesError) { + ScopedCapture cap; + if (setjmp(capture_jmp_buf) == 0) { + mju_error("test error %s", "foo"); + } + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_ERROR); + EXPECT_EQ(cap.msgs()[0].subject, "test error foo"); +} + +TEST(LogHandlerTest, WarningRecursionGuard) { + static thread_local int call_count = 0; + call_count = 0; + auto recursive_handler = +[](const mjLogMessage* msg) { + call_count++; + mju_warning("recursive warning"); + }; + + auto old_tls = _mjPRIVATE_setTlsLogHandler(recursive_handler); + mju_warning("initial warning"); + _mjPRIVATE_setTlsLogHandler(old_tls); + + EXPECT_EQ(call_count, 1); +} + + +// ========================= TLS handler override tests ======================= + +TEST(TlsHandlerTest, TlsOverridesGlobal) { + // install a global handler + auto global_prev = mju_setLogHandler(CapturingHandler); + + // install a different TLS handler + static thread_local bool tls_called = false; + auto tls_handler = +[](const mjLogMessage* msg) { + tls_called = true; + if (msg->level == mjLOG_ERROR) { + std::longjmp(capture_jmp_buf, 1); + } + }; + + tls_called = false; + captured_msgs.clear(); + auto old_tls = _mjPRIVATE_setTlsLogHandler(tls_handler); + + if (setjmp(capture_jmp_buf) == 0) { + mju_error("tls test"); + } + + // TLS handler should have been called, not the global one + EXPECT_TRUE(tls_called); + EXPECT_EQ(captured_msgs.size(), 0); + + _mjPRIVATE_setTlsLogHandler(old_tls); + mju_setLogHandler(global_prev); +} + +TEST(TlsHandlerTest, NullTlsFallsBackToGlobal) { + auto global_prev = mju_setLogHandler(CapturingHandler); + captured_msgs.clear(); + + // ensure TLS is null + auto old_tls = _mjPRIVATE_setTlsLogHandler(nullptr); + + mju_warning("fallback test"); + + // global capturing handler should have been called + ASSERT_EQ(captured_msgs.size(), 1); + EXPECT_EQ(captured_msgs[0].subject, "fallback test"); + + _mjPRIVATE_setTlsLogHandler(old_tls); + mju_setLogHandler(global_prev); +} + +TEST(TlsHandlerTest, SetTlsReturnsPrevious) { + auto h1 = _mjPRIVATE_setTlsLogHandler(CapturingHandler); + auto h2 = _mjPRIVATE_setTlsLogHandler(nullptr); + EXPECT_EQ(h2, CapturingHandler); + _mjPRIVATE_setTlsLogHandler(h1); +} + +// ========================= mju_info and topic filtering ===================== + +TEST(InfoTest, InfoMessageReachesHandler) { + ScopedCapture cap; + mju_info(mjTOPIC_NONE, "info message %d", 7); + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_INFO); + EXPECT_EQ(cap.msgs()[0].topic, mjTOPIC_NONE); + EXPECT_EQ(cap.msgs()[0].subject, "info message 7"); +} + +TEST(InfoTest, TopicZeroAlwaysPasses) { + // topic 0 (NONE) should pass regardless of config + ScopedCapture cap; + mju_info(mjTOPIC_NONE, "always passes"); + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].subject, "always passes"); +} + +// ========================= mjLogConfig tests ================================ + +TEST(LogConfigTest, GetSetRoundtrip) { + mjLogConfig orig = mju_getLogConfig(); + + mjLogConfig custom = {.logto_console = false, + .logto_file = false, + .logfile = "", + .topics = (1 << 0) | (1 << 1)}; + mju_setLogConfig(custom); + + mjLogConfig readback = mju_getLogConfig(); + EXPECT_EQ(readback.logto_console, false); + EXPECT_EQ(readback.logto_file, false); + EXPECT_STREQ(readback.logfile, ""); + EXPECT_EQ(readback.topics, (1 << 0) | (1 << 1)); + + // restore + mju_setLogConfig(orig); +} + +TEST(LogConfigTest, InitFromEnv) { + mjLogConfig orig = mju_getLogConfig(); + + setenv("MUJOCO_LOG_TOPICS", "sleep,time_cmp", 1); + mju_clearHandlers(); + + mjLogConfig config = mju_getLogConfig(); + EXPECT_EQ(config.topics, (1 << 1) | (1 << 2)); + + unsetenv("MUJOCO_LOG_TOPICS"); + mju_clearHandlers(); + mju_setLogConfig(orig); +} + +// ========================= topic filtering in default handler =============== + +TEST(TopicFilterTest, DefaultHandlerFiltersDisabledTopic) { + // save and configure: disable all topics, route to capture + mjLogConfig orig = mju_getLogConfig(); + mjLogConfig no_topics = { + .logto_console = false, .logto_file = false, .logfile = "", .topics = 0}; + mju_setLogConfig(no_topics); + + auto global_prev = mju_setLogHandler(nullptr); // restore default handler + + // send info with a topic — should be filtered by default handler + // we need to observe absence of output, so we'll use a custom global handler + mju_setLogHandler(CapturingHandler); + captured_msgs.clear(); + + // make sure TLS is null so global handler is used + auto old_tls = _mjPRIVATE_setTlsLogHandler(nullptr); + + mju_info(mjTOPIC_SLEEP, "should be filtered"); + + // TLS handler (none) -> global handler (CapturingHandler) + // But topic filtering happens inside the handler dispatch, not in mju_info + // mju_info just dispatches; the *default* handler filters. + // Since we installed CapturingHandler (not default), it won't filter. + // To test default handler filtering, we'd need the default handler. + // Instead, test that the topic field is correctly set. + ASSERT_EQ(captured_msgs.size(), 1); + EXPECT_EQ(captured_msgs[0].topic, mjTOPIC_SLEEP); + + _mjPRIVATE_setTlsLogHandler(old_tls); + mju_setLogHandler(global_prev); + mju_setLogConfig(orig); +} + +// ========================= mjERROR macro tests ============================== + +TEST(MjErrorMacroTest, HasSourceLocation) { + ScopedCapture cap; + if (setjmp(capture_jmp_buf) == 0) { + mjERROR("macro error %d", 99); + } + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_ERROR); + EXPECT_EQ(cap.msgs()[0].subject, "macro error 99"); + EXPECT_FALSE(cap.msgs()[0].func.empty()); + EXPECT_FALSE(cap.msgs()[0].file.empty()); + EXPECT_GT(cap.msgs()[0].line, 0); +} + +TEST(MjErrorMacroTest, FileIsPath) { + ScopedCapture cap; + if (setjmp(capture_jmp_buf) == 0) { + mjERROR("path test"); + } + + ASSERT_EQ(cap.msgs().size(), 1); + // file should be a path containing the filename + EXPECT_NE(cap.msgs()[0].file.find("engine_util_errmem_test.cc"), + std::string::npos); +} + +// ========================= mju_clearHandlers ================================ + +TEST(ClearHandlersTest, RestoresDefaults) { + // set some custom state + mju_user_error = [](const char*) {}; + mju_user_warning = [](const char*) {}; + + mju_clearHandlers(); + + EXPECT_EQ(mju_user_error, nullptr); + EXPECT_EQ(mju_user_warning, nullptr); + EXPECT_EQ(mju_user_malloc, nullptr); + EXPECT_EQ(mju_user_free, nullptr); + + // log config should be restored to defaults + mjLogConfig config = mju_getLogConfig(); + EXPECT_TRUE(config.logto_console); + EXPECT_STREQ(config.logfile, "MUJOCO_LOG.TXT"); +} + +// ========================= mju_message ====================================== + +TEST(MessageTest, DispatchesStructuredMessage) { + ScopedCapture cap; + mjLogMessage msg = {}; + msg.level = mjLOG_WARNING; + snprintf(msg.subject, sizeof(msg.subject), "raw warning"); + msg.func = "TestFunc"; + msg.file = "test.c"; + msg.line = 42; + + mju_message(&msg); + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_WARNING); + EXPECT_EQ(cap.msgs()[0].subject, "raw warning"); + EXPECT_EQ(cap.msgs()[0].func, "TestFunc"); + EXPECT_EQ(cap.msgs()[0].file, "test.c"); + EXPECT_EQ(cap.msgs()[0].line, 42); +} + +TEST(MessageTest, DispatchesError) { + ScopedCapture cap; + mjLogMessage msg = {}; + msg.level = mjLOG_ERROR; + snprintf(msg.subject, sizeof(msg.subject), "raw error"); + + if (setjmp(capture_jmp_buf) == 0) { + mju_message(&msg); + } + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_ERROR); + EXPECT_EQ(cap.msgs()[0].subject, "raw error"); +} + +// ========================= legacy handler compatibility ===================== + +TEST(LegacyCompatTest, LegacyErrorHandlerViaDefault) { + static thread_local std::string legacy_msg; + legacy_msg.clear(); + + auto old_tls = _mjPRIVATE_setTlsLogHandler(nullptr); + auto old_global = mju_setLogHandler(nullptr); // default handler + mju_user_error = [](const char* msg) { + legacy_msg = msg; + // legacy error handlers are expected to not return; longjmp to simulate + std::longjmp(capture_jmp_buf, 1); + }; + + if (setjmp(capture_jmp_buf) == 0) { + mju_error("legacy test %d", 1); + } + + EXPECT_EQ(legacy_msg, "legacy test 1"); + + mju_user_error = nullptr; + mju_setLogHandler(old_global); + _mjPRIVATE_setTlsLogHandler(old_tls); +} + +TEST(LegacyCompatTest, LegacyWarningHandlerViaDefault) { + static thread_local std::string legacy_msg; + legacy_msg.clear(); + + auto old_tls = _mjPRIVATE_setTlsLogHandler(nullptr); + auto old_global = mju_setLogHandler(nullptr); // default handler + mju_user_warning = [](const char* msg) { + legacy_msg = msg; + }; + + mju_warning("legacy warn %s", "bar"); + + EXPECT_EQ(legacy_msg, "legacy warn bar"); + + mju_user_warning = nullptr; + mju_setLogHandler(old_global); + _mjPRIVATE_setTlsLogHandler(old_tls); +} + +// ========================= truncation tests (from original) ================= + + + +TEST(TruncationTest, MjuErrorInternal) { + ScopedCapture cap; + if (setjmp(capture_jmp_buf) == 0) { + mjERROR("foobar %d", 123); + } + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].subject, "foobar 123"); + // func field should contain the test function name + EXPECT_FALSE(cap.msgs()[0].func.empty()); +} + +// ========================= mjDEBUG macro tests ============================== + +TEST(MjDebugMacroTest, EmitsDebugMessage) { + mjLogConfig orig = mju_getLogConfig(); + mjLogConfig cfg = orig; + cfg.topics = (1 << (mjTOPIC_SLEEP - 1)); + mju_setLogConfig(cfg); + + ScopedCapture cap; + mjDEBUG(mjTOPIC_SLEEP, "debug msg %d", 77); + + ASSERT_EQ(cap.msgs().size(), 1); + EXPECT_EQ(cap.msgs()[0].level, mjLOG_DEBUG); + EXPECT_EQ(cap.msgs()[0].topic, mjTOPIC_SLEEP); + EXPECT_EQ(cap.msgs()[0].subject, "debug msg 77"); + EXPECT_FALSE(cap.msgs()[0].func.empty()); + + mju_setLogConfig(orig); +} + +TEST(MjDebugMacroTest, FilteredByProducerSideCheck) { + mjLogConfig orig = mju_getLogConfig(); + mjLogConfig cfg = orig; + cfg.topics = 0; + mju_setLogConfig(cfg); + + ScopedCapture cap; + mjDEBUG(mjTOPIC_SLEEP, "should be filtered"); + + EXPECT_EQ(cap.msgs().size(), 0); + + mju_setLogConfig(orig); +} + +// ========================= BaseName tests =================================== + +TEST(BaseNameTest, UnixPath) { + EXPECT_STREQ(BaseName("/path/to/file.c"), "file.c"); +} + +TEST(BaseNameTest, WindowsPath) { + EXPECT_STREQ(BaseName("C:\\path\\to\\file.c"), "file.c"); +} + +TEST(BaseNameTest, NoSeparator) { + EXPECT_STREQ(BaseName("file.c"), "file.c"); +} + +TEST(BaseNameTest, MixedSeparators) { + EXPECT_STREQ(BaseName("/mixed\\path/file.c"), "file.c"); + EXPECT_STREQ(BaseName("C:\\mixed/path\\file.c"), "file.c"); +} + +TEST(BaseNameTest, EmptyString) { + EXPECT_STREQ(BaseName(""), ""); +} + +// ========================= default handler topic filtering ================== + +TEST(DefaultHandlerFilterTest, DisabledTopicNotWrittenToFile) { + mjLogConfig orig = mju_getLogConfig(); + auto old_tls = _mjPRIVATE_setTlsLogHandler(nullptr); + auto old_global = mju_setLogHandler(nullptr); + + std::string logpath = std::string(::testing::TempDir()) + "/filter_test.txt"; + std::remove(logpath.c_str()); + + mjLogConfig cfg = {}; + cfg.logto_console = false; + cfg.logto_file = true; + cfg.topics = 0; + snprintf(cfg.logfile, sizeof(cfg.logfile), "%s", logpath.c_str()); + mju_setLogConfig(cfg); + + // disabled topic: should be filtered by default handler + mju_info(mjTOPIC_SLEEP, "filtered message"); + + std::FILE* fp = std::fopen(logpath.c_str(), "r"); + bool file_empty = true; + if (fp) { + std::fseek(fp, 0, SEEK_END); + file_empty = (std::ftell(fp) == 0); + std::fclose(fp); + } + EXPECT_TRUE(file_empty) << "disabled topic should not write to logfile"; + + // enable the topic: should pass through + cfg.topics = (1 << (mjTOPIC_SLEEP - 1)); + mju_setLogConfig(cfg); + mju_info(mjTOPIC_SLEEP, "passed message"); + + fp = std::fopen(logpath.c_str(), "r"); + ASSERT_NE(fp, nullptr); + std::fseek(fp, 0, SEEK_END); + EXPECT_GT(std::ftell(fp), 0) << "enabled topic should write to logfile"; + std::fclose(fp); + + std::remove(logpath.c_str()); + mju_setLogConfig(orig); + mju_setLogHandler(old_global); + _mjPRIVATE_setTlsLogHandler(old_tls); +} + +// ========================= timing diagnostics =============================== + +TEST(TimingDiagnosticsTest, EmitsOnReset) { + const char xml[] = + ""; + char error[1024] = ""; + mjVFS vfs; + mj_defaultVFS(&vfs); + mj_addBufferVFS(&vfs, "m.xml", xml, static_cast(std::strlen(xml))); + mjModel* m = mj_loadXML("m.xml", &vfs, error, sizeof(error)); + mj_deleteVFS(&vfs); + ASSERT_NE(m, nullptr) << error; + mjData* d = mj_makeData(m); + ASSERT_NE(d, nullptr); + + // populate timers manually + d->timer[mjTIMER_STEP].number = 100; + d->timer[mjTIMER_STEP].duration = 0.01; + d->timer[mjTIMER_POSITION].number = 100; + d->timer[mjTIMER_POSITION].duration = 0.005; + + // capture log messages during reset + ScopedCapture cap; + mj_resetData(m, d); + + // find the timing diagnostics message + const CapturedMsg* tmsg = nullptr; + for (const auto& msg : cap.msgs()) { + if (msg.level == mjLOG_INFO && msg.topic == mjTOPIC_TIME_STP) { + tmsg = &msg; + break; + } + } + ASSERT_NE(tmsg, nullptr) << "expected timing diagnostics message"; + EXPECT_NE(tmsg->subject.find("100 steps"), std::string::npos); + EXPECT_FALSE(tmsg->body.empty()); + EXPECT_NE(tmsg->body.find("total"), std::string::npos); + + mj_deleteData(d); + mj_deleteModel(m); + mj_freeLastXML(); +} + +// ========================= env var edge cases =============================== + +TEST(InitFromEnvEdgeTest, EmptyString) { + mjLogConfig orig = mju_getLogConfig(); + setenv("MUJOCO_LOG_TOPICS", "", 1); + mju_clearHandlers(); + EXPECT_EQ(mju_getLogConfig().topics, 0); + unsetenv("MUJOCO_LOG_TOPICS"); + mju_clearHandlers(); + mju_setLogConfig(orig); +} + +TEST(InitFromEnvEdgeTest, UnknownTopic) { + mjLogConfig orig = mju_getLogConfig(); + setenv("MUJOCO_LOG_TOPICS", "nonexistent", 1); + mju_clearHandlers(); + EXPECT_EQ(mju_getLogConfig().topics, 0); + unsetenv("MUJOCO_LOG_TOPICS"); + mju_clearHandlers(); + mju_setLogConfig(orig); +} + +TEST(InitFromEnvEdgeTest, ExtraCommas) { + mjLogConfig orig = mju_getLogConfig(); + setenv("MUJOCO_LOG_TOPICS", ",,sleep,,", 1); + mju_clearHandlers(); + EXPECT_EQ(mju_getLogConfig().topics, (1 << 2)); + unsetenv("MUJOCO_LOG_TOPICS"); + mju_clearHandlers(); + mju_setLogConfig(orig); +} + +TEST(InitFromEnvEdgeTest, WhitespaceHandling) { + mjLogConfig orig = mju_getLogConfig(); + setenv("MUJOCO_LOG_TOPICS", " sleep , time_cmp ", 1); + mju_clearHandlers(); + EXPECT_EQ(mju_getLogConfig().topics, (1 << 1) | (1 << 2)); + unsetenv("MUJOCO_LOG_TOPICS"); + mju_clearHandlers(); + mju_setLogConfig(orig); } } // namespace diff --git a/test/fixture.cc b/test/fixture.cc index b66de8e9..1f3c7d67 100644 --- a/test/fixture.cc +++ b/test/fixture.cc @@ -21,12 +21,10 @@ #include #include // NOLINT #include -#include #include #include #include -#include #include #include @@ -39,7 +37,6 @@ #include #include #include -#include #include #include "src/xml/xml_global.h" diff --git a/test/fixture.h b/test/fixture.h index bcf4c0de..c6a4457b 100644 --- a/test/fixture.h +++ b/test/fixture.h @@ -34,8 +34,7 @@ #include extern "C" { -MJAPI void _mjPRIVATE__set_tls_error_fn(decltype(mju_user_error)); -MJAPI decltype(mju_user_error) _mjPRIVATE__get_tls_error_fn(); +MJAPI mjfLogHandler _mjPRIVATE_setTlsLogHandler(mjfLogHandler handler); } namespace mujoco { @@ -138,21 +137,20 @@ auto MjuErrorMessageFrom(Return (*func)(Args...)) { thread_local std::jmp_buf current_jmp_buf; thread_local char err_msg[1000]; - auto* old_error_handler = _mjPRIVATE__get_tls_error_fn(); - auto* new_error_handler = +[](const char* msg) -> void { - std::strncpy(err_msg, msg, sizeof(err_msg)); + auto new_error_handler = +[](const mjLogMessage* msg) -> void { + if (msg->level != mjLOG_ERROR) return; + std::strncpy(err_msg, msg->subject, sizeof(err_msg)); std::longjmp(current_jmp_buf, 1); }; - return [func, old_error_handler, - new_error_handler](Args... args) -> std::string { + return [func, new_error_handler](Args... args) -> std::string { + auto old_handler = _mjPRIVATE_setTlsLogHandler(new_error_handler); if (setjmp(current_jmp_buf) == 0) { err_msg[0] = '\0'; - _mjPRIVATE__set_tls_error_fn(new_error_handler); func(args...); } - _mjPRIVATE__set_tls_error_fn(old_error_handler); + _mjPRIVATE_setTlsLogHandler(old_handler); return err_msg; }; } diff --git a/unity/Runtime/Bindings/MjBindings.cs b/unity/Runtime/Bindings/MjBindings.cs index 5f6aee9c..26bfe6d6 100644 --- a/unity/Runtime/Bindings/MjBindings.cs +++ b/unity/Runtime/Bindings/MjBindings.cs @@ -516,6 +516,19 @@ public enum mjtSleepState : int{ mjS_ASLEEP = 0, mjS_AWAKE = 1, } +public enum mjtLogLevel : int{ + mjLOG_DEBUG = 0, + mjLOG_INFO = 1, + mjLOG_WARNING = 2, + mjLOG_ERROR = 3, +} +public enum mjtLogTopic : int{ + mjTOPIC_NONE = 0, + mjTOPIC_TIME_STP = 1, + mjTOPIC_TIME_CMP = 2, + mjTOPIC_SLEEP = 3, + mjNTOPIC = 3, +} public enum mjtGeomInertia : int{ mjINERTIA_VOLUME = 0, mjINERTIA_SHELL = 1, @@ -803,6 +816,26 @@ public enum mjtSection : int{ // -------------------------------struct declarations--------------------------- +[StructLayout(LayoutKind.Sequential)] +public unsafe struct mjLogMessage_ { + public int level; + public int topic; + public fixed char subject[1024]; + public char* body; + public char* func; + public char* file; + public int line; + public byte timestamp; +} + +[StructLayout(LayoutKind.Sequential)] +public unsafe struct mjLogConfig_ { + public byte logto_console; + public byte logto_file; + public fixed char logfile[1024]; + public int topics; +} + [StructLayout(LayoutKind.Sequential)] public unsafe struct mjLROpt_ { public int mode; @@ -7267,6 +7300,21 @@ public static unsafe extern void mju_warning([MarshalAs(UnmanagedType.LPStr)]str [DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] public static unsafe extern void mju_clearHandlers(); +[DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] +public static unsafe extern IntPtr mju_setLogHandler(IntPtr handler); + +[DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] +public static unsafe extern mjLogConfig_ mju_getLogConfig(); + +[DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] +public static unsafe extern void mju_setLogConfig(mjLogConfig_ config); + +[DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] +public static unsafe extern void mju_info(int topic, [MarshalAs(UnmanagedType.LPStr)]string msg); + +[DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] +public static unsafe extern void mju_message(mjLogMessage_* msg); + [DllImport("mujoco", CallingConvention = CallingConvention.Cdecl)] public static unsafe extern void* mju_malloc(UIntPtr size); diff --git a/wasm/codegen/generated/bindings.cc b/wasm/codegen/generated/bindings.cc index 7f41dde5..5302989a 100644 --- a/wasm/codegen/generated/bindings.cc +++ b/wasm/codegen/generated/bindings.cc @@ -597,6 +597,90 @@ struct MjLROpt { bool owned_ = false; }; +struct MjLogConfig { + ~MjLogConfig(); + MjLogConfig(); + explicit MjLogConfig(mjLogConfig *ptr); + MjLogConfig(const MjLogConfig &); + MjLogConfig &operator=(const MjLogConfig &); + std::unique_ptr copy(); + mjLogConfig* get() const; + void set(mjLogConfig* ptr); + mjtBool logto_console() const { + return ptr_->logto_console; + } + void set_logto_console(mjtBool value) { + ptr_->logto_console = value; + } + mjtBool logto_file() const { + return ptr_->logto_file; + } + void set_logto_file(mjtBool value) { + ptr_->logto_file = value; + } + emscripten::val logfile() const { + return emscripten::val(emscripten::typed_memory_view(1024, ptr_->logfile)); + } + int topics() const { + return ptr_->topics; + } + void set_topics(int value) { + ptr_->topics = value; + } + + private: + mjLogConfig* ptr_; + bool owned_ = false; +}; + +struct MjLogMessage { + ~MjLogMessage(); + MjLogMessage(); + explicit MjLogMessage(mjLogMessage *ptr); + mjLogMessage* get() const; + void set(mjLogMessage* ptr); + int level() const { + return ptr_->level; + } + void set_level(int value) { + ptr_->level = value; + } + int topic() const { + return ptr_->topic; + } + void set_topic(int value) { + ptr_->topic = value; + } + emscripten::val subject() const { + return emscripten::val(emscripten::typed_memory_view(1024, ptr_->subject)); + } + std::string body() const { + return ptr_->body ? std::string(ptr_->body) : ""; + } + std::string func() const { + return ptr_->func ? std::string(ptr_->func) : ""; + } + std::string file() const { + return ptr_->file ? std::string(ptr_->file) : ""; + } + int line() const { + return ptr_->line; + } + void set_line(int value) { + ptr_->line = value; + } + mjtBool timestamp() const { + return ptr_->timestamp; + } + void set_timestamp(mjtBool value) { + ptr_->timestamp = value; + } + + private: + mjLogMessage* ptr_; + bool owned_ = false; +}; + struct MjOption { ~MjOption(); MjOption(); @@ -7194,6 +7278,51 @@ void MjLROpt::set(mjLROpt* ptr) { ptr_ = ptr; } +MjLogConfig::MjLogConfig(mjLogConfig *ptr) : ptr_(ptr) {} +MjLogConfig::~MjLogConfig() { + if (owned_ && ptr_) { + delete ptr_; + } +} +MjLogConfig::MjLogConfig() : ptr_(new mjLogConfig()) { + owned_ = true; +} +MjLogConfig::MjLogConfig(const MjLogConfig &other) : MjLogConfig() { + *ptr_ = *other.get(); +} +MjLogConfig& MjLogConfig::operator=(const MjLogConfig &other) { + if (this == &other) { + return *this; + } + *ptr_ = *other.get(); + return *this; +} +std::unique_ptr MjLogConfig::copy() { + return std::make_unique(*this); +} +mjLogConfig* MjLogConfig::get() const { + return ptr_; +} +void MjLogConfig::set(mjLogConfig* ptr) { + ptr_ = ptr; +} + +MjLogMessage::MjLogMessage(mjLogMessage *ptr) : ptr_(ptr) {} +MjLogMessage::~MjLogMessage() { + if (owned_ && ptr_) { + delete ptr_; + } +} +MjLogMessage::MjLogMessage() : ptr_(new mjLogMessage()) { + owned_ = true; +} +mjLogMessage* MjLogMessage::get() const { + return ptr_; +} +void MjLogMessage::set(mjLogMessage* ptr) { + ptr_ = ptr; +} + MjOption::MjOption(mjOption *ptr) : ptr_(ptr) {} MjOption::~MjOption() { if (owned_ && ptr_) { @@ -8552,6 +8681,11 @@ int mj_setLengthRange_wrapper(const MjModel& m, const MjData& d, int index, cons return result; } +void mju_info_wrapper(int topic, const String& msg) { + CHECK_VAL(msg); + mju_info(topic, "%s", msg.as().data()); +} + void mj_Euler_wrapper(const MjModel& m, MjData& d) { mj_Euler(m.get(), d.get()); } @@ -10364,6 +10498,12 @@ void mju_fill_wrapper(const val& res, mjtNum val) { mju_fill(res_.data(), val, n); } +MjLogConfig mju_getLogConfig_wrapper() { + MjLogConfig result; + *result.get() = mju_getLogConfig(); + return result; +} + void mju_insertionSort_wrapper(const val& list) { UNPACK_VALUE(mjtNum, list); int n = list_.size(); @@ -10393,6 +10533,10 @@ int mju_mat2Rot_wrapper(const val& quat, const NumberArray& mat) { return mju_mat2Rot(quat_.data(), mat_.data()); } +void mju_message_wrapper(const MjLogMessage& msg) { + mju_message(msg.get()); +} + void mju_mulMatMat_wrapper(const val& res, const NumberArray& mat1, const NumberArray& mat2, int r1, int c1, int c2) { UNPACK_VALUE(mjtNum, res); UNPACK_ARRAY(mjtNum, mat1); @@ -10642,6 +10786,10 @@ void mju_scl3_wrapper(const val& res, const NumberArray& vec, mjtNum scl) { mju_scl3(res_.data(), vec_.data(), scl); } +void mju_setLogConfig_wrapper(const MjLogConfig& config) { + mju_setLogConfig(*config.get()); +} + void mju_sparse2dense_wrapper(const val& res, const NumberArray& mat, int nr, int nc, const NumberArray& rownnz, const NumberArray& rowadr, const NumberArray& colind) { UNPACK_VALUE(mjtNum, res); UNPACK_ARRAY(mjtNum, mat); @@ -11258,6 +11406,17 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { .value("mjLIMITED_FALSE", mjLIMITED_FALSE) .value("mjLIMITED_TRUE", mjLIMITED_TRUE) .value("mjLIMITED_AUTO", mjLIMITED_AUTO); + enum_("mjtLogLevel") + .value("mjLOG_DEBUG", mjLOG_DEBUG) + .value("mjLOG_INFO", mjLOG_INFO) + .value("mjLOG_WARNING", mjLOG_WARNING) + .value("mjLOG_ERROR", mjLOG_ERROR); + enum_("mjtLogTopic") + .value("mjTOPIC_NONE", mjTOPIC_NONE) + .value("mjTOPIC_TIME_STP", mjTOPIC_TIME_STP) + .value("mjTOPIC_TIME_CMP", mjTOPIC_TIME_CMP) + .value("mjTOPIC_SLEEP", mjTOPIC_SLEEP) + .value("mjNTOPIC", mjNTOPIC); enum_("mjtMark") .value("mjMARK_NONE", mjMARK_NONE) .value("mjMARK_EDGE", mjMARK_EDGE) @@ -11817,6 +11976,23 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { .property("tolrange", &MjLROpt::tolrange, &MjLROpt::set_tolrange, reference()) .property("useexisting", &MjLROpt::useexisting, &MjLROpt::set_useexisting, reference()) .property("uselimit", &MjLROpt::uselimit, &MjLROpt::set_uselimit, reference()); + emscripten::class_("MjLogConfig") + .constructor<>() + .function("copy", &MjLogConfig::copy, take_ownership()) + .property("logfile", &MjLogConfig::logfile) + .property("logto_console", &MjLogConfig::logto_console, &MjLogConfig::set_logto_console, reference()) + .property("logto_file", &MjLogConfig::logto_file, &MjLogConfig::set_logto_file, reference()) + .property("topics", &MjLogConfig::topics, &MjLogConfig::set_topics, reference()); + emscripten::class_("MjLogMessage") + .constructor<>() + .property("body", &MjLogMessage::body, reference()) + .property("file", &MjLogMessage::file, reference()) + .property("func", &MjLogMessage::func, reference()) + .property("level", &MjLogMessage::level, &MjLogMessage::set_level, reference()) + .property("line", &MjLogMessage::line, &MjLogMessage::set_line, reference()) + .property("subject", &MjLogMessage::subject) + .property("timestamp", &MjLogMessage::timestamp, &MjLogMessage::set_timestamp, reference()) + .property("topic", &MjLogMessage::topic, &MjLogMessage::set_topic, reference()); emscripten::class_("MjModel") // mj_loadXML is deprecated and will be removed in a future release .class_function("mj_loadXML", emscripten::select_overload(std::string)>(&mj_loadXML_wrapper_1)) @@ -13534,6 +13710,7 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { function("mju_eye", &mju_eye_wrapper); function("mju_f2n", &mju_f2n_wrapper); function("mju_fill", &mju_fill_wrapper); + function("mju_getLogConfig", &mju_getLogConfig_wrapper); function("mju_insertionSort", &mju_insertionSort_wrapper); function("mju_insertionSortInt", &mju_insertionSortInt_wrapper); function("mju_isBad", &mju_isBad); @@ -13541,6 +13718,7 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { function("mju_mat2Quat", &mju_mat2Quat_wrapper); function("mju_mat2Rot", &mju_mat2Rot_wrapper); function("mju_max", &mju_max); + function("mju_message", &mju_message_wrapper); function("mju_min", &mju_min); function("mju_mulMatMat", &mju_mulMatMat_wrapper); function("mju_mulMatMatT", &mju_mulMatMatT_wrapper); @@ -13577,6 +13755,7 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { function("mju_round", &mju_round); function("mju_scl", &mju_scl_wrapper); function("mju_scl3", &mju_scl3_wrapper); + function("mju_setLogConfig", &mju_setLogConfig_wrapper); function("mju_sigmoid", &mju_sigmoid); function("mju_sign", &mju_sign); function("mju_sparse2dense", &mju_sparse2dense_wrapper); @@ -13636,6 +13815,7 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { function("mj_saveModel", &mj_saveModel_wrapper); function("mj_saveLastXML", &mj_saveLastXML_wrapper); function("mj_setLengthRange", &mj_setLengthRange_wrapper); + function("mju_info", &mju_info_wrapper); // mj_compile is bound using two overloads to handle the optional MjVFS argument, // as using std::optional caused memory errors due to missing copy/move constructors. function("mj_compile", emscripten::select_overload(const MjSpec&)>(&mj_compile_wrapper_1)); diff --git a/wasm/codegen/generators/common.py b/wasm/codegen/generators/common.py index 69d450c0..34bf5e7a 100644 --- a/wasm/codegen/generators/common.py +++ b/wasm/codegen/generators/common.py @@ -15,7 +15,9 @@ """Utility functions for code generation.""" import os +from typing import Union from introspect import ast_nodes +from wasm.codegen.generators import constants def write_to_file(filepath: str, content: str) -> None: @@ -87,12 +89,27 @@ def get_inner_value_type( return param.type.inner_type +def is_struct_value_type( + t: Union[ast_nodes.ValueType, ast_nodes.ArrayType, ast_nodes.PointerType], +) -> bool: + """Checks if a type is a struct passed by value.""" + if isinstance(t, ast_nodes.ValueType): + return ( + t.name not in constants.PRIMITIVE_TYPES + and t.name != "void" + and not t.name.startswith("mjf") + ) + return False + + def should_be_wrapped(func: ast_nodes.FunctionDecl) -> bool: """Checks if a MuJoCo function needs a wrapper function.""" if get_pointer_return_inner_value_type(func): return True + if is_struct_value_type(func.return_type): + return True for param in func.parameters: - if get_inner_value_type(param): + if get_inner_value_type(param) or is_struct_value_type(param.type): return True return False diff --git a/wasm/codegen/generators/constants.py b/wasm/codegen/generators/constants.py index 223dde27..64b030cf 100644 --- a/wasm/codegen/generators/constants.py +++ b/wasm/codegen/generators/constants.py @@ -149,6 +149,7 @@ _SKIPPED_MEMORY_FUNCTIONS: tuple[str, ...] = ( "mju_error", "mju_free", "mju_malloc", + "mju_setLogHandler", "mju_strncpy", "mju_warning", # go/keep-sorted end @@ -230,6 +231,7 @@ MANUAL_WRAPPER_FUNCTIONS: tuple[str, ...] = ( "mj_saveModel", "mj_setLengthRange", "mju_error", + "mju_info", # go/keep-sorted end ) @@ -276,6 +278,8 @@ STRUCTS_TO_BIND: list[str] = list( NO_DEFAULT_CONSTRUCTORS: tuple[str, ...] = ( # go/keep-sorted start "mjContact", + "mjLogConfig", + "mjLogMessage", "mjPreContact", "mjSolverStat", "mjStatistic", diff --git a/wasm/codegen/generators/functions.py b/wasm/codegen/generators/functions.py index f7939a83..d8bb652c 100644 --- a/wasm/codegen/generators/functions.py +++ b/wasm/codegen/generators/functions.py @@ -154,6 +154,14 @@ def get_param_string(p: ast_nodes.FunctionParameterDecl) -> str: return f"const NumberArray& {p.name}" else: return f"const val& {p.name}" + elif common.is_struct_value_type(p.type): + # Struct by value parameters + value_type = cast(ast_nodes.ValueType, p.type) + const_qualifier = "const " if value_type.is_const else "const " + return ( + f"{const_qualifier}{common.capitalize(value_type.name)}&" + f" {p.name}" + ) else: # This case should ideally not be reached if AST is well-formed # and types are categorized by the helper booleans correctly. @@ -183,6 +191,8 @@ def get_params_string_maybe_with_conversion( native_params.append(f"{p.name}.get()") elif param_is_primitive_value(p): native_params.append(p.name) + elif common.is_struct_value_type(p.type): + native_params.append(f"*{p.name}.get()") else: raise TypeError( f"Unhandled parameter type for conversion: {p.type} for param" @@ -201,6 +211,14 @@ def get_compatible_return_code(func: ast_nodes.FunctionDecl) -> str: return f"{c_call};" if func.return_type.name in constants.PRIMITIVE_TYPES: return f"return {c_call};" + if common.is_struct_value_type(func.return_type): + struct_name = func.return_type.name + w = common.wrapped_struct_name(struct_name) + builder = code_builder.CodeBuilder() + builder.line(f"{w} result;") + builder.line(f"*result.get() = {c_call};") + builder.line("return result;") + return builder.to_string() if inner_type := common.get_pointer_return_inner_value_type(func): if inner_type.name == "char": @@ -230,6 +248,9 @@ def get_compatible_return_type(func: ast_nodes.FunctionDecl) -> str: and func.return_type.name in constants.PRIMITIVE_TYPES ): return f"{func.return_type.name}" + if common.is_struct_value_type(func.return_type): + return_type = cast(ast_nodes.ValueType, func.return_type) + return common.wrapped_struct_name(return_type.name) return "val" diff --git a/wasm/codegen/generators/structs.py b/wasm/codegen/generators/structs.py index a2731326..197aac2d 100644 --- a/wasm/codegen/generators/structs.py +++ b/wasm/codegen/generators/structs.py @@ -229,6 +229,36 @@ def _generate_field_data( binding=_get_property_binding(f, w, setter=False, reference=True), ) + # Case 2.5: const char* without array_extent (C strings like body, func). + elif ( + inner_type_name == "char" + and not is_dynamically_sized + ): + builder = code_builder.CodeBuilder() + if f.type.inner_type.is_const: + with builder.function(f"std::string {f.name}() const"): + builder.line( + f'return ptr_->{f.name} ? std::string(ptr_->{f.name}) : "";' + ) + else: + with builder.function(f"std::string {f.name}() const"): + builder.line( + f'return ptr_->{f.name} ? std::string(ptr_->{f.name}) : "";' + ) + with builder.function(f"void set_{f.name}(const std::string& value)"): + with builder.block(f"if (ptr_->{f.name})"): + builder.line( + f"std::strncpy(ptr_->{f.name}, value.c_str()," + f" sizeof(ptr_->{f.name}));" + ) + return WrappedFieldData( + declaration=builder.to_string(), + typename=_get_field_struct_type(f, s), + binding=_get_property_binding( + f, w, setter=not f.type.inner_type.is_const, reference=True + ), + ) + # Case 3: Non-dynamically sized pointer fields to other structs. elif ( not is_dynamically_sized diff --git a/wasm/codegen/templates/bindings.cc b/wasm/codegen/templates/bindings.cc index e4255e15..dd76de48 100644 --- a/wasm/codegen/templates/bindings.cc +++ b/wasm/codegen/templates/bindings.cc @@ -833,6 +833,11 @@ int mj_setLengthRange_wrapper(const MjModel& m, const MjData& d, int index, cons return result; } +void mju_info_wrapper(int topic, const String& msg) { + CHECK_VAL(msg); + mju_info(topic, "%s", msg.as().data()); +} + // {{ WRAPPER_FUNCTIONS }} EMSCRIPTEN_BINDINGS(mujoco_bindings) { @@ -879,6 +884,7 @@ EMSCRIPTEN_BINDINGS(mujoco_bindings) { function("mj_saveModel", &mj_saveModel_wrapper); function("mj_saveLastXML", &mj_saveLastXML_wrapper); function("mj_setLengthRange", &mj_setLengthRange_wrapper); + function("mju_info", &mju_info_wrapper); // mj_compile is bound using two overloads to handle the optional MjVFS argument, // as using std::optional caused memory errors due to missing copy/move constructors. function("mj_compile", emscripten::select_overload(const MjSpec&)>(&mj_compile_wrapper_1));