Skip to content

Test test_postgresql_replica_database_engine/test_0.py::test_table_schema_changes is flaky #86185

@Avogar

Description

@Avogar

https://play.clickhouse.com/play?user=play#CldJVEgKICAgICd0ZXN0X3RhYmxlX3NjaGVtYV9jaGFuZ2VzJyBBUyBuYW1lX3N1YnN0ciwKICAgIDkwIEFTIGludGVydmFsX2RheXMsCiAgICAoJ1N0YXRlbGVzcyB0ZXN0cyAoYXNhbiknLCAnU3RhdGVsZXNzIHRlc3RzIChhZGRyZXNzKScsICdTdGF0ZWxlc3MgdGVzdHMgKGFkZHJlc3MsIGFjdGlvbnMpJykgQVMgYmFja3BvcnRfYW5kX3JlbGVhc2Vfc3BlY2lmaWNfY2hlY2tzClNFTEVDVAogICAgY2hlY2tfc3RhcnRfdGltZSBBUyBkLAogICAgcHVsbF9yZXF1ZXN0X251bWJlciBBUyBwciwKICAgIHJlcG9ydF91cmwKRlJPTSBjaGVja3MKV0hFUkUgKChub3coKSAtIHRvSW50ZXJ2YWxEYXkoaW50ZXJ2YWxfZGF5cykpIDw9IGNoZWNrX3N0YXJ0X3RpbWUpIEFORCAocHVsbF9yZXF1ZXN0X251bWJlciBOT1QgSU4gKAogICAgU0VMRUNUIHB1bGxfcmVxdWVzdF9udW1iZXIgQVMgcHJuCiAgICBGUk9NIGNoZWNrcwogICAgV0hFUkUgKHBybiAhPSAwKSBBTkQgKChub3coKSAtIHRvSW50ZXJ2YWxEYXkoaW50ZXJ2YWxfZGF5cykpIDw9IGNoZWNrX3N0YXJ0X3RpbWUpIEFORCAoY2hlY2tfbmFtZSBJTiAoYmFja3BvcnRfYW5kX3JlbGVhc2Vfc3BlY2lmaWNfY2hlY2tzKSkKKSkgQU5EIChwb3NpdGlvbih0ZXN0X25hbWUsIG5hbWVfc3Vic3RyKSA+IDApIEFORCAodGVzdF9zdGF0dXMgSU4gKCdGQUlMJywgJ0VSUk9SJywgJ0ZMQUtZJykpCk9SREVSIEJZIGQgREVTQwo=

Example: https://s3.amazonaws.com/clickhouse-test-reports/json.html?PR=85765&sha=d9c83add6087386351df45010de71b027af87a76&name_0=PR&name_1=Integration%20tests%20%28amd_binary%2C%204%2F5%29&name_1=Integration%20tests%20%28amd_binary%2C%204%2F5%29

Error:

    def test_table_schema_changes(started_cluster):
        NUM_TABLES = 5
    
        for i in range(NUM_TABLES):
            pg_manager.create_postgres_table(
                f"postgresql_replica_{i}", template=postgres_table_template_2
            )
            instance.query(
                f"INSERT INTO postgres_database.postgresql_replica_{i} SELECT number, {i}, {i}, {i} from numbers(25)"
            )
    
        pg_manager.create_materialized_db(
            ip=started_cluster.postgres_ip,
            port=started_cluster.postgres_port,
        )
    
        for i in range(NUM_TABLES):
            instance.query(
                f"INSERT INTO postgres_database.postgresql_replica_{i} SELECT 25 + number, {i}, {i}, {i} from numbers(25)"
            )
    
        check_several_tables_are_synchronized(instance, NUM_TABLES)
    
        expected = instance.query(
            "SELECT key, value1, value3 FROM test_database.postgresql_replica_3 ORDER BY key"
        )
    
        altered_idx = random.randint(0, 4)
        altered_table = f"postgresql_replica_{altered_idx}"
        prev_count = int(
            instance.query(f"SELECT count() FROM test_database.{altered_table}")
        )
    
        pg_manager.execute(f"ALTER TABLE {altered_table} DROP COLUMN value2")
        for i in range(NUM_TABLES):
            pg_manager.execute(f"INSERT INTO postgresql_replica_{i} VALUES (50, {i}, {i})")
    
>       assert instance.wait_for_log_line(
            f"Table postgresql_replica_{altered_idx} is skipped from replication stream"
        )

test_postgresql_replica_database_engine/test_0.py:383: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
helpers/cluster.py:4740: in wait_for_log_line
    result = self.exec_in_container(
helpers/cluster.py:4655: in exec_in_container
    return self.cluster.exec_in_container(
helpers/cluster.py:2376: in exec_in_container
    result = subprocess_check_call(
helpers/cluster.py:277: in subprocess_check_call
    return run_and_check(args, detach=detach, nothrow=nothrow, **kwargs)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

args = ['docker', 'exec', 'roottestpostgresqlreplicadatabaseengine0-gw0-instance-1', 'bash', '-c', 'timeout 30 tail -Fn100 "/...ickhouse-server/clickhouse-server.log" | grep -Em 1 \'Table postgresql_replica_2 is skipped from replication stream\'']
env = None, shell = False, stdout = -1, stderr = -1, timeout = 300
nothrow = False, detach = False

    def run_and_check(
        args: Union[Sequence[str], str],
        env=None,
        shell=False,
        stdout=subprocess.PIPE,
        stderr=subprocess.PIPE,
        timeout=300,
        nothrow=False,
        detach=False,
    ) -> str:
        if shell:
            if isinstance(args, str):
                shell_args = args
            else:
                shell_args = next(a for a in args)
        else:
            shell_args = " ".join(args)
    
        logging.debug("Command:[%s]", shell_args)
        if detach:
            subprocess.Popen(
                args,
                stdout=subprocess.DEVNULL,
                stderr=subprocess.DEVNULL,
                env=env,
                shell=shell,
            )
            return ""
    
        res = subprocess.run(
            args,
            stdout=stdout,
            stderr=stderr,
            env=env,
            shell=shell,
            timeout=timeout,
            check=False,
        )
        out = res.stdout.decode("utf-8", "ignore")
        err = res.stderr.decode("utf-8", "ignore")
        # check_call(...) from subprocess does not print stderr, so we do it manually
        for outline in out.splitlines():
            logging.debug("Stdout:%s", outline)
        for errline in err.splitlines():
            logging.debug("Stderr:%s", errline)
        if res.returncode != 0:
            logging.debug("Exitcode:%s", res.returncode)
            if env:
                logging.debug("Env:%s", env)
            if not nothrow:
>               raise Exception(
                    f"Command [{shell_args}] return non-zero code {res.returncode}: {res.stderr.decode('utf-8')}"
                )
E               Exception: Command [docker exec roottestpostgresqlreplicadatabaseengine0-gw0-instance-1 bash -c timeout 30 tail -Fn100 "/var/log/clickhouse-server/clickhouse-server.log" | grep -Em 1 'Table postgresql_replica_2 is skipped from replication stream'] return non-zero code 1:

Metadata

Metadata

Assignees

Labels

flaky testflaky test found by CI

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions