Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

functional test flaky. "etcdserver: too many requests" #14826

Closed
lavacat opened this issue Nov 22, 2022 · 4 comments
Closed

functional test flaky. "etcdserver: too many requests" #14826

lavacat opened this issue Nov 22, 2022 · 4 comments
Labels
stale type/flake

Comments

@lavacat
Copy link

lavacat commented Nov 22, 2022 •
edited
Loading

Which github workflows are flaking?

https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1802

I've also seen the same failure in #14257 (comment) (see 2)

Which tests are flaking?

In both cases it was BLACKHOLE_PEER_PORT_TX_RX_LEADER test case.

Full log with error:

=== RUN   TestFunctional/round-0/6_BLACKHOLE_PEER_PORT_TX_RX_LEADER
[1383](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1384)
=== CONT  TestFunctional
[1384](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1385)
    logger.go:130: 2022-11-22T16:47:47.805Z	INFO	tester	case START	{"round": 0, "case": 6, "case-total": 22, "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1385](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1386)
    logger.go:130: 2022-11-22T16:47:47.805Z	INFO	tester	wait health before injecting failures
[1386](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1387)
    logger.go:130: 2022-11-22T16:47:47.819Z	INFO	tester	health check PASS	{"retries": 0, "endpoint": "127.0.0.1:1379"}
[1387](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1388)
    logger.go:130: 2022-11-22T16:47:47.832Z	INFO	tester	health check PASS	{"retries": 0, "endpoint": "127.0.0.1:2379"}
[1388](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1389)
    logger.go:130: 2022-11-22T16:47:47.844Z	INFO	tester	health check PASS	{"retries": 0, "endpoint": "127.0.0.1:3379"}
[1389](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1390)
    logger.go:130: 2022-11-22T16:47:47.844Z	INFO	tester	health check ALL PASS
[1390](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1391)
    logger.go:130: 2022-11-22T16:47:47.845Z	INFO	tester	stress START	{"round": 0, "case": 6, "case-total": 22, "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1391](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1392)
    logger.go:130: 2022-11-22T16:47:47.845Z	INFO	tester	stress START	{"stress-type": "LEASE", "endpoint": "127.0.0.1:1379"}
[1392](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1393)
    logger.go:130: 2022-11-22T16:47:47.849Z	INFO	tester	stress START	{"stress-type": "KV", "endpoint": "127.0.0.1:1379"}
[1393](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1394)
    logger.go:130: 2022-11-22T16:47:47.849Z	INFO	tester	stress START	{"stress-type": "LEASE", "endpoint": "127.0.0.1:2379"}
[1394](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1395)
    logger.go:130: 2022-11-22T16:47:47.850Z	INFO	tester	stress START	{"stress-type": "KV", "endpoint": "127.0.0.1:2379"}
[1395](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1396)
    logger.go:130: 2022-11-22T16:47:47.850Z	INFO	tester	stress START	{"stress-type": "LEASE", "endpoint": "127.0.0.1:3379"}
[1396](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1397)
    logger.go:130: 2022-11-22T16:47:47.851Z	INFO	tester	stress START	{"stress-type": "KV", "endpoint": "127.0.0.1:3379"}
[1397](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1398)
    logger.go:130: 2022-11-22T16:47:47.851Z	INFO	tester	inject START	{"round": 0, "case": 6, "case-total": 22, "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1398](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1399)
    logger.go:130: 2022-11-22T16:47:47.921Z	INFO	tester	sent request	{"operation": "BLACKHOLE_PEER_PORT_TX_RX", "to": "127.0.0.1:1379"}
[1399](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1400)
2022-11-22T16:47:47.924Z	INFO	agent	agent/handler.go:642	blackholing	{"address": "127.0.0.1:19027", "peer-port": 1381}
[1400](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1401)
2022-11-22T16:47:47.924Z	INFO	agent	proxy/server.go:822	modifying tx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1381", "to": "tcp://127.0.0.1:1380"}
[1401](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1402)
2022-11-22T16:47:47.924Z	INFO	agent	proxy/server.go:866	blackholed tx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1381", "to": "tcp://127.0.0.1:1380"}
[1402](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1403)
2022-11-22T16:47:47.924Z	INFO	agent	proxy/server.go:845	modifying rx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1380", "to": "tcp://127.0.0.1:1381"}
[1403](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1404)
2022-11-22T16:47:47.924Z	INFO	agent	proxy/server.go:884	blackholed rx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1380", "to": "tcp://127.0.0.1:1381"}
[1404](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1405)
2022-11-22T16:47:47.924Z	INFO	agent	agent/handler.go:645	blackholed	{"address": "127.0.0.1:19027", "peer-port": 1381}
[1405](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1406)
2022-11-22T16:47:47.924Z	INFO	agent	agent/handler.go:40	handler success	{"address": "127.0.0.1:19027", "operation": "BLACKHOLE_PEER_PORT_TX_RX"}
[1406](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1407)
    logger.go:130: 2022-11-22T16:47:47.925Z	INFO	tester	received response	{"operation": "BLACKHOLE_PEER_PORT_TX_RX", "from": "127.0.0.1:1379", "success": true, "status": "blackholed peer port tx/rx"}
[1407](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1408)
    logger.go:130: 2022-11-22T16:47:47.925Z	INFO	tester	wait after inject	{"delay": "7s", "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1408](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1409)
    logger.go:130: 2022-11-22T16:47:54.925Z	INFO	tester	recover START	{"round": 0, "case": 6, "case-total": 22, "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1409](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1410)
2022-11-22T16:47:54.926Z	INFO	agent	agent/handler.go:655	unblackholing	{"address": "127.0.0.1:19027", "peer-port": 1381}
[1410](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1411)
    logger.go:130: 2022-11-22T16:47:54.925Z	INFO	tester	sent request	{"operation": "UNBLACKHOLE_PEER_PORT_TX_RX", "to": "127.0.0.1:1379"}
[1411](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1412)
2022-11-22T16:47:54.926Z	INFO	agent	proxy/server.go:834	unmodifyed tx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1381", "to": "tcp://127.0.0.1:1380"}
[1412](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1413)
2022-11-22T16:47:54.926Z	INFO	agent	proxy/server.go:875	unblackholed tx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1381", "to": "tcp://127.0.0.1:1380"}
[1413](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1414)
2022-11-22T16:47:54.926Z	INFO	agent	proxy/server.go:857	unmodifyed rx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1380", "to": "tcp://127.0.0.1:1381"}
[1414](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1415)
2022-11-22T16:47:54.926Z	INFO	agent	proxy/server.go:893	unblackholed rx	{"address": "127.0.0.1:19027", "from": "tcp://127.0.0.1:1380", "to": "tcp://127.0.0.1:1381"}
[1415](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1416)
2022-11-22T16:47:54.926Z	INFO	agent	agent/handler.go:658	unblackholed	{"address": "127.0.0.1:19027", "peer-port": 1381}
[1416](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1417)
2022-11-22T16:47:54.926Z	INFO	agent	agent/handler.go:40	handler success	{"address": "127.0.0.1:19027", "operation": "UNBLACKHOLE_PEER_PORT_TX_RX"}
[1417](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1418)
    logger.go:130: 2022-11-22T16:47:54.927Z	INFO	tester	received response	{"operation": "UNBLACKHOLE_PEER_PORT_TX_RX", "from": "127.0.0.1:1379", "success": true, "status": "unblackholed peer port tx/rx"}
[1418](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1419)
    logger.go:130: 2022-11-22T16:47:54.928Z	INFO	tester	stress PAUSE	{"round": 0, "case": 6, "case-total": 22, "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1419](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1420)
    logger.go:130: 2022-11-22T16:47:54.932Z	INFO	tester	stress STOP	{"stress-type": "LEASE", "endpoint": "127.0.0.1:3379"}
[1420](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1421)
    logger.go:130: 2022-11-22T16:47:54.934Z	INFO	tester	stress STOP	{"stress-type": "LEASE", "endpoint": "127.0.0.1:1379"}
[1421](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1422)
    logger.go:130: 2022-11-22T16:47:54.935Z	INFO	tester	stress STOP	{"stress-type": "KV", "endpoint": "127.0.0.1:1379"}
[1422](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1423)
    logger.go:130: 2022-11-22T16:47:54.936Z	INFO	tester	stress STOP	{"stress-type": "LEASE", "endpoint": "127.0.0.1:2379"}
[1423](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1424)
    logger.go:130: 2022-11-22T16:47:54.936Z	INFO	tester	stress STOP	{"stress-type": "KV", "endpoint": "127.0.0.1:2379"}
[1424](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1425)
    logger.go:130: 2022-11-22T16:47:54.936Z	INFO	tester	stress STOP	{"stress-type": "KV", "endpoint": "127.0.0.1:3379"}
[1425](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1426)
    logger.go:130: 2022-11-22T16:47:54.940Z	INFO	tester	health check START	{"round": 0, "case": 6, "case-total": 22, "desc": "BLACKHOLE_PEER_PORT_TX_RX_LEADER"}
[1426](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1427)
    logger.go:130: 2022-11-22T16:47:59.942Z	WARN	tester	health check FAIL	{"retries": 0, "endpoint": "127.0.0.1:1379", "error": "context deadline exceeded (\"127.0.0.1:1379\")"}
[1427](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1428)
    logger.go:130: 2022-11-22T16:48:00.955Z	WARN	tester	health check FAIL	{"retries": 1, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1428](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1429)
    logger.go:130: 2022-11-22T16:48:01.969Z	WARN	tester	health check FAIL	{"retries": 2, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1429](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1430)
    logger.go:130: 2022-11-22T16:48:02.981Z	WARN	tester	health check FAIL	{"retries": 3, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1430](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1431)
    logger.go:130: 2022-11-22T16:48:03.993Z	WARN	tester	health check FAIL	{"retries": 4, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1431](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1432)
    logger.go:130: 2022-11-22T16:48:05.005Z	WARN	tester	health check FAIL	{"retries": 5, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1432](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1433)
    logger.go:130: 2022-11-22T16:48:06.019Z	WARN	tester	health check FAIL	{"retries": 6, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1433](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1434)
    logger.go:130: 2022-11-22T16:48:07.031Z	WARN	tester	health check FAIL	{"retries": 7, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1434](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1435)
    logger.go:130: 2022-11-22T16:48:08.048Z	WARN	tester	health check FAIL	{"retries": 8, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1435](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1436)
    logger.go:130: 2022-11-22T16:48:09.060Z	WARN	tester	health check FAIL	{"retries": 9, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1436](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1437)
    logger.go:130: 2022-11-22T16:48:10.072Z	WARN	tester	health check FAIL	{"retries": 10, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1437](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1438)
    logger.go:130: 2022-11-22T16:48:11.085Z	WARN	tester	health check FAIL	{"retries": 11, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1438](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1439)
    logger.go:130: 2022-11-22T16:48:12.097Z	WARN	tester	health check FAIL	{"retries": 12, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1439](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1440)
    logger.go:130: 2022-11-22T16:48:13.110Z	WARN	tester	health check FAIL	{"retries": 13, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1440](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1441)
    logger.go:130: 2022-11-22T16:48:14.122Z	WARN	tester	health check FAIL	{"retries": 14, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1441](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1442)
    logger.go:130: 2022-11-22T16:48:15.135Z	WARN	tester	health check FAIL	{"retries": 15, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1442](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1443)
    logger.go:130: 2022-11-22T16:48:16.148Z	WARN	tester	health check FAIL	{"retries": 16, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1443](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1444)
    logger.go:130: 2022-11-22T16:48:17.161Z	WARN	tester	health check FAIL	{"retries": 17, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1444](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1445)
    logger.go:130: 2022-11-22T16:48:18.173Z	WARN	tester	health check FAIL	{"retries": 18, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1445](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1446)
    logger.go:130: 2022-11-22T16:48:19.186Z	WARN	tester	health check FAIL	{"retries": 19, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1446](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1447)
    logger.go:130: 2022-11-22T16:48:20.200Z	WARN	tester	health check FAIL	{"retries": 20, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1447](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1448)
    logger.go:130: 2022-11-22T16:48:21.214Z	WARN	tester	health check FAIL	{"retries": 21, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1448](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1449)
    logger.go:130: 2022-11-22T16:48:22.227Z	WARN	tester	health check FAIL	{"retries": 22, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1449](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1450)
    logger.go:130: 2022-11-22T16:48:23.239Z	WARN	tester	health check FAIL	{"retries": 23, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1450](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1451)
    logger.go:130: 2022-11-22T16:48:24.251Z	WARN	tester	health check FAIL	{"retries": 24, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1451](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1452)
    logger.go:130: 2022-11-22T16:48:25.264Z	WARN	tester	health check FAIL	{"retries": 25, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1452](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1453)
    logger.go:130: 2022-11-22T16:48:26.276Z	WARN	tester	health check FAIL	{"retries": 26, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1453](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1454)
    logger.go:130: 2022-11-22T16:48:27.288Z	WARN	tester	health check FAIL	{"retries": 27, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1454](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1455)
    logger.go:130: 2022-11-22T16:48:28.300Z	WARN	tester	health check FAIL	{"retries": 28, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1455](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1456)
    logger.go:130: 2022-11-22T16:48:29.312Z	WARN	tester	health check FAIL	{"retries": 29, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1456](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1457)
    logger.go:130: 2022-11-22T16:48:30.324Z	WARN	tester	health check FAIL	{"retries": 30, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1457](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1458)
    logger.go:130: 2022-11-22T16:48:31.337Z	WARN	tester	health check FAIL	{"retries": 31, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1458](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1459)
    logger.go:130: 2022-11-22T16:48:32.350Z	WARN	tester	health check FAIL	{"retries": 32, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1459](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1460)
    logger.go:130: 2022-11-22T16:48:33.363Z	WARN	tester	health check FAIL	{"retries": 33, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1460](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1461)
    logger.go:130: 2022-11-22T16:48:34.376Z	WARN	tester	health check FAIL	{"retries": 34, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1461](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1462)
    logger.go:130: 2022-11-22T16:48:35.388Z	WARN	tester	health check FAIL	{"retries": 35, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1462](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1463)
    logger.go:130: 2022-11-22T16:48:36.401Z	WARN	tester	health check FAIL	{"retries": 36, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1463](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1464)
    logger.go:130: 2022-11-22T16:48:37.414Z	WARN	tester	health check FAIL	{"retries": 37, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1464](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1465)
    logger.go:130: 2022-11-22T16:48:38.426Z	WARN	tester	health check FAIL	{"retries": 38, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1465](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1466)
    logger.go:130: 2022-11-22T16:48:39.439Z	WARN	tester	health check FAIL	{"retries": 39, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1466](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1467)
    logger.go:130: 2022-11-22T16:48:40.451Z	WARN	tester	health check FAIL	{"retries": 40, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1467](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1468)
    logger.go:130: 2022-11-22T16:48:41.464Z	WARN	tester	health check FAIL	{"retries": 41, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1468](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1469)
    logger.go:130: 2022-11-22T16:48:42.476Z	WARN	tester	health check FAIL	{"retries": 42, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1469](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1470)
    logger.go:130: 2022-11-22T16:48:43.488Z	WARN	tester	health check FAIL	{"retries": 43, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1470](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1471)
    logger.go:130: 2022-11-22T16:48:44.502Z	WARN	tester	health check FAIL	{"retries": 44, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1471](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1472)
    logger.go:130: 2022-11-22T16:48:45.515Z	WARN	tester	health check FAIL	{"retries": 45, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1472](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1473)
    logger.go:130: 2022-11-22T16:48:46.527Z	WARN	tester	health check FAIL	{"retries": 46, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1473](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1474)
    logger.go:130: 2022-11-22T16:48:47.540Z	WARN	tester	health check FAIL	{"retries": 47, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1474](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1475)
    logger.go:130: 2022-11-22T16:48:48.552Z	WARN	tester	health check FAIL	{"retries": 48, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1475](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1476)
    logger.go:130: 2022-11-22T16:48:49.565Z	WARN	tester	health check FAIL	{"retries": 49, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1476](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1477)
    logger.go:130: 2022-11-22T16:48:50.577Z	WARN	tester	health check FAIL	{"retries": 50, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1477](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1478)
    logger.go:130: 2022-11-22T16:48:51.589Z	WARN	tester	health check FAIL	{"retries": 51, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1478](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1479)
    logger.go:130: 2022-11-22T16:48:52.601Z	WARN	tester	health check FAIL	{"retries": 52, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1479](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1480)
    logger.go:130: 2022-11-22T16:48:53.614Z	WARN	tester	health check FAIL	{"retries": 53, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1480](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1481)
    logger.go:130: 2022-11-22T16:48:54.626Z	WARN	tester	health check FAIL	{"retries": 54, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1481](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1482)
    logger.go:130: 2022-11-22T16:48:55.640Z	WARN	tester	health check FAIL	{"retries": 55, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1482](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1483)
    logger.go:130: 2022-11-22T16:48:56.652Z	WARN	tester	health check FAIL	{"retries": 56, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1483](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1484)
    logger.go:130: 2022-11-22T16:48:57.664Z	WARN	tester	health check FAIL	{"retries": 57, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1484](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1485)
    logger.go:130: 2022-11-22T16:48:58.677Z	WARN	tester	health check FAIL	{"retries": 58, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1485](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1486)
    logger.go:130: 2022-11-22T16:48:59.689Z	WARN	tester	health check FAIL	{"retries": 59, "endpoint": "127.0.0.1:1379", "error": "etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1486](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1487)
    logger.go:130: 2022-11-22T16:49:00.689Z	ERROR	tester	functional-tester FAIL	{"round": 0, "case-name": "TestFunctional/round-0/6_BLACKHOLE_PEER_PORT_TX_RX_LEADER", "case-number": 6, "case-total": 22, "error": "wait full health error after test finished: etcdserver: too many requests (\"127.0.0.1:1379\")"}
[1487](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1488)
FAIL: (code:2):
[1488](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1489)
  % './bin/etcd-tester' '--config' './tests/functional/functional.yaml' '-test.v'
[1489](https://github.com/etcd-io/etcd/actions/runs/3525330252/jobs/5911919473#step:5:1490)
ETCD_TESTER_EXIT_CODE: 2

Github Action link

https://github.com/etcd-io/etcd/actions/runs/3525330252

Reason for failure (if possible)

No response

Anything else we need to know?

No response
@lavacat lavacat changed the title functional test fails. "etcdserver: too many requests" functional test flaky. "etcdserver: too many requests" Nov 22, 2022
@lavacat
Copy link
Author

lavacat commented Nov 22, 2022

There are repeated failed to detach old lease from a key in the tailed logs from etcd nodes.

2022-11-22T16:49:00.7951076Z {"level":"error","ts":"2022-11-22T16:47:53.027Z","caller":"mvcc/kvstore_txn.go:309","msg":"failed to detach old lease from a key","error":"lease not found","stacktrace":"go.etcd.io/etcd/server/v3/storage/mvcc.(*storeTxnWrite).delete
	go.etcd.io/etcd/server/v3/storage/mvcc/kvstore_txn.go:309
go.etcd.io/etcd/server/v3/storage/mvcc.(*storeTxnWrite).deleteRange
	go.etcd.io/etcd/server/v3/storage/mvcc/kvstore_txn.go:270
go.etcd.io/etcd/server/v3/storage/mvcc.(*storeTxnWrite).DeleteRange
	go.etcd.io/etcd/server/v3/storage/mvcc/kvstore_txn.go:165
go.etcd.io/etcd/server/v3/storage/mvcc.(*metricsTxnWrite).DeleteRange
	go.etcd.io/etcd/server/v3/storage/mvcc/metrics_txn.go:46
go.etcd.io/etcd/server/v3/lease.(*lessor).Revoke
	go.etcd.io/etcd/server/v3/lease/lessor.go:349
go.etcd.io/etcd/server/v3/etcdserver/apply.(*applierV3backend).LeaseRevoke
	go.etcd.io/etcd/server/v3/etcdserver/apply/apply.go:205
go.etcd.io/etcd/server/v3/etcdserver/apply.(*authApplierV3).LeaseRevoke
	go.etcd.io/etcd/server/v3/etcdserver/apply/apply_auth.go:122
go.etcd.io/etcd/server/v3/etcdserver/apply.(*uberApplier).dispatch
	go.etcd.io/etcd/server/v3/etcdserver/apply/uber_applier.go:173
go.etcd.io/etcd/server/v3/etcdserver/apply.(*applierV3backend).Apply
	go.etcd.io/etcd/server/v3/etcdserver/apply/apply.go:156
go.etcd.io/etcd/server/v3/etcdserver/apply.(*authApplierV3).Apply
	go.etcd.io/etcd/server/v3/etcdserver/apply/apply_auth.go:62
go.etcd.io/etcd/server/v3/etcdserver/apply.(*uberApplier).Apply
	go.etcd.io/etcd/server/v3/etcdserver/apply/uber_applier.go:116
go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).applyEntryNormal
	go.etcd.io/etcd/server/v3/etcdserver/server.go:1906
go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).apply
	go.etcd.io/etcd/server/v3/etcdserver/server.go:1805
go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).applyEntries
	go.etcd.io/etcd/server/v3/etcdserver/server.go:1126
go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).applyAll
	go.etcd.io/etcd/server/v3/etcdserver/server.go:922
go.etcd.io/etcd/server/v3/etcdserver.(*EtcdServer).run.func8
	go.etcd.io/etcd/server/v3/etcdserver/server.go:845
go.etcd.io/etcd/pkg/v3/schedule.job.Do
	go.etcd.io/etcd/pkg/[email protected]/schedule/schedule.go:41
go.etcd.io/etcd/pkg/v3/schedule.(*fifo).executeJob
	go.etcd.io/etcd/pkg/[email protected]/schedule/schedule.go:206
go.etcd.io/etcd/pkg/v3/schedule.(*fifo).run
	go.etcd.io/etcd/pkg/[email protected]/schedule/schedule.go:187"}

Might be related to #14487 (same error msg)

@lavacat
Copy link
Author

lavacat commented Feb 5, 2023

Similar error https://github.com/etcd-io/etcd/actions/runs/4095637113/jobs/7062692311

Saved logs using "Download log archive" button
logs_51862.zip

@lavacat lavacat mentioned this issue Feb 5, 2023
Merged
@serathius
Copy link
Member

I would not bother fixing functional tests as we plan to remove them #15102

@stale
Copy link

stale bot commented May 21, 2023

This issue has been automatically marked as stale because it has not had recent activity. It will be closed after 21 days if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale label May 21, 2023
@ahrtr ahrtr closed this as completed May 21, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
stale type/flake
Milestone
No milestone
Development

No branches or pull requests
3 participants
@lavacat @serathius @ahrtr