tracing_subscriber : The log CAN NOT display the time correctly in the LINUX with tracing_subscriber::fmt().with_timer(LocalTime::rfc_3339())

[TQLeung]

Bug Report

The log show < unknown time > INFO actix_server:: accept : accept thread stopped in the Linux Centos7

Version 0.3.17

Platform

Linux localhost.localdomain 3.10.0-1160.92.1.el7.x86_64 #1 SMP Tue Jun 20 11:48:01 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Crates

[dependencies]
actix-web = "4.4.0"
sea-orm = { version = "0.12.2", features = [ "sqlx-mysql", "runtime-tokio-rustls", "macros", "mock" ] }
log = "0.4.20"
futures = "0.3.28"
sea-orm-migration = "0.12.2"
serde_json = "1.0.64"
serde_urlencoded = "0.7.0"
serde = { version = "1.0.64", features = ["derive"] }
chrono = "0.4.28"
uuid = { version = "1.4.1", features = ["serde", "v4"] }
tracing-subscriber = { version = "0.3.17", features = ["env-filter", "local-time"] }
async-graphql = "6.0.5"
async-graphql-actix-web = "6.0.5"
error-chain = "0.12.4"
rand = "0.8.5"
structopt = "0.3"
once_cell = "1"
regex = "1.9"
config = "0.13"

Description

in the WINDOW11 is correct， BUT THE LOG IN THE LINUX IS ERROR, THE LOGS as BELOW：

2023-09-10T17:26:29.69398601+08:00

< unknown time >

when server start， the log can display correct time info，but after that， the time info change to < unknown time >
THE problem AT THE BEGINNING OF THE EACH LINE

2023-09-10T17:26:29.69398601+08:00 INFO actix_server::builder: starting 2 workers
2023-09-10T17:26:29.69435411+08:00 INFO actix_server::server: Actix runtime found; starting in Actix runtime
< unknown time > INFO sqlx::query: summary="SET sql_mode=(SELECT CONCAT(@@sql_mode, ',PIPES_AS_CONCAT,NO_ENGINE_SUBSTITUTION')),time_zone='+00:00',NAMES …" db.statement="\n\nSET\n sql_mode =(\n SELECT\n CONCAT(\n @ @sql_mode,\n ',PIPES_AS_CONCAT,NO_ENGINE_SUBSTITUTION'\n )\n ),\n time_zone = '+00:00',\n NAMES utf8mb4 COLLATE utf8mb4_unicode_ci;\n" rows_affected=0 rows_returned=0 elapsed=1.5326ms
< unknown time > INFO actix_server::server: SIGINT received; starting forced shutdown
< unknown time > INFO actix_server::accept: accept thread stopped
< unknown time > INFO actix_server::worker: shutting down idle worker
< unknown time > INFO actix_server::worker: shutting down idle worker

Code

tracing-subscriber = { version = "0.3.17", features = ["env-filter", "local-time"] }

std::env::set_var("RUST_LOG", "DEBUG");
tracing_subscriber::fmt::time::LocalTime::rfc_3339();
tracing_subscriber::fmt()
.with_timer(LocalTime::rfc_3339())
.init();

[hawkw]

<unknown time> is displayed when an error is returned by the time crate's OffsetDateTime::now_local function:

tracing/tracing-subscriber/src/fmt/time/time_crate.rs

Line 165 in b8c45cc

let now = OffsetDateTime::now_local().map_err(|_| fmt::Error)?;

Since these errors do not originate in tracing-subscriber, you're probably better off investigating what scenarios can result in time returning an error here. The time contributors can probably help you better than we can.

[xxf2103625]

time-rs/time#617
Can't use OffsetDateTime::now_local() in async runtime multi-threaded?

[TQLeung]

Can't use OffsetDateTime::now_local() in async runtime multi-threaded?

I thought it looks not sense. Can be fixed in future?

[jiuliyemingzhi]

<unknown time> INFO tokio-runtime-worker So did I, If I use default timer, will not appear。

[davidbarsky]

Consider using tracing_subscriber::fmt::time::ChronoLocal instead, or if this is a server application, consider avoiding local time entirely.

We'll switch to chrono as the default in tracing-subscriber 0.4.

[jiuliyemingzhi]

Consider using tracing_subscriber::fmt::time::ChronoLocal instead, or if this is a server application, consider avoiding local time entirely.

We'll switch to chrono as the default in tracing-subscriber 0.4.

Oh think you, It's working properly