Change timestamps to POSIX format.

PATCH In review Gert Doering 6 participants 13 messages Aug 11, 2016 – Aug 13, 2016

lore

Share & tools

lore

Gert Doering

author

2016-08-11 19:23 UTC #0 lore raw

PATCH 1/1 Change timestamps to POSIX format.

All our timestams used to be "what ctime()" produces, which is

"Thu Aug 11 21:15:27 2016"

Changed to use POSIX standard format, which is

"2016-08-11 21:15:27"

this applies to logging (except to syslog or if --machine-readable-ouput is used) and to various other places where informational timestamps are produced. Among these are the status files / status to management interface, so applications parsing these time stamp need to be adjusted.

trac#719

Signed-off-by Gert Doering <[email protected]...>

---
 src/openvpn/otime.c | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)

src/openvpn/otime.c +5 -2

index 2c1e5b1..c10a6a8 100644
@@ -112,6 +112,7 @@ time_string (time_t t, int usec, bool show_usec, struct gc_arena *gc)
 {
   struct buffer out = alloc_buf_gc (64, gc);
   struct timeval tv;
+  struct tm *tm;
 
   if (t)
     {

@@ -124,8 +125,10 @@ time_string (time_t t, int usec, bool show_usec, struct gc_arena *gc)
     }
 
   t = tv.tv_sec;
-  buf_printf (&out, "%s", ctime(&t));
-  buf_rmtail (&out, '\n');
+  tm = localtime(&t);
+  buf_printf (&out, "%04d-%02d-%02d %02d:%02d:%02d",
+		tm->tm_year+1900, tm->tm_mon+1, tm->tm_mday,
+		tm->tm_hour, tm->tm_min, tm->tm_sec );
 
   if (show_usec && tv.tv_usec)
     buf_printf (&out, " us=%d", (int)tv.tv_usec);

Signature · 1 line

2.7.3

Илья Шипицин

2016-08-11 19:46 UTC #1 lore raw

iso 8601 is good format.
it is accepted by default by sql servers, Log Parser

2016-08-12 0:23 GMT+05:00 Gert Doering <[email protected]...>:

Quoted 65 lines

All our timestams used to be "what ctime()" produces, which is
"Thu Aug 11 21:15:27 2016"
Changed to use POSIX standard format, which is
"2016-08-11 21:15:27"
this applies to logging (except to syslog or if --machine-readable-ouput is used) and to various other places where informational timestamps are produced. Among these are the status files / status to management interface, so applications parsing these time stamp need to be adjusted.
trac#719
Signed-off-by Gert Doering <[email protected]...>
---
 src/openvpn/otime.c | 7 +++++--
 1 file changed, 5 insertions(+), 2 deletions(-)
src/openvpn/otime.c +1 -0
index 2c1e5b1..c10a6a8 100644
@@ -112,6 +112,7 @@ time_string (time_t t, int usec, bool show_usec,
 struct gc_arena *gc)
 {
   struct buffer out = alloc_buf_gc (64, gc);
   struct timeval tv;
+  struct tm *tm;
 
   if (t)
     {
src/openvpn/otime.c +4 -2
@@ -124,8 +125,10 @@ time_string (time_t t, int usec, bool show_usec,
 struct gc_arena *gc)
     }
 
   t = tv.tv_sec;
-  buf_printf (&out, "%s", ctime(&t));
-  buf_rmtail (&out, '\n');
+  tm = localtime(&t);
+  buf_printf (&out, "%04d-%02d-%02d %02d:%02d:%02d",
+               tm->tm_year+1900, tm->tm_mon+1, tm->tm_mday,
+               tm->tm_hour, tm->tm_min, tm->tm_sec );
 
   if (show_usec && tv.tv_usec)
     buf_printf (&out, " us=%d", (int)tv.tv_usec);
--
2.7.3
------------------------------------------------------------
------------------
What NetFlow Analyzer can do for you? Monitors network bandwidth and traffic
patterns at an interface-level. Reveals which users, apps, and protocols are
consuming the most bandwidth. Provides multi-vendor support for NetFlow, J-Flow, sFlow and other flows. Make informed decisions using capacity planning reports. http://sdm.link/zohodev2dev
_______________________________________________
Openvpn-devel mailing list [email protected]
https://lists.sourceforge.net/lists/listinfo/openvpn-devel

David Sommerseth

2016-08-12 10:03 UTC #2 lore raw

In reply to Gert Doering

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Quoted 14 lines · Gert Doering

All our timestams used to be "what ctime()" produces, which is
"Thu Aug 11 21:15:27 2016"
Changed to use POSIX standard format, which is
"2016-08-11 21:15:27"
this applies to logging (except to syslog or if --machine-readable-ouput is used) and to various other places where informational timestamps are produced. Among these are the status files / status to management interface, so applications parsing these time stamp need to be adjusted.

Quoted 6 lines

trac#719
Signed-off-by Gert Doering <[email protected]...> ---
src/openvpn/otime.c | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-)

I generally think this is a very good idea. But I fear what we break along the way.

It would be great if as many as possible could put this into somewhat limited production environment for testing if this breaks any thing *and* report back after a while; even if no issues where detected.

- --
kind regards,

David Sommerseth
OpenVPN Technologies, Inc

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)

