| .. _trace-h: |
| |
| ======= |
| trace.h |
| ======= |
| |
| The Emscripten tracing API provides some useful capabilities to better see |
| what is going on inside of your application, in particular with respect to |
| memory usage (which is otherwise not available to traditional browser |
| performance tools). |
| |
| The tracing API can talk to a custom collection server (see `Running the Server`_ |
| for more details) or it can talk with the `Google Web Tracing Framework`_. |
| When talking with the `Google Web Tracing Framework`_, a subset of the data |
| available is collected. |
| |
| |
| .. contents:: table of contents |
| :local: |
| :depth: 2 |
| |
| Usage |
| ===== |
| |
| Compiler Interaction |
| -------------------- |
| |
| When using the tracing API, you should pass ``--tracing`` to ``emcc`` at each |
| compile and link stage. This |
| will automatically include the ``library_trace.js`` library file as well as |
| set the preprocessor flag ``__EMSCRIPTEN_TRACING__``. If you are invoking |
| ``clang`` directly to build your C / C++ code, then you will want to pass |
| ``-D__EMSCRIPTEN_TRACING__`` when building code. When the preprocessor |
| flag ``__EMSCRIPTEN_TRACING__`` is not defined, the tracing API implementation |
| will be provided by inlined empty stubs. |
| |
| Also, since enabling tracing modifies the implementation of ``dlmalloc.c`` |
| in the ``libc`` implementation, it is advised that you manually clear your |
| cache before switching to using the tracing API. If you do not do this, then |
| you will not get full allocation details recorded. You can clear the cache |
| with this ``emcc`` command:: |
| |
| emcc --clear-cache |
| |
| Initialization and Teardown |
| --------------------------- |
| |
| To initialize the tracing API, you call :c:func:`emscripten_trace_configure`: |
| |
| .. code-block:: c |
| |
| emscripten_trace_configure("http://127.0.0.1:5000/", "MyApplication"); |
| |
| If you are simply going to use the tracing API with the `Google Web Tracing |
| Framework`_, then you can just call :c:func:`emscripten_trace_configure_for_google_wtf` |
| instead: |
| |
| .. code-block:: c |
| |
| emscripten_trace_configure_for_google_wtf(); |
| |
| If you have the concept of a username or have some other way to identify |
| a given user of the application, then passing that to the tracing API |
| can make it easier to identify sessions in the collector server: |
| |
| .. code-block:: c |
| |
| emscripten_trace_set_session_username(username); |
| |
| To shut it down at application exit, you simply call |
| :c:func:`emscripten_trace_close`: |
| |
| .. code-block:: c |
| |
| emscripten_trace_close(); |
| |
| Contexts |
| -------- |
| |
| Contexts are a way to tell the tracing API what part of your application |
| is currently running. Contexts are effectively maintained as a stack of |
| current contexts. |
| |
| A context might be something as big as "running physics" or as small |
| as "updating animations on entity X". |
| |
| The granularity of the context stack is up to the team instrumenting |
| their application. Some applications may find fine-grained contexts |
| more useful, while others are more comfortable with larger contexts. |
| |
| Rather than getting a stack trace on every tracing call, we can often |
| look at the current context stack and record that instead, which is |
| much cheaper. |
| |
| When contexts are fully implemented by the server, they will also be |
| used to track how much time is spent in each context (a primitive |
| profiling mechanism), as well as how much memory has been allocated |
| and freed while the context was active. This should help give a good |
| idea of which parts of your application are using more memory or |
| creating a lot of churn (and possibly heap fragmentation). |
| |
| Recording context entry and exit is simple: |
| |
| .. code-block:: c |
| |
| emscripten_trace_enter_context("Physics Update"); |
| ... |
| emscripten_trace_exit_context(); |
| |
| Frames |
| ------ |
| |
| It is important to record where your frame or event loop begins |
| and ends. This allows the tracing API to perform useful additional |
| analysis. |
| |
| Noting the start of an event loop is as easy as: |
| |
| .. code-block:: c |
| |
| emscripten_trace_record_frame_start(); |
| |
| And noting the end of the event loop is just as easy: |
| |
| .. code-block:: c |
| |
| emscripten_trace_record_frame_end(); |
| |
| Annotating Allocations |
| ---------------------- |
| |
| Each allocation and free operation should be recorded. Ideally, |
| the data type name will also be recorded, but this must currently |
| be done manually. |
| |
| When building with ``--tracing`` and a cleared cache, the ``libc`` |
| that Emscripten builds will automatically record all calls to |
| ``malloc``, ``realloc`` and ``free``. |
| |
| As for recording the data type name, after you've allocated the |
| memory, you can annotate the address: |
| |
| .. code-block:: c |
| |
| emscripten_trace_annotate_address_type(model, "UI::Model"); |
| |
| Additionally, some applications may want to associate the size |
| of additional storage with an allocation. This can be done via |
| :c:func:`emscripten_trace_associate_storage_size`: |
| |
| .. code-block:: c |
| |
| emscripten_trace_associate_storage_size(mesh, mesh->GetTotalMemoryUsage()); |
| |
| Overall Memory Usage |
| -------------------- |
| |
| Periodically, the overall heap layout and memory usage should |
| be reported to the trace API. |
| |
| This is done with 2 calls: |
| |
| .. code-block:: c |
| |
| emscripten_trace_report_memory_layout(); |
| emscripten_trace_report_off_heap_data(); |
| |
| Logging Messages |
| ---------------- |
| |
| Messages can be logged and recorded via the Emscripten tracing API. |
| These messages can have both a channel and the actual message. The |
| channel name will help to categorize and filter messages within |
| the visualization interface. You should avoid allocating memory |
| on the heap while logging a message. |
| |
| .. code-block:: c |
| |
| emscripten_trace_log_message("Application", "Started"); |
| |
| Over time, the visualization interface will improve to help you |
| better correlate these log messages with other views, such as |
| memory usage over time. Logging messages for things that may |
| cause large amounts of memory activity, like loading a new |
| model or game asset, is very useful when analyzing memory |
| usage behavior patterns. |
| |
| Tasks |
| ----- |
| |
| Specific tasks can be recorded and analyzed. A task is typically |
| a unit of work that is not repeating. It may be suspended or |
| blocked due to having portions performed asynchronously. |
| |
| An example of a task is loading an asset which usually involves |
| chains of callbacks. |
| |
| The application should keep track of task IDs (integers) and |
| ensure that they are unique. |
| |
| The task ID need not be passed to every trace call involving |
| tasks as most calls operate on the current task. |
| |
| Tasks can be started and stopped with: |
| |
| .. code-block:: c |
| |
| emscripten_trace_task_start(taskID, name); |
| emscripten_trace_task_end(); |
| |
| If a task is suspended / blocked, this can be noted via: |
| |
| .. code-block:: c |
| |
| emscripten_trace_task_suspend("loading via HTTP"); |
| |
| And when it is resumed: |
| |
| .. code-block:: c |
| |
| emscripten_trace_task_resume(taskID, "parsing"); |
| |
| It is common to need to associate additional data with the |
| current task for use when examining task data later. An example |
| of this would be the URL of an asset that was loaded: |
| |
| .. code-block:: c |
| |
| emscripten_trace_task_associate_data("url", url); |
| |
| Reporting Errors |
| ---------------- |
| |
| Errors encountered by the application can be reported to the tracing |
| API as an ancillary service: |
| |
| .. code-block:: c |
| |
| emscripten_trace_report_error("Assertion failed: ..."); |
| |
| This feature is included as an indication of the future direction |
| of the Emscripten tracing API. |
| |
| Running the Server |
| ================== |
| |
| * Obtain a copy of the `emscripten-trace-collector`_ server. |
| * Follow the directions in the `README.rst`. |
| |
| Design Notes |
| ============ |
| |
| Client / Server Design |
| ---------------------- |
| |
| The Emscripten tracing API gathers data from instrumented code and transmits |
| it to a collector server. The server also performs data analysis and |
| provides a web interface for viewing the collected data. |
| |
| This client / server design is intended to allow the tool to run without |
| interfering with the browser on lower-end hardware where memory might |
| be at a premium, like 32 bit Windows machines. |
| |
| This design also allows for a single server to be run to collect data |
| from a variety of clients. |
| |
| Data Batching |
| ------------- |
| |
| Data is batched and sent to the server in chunks, roughly once or twice |
| per second. This avoids having to open a new connection to the server |
| for every single event being recorded. |
| |
| Do Not Perturb The Heap |
| ----------------------- |
| |
| When using the Emscripten tracing API, you should be careful that you do |
| not perform operations that would perturb the heap. For example, you shouldn't |
| allocate a string to pass to :c:func:`emscripten_trace_log_message` as |
| that would result in the allocation being tracked and possibly |
| disturbing the behavior or results that you are trying to analyze. |
| |
| For this reason, the Emscripten tracing API also keeps all of its own |
| data off of the Emscripten heap and performs no writes to the Emscripten |
| heap. |
| |
| Functions |
| ========= |
| |
| .. c:function:: void emscripten_trace_configure(const char *collector_url, const char *application) |
| |
| :param collector_url: The base URL for the collector server. |
| :type collector_url: const char* |
| :param application: The name of the application being traced. |
| :type application: const char* |
| :rtype: void |
| |
| Configure the connection to the collector server. |
| |
| This should be one of the very first things that is done after the |
| application has started. |
| |
| In most cases, the ``collector_url`` will be ``http://127.0.0.1:5000/``. |
| |
| .. c:function:: void emscripten_trace_configure_for_google_wtf(void) |
| |
| :rtype: void |
| |
| Configure tracing to communicate with the `Google Web Tracing Framework`_. |
| |
| Not all features of the tracing are available within the Google WTF |
| tools. (Currently, only contexts, log messages and marks.) |
| |
| .. c:function:: void emscripten_trace_set_enabled(bool enabled) |
| |
| :param enabled: Whether or not tracing is enabled. |
| :type enabled: bool |
| :rtype: void |
| |
| Set whether or not tracing is enabled. Using this option to disable |
| tracing will likely result in inaccurate data being collected about |
| memory usage. |
| |
| .. c:function:: void emscripten_trace_set_session_username(const char *username) |
| |
| :param username: The username of the person running the application. |
| :type username: const char* |
| :rtype: void |
| |
| This is useful when a collector server is being used by multiple |
| people and you want to be able to identify individual sessions |
| by a means other than their timestamped session ID. |
| |
| This can be set after tracing has already started, so it is fine |
| to set this after the user has gone through a login or authentication |
| process. |
| |
| .. c:function:: void emscripten_trace_record_frame_start(void) |
| |
| :rtype: void |
| |
| This should be called at the start of the frame / event loop. |
| |
| The current timestamp is associated with this data. |
| |
| The server uses this to track frame times (and therefore frames |
| per second), as well as accounting for memory operations that |
| happen during the frame processing. |
| |
| .. c:function:: void emscripten_trace_record_frame_end(void) |
| |
| :rtype: void |
| |
| This should be called at the end of the frame / event loop. |
| |
| The current timestamp is associated with this data. |
| |
| The server uses this to stop accruing memory operations and |
| elapsed time to the frame. |
| |
| .. c:function:: void emscripten_trace_log_message(const char *channel, const char *message) |
| |
| :param channel: The category of the timeline event being emitted. |
| :type channel: const char* |
| :param message: The description for the timeline event being emitted. |
| :type message: const char* |
| :rtype: void |
| |
| Record a log message. This is useful for noting events or actions |
| which have occurred which might be advantageous to have correlated |
| against memory usage or changes in frame rate. |
| |
| The current timestamp is associated with this data. |
| |
| *The server doesn't yet do enough with this data. This will improve |
| in the future.* |
| |
| .. c:function:: void emscripten_trace_mark(const char *message) |
| |
| :param message: The name of the mark begin emitted. |
| :type message: const char * |
| :rtype: void |
| |
| Record a mark in the timeline. This is primary for use with the |
| `Google Web Tracing Framework`_. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_report_error(const char *error) |
| |
| :param error: The error message being reported. |
| :type error: const char* |
| :rtype: void |
| |
| The API will obtain the current callstack and include that in the report |
| to the server. |
| |
| The current timestamp is associated with this data. |
| |
| This could be used for various things including capturing JavaScript and |
| web-worker errors, as well as failed assertions or other run-time errors |
| from within the C/C++ code. |
| |
| .. c:function:: void emscripten_trace_record_allocation(const void *address, int32_t size) |
| |
| :param address: Memory address which has been allocated. |
| :type address: const void* |
| :param size: Size of the memory block allocated. |
| :type size: int32_t |
| :rtype: void |
| |
| This must be called for each and every memory allocation. The best place to |
| do this is within the ``dlmalloc`` implementation in Emscripten. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_record_reallocation(const void *old_address, const void *new_address, int32_t size) |
| |
| :param old_address: Old address of the memory block which has been reallocated. |
| :type old_address: const void* |
| :param new_address: New address of the memory block which has been reallocated. |
| :type new_address: const void* |
| :param size: New size of the memory block reallocated. |
| :type size: int32_t |
| :rtype: void |
| |
| This must be called for each and every memory re-allocation. The best place to |
| do this is within the ``dlmalloc`` implementation in Emscripten. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_record_free(const void *address) |
| |
| :param address: Memory address which is being freed. |
| :type address: const void* |
| :rtype: void |
| |
| This must be called for each and every ``free`` operation. The best place |
| to do this is within the ``dlmalloc`` implementation in Emscripten. |
| |
| The current timestamp is associated with this data. |
| |
| It is also important that this not be called multiple times for a single |
| ``free`` operation. |
| |
| .. c:function:: void emscripten_trace_annotate_address_type(const void *address, const char *type) |
| |
| :param address: Memory address which should be annotated. |
| :type address: const void* |
| :param type: The name of the data type being allocated. |
| :type type: const char* |
| :rtype: void |
| |
| Annotate an address with the name of the data type that is |
| stored there. This is used by the server to help breakdown |
| what is in memory. |
| |
| .. c:function:: void emscripten_trace_associate_storage_size(const void *address, int32_t size) |
| |
| :param address: Memory address which should be annotated. |
| :type address: const void* |
| :param size: Size of the memory associated with this allocation. |
| :type size: int32_t |
| :rtype: void |
| |
| Associate an amount of additional storage with this address. This |
| does not represent the size of the allocation itself, but rather |
| associated memory that should be taken into account when looking |
| at the size of this object. |
| |
| This associated storage is application specific in nature. |
| |
| An example is when an object contains a vector or string, you may |
| want to be aware of that when analyzing memory usage and this |
| provides a way to let the server be aware of that additional |
| storage. |
| |
| .. c:function:: void emscripten_trace_report_memory_layout(void) |
| |
| :rtype: void |
| |
| This should be called periodically to report the usage of the |
| normal Emscripten heap. This provides details of both the stack |
| and the dynamic memory usage as well as the total memory size. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_report_off_heap_data(void) |
| |
| :rtype: void |
| |
| This should be called periodically to report memory usage that is |
| not part of the normal Emscripten heap. This is currently used |
| to report OpenAL memory usage. |
| |
| The current timestamp is associated with this data. |
| |
| *The server does not yet display this data.* |
| |
| .. c:function:: void emscripten_trace_enter_context(const char *name) |
| |
| :param name: Context name. |
| :type name: const char* |
| :rtype: void |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_exit_context(void) |
| |
| :rtype: void |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_task_start(int task_id, const char *name); |
| |
| :param task_id: Task ID |
| :type task_id: int |
| :param name: Task name |
| :type name: const char* |
| :rtype: void |
| |
| A task is initiated. The task ID should be unique over the lifetime of |
| the application. It should be managed / tracked by the application. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_task_associate_data(const char *key, const char *value); |
| |
| :param key: Key |
| :type key: const char* |
| :param value: Value |
| :type value: const char* |
| :rtype: void |
| |
| Associate a key / value pair with the current task. |
| |
| .. c:function:: void emscripten_trace_task_suspend(const char *explanation); |
| |
| :param explanation: Why the task is suspending. |
| :type explanation: const char* |
| :rtype: void |
| |
| The current task is suspended. |
| |
| The explanation should indicate why the task is being suspended |
| so that this information can be made available when viewing the |
| task's history. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_task_resume(int task_id, const char *explanation); |
| |
| :param task_id: Task ID |
| :type task_id: int |
| :param explanation: Why the task is being resumed. |
| :type explanation: const char* |
| :rtype: void |
| |
| The task identified by ``task_id`` is resumed and made the current task. |
| |
| The explanation should indicate what the task is being resumed to do |
| so that this information can be made available when viewing the task's |
| history. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_task_end(void); |
| |
| :rtype: void |
| |
| The current task is ended. |
| |
| The current timestamp is associated with this data. |
| |
| .. c:function:: void emscripten_trace_close(void) |
| |
| :rtype: void |
| |
| This should be closed during application termination. It helps ensure |
| is flushed to the server and terminates the tracing code. |
| |
| .. _emscripten-trace-collector: https://github.com/waywardmonkeys/emscripten-trace-collector |
| .. _README.rst: https://github.com/waywardmonkeys/emscripten-trace-collector/blob/master/README.rst |
| .. _Google Web Tracing Framework: http://google.github.io/tracing-framework/ |
