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

log: change date format to ISO8601-like #2386

Merged
merged 3 commits into from
Oct 14, 2022

Conversation

metalefty
Copy link
Member

@metalefty metalefty commented Oct 7, 2022

Former format: "[20221007-16:36:02] "
New format: "[2022-10-07T16:36:04.357+0900] "

Two reasons for this change:

  • msec is required
  • timezone info is required

While I was debugging, I want to add msec for more precision. However, this will break backward compatibility. I think logs are mostly read by human so compatibility is not a serious problem. Any opinions?

The difference between the true ISO 8601 and this format is msec. The true ISO 8601 doesn't include msec.

[20221007-16:13:33] [DEBUG] item bitmap_compression, value true
[20221007-16:13:33] [DEBUG] item bulk_compression, value true
[20221007-16:13:33] [DEBUG] item max_bpp, value 32
[20221007-16:13:33] [DEBUG] item new_cursors, value true
[20221007-16:13:33] [DEBUG] item use_fastpath, value none
[20221007-16:13:33] [DEBUG] item grey, value e1e1e1
[20221007-16:13:33] [DEBUG] item dark_grey, value b4b4b4
[20221007-16:13:33] [DEBUG] item blue, value 0078d7
[20221007-16:13:33] [DEBUG] item dark_blue, value 0078d7
[20221007-16:13:33] [DEBUG] item ls_top_window_bg_color, value 003057
[20221007-16:13:33] [DEBUG] item ls_width, value 350
[20221007-16:13:33] [DEBUG] item ls_height, value 360
[20221007-16:13:33] [DEBUG] item ls_bg_color, value f0f0f0
[20221007-16:13:33] [DEBUG] item ls_logo_filename, value
[20221007-16:13:33] [DEBUG] item ls_logo_transform, value scale
[20221007-16:13:33] [DEBUG] item ls_logo_width, value 250
[20221007-16:13:33] [DEBUG] item ls_logo_height, value 110
[20221007-16:13:33] [DEBUG] item ls_logo_x_pos, value 55
[20221007-16:13:33] [DEBUG] item ls_logo_y_pos, value 35
[20221007-16:13:33] [DEBUG] item ls_label_x_pos, value 30
[20221007-16:13:33] [DEBUG] item ls_label_width, value 68
[20221007-16:13:33] [DEBUG] item ls_input_x_pos, value 110
[20221007-16:13:33] [DEBUG] item ls_input_width, value 210
[20221007-16:13:33] [DEBUG] item ls_input_y_pos, value 158
[20221007-16:13:33] [DEBUG] item ls_btn_ok_x_pos, value 142
[20221007-16:13:33] [DEBUG] item ls_btn_ok_y_pos, value 308
[20221007-16:13:33] [DEBUG] item ls_btn_ok_width, value 85
[20221007-16:13:33] [DEBUG] item ls_btn_ok_height, value 30
[20221007-16:13:33] [DEBUG] item ls_btn_cancel_x_pos, value 237
[20221007-16:13:33] [DEBUG] item ls_btn_cancel_y_pos, value 308
[20221007-16:13:33] [DEBUG] item ls_btn_cancel_width, value 85
[20221007-16:13:33] [DEBUG] item ls_btn_cancel_height, value 30
[20221007-16:13:33] [INFO ] Security protocol: configured [SSL], requested [SSL|HYBRID|RDP], selected [SSL]

Finally, I get the following log.

xrdp-sesman.log