iEYEARECAAYFAletnvUACgkQDC186MBRfrqAhQCgm79bWoRc0Rx8yfDPfkghhaxC ppUAoKsW896yhktq76znVoPagDWvlo7n
=IR81
-----END PGP SIGNATURE-----

Gert Doering

author

2016-08-12 17:41 UTC #3 lore raw

PATCH v2 1/1 Change timestamps to ISO 8601 format.

In reply to Gert Doering

All our timestams used to be "what ctime()" produces, which is

"Thu Aug 11 21:15:27 2016"

Changed to use ISO 8601 standard format, which is

"2016-08-11 21:15:27"

trac#719

v2: changes.rst, and correctly call this "ISO 8601" not "POSIX"

Signed-off-by Gert Doering <[email protected]...>

---
 Changes.rst         | 3 +++
 src/openvpn/otime.c | 7 +++++--
 2 files changed, 8 insertions(+), 2 deletions(-)

Changes.rst +3 -0

index 9fcba75..ad6363e 100644
@@ -135,6 +135,9 @@ User-visible Changes
   ciphers configured in the config file.  Use --ncp-disable if you don't want
   that.
 
+- all time stamps, including log file, status file and management interface,
+  are now output in ISO 8601 standard format.
+
 
 Maintainer-visible changes
 --------------------------

src/openvpn/otime.c +5 -2

index 2c1e5b1..c10a6a8 100644
@@ -112,6 +112,7 @@ time_string (time_t t, int usec, bool show_usec, struct gc_arena *gc)
 {
   struct buffer out = alloc_buf_gc (64, gc);
   struct timeval tv;
+  struct tm *tm;
 
   if (t)
     {

@@ -124,8 +125,10 @@ time_string (time_t t, int usec, bool show_usec, struct gc_arena *gc)
     }
 
   t = tv.tv_sec;
-  buf_printf (&out, "%s", ctime(&t));
-  buf_rmtail (&out, '\n');
+  tm = localtime(&t);
+  buf_printf (&out, "%04d-%02d-%02d %02d:%02d:%02d",
+		tm->tm_year+1900, tm->tm_mon+1, tm->tm_mday,
+		tm->tm_hour, tm->tm_min, tm->tm_sec );
 
   if (show_usec && tv.tv_usec)
     buf_printf (&out, " us=%d", (int)tv.tv_usec);

Signature · 1 line

2.7.3

Arne Schwabe

2016-08-12 18:19 UTC #4 lore raw

Re: [Openvpn-devel] [PATCH v2] Change timestamps to ISO 8601 format.

Am 12.08.16 um 19:41 schrieb Gert Doering:

Quoted 8 lines

All our timestams used to be "what ctime()" produces, which is
"Thu Aug 11 21:15:27 2016"
Changed to use ISO 8601 standard format, which is
"2016-08-11 21:15:27"

Quoted 9 lines

this applies to logging (except to syslog or if --machine-readable-ouput is used) and to various other places where informational timestamps are produced. Among these are the status files / status to management interface, so applications parsing these time stamp need to be adjusted.
trac#719
v2: changes.rst, and correctly call this "ISO 8601" not "POSIX"

ACK from me. I would have used strfrtime but I am fine with this manual way.

Arne

Selva Nair

2016-08-12 18:25 UTC #5 lore raw

Re: [Openvpn-devel] [PATCH v2] Change timestamps to ISO 8601 format.

In reply to Gert Doering

Quoted 12 lines · Gert Doering

Changes.rst +0 -0
index 9fcba75..ad6363e 100644
@@ -135,6 +135,9 @@ User-visible Changes
   ciphers configured in the config file.  Use --ncp-disable if you don't
want
that.
+- all time stamps, including log file, status file and management interface,

Changes.rst User-visible Changes · line 140

Quoted 2 lines

Changes.rst +2 -0

+  are now output in ISO 8601 standard format.
+

Currently the >LOG message to the management is like

Quoted 1 line

LOG:1471025385,,Closing TUN/TAP interface

with unix time as timestamp. Similarly for INFO message in response to 'log n' request or the state message.The patch would not change those, would it?

Selva

Gert Doering

author

2016-08-12 18:45 UTC #6 lore raw

Re: [Openvpn-devel] [PATCH v2] Change timestamps to ISO 8601 format.

Hi,

Quoted 11 lines · Selva Nair

Changes.rst User-visible Changes · line 140
Quoted 4 lines
+- all time stamps, including log file, status file and management interface,
Changes.rst +2 -0
+  are now output in ISO 8601 standard format.
+
Currently the >LOG message to the management is like
Quoted 1 line
LOG:1471025385,,Closing TUN/TAP interface
with unix time as timestamp. Similarly for INFO message in response to 'log n' request or the state message.The patch would not change those, would it?

Those wouldn't be affected, no. Only those that have the "old" ctime() format today - what I spotted on the management interface is "status" output, both in the header and in each idividual client line.

gert

Signature · 4 lines

USENET is *not* the non-clickable part of WWW!
                                                           //www.muc.de/~gert/
Gert Doering - Munich, Germany                             [email protected]...
fax: +49-89-35655025                        [email protected]...

Selva Nair

2016-08-12 19:32 UTC #7 lore raw

Re: [Openvpn-devel] [PATCH v2] Change timestamps to ISO 8601 format.

Quoted 11 lines · Gert Doering

Quoted 9 lines · Selva Nair
Changes.rst User-visible Changes · line 140
Quoted 4 lines
+- all time stamps, including log file, status file and management interface,
Changes.rst +2 -0
+  are now output in ISO 8601 standard format.
+
Currently the >LOG message to the management is like
Quoted 1 line
LOG:1471025385,,Closing TUN/TAP interface

Quoted 8 lines

Quoted 1 line
with unix time as timestamp. Similarly for INFO message in response to
'log
Quoted 1 line
n' request or the state message.The patch would not change those, would
it?
Those wouldn't be affected, no. Only those that have the "old" ctime() format today - what I spotted on the management interface is "status" output, both in the header and in each idividual client line.

Thanks for the clarification. AFAIK, we do not parse status output in OpenVPN GUI. A UI for server would need to parse those and it would have been nicer to have status timestamps sent to management be in unix time as well -- not a fault of this patch.

Selva

Gert Doering

author

2016-08-12 20:52 UTC #8 lore raw

Re: [Openvpn-devel] [PATCH v2] Change timestamps to ISO 8601 format.

Hi,

Quoted 2 lines · Selva Nair

Thanks for the clarification. AFAIK, we do not parse status output in OpenVPN GUI.

Good :-)

