Skip to content

Conversation

@dveeden
Copy link
Contributor

@dveeden dveeden commented Sep 4, 2025

What problem does this PR solve?

Issue Number: close #855

Problem Summary:

Logging is setup based with the generic NewConfig() and used during the initial parsing of the config file. Then later the watcher is correcting things where needed. However the encoder isn't changed. This results in the encoder from the config to be ignored.

What is changed and how it works:

  1. Change the reading of the config to not use the logger at all. Messages might now go to stderr instead.
  2. Delay the setup of logger until we have a config.
  3. Print the config once we have the config and a logger.

As indicated for the changes in TestChecksum:

  • With these changes the config isn't printed again when it changes
  • The printing of the config is done in a different part of the code.

Check List

Tests

  • Unit test
  • Integration test
  • Manual test (add detailed scripts or steps below)
  • No code

Notable changes

  • Has configuration change
  • Has HTTP API interfaces change
  • Has tiproxyctl change
  • Other user behavior changes

Release note

Please refer to Release Notes Language Style Guide to write a quality release note.

Handling of the log encoder was corrected.

@ti-chi-bot
Copy link

ti-chi-bot bot commented Sep 4, 2025

Skipping CI for Draft Pull Request.
If you want CI signal for your change, please convert it to an actual PR.
You can still manually trigger a test run with /test all

@dveeden
Copy link
Contributor Author

dveeden commented Sep 4, 2025

/cc @djshow832

@ti-chi-bot ti-chi-bot bot requested a review from djshow832 September 4, 2025 07:54
@dveeden dveeden marked this pull request as ready for review September 4, 2025 07:54
@dveeden
Copy link
Contributor Author

dveeden commented Sep 4, 2025

This should probably get some more tests:

  • With a logfile configured there should not be any output to stdout
  • With a json encoder configured the output should parse as valid json

@dveeden
Copy link
Contributor Author

dveeden commented Sep 4, 2025

$ ./bin/tiproxy --config=<(echo -en '[log]\nencoder = "json"\n') | head -1 | jq .
{
  "level": "INFO",
  "ts": "2025/09/04 10:00:58.199 +02:00",
  "logger": "main",
  "caller": "server/server.go:220",
  "msg": "Welcome to TiProxy.",
  "Release Version": "v1.4.0-beta.1-32-gd3f8304-dirty",
  "Git Commit Hash": "d3f830449f31e989e170340f6edc4627c0a09baa-dirty",
  "Git Branch": "main",
  "UTC Build Time": "2025-09-04 07:45:15",
  "GoVersion": "go1.24.6",
  "OS": "linux",
  "Arch": "amd64"
}

And with the current main branch:

dvaneeden@dve-carbon:~/dev/pingcap/tiproxy$ ./bin/tiproxy --config=<(echo -en '[log]\nencoder = "json"\n') | head -1 | jq .
jq: parse error: Invalid numeric literal at line 1, column 12
dvaneeden@dve-carbon:~/dev/pingcap/tiproxy$ ./bin/tiproxy --config=<(echo -en '[log]\nencoder = "json"\n') | head -1
[2025/09/04 10:02:05.431 +02:00] [INFO] [main.config] [config/config.go:71] [current config]  [cfg="{\"proxy\":{\"addr\":\"0.0.0.0:6000\",\"pd-addrs\":\"127.0.0.1:2379\",\"frontend-keepalive\":{\"enabled\":true},\"backend-healthy-keepalive\":{\"enabled\":true,\"idle\":60000000000,\"cnt\":5,\"intvl\":3000000000,\"timeout\":15000000000},\"backend-unhealthy-keepalive\":{\"enabled\":true,\"idle\":10000000000,\"cnt\":5,\"intvl\":1000000000,\"timeout\":5000000000},\"graceful-close-conn-timeout\":15},\"api\":{\"addr\":\"0.0.0.0:3080\"},\"workdir\":\"/home/dvaneeden/dev/pingcap/tiproxy/work\",\"security\":{\"server-tls\":{\"min-tls-version\":\"1.2\"},\"server-http-tls\":{\"min-tls-version\":\"1.2\"},\"cluster-tls\":{\"min-tls-version\":\"1.2\"},\"sql-tls\":{\"min-tls-version\":\"1.2\"}},\"log\":{\"encoder\":\"json\",\"level\":\"info\",\"log-file\":{\"max-size\":300,\"max-days\":3,\"max-backups\":3}},\"balance\":{\"policy\":\"resource\"},\"ha\":{},\"enable-traffic-replay\":true}"]

