diff --git a/CHANGELOG.md b/CHANGELOG.md index 76dcda362..1765439fc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,8 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0. ### Fixed +- Possible line loss/duplication when the log file is renamed. + ## [2.13.0] - 2026-05-21 This release adds cluster worker configuration management and fixes diff --git a/cli/tail/follow.go b/cli/tail/follow.go index 0ef24d740..1020cd975 100644 --- a/cli/tail/follow.go +++ b/cli/tail/follow.go @@ -10,7 +10,7 @@ import ( "time" "github.com/apex/log" - "github.com/nxadm/tail" + "github.com/tarantool/go-tail" ) const ( diff --git a/cli/tail/follow_test.go b/cli/tail/follow_test.go index a7756b0db..4dee87466 100644 --- a/cli/tail/follow_test.go +++ b/cli/tail/follow_test.go @@ -103,10 +103,6 @@ func TestFollow2_ReadExistingContent(t *testing.T) { } func TestFollow2_FollowNewContent(t *testing.T) { - if os.Getenv("CI") != "" { - t.Skip("Skipping flaky test on CI until issue #TNTP-3131 is fixed") - } - lf := createTmpLogFile(t, linesPerStep, logLineFormat) ctx, cancel := context.WithCancel(context.Background()) @@ -195,7 +191,7 @@ func TestFollow2_NonExistentFile(t *testing.T) { } } -func rotationTest(t *testing.T, use_delay bool) { +func TestFollow2_FileRotation(t *testing.T) { lf := createTmpLogFile(t, linesPerStep, logLineFormat) ctx, cancel := context.WithCancel(context.Background()) @@ -219,10 +215,6 @@ func rotationTest(t *testing.T, use_delay bool) { t.Fatalf("Failed to rotate log file: %v", err) } - if use_delay { - time.Sleep(500 * time.Millisecond) // Add delay to avoid flaky fails. - } - newFile, err := os.Create(lf) if err != nil { t.Fatalf("Failed to create new log file: %v", err) @@ -248,36 +240,3 @@ func rotationTest(t *testing.T, use_delay bool) { cancel() f.Wait() } - -// TestFollow2_FileRotation_Flaky tests the file rotation with flaky retries. -// It retries the test multiple times to handle potential flakiness in the tail library. -// This is a workaround for the issue #TNTP-3131, where the tail library -// does not handle file rotation correctly. -// - TODO: Need fix `tail` library, see #TNTP-3131 for more details. -func TestFollow2_FileRotation_Flaky(t *testing.T) { - if os.Getenv("CI") != "" { - t.Skip("Skipping flaky test on CI until issue #TNTP-3131 is fixed") - } - - const flakyRepeatCount = 3 - - test_pass := false - - for i := range flakyRepeatCount { - t.Run(fmt.Sprintf("Rotation-%d", i+1), func(t *testing.T) { - rotationTest(t, i > 0) - - test_pass = !t.Skipped() - }) - - if test_pass { - break - } - - t.Logf("FLAKY test %s failed, retrying flaky test iteration", t.Name()) - } - - if !test_pass { - t.Fatalf("Test failed after all flaky iterations") - } -} diff --git a/cli/tail/tail.go b/cli/tail/tail.go index 80b01df06..89b358fe7 100644 --- a/cli/tail/tail.go +++ b/cli/tail/tail.go @@ -12,7 +12,7 @@ import ( "github.com/apex/log" "github.com/fatih/color" - "github.com/nxadm/tail" + "github.com/tarantool/go-tail" ) const blockSize = 8192 diff --git a/go.mod b/go.mod index 941062da7..18e3652fc 100644 --- a/go.mod +++ b/go.mod @@ -22,7 +22,6 @@ require ( github.com/moby/moby/api v1.54.0 github.com/moby/moby/client v0.3.0 github.com/moby/term v0.5.2 - github.com/nxadm/tail v1.4.11 github.com/otiai10/copy v1.14.1 github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 github.com/spf13/cobra v1.10.2 @@ -30,6 +29,7 @@ require ( github.com/tarantool/cartridge-cli v0.0.0-00010101000000-000000000000 github.com/tarantool/go-prompt v1.0.1 github.com/tarantool/go-storage v1.5.0 + github.com/tarantool/go-tail v1.4.12 github.com/tarantool/go-tarantool v1.12.3 github.com/tarantool/go-tarantool/v2 v2.4.2 github.com/tarantool/tt/lib/cluster v0.0.0 @@ -149,7 +149,6 @@ require ( go.opentelemetry.io/otel v1.42.0 // indirect go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.42.0 // indirect go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.40.0 // indirect - go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.42.0 // indirect go.opentelemetry.io/otel/metric v1.42.0 // indirect go.opentelemetry.io/otel/sdk v1.42.0 // indirect go.opentelemetry.io/otel/trace v1.42.0 // indirect diff --git a/go.sum b/go.sum index 9ccb1dc81..951c62697 100644 --- a/go.sum +++ b/go.sum @@ -98,7 +98,6 @@ github.com/fatih/structs v1.1.0/go.mod h1:9NiDSp5zOcgEDl+j00MP/WkGVPOlPRLejGD8Ga github.com/felixge/httpsnoop v1.0.4 h1:NFTV2Zj1bL4mc9sqWACXbQFVBBg2W3GPvqp8/ESS2Wg= github.com/felixge/httpsnoop v1.0.4/go.mod h1:m8KPJKqk1gH5J9DgRY2ASl2lWCfGKXixSwevea8zH2U= github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo= -github.com/fsnotify/fsnotify v1.6.0/go.mod h1:sl3t1tCWJFWoRz9R8WJCbQihKKwmorjAbSClcnxKAGw= github.com/fsnotify/fsnotify v1.9.0 h1:2Ml+OJNzbYCTzsxtv8vKSFD9PbJjmhYF14k/jKC7S9k= github.com/fsnotify/fsnotify v1.9.0/go.mod h1:8jBTzvmWwFyi3Pb8djgCCO5IBqzKJ/Jwo8TRcHyHii0= github.com/go-kit/log v0.1.0/go.mod h1:zbhenjAZHb184qTLMA9ZjW7ThYL0H2mk7Q6pNt4vbaY= @@ -234,8 +233,6 @@ github.com/morikuni/aec v1.0.0/go.mod h1:BbKIizmSmc5MMPqRYbxO4ZU0S0+P200+tUnFx7P github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822 h1:C3w9PqII01/Oq1c1nUAm88MOHcQC9l5mIlSMApZMrHA= github.com/munnerz/goautoneg v0.0.0-20191010083416-a7dc8b61c822/go.mod h1:+n7T8mK8HuQTcFwEeznm/DIxMOiR9yIdICNftLE1DvQ= github.com/niemeyer/pretty v0.0.0-20200227124842-a10e7caefd8e/go.mod h1:zD1mROLANZcx1PVRCS0qkT7pwLkGfwJo4zjcN/Tysno= -github.com/nxadm/tail v1.4.11 h1:8feyoE3OzPrcshW5/MJ4sGESc5cqmGkGCWlco4l0bqY= -github.com/nxadm/tail v1.4.11/go.mod h1:OTaG3NK980DZzxbRq6lEuzgU+mug70nY11sMd4JXXHc= github.com/olekukonko/tablewriter v0.0.5 h1:P2Ga83D34wi1o9J6Wh1mRuqd4mF/x/lgBS7N7AbDhec= github.com/olekukonko/tablewriter v0.0.5/go.mod h1:hPp6KlRPjbx+hW8ykQs1w3UBbZlj6HuIJcUGPhkA7kY= github.com/onsi/ginkgo v1.6.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE= @@ -325,6 +322,8 @@ github.com/tarantool/go-prompt v1.0.1 h1:88Yer6gCFylqGRrdWwikNFVbklRQsqKF7mycvGd github.com/tarantool/go-prompt v1.0.1/go.mod h1:9Vuvi60Bk+3yaXqgYaXNTpLbwPPaaEOeaUgpFW1jqTU= github.com/tarantool/go-storage v1.5.0 h1:WRi5eahOinBHh+Nnc5CmiaFNxYQCd5OoiUfA7n9pe30= github.com/tarantool/go-storage v1.5.0/go.mod h1:Aj8RoWXZGYOI7oWT3Utj9IE7FItvMSDf2smHxHJo96M= +github.com/tarantool/go-tail v1.4.12 h1:bVIO9XbroPSF7/n0Mdp6dwxN1umNtuE6VtZGUpH7YqE= +github.com/tarantool/go-tail v1.4.12/go.mod h1:NqLWssaRJ2w9myxdJWlc4WaZWHU2CLZDdEYfKlSnbEQ= github.com/tarantool/go-tarantool v1.12.3 h1:GXabowmrTSW225xFEjX4t+8PlccVDCeGB5OM1VLbBXE= github.com/tarantool/go-tarantool v1.12.3/go.mod h1:QRiXv0jnxwgxHtr9ZmifSr/eRba76gTUBgp69pDMX1U= github.com/tarantool/go-tarantool/v2 v2.4.2 h1:rkzYtFhLJLA9RDIhjzN93MJBN5PBxHW4+soq+RB90gE= @@ -486,7 +485,6 @@ golang.org/x/sys v0.0.0-20211025201205-69cdffdb9359/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.0.0-20220310020820-b874c991c1a5/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220520151302-bc2c85ada10a/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.0.0-20220722155257-8c9f86f7a55f/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= -golang.org/x/sys v0.0.0-20220908164124-27713097b956/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.42.0 h1:omrd2nAlyT5ESRdCLYdm3+fMfNFE/+Rf4bDIQImRJeo= golang.org/x/sys v0.42.0/go.mod h1:4GL1E5IUh+htKOUEOaiffhrAeqysfVGipDYzABqnCmw= diff --git a/test/integration/log/test_log.py b/test/integration/log/test_log.py index b345c71a7..3e517bd4f 100644 --- a/test/integration/log/test_log.py +++ b/test/integration/log/test_log.py @@ -290,7 +290,7 @@ def test_log_dir_removed_after_follow(tt_cmd, mock_env_dir): assert os.path.exists(var_dir) shutil.rmtree(var_dir) - assert process.wait(2) == 0 + assert process.wait(5) == 0 assert "Failed to detect creation of" in process.stdout.read() diff --git a/test/integration/tcm/test_tcm_log.py b/test/integration/tcm/test_tcm_log.py index d9747ab2f..95af2d8cb 100644 --- a/test/integration/tcm/test_tcm_log.py +++ b/test/integration/tcm/test_tcm_log.py @@ -1,5 +1,5 @@ -import os import signal +import subprocess import sys import time from pathlib import Path @@ -8,7 +8,9 @@ import pytest from async_reader import AsyncProcessReader -from utils import run_command_and_get_output +import utils + +# from utils import run_command_and_get_output DATA_DIR = Path(__file__).parent / "testdata" EXPECTED_DATA = DATA_DIR / "expected" @@ -86,7 +88,7 @@ def test_log_n_lines( if lines > 0: cmd.extend(("-n", str(lines))) cmd.extend(options) - rc, output = run_command_and_get_output(cmd, cwd=DATA_DIR / mode) + rc, output = utils.run_command_and_get_output(cmd, cwd=DATA_DIR / mode) assert rc == 0, f"Command failed with return code {rc}." expected_file = expected_file_name(mode, lines, options) @@ -124,6 +126,35 @@ def handle_static_logs( return tmp_log, reader, stdout_lines +def handle_static_logs2( + tt_cmd: Path, + tmp_path: Path, + mode: str, + lines: int, + options: list[str], +) -> tuple[Path, AsyncProcessReader, list[str]]: + tmp_log, eof_marker = prepare_first_log(tmp_path, mode) + + cmd = [tt_cmd, "tcm", "log", "--follow"] + if lines > 0: + cmd.append(f"--lines={lines + 1}") # +1 to include the extra EOF marker line. + cmd.extend(options) + + p = subprocess.Popen( + cmd, + cwd=tmp_path, + stderr=subprocess.PIPE, + stdout=subprocess.PIPE, + text=True, + encoding="utf-8", + ) + + assert utils.wait_for_string(10, p.stdout, eof_marker), \ + f"Expected end marker {eof_marker} not found." + + return tmp_log, p + + def prepare_second_log( tmp_log: Path, mode: str, @@ -155,7 +186,9 @@ def handle_updating_logs( ) -> tuple[list[str], int]: eof_marker, write_cnt = prepare_second_log(tmp_log, mode, delay_time, is_append) + # print(f"@@@@@@@@@ {time.time()} handle_updating_logs") lines, is_found = reader.stdout_wait_for(eof_marker, timeout=10) + # print(f"@@@@@@@@@ {time.time()} handle_updating_logs2") reader.send_signal(signal.SIGINT) reader.pStop() @@ -203,10 +236,6 @@ def final_checks( check_output("".join(stdout_lines), update_testdata, expected_file) -@pytest.mark.skipif( - condition=os.getenv("CI") is not None, - reason="Skip on CI runs until issue #TNTP-3131 is fixed.", -) @pytest.mark.parametrize("delay_time", (0.1, 0.01, 0)) @pytest.mark.parametrize("lines, options", TEST_CASES) @pytest.mark.parametrize("mode", TEST_DATA_MODES) @@ -235,12 +264,52 @@ def test_log_follow( ) +def handle_updating_logs2( + p, + tmp_log: Path, + mode: str, + delay_time: float, + is_append: bool, +) -> tuple[list[str], int]: + eof_marker, write_cnt = prepare_second_log(tmp_log, mode, delay_time, is_append) + + # print(f"@@@@@@@@@ {time.time()} handle_updating_logs") + assert utils.wait_for_string(10, p.stdout, eof_marker), \ + f"Expected end marker {eof_marker} not found." + lines, is_found = reader.stdout_wait_for(eof_marker, timeout=10) + # print(f"@@@@@@@@@ {time.time()} handle_updating_logs2") + + reader.send_signal(signal.SIGINT) + reader.pStop() + + + + + stderr_lines = reader.stderr + assert "context canceled" in "".join(stderr_lines), ( + f"Expected message not found in stderr {stderr_lines}" + ) + + if reader.pWait() is None: + reader.pKill() + + if not is_found: + print(f"Second marker not found in stdout:\n{''.join(lines)}") + rest_lines = reader.stdout + if rest_lines: + print(f"Rest output =>\n{''.join(rest_lines)}") + if stderr_lines: + print(f"Got stderr:\n{''.join(stderr_lines)}", file=sys.stderr) + + assert is_found, f"Expected end marker {eof_marker} not found." + + assert reader.returncode == 1, ( + f"Command failed with return code {reader.returncode} (expected 1)." + ) + return lines, write_cnt + + @pytest.mark.slow -@pytest.mark.skipif( - condition=os.getenv("CI") is not None, - reason="Skip on CI runs until issue #TNTP-3131 is fixed.", -) -@pytest.mark.flaky(reruns=5) # See notes below about issues with `tail` package. @pytest.mark.parametrize("delay_time", (0.1, 0.01, 0)) @pytest.mark.parametrize("lines, options", TEST_CASES) @pytest.mark.parametrize("mode", TEST_DATA_MODES) @@ -264,13 +333,6 @@ def test_log_rotate( tmp_log.rename(tmp_log.with_suffix(".bak")) assert not tmp_log.exists(), "Temporary log file should be deleted." - # TODO: Need fix `tail` library, see #TNTP-3131 for more details. - # See `tail` opened issues, since 2024: - # - https://github.com/nxadm/tail/issues/72 - # - https://github.com/nxadm/tail/pull/73 - _, found = reader.stderr_wait_for("tryReopenTailer", timeout=0.5) - if not found: - time.sleep(1) new_lines, cnt_lines = handle_updating_logs(reader, tmp_log, mode, delay_time, is_append=True) stdout_lines.extend(new_lines) diff --git a/test/utils.py b/test/utils.py index b9403744e..e6c9d585d 100644 --- a/test/utils.py +++ b/test/utils.py @@ -730,3 +730,10 @@ def update_dict_leaves(d, other): d[k] = v elif v is not None: d[k] = v + + +def wait_for_string(timeout, stream, s, interval=0.1): + def check_next_line(): + return s in stream.readline() + + return wait_event(timeout, check_next_line, interval)