Wrong log time returned by external web table created to fetch pg

Products

VMware Tanzu Greenplum

Issue/Introduction

Symptoms:
Create a external web table:

CREATE EXTERNAL WEB TABLE public.gp_log_yestoday_master_ext (LIKE gp_toolkit.__gp_log_master_ext)                                                                                           EXECUTE 'cat /data/master/gpseg-1/pg_log/gpdb-2019-06-11_000000.csv'                                                                                                                                 ON MASTER FORMAT 'csv' (delimiter ',' null '' escape '"' quote '"') ENCODING 'UTF8';

Check the records of the table that was just created - you can find it seems to return log entries dated on 2019-06-12. However, the DDL of the external table is to fetch the logs in a pg_log file dated 2019-06-11.

testdb=# select * from public.gp_log_yestoday_master_ext limit 1;
            logtime            | loguser | logdatabase | logpid |  logthread   | loghost | logport |     logsessiontime     | logtransaction | logsession | logcmdcount | logsegment | logslice | log
distxact | loglocalxact | logsubxact | logseverity | logstate |                           logmessage                            | logdetail | loghint | logquery | logquerypos | logcontext |       
               logdebug                       | logcursorpos | logfunction |  logfile   | logline | logstack
-------------------------------+---------+-------------+--------+--------------+---------+---------+------------------------+----------------+------------+-------------+------------+----------+----
---------+--------------+------------+-------------+----------+-----------------------------------------------------------------+-----------+---------+----------+-------------+------------+--------
----------------------------------------------+--------------+-------------+------------+---------+----------
 2019-06-12 04:51:24.793875+08 | gpmon   | gpperfmon   | p1825  | th-100489440 | [local] |         | 2019-06-12 04:51:24+08 |              0 | con30321   | cmd1        | seg-1      |          | dx2
9466     |              | sx1        | LOG         | 00000    | statement: SELECT sess_id, current_query FROM pg_stat_activity; |           |         |          |             |            | SELECT
sess_id, current_query FROM pg_stat_activity; |            0 |             | postgres.c |    1590 |
(1 row)

So does that necessarily mean the table fetch logs that are not required actually?

Environment

Cause

Actually, both of the two are showing correct log entires, the issue is due to the inconsistent timezone between the external table output and the timezone for log.

From the log entries in pg_log files, we can see the time is good and it shows CST(China Standard Time) as expected:

[gpadmin@dw-greenplum-1 pg_log]$ cat ./* | grep -i "con30321"
2019-06-11 14:51:24.793875 CST,"gpmon","gpperfmon",p1825,th-100489440,"[local]",,2019-06-11 14:51:24 CST,0,con30321,cmd1,seg-1,,dx29466,,sx1,"LOG","00000","statement: SELECT sess_id, current_query FROM pg_stat_activity;",,,,,,"SELECT sess_id, current_query FROM pg_stat_activity;",0,,"postgres.c",1590,

However in the table record, the time is 14 hours later although it also shows +08 timezone, which should be the same timezone:

testdb=# select * from public.gp_log_yestoday_master_ext limit 1;
            logtime            | loguser | logdatabase | logpid |  logthread   | loghost | logport |     logsessiontime     | logtransaction | logsession | logcmdcount | logsegment | logslice | log
distxact | loglocalxact | logsubxact | logseverity | logstate |                           logmessage                            | logdetail | loghint | logquery | logquerypos | logcontext |       
               logdebug                       | logcursorpos | logfunction |  logfile   | logline | logstack
-------------------------------+---------+-------------+--------+--------------+---------+---------+------------------------+----------------+------------+-------------+------------+----------+----
---------+--------------+------------+-------------+----------+-----------------------------------------------------------------+-----------+---------+----------+-------------+------------+--------
----------------------------------------------+--------------+-------------+------------+---------+----------
 2019-06-12 04:51:24.793875+08 | gpmon   | gpperfmon   | p1825  | th-100489440 | [local] |         | 2019-06-12 04:51:24+08 |              0 | con30321   | cmd1        | seg-1      |          | dx2
9466     |              | sx1        | LOG         | 00000    | statement: SELECT sess_id, current_query FROM pg_stat_activity; |           |         |          |             |            | SELECT
sess_id, current_query FROM pg_stat_activity; |            0 |             | postgres.c |    1590 |
(1 row)

And we can see both the GUCs log_timezone and timezone are set to "PRC" (China time):

[gpadmin@dw-greenplum-1 pg_log]$ gpconfig -s log_timezone;
Values on all segments are consistent
GUC          : log_timezone
Master  value: PRC
Segment value: PRC
[gpadmin@dw-greenplum-1 pg_log]$ gpconfig -s timezone;
Values on all segments are consistent
GUC          : timezone
Master  value: PRC
Segment value: PRC

When fetching log entries via the external web table, the DB will parse the timezone in pg_log files as another CST (US Center Standard Time) instead of CST (China Standard Time), that's why we can see 14 hours' gap.

Resolution

To workaround this issue, set both of the GUCs log_timezone and timezone to 'Asia/Singapore' and then restart your DB.