[pmg-devel] [PATCH log-tracker 1/2] add compatibility with API/Tracking Center

[pmg-devel] [PATCH log-tracker 1/2] add compatibility with API/Tracking Center

[Mira Limbeck]

The API assumes the timestamps to be in the local timezone rather than
UTC. It then subtracts the timezone offset leading to wrong values when
timestamps are in UTC, but timezone is not.

For compatibility, add the local timezone to those timestamps.

Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
 src/main.rs | 43 ++++++++++++++++++++++++++++++++-----------
 1 file changed, 32 insertions(+), 11 deletions(-)

diff --git a/src/main.rs b/src/main.rs
index e7bffd8..e55f17b 100644
--- a/src/main.rs
+++ b/src/main.rs
@@ -1737,6 +1737,8 @@ struct Parser {
     string_match: bool,
 
     lines: u64,
+
+    timezone_offset: time_t,
 }
 
 impl Parser {
@@ -1762,6 +1764,7 @@ impl Parser {
             ctime: 0,
             string_match: false,
             lines: 0,
+            timezone_offset: ltime.tm_gmtoff,
         })
     }
 
@@ -1836,7 +1839,12 @@ impl Parser {
             let line = &buffer[0..size - 1];
             let complete_line = line;
 
-            let (time, line) = match parse_time(line, self.current_year, self.current_month) {
+            let (time, line) = match parse_time(
+                line,
+                self.current_year,
+                self.current_month,
+                self.timezone_offset,
+            ) {
                 Some(t) => t,
                 None => continue,
             };
@@ -1920,9 +1928,12 @@ impl Parser {
                         if size == 0 {
                             return count;
                         }
-                        if let Some((time, _)) =
-                            parse_time(&buffer[0..size], self.current_year, self.current_month)
-                        {
+                        if let Some((time, _)) = parse_time(
+                            &buffer[0..size],
+                            self.current_year,
+                            self.current_month,
+                            self.timezone_offset,
+                        ) {
                             // found the earliest file in the time frame
                             if time < self.options.start {
                                 break;
@@ -1937,9 +1948,12 @@ impl Parser {
                         if size == 0 {
                             return count;
                         }
-                        if let Some((time, _)) =
-                            parse_time(&buffer[0..size], self.current_year, self.current_month)
-                        {
+                        if let Some((time, _)) = parse_time(
+                            &buffer[0..size],
+                            self.current_year,
+                            self.current_month,
+                            self.timezone_offset,
+                        ) {
                             if time < self.options.start {
                                 break;
                             }
@@ -2235,11 +2249,17 @@ fn parse_number(data: &[u8], max_digits: usize) -> Option<(usize, &[u8])> {
 }
 
 /// Parse time. Returns a tuple of (parsed_time, remaining_text) or None.
-fn parse_time(data: &'_ [u8], cur_year: i64, cur_month: i64) -> Option<(time_t, &'_ [u8])> {
-    parse_time_with_year(data).or_else(|| parse_time_no_year(data, cur_year, cur_month))
+fn parse_time(
+    data: &'_ [u8],
+    cur_year: i64,
+    cur_month: i64,
+    timezone_offset: time_t,
+) -> Option<(time_t, &'_ [u8])> {
+    parse_time_with_year(data, timezone_offset)
+        .or_else(|| parse_time_no_year(data, cur_year, cur_month))
 }
 
-fn parse_time_with_year(data: &'_ [u8]) -> Option<(time_t, &'_ [u8])> {
+fn parse_time_with_year(data: &'_ [u8], timezone_offset: time_t) -> Option<(time_t, &'_ [u8])> {
     let mut timestamp_buffer = [0u8; 25];
 
     let count = data.iter().take_while(|b| **b != b' ').count();
@@ -2266,7 +2286,8 @@ fn parse_time_with_year(data: &'_ [u8]) -> Option<(time_t, &'_ [u8])> {
     match proxmox_time::parse_rfc3339(unsafe {
         std::str::from_utf8_unchecked(&timestamp_buffer[0..timestamp_len])
     }) {
-        Ok(ltime) => Some((ltime, data)),
+        // TODO handle timezone offset in old code path instead
+        Ok(ltime) => Some((ltime + timezone_offset, data)),
         Err(_err) => None,
     }
 }
-- 
2.30.2

[pmg-devel] [PATCH log-tracker 2/2] tests: update to match the compatibility changes

[Mira Limbeck]

Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
---
 tests/test_output_time_rfc3339_mixed | 26 +++++++++++++-------------
 tests/tests_time_rfc3339.rs          |  5 ++++-
 2 files changed, 17 insertions(+), 14 deletions(-)

diff --git a/tests/test_output_time_rfc3339_mixed b/tests/test_output_time_rfc3339_mixed
index 6c597d9..3e628b8 100644
--- a/tests/test_output_time_rfc3339_mixed
+++ b/tests/test_output_time_rfc3339_mixed
@@ -1,16 +1,16 @@
-# LogReader: 6673
+# LogReader: 31272
 # Query options
 # Start: 2023-06-23 00:00:00 (1687478400)
-# End: 2023-06-23 23:59:59 (1687564799)
+# End: 2023-06-23 23:59:00 (1687564740)
 # End Query Options
 
 QENTRY: 520C9C0192
-CTIME: 64958F79
+CTIME: 6495AB99
 SIZE: 1902
 CLIENT: pmghost.mydomain.tld[192.168.1.001]
 MSGID: <redacted:msgid>
-TO:64958F79:520C9C0192:Q: from <redacted:returnpath@domain.tld> to <user@domain2.tld> (C01C264958F7962FEA)
-TO:64958F79:520C9C0192:Q: from <redacted:returnpath@domain.tld> to <test@mydomain.tld> (C01C264958F7962FEA)
+TO:6495AB99:520C9C0192:Q: from <redacted:returnpath@domain.tld> to <user@domain2.tld> (C01C264958F7962FEA)
+TO:6495AB99:520C9C0192:Q: from <redacted:returnpath@domain.tld> to <test@mydomain.tld> (C01C264958F7962FEA)
 SMTP:
 L00000004 2023-06-23T14:26:29.331019+02:00 pmg1 postfix/smtpd[1181]: connect from pmghost.mydomain.tld[192.168.1.001]
 L00000005 2023-06-23T14:26:29.336189+02:00 pmg1 postfix/smtpd[1181]: 520C9C0192: client=pmghost.mydomain.tld[192.168.1.001]
@@ -29,12 +29,12 @@ L00000011 2023-06-23T14:26:33.461645+02:00 pmg1 postfix/lmtp[1186]: 520C9C0192:
 L00000012 2023-06-23T14:26:33.461834+02:00 pmg1 postfix/qmgr[1136]: 520C9C0192: removed
 
 QENTRY: 866B7C0192
-CTIME: 6495ABDD
+CTIME: 6495C7FD
 SIZE: 44585
 CLIENT: pmghost.mydomain.tld[192.168.1.001]
 MSGID: <redacted:msgid>
-TO:6495ABDD:866B7C0192:Q: from <redacted:returnpath@domain.tld> to <user@domain2.tld> (C01C364958FBD55D53)
-TO:6495ABDD:866B7C0192:Q: from <redacted:returnpath@domain.tld> to <test@mydomain.tld> (C01C364958FBD55D53)
+TO:6495C7FD:866B7C0192:Q: from <redacted:returnpath@domain.tld> to <user@domain2.tld> (C01C364958FBD55D53)
+TO:6495C7FD:866B7C0192:Q: from <redacted:returnpath@domain.tld> to <test@mydomain.tld> (C01C364958FBD55D53)
 SMTP:
 L00000019 2023-06-23T14:27:40.550478Z pmg1 postfix/smtpd[1181]: connect from pmghost.mydomain.tld[192.168.1.001]
 L0000001A 2023-06-23T14:27:40.550799Z pmg1 postfix/smtpd[1181]: 866B7C0192: client=pmghost.mydomain.tld[192.168.1.001]
@@ -53,12 +53,12 @@ L00000026 2023-06-23T14:27:41.429627Z pmg1 postfix/lmtp[1186]: 866B7C0192: to=<u
 L00000027 2023-06-23T14:27:41.429803Z pmg1 postfix/qmgr[1136]: 866B7C0192: removed
 
 QENTRY: C4EC9C0192
-CTIME: 6495C82A
+CTIME: 6495E44A
 SIZE: 130922
 CLIENT: pmghost.mydomain.tld[192.168.1.001]
 MSGID: <redacted:msgid>
-TO:6495C82A:C4EC9C0192:Q: from <redacted:returnpath@domain.tld> to <user@domain2.tld> (C01D364958FEA2A254)
-TO:6495C82A:C4EC9C0192:Q: from <redacted:returnpath@domain.tld> to <test@mydomain.tld> (C01D364958FEA2A254)
+TO:6495E44A:C4EC9C0192:Q: from <redacted:returnpath@domain.tld> to <user@domain2.tld> (C01D364958FEA2A254)
+TO:6495E44A:C4EC9C0192:Q: from <redacted:returnpath@domain.tld> to <test@mydomain.tld> (C01D364958FEA2A254)
 SMTP:
 L0000002C 2023-06-23T14:28:23.806586-02:00 pmg1 postfix/smtpd[1181]: connect from pmghost.mydomain.tld[192.168.1.001]
 L0000002D 2023-06-23T14:28:23.806755-02:00 pmg1 postfix/smtpd[1181]: C4EC9C0192: client=pmghost.mydomain.tld[192.168.1.001]
@@ -77,11 +77,11 @@ L00000038 2023-06-23T14:28:26.241632-02:00 pmg1 postfix/lmtp[1186]: C4EC9C0192:
 L00000039 2023-06-23T14:28:26.242140-02:00 pmg1 postfix/qmgr[1136]: C4EC9C0192: removed
 
 QENTRY: 71386C0192
-CTIME: 6495C841
+CTIME: 6495E461
 SIZE: 129347
 CLIENT: localhost.localdomain[127.0.0.1]
 MSGID: <redacted:msgid>
-TO:6495C841:71386C0192:2: from <postmaster@pmghost.mydomain.tld> to <user@domain2.tld> (relay.domain3.tld[192.168.1.002]:25)
+TO:6495E461:71386C0192:2: from <postmaster@pmghost.mydomain.tld> to <user@domain2.tld> (relay.domain3.tld[192.168.1.002]:25)
 SMTP:
 L0000003C 2023-06-23T14:28:42.463301-02:00 pmg1 postfix/smtpd[1274]: connect from localhost.localdomain[127.0.0.1]
 L0000003D 2023-06-23T14:28:42.463813-02:00 pmg1 postfix/smtpd[1274]: 71386C0192: client=localhost.localdomain[127.0.0.1]
diff --git a/tests/tests_time_rfc3339.rs b/tests/tests_time_rfc3339.rs
index 874a332..edcface 100644
--- a/tests/tests_time_rfc3339.rs
+++ b/tests/tests_time_rfc3339.rs
@@ -6,7 +6,10 @@ mod utils;
 
 #[test]
 fn after_queue_time_rfc3339_mixed() {
-    let output = Command::new(utils::log_tracker_path())
+    let output = Command::new("faketime")
+        .env("TZ", "Europe/Vienna")
+        .arg("2023-06-28 23:59:59")
+        .arg(utils::log_tracker_path())
         .arg("-vv")
         .arg("-s")
         .arg("2023-06-23 00:00:00")
-- 
2.30.2

Re: [pmg-devel] [PATCH log-tracker 1/2] add compatibility with API/Tracking Center

[Dominik Csapak]

LGTM and works as intended, even with changed timezones
the logs with new timestamp format don't change
(while the old ones do)

consider both patches:

Reviewed-by: Dominik Csapak <d.csapak@proxmox.com>
Tested-by: Dominik Csapak <d.csapak@proxmox.com>

[pmg-devel] applied-series: [PATCH log-tracker 1/2] add compatibility with API/Tracking Center

[Stoiko Ivanov]

Thanks for addressing the issue so quickly and far cleaner than my RFC!
Thanks also for the testing!

quickly verified that it looks good on my test-system and applied with
Dominik's R-b, T-b

small nit I just realized after pushing - a mention of rfc3339/new
syslogformat parsing in the commit subject or message would have been good.


On Wed, 28 Jun 2023 10:54:28 +0200
Mira Limbeck <m.limbeck@proxmox.com> wrote:

> The API assumes the timestamps to be in the local timezone rather than
> UTC. It then subtracts the timezone offset leading to wrong values when
> timestamps are in UTC, but timezone is not.
> 
> For compatibility, add the local timezone to those timestamps.
> 
> Signed-off-by: Mira Limbeck <m.limbeck@proxmox.com>
> ---
>  src/main.rs | 43 ++++++++++++++++++++++++++++++++-----------
>  1 file changed, 32 insertions(+), 11 deletions(-)
> 
> diff --git a/src/main.rs b/src/main.rs
> index e7bffd8..e55f17b 100644
> --- a/src/main.rs
> +++ b/src/main.rs
> @@ -1737,6 +1737,8 @@ struct Parser {
>      string_match: bool,
>  
>      lines: u64,
> +
> +    timezone_offset: time_t,
>  }
>  
>  impl Parser {
> @@ -1762,6 +1764,7 @@ impl Parser {
>              ctime: 0,
>              string_match: false,
>              lines: 0,
> +            timezone_offset: ltime.tm_gmtoff,
>          })
>      }
>  
> @@ -1836,7 +1839,12 @@ impl Parser {
>              let line = &buffer[0..size - 1];
>              let complete_line = line;
>  
> -            let (time, line) = match parse_time(line, self.current_year, self.current_month) {
> +            let (time, line) = match parse_time(
> +                line,
> +                self.current_year,
> +                self.current_month,
> +                self.timezone_offset,
> +            ) {
>                  Some(t) => t,
>                  None => continue,
>              };
> @@ -1920,9 +1928,12 @@ impl Parser {
>                          if size == 0 {
>                              return count;
>                          }
> -                        if let Some((time, _)) =
> -                            parse_time(&buffer[0..size], self.current_year, self.current_month)
> -                        {
> +                        if let Some((time, _)) = parse_time(
> +                            &buffer[0..size],
> +                            self.current_year,
> +                            self.current_month,
> +                            self.timezone_offset,
> +                        ) {
>                              // found the earliest file in the time frame
>                              if time < self.options.start {
>                                  break;
> @@ -1937,9 +1948,12 @@ impl Parser {
>                          if size == 0 {
>                              return count;
>                          }
> -                        if let Some((time, _)) =
> -                            parse_time(&buffer[0..size], self.current_year, self.current_month)
> -                        {
> +                        if let Some((time, _)) = parse_time(
> +                            &buffer[0..size],
> +                            self.current_year,
> +                            self.current_month,
> +                            self.timezone_offset,
> +                        ) {
>                              if time < self.options.start {
>                                  break;
>                              }
> @@ -2235,11 +2249,17 @@ fn parse_number(data: &[u8], max_digits: usize) -> Option<(usize, &[u8])> {
>  }
>  
>  /// Parse time. Returns a tuple of (parsed_time, remaining_text) or None.
> -fn parse_time(data: &'_ [u8], cur_year: i64, cur_month: i64) -> Option<(time_t, &'_ [u8])> {
> -    parse_time_with_year(data).or_else(|| parse_time_no_year(data, cur_year, cur_month))
> +fn parse_time(
> +    data: &'_ [u8],
> +    cur_year: i64,
> +    cur_month: i64,
> +    timezone_offset: time_t,
> +) -> Option<(time_t, &'_ [u8])> {
> +    parse_time_with_year(data, timezone_offset)
> +        .or_else(|| parse_time_no_year(data, cur_year, cur_month))
>  }
>  
> -fn parse_time_with_year(data: &'_ [u8]) -> Option<(time_t, &'_ [u8])> {
> +fn parse_time_with_year(data: &'_ [u8], timezone_offset: time_t) -> Option<(time_t, &'_ [u8])> {
>      let mut timestamp_buffer = [0u8; 25];
>  
>      let count = data.iter().take_while(|b| **b != b' ').count();
> @@ -2266,7 +2286,8 @@ fn parse_time_with_year(data: &'_ [u8]) -> Option<(time_t, &'_ [u8])> {
>      match proxmox_time::parse_rfc3339(unsafe {
>          std::str::from_utf8_unchecked(&timestamp_buffer[0..timestamp_len])
>      }) {
> -        Ok(ltime) => Some((ltime, data)),
> +        // TODO handle timezone offset in old code path instead
> +        Ok(ltime) => Some((ltime + timezone_offset, data)),
>          Err(_err) => None,
>      }
>  }