Skip to content

Commit

Permalink
acceptance: make TestDockerCLI_test_exec_log wait for unambiguous l…
Browse files Browse the repository at this point in the history
…og line

The `TestDockerCLI_test_exec_log` test had a section where it
waits for the last executed stmt to appear in the exec_log file
before proceeding to the next section. This is done by grep'ing
the query string of the last stmt. This works fine most of the time,
 however, the 2nd last and last stmt executed happen to have the same
query string, so it's possible that we are only seeing the 2nd to last
stmt in the log. This can cause the test to fail as in the next section,
we expect all query logs to be present in the file.

This commit fixes this by issuing a distinct query as the last query
so that we can grep for a distinct query string to verify all stmts
should have been written.

A new proc is also added to `common.tcl`:
flush_and_sync_logs is a proc that takes 2 arguments, `filename` and
`grep_text`. It will trigger a signal hang up to trigger a log flush
and then attempt to find the `grep_text` in the specified file.

Epic: none
Fixes: cockroachdb#106367
  • Loading branch information
xinhaoz committed Jul 27, 2023
1 parent c917a6b commit bb5d813
Show file tree
Hide file tree
Showing 2 changed files with 22 additions and 16 deletions.
14 changes: 14 additions & 0 deletions pkg/cli/interactive_tests/common.tcl
Original file line number Diff line number Diff line change
Expand Up @@ -144,6 +144,20 @@ proc flush_server_logs {} {
report "END FLUSH LOGS"
}

proc flush_and_sync_logs {filename grep_text} {
report "BEGIN FLUSH LOGS $filename"
system "kill -HUP `cat server_pid` 2>/dev/null"
# Wait for flush to occur.
system "for i in `seq 1 5`; do
grep '$grep_text' $filename && exit 0;
echo still waiting
sleep 1
done
echo 'server failed to flush logs?'
exit 1"
report "END FLUSH LOGS"
}

proc force_stop_server {argv} {
report "BEGIN FORCE STOP SERVER"
system "kill -KILL `cat server_pid`"
Expand Down
24 changes: 8 additions & 16 deletions pkg/cli/interactive_tests/test_exec_log.tcl
Original file line number Diff line number Diff line change
Expand Up @@ -97,23 +97,15 @@ send "SELECT 550+5;\r"
eexpect 555
eexpect root@

flush_server_logs
# Use this distinct query to be the boundary - if we see this stmt in the
# exec log, then we should expect all the previous statements in the log too.

send "SELECT 111;\r"
eexpect 111
eexpect root@

flush_and_sync_logs $logfile "SELECT ..*111..*"

# Now check the items are there in the log file. We need to iterate
# because flush_server_logs only syncs on flush of cockroach.log, not
# the exec log.
#
# We also check the last statement first, this ensures that every
# previous statement is also in the log file after this check
# succeeds.
system "for i in `seq 1 3`; do
grep 'SELECT ..*550..* +' $logfile && exit 0;
echo still waiting;
sleep 1;
done;
echo 'not finding two separate txn counter values?';
grep 'SELECT ..*550..* +' $logfile;
exit 1;"

# Two separate single-stmt txns.
system "n=`grep 'SELECT ..*550..* +' $logfile | sed -e 's/.*TxnCounter.:\\(\[0-9\]*\\).*/\\1/g' | uniq | wc -l`; if test \$n -ne 2; then echo unexpected \$n; exit 1; fi"
Expand Down

0 comments on commit bb5d813

Please sign in to comment.