@codecov-commenter
Copy link

Codecov Report

❌ Patch coverage is 83.33333% with 2 lines in your changes missing coverage. Please review.
⚠️ Please upload report for BASE (main@d3f8304). Learn more about missing BASE report.

Files with missing lines Patch % Lines
pkg/server/server.go 80.00% 0 Missing and 2 partials ⚠️
Additional details and impacted files
@@           Coverage Diff           @@
##             main     #856   +/-   ##
=======================================
  Coverage        ?   67.09%           
=======================================
  Files           ?      129           
  Lines           ?    12261           
  Branches        ?        0           
=======================================
  Hits            ?     8226           
  Misses          ?     3451           
  Partials        ?      584           
Flag Coverage Δ
unit 67.09% <83.33%> (?)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

djshow832

This comment was marked as outdated.

@ti-chi-bot
Copy link

ti-chi-bot bot commented Sep 8, 2025

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: djshow832

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@djshow832
Copy link
Collaborator

Unit test failed. @dveeden

@ti-chi-bot ti-chi-bot bot removed the lgtm label Sep 23, 2025
@ti-chi-bot
Copy link

ti-chi-bot bot commented Sep 23, 2025

[LGTM Timeline notifier]

Timeline:

  • 2025-09-08 13:37:25.292936132 +0000 UTC m=+282111.852817629: ☑️ agreed by djshow832.
  • 2025-09-23 14:09:26.687133386 +0000 UTC m=+365776.757627069: ✖️🔁 reset by dveeden.

@ti-chi-bot
Copy link

ti-chi-bot bot commented Sep 23, 2025

New changes are detected. LGTM label has been removed.

@dveeden
Copy link
Contributor Author

dveeden commented Sep 23, 2025

Unit test failed. @dveeden

I'm working on this

@dveeden
Copy link
Contributor Author

dveeden commented Nov 6, 2025

I haven't figured out why the test is failing exactly.

When I run ./tiproxy --config tiproxy.toml and edit the config then I see it picking up changes in log level and filename.

The part of the TestUpdateCfg test that fails is this:

		{
			updateCfg: func(cfg *config.LogOnline) {
				cfg.LogFile.MaxSize = 3
				cfg.LogFile.MaxBackups = 5
			},
			action: func(log *zap.Logger) {
				for range 5 {
					msg := strings.Repeat("a", 500*1024)
					log.Info(msg)
				}
			},
			check: func(files []os.FileInfo) bool {
				if len(files) != 1 {
					return false
				}
				return files[0].Size() >= int64(5*500*1024)
			},
		},

After running the updateCfg and the action the check doesn't get the expected size but instead gets a lower size.

@dveeden
Copy link
Contributor Author

dveeden commented Nov 6, 2025

When debugging this I can see that the for look that does the log.Info(msg) writes to the file with every iteration.
I also see that the file had leftovers from test case 0, the bbbbb....
Note that I only sees 4 aaaa... lines as it hits the breakpoint before the actual logging is done, this is expected.

breakpoints:

  • bp 1: manager_test.go:69 ( log.Info(msg) )
  • bp 2: manager_test.go:73 ( if len(files) != 1 { )

First bp 1 hit: size = 615554

dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | cut -c 1-200
[2025/11/06 13:32:18.675 +01:00] [ERROR] [main.another] [logger/manager_test.go:55] [bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | wc -c
615554

Second bp 1 hit: size = 1127659

dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | cut -c 1-200
[2025/11/06 13:32:18.675 +01:00] [ERROR] [main.another] [logger/manager_test.go:55] [bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:35:14.599 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | wc -c
1127659

Third bp 1 hit: size = 1639764

dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | cut -c 1-200
[2025/11/06 13:32:18.675 +01:00] [ERROR] [main.another] [logger/manager_test.go:55] [bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:35:14.599 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[2025/11/06 13:36:20.676 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | wc -c
1639764

Fourth bp 1 hit: size = 2151869

dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | cut -c 1-200
[2025/11/06 13:32:18.675 +01:00] [ERROR] [main.another] [logger/manager_test.go:55] [bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:35:14.599 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[2025/11/06 13:36:20.676 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[2025/11/06 13:37:07.573 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | wc -c
2151869

Fifth bp 1 hit: size = 2663974

dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | cut -c 1-200
[2025/11/06 13:32:18.675 +01:00] [ERROR] [main.another] [logger/manager_test.go:55] [bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:32:18.726 +01:00] [INFO] [main.lgmgr] [logger/manager.go:80] [current config]  [cfg="{\"proxy\":{\"frontend-keepalive\":{},\"backend-healthy-keepalive\":{},\"backend-unhealthy-keepalive
[2025/11/06 13:35:14.599 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[2025/11/06 13:36:20.676 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[2025/11/06 13:37:07.573 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[2025/11/06 13:38:33.560 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | wc -c
2663974

Hitting bp 2:

dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | cut -c 1-200
[2025/11/06 13:39:49.243 +01:00] [INFO] [main.another] [logger/manager_test.go:69] [aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
dvaneeden@dve-carbon:~$ cat /proc/$(pgrep -f tiproxy)/fd/4 | wc -c
512105

@dveeden
Copy link
Contributor Author

dveeden commented Nov 6, 2025

This shows that it seems to pickup the cfg.LogFile.MaxSize = 3 and cfg.LogFile.MaxBackups = 5 correctly.

dvaneeden@dve-carbon:~/dev/pingcap/tiproxy/pkg/manager/logger$ dlv test -- -test.run '^TestUpdateCfg$'
Type 'help' for list of commands.
(dlv) b manager_test.go:69
Breakpoint 1 set at 0xb78535 for github.com/pingcap/tiproxy/pkg/manager/logger.TestUpdateCfg.func5() ./manager_test.go:69
(dlv) c
> [Breakpoint 1] github.com/pingcap/tiproxy/pkg/manager/logger.TestUpdateCfg.func5() ./manager_test.go:69 (hits goroutine(34):1 total:1) (PC: 0xb78535)
    64:					cfg.LogFile.MaxBackups = 5
    65:				},
    66:				action: func(log *zap.Logger) {
    67:					for range 5 {
    68:						msg := strings.Repeat("a", 500*1024)
=>  69:						log.Info(msg)
    70:					}
    71:				},
    72:				check: func(files []os.FileInfo) bool {
    73:					if len(files) != 1 {
    74:						return false
(dlv) p log.core.out.output.Logger.Filename
"/tmp/TestUpdateCfg2325804022/001/proxy.log"
(dlv) p log.core.out.output.Logger.MaxSize
3
(dlv) p log.core.out.output.Logger.MaxBackups
5

@dveeden
Copy link
Contributor Author

dveeden commented Nov 6, 2025

Watching the output of ls -li for the fds of the test process:

dvaneeden@dve-carbon:/proc/1666863/fd$ ls -li
total 0
4571402 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 0 -> /dev/null
4571403 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 1 -> /dev/pts/0
4571404 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 2 -> /dev/pts/0
4571405 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 4 -> 'anon_inode:[eventpoll]'
4571406 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 5 -> 'anon_inode:[eventfd]'
4571407 l-wx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 6 -> '/tmp/TestUpdateCfg2662703283/001/proxy.log (deleted)'
dvaneeden@dve-carbon:/proc/1666863/fd$ ls -li
total 0
4571402 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 0 -> /dev/null
4571403 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 1 -> /dev/pts/0
4571404 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 2 -> /dev/pts/0
4571405 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 4 -> 'anon_inode:[eventpoll]'
4571406 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 5 -> 'anon_inode:[eventfd]'
4571407 l-wx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 6 -> '/tmp/TestUpdateCfg2662703283/001/proxy.log (deleted)'
dvaneeden@dve-carbon:/proc/1666863/fd$ ls -li
total 0
4571402 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 0 -> /dev/null
4571403 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 1 -> /dev/pts/0
4571404 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 2 -> /dev/pts/0
4571405 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 4 -> 'anon_inode:[eventpoll]'
4571406 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 5 -> 'anon_inode:[eventfd]'
4571407 l-wx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 6 -> '/tmp/TestUpdateCfg2662703283/001/proxy.log (deleted)'
dvaneeden@dve-carbon:/proc/1666863/fd$ ls -li
total 0
4571402 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 0 -> /dev/null
4571403 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 1 -> /dev/pts/0
4571404 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 2 -> /dev/pts/0
4573420 l-wx------. 1 dvaneeden dvaneeden 64 Nov  6 14:05 3 -> /tmp/TestUpdateCfg2662703283/001/proxy.log
4571405 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 4 -> 'anon_inode:[eventpoll]'
4571406 lrwx------. 1 dvaneeden dvaneeden 64 Nov  6 14:04 5 -> 'anon_inode:[eventfd]'

This shows that once it starts to do the check, the inode number changes from 4571407 to 4573420 and that ls no longer shows (deleted) after the filename.

So it looks like something closes the old fd and creates a new fd before the check runs.

@dveeden
Copy link
Contributor Author

dveeden commented Nov 6, 2025

Looks like this makes the test succeed. But it is probably not the right solution.

diff --git a/pkg/manager/logger/manager_test.go b/pkg/manager/logger/manager_test.go
index 36d4d3f..e675fd1 100644
--- a/pkg/manager/logger/manager_test.go
+++ b/pkg/manager/logger/manager_test.go
@@ -116,8 +116,10 @@ func TestUpdateCfg(t *testing.T) {
                // 2rd will block due to watch channel of size 1
                // this ensured all old data are flushed by closing the older file logger
                ch <- clonedCfg
+               ch <- clonedCfg
 
                // delete old data after flushed
+               os.Remove(fileName)
                err := os.RemoveAll(dir)
                require.NoError(t, err)
 

zap.NamedError("cfg marshal error", merr),
)
}
lm.logger.Info("current config", zap.Any("cfg", acfg))
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The test fails because the logger outputs another thing each time the config is updated.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I suggest you to modify the log level in the test to skip this log. Remember to add a comment to explain this.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I tried this:

diff --git a/pkg/manager/logger/manager_test.go b/pkg/manager/logger/manager_test.go
index 36d4d3f..9562476 100644
--- a/pkg/manager/logger/manager_test.go
+++ b/pkg/manager/logger/manager_test.go
@@ -27,7 +27,7 @@ func TestUpdateCfg(t *testing.T) {
                Log: config.Log{
                        Encoder: "tidb",
                        LogOnline: config.LogOnline{
-                               Level: "info",
+                               Level: "error",
                                LogFile: config.LogFile{
                                        Filename:   fileName,
                                        MaxSize:    1,

And this:

diff --git a/pkg/manager/logger/manager_test.go b/pkg/manager/logger/manager_test.go
index 36d4d3f..54216d6 100644
--- a/pkg/manager/logger/manager_test.go
+++ b/pkg/manager/logger/manager_test.go
@@ -60,6 +60,7 @@ func TestUpdateCfg(t *testing.T) {
                },
                {
                        updateCfg: func(cfg *config.LogOnline) {
+                               cfg.Level = "error"
                                cfg.LogFile.MaxSize = 3
                                cfg.LogFile.MaxBackups = 5
                        },

But neither of these seems to work.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Commenting out the line like this also doesn't work:

diff --git a/pkg/manager/logger/manager.go b/pkg/manager/logger/manager.go
index 97f200c..76c7e76 100644
--- a/pkg/manager/logger/manager.go
+++ b/pkg/manager/logger/manager.go
@@ -77,7 +77,7 @@ func (lm *LoggerManager) watchCfg(ctx context.Context, cfgch <-chan *config.Conf
                                        zap.NamedError("cfg marshal error", merr),
                                )
                        }
-                       lm.logger.Info("current config", zap.Any("cfg", acfg))
+                       // lm.logger.Info("current config", zap.Any("cfg", acfg))
                }
        }
 }

@ti-chi-bot
Copy link

ti-chi-bot bot commented Nov 10, 2025

@dveeden: The following test failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name Commit Details Required Rerun command
pull-unit-test bf65ecd link true /test unit-test

Full PR test history. Your PR dashboard.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository. I understand the commands that are listed here.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Log encoder not picked up from config file

3 participants