BUG#32893161: BACKPORT 28632725 TO 5.7

When using --log-timestamps=system, ISO8601 timestamps in
logging would always show the timezone's default offset to
UTC, even when DST was active.

Note:
This is a backport of the fix for Bug#28632725 to 5.7.

Change-Id: I488f3468cc320de555cea7bb6f911e9c2f82e225

Author: karthik-kamath

config.h.cmake

@@ -187,6 +187,7 @@
 #cmakedefine HAVE_ULONG 1
 #cmakedefine HAVE_U_INT32_T 1
 #cmakedefine HAVE_STRUCT_TIMESPEC
+#cmakedefine HAVE_TM_GMTOFF 1
 
 /* Support for tagging symbols with __attribute__((visibility("hidden"))) */
 #cmakedefine HAVE_VISIBILITY_HIDDEN 1

configure.cmake

@@ -445,6 +445,9 @@ CHECK_TYPE_SIZE("off_t"     SIZEOF_OFF_T)
 CHECK_TYPE_SIZE("time_t"    SIZEOF_TIME_T)
 CHECK_TYPE_SIZE("struct timespec" STRUCT_TIMESPEC)
 
+CHECK_STRUCT_HAS_MEMBER("struct tm"
+ tm_gmtoff "time.h" HAVE_TM_GMTOFF)
+
 # If finds the size of a type, set SIZEOF_<type> and HAVE_<type>
 FUNCTION(MY_CHECK_TYPE_SIZE type defbase)
   CHECK_TYPE_SIZE("${type}" SIZEOF_${defbase})

sql/log.cc

@@ -60,10 +60,6 @@ static int   log_syslog_facility= 0;
 static char *log_syslog_ident   = NULL;
 static bool  log_syslog_enabled = false;
 