[2022-10-07T21:48:24.826+0900] [INFO ] [session start] (display 10): calling auth_start_session from pid 75249
[2022-10-07T21:48:24.848+0900] [INFO ] PAM: Last login: Fri Oct  7 21:19:04 from tmux(1745).%12
[2022-10-07T21:48:24.877+0900] [INFO ] Starting X server on display 10: /usr/local/libexec/Xorg :10 -auth .Xauthority -config xrdp/xorg.conf -noreset -nolisten tcp -logfile .xorgxrdp.%s.log
[2022-10-07T21:48:25.126+0900] [INFO ] Found X server running at /tmp/.X11-unix/X10
[2022-10-07T21:48:25.170+0900] [INFO ] Session started successfully for user meta on display 10
[2022-10-07T21:48:25.127+0900] [INFO ] Found X server running at /tmp/.X11-unix/X10
[2022-10-07T21:48:25.171+0900] [INFO ] Starting the xrdp channel server for display 10
[2022-10-07T21:48:25.237+0900] [INFO ] Found X server running at /tmp/.X11-unix/X10
[2022-10-07T21:48:25.302+0900] [INFO ] Starting the default window manager on display 10: /usr/local/etc/xrdp/startwm.sh
[2022-10-07T21:48:25.226+0900] [INFO ] Session in progress on display 10, waiting until the window manager (pid 75251) exits to end the session
[2022-10-07T21:48:26.909+0900] [ERROR] sesman_main_loop: trans_check_wait_objs failed, removing trans

xrdp.log

[2022-10-07T21:54:53.888+0900] [DEBUG] item ssl_protocols, value TLSv1.2, TLSv1.3
[2022-10-07T21:54:53.890+0900] [DEBUG] TLSv1.3 enabled
[2022-10-07T21:54:53.891+0900] [DEBUG] TLSv1.2 enabled
[2022-10-07T21:54:53.893+0900] [DEBUG] item autorun, value
[2022-10-07T21:54:53.894+0900] [DEBUG] item allow_channels, value true
[2022-10-07T21:54:53.896+0900] [DEBUG] item allow_multimon, value true
[2022-10-07T21:54:53.898+0900] [DEBUG] item bitmap_cache, value true
[2022-10-07T21:54:53.899+0900] [DEBUG] item bitmap_compression, value true
[2022-10-07T21:54:53.901+0900] [DEBUG] item bulk_compression, value true
[2022-10-07T21:54:53.902+0900] [DEBUG] item max_bpp, value 32
[2022-10-07T21:54:53.904+0900] [DEBUG] item new_cursors, value true
[2022-10-07T21:54:53.906+0900] [DEBUG] item use_fastpath, value none

@metalefty
Copy link
Member Author

Oops, %N is platform specific.

@metalefty
Copy link
Member Author

metalefty commented Oct 7, 2022

I'm thinking of creating new function like this:

const char *
getFormattedTime()
{
    static char buffer[32];
    static char buf_datetime[21];
    static char buf_millisec[4];
    static char buf_timezone[6];

    struct tm *now;
    struct timeval tv;
    int millisec;

    gettimeofday(&tv, NULL);
    now = localtime(&tv.tv_sec);

    millisec = lrint(tv.tv_usec / 1000.0);
    sprintf(buf_millisec, "%03d", millisec);

    strftime(buf_datetime, sizeof(buf_datetime), "%FT%T.", now);
    strftime(buf_timezone, sizeof(buf_timezone), "%z", now);
    sprintf(buffer, "[%s%s%s] ", buf_datetime, buf_millisec, buf_timezone);

    return buffer;
}

@metalefty metalefty force-pushed the log_time branch 4 times, most recently from ad4afe6 to 62dd78b Compare October 7, 2022 13:18
@metalefty metalefty requested a review from matt335672 October 7, 2022 13:24
@metalefty
Copy link
Member Author

@aquesnel Can you also have a look? You worked hard on logging.

Copy link
Member

@matt335672 matt335672 left a comment

Choose a reason for hiding this comment

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

Looks fine - just one query.

Former format:  "[20221007-16:36:02] "
New format:     "[2022-10-07T16:36:04.357+0900] "
@metalefty metalefty merged commit 5b51010 into neutrinolabs:devel Oct 14, 2022
@metalefty metalefty deleted the log_time branch October 14, 2022 01:19
Copy link
Contributor

@aquesnel aquesnel left a comment

Choose a reason for hiding this comment

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

I really like this change, thanks for making it. :-)

metalefty added a commit to metalefty/xrdp that referenced this pull request Feb 9, 2023
The tail of new datetime format was sticking out.
metalefty added a commit to metalefty/xrdp that referenced this pull request Feb 9, 2023
The tail of new datetime format was sticking out.
metalefty added a commit that referenced this pull request Feb 10, 2023
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.

3 participants