Quoted 3 lines

A UI for server would need to parse those and it would have been nicer to have status timestamps sent to management be in unix time as well -- not a fault of this patch.

David checked with James, and at least OpenVPN AS supposedly doesn't parse these timestamps - so, no show stopper yet...

gert

Signature · 4 lines

USENET is *not* the non-clickable part of WWW!
                                                           //www.muc.de/~gert/
Gert Doering - Munich, Germany                             [email protected]...
fax: +49-89-35655025                        [email protected]...

David Woodhouse

2016-08-12 19:53 UTC #9 lore raw

In reply to Gert Doering

Quoted 7 lines · Gert Doering

All our timestams used to be "what ctime()" produces, which is
"Thu Aug 11 21:15:27 2016"
Changed to use POSIX standard format, which is
"2016-08-11 21:15:27"

While you're at it, perhaps also add the timezone in numeric (±0000) format. It is often the case that servers logging in their own random localtime make it difficult to correlate logs from hosts in different parts of the world. The general rule of thumb is that a time without a zone is meaningless.

Signature · 1 line

dwmw2

Gert Doering

author

2016-08-12 21:02 UTC #10 lore raw

Hi,

Quoted 7 lines · David Woodhouse

Quoted 6 lines · Gert Doering
All our timestams used to be "what ctime()" produces, which is
"Thu Aug 11 21:15:27 2016"
Changed to use POSIX standard format, which is

Quoted 7 lines

Quoted 1 line
"2016-08-11 21:15:27"
While you're at it, perhaps also add the timezone in numeric (±0000) format. It is often the case that servers logging in their own random localtime make it difficult to correlate logs from hosts in different parts of the world. The general rule of thumb is that a time without a zone is meaningless.

This is a good argument. Unfortunately, it's a surprisingly *hairy* one, as there are time zones that do not have a full-hour offset - so ISO 8601 (according to wikipedia) says you should do "±hh:mm" then - and for most folks, ":mm" would always be ":00", sort of waste of screen real estate...

Regarding portability, this is even more interesting. I assumed that localtime()'s "struct tm" would be truly portable, but it seems that
older unixes have "long tm_tzadj; /* seconds from UTC */" while
modern ones have "long tm_gmtoff; /* offset from UTC in seconds */" (WHY OH WHY???)....