-
-/* 26 for regular timestamp, plus 7 (".123456") when using micro-seconds */
-static const int iso8601_size= 33;
-
 enum enum_slow_query_log_table_field
 {
   SQLT_FIELD_START_TIME = 0,
@@ -467,7 +463,7 @@ static void ull2timeval(ulonglong utime, struct timeval *tv)
   @return          length of timestamp (excluding \0)
 */
 
-static int make_iso8601_timestamp(char *buf, ulonglong utime= 0)
+int make_iso8601_timestamp(char *buf, ulonglong utime)
 {
   struct tm  my_tm;
   char       tzinfo[7]="Z";  // max 6 chars plus \0
@@ -486,16 +482,24 @@ static int make_iso8601_timestamp(char *buf, ulonglong utime= 0)
   {
     localtime_r(&seconds, &my_tm);
 
-#ifdef __FreeBSD__
+#ifdef HAVE_TM_GMTOFF
     /*
       The field tm_gmtoff is the offset (in seconds) of the time represented
       from UTC, with positive values indicating east of the Prime Meridian.
+      Originally a BSDism, this is also supported in glibc, so this should
+      cover the majority of our platforms.
     */
     long tim= -my_tm.tm_gmtoff;
-#elif _WIN32
-    long tim = _timezone;
 #else
-    long tim= timezone; // seconds West of UTC.
+    /*
+       Work this out "manually".
+    */
+    struct tm my_gm;
+    long tim, gm;
+    gmtime_r(&seconds, &my_gm);
+    gm = (my_gm.tm_sec + 60 * (my_gm.tm_min + 60 * my_gm.tm_hour));
+    tim = (my_tm.tm_sec + 60 * (my_tm.tm_min + 60 * my_tm.tm_hour));
+    tim = gm - tim;
 #endif
     char dir= '-';
 

sql/log.h

@@ -969,4 +969,18 @@ bool log_syslog_find_facility(char *f, SYSLOG_FACILITY *rsf);
 bool log_syslog_init();
 void log_syslog_exit();
 
+/* 26 for regular timestamp, plus 7 (".123456") when using micro-seconds */
+static const int iso8601_size = 33;
+
+/**
+  Make and return an ISO 8601 / RFC 3339 compliant timestamp.
+  Heeds log_timestamps.
+
+  @param buf       A buffer of at least 26 bytes to store the timestamp in
+                   (19 + tzinfo tail + \0)
+  @param seconds   Seconds since the epoch, or 0 for "now"
+
+  @return          length of timestamp (excluding \0)
+*/
+int make_iso8601_timestamp(char *buf, ulonglong utime = 0);
 #endif /* LOG_H */

unittest/gunit/CMakeLists.txt

@@ -331,6 +331,7 @@ SET(SERVER_TESTS
   json_path
   locking_service
   log_throttle
+  log_timestamp
   make_sortkey
   mdl_sync
   my_decimal

unittest/gunit/log_timestamp-t.cc

@@ -0,0 +1,138 @@
+/* Copyright (c) 2022, Oracle and/or its affiliates. All rights reserved.
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; version 2 of the License.
+
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+   GNU General Public License for more details.
+
+   You should have received a copy of the GNU General Public License
+   along with this program; if not, write to the Free Software
+   Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA */
+
+// First include (the generated) my_config.h, to get correct platform defines,
+// then gtest.h (before any other MySQL headers), to avoid min() macros etc ...
+
+#ifdef _WIN32_WINNT
+#if (_WIN32_WINNT < 0x0602)
+#undef _WIN32_WINNT
+// We need at least _WIN32_WINNT_WIN8 i.e. 0x0602 for
+// EnumDynamicTimeZoneInformation
+#define _WIN32_WINNT 0x0602
+#endif // (_WIN32_WINNT < 0x0602)
+#endif // _WIN32_WINNT
+
+#include "my_config.h"
+#include "test_utils.h"
+#include <gtest/gtest.h>
+#include <stdlib.h>
+
+#include "../sql/log.h"
+
+// CET: 32 bytes
+//   date (10), 'T', time (8), '.', microseconds (6), timezone offset (6)
+#define LEN_MS_CET 32
+
+// UTC: 27 bytes
+//   date (10), 'T', time (8), '.', microseconds (6), 'Z'
+#define LEN_MS_UTC 27
+
+// we use micro-seconds since the epoch
+#define MICRO_FAC ((ulonglong)1000000L)
+
+namespace log_timestamp_unittest
+{
+
+using my_testing::Server_initializer;
+
+class LogTimestampTest : public ::testing::Test
+{
+protected:
+  virtual void SetUp() { initializer.SetUp(); }
+  virtual void TearDown() { initializer.TearDown(); }
+
+  THD *thd() { return initializer.thd(); }
+
+  Server_initializer initializer;
+};
+
+/*
+  Test basic functionality - throttling, eligibility, printing of summary of
+                             Slow_log_throttle.
+*/
+TEST_F(LogTimestampTest, iso8601)
+{
+  char time_buff[iso8601_size];
+#ifdef WIN32
+  DYNAMIC_TIME_ZONE_INFORMATION original_dti = {};
+  DWORD original_dti_result = GetDynamicTimeZoneInformation(&original_dti);
+  EXPECT_NE(original_dti_result, TIME_ZONE_ID_INVALID);
+
+  if (original_dti.DaylightDate.wMonth == 0)
+  {
+    /*
+      Current system time zone does not support Daylight savings. If the Windows
+      system time zone has no daylight saving, then attempting to set TZ to a
+      timezone that does have daylight saving will result in localtime_r
+      producing inaccurate results. Skipping the test.
+      Bug#34380460 will be tracking this issue.
+    */
+    return;
+  }
+  char tz[] = "TZ=CET-1CES";
+#else
+  char tz[] = "TZ=CET";
+#endif
+  int time_buff_len;
+
+  EXPECT_EQ(((iso8601_size)-1), LEN_MS_CET);
+  EXPECT_EQ(((LEN_MS_CET)-5), LEN_MS_UTC);
+
+  // set up timezone (central european time)
+  putenv(tz);
+  EXPECT_STREQ(&(tz[3]), getenv("TZ"));
+  tzset();
+
+  /// 1970/01/01 .000001  (1)
+
+  // UTC (winter)
+  opt_log_timestamps = 0; // UTC Timestamp
+  time_buff_len = make_iso8601_timestamp(time_buff, 1);
+  EXPECT_EQ(LEN_MS_UTC, time_buff_len);
+  EXPECT_STREQ("1970-01-01T00:00:00.000001Z", time_buff);
+
+  // CET (winter) +1h
+  opt_log_timestamps = 1; // System Timestamp
+  time_buff_len = make_iso8601_timestamp(time_buff, 1);
+  EXPECT_EQ(LEN_MS_CET, time_buff_len);
+  EXPECT_STREQ("1970-01-01T01:00:00.000001+01:00", time_buff);
+
+  /// 2011-07-07  (1309996800)
+
+  // UTC (summer)
+  opt_log_timestamps = 0;
+  time_buff_len = make_iso8601_timestamp(time_buff, MICRO_FAC * 1309996800);
+  EXPECT_EQ(LEN_MS_UTC, time_buff_len);
+  EXPECT_STREQ("2011-07-07T00:00:00.000000Z", time_buff);
+
+  // CET (summer) +2h
+  opt_log_timestamps = 1;
+  time_buff_len = make_iso8601_timestamp(time_buff, MICRO_FAC * 1309996800);
+  EXPECT_EQ(LEN_MS_CET, time_buff_len);
+  EXPECT_STREQ("2011-07-07T02:00:00.000000+02:00", time_buff);
+
+  /// 1987-06-05 04:03:02.123456
+
+  // UTC
+  opt_log_timestamps = 0;
+  time_buff_len = make_iso8601_timestamp(
+      time_buff, (MICRO_FAC * 549864182) + 123456);
+  EXPECT_EQ(LEN_MS_UTC, time_buff_len);
+  EXPECT_STREQ("1987-06-05T04:03:02.123456Z", time_buff);
+}
+// End of Error_log_timestamp test cases.
+
+}  // namespace log_timestamp_unittest