Closed nunoguedelha closed 1 year ago
yarp_logging
yarp_logging Logging with YARP
YARP has an internal mechanism to help you debug your distributed application.
While you can simply use
printf
orstd::cout
methods to debug your application locally, if you use the functionalities offered, YARP will collect and show several additional information, including system and network time, file, line, thread id, etc., and eventually forward them to [yarplogger](@ref yarplogger).YARP is also able to detect if it is running on a console or inside [yarprun](@ref yarprun) and if the application output is forwarded to [yarplogger](@ref yarplogger) (using the
--log
option), and change its output accordingly, so that the extra information is forwarded properly.When the log is forwarded over the network, the logging process opens a yarp port with the following syntax:
/log/hostname/processname/pid
. NOTE: If yarprun is used, hostname is replaced by the name of yarprun server.
User can set
YARP_LOG_PROCESS_LABEL
to specify a string which can help in identifying the process which is currently broadcasting the log over the network. The string will be appended after the process name in the log port and included between two square brackets, i.e./log/hostname/processname[user_label]/pid
. A typical use case for this environment variable is when multiple [yarprobotinterface](@ref yarprobotinterface) and/or [yarpdev](@ref yarpdev) are running simultaneously. In this case, the name log ports are difficult to interpret, since the process name alone is not enough to identify them. In this case the user can set a custom label for each of them to better distinguish them in the [yarplogger](@ref yarplogger) gui.YARP_LOG_PROCESS_LABEL
can be easily set for each individual process, via [yarpmanager](@ref yarpmanager), using theenvironment
section.
By default, the logging callback prints the output on the
stdout
/stderr
. When a YARP program is started by [yarprun --log](@ref yarprun), this will forward the output on a YARP port that can be read by [yarplogger](@ref yarplogger), and displayed.This behaviour can be obtained also without [yarprun](@ref yarprun), by setting the
YARP_FORWARD_LOG_ENABLE
environment variable to1
. Please note that, while [yarprun](@ref yarprun) is able to forward all the output of the application (includingprintf
andstd::out
output), this method will forward only the output using YARP log utilities.At the moment, not all the information gathered is forwarded. It is possible to enable them by using the following environment variables:
YARP_FORWARD_CODEINFO_ENABLE
YARP_FORWARD_HOSTNAME_ENABLE
YARP_FORWARD_PROCESSINFO_ENABLE
YARP_FORWARD_BACKTRACE_ENABLE
Please note that
yarp::os
internal logging is never forwarded, since this could cause recursions that will crash the program.
For now, we shall only use the variables YARP_FORWARD_LOG_ENABLE=1
and :
YARP_LOG_PROCESS_LABEL=YarpJS_WholeBodyDynamics
at the step 5 of https://github.com/ami-iit/yarp-openmct#how-to-run-the-telemetry-visualization-tool-arrow_up :
YARP_CLOCK=/clock YARP_LOG_PROCESS_LABEL=YarpJS_WholeBodyDynamics yarprobotinterface YARP_FORWARD_LOG_ENABLE=1 --config launch-wholebodydynamics.xml
YARP_LOG_PROCESS_LABEL=YarpJS_WalkingModule
at step 6 of https://github.com/ami-iit/yarp-openmct#how-to-run-the-telemetry-visualization-tool-arrow_up :
YARP_CLOCK=/clock YARP_LOG_PROCESS_LABEL=YarpJS_WalkingModule YARP_FORWARD_LOG_ENABLE=1 WalkingModule
The YARP_FORWARD_LOG_ENABLE=1
setting is working properly, I'm able to connect to the respective logging ports and stream the expected messages.
The YARP_LOG_PROCESS_LABEL
variable is not having any effect on the port name. This is probably because I was using an old YARP version older than 3.5.1, while 3.5.1 includes the commit https://github.com/robotology/yarp/tree/64beef5720bedd3ecca59d6a315a6fb7124047c5 .
So I tried updating my setup, installing a recent superbuild (binary installation). I'm having some issues installing the whole barraca due to some cross-dependencies on Conda. I will discuss with @traversaro offline about this.
@traversaro , at the end I was able to install Gazebo 11.11.0, after:
The installation of Robotology packages was successful, but I'm now encountering a new issue with Gazebo, unrelated to Robotology packages. Every time I try to insert any model (even native Gazebo models), it simply disappears right away:
gazebo --verbose
insert
tab on the left paneArm Part
model (for instance)No debug, warning nor error message is printed on the terminal.
When previously installing Gazebo with conda, I got the warning message:
...
Preparing transaction: done
Verifying transaction: done
Executing transaction: \ objc[39523]: Class GNotificationCenterDelegate is implemented in both /Users/nunoguedelha/miniforge3/envs/robotologybin/lib/libgio-2.0.0.dylib (0x103bc1bc0) and /usr/local/opt/glib/lib/libgio-2.0.0.dylib (0x104109330). One of the two will be used. Which one is undefined.
- objc[39594]: Class GNotificationCenterDelegate is implemented in both /Users/nunoguedelha/miniforge3/envs/robotologybin/lib/libgio-2.0.0.dylib (0x1065a9bc0) and /usr/local/opt/glib/lib/libgio-2.0.0.dylib (0x106aeb330). One of the two will be used. Which one is undefined.
done
but it doesn't seem to be related to my issue.
updating conda to 4.14.0 (although you mentioned it shouldn't matter in this case, but maybe same base package was causing a conflict and resulting in a crash of Gazebo)
In theory no package in the base environment should be used by Gazebo . Anyhow, perhaps something strange was going on.
Are you able to run models by spawning an existing world?
Are you able to run models by spawning an existing world?
As discussed in Teams, yes I can, but I can't add other models from the GUI. As @traversaro noticed, it seems that the client is not connected to the server. refer to https://github.com/conda-forge/gazebo-feedstock/issues/148 submitted by @traversaro .
As this issue prevents running Gazebo ≥ 11.10.1, and installing/running Gazebo < 11.10.1 prevents running the gazebo-yarp-plugins
and yarp
versions required for getting the proper handling of the YARP_LOG_PROCESS_LABEL
variable, I'm proceeding without it for now.
As this issue prevents running Gazebo ≥ 11.10.1, and installing/running Gazebo < 11.10.1 prevents running the
gazebo-yarp-plugins
andyarp
versions required for getting the proper handling of theYARP_LOG_PROCESS_LABEL
variable, I'm proceeding without it for now.
A possible alternative is to compile yarp and gazebo-yarp-plugins from source with gazebo 11.9, right? Anyhow, if it is not worth the trouble no problem.
Indeed, but I wanted to avoid building from source to make it quicker 😄 , at the end it was worse.. well, I'll give a shot to building from source.
Side note: it would be interesting to build Gazebo from source, installing the dependencies through Conda. This requires significant effort rewriting the CMake files.
Side note: it would be interesting to build Gazebo from source, installing the dependencies through Conda. This requires significant effort rewriting the CMake files.
I actually did this, I do not think there is any modification required in CMake files, see https://github.com/conda-forge/gazebo-feedstock/issues/148#issuecomment-1240321643 .
Awesome, thanks @traversaro ! I wasn't aware of this.
CC @S-Dafarra
well, I'll give a shot to building from source.
I built the superbuild from source and installed Gazebo 11.9.1 on the same conda environment. I ran Gazebo and as soon as I insert an iCub model, I get this protobuf error:
[libprotobuf ERROR google/protobuf/descriptor_database.cc:559] Invalid file descriptor data passed to EncodedDescriptorDatabase::Add().
[libprotobuf FATAL google/protobuf/descriptor.cc:1357] CHECK failed: GeneratedDatabase()->Add(encoded_file_descriptor, size):
libc++abi.dylib: terminating with uncaught exception of type google::protobuf::FatalException: CHECK failed: GeneratedDatabase()->Add(encoded_file_descriptor, size):
I'll open an issue on the superbuild repo.
I'll open an issue on the superbuild repo.
https://github.com/robotology/robotology-superbuild/issues/1253
Moving on...
I list below the steps for getting the Yarprobotinterface and WalkingController modules logging output on the OpenMCT visualizer.
In a first step we focus on the data parsing and sending to the visualizer, the dictionary definition and the actual data visualisation in the OpenMCT framework. For this purpose, the port names are fully defined in the configuration file servers.js
, and edited every time the processes logging the data (yarprobotinterface
, WalkingModule
) are stopped and run again.
In the configuration file:
On the telemetry server:
state
buffer.On OpenMCT framework:
In the configuration file:
On the telemetry server:
On the telemetry server:
[ ] Connect the Yarp text logging ports as soon as a subscription is received from the OpenMCT client:
- [ ] Get the list of Yarp ports
- [ ] Select the ports matching the process labels set in the main configuration.
- [ ] Open the ports and connect.
I've worked on the design of this part, but it needs further analysis/improvement. I've decided to manually add the YARP ports in the config file for now and proceed with the development steps (parsing, dictionary & OpenMCT changes, etc).
Updated the Implementation Steps.
yarprobotinterface
or WalkingModule
).(we are not breaking nor on the supportsSubscribe
nor subscribe
methods.
Analysing...
I've checked the Vue.js components bound to the telemetry domain objects, and compared a working case with the failing case, e.g. comparing yarpopenmct.icubtelemetry:sens.legacyIMU
to yarpopenmct.processLogging:yarplogger.yarpRobotInterface
:
yarpopenmct.icubtelemetry:sens.legacyIMU
yarpopenmct.processLogging:yarplogger.yarpRobotInterface
domainObject.telemetry.values
hasn't been evaluated (expanded), we still see the unexpanded string ${JSON.stringify(this.presetValuesBase.yarpLoggerMessage)}
.
This is because the dictionary file was retrieved through an http request, and no route function was added through app.get
on the server side to "evaluate" the file (evaluate template literals through evalTemplateLiteralInJSON
) prior sending it.
After fixing this issue, clicking on the domain object "yarprobotinterface process logging through yarplogger" triggers a subscription and the logging data stream is established. We can see the data displayed in the canvas, in the "telemetry table" view:
After creating a "Telemetry Table" domain object in "My Items", dragging into it the "yarprobotinterface process logging through yarplogger" and arranging the table to display the more relevant data, we get:
Next step is to display messages only when they are received from the Yarp port, instead of repeating the last received message.
Next step is to display messages only when they are received from the Yarp port, instead of repeating the last received message.
=> completed in commit 126edf941d1448ba552ce3820859a1df3242c69b. (adding details shortly)
Work now on the automatic port detection.
We added a sourceSync
parameter to the portInConfig
port configuration portInConfig
, with two possible values, localTimer
or yarpPort
.
localTimer
This was the default setting so far for which a notifierTask
is triggered by a local timer every 10 ms and calls generateTelemetry
which generates and sends the telemetry samples. The task used to send the samples for all the telemetry IDs in the ICubTelemetry.state
buffer.
Change => The task sends the samples of the IDs scheduled for sending in ICubTelemetry.telemetryIDsToSend
. Upon a call of the "read" listener, the Yarp message is parsed and the respective ID scheduled for sending.
https://github.com/ami-iit/yarp-openmct/blob/126edf941d1448ba552ce3820859a1df3242c69b/iCubTelemVizServer/iCubTelemVizServer.js#L87-L89 => https://github.com/ami-iit/yarp-openmct/blob/126edf941d1448ba552ce3820859a1df3242c69b/iCubTelemVizServer/icubtelemetry.js#L161 => https://github.com/ami-iit/yarp-openmct/blob/126edf941d1448ba552ce3820859a1df3242c69b/iCubTelemVizServer/icubtelemetry.js#L148-L151
...
yarpPort
The notifierTask
is not used. Upon the call of the "read" listener, the Yarp message is parsed and the respective ID is directly sent.
YARP_LOG_PROCESS_LABEL
of his choice for matching the ports streaming the logging data fromyarprobotinterface
and WalkingModule
modules.[^*]: The syntax is as follows: the pattern "@{...}"
wraps a regular expression which, once unwrapped, can be directly interpreted by the Javascript code.
(Re)connect the Yarp text logging ports as soon as the client page is refreshed (servers.json config is reloaded)
servers.json
route function.~<regexp-port-names-list>
.<regexp-port-names-list>
is empty, return, otherwise continue.<yarp-ports-list>
.<regexp-port-names-list>
, get the Yarp port name from <yarp-ports-list>
matching the regexp pattern => <matched-yarp-remote-ports-list>
.<matched-yarp-remote-ports-list>
:
<yarpjs-local-port>
port exists => if not, create it.~ We consider that these didn't change, otherwise just restart the telemetry server.<yarp-remote-port>
to <yarpjs-local-port>
(if the connection already exists, this step does nothing).servers.json
route function (nice-to-have)[ ] Trigger the regexp ports reconnection in the config file
servers.json
route function (nice-to-have)
@S-Dafarra , this is very useful, but not a blocker. Without this you have to restart the server if the remote yarp text logging ports are closed and opened again (with different PIDs).
You can already perform some tests the development branch feature/ami138-visualise-yarptextlogging
.
Work completed.
Some modules can forward their execution log to the Yarplogger through a Yarp port. We could visualise the logged data on OpenMCT. Refer to the discussion referenced below:
Originally posted by @S-Dafarra in https://github.com/ami-iit/yarp-openmct/issues/121#issuecomment-1180685833
Originally posted by @GiulioRomualdi in https://github.com/ami-iit/yarp-openmct/issues/121#issuecomment-1182455351
Originally posted by @nunoguedelha in https://github.com/ami-iit/yarp-openmct/issues/121#issuecomment-1235252330
For the development, we relate to the analysis done in https://github.com/ami-iit/bipedal-locomotion-framework/pull/540 .