ovphysx_step_sync slows down with ovphysx_update_from_ovstage cycles

[EliasStoffels]

Library and Version

ovphysx 0.5.9, ovstage 0.1.0.346039

Operating System

Linux x86_64

Steps to Trigger Behavior

1. Create an ovphysx instance and an ovstage instance; attach a minimal seed scene.
2. Loop: remove the previous cycle's /Spawned_N USD reference (ovstage_population_remove_usd_reference, skip on the first iteration)-> author and add a freshly-named /Spawned_N+1 reference (ovstage_population_add_usd_reference_from_string)-> ovstage_population_apply_usd_changes-> ovstage_advance_write_floor -> ovphysx_update_from_ovstage (drains everything sealed so far) ->5x ovphysx_step_sync.
3. ovphysx_step_sync continuesly slows down and hangs around cycle 27.

Code Snippet to Reproduce Behavior

#include <chrono>
#include <cstdio>
#include <string>
#include <ovphysx/ovphysx.h>
#include <ovstage/ovstage.h>
#include <ovstage/ovstage_population.h>

using Clock = std::chrono::steady_clock;
static double us_since(Clock::time_point t0) {
    return std::chrono::duration<double, std::micro>(Clock::now() - t0).count();
}

static bool wait_pop(ovstage_instance_t* s, ovstage_population_enqueue_result_t r) {
    if (r.status != OVSTAGE_OK) return false;
    ovstage_population_op_wait_result_t w{};
    return ovstage_population_wait_op(s, r.op_index, OVSTAGE_TIMEOUT_INFINITE, &w) == OVSTAGE_OK;
}

static bool floor(ovstage_instance_t* s, ovstage_ordinal_t o) {
    ovstage_write_floor_desc_t d{};
    d.ordinal = o;
    d.scope = OVSTAGE_SCOPE_ALL;
    ovstage_enqueue_result_t r = ovstage_advance_write_floor(s, &d);
    if (r.status != OVSTAGE_OK) return false;
    ovstage_op_wait_result_t w{};
    return ovstage_wait_op(s, r.op_index, OVSTAGE_TIMEOUT_INFINITE, &w) == OVSTAGE_OK;
}

static std::string cube(const std::string& n) {
    return "#usda 1.0\n(\n    defaultPrim = \"" + n + "\"\n)\n\n"
           "def Cube \"" + n + "\" (\n"
           "    prepend apiSchemas = [\"PhysicsRigidBodyAPI\", \"PhysicsCollisionAPI\", \"PhysicsMassAPI\"]\n)\n{\n"
           "    double size = 1\n"
           "    double3 xformOp:translate = (0, 3, 0)\n"
           "    uniform token[] xformOpOrder = [\"xformOp:translate\"]\n"
           "    float physics:mass = 1\n"
           "}\n";
}

static bool add_ref(ovstage_instance_t* s, const std::string& usda, const std::string& tgt,
                     ovstage_population_usd_reference_handle_t* h) {
    ovx_string_t u{usda.c_str(), usda.size()};
    ovx_string_t t{tgt.c_str(), tgt.size()};
    return wait_pop(s, ovstage_population_add_usd_reference_from_string(s, u, t, h));
}

int main() {
    ovphysx_initialize();

    ovphysx_handle_t handle = 0;
    ovphysx_create_args args = OVPHYSX_CREATE_ARGS_DEFAULT;
    if (ovphysx_create_instance(&args, &handle).status != OVPHYSX_API_SUCCESS) return 1;

    ovstage_instance_desc_t d{};
    d.name = "repro";
    ovstage_instance_t* stage = nullptr;
    if (ovstage_create_instance(&d, &stage) != OVSTAGE_OK) return 1;

    ovstage_ordinal_t ord = 1;
    std::string meta = "#usda 1.0\n(\n    upAxis = \"Y\"\n    metersPerUnit = 1\n)\n";
    ovx_string_t metaStr{meta.c_str(), meta.size()};
    if (!wait_pop(stage, ovstage_population_open_usd_from_string(stage, metaStr, ord, 0.0, OVSTAGE_POPULATION_DOMAIN_PHYSICS))) return 1;
    if (!floor(stage, ord)) return 1;
    ++ord;

    std::string ground =
        "#usda 1.0\n(\n    defaultPrim = \"Ground\"\n)\n\n"
        "def Plane \"Ground\" (\n    prepend apiSchemas = [\"PhysicsCollisionAPI\"]\n)\n{\n"
        "    uniform token axis = \"Y\"\n    double width = 100\n    double length = 100\n}\n";
    ovstage_population_usd_reference_handle_t groundHandle{}, fallingHandle{}, spawnedHandle{};
    if (!add_ref(stage, ground, "/Ground", &groundHandle)) return 1;
    if (!add_ref(stage, cube("FallingCube"), "/FallingCube", &fallingHandle)) return 1;
    if (!wait_pop(stage, ovstage_population_apply_usd_changes(stage, ord))) return 1;
    if (!floor(stage, ord)) return 1;
    if (ovphysx_attach_ovstage(handle, stage, ord).status != OVPHYSX_API_SUCCESS) return 1;
    ++ord;

    for (int cycle = 1; cycle <= 40; ++cycle) {
        if (cycle > 1 && !wait_pop(stage, ovstage_population_remove_usd_reference(stage, spawnedHandle))) return 1;

        std::string name = "Spawned_" + std::to_string(cycle);
        if (!add_ref(stage, cube(name), "/" + name, &spawnedHandle)) return 1;
        if (!wait_pop(stage, ovstage_population_apply_usd_changes(stage, ord))) return 1;
        if (!floor(stage, ord)) return 1;

        ovstage_ordinal_range_t range{0, ord, false};
        if (ovphysx_update_from_ovstage(handle, range).status != OVPHYSX_API_SUCCESS) return 1;
        ++ord;

        double total_us = 0;
        for (int i = 0; i < 5; ++i) {
            Clock::time_point t0 = Clock::now();
            if (ovphysx_step_sync(handle, 1.0f / 60.0f).status != OVPHYSX_API_SUCCESS) return 1;
            total_us += us_since(t0);
        }

        fprintf(stderr, "cycle %2d avg_step_sync_us=%.0f\n", cycle, total_us / 5.0);
        fflush(stderr);
    }

    return 0;
}

