Closed rob-mau closed 5 months ago
Can you add the mat file here?
cc @GiulioRomualdi
was able to replicate the issue in my setup. I noticed that once the logger is closed, the last timestamp appears to be a high number.
This is the first timestamp
>> robot_logger_device.FTs.r_foot_front_ft.timestamps(1)
ans =
10.5960
This is the second-to-last timestamp:
>> robot_logger_device.FTs.r_foot_front_ft.timestamps(end-1)
ans =
122.3720
However, the last one is
>> robot_logger_device.FTs.r_foot_front_ft.timestamps(end)
ans =
1.7086e+09
The device utilizes the YarpClock to obtain the time
I'm afraid it is something related to the clock when we destroy the device @traversaro
When pressing CTRL+C, the close
method should be called (see here, then here and finally here). I noticed that in the close
method we do not stop the acquisition thread. We probably should add a this->askToStop();
at the beginning of the close
method
Can you add the mat file here?
When pressing CTRL+C, the
close
method should be called (see here, then here and finally here). I noticed that in theclose
method we do not stop the acquisition thread. We probably should add athis->askToStop();
at the beginning of theclose
method
Nice catch! @rob-mau could you try to implement what @S-Dafarra suggests and open a PR for that :) ?
CC @nicktrem
When pressing CTRL+C, the
close
method should be called (see here, then here and finally here). I noticed that in theclose
method we do not stop the acquisition thread. We probably should add athis->askToStop();
at the beginning of theclose
method
Probably we should also substitute the default destructor adding a this->stop()
to make sure that the thread is stopped before starting to destroy stuff.
rob-mau could you try to implement what S-Dafarra suggests and open a PR for that :) ?
I have implemented the suggested changes and opened a PR. The problem still persists.
We may double-check the attachments levels as explained in https://github.com/robotology/robots-configuration/issues/377
We may double-check the attachments levels as explained in robotology/robots-configuration#377
I checked them, I fixed one of the detach level still the problem is there.
I noticed that when I press ctrl-c we got
^C[WARNING] |yarp.os.NetworkClock| Destroying network clock
[ERROR] [2024-04-15 11:45:01.780] [thread: 65590] [blf] [YarpSensorBridge::Impl::readAllJointSensors] Unable to read from IEncodersTimed interface, use previous measurement.
[ERROR] [2024-04-15 11:45:01.780] [thread: 65590] [blf] [YarpSensorBridge::Impl::readAllJointSensors] Unable to read from ITorqueControl interface, use previous measurement.
[ERROR] |yarp.device.multipleanalogsensorsclient| No data received in the last 1713170648.783669 seconds, timeout enabled.
[ERROR] |yarp.device.multipleanalogsensorsclient| Sensor of type ThreeAxisLinearAccelerometers with index 1 has non-MAS_OK status.
[ERROR] [2024-04-15 11:45:01.780] [thread: 65590] [blf] [YarpSensorBridge::Impl::readMASSensor] Unable to read from r_foot_rear_ft_imu, use previous measurement.
So the clock is destroyed while the thread is still running. As you can notice
[WARNING] |yarp.os.NetworkClock| Destroying network clock
is before
[ERROR] [2024-04-15 11:45:01.780] [thread: 65590] [blf] [YarpSensorBridge::Impl::readAllJointSensors] Unable to read from IEncodersTimed interface, use previous measurement.
I added a print at the beginning of the close
and detachAll
methods.
This is the trace. The clock is destroyed before the detachAll
is called. That could be the reason why @rob-mau didn't solve the problem https://github.com/ami-iit/bipedal-locomotion-framework/issues/812#issuecomment-1975200369
[WARNING] |yarp.os.NetworkClock| Destroying network clock
[INFO] |yarp.os.Network| Success: port-to-port persistent connection added.
[INFO] |yarp.os.impl.PortCoreInputUnit|/iiticublap261/yarprobotinterface/69520/clock:i| Removing input from /clock to /iiticublap261/yarprobotinterface/69520/clock:i
[INFO] |yarp.os.RFModule| [try 1 of 3] Trying to shut down.
[WARNING] Interrupt # 1 # received.
[INFO] Interrupt received. Stopping all running threads.
[INFO] All actions for action level 15 of startup phase started. Waiting for unfinished actions.
[INFO] All actions for action level 15 of startup phase finished.
[INFO] startup phase finished.
[INFO] run phase starting...
[INFO] |yarp.os.RFModule| RFModule closing.
[INFO] interrupt1 phase starting...
[INFO] interrupt1 phase finished.
[INFO] shutdown phase starting...
[INFO] Entering action level 2 of phase shutdown
[INFO] Executing detach action, level 2 on device yarp-robot-logger with parameters []
-----> detachAll
[INFO] All actions for action level 2 of shutdown phase started. Waiting for unfinished actions.
[INFO] All actions for action level 2 of shutdown phase finished.
[INFO] Entering action level 20 of phase shutdown
[INFO] Executing detach action, level 20 on device mas-remapper with parameters []
[INFO] All actions for action level 20 of shutdown phase started. Waiting for unfinished actions.
[INFO] All actions for action level 20 of shutdown phase finished.
[INFO] Closing device yarp-robot-logger
-----> close
Perhaps @traversaro and/or @randaz81 have some hints
I have noticed that the clock gets destroyed when calling removeClock
, which is done in NetworkBase::finiMinimum
I have noticed that the clock gets destroyed when calling
removeClock
, which is done inNetworkBase::finiMinimum
That is called by the destructor of the RFModule
I think I might have an idea. yarprobotinterface
is itself a RFModule
. When pressing CTRL-C, it sets the use of SystemClock
that in turns delete the Network clock
I guess that the problem is not the switch to the SystemClock
per-se. I guess that the big number arises because the network clock and the System clock might use a different epoch.
I guess that the problem is not the switch to the
SystemClock
per-se. I guess that the big number arises because the network clock and the System clock might use a different epoch.
From a theoretical perspective, I don't see anything preventing the two clocks from starting at different epochs 🤔
In our case, the network clock is generated by https://github.com/robotology/gazebo-yarp-plugins/tree/master/plugins/clock.
The content of the /clock
port is as follows:
0 1000000
0 2000000
0 3000000
0 4000000
0 5000000
...
when I start Gazebo.
As explained here, the first value represents seconds and the second represents nanoseconds. It starts from 0.0000000 s
. However, starting the network clock from the system clock might not be the correct solution, as the network clock, i.e., the Gazebo simulation, could quickly diverge from the system clock (realtime factor different from 1)
Talking with @S-Dafarra we thought that we could avoid saving the data if the difference between the current time instant and the previous one is greater than the threshold
Fixed by #839
cc @FabioBergonti
I would like to report a peculiar behavior of the
YARPRobotLoggerDevice
. If I run it withYARP_CLOCK
:and then I launch the
robot-log-visualizer
, the signal plot displays an excessively long time horizon (on the order of 1e9 seconds!).Conversely, when I launch the logger without
YARP_CLOCK
, the amplitude of the time window is consistent with the logger's execution time.