Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Add human readable date to logging formats #441

Merged
merged 2 commits into from
Mar 15, 2024

Conversation

Kaju-Bubanja
Copy link
Contributor

No description provided.

@Kaju-Bubanja
Copy link
Contributor Author

Kaju-Bubanja commented Nov 27, 2023

Some linters are failing, is there an autoformatter I can run on the diff?

Copy link
Contributor

@ahcorde ahcorde left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

there are some magic number thatwe should define as constant

include/rcutils/time.h Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
@clalancette
Copy link
Contributor

Some linters are failing, is there an autoformatter I can run on the diff?

Yes, if you run colcon test --packages-select rcutils locally, it will run the linters for you.

src/logging.c Outdated Show resolved Hide resolved
@Kaju-Bubanja
Copy link
Contributor Author

All good suggestions, I implemented them. I'm fighting with the linter now. When I try and run:

colcon test --packages-select rcutils
Starting >>> rcutils 
--- stderr: rcutils                     
Errors while running CTest
Output from these tests are in: /home/user/ros2_humble/build/rcutils/Testing/Temporary/LastTest.log
Use "--rerun-failed --output-on-failure" to re-run the failed cases verbosely.
---
Finished <<< rcutils [27.7s]	[ with test failures ]

Summary: 1 package finished [30.4s]
  1 package had stderr output: rcutils
  1 package had test failures: rcutils

I tried:

colcon test --packages-select --output-on-failure --rerun-failed rcutils

but only get unrecognized argument. I checked the LastTest.log but there is nothing there. How can I show the offending file/line?

@clalancette
Copy link
Contributor

but only get unrecognized argument. I checked the LastTest.log but there is nothing there. How can I show the offending file/line?

Try:

colcon test --event-handlers console_direct+ --packages-select rcutils

You can also look in log/latest_test/rcutils/stderr.log, which should also show the output.

@Kaju-Bubanja
Copy link
Contributor Author

Some linters are failing, is there an autoformatter I can run on the diff?

Yes, if you run colcon test --packages-select rcutils locally, it will run the linters for you.

What I meant with autoformatter is a tool, which will automatically change the format applying some standard stylesheet, so that the style conforms with the linters. I got the linter to output what it's doing with --event-handlers console_direct+ as you suggested, but there are a few issues. Is the current workflow indeed to manually fix issues which the linter brings up?

@clalancette
Copy link
Contributor

Is the current workflow indeed to manually fix issues which the linter brings up?

That's how I usually do it. I think you may be able to run ament_uncrustify --reformat to have it do some of the work for you.

@Kaju-Bubanja
Copy link
Contributor Author

Kaju-Bubanja commented Nov 27, 2023

Alright, thank you for the comment. I fixed the linting issues.

include/rcutils/time.h Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
Copy link
Collaborator

@fujitatomoya fujitatomoya left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Kaju-Bubanja can you add some test for this?

src/time.c Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
src/time.c Show resolved Hide resolved
src/logging.c Show resolved Hide resolved
@Kaju-Bubanja
Copy link
Contributor Author

I added some tests but I don't get why the zero time on the jenkins machine is 1969-12-31 16:00:00 instead of 1970-01-01 01:00:00. Anybody got an idea how to fix this? And also what timepoint I should use for the test? Is 100ns fine?

Copy link
Collaborator

@fujitatomoya fujitatomoya left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

a couple of comments.

src/time.c Outdated Show resolved Hide resolved
src/time.c Outdated Show resolved Hide resolved
Copy link
Contributor

@ahcorde ahcorde left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

tests are failing : rcutils.TestTimeFixture.test_rcutils_time_point_value_as_date_string

@Kaju-Bubanja
Copy link
Contributor Author

I added some tests but I don't get why the zero time on the jenkins machine is 1969-12-31 16:00:00 instead of 1970-01-01 01:00:00. Anybody got an idea how to fix this? And also what timepoint I should use for the test? Is 100ns fine?

Yeah because of this. Not really my domain

@fujitatomoya
Copy link
Collaborator

Yeah because of this. Not really my domain

@Kaju-Bubanja i think we need to set timezone explicitly during this test?

@Kaju-Bubanja
Copy link
Contributor Author

Yeah because of this. Not really my domain

@Kaju-Bubanja i think we need to set timezone explicitly during this test?