Expected Behavior

Adding/removing singular prims to not have a significant effect on ovphysx_step_sync per call cost.

Actual Behavior

Ovphysx_step_sync's own per-call cost climbs from ~5.3ms (cycle 1) to ~9.0ms (cycle 26) before the cycle-27 hang, suggesting it's an accumulation error.

[AlesBorovicka]

Thanks for the report, I was able to reproduce the issue, it should be resolved in upcoming release (likely tomorrow):
cycle | 0.5.9 step_sync | 0.5.9 update | 0.5.10 step_sync | 0.5.10 update
------+-----------------+--------------+------------------+--------------
1 | 5.2 | 82.2 | 4.3 | 2.8
2 | 4.9 | 48.7 | 7.2 | 2.2
3 | 4.7 | 60.1 | 4.6 | 3.6
4 | 4.4 | 47.3 | 4.2 | 4.0
5 | 4.4 | 44.6 | 7.1 | 3.7
6 | 4.5 | 52.0 | 7.5 | 2.5
7 | 6.5 | 55.3 | 3.6 | 2.7
8 | 3.3 | 45.4 | 3.0 | 4.0
9 | 3.9 | 55.7 | 6.4 | 3.9
10 | 7.5 | 48.0 | 4.0 | 2.4
11 | 4.6 | 49.6 | 4.5 | 4.2
12 | 5.6 | 82.1 | 4.0 | 3.9
13 | 4.7 | 57.8 | 4.1 | 4.0
14 | 4.6 | 83.8 | 4.1 | 2.5
15 | 4.9 | 81.2 | 4.0 | 4.2
16 | 4.8 | 53.4 | 4.1 | 4.9
17 | 8.0 | 58.2 | 3.7 | 4.6
18 | 4.5 | 48.9 | 9.1 | 4.8
19 | 4.3 | 53.0 | 3.4 | 2.5
20 | 7.3 | 42.8 | 3.4 | 2.4
21 | 4.8 | 43.9 | 3.4 | 2.5
22 | 4.6 | 49.6 | 6.2 | 2.8
23 | 7.6 | 48.7 | 3.4 | 2.7
24 | 5.3 | 41.6 | 3.4 | 2.4
25 | 5.2 | 44.0 | 3.4 | 2.5
26 | 5.7 | 90.7 | 6.2 | 3.8
27 | 6.1 | 77.0 | 3.6 | 2.5
28 | 7.5 | 76.5 | 3.3 | 2.5
29 | 7.5 | 52.9 | 6.4 | 2.7
30 | 15.0 | 42.3 | 6.8 | 2.4
31 | hang | hang | 3.4 | 2.3
32 | hang | hang | 3.4 | 2.3
33 | hang | hang | 3.4 | 2.3
34 | hang | hang | 3.9 | 4.1
35 | hang | hang | 6.2 | 2.7
36 | hang | hang | 3.4 | 2.4
37 | hang | hang | 6.2 | 2.7
38 | hang | hang | 3.4 | 2.4
39 | hang | hang | 3.4 | 2.5
40 | hang | hang | 6.4 | 2.5

Sorry about the trouble! I am really glad that you reported the issue, we are trying to fixup this first release based on ovstage and setup some good perf baselines for the next minor release.

Thanks!
Ales