* TZMINS_USE_xxxxxx specifies how to get timezone offset. *
* TZMINS_USE_TM_TZADJ use (struct tm*)->tm_tzadj
* TZMINS_USE_TM_GMTOFF use (struct tm*)->tm_gmtoff
* TZMINS_USE_TZAZ_GLOBAL use "timezone, altzone" externals

 *	TZMINS_USE_TZ_GLOBAL   use "timezone" external
 *	TZMINS_USE_FTIME       use ftime() function
 *	TZMINS_USE_TIMEOFDAY   use gettimeofday() function

... from ports/elm/lib/get_tz.c...

(I don't think anything but tzadj/gmtoff is relevant anymore today, but need to check more systems. And no, strftime() isn't helping - it has "%z", which, according to FreeBSD's man page is an extention to the C90 standard...)

I think I can see why James just used ctime() here :-)

gert

Signature · 4 lines

USENET is *not* the non-clickable part of WWW!
                                                           //www.muc.de/~gert/
Gert Doering - Munich, Germany                             [email protected]...
fax: +49-89-35655025                        [email protected]...

David Woodhouse

2016-08-12 21:39 UTC #11 lore raw

Quoted 5 lines · Gert Doering

This is a good argument. Unfortunately, it's a surprisingly *hairy* one, as there are time zones that do not have a full-hour offset - so ISO 8601 (according to wikipedia) says you should do "±hh:mm" then - and for most folks, ":mm" would always be ":00", sort of waste of screen real estate...

You would definitely want to use the standard format that you see every day in email, and as you see it above: +0200.

Quoted 15 lines

Regarding portability, this is even more interesting.  I assumed that localtime()'s "struct tm" would be truly portable, but it seems that older unixes have "long    tm_tzadj; /* seconds from UTC */" while modern ones have "long tm_gmtoff; /* offset from UTC in seconds */" (WHY OH WHY???)....
* TZMINS_USE_xxxxxx specifies how to get timezone offset. *
* TZMINS_USE_TM_TZADJ    use (struct tm*)->tm_tzadj
* TZMINS_USE_TM_GMTOFF   use (struct tm*)->tm_gmtoff
* TZMINS_USE_TZAZ_GLOBAL use "timezone, altzone" externals
* TZMINS_USE_TZ_GLOBAL   use "timezone" external
* TZMINS_USE_FTIME       use ftime() function
* TZMINS_USE_TIMEOFDAY   use gettimeofday() function

Quoted 6 lines

... from ports/elm/lib/get_tz.c...
(I don't think anything but tzadj/gmtoff is relevant anymore today, but need to check more systems. And no, strftime() isn't helping - it has "%z", which, according to FreeBSD's man page is an extention to the C90 standard...)

Yeah, I once made git use strftime("%z") but that is... handled differently now.

time(&now);

offset = tm_to_time_t(localtime(&now)) - now; offset /= 60;

Where tm_to_time_t() is basically mktime() except that *that* has bizarre issues on some platforms too. But fundamentally, comparing gmtime(now) with localtime(now) might be the way to go.

The alternative option is just to *always* log in UTC, of course... :)

Signature · 1 line

dwmw2

Gert Doering

author

2016-08-13 09:40 UTC #12 lore raw

Hi,

Quoted 11 lines · David Woodhouse

Yeah, I once made git use strftime("%z") but that is... handled differently now.
time(&now);
offset = tm_to_time_t(localtime(&now)) - now; offset /= 60;
Where tm_to_time_t() is basically mktime() except that *that* has bizarre issues on some platforms too. But fundamentally, comparing gmtime(now) with localtime(now) might be the way to go.

After having looked at "man localtime" and "man strftime" on a few platforms we support, I conclude that tm_adjtime and tm_gmtoffs are both out (not on Solaris and AIX) and "%z" as well (not on AIX). Meh.

Can you remember what the "bizarre issues" in mktime() are, and on which platforms? That would be a halfway compact way to find the offset, while reimplementing the "comparing gmtime to localtime" bit (and repeating all possible errors that people have made there in the past) is not something I'm looking forward to...

Quoted 1 line

The alternative option is just to *always* log in UTC, of course... :)

Dunno about others, but I *like* local time in timestamps - it helps my brain put things together, and for some reason, my brain works in local time...

(And yes, it would be much easier indeed... "just log seconds since the Epoch in UTC!" - good enough for log correlation, bad for silly humans :-) )

gert

Signature · 4 lines

USENET is *not* the non-clickable part of WWW!
                                                           //www.muc.de/~gert/
Gert Doering - Munich, Germany                             [email protected]...
fax: +49-89-35655025                        [email protected]...