cloud_storage/tests: wait for partition metadata during topic recovery tests

[abhijat]

Cover Letter

If a leader election happened right before we verify topic watermark, rpk may return an error such as "not leader for partition" due to stale metadata.

Instead of failing immediately this change makes the caller wait for upto 1 minute so that the new leadership info is propagated to the cluster and rpk returns the correct partition metadata.

in a failed test in linked CI failure the following logs are seen due to metadata returned during leader election:

INFO  2022-07-29 18:08:38,744 [shard 1] raft - [group_id:1, {kafka/panda-topic-1/0}] vote_stm.cc:255 - becoming the leader term:5
INFO  2022-07-29 18:08:38,764 [shard 1] raft - [group_id:2, {kafka/panda-topic-1/1}] vote_stm.cc:255 - becoming the leader term:5
TRACE 2022-07-29 18:08:38,858 [shard 0] kafka - request_context.h:160 - [172.16.16.27:48330] sending 2:list_offsets response {throttle_time_ms=0 topics={{name={panda-topic-1} partitions={{partition_index=0 error_code={ error_code: not_leader_for_partition [6] } old_style_offsets={} timestamp={timestamp: missing} offset=-1 leader_epoch=-1}}}}}
TRACE 2022-07-29 18:08:38,863 [shard 0] kafka - request_context.h:160 - [172.16.16.27:55628] sending 2:list_offsets response {throttle_time_ms=0 topics={{name={panda-topic-1} partitions={{partition_index=1 error_code={ error_code: not_leader_for_partition [6] } old_style_offsets={} timestamp={timestamp: missing} offset=-1 leader_epoch=-1}}}}}
TRACE 2022-07-29 18:08:38,865 [shard 0] kafka - request_context.h:160 - [172.16.16.27:55628] sending 2:list_offsets response {throttle_time_ms=0 topics={{name={panda-topic-1} partitions={{partition_index=1 error_code={ error_code: not_leader_for_partition [6] } old_style_offsets={} timestamp={timestamp: missing} offset=-1 leader_epoch=-1}}}}}
TRACE 2022-07-29 18:08:38,866 [shard 0] kafka - request_context.h:160 - [172.16.16.27:48330] sending 2:list_offsets response {throttle_time_ms=0 topics={{name={panda-topic-1} partitions={{partition_index=0 error_code={ error_code: not_leader_for_partition [6] } old_style_offsets={} timestamp={timestamp: missing} offset=-1 leader_epoch=-1}}}}}
TRACE 2022-07-29 18:08:38,869 [shard 0] kafka - request_context.h:160 - [172.16.16.27:55628] sending 2:list_offsets response {throttle_time_ms=0 topics={{name={panda-topic-1} partitions={{partition_index=1 error_code={ error_code: not_leader_for_partition [6] } old_style_offsets={} timestamp={timestamp: missing} offset=-1 leader_epoch=-1}}}}}
TRACE 2022-07-29 18:08:38,869 [shard 0] kafka - request_context.h:160 - [172.16.16.27:48330] sending 2:list_offsets response {throttle_time_ms=0 topics={{name={panda-topic-1} partitions={{partition_index=0 error_code={ error_code: not_leader_for_partition [6] } old_style_offsets={} timestamp={timestamp: missing} offset=-1 leader_epoch=-1}}}}}
INFO  2022-07-29 18:08:39,027 [shard 1] raft - [group_id:1, {kafka/panda-topic-1/0}] vote_stm.cc:270 - became the leader term:5
INFO  2022-07-29 18:08:39,033 [shard 1] raft - [group_id:2, {kafka/panda-topic-1/1}] vote_stm.cc:270 - became the leader term:5

fixes #5737

force push: fix capturing the variable in wait_until

Release Notes

[abhijat]

should we calculate the max/min/first value which is not None watermark over all partitions?

right now we are effectively just getting the value from the last row that rpk produced.

cc @Lazin

[Lazin]

We only need high watermark for this test.

[Lazin]

LGTM (when it will stop being a draft PR)

[abhijat]

LGTM (when it will stop being a draft PR)

I had a bug in the way watermark was captured, latest commit should fix it.

[abhijat]

errors:
https://buildkite.com/redpanda/redpanda/builds/13415#018259ea-dff0-4d4e-8c72-89c30874ce5f

test_id:    rptest.tests.controller_upgrade_test.ControllerUpgradeTest.test_updating_cluster_when_executing_operations
status:     FAIL
run time:   5 minutes 0.884 seconds
 
    <BadLogLines nodes=docker-rp-19(1) example="ERROR 2022-08-01 15:46:09,378 [shard 1] r/heartbeat - heartbeat_manager.cc:284 - cannot find consensus group:19">
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/dist-packages/ducktape/tests/runner_client.py", line 135, in run
    data = self.run_test()
  File "/usr/local/lib/python3.10/dist-packages/ducktape/tests/runner_client.py", line 227, in run_test
    return self.test_context.function(self.test)
  File "/root/tests/rptest/services/cluster.py", line 48, in wrapped
    self.redpanda.raise_on_bad_logs(allow_list=log_allow_list)
  File "/root/tests/rptest/services/redpanda.py", line 1121, in raise_on_bad_logs
    raise BadLogLines(bad_lines)
rptest.services.utils.BadLogLines: <BadLogLines nodes=docker-rp-19(1) example="ERROR 2022-08-01 15:46:09,378 [shard 1] r/heartbeat - heartbeat_manager.cc:284 - cannot find consensus group:19">

#5378 related, should be fixed with PR #5742

test_id:
rptest.tests.partition_move_interruption_test.PartitionMoveInterruption.test_cancelling_partition_move.replication_factor=3.unclean_abort=False.recovery=restart_recovery
status: FAIL
run time: 3 minutes 30.828 seconds

<BadLogLines nodes=docker-rp-11(1)
    example="ERROR 2022-08-01 15:53:16,410 [shard 1] rpc - transport.h:180 - Protocol violation: request version rpc::transport_version::v1 incompatible with reply version rpc::transport_version::v2 reply type raft::append_entries_reply">
    Traceback (most recent call last):
    File "/usr/local/lib/python3.10/dist-packages/ducktape/tests/runner_client.py", line 135, in run
    data = self.run_test()
    File "/usr/local/lib/python3.10/dist-packages/ducktape/tests/runner_client.py", line 227, in run_test
    return self.test_context.function(self.test)
    File "/usr/local/lib/python3.10/dist-packages/ducktape/mark/_mark.py", line 476, in wrapper
    return functools.partial(f, *args, **kwargs)(*w_args, **w_kwargs)
    File "/root/tests/rptest/services/cluster.py", line 48, in wrapped
    self.redpanda.raise_on_bad_logs(allow_list=log_allow_list)
    File "/root/tests/rptest/services/redpanda.py", line 1121, in raise_on_bad_logs
    raise BadLogLines(bad_lines)
    rptest.services.utils.BadLogLines: <BadLogLines nodes=docker-rp-11(1)
        example="ERROR 2022-08-01 15:53:16,410 [shard 1] rpc - transport.h:180 - Protocol violation: request version rpc::transport_version::v1 incompatible with reply version rpc::transport_version::v2 reply type raft::append_entries_reply">

seems an instance of #5608 Protocol violation: request version rpc::transport_version::v1 incompatible with reply version rpc::transport_version::v2 reply type raft::append_entries_reply

[dotnwat]

#5378 related, should be fixed with PR #5742

thank you for doing this. could you post the stack traces on the issue related to the failure rather than the PR that experienced the failure?

[ajfabbri]

Looks good. Only problem is your force-push fix ended up in the wrong commit. I've done this before, 😅.

[abhijat]

/backport v22.2.x

[abhijat]

/backport v22.1.x