From 8eeece4ab3e80d2c648978ecaa3d5b10e8119117 Mon Sep 17 00:00:00 2001 From: Binbin Date: Mon, 12 Feb 2024 14:11:33 +0800 Subject: [PATCH] Fix CLIENAT KILL MAXAGE test timing issue (#13047) This test fails occasionally: ``` *** [err]: CLIENT KILL maxAGE will kill old clients in tests/unit/introspection.tcl Expected 2 == 1 (context: type eval line 14 cmd {assert {$res == 1}} proc ::test) ``` This test is very likely to do a false positive if the execute time takes longer than the max age, for example, if the execution time between sleep and kill exceeds 1s, rd2 will also be killed due to the max age. The test can adjust the order of execution statements to increase the probability of passing, but this is still will be a timing issue in some slow machines, so decided give it a few more chances. The test was introduced in #12299. --- .github/workflows/external.yml | 3 +++ tests/unit/introspection.tcl | 39 ++++++++++++++++++++++++---------- 2 files changed, 31 insertions(+), 11 deletions(-) diff --git a/.github/workflows/external.yml b/.github/workflows/external.yml index 15a9afb6e..0c884053b 100644 --- a/.github/workflows/external.yml +++ b/.github/workflows/external.yml @@ -23,6 +23,7 @@ jobs: run: | ./runtest \ --host 127.0.0.1 --port 6379 \ + --verbose \ --tags -slow - name: Archive redis log if: ${{ failure() }} @@ -49,6 +50,7 @@ jobs: run: | ./runtest \ --host 127.0.0.1 --port 6379 \ + --verbose \ --cluster-mode \ --tags -slow - name: Archive redis log @@ -73,6 +75,7 @@ jobs: run: | ./runtest \ --host 127.0.0.1 --port 6379 \ + --verbose \ --tags "-slow -needs:debug" - name: Archive redis log if: ${{ failure() }} diff --git a/tests/unit/introspection.tcl b/tests/unit/introspection.tcl index 0a5dac351..5e3528439 100644 --- a/tests/unit/introspection.tcl +++ b/tests/unit/introspection.tcl @@ -39,19 +39,36 @@ start_server {tags {"introspection"}} { } test {CLIENT KILL maxAGE will kill old clients} { - set rd1 [redis_deferring_client] - r debug sleep 2 - set rd2 [redis_deferring_client] + # This test is very likely to do a false positive if the execute time + # takes longer than the max age, so give it a few more chances. Go with + # 3 retries of increasing sleep_time, i.e. start with 2s, then go 4s, 8s. + set sleep_time 2 + for {set i 0} {$i < 3} {incr i} { + set rd1 [redis_deferring_client] + r debug sleep $sleep_time + set rd2 [redis_deferring_client] + r acl setuser dummy on nopass +ping + $rd1 auth dummy "" + $rd1 read + $rd2 auth dummy "" + $rd2 read - r acl setuser dummy on nopass +ping - $rd1 auth dummy "" - $rd1 read - $rd2 auth dummy "" - $rd2 read + # Should kill rd1 but not rd2 + set max_age [expr $sleep_time / 2] + set res [r client kill user dummy maxage $max_age] + if {$res == 1} { + break + } else { + # Clean up and try again next time + set sleep_time [expr $sleep_time * 2] + $rd1 close + $rd2 close + } - # Should kill rd1 but not rd2 - set res [r client kill user dummy maxage 1] - assert {$res == 1} + } ;# for + + if {$::verbose} { puts "CLIENT KILL maxAGE will kill old clients test attempts: $i" } + assert_equal $res 1 # rd2 should still be connected $rd2 ping