I checked tzinfo which says:

   The tzset() function initializes the tzname variable from the TZ
   environment variable.  This function is automatically called by
   the other time conversion functions that depend on the timezone.
   In a System-V-like environment, it will also set the variables
   timezone (seconds West of UTC) and daylight (to 0 if this
   timezone does not have any daylight saving time rules, or to
   nonzero if there is a time, past, present, or future when
   daylight saving time applies).

   If the TZ variable does not appear in the environment, the system
   timezone is used.  The system timezone is configured by copying,
   or linking, a file in the [tzfile(5)](https://man7.org/linux/man-pages/man5/tzfile.5.html) format to /etc/localtime.  A
   timezone database of these files may be located in the system
   timezone directory (see the FILES section below).

   If the TZ variable does appear in the environment, but its value
   is empty, or its value cannot be interpreted using any of the
   formats specified below, then Coordinated Universal Time (UTC) is
   used.

   The value of TZ can be one of two formats.  The first format is a
   string of characters that directly represent the timezone to be
   used:

So it looks like the runner needs to add the TZ variable and ideally set it to UTC. I don't know how to do that or if I even have the rights to change the environment variables of the runner. It would be great to get this useful feature into ROS. But I think somebody with more knowledge and maybe access needs to help us get this going.

test/test_time.cpp Outdated Show resolved Hide resolved
@fujitatomoya
Copy link
Collaborator

CI:

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Windows Build Status

@Kaju-Bubanja
Copy link
Contributor Author

I think it's ready @clalancette @fujitatomoya

@fujitatomoya
Copy link
Collaborator

@Kaju-Bubanja thanks for the fix!

CI:

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Windows Build Status

src/time.c Outdated
time_t now_t = (time_t)(seconds);
struct tm ptm = {.tm_year = 0, .tm_mday = 0};
#ifdef _WIN32
if (localtime_s(&now_t, &ptm) == NULL) {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

getting closer but windows CI is still unhappy, see https://ci.ros2.org/job/ci_windows/21119/msbuild/new/

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ofc win and Linux have source/dest switched around :D

@Kaju-Bubanja
Copy link
Contributor Author

Kaju-Bubanja commented Feb 27, 2024

@fujitatomoya Can I do that too, I wonder:

CI:

Ok, doesn't look like it, I thought maybe there is a bot which adds the labels when you write CI:

@clalancette
Copy link
Contributor

CI:

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Windows Build Status

Copy link
Contributor

@clalancette clalancette left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Besides the comment inline, Windows testing is failing in this code: https://ci.ros2.org/job/ci_windows/21127/testReport/junit/(root)/projectroot/test_time/

src/time.c Outdated
time_t now_t = (time_t)(seconds);
struct tm ptm = {.tm_year = 0, .tm_mday = 0};
#ifdef _WIN32
if (localtime_s(&ptm, &now_t) == NULL) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

MSVC is saying:

'==': 'errno_t' differs in levels of indirection from 'void *'

Indeed, looking up the documentation for localtime_s shows that it returns an errno_t, not a pointer. So at least this needs to be fixed.

Signed-off-by: Kaju Bubanja <bubanja.kaju@gmail.com>
Signed-off-by: Kaju Bubanja <bubanja.kaju@gmail.com>
@Kaju-Bubanja
Copy link
Contributor Author

CI:

* Linux [![Build Status](https://camo.githubusercontent.com/b6ff6b6b4d14dccc76a72aa09b11bf43b0f658feeec07affe6cd49d8979a4a72/687474703a2f2f63692e726f73322e6f72672f6275696c645374617475732f69636f6e3f6a6f623d63695f6c696e7578266275696c643d3230333737)](http://ci.ros2.org/job/ci_linux/20377/)

* Linux-aarch64 [![Build Status](https://camo.githubusercontent.com/34957372f61666bb5834485aaeea740b608daa7c25244119009cc09b4a214402/687474703a2f2f63692e726f73322e6f72672f6275696c645374617475732f69636f6e3f6a6f623d63695f6c696e75782d61617263683634266275696c643d3134373836)](http://ci.ros2.org/job/ci_linux-aarch64/14786/)

* Windows [![Build Status](https://camo.githubusercontent.com/bd1f3c34dca61579747d61643719f02fac942a721578ce7eebeac7dd421bc0ad/687474703a2f2f63692e726f73322e6f72672f6275696c645374617475732f69636f6e3f6a6f623d63695f77696e646f7773266275696c643d3231313237)](http://ci.ros2.org/job/ci_windows/21127/)

Can I see these jobs myself, so to not loop you in unecessarily each time I fixed something? Because the checks which are running below always show 3 successful checks. Are these CI runs manually run by you and you link to the results or are they automatically run?

@clalancette
Copy link
Contributor

Are these CI runs manually run by you and you link to the results or are they automatically run?

They are unfortunately run manually.

@clalancette
Copy link
Contributor

Let's give CI another shot with the latest changes:

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Windows Build Status

Copy link
Contributor

@clalancette clalancette left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks good to me now. Thanks @Kaju-Bubanja for all of the iterations. @ahcorde you have the last remaining review, are you good with this now?

@clalancette
Copy link
Contributor

I'm going to go ahead with this one. Thanks @Kaju-Bubanja .

@clalancette clalancette merged commit 961c4c8 into ros2:rolling Mar 15, 2024
3 of 4 checks passed
@Kaju-Bubanja
Copy link
Contributor Author

Thank you guys, happy we got this useful feature into rolling :)

drensber pushed a commit to drensber/rcutils that referenced this pull request Mar 19, 2024
* feat: Add human readable date to logging formats

Signed-off-by: Kaju Bubanja <bubanja.kaju@gmail.com>
Signed-off-by: Dave Rensberger <davidr@beechwoods.com>
drensber pushed a commit to drensber/rcutils that referenced this pull request Apr 2, 2024
* feat: Add human readable date to logging formats

Signed-off-by: Kaju Bubanja <bubanja.kaju@gmail.com>
Signed-off-by: Dave Rensberger <davidr@beechwoods.com>
@ros-discourse
Copy link

This pull request has been mentioned on ROS Discourse. There might be relevant details there:

https://discourse.ros.org/t/ros-2-jazzy-jalisco-released/37862/1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants