Watch dropping an event when compacting on delete #18089
Assignees
Labels
area/robustness-testing
priority/critical-urgent
Highest priority. Must be actively worked on as someone's top priority right now.
release/v3.4
release/v3.5
type/bug
Comments
|
cc @MadhavJivrajani @siyuanfoundation @fuweid Can someone take a look and double check my findings? |
|
/assign |
|
I rerun the report on latest version of #17833 and it found that linearization was broken. Looks like a false positive due to some bug. |
|
Ok, ok I encountered another case. Failpoint used: Report: 1717749910517706368.tar.gz Found when adding compaction to operations serathius@5959110 Logs showing broken watch guarantee due to missing log: Screenshot showing a transaction for revision 141 and fact that key "key6" was present so delete really happened. Watch response showing missing delete event Complete log: |
|
@fuweid Think this is related to #17780 See the following logs: Looks like we lost first delete after restoring from restoring from "last compact revision". |
|
Yes. Let me try to reproduce it in my local. Update it later. |
|
I managed to reproduce it without multi TXN, just a delete request. This extends the impact to Kubernetes. Again the common thing is that etcd misses a watch even if it restores kvstore on revision before a delete. In last repro: etcd bootstrap log: |
|
Something similar reproduced on v3.4, however this time it was long after crash, and it flagged broken resumable properly. Which just means it provided incorrect event on a newly opened watch which provided revision. |
For this one, the tombstone of |
Correct. :( Currently, watcher isn't able to send out all the possible deleted events. |
|
Did the client side receive an ErrCompacted? If yes, then it should be expected behaviour.
|
No, it would be recorded in the report. |
@fuweid, don't understand the statement. Distributed system needs to uphold it's guarantees even if a node is down. Events on WAL used for replay should match what users observes. For watch client should observe either full history or or get ErrCompacted, as @ahrtr mentioned. |
|
One thing I noticed, that the WatchChan is not broken during etcd downtime, so the time it's down is short enough that the etcd client code retries the request in a transparent way. There might be a bug there too. Still there is a possibility of a bug in recording client responses, it is a little more complicated to record history of watch than KV requests. etcd/tests/robustness/client/client.go Lines 268 to 304 in 8a0054f |
|
@fuweid Please feel free to ping me on slack if you want a quick discussion on this issue. |
It's expected behaviour and by design as long as etcdserver doesn't return any error (e.g ErrCompacted). |
|
Added logs to ensure that issue is not one robustness test, got: They clearly show that revision 125 was not provided to client. |
Where did you add the log? Also suggest to provide a clear summary on the exact steps you did. |
serathius
added a commit
to serathius/etcd
that referenced
this issue
Jun 10, 2024
Signed-off-by: Marek Siarkowicz <siarkowicz@google.com>
|
Code #18145 |
|
The code to handle compacted version in watch was written 8 years ago, and it never handled the etcd/server/storage/mvcc/watcher_group.go Lines 253 to 262 in 5790774 |
|
Just as a thought exercise, how can admin of etcd cluster be alerted about the dropped watch events issue in general? In kubernetes/kubernetes#123072, However, this issue seems difficult to catch by alarms because just one delete event is missed. Diff by 1 could be caused by different times that client restarted. Trying to monitor in production and measure how many kubernetes clusters are impacted. Any insights are much appreciated !! |
Excellent question! Unfortunately, there's no simple way for etcd cluster admins to be directly alerted about dropped watch events in a production environment. The robustness tests achieve this by collecting comprehensive data – requests from all clients, WAL entries, etc. – and performing in-depth analysis. This level of data collection and analysis isn't feasible in production due to the sheer volume of information involved. This highlights the importance of rigorous, continuous robustness testing with diverse traffic types and failure injection. It allows us to thoroughly analyze smaller chunks of data in a controlled environment, identifying issues that might otherwise go unnoticed in the vastness of production data. On Kubernetes side, I have some plans to improve watch cache observability. Stay tuned! |
|
Tried replicating #18089 (comment) in an e2e here: #18201 |
Thanks @MadhavJivrajani . We need to add more tests ((or update existing tests)), please see all the proposed test cases as mentioned in #18162 (comment). Note I also added the test cases in the doc (under the option 2). @fuweid @MadhavJivrajani Please consider a whole plan to resolve this issue. Please feel free to ping on slack if you want any discussion. |
serathius
added a commit
to serathius/etcd
that referenced
this issue
Jun 22, 2024
serathius
added a commit
to serathius/etcd
that referenced
this issue
Jun 22, 2024
serathius
added a commit
to serathius/etcd
that referenced
this issue
Jun 22, 2024
… other issues Signed-off-by: Marek Siarkowicz <siarkowicz@google.com>
serathius
added a commit
that referenced
this issue
Jun 24, 2024
Disable robustness test detection of #18089 to allow detecting other issues
ah8ad3
pushed a commit
to ah8ad3/etcd
that referenced
this issue
Jul 23, 2024
… other issues Signed-off-by: Marek Siarkowicz <siarkowicz@google.com>
fuweid
added a commit
to fuweid/etcd
that referenced
this issue
Aug 1, 2024
…etecting other issues" This reverts commit 4fe227c. Signed-off-by: Wei Fu <fuweid89@gmail.com>
fuweid
added a commit
to fuweid/etcd
that referenced
this issue
Aug 16, 2024
…etecting other issues" This reverts commit 4fe227c. Signed-off-by: Wei Fu <fuweid89@gmail.com>
serathius
added a commit
that referenced
this issue
Aug 21, 2024
Revert "Disable robustness test detection of #18089 to allow detecting other issues
|
Awesome work @fuweid ! |
|
Let's close the issue and create dedicated issue for robustness testing . |
a-nych
pushed a commit
to a-nych/etcd
that referenced
this issue
Oct 16, 2024
…etecting other issues" This reverts commit 4fe227c. Signed-off-by: Wei Fu <fuweid89@gmail.com>
a-nych
pushed a commit
to a-nych/etcd
that referenced
this issue
Oct 16, 2024
…etecting other issues" This reverts commit 4fe227c. Signed-off-by: Wei Fu <fuweid89@gmail.com>
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Bug report criteria
What happened?
When testing #17833 I encountered watch breaking reliable guarantee.
Report included
1716928418720891814.zip
What did you expect to happen?
Watch should not break guarantee
How can we reproduce it (as minimally and precisely as possible)?
TODO
Anything else we need to know?
No response
Etcd version (please run commands below)
v3.5
Etcd configuration (command line flags or environment variables)
paste your configuration here
Etcd debug information (please run commands below, feel free to obfuscate the IP address or FQDN in the output)
Relevant log output
logger.go:146: 2024-05-28T22:33:31.699+0200 INFO starting proxy... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "from": "https://localhost:20013", "to": "https://localhost:20011"} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO starting proxy... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0", "from": "https://localhost:20003", "to": "https://localhost:20001"} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO starting proxy... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1", "from": "https://localhost:20008", "to": "https://localhost:20006"} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO starting server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO starting server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0"} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO spawning process {"args": ["/tmp/etcd-release-3.5-failpoints/bin/etcd", "--name=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "--listen-client-urls=http://localhost:20010", "--advertise-client-urls=http://localhost:20010", "--listen-peer-urls=https://localhost:20011", "--initial-advertise-peer-urls=https://localhost:20013", "--initial-cluster-token=new", "--data-dir", "/tmp/TestRobustnessExploratoryEtcdHighTrafficClusterOfSize34219590533/003", "--snapshot-count=1000", "--peer-cert-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/ca.crt", "--initial-cluster-token=new", "--experimental-watch-progress-notify-interval=100ms", "--snapshot-count=1000", "--experimental-snapshot-catchup-entries=100", "--experimental-compaction-batch-limit=1000", "--initial-cluster=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0=https://localhost:20003,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1=https://localhost:20008,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2=https://localhost:20013", "--initial-cluster-state=new"], "working-dir": "/tmp/TestRobustnessExploratory1597671579/001", "name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "environment-variables": ["GOFAIL_HTTP=127.0.0.1:32381", "ETCD_VERIFY=all", "PATH=/home/serathius/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.3.linux-amd64/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/bin:/home/serathius//bin/:/home/serathius/.gvm/pkgsets/go1.22/global/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/.gvm/pkgsets/go1.22/global/overlay/bin:/home/serathius/.gvm/bin:/home/serathius/.gvm/bin:/home/serathius/.cabal/bin/:/home/serathius/.local/bin:/home/serathius/.local/share/umake/bin:/home/serathius/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin", "ETCD_UNSUPPORTED_ARCH=amd64"]} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO spawning process {"args": ["/tmp/etcd-release-3.5-failpoints/bin/etcd", "--name=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0", "--listen-client-urls=http://localhost:20000", "--advertise-client-urls=http://localhost:20000", "--listen-peer-urls=https://localhost:20001", "--initial-advertise-peer-urls=https://localhost:20003", "--initial-cluster-token=new", "--data-dir", "/tmp/TestRobustnessExploratoryEtcdHighTrafficClusterOfSize34219590533/001", "--snapshot-count=1000", "--peer-cert-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/ca.crt", "--experimental-watch-progress-notify-interval=100ms", "--initial-cluster-token=new", "--experimental-snapshot-catchup-entries=100", "--experimental-compaction-batch-limit=1000", "--snapshot-count=1000", "--initial-cluster=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0=https://localhost:20003,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1=https://localhost:20008,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2=https://localhost:20013", "--initial-cluster-state=new"], "working-dir": "/tmp/TestRobustnessExploratory1597671579/001", "name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0", "environment-variables": ["GOFAIL_HTTP=127.0.0.1:12381", "ETCD_VERIFY=all", "PATH=/home/serathius/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.3.linux-amd64/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/bin:/home/serathius//bin/:/home/serathius/.gvm/pkgsets/go1.22/global/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/.gvm/pkgsets/go1.22/global/overlay/bin:/home/serathius/.gvm/bin:/home/serathius/.gvm/bin:/home/serathius/.cabal/bin/:/home/serathius/.local/bin:/home/serathius/.local/share/umake/bin:/home/serathius/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin", "ETCD_UNSUPPORTED_ARCH=amd64"]} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO starting server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1"} logger.go:146: 2024-05-28T22:33:31.699+0200 INFO spawning process {"args": ["/tmp/etcd-release-3.5-failpoints/bin/etcd", "--name=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1", "--listen-client-urls=http://localhost:20005", "--advertise-client-urls=http://localhost:20005", "--listen-peer-urls=https://localhost:20006", "--initial-advertise-peer-urls=https://localhost:20008", "--initial-cluster-token=new", "--data-dir", "/tmp/TestRobustnessExploratoryEtcdHighTrafficClusterOfSize34219590533/002", "--snapshot-count=1000", "--peer-cert-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/ca.crt", "--experimental-snapshot-catchup-entries=100", "--initial-cluster-token=new", "--experimental-watch-progress-notify-interval=100ms", "--snapshot-count=1000", "--experimental-compaction-batch-limit=1000", "--initial-cluster=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0=https://localhost:20003,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1=https://localhost:20008,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2=https://localhost:20013", "--initial-cluster-state=new"], "working-dir": "/tmp/TestRobustnessExploratory1597671579/001", "name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1", "environment-variables": ["GOFAIL_HTTP=127.0.0.1:22381", "ETCD_VERIFY=all", "PATH=/home/serathius/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.3.linux-amd64/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/bin:/home/serathius//bin/:/home/serathius/.gvm/pkgsets/go1.22/global/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/.gvm/pkgsets/go1.22/global/overlay/bin:/home/serathius/.gvm/bin:/home/serathius/.gvm/bin:/home/serathius/.cabal/bin/:/home/serathius/.local/bin:/home/serathius/.local/share/umake/bin:/home/serathius/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin", "ETCD_UNSUPPORTED_ARCH=amd64"]} logger.go:146: 2024-05-28T22:33:33.927+0200 INFO started server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1", "pid": 191460} logger.go:146: 2024-05-28T22:33:33.927+0200 INFO started server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0", "pid": 191459} logger.go:146: 2024-05-28T22:33:33.927+0200 INFO started server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "pid": 191458} logger.go:146: 2024-05-28T22:33:33.931+0200 INFO Start traffic logger.go:146: 2024-05-28T22:33:34.969+0200 INFO Triggering failpoint {"failpoint": "raftBeforeLeaderSend=panic()"} cluster.go:1066: members agree on a leader, members:map[12416079282240904009:1 13770228943176794332:2 16914881897345358027:0] , leader:13770228943176794332 logger.go:146: 2024-05-28T22:33:35.012+0200 INFO Setting up gofailpoint {"failpoint": "raftBeforeLeaderSend=panic()"} logger.go:146: 2024-05-28T22:33:35.012+0200 INFO Waiting for member to exit {"member": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:35.019+0200 INFO server exited {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "code": 2} logger.go:146: 2024-05-28T22:33:35.019+0200 INFO Member exited as expected {"member": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:35.019+0200 INFO starting server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:35.019+0200 INFO spawning process {"args": ["/tmp/etcd-release-3.5-failpoints/bin/etcd", "--name=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "--listen-client-urls=http://localhost:20010", "--advertise-client-urls=http://localhost:20010", "--listen-peer-urls=https://localhost:20011", "--initial-advertise-peer-urls=https://localhost:20013", "--initial-cluster-token=new", "--data-dir", "/tmp/TestRobustnessExploratoryEtcdHighTrafficClusterOfSize34219590533/003", "--snapshot-count=1000", "--peer-cert-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/serathius/src/go.etcd.io/etcd/tests/fixtures/ca.crt", "--initial-cluster-token=new", "--experimental-watch-progress-notify-interval=100ms", "--snapshot-count=1000", "--experimental-snapshot-catchup-entries=100", "--experimental-compaction-batch-limit=1000", "--initial-cluster=TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0=https://localhost:20003,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1=https://localhost:20008,TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2=https://localhost:20013", "--initial-cluster-state=new"], "working-dir": "/tmp/TestRobustnessExploratory1597671579/001", "name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "environment-variables": ["GOFAIL_HTTP=127.0.0.1:32381", "ETCD_VERIFY=all", "PATH=/home/serathius/pkg/mod/golang.org/toolchain@v0.0.1-go1.22.3.linux-amd64/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/bin:/home/serathius//bin/:/home/serathius/.gvm/pkgsets/go1.22/global/bin:/home/serathius/.gvm/gos/go1.22/bin:/home/serathius/.gvm/pkgsets/go1.22/global/overlay/bin:/home/serathius/.gvm/bin:/home/serathius/.gvm/bin:/home/serathius/.cabal/bin/:/home/serathius/.local/bin:/home/serathius/.local/share/umake/bin:/home/serathius/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin", "ETCD_UNSUPPORTED_ARCH=amd64"]} logger.go:146: 2024-05-28T22:33:36.129+0200 INFO started server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "pid": 191560} logger.go:146: 2024-05-28T22:33:36.130+0200 INFO Finished triggering failpoint {"failpoint": "raftBeforeLeaderSend=panic()"} logger.go:146: 2024-05-28T22:33:37.138+0200 INFO Finished traffic logger.go:146: 2024-05-28T22:33:38.141+0200 INFO Reporting complete traffic {"successes": 2340, "failures": 74, "successRate": 0.9693454846727423, "period": "3.207153256s", "qps": 729.6190151257306} logger.go:146: 2024-05-28T22:33:38.141+0200 INFO Reporting traffic before failure injection {"successes": 1250, "failures": 1, "successRate": 0.9992006394884093, "period": "1.038661462s", "qps": 1203.4720125198983} logger.go:146: 2024-05-28T22:33:38.141+0200 INFO Reporting traffic during failure injection {"successes": 64, "failures": 41, "successRate": 0.6095238095238096, "period": "1.161063679s", "qps": 55.12186898751485} logger.go:146: 2024-05-28T22:33:38.141+0200 INFO Reporting traffic after failure injection {"successes": 1026, "failures": 32, "successRate": 0.9697542533081286, "period": "1.007428115s", "qps": 1018.4349480856011} logger.go:146: 2024-05-28T22:33:38.141+0200 INFO Finished simulating traffic {"max-revision": 1107} logger.go:146: 2024-05-28T22:33:38.202+0200 INFO Validating linearizable operations {"timeout": "5m0s"} logger.go:146: 2024-05-28T22:33:38.697+0200 INFO Linearization success {"duration": "494.602505ms"} logger.go:146: 2024-05-28T22:33:38.698+0200 INFO Validating watch logger.go:146: 2024-05-28T22:33:38.715+0200 ERROR Broke watch guarantee {"guarantee": "reliable", "client": 4, "diff": " []model.PersistedEvent{\n \t... // 725 identical elements\n \t{Event: {Type: \"put-operation\", Key: \"key4\", Value: {Value: \"632\"}}, Revision: 627},\n \t{Event: {Type: \"put-operation\", Key: \"key7\", Value: {Value: \"641\"}}, Revision: 628},\n- \t{Event: model.Event{Type: \"delete-operation\", Key: \"key0\"}, Revision: 628},\n \t{Event: {Type: \"put-operation\", Key: \"key5\", Value: {Value: \"642\"}}, Revision: 628},\n \t{Event: {Type: \"put-operation\", Key: \"key0\", Value: {Value: \"643\"}}, Revision: 629, ...},\n \t... // 555 identical elements\n }\n"} validate.go:49: Failed validating watch history, err: broke Reliable - a sequence of events will never drop any subsequence of events; if there are events ordered in time as a < b < c, then if the watch receives events a and c, it is guaranteed to receive b logger.go:146: 2024-05-28T22:33:38.715+0200 INFO Validating serializable operations logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving robustness test report {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814"} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving member data dir {"member": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0", "path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/server-TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0"} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving member data dir {"member": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1", "path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/server-TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1"} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving member data dir {"member": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2", "path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/server-TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving watch operations {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-1/watch.json"} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO no KV operations for client, skip persisting {"client-id": 1} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO no watch operations for client, skip persisting {"client-id": 2} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-2/operations.json"} logger.go:146: 2024-05-28T22:33:38.721+0200 INFO Saving watch operations {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-3/watch.json"} logger.go:146: 2024-05-28T22:33:38.722+0200 INFO no KV operations for client, skip persisting {"client-id": 3} logger.go:146: 2024-05-28T22:33:38.722+0200 INFO Saving watch operations {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-4/watch.json"} logger.go:146: 2024-05-28T22:33:38.722+0200 INFO no KV operations for client, skip persisting {"client-id": 4} logger.go:146: 2024-05-28T22:33:38.722+0200 INFO no watch operations for client, skip persisting {"client-id": 5} logger.go:146: 2024-05-28T22:33:38.722+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-5/operations.json"} logger.go:146: 2024-05-28T22:33:38.723+0200 INFO no watch operations for client, skip persisting {"client-id": 6} logger.go:146: 2024-05-28T22:33:38.723+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-6/operations.json"} logger.go:146: 2024-05-28T22:33:38.723+0200 INFO no watch operations for client, skip persisting {"client-id": 7} logger.go:146: 2024-05-28T22:33:38.723+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-7/operations.json"} logger.go:146: 2024-05-28T22:33:38.724+0200 INFO no watch operations for client, skip persisting {"client-id": 8} logger.go:146: 2024-05-28T22:33:38.724+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-8/operations.json"} logger.go:146: 2024-05-28T22:33:38.724+0200 INFO no watch operations for client, skip persisting {"client-id": 9} logger.go:146: 2024-05-28T22:33:38.725+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-9/operations.json"} logger.go:146: 2024-05-28T22:33:38.725+0200 INFO no watch operations for client, skip persisting {"client-id": 10} logger.go:146: 2024-05-28T22:33:38.725+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-10/operations.json"} logger.go:146: 2024-05-28T22:33:38.726+0200 INFO no watch operations for client, skip persisting {"client-id": 11} logger.go:146: 2024-05-28T22:33:38.726+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-11/operations.json"} logger.go:146: 2024-05-28T22:33:38.726+0200 INFO no watch operations for client, skip persisting {"client-id": 12} logger.go:146: 2024-05-28T22:33:38.726+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-12/operations.json"} logger.go:146: 2024-05-28T22:33:38.727+0200 INFO no watch operations for client, skip persisting {"client-id": 13} logger.go:146: 2024-05-28T22:33:38.727+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-13/operations.json"} logger.go:146: 2024-05-28T22:33:38.727+0200 INFO no watch operations for client, skip persisting {"client-id": 14} logger.go:146: 2024-05-28T22:33:38.727+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-14/operations.json"} logger.go:146: 2024-05-28T22:33:38.728+0200 INFO no watch operations for client, skip persisting {"client-id": 15} logger.go:146: 2024-05-28T22:33:38.728+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-15/operations.json"} logger.go:146: 2024-05-28T22:33:38.728+0200 INFO no watch operations for client, skip persisting {"client-id": 16} logger.go:146: 2024-05-28T22:33:38.728+0200 INFO Saving operation history {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/client-16/operations.json"} logger.go:146: 2024-05-28T22:33:38.729+0200 INFO Saving visualization {"path": "/tmp/TestRobustnessExploratory_Etcd_HighTraffic_ClusterOfSize3/1716928418720891814/history.html"} logger.go:146: 2024-05-28T22:33:38.772+0200 INFO killing server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0"} logger.go:146: 2024-05-28T22:33:38.772+0200 INFO killing server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1"} logger.go:146: 2024-05-28T22:33:38.772+0200 INFO killing server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:38.772+0200 INFO stopping server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:38.772+0200 INFO stopping server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0"} logger.go:146: 2024-05-28T22:33:38.772+0200 INFO stopping server... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1"} logger.go:146: 2024-05-28T22:33:38.777+0200 INFO stopped server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0"} logger.go:146: 2024-05-28T22:33:38.777+0200 INFO stopping proxy... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-0"} logger.go:146: 2024-05-28T22:33:38.777+0200 INFO stopped server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1"} logger.go:146: 2024-05-28T22:33:38.777+0200 INFO stopping proxy... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-1"} logger.go:146: 2024-05-28T22:33:38.777+0200 INFO stopped server. {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"} logger.go:146: 2024-05-28T22:33:38.777+0200 INFO stopping proxy... {"name": "TestRobustnessExploratoryEtcdHighTrafficClusterOfSize3-test-2"}The text was updated successfully, but these errors were encountered: