fix: detect the custom timezone and adjust last time activity (#504)

Author: agneum

engine/Dockerfile.dblab-cli

@@ -1,7 +1,7 @@
 FROM docker:20.10.24
 
 # Install dependencies.
-RUN apk update && apk add --no-cache bash jq
+RUN apk update && apk add --no-cache bash jq tzdata
 
 WORKDIR /home/dblab
 COPY ./bin/dblab ./bin/dblab

engine/Dockerfile.dblab-server

@@ -4,7 +4,7 @@ FROM docker:20.10.24
 
 # Install dependencies
 RUN apk update \
-  && apk add --no-cache zfs lvm2 bash util-linux
+  && apk add --no-cache zfs lvm2 bash util-linux tzdata
 
 WORKDIR /home/dblab
 

engine/Dockerfile.dblab-server-debug

@@ -17,7 +17,7 @@ FROM docker:20.10.12
 # Install dependencies
 RUN apk update \
   && apk add zfs=2.1.4-r0 --no-cache --repository=https://dl-cdn.alpinelinux.org/alpine/edge/main \
-  && apk add --no-cache lvm2 bash util-linux
+  && apk add --no-cache lvm2 bash util-linux tzdata
 
 WORKDIR /home/dblab
 

engine/Dockerfile.dblab-server-zfs08

@@ -4,7 +4,7 @@ FROM docker:20.10.24
 
 # Install dependencies.
 RUN apk update && apk add zfs=0.8.4-r0 --no-cache --repository=https://dl-cdn.alpinelinux.org/alpine/v3.12/main \
-  && apk add --no-cache lvm2 bash util-linux
+  && apk add --no-cache lvm2 bash util-linux tzdata
 
 WORKDIR /home/dblab
 

engine/internal/provision/databases/postgres/pgconfig/configuration.go

@@ -224,7 +224,7 @@ func (m *Manager) adjustHBAConf() error {
 }
 
 // adjustGeneralConfigs corrects general PostgreSQL parameters with Database Lab configs.
-func (m Manager) adjustGeneralConfigs() error {
+func (m *Manager) adjustGeneralConfigs() error {
 	log.Dbg("Configuring Postgres...")
 
 	pgConfSrc, err := util.GetStandardConfigPath(path.Join(pgCfgDir, pgControlDir, PgConfName))
@@ -439,16 +439,16 @@ func (m *Manager) ApplyUserConfig(cfg map[string]string) error {
 
 // getConfigPath builds a path of the Database Lab config file.
 func (m *Manager) getConfigPath(configName string) string {
-	return path.Join(m.dataDir, configPrefix+configName)
+	return GetConfigPath(m.dataDir, configName)
 }
 
 // recoveryPath returns the path of the recovery configuration file.
-func (m Manager) recoveryPath() string {
+func (m *Manager) recoveryPath() string {
 	return path.Join(m.dataDir, m.recoveryFilename())
 }
 
 // recoveryFilename returns the name of the recovery configuration file.
-func (m Manager) recoveryFilename() string {
+func (m *Manager) recoveryFilename() string {
 	if m.pgVersion >= defaults.PGVersion12 {
 		return configPrefix + recoveryConfName
 	}
@@ -457,12 +457,12 @@ func (m Manager) recoveryFilename() string {
 }
 
 // recoverySignalPath returns the path of the recovery signal file.
-func (m Manager) recoverySignalPath() string {
+func (m *Manager) recoverySignalPath() string {
 	return path.Join(m.dataDir, recoverySignal)
 }
 
 // standbySignalPath returns the path of the standby signal file.
-func (m Manager) standbySignalPath() string {
+func (m *Manager) standbySignalPath() string {
 	return path.Join(m.dataDir, standbySignal)
 }
 
@@ -509,6 +509,16 @@ func (m *Manager) truncateConfig(pgConf string) error {
 	return os.WriteFile(pgConf, []byte{}, 0644)
 }
 
+// ReadUserConfig reads user configuration file.
+func ReadUserConfig(dataDir string) (map[string]string, error) {
+	return readConfig(GetConfigPath(dataDir, userConfigName))
+}
+
+// GetConfigPath returns configuration path.
+func GetConfigPath(dataDir, configName string) string {
+	return path.Join(dataDir, configPrefix+configName)
+}
+
 // readConfig reads a configuration file.
 func readConfig(cfgFile string) (map[string]string, error) {
 	config := make(map[string]string)

engine/internal/provision/mode_local.go

@@ -24,6 +24,7 @@ import (
 	"github.com/pkg/errors"
 
 	"gitlab.com/postgres-ai/database-lab/v3/internal/provision/databases/postgres"
+	"gitlab.com/postgres-ai/database-lab/v3/internal/provision/databases/postgres/pgconfig"
 	"gitlab.com/postgres-ai/database-lab/v3/internal/provision/docker"
 	"gitlab.com/postgres-ai/database-lab/v3/internal/provision/pool"
 	"gitlab.com/postgres-ai/database-lab/v3/internal/provision/resources"
@@ -620,12 +621,15 @@ func (p *Provisioner) LastSessionActivity(session *resources.Session, minimumTim
 	ctx, cancel := context.WithCancel(p.ctx)
 	defer cancel()
 
-	fileSelector := pglog.NewSelector(fsm.Pool().ClonePath(session.Port))
+	clonePath := fsm.Pool().ClonePath(session.Port)
+	fileSelector := pglog.NewSelector(clonePath)
 
 	if err := fileSelector.DiscoverLogDir(); err != nil {
 		return nil, errors.Wrap(err, "failed to init file selector")
 	}
 
+	location := detectLogsTimeZone(clonePath)
+
 	fileSelector.SetMinimumTime(minimumTime)
 	fileSelector.FilterOldFilesInList()
 
@@ -639,7 +643,7 @@ func (p *Provisioner) LastSessionActivity(session *resources.Session, minimumTim
 			return nil, errors.Wrap(err, "failed get CSV log filenames")
 		}
 
-		activity, err := p.scanCSVLogFile(ctx, filename, minimumTime)
+		activity, err := p.scanCSVLogFile(ctx, filename, minimumTime, location)
 		if err == io.EOF {
 			continue
 		}
@@ -650,12 +654,39 @@ func (p *Provisioner) LastSessionActivity(session *resources.Session, minimumTim
 	return nil, pglog.ErrNotFound
 }
 
-const csvMessageLogFieldsLength = 14
+const (
+	csvMessageLogFieldsLength = 14
+	logTZ                     = "log_timezone"
+)
+
+func detectLogsTimeZone(dataDir string) *time.Location {
+	userCfg, err := pgconfig.ReadUserConfig(dataDir)
+	if err != nil {
+		log.Msg("unable to read user-defined config of clone:", err.Error())
+
+		return time.UTC
+	}
+
+	if tz, ok := userCfg[logTZ]; ok {
+		location, err := time.LoadLocation(tz)
+
+		if err != nil {
+			log.Msg(fmt.Sprintf("unable to load location (%q) defined in config: %s", tz, err.Error()))
+
+			return time.UTC
+		}
+
+		return location
+	}
+
+	return time.UTC
+}
 
-func (p *Provisioner) scanCSVLogFile(ctx context.Context, filename string, availableTime time.Time) (*time.Time, error) {
+func (p *Provisioner) scanCSVLogFile(ctx context.Context, filename string, availableTime time.Time,
+	location *time.Location) (*time.Time, error) {
 	csvFile, err := os.Open(filename)
 	if err != nil {
-		return nil, errors.Wrap(err, "failed to open a CSV log file")
+		return nil, errors.Wrap(err, "failed to open CSV log file")
 	}
 
 	defer func() {
@@ -683,13 +714,13 @@ func (p *Provisioner) scanCSVLogFile(ctx context.Context, filename string, avail
 		logTime := entry[0]
 		logMessage := entry[13]
 
-		lastActivity, err := pglog.ParsePostgresLastActivity(logTime, logMessage)
+		lastActivity, err := pglog.ParsePostgresLastActivity(logTime, logMessage, location)
 		if err != nil {
-			return nil, errors.Wrapf(err, "failed to get the time of last activity")
+			return nil, errors.Wrapf(err, "failed to determine last activity timestamp")
 		}
 
 		// Filter invalid and non-recent activity.
-		if lastActivity == nil || lastActivity.Before(availableTime) {
+		if lastActivity == nil || lastActivity.In(time.UTC).Before(availableTime) {
 			continue
 		}
 

engine/internal/provision/mode_local_test.go

@@ -2,6 +2,8 @@ package provision
 
 import (
 	"context"
+	"os"
+	"path"
 	"testing"
 	"time"
 
@@ -240,3 +242,87 @@ func TestLatestSnapshot(t *testing.T) {
 		}
 	})
 }
+
+func TestDetectLogsTimeZone(t *testing.T) {
+	tempDir := path.Join(os.TempDir(), "dle_logs_tz")
+	defer os.RemoveAll(tempDir)
+
+	const (
+		layout         = "2006-01-02 15:04:05.000 MST"
+		datetime       = "2023-04-28 12:50:10.779 CEST"
+		emptyContent   = `# PostgreSQL configuration file`
+		invalidContent = `# PostgreSQL configuration file
+# TimeZone setting
+log_timezone = 'America/Stockholm'
+`
+		validContent = `# PostgreSQL configuration file
+# TimeZone setting
+log_timezone = 'Europe/Stockholm'
+`
+	)
+
+	tests := []struct {
+		name        string
+		dataDir     string
+		fileName    string
+		content     string
+		expectedLoc *time.Location
+	}{
+		{
+			name:        "no config file",
+			dataDir:     "/path/to/missing/config",
+			fileName:    "missing_config",
+			expectedLoc: time.UTC,
+		},
+		{
+			name:        "config file without timezone",
+			dataDir:     "empty_config",
+			fileName:    "postgresql.dblab.user_defined.conf",
+			content:     emptyContent,
+			expectedLoc: time.UTC,
+		},
+		{
+			name:        "config file with invalid timezone",
+			dataDir:     "invalid_dir",
+			fileName:    "postgresql.dblab.user_defined.conf",
+			content:     invalidContent,
+			expectedLoc: time.UTC,
+		},
+		{
+			name:        "config file with valid timezone",
+			dataDir:     "valid_dir",
+			fileName:    "postgresql.dblab.user_defined.conf",
+			content:     validContent,
+			expectedLoc: time.FixedZone("CEST", 2*60*60), // CEST (+2)
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			testCaseDir := path.Join(tempDir, tt.dataDir)
+			err := createTempConfigFile(testCaseDir, tt.fileName, tt.content)
+			require.NoError(t, err)
+
+			loc := detectLogsTimeZone(testCaseDir)
+
+			expectedTime, err := time.ParseInLocation(layout, datetime, tt.expectedLoc)
+			require.NoError(t, err)
+
+			locationTime, err := time.ParseInLocation(layout, datetime, loc)
+			require.NoError(t, err)
+
+			require.Truef(t, locationTime.UTC().Equal(expectedTime.UTC()), "detectLogsTimeZone(%s) returned unexpected location time. Expected %s, but got %s.", tt.dataDir, expectedTime, locationTime)
+		})
+	}
+}
+
+func createTempConfigFile(testCaseDir, fileName string, content string) error {
+	err := os.MkdirAll(testCaseDir, 0777)
+	if err != nil {
+		return err
+	}
+
+	fn := path.Join(testCaseDir, fileName)
+
+	return os.WriteFile(fn, []byte(content), 0666)
+}

engine/pkg/util/pglog/activity.go

@@ -124,12 +124,12 @@ func (s *Selector) FilterOldFilesInList() {
 }
 
 // ParsePostgresLastActivity extracts the time of last session activity.
-func ParsePostgresLastActivity(logTime, text string) (*time.Time, error) {
+func ParsePostgresLastActivity(logTime, text string, loc *time.Location) (*time.Time, error) {
 	if logTime == "" || !(strings.Contains(text, "statement:") || strings.Contains(text, "duration:")) {
 		return nil, nil
 	}
 
-	lastActivityTime, err := time.Parse("2006-01-02 15:04:05.000 MST", logTime)
+	lastActivityTime, err := time.ParseInLocation("2006-01-02 15:04:05.000 MST", logTime, loc)
 	if err != nil {
 		return nil, errs.Wrap(err, "failed to parse the last activity time")
 	}

engine/pkg/util/pglog/activity_test.go

@@ -14,20 +14,24 @@ func TestGetPostgresLastActivity(t *testing.T) {
 		logTime      string
 		logMessage   string
 		timeActivity *time.Time
+		loc          *time.Location
 	}{
 		{
 			logTime:      "2020-01-10 11:49:14.615 UTC",
 			logMessage:   "duration: 9.893 ms  statement: SELECT 1;",
+			loc:          time.UTC,
 			timeActivity: pointer.ToTime(time.Date(2020, 1, 10, 11, 49, 14, 615000000, time.UTC)),
 		},
 		{
 			logTime:      "2020-01-10 11:49:14.615 CET",
 			logMessage:   "duration: 9.893 ms  statement: SELECT 1;",
-			timeActivity: pointer.ToTime(time.Date(2020, 1, 10, 11, 49, 14, 615000000, time.FixedZone("CET", 0))),
+			loc:          time.FixedZone("CET", 3600),
+			timeActivity: pointer.ToTime(time.Date(2020, 1, 10, 11, 49, 14, 615000000, time.FixedZone("CET", 3600))),
 		},
 		{
 			logTime:      "2020-01-11 13:10:58.503 UTC",
 			logMessage:   "duration: 0.077 ms  statement:",
+			loc:          time.UTC,
 			timeActivity: pointer.ToTime(time.Date(2020, 1, 11, 13, 10, 58, 503000000, time.UTC)),
 		},
 		{
@@ -48,7 +52,7 @@ func TestGetPostgresLastActivity(t *testing.T) {
 	}
 
 	for _, tc := range testCases {
-		lastActivity, err := ParsePostgresLastActivity(tc.logTime, tc.logMessage)
+		lastActivity, err := ParsePostgresLastActivity(tc.logTime, tc.logMessage, tc.loc)
 		require.NoError(t, err)
 		assert.Equal(t, tc.timeActivity, lastActivity)
 	}
@@ -68,7 +72,7 @@ func TestGetPostgresLastActivityWhenFailedParseTime(t *testing.T) {
 	}
 
 	for _, tc := range testCases {
-		lastActivity, err := ParsePostgresLastActivity(tc.logTime, tc.logMessage)
+		lastActivity, err := ParsePostgresLastActivity(tc.logTime, tc.logMessage, time.UTC)
 		require.Nil(t, lastActivity)
 		assert.EqualError(t, err, tc.errorString)
 	}