go: "TestKVWithEmptyValue" of etcd-io/etcd fails with master go

What version of Go are you using (go version)?

go version devel go1.17-5daefc5363 Thu Apr 22 01:40:02 2021 +0000 linux/ppc64le

Does this issue reproduce with the latest release?

No

What operating system and processor architecture are you using (go env)?

Linux ppc64le

What did you do?

go test go.etcd.io/etcd/tests/v3/integration Ran integration tests of etcd-io/etcd

What did you expect to see?

Should Pass successfully. NOTE: It passed with the stable release.

[root@rajalakshmi1-workspace etcd]# go test go.etcd.io/etcd/tests/v3/integration

ok      go.etcd.io/etcd/tests/v3/integration    191.044s
[root@rajalakshmi1-workspace etcd]# go version
go version go1.16 linux/ppc64le
[root@rajalakshmi1-workspace etcd]

What did you see instead?

Following Error for TestKVWithEmptyValue:

--- FAIL: TestKVWithEmptyValue (0.12s)
    logger.go:130: 2021-04-22T02:16:41.750Z     INFO    m0      LISTEN GRPC     {"member": "m0", "m.grpcAddr": "localhost:m0", "m.Name": "m0"}
    logger.go:130: 2021-04-22T02:16:41.751Z     INFO    m0      launching a member      {"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:215174179541"], "listen-client-urls": ["unix://127.0.0.1:215184179541"], "grpc-address": "unix://localhost:m00"}
    logger.go:130: 2021-04-22T02:16:41.752Z     INFO    m0      opened backend db       {"member": "m0", "path": "/tmp/TestKVWithEmptyValue3985847728/002/etcd4041780374/member/snap/db", "took": "1.166028ms"}
    logger.go:130: 2021-04-22T02:16:41.753Z     INFO    m0      starting local member   {"member": "m0", "local-member-id": "fa19bbaf425c7e1c", "cluster-id": "5ed47e72b9de8e47"}
    logger.go:130: 2021-04-22T02:16:41.753Z     INFO    m0.raft fa19bbaf425c7e1c switched to configuration voters=()    {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.753Z     INFO    m0.raft fa19bbaf425c7e1c became follower at term 0      {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.753Z     INFO    m0.raft newRaft fa19bbaf425c7e1c [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0] {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.753Z     INFO    m0.raft fa19bbaf425c7e1c became follower at term 1      {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.753Z     INFO    m0.raft fa19bbaf425c7e1c switched to configuration voters=(18021641745306779164)        {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.754Z     WARN    m0      simple token is not cryptographically signed    {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.756Z     INFO    m0      starting etcd server    {"member": "m0", "local-member-id": "fa19bbaf425c7e1c", "local-server-version": "3.5.0-alpha.0", "cluster-version": "to_be_decided"}
    logger.go:130: 2021-04-22T02:16:41.757Z     INFO    m0      started as single-node; fast-forwarding election ticks  {"member": "m0", "local-member-id": "fa19bbaf425c7e1c", "forward-ticks": 9, "forward-duration": "90ms", "election-ticks": 10, "election-timeout": "100ms"}
    logger.go:130: 2021-04-22T02:16:41.757Z     INFO    m0.raft fa19bbaf425c7e1c switched to configuration voters=(18021641745306779164)        {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.757Z     INFO    m0      added member    {"member": "m0", "cluster-id": "5ed47e72b9de8e47", "local-member-id": "fa19bbaf425c7e1c", "added-peer-id": "fa19bbaf425c7e1c", "added-peer-peer-urls": ["unix://127.0.0.1:215174179541"]}
logger.go:130: 2021-04-22T02:16:41.758Z     INFO    m0      launched a member       {"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:215174179541"], "listen-client-urls": ["unix://127.0.0.1:215184179541"], "grpc-address": "unix://localhost:m00"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0.raft fa19bbaf425c7e1c is starting a new election at term 1   {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0.raft fa19bbaf425c7e1c became candidate at term 2     {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0.raft fa19bbaf425c7e1c received MsgVoteResp from fa19bbaf425c7e1c at term 2   {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0.raft fa19bbaf425c7e1c became leader at term 2        {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0.raft raft.node: fa19bbaf425c7e1c elected leader fa19bbaf425c7e1c at term 2   {"member": "m0"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0      published local member to cluster through raft  {"member": "m0", "local-member-id": "fa19bbaf425c7e1c", "local-member-attributes": "{Name:m0 ClientURLs:[unix://127.0.0.1:215184179541]}", "request-path": "/0/members/fa19bbaf425c7e1c/attributes", "cluster-id": "5ed47e72b9de8e47", "publish-timeout": "5.2s"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0      setting up initial cluster version      {"member": "m0", "cluster-version": "3.5"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0      set initial cluster version     {"member": "m0", "cluster-id": "5ed47e72b9de8e47", "local-member-id": "fa19bbaf425c7e1c", "cluster-version": "3.5"}
    logger.go:130: 2021-04-22T02:16:41.854Z     INFO    m0      cluster version is updated      {"member": "m0", "cluster-version": "3.5"}
    cluster.go:251:  - m0 -> fa19bbaf425c7e1c (unix://localhost:m00)
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] parsed scheme: "etcd-endpoints"]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] ccResolverWrapper: sending update to cc: {[{unix:localhost:m00 localhost <nil> 0 <nil>}] 0xc00adc6ba0 <nil>}]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] ClientConn switching balancer to "round_robin"]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] Channel switches to new LB policy "round_robin"]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[balancer] base.baseBalancer: got new ClientConn state:  {{[{unix:localhost:m00 localhost <nil> 0 <nil>}] 0xc00adc6ba0 <nil>} <nil>}]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] Subchannel Connectivity change to CONNECTING]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] Subchannel picks a new address "unix:localhost:m00" to connect]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[balancer] base.baseBalancer: handle SubConn state change: 0xc0137e3ab0, CONNECTING]
    logger.go:130: 2021-04-22T02:16:41.858Z     INFO    grpc    [[core] Channel Connectivity change to CONNECTING]
    logger.go:130: 2021-04-22T02:16:41.861Z     INFO    grpc    [[core] Subchannel Connectivity change to READY]
    logger.go:130: 2021-04-22T02:16:41.861Z     INFO    grpc    [[balancer] base.baseBalancer: handle SubConn state change: 0xc0137e3ab0, READY]
    logger.go:130: 2021-04-22T02:16:41.861Z     INFO    grpc    [[roundrobin] roundrobinPicker: newPicker called with info: {map[0xc0137e3ab0:{{unix:localhost:m00 localhost <nil> 0 <nil>}}]}]
    logger.go:130: 2021-04-22T02:16:41.861Z     INFO    grpc    [[core] Channel Connectivity change to READY]
    v3_kv_test.go:39: my-namespace/foobar = data
    v3_kv_test.go:39: my-namespace/foobar1 = data
    v3_kv_test.go:39: namespace/foobar1 = data
    v3_kv_test.go:46: etcdserver: key is not provided
    logger.go:130: 2021-04-22T02:16:41.865Z     INFO    grpc    [[core] Channel Connectivity change to SHUTDOWN]
    logger.go:130: 2021-04-22T02:16:41.865Z     INFO    grpc    [[core] Subchannel Connectivity change to SHUTDOWN]
    logger.go:130: 2021-04-22T02:16:41.865Z     INFO    m0      terminating a member    {"member": "m0", "name": "m0", "advertise-peer-urls": ["unix://127.0.0.1:215174179541"], "listen-client-urls": ["unix://127.0.0.1:215184179541"], "grpc-address": "unix://localhost:m00"}
    logger.go:130: 2021-04-22T02:16:41.865Z     INFO    grpc    [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"]
    logger.go:130: 2021-04-22T02:16:41.865Z     INFO    grpc    [[transport] transport: loopyWriter.run returning. connection error: desc = "transport is closing"]

Please find the attached log etcd.log

About this issue

  • Original URL
  • State: closed
  • Created 3 years ago
  • Comments: 17 (13 by maintainers)

Most upvoted comments

I thought so because it passed with stable go version and not with the master go.

That doesn’t imply it is a Go bug. The code might depend on buggy or internal behavior of earlier versions of Go, which may change.