RobotLocomotion / drake

Model-based design and verification for robotics.
https://drake.mit.edu
Other
3.25k stars 1.25k forks source link

//bindings/pydrake/visualization:py/model_visualizer_test failure in CI #19415

Closed ggould-tri closed 1 year ago

ggould-tri commented 1 year ago

What happened?

CI failure on linux-focal-unprovisioned-clang-bazel-nightly-debug: https://drake-jenkins.csail.mit.edu/view/Production/job/linux-focal-unprovisioned-clang-bazel-nightly-debug/757/consoleFull

Initial glance suggests a network transient; this will be auto-closed until it recurs per policy.

Version

No response

What operating system are you using?

Ubuntu 20.04

What installation option are you using?

compiled from source code using Bazel

Relevant log output

[2:48:51 AM]  ==================== Test output for //bindings/pydrake/visualization:py/model_visualizer_test:
[2:48:51 AM]  
[2:48:51 AM]  Running tests...
[2:48:51 AM]  ----------------------------------------------------------------------
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7000
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7001
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7002
[2:48:51 AM]  INFO:drake:Meshcat listening for connections at http://localhost:7003
[2:48:51 AM]  INFO:drake:Meshcat listening for connections at http://localhost:7004
[2:48:51 AM]  INFO:drake:Meshcat listening for connections at http://localhost:7005
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7006
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7007
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7008
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7009
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7010
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7011
[2:48:51 AM]  [2023-05-16 06:48:34,464] [meshcat_websocket_client] [INFO] Connecting...
[2:48:51 AM]  [2023-05-16 06:48:34,472] [meshcat_websocket_client] [INFO] ... connected
[2:48:51 AM]  [2023-05-16 06:48:34,472] [meshcat_websocket_client] [INFO] Sending...
[2:48:51 AM]  [2023-05-16 06:48:34,472] [meshcat_websocket_client] [INFO] ... sent
[2:48:51 AM]  [2023-05-16 06:48:34,472] [meshcat_websocket_client] [INFO] Disconnecting...
[2:48:51 AM]  [2023-05-16 06:48:34,476] [meshcat_websocket_client] [INFO] ... disconnected
[2:48:51 AM]  INFO:drake:Reload was successful
[2:48:51 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7012
[2:48:51 AM]  ..INFO:drake:Meshcat listening for connections at http://localhost:7012
[2:48:51 AM]  .drake/multibody/benchmarks/acrobot/acrobot.sdf
[2:48:51 AM]  INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  drake/multibody/benchmarks/acrobot/acrobot.urdf
[2:48:51 AM]  INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  drake/manipulation/util/test/simple_nested_model.sdf
[2:48:51 AM]  INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  drake/manipulation/util/test/simple_world_with_two_models.sdf
[2:48:51 AM]  INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  .INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  .INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  .drake/multibody/benchmarks/acrobot/acrobot.sdf
[2:48:51 AM]  INFO: Meshcat listening for connections at http://localhost:7014
[2:48:51 AM]  drake/multibody/benchmarks/acrobot/acrobot.urdf
[2:48:51 AM]  INFO: Meshcat listening for connections at http://localhost:7013
[2:48:51 AM]  [*** LOG ERROR #0001 ***] [2023-05-16 06:48:50] [console] {Unknown exception in logger}
[2:48:51 AM]  FATAL: exception not rethrown
[2:48:51 AM]  E
[2:48:51 AM]  ======================================================================
[2:48:51 AM]  ERROR [3.819s]: test_set_position (model_visualizer_test.TestModelVisualizerSubprocess)
[2:48:51 AM]  Test that the --position option doesn't crash.
[2:48:51 AM]  ----------------------------------------------------------------------
[2:48:51 AM]  Traceback (most recent call last):
[2:48:51 AM]    File "/media/ephemeral0/ubuntu/workspace/linux-focal-unprovisioned-clang-bazel-nightly-debug/_bazel_ubuntu/a932ec712c8398859de59d8e3b493f98/sandbox/linux-sandbox/11960/execroot/drake/bazel-out/k8-dbg/bin/bindings/pydrake/visualization/py/model_visualizer_test.runfiles/drake/bindings/pydrake/visualization/test/model_visualizer_test.py", line 70, in test_set_position
[2:48:51 AM]      subprocess.check_call([self.dut, self.model_file(model_runpath),
[2:48:51 AM]    File "/usr/lib/python3.8/subprocess.py", line 364, in check_call
[2:48:51 AM]      raise CalledProcessError(retcode, cmd)
[2:48:51 AM]  subprocess.CalledProcessError: Command '['/media/ephemeral0/ubuntu/workspace/linux-focal-unprovisioned-clang-bazel-nightly-debug/_bazel_ubuntu/a932ec712c8398859de59d8e3b493f98/sandbox/linux-sandbox/11960/execroot/drake/bazel-out/k8-dbg/bin/bindings/pydrake/visualization/py/model_visualizer_test.runfiles/drake/bindings/pydrake/visualization/model_visualizer', '/media/ephemeral0/ubuntu/workspace/linux-focal-unprovisioned-clang-bazel-nightly-debug/_bazel_ubuntu/a932ec712c8398859de59d8e3b493f98/sandbox/linux-sandbox/11960/execroot/drake/bazel-out/k8-dbg/bin/bindings/pydrake/visualization/py/model_visualizer_test.runfiles/drake/multibody/benchmarks/acrobot/acrobot.urdf', '--loop_once', '--position', '0.1', '0.2']' died with <Signals.SIGABRT: 6>.
[2:48:51 AM]  
[2:48:51 AM]  ----------------------------------------------------------------------
[2:48:51 AM]  Ran 17 tests in 21.028s
[2:48:51 AM]  
[2:48:51 AM]  FAILED (errors=1)
ggould-tri commented 1 year ago

This occurred during a time we later found to have network problems for our CI machines, so it is likely that this was spurious.

BetsyMcPhail commented 1 year ago

There was a similar failure on 5/24 --> https://drake-jenkins.csail.mit.edu/job/linux-jammy-gcc-bazel-continuous-release/1378

[12:32:40 PM]  ==================== Test output for //bindings/pydrake/visualization:py/model_visualizer_test:
[12:32:40 PM]  Matplotlib created a temporary config/cache directory at /tmp/matplotlib-9xkwv36m because the default path (/home/ubuntu/.config/matplotlib) is not a writable directory; it is highly recommended to set the MPLCONFIGDIR environment variable to a writable directory, in particular to speed up the import of Matplotlib and to better support multiprocessing.
[12:32:40 PM]  
[12:32:40 PM]  Running tests...
[12:32:40 PM]  ----------------------------------------------------------------------
[12:32:40 PM]  .INFO:drake:Meshcat listening for connections at http://localhost:7010/
[12:32:40 PM]  X Error of failed request:  BadValue (integer parameter out of range for operation)
[12:32:40 PM]    Major opcode of failed request:  130 (MIT-SHM)
[12:32:40 PM]    Minor opcode of failed request:  3 (X_ShmPutImage)
[12:32:40 PM]    Value in failed request:  0x5c0
[12:32:40 PM]    Serial number of failed request:  46
[12:32:40 PM]    Current serial number in output stream:  47
BetsyMcPhail commented 1 year ago

5/31 failure --> https://drake-jenkins.csail.mit.edu/view/Continuous%20Production/job/linux-jammy-gcc-bazel-continuous-release/1389/

Running tests...
----------------------------------------------------------------------
.INFO:drake:Meshcat listening for connections at http://localhost:7003
X Error of failed request:  BadValue (integer parameter out of range for operation)
  Major opcode of failed request:  130 (MIT-SHM)
  Minor opcode of failed request:  3 (X_ShmPutImage)
  Value in failed request:  0x5c0
  Serial number of failed request:  46
  Current serial number in output stream:  47

//bindings/pydrake/visualization:py/model_visualizer_test                FAILED in 1.8s
BetsyMcPhail commented 1 year ago

6/1 failure --> https://drake-jenkins.csail.mit.edu/job/linux-focal-gcc-bazel-continuous-everything-release/4299/

[11:14:45 AM]  FAIL: //bindings/pydrake/visualization:py/model_visualizer_test (see /media/ephemeral0/ubuntu/workspace/linux-focal-gcc-bazel-continuous-everything-release/_bazel_ubuntu/8b3a9a7e3ae2948e044e489275837ba3/execroot/drake/bazel-out/k8-opt/testlogs/bindings/pydrake/visualization/py/model_visualizer_test/test.log)
[11:14:45 AM]  [37,940 / 37,955] 6515 / 6555 tests, 1 failed; Testing //bindings/pydrake/examples:py/manipulation_station_test; 7s remote-cache, linux-sandbox ... (28 actions running)
[11:14:45 AM]  INFO: From Testing //bindings/pydrake/visualization:py/model_visualizer_test:
[11:14:45 AM]  ==================== Test output for //bindings/pydrake/visualization:py/model_visualizer_test:
[11:14:45 AM]  
[11:14:45 AM]  Running tests...
[11:14:45 AM]  ----------------------------------------------------------------------
[11:14:45 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7001/
[11:14:45 AM]  Failed to create /home/ubuntu/.cache/mesa_shader_cache for shader cache (Read-only file system)---disabling.
[11:14:45 AM]  X Error of failed request:  BadValue (integer parameter out of range for operation)
[11:14:45 AM]    Major opcode of failed request:  130 (MIT-SHM)
[11:14:45 AM]    Minor opcode of failed request:  3 (X_ShmPutImage)
[11:14:45 AM]    Value in failed request:  0x5c0
[11:14:45 AM]    Serial number of failed request:  45
[11:14:45 AM]    Current serial number in output stream:  46
BetsyMcPhail commented 1 year ago

6/9 failure --> https://drake-jenkins.csail.mit.edu/view/Nightly%20Production/job/linux-focal-clang-bazel-nightly-everything-release/1105/

[2:29:34 AM]  TIMEOUT: //bindings/pydrake/visualization:py/model_visualizer_test (Summary)
[2:29:34 AM]        /media/ephemeral0/ubuntu/workspace/linux-focal-clang-bazel-nightly-everything-release/_bazel_ubuntu/5c75e7d5b062695511c8ae0c5a72b8b8/execroot/drake/bazel-out/k8-opt/testlogs/bindings/pydrake/visualization/py/model_visualizer_test/test.log
[2:29:34 AM]  INFO: From Testing //bindings/pydrake/visualization:py/model_visualizer_test:
[2:29:34 AM]  ==================== Test output for //bindings/pydrake/visualization:py/model_visualizer_test:
[2:29:34 AM]  
[2:29:34 AM]  Running tests...
[2:29:34 AM]  ----------------------------------------------------------------------
[2:29:34 AM]  .INFO:drake:Meshcat listening for connections at http://localhost:7000/
[2:29:34 AM]  WARNING:drake:Meshcat ignored a 'no_such_type' event
[2:29:34 AM]  -- Test timed out at 2023-06-09 06:29:33 UTC --
DamrongGuoy commented 1 year ago

June 20, 2023 failure --> https://drake-jenkins.csail.mit.edu/view/Nightly%20Production/job/linux-focal-clang-bazel-nightly-everything-debug/795/consoleFull

[11:53:33 PM]  FAIL: //bindings/pydrake/visualization:py/model_visualizer_test (see /media/ephemeral0/ubuntu/workspace/linux-focal-clang-bazel-nightly-everything-debug/_bazel_ubuntu/c5b92c3367a0b0aefa4b049a3b942e27/execroot/drake/bazel-out/k8-dbg/testlogs/bindings/pydrake/visualization/py/model_visualizer_test/test.log)
[11:53:33 PM]  ==================== Test output for //bindings/pydrake/visualization:py/model_visualizer_test:
[11:53:33 PM]  
[11:53:33 PM]  Running tests...
[11:53:33 PM]  ----------------------------------------------------------------------
[11:53:33 PM]  .INFO:drake:Meshcat listening for connections at http://localhost:7000
[11:53:33 PM]  X Error of failed request:  BadValue (integer parameter out of range for operation)
[11:53:33 PM]    Major opcode of failed request:  130 (MIT-SHM)
[11:53:33 PM]    Minor opcode of failed request:  3 (X_ShmPutImage)
[11:53:33 PM]    Value in failed request:  0x5c0
[11:53:33 PM]    Serial number of failed request:  45
[11:53:33 PM]    Current serial number in output stream:  46
[11:53:33 PM]  ================================================================================
[11:53:33 PM]  INFO: From Testing //bindings/pydrake/visualization:py/model_visualizer_test:
jwnimmer-tri commented 1 year ago

We should factor the TestModelVisualizer.test_camera into a separate test program, and mark that program flaky = True. You can assign to me if you'd like me to do that.

DamrongGuoy commented 1 year ago

Assign to @jwnimmer-tri . Thank you!