TestLongListRemote shall pass

cmd/clickhouse-backup/main.go

@@ -3,16 +3,14 @@ package main
 import (
 	"context"
 	"fmt"
-	stdlog "log"
-	"os"
-	"strconv"
-	"strings"
-	"time"
-
 	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/log"
 	"github.com/rs/zerolog/pkgerrors"
 	"github.com/urfave/cli"
+	stdlog "log"
+	"os"
+	"strconv"
+	"strings"
 
 	"github.com/Altinity/clickhouse-backup/v2/pkg/backup"
 	"github.com/Altinity/clickhouse-backup/v2/pkg/config"
@@ -309,9 +307,7 @@ func main() {
 			UsageText: "clickhouse-backup list [all|local|remote] [latest|previous]",
 			Action: func(c *cli.Context) error {
 				b := backup.NewBackuper(config.GetConfigFromCli(c))
-				listStart := time.Now()
 				err := b.List(c.Args().Get(0), c.Args().Get(1))
-				log.Info().TimeDiff("listTimeMs", time.Now(), listStart).Send()
 				return err
 			},
 			Flags: cliapp.Flags,

pkg/backup/list.go

@@ -19,7 +19,6 @@ import (
 	"sort"
 	"strings"
 	"text/tabwriter"
-	"time"
 )
 
 // List - list backups to stdout from command line
@@ -315,12 +314,10 @@ func (b *Backuper) PrintRemoteBackups(ctx context.Context, format string) error
 			log.Error().Msgf("can't flush tabular writer error: %v", err)
 		}
 	}()
-	getRemoteBackupsStart := time.Now()
 	backupList, err := b.GetRemoteBackups(ctx, true)
 	if err != nil {
 		return err
 	}
-	log.Debug().Dur("b.GetRemoteBackups", time.Since(getRemoteBackupsStart)).Send()
 	err = printBackupsRemote(w, backupList, format)
 	return err
 }
@@ -360,11 +357,9 @@ func (b *Backuper) GetRemoteBackups(ctx context.Context, parseMetadata bool) ([]
 	if err != nil {
 		return []storage.Backup{}, err
 	}
-	bdConnectStart := time.Now()
 	if err := bd.Connect(ctx); err != nil {
 		return []storage.Backup{}, err
 	}
-	log.Debug().Dur("bd.Connect", time.Since(bdConnectStart)).Send()
 	defer func() {
 		if err := bd.Close(ctx); err != nil {
 			log.Warn().Msgf("can't close BackupDestination error: %v", err)

pkg/storage/general.go

@@ -160,7 +160,7 @@ func (bd *BackupDestination) saveMetadataCache(ctx context.Context, listCache ma
 func (bd *BackupDestination) BackupList(ctx context.Context, parseMetadata bool, parseMetadataOnly string) ([]Backup, error) {
 	backupListStart := time.Now()
 	defer func() {
-		log.Debug().Dur("bd.BackupList", time.Since(backupListStart)).Send()
+		log.Info().Dur("list_duration", time.Since(backupListStart)).Send()
 	}()
 	result := make([]Backup, 0)
 	metadataCacheLock.Lock()
@@ -530,10 +530,6 @@ func (bd *BackupDestination) throttleSpeed(startTime time.Time, size int64, maxS
 }
 
 func NewBackupDestination(ctx context.Context, cfg *config.Config, ch *clickhouse.ClickHouse, backupName string) (*BackupDestination, error) {
-	newBackupDestinationStart := time.Now()
-	defer func() {
-		log.Debug().Dur("NewBackupDestination", time.Since(newBackupDestinationStart)).Send()
-	}()
 	var err error
 	switch cfg.General.RemoteStorage {
 	case "azblob":

test/integration/integration_test.go

@@ -505,7 +505,7 @@ func (env *TestEnvironment) Cleanup(t *testing.T, r *require.Assertions) {
 
 }
 
-var listTimeMsRE = regexp.MustCompile(`listTimeMs=(\d+)`)
+var listTimeMsRE = regexp.MustCompile(`list_duration=(\d+.\d+)`)
 
 // TestLongListRemote - no parallel, cause need to restart minio
 func TestLongListRemote(t *testing.T) {
@@ -524,7 +524,7 @@ func TestLongListRemote(t *testing.T) {
 	var err error
 	var cachedOut, nonCachedOut, clearCacheOut string
 	extractListTimeMs := func(out string) float64 {
-		r.Contains(out, "listTimeMs=")
+		r.Contains(out, "list_duration=")
 		matches := listTimeMsRE.FindStringSubmatch(out)
 		r.True(len(matches) == 2)
 		log.Debug().Msgf("extractListTimeMs=%s", matches[1])