futriix/tests/integration
Oran Agra 0ecf6cdc0a
fix handshake timeout replication test race (#11640)
Test on ARM + TLS often fail with this error:
```
*** [err]: Slave is able to detect timeout during handshake in tests/integration/replication.tcl
Replica is not able to detect timeout
```
https://github.com/redis/redis-extra-ci/actions/runs/3727554226/jobs/6321797837

The replica logs show that in this case the replica got timeout before even getting a response to the PING command (instead of the SYNC command).

it should have shown these:
```
* MASTER <-> REPLICA sync started
* REPLICAOF 127.0.0.1:22112 enabled ....
### Starting test Slave enters handshake in tests/integration/replication.tcl
* Non blocking connect for SYNC fired the event.
```
then:
```
* Master replied to PING, replication can continue...
* Trying a partial resynchronization (request 50da9eff70d774f4e6cb723eb4b091440f215772:1).
```
and then hang for 5 seconds:
```
# Timeout connecting to the MASTER...
* Reconnecting to MASTER 127.0.0.1:21112 after failure
```

but instead it got this (looks like it disconnected too early, and then tried to re-connect):
```
10890:M 19 Dec 2022 01:32:54.794 * Ready to accept connections tls
10890:M 19 Dec 2022 01:32:54.809 - Accepted 127.0.0.1:41047
10890:M 19 Dec 2022 01:32:54.878 - Reading from client: error:0A000126:SSL routines::unexpected eof while reading
10890:M 19 Dec 2022 01:32:54.925 - Accepted 127.0.0.1:39207
10890:S 19 Dec 2022 01:32:55.463 * Before turning into a replica, using my own master parameters to synthesize a cached master: I may be able to synchronize with the new master with just a partial transfer.
10890:S 19 Dec 2022 01:32:55.463 * Connecting to MASTER 127.0.0.1:24126
10890:S 19 Dec 2022 01:32:55.463 * MASTER <-> REPLICA sync started
10890:S 19 Dec 2022 01:32:55.463 * REPLICAOF 127.0.0.1:24126 enabled (user request from 'id=4 addr=127.0.0.1:39207 laddr=127.0.0.1:24125 fd=8 name= age=1 idle=0 flags=N db=9 sub=0 psub=0 ssub=0 multi=-1 qbuf=43 qbuf-free=20431 argv-mem=21 multi-mem=0 rbs=1024 rbp=5 obl=0 oll=0 omem=0 tot-mem=22317 events=r cmd=slaveof user=default redir=-1 resp=2')
### Starting test Slave enters handshake in tests/integration/replication.tcl
10890:S 19 Dec 2022 01:32:55.476 * Non blocking connect for SYNC fired the event.
10890:S 19 Dec 2022 01:33:00.701 # Failed to read response from the server: (null)         <- note this!!
10890:S 19 Dec 2022 01:33:00.701 # Master did not respond to command during SYNC handshake
10890:S 19 Dec 2022 01:33:01.002 * Connecting to MASTER 127.0.0.1:24126
10890:S 19 Dec 2022 01:33:01.002 * MASTER <-> REPLICA sync started
### Starting test Slave is able to detect timeout during handshake in tests/integration/replication.tcl
10890:S 19 Dec 2022 01:33:05.497 * Non blocking connect for SYNC fired the event.
10890:S 19 Dec 2022 01:33:05.500 * Master replied to PING, replication can continue...
10890:S 19 Dec 2022 01:33:05.510 * Trying a partial resynchronization (request 947e1956372a0e6c819cfec51c42cc7979b0c221:1).
10890:S 19 Dec 2022 01:34:05.833 # Failed to read response from the server: error:0A000126:SSL routines::unexpected eof while reading
10890:S 19 Dec 2022 01:34:05.833 # Master did not reply to PSYNC, will try later
```

This PR sets enables the 5 seconds timeout at a later stage to try and prevent the early disconnection.
2023-01-04 10:56:09 +02:00
..