Add compiler timing diagnostics to mjsCompiler, printed by compile.cc

For example, `compile mujoco_menagerie/robotis_op3/scene.xml` now outputs

```
Compile 1 (cold cache):
  total:      317.2 ms
  assets:     284.8 ms (wall clock)
    load:     616.1 ms
    hull:      26.4 ms
    poly:     137.8 ms
    inert:    177.8 ms
    bvh:      568.2 ms
    octr:       1.6 ms
    tex:       25.3 ms
  other:       32.4 ms

Compile 2 (warm cache):
  total:       79.9 ms
  assets:      54.5 ms (wall clock)
    load:     888.5 ms
    hull:       0.0 ms
    poly:       0.0 ms
    inert:      0.0 ms
    bvh:        0.0 ms
    octr:       0.0 ms
    tex:       21.4 ms
  other:       25.3 ms
```

PiperOrigin-RevId: 917850214
Change-Id: Iaec86230bec0faf2e47820e20cbff61de5b2621e

src/user/user_api.cc

@@ -427,6 +427,17 @@ const char* mjs_getError(mjSpec* s) {
 
 
 
+// get compiler timers from model
+const double* mjs_getTimer(mjSpec* s) {
+  if (!s) {
+    return nullptr;
+  }
+  mjCModel* modelC = static_cast<mjCModel*>(s->element);
+  return modelC->timer;
+}
+
+
+
 // check if model has warnings
 int mjs_isWarning(mjSpec* s) {
   mjCModel* modelC = static_cast<mjCModel*>(s->element);

src/user/user_mesh.cc

@@ -14,19 +14,18 @@
 
 #include <algorithm>
 #include <array>
+#include <chrono>
 #include <climits>
 #include <cmath>
 #include <csetjmp>
 #include <cstddef>
 #include <cstdio>
 #include <cstring>
-#include <deque>
 #include <functional>
 #include <limits>
 #include <map>
 #include <memory>
 #include <queue>
-#include <set>
 #include <string>
 #include <string_view>
 #include <unordered_map>
@@ -688,11 +687,17 @@ void mjCMesh::Compile(const mjVFS* vfs) {
 
 // compiler
 void mjCMesh::TryCompile(const mjVFS* vfs) {
+  using Clock = std::chrono::steady_clock;
+  using Seconds = std::chrono::duration<double>;
+  std::fill_n(mesh_timer_, mjNCTIMER, 0.0);
+
   bool fromCache = false;
   CopyFromSpec();
   visual_ = true;
   mjCCache *cache = reinterpret_cast<mjCCache*>(mj_getCache()->impl_);
 
+  Clock::time_point t0 = Clock::now();
+
   // load file
   if (!file_.empty()) {
     vert_.clear();
@@ -765,12 +770,13 @@ void mjCMesh::TryCompile(const mjVFS* vfs) {
     LoadSDF();  // create using marching cubes
   }
 
+  mesh_timer_[mjCTIMER_MESH_LOAD] = Seconds(Clock::now() - t0).count();
+
   CheckInitialMesh();
 
   // compute mesh properties
   if (!fromCache) {
     Process();
-
     if (!file_.empty()) {
       CacheMesh(cache, resource_);
     }
@@ -778,6 +784,7 @@ void mjCMesh::TryCompile(const mjVFS* vfs) {
     // When a mesh is loaded from the cache, has no octree but needs one,
     // we need to compute it here. If inversely it has an octree but we *do not*
     // need one, we clear it.
+    t0 = Clock::now();
     if (!needsdf) {
       octree_.Clear();
     } else if (octree_.NumNodes() == 0) {
@@ -789,6 +796,7 @@ void mjCMesh::TryCompile(const mjVFS* vfs) {
         octree_.ComputeSdfCoeffs(dvert.data(), nvert(), face_.data(), nface(), tree_);
       }
     }
+    mesh_timer_[mjCTIMER_MESH_OCTREE] = Seconds(Clock::now() - t0).count();
   }
 
   // close resource
@@ -1341,7 +1349,9 @@ double mjCMesh::ComputeFaceCentroid(double facecen[3], const double* dvert) cons
 
 void mjCMesh::Process() {
   std::vector<double> dvert(vert_.begin(), vert_.end());
-
+  using Clock = std::chrono::steady_clock;
+  using Seconds = std::chrono::duration<double>;
+  Clock::time_point t0;
   // create half-edge structure (if mesh was in XML)
   if (halfedge_.empty()) {
     for (int i = 0; i < nface(); i++) {
@@ -1370,6 +1380,7 @@ void mjCMesh::Process() {
     }
   }
 
+  t0 = Clock::now();
   // make graph describing convex hull
   if (needhull_ || face_.empty()) {
     MakeGraph(dvert.data());
@@ -1379,7 +1390,9 @@ void mjCMesh::Process() {
   if (face_.empty()) {
     CopyGraph();
   }
+  mesh_timer_[mjCTIMER_MESH_HULL] += Seconds(Clock::now() - t0).count();
 
+  t0 = Clock::now();
   // no normals: make
   if (normal_.empty()) {
     MakeNormal(dvert.data());
@@ -1424,6 +1437,9 @@ void mjCMesh::Process() {
     }
   }
 
+  mesh_timer_[mjCTIMER_MESH_POLYGON] += Seconds(Clock::now() - t0).count();
+
+  t0 = Clock::now();
   // user offset, rotation, scaling
   ApplyTransformations(dvert.data());
 
@@ -1519,7 +1535,9 @@ void mjCMesh::Process() {
 
   // recompute polygon normals
   MakePolygonNormals(dvert.data());
+  mesh_timer_[mjCTIMER_MESH_INERTIA] += Seconds(Clock::now() - t0).count();
 
+  t0 = Clock::now();
   // make bounding volume hierarchy
   if (tree_.Bvh().empty()) {
     face_aabb_.clear();
@@ -1530,7 +1548,9 @@ void mjCMesh::Process() {
     }
     tree_.CreateBVH();
   }
+  mesh_timer_[mjCTIMER_MESH_BVH] += Seconds(Clock::now() - t0).count();
 
+  t0 = Clock::now();
   // make octree
   if (needsdf) {
     octree_.SetFace(dvert, face_);
@@ -1546,6 +1566,7 @@ void mjCMesh::Process() {
   for (int i = 0; i < (int)dvert.size(); i++) {
     vert_[i] = (float)dvert[i];
   }
+  mesh_timer_[mjCTIMER_MESH_OCTREE] += Seconds(Clock::now() - t0).count();
 }
 
 

src/user/user_model.cc

@@ -16,7 +16,7 @@
 
 #include <algorithm>
 #include <array>
-#include <atomic>
+#include <chrono>
 #include <cmath>
 #include <csetjmp>
 #include <cstdint>
@@ -662,7 +662,6 @@ mjCModel& mjCModel::operator+=(mjCDef& subtree) {
 
 // remove default class from array
 mjCModel& mjCModel::operator-=(const mjCDef& subtree) {
-
   // check we aren't trying to remove the 'main' default
   if (subtree.id == 0) {
     throw mjCError(0, "cannot remove the global default ('main')");
@@ -922,7 +921,7 @@ void mjCModel::ComputeSparseSizes() {
 
   // 1. build dof_parentid, dof_bodyid
   if (nbody > 0) {
-    body_lastdof_map[0] = -1; // world has no parent dof
+    body_lastdof_map[0] = -1;  // world has no parent dof
   }
   for (int i = 0; i < nbody; ++i) {
     mjCBody* pb = bodies_[i];
@@ -961,7 +960,7 @@ void mjCModel::ComputeSparseSizes() {
   nD = 2 * nM - nv;
 
   // 4. compute subtreedofs and nB
-  for(int i = nbody - 1; i >= 0; --i) {
+  for (int i = nbody - 1; i >= 0; --i) {
     bodies_[i]->subtreedofs = bodies_[i]->dofnum;
     for (const auto* child : bodies_[i]->Bodies()) {
       bodies_[i]->subtreedofs += child->subtreedofs;
@@ -984,7 +983,7 @@ void mjCModel::ComputeSparseSizes() {
   }
 
   // 5. compute nC
-  for(int i = 0; i < nbody; ++i) {
+  for (int i = 0; i < nbody; ++i) {
     mjCBody* pb = bodies_[i];
     mjCBody* par = pb->parent;
     int parentid = par ? par->id : 0;
@@ -4744,10 +4743,13 @@ static void CompileMesh(mjCMesh* mesh, const mjVFS* vfs,
 static void CompileTexture(mjCTexture* texture, const mjVFS* vfs,
                            std::exception_ptr& exception,
                            std::mutex& exception_mutex, std::string* warningtext) {
+  using Clock = std::chrono::steady_clock;
+  using Seconds = std::chrono::duration<double>;
   local_warningtext_ptr = warningtext;
   auto previous_handler = _mjPRIVATE__get_tls_warning_fn();
   _mjPRIVATE__set_tls_warning_fn(warninghandler);
 
+  Clock::time_point t0 = Clock::now();
   try {
     texture->Compile(vfs);
   } catch (...) {
@@ -4756,6 +4758,7 @@ static void CompileTexture(mjCTexture* texture, const mjVFS* vfs,
       exception = std::current_exception();
     }
   }
+  texture->texture_time_ = Seconds(Clock::now() - t0).count();
 
   _mjPRIVATE__set_tls_warning_fn(previous_handler);
   local_warningtext_ptr = nullptr;
@@ -4843,6 +4846,15 @@ void mjCModel::CompileMeshesAndTextures(const mjVFS* vfs) {
   if (texture_exception) {
     std::rethrow_exception(texture_exception);
   }
+
+  for (int i = 0; i < nmesh; i++) {
+    for (int t = 0; t < mjNCTIMER; t++) {
+      timer[t] += meshes_[i]->mesh_timer_[t];
+    }
+  }
+  for (int i = 0; i < ntexture; i++) {
+    timer[mjCTIMER_TEXTURE] += textures_[i]->texture_time_;
+  }
 }
 
 // compute qpos0
@@ -4984,6 +4996,12 @@ void mjCModel::TryCompile(mjModel*& m, mjData*& d, const mjVFS* vfs) {
   } disable_usethread(compiler.usethread);
 #endif
 
+  using Clock = std::chrono::steady_clock;
+  using Seconds = std::chrono::duration<double>;
+  for (int i=0; i < mjNCTIMER; i++) {
+    timer[i] = 0;
+  }
+  Clock::time_point timer_start = Clock::now();
   // check if nan test works
   double test = mjNAN;
   if (mjuu_defined(test)) {
@@ -5085,7 +5103,11 @@ void mjCModel::TryCompile(mjModel*& m, mjData*& d, const mjVFS* vfs) {
   SetNuser();
 
   // compile meshes and textures (needed for geom compilation)
-  CompileMeshesAndTextures(vfs);
+  {
+    Clock::time_point t0 = Clock::now();
+    CompileMeshesAndTextures(vfs);
+    timer[mjCTIMER_ASSETS] = Seconds(Clock::now() - t0).count();
+  }
 
   // compile objects in kinematic tree
   for (int i=0; i < bodies_.size(); i++) {
@@ -5359,6 +5381,8 @@ void mjCModel::TryCompile(mjModel*& m, mjData*& d, const mjVFS* vfs) {
   // save signature
   m->signature = Signature();
 
+  timer[mjCTIMER_TOTAL] = Seconds(Clock::now() - timer_start).count();
+
   // special cases that are not caused by user edits
   if (compiler.fusestatic || compiler.discardvisual ||
       !pairs_.empty() || !excludes_.empty()) {

src/user/user_model.h

@@ -198,6 +198,7 @@ class mjCModel : public mjCModel_, private mjSpec {
   mjCModel& operator-=(const mjCDef& subtree);    // remove default tree from this model
 
   mjSpec spec;
+  double timer[mjNCTIMER] = {0};                  // compiler timers
 
   mjModel* Compile(const mjVFS* vfs = nullptr, mjModel** m = nullptr);  // construct mjModel
   bool CopyBack(const mjModel*);                 // DECOMPILER: copy numeric back

src/user/user_objects.h

@@ -1133,6 +1133,7 @@ class mjCMesh_ : public mjCBase {
 
   // octree
   mjCOctree octree_;                  // octree of the mesh
+  double mesh_timer_[mjNCTIMER] = {0};
 };
 
 class mjCMesh: public mjCMesh_, private mjsMesh {
@@ -1465,6 +1466,7 @@ class mjCTexture : public mjCTexture_, private mjsTexture {
   void PointToLocal(void);
   void NameSpace(const mjCModel* m);
   void Compile(const mjVFS* vfs);
+  double texture_time_ = 0;
 
   std::string File() const { return file_; }
   std::string get_content_type() const { return content_type_; }