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.

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

keyspace group distribution manager failed to unmarshal service registry entry #6343

Closed
binshi-bing opened this issue Apr 19, 2023 · 0 comments · Fixed by #6346
Closed

keyspace group distribution manager failed to unmarshal service registry entry #6343

binshi-bing opened this issue Apr 19, 2023 · 0 comments · Fixed by #6346
Labels
type/enhancement The issue or PR belongs to an enhancement.

Comments

@binshi-bing
Copy link
Contributor

binshi-bing commented Apr 19, 2023

Enhancement Task

Issue Number: Ref #6233
There are two bugs:

  1. When re-watch a range, to continue from what left by the last watch, the revision is wresp.Header.Revision + 1 instead of wresp.Header.Revision, where wresp.Header.Revision is the revision indicated in the response of the last watch. Because of this bug, it was processing the same event endless as you can see from the log below.
  2. In tso service watch loop in /Users/binshi/code/pingcap/my-pd/pkg/keyspace/tso_keyspace_group.go, If this is delete event, the json.Unmarshal(event.Kv.Value, s) will fail with the error "unexpected end of JSON input", so there is no way to get s.serviceAddr from the result of json.Unmarshal.

under /pd/tests/integrations/mcs, run "go test -run TestAPIServerForwardTestSuite/TestForwardTSOWhenPrimaryChanged tso/server_test.go -v". Though the test passed, but the log contains numberless suspicious log lines:

2023/04/19 14:40:11.285 -07:00] [WARN] [tso_keyspace_group.go:224] ["failed to unmarshal service registry entry"] [error="unexpected end of JSON input"]
[2023/04/19 14:40:11.285 -07:00] [WARN] [tso_keyspace_group.go:224] ["failed to unmarshal service registry entry"] [error="unexpected end of JSON input"]
[2023/04/19 14:40:11.285 -07:00] [WARN] [tso_keyspace_group.go:224] ["failed to unmarshal service registry entry"] [error="unexpected end of JSON input"]
...

[2023/04/19 15:14:05.499 -07:00] [ERROR] [operator_controller.go:878] ["invalid store ID"] [store-id=11]
[2023/04/19 15:14:05.499 -07:00] [INFO] [operator_controller.go:618] ["operator canceled"] [region-id=9] [takes=0s] [operator=""add-rule-peer {add peer: store [1]} (kind:replica,region,leader, region:9(0, 0), createAt:2023-04-19 15:14:05.499451 -0700 PDT m=+18.349748751, startAt:0001-01-01 00:00:00 +0000 UTC, currentStep:0, size:1, steps:[add learner peer 18 on store 1, promote learner peer 18 on store 1 to voter, transfer leader from store 11 to store 1],timeout:[12m0s])""] [additional-info=]
[2023/04/19 15:14:05.541 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:05.541 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:05.641 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:05.641 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:05.741 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:05.741 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:05.841 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:05.841 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:05.942 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:05.942 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.042 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.042 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.142 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.142 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.242 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.242 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.342 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.342 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.442 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.442 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.543 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.543 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.643 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.643 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.743 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.743 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.843 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.843 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:06.943 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:06.943 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.044 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.044 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.106 -07:00] [ERROR] [operator_controller.go:878] ["invalid store ID"] [store-id=11]
[2023/04/19 15:14:07.106 -07:00] [INFO] [operator_controller.go:618] ["operator canceled"] [region-id=9] [takes=0s] [operator=""add-rule-peer {add peer: store [1]} (kind:replica,region,leader, region:9(0, 0), createAt:2023-04-19 15:14:07.106377 -0700 PDT m=+19.956673085, startAt:0001-01-01 00:00:00 +0000 UTC, currentStep:0, size:1, steps:[add learner peer 19 on store 1, promote learner peer 19 on store 1 to voter, transfer leader from store 11 to store 1],timeout:[12m0s])""] [additional-info=]
[2023/04/19 15:14:07.144 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.144 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.244 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.244 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.344 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.344 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.437 -07:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {127.0.0.1:59363 0 }. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:59363: connect: connection refused". Reconnecting..."]
[2023/04/19 15:14:07.444 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.445 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.543 -07:00] [WARN] [grpclog.go:60] ["grpc: addrConn.createTransport failed to connect to {127.0.0.1:59363 0 }. Err :connection error: desc = "transport: Error while dialing dial tcp 127.0.0.1:59363: connect: connection refused". Reconnecting..."]
[2023/04/19 15:14:07.545 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.545 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.645 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.645 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04/19 15:14:07.746 -07:00] [WARN] [tso_keyspace_group.go:222] ["parsing events !!!!!!!!!!!!!!!!!"] [req-revision=53] [resp-revision=53] [events=1]
[2023/04/19 15:14:07.746 -07:00] [WARN] [tso_keyspace_group.go:229] ["failed to unmarshal service registry entry"] [key=/ms/7223887727742035347/tso/registry/http://127.0.0.1:59363] [value=] [error="unexpected end of JSON input"]
[2023/04

@binshi-bing binshi-bing added the type/enhancement The issue or PR belongs to an enhancement. label Apr 19, 2023
ti-chi-bot pushed a commit that referenced this issue Apr 20, 2023
ref #6343

Fixed the following two bugs:
1. When re-watch a range, to continue from what left by the last watch, the revision is wresp.Header.Revision + 1 instead of wresp.Header.Revision, where wresp.Header.Revision is the revision indicated in the response of the last watch. Because of this bug, it was processing the same event endless as you can see from the log below.
2. In tso service watch loop in /Users/binshi/code/pingcap/my-pd/pkg/keyspace/tso_keyspace_group.go, If this is delete event, the json.Unmarshal(event.Kv.Value, s) will fail with the error "unexpected end of JSON input", so there is no way to get s.serviceAddr from the result of json.Unmarshal.

Signed-off-by: Bin Shi <[email protected]>
rleungx pushed a commit to rleungx/pd that referenced this issue Aug 2, 2023
ref tikv#6343

Fixed the following two bugs:
1. When re-watch a range, to continue from what left by the last watch, the revision is wresp.Header.Revision + 1 instead of wresp.Header.Revision, where wresp.Header.Revision is the revision indicated in the response of the last watch. Because of this bug, it was processing the same event endless as you can see from the log below.
2. In tso service watch loop in /Users/binshi/code/pingcap/my-pd/pkg/keyspace/tso_keyspace_group.go, If this is delete event, the json.Unmarshal(event.Kv.Value, s) will fail with the error "unexpected end of JSON input", so there is no way to get s.serviceAddr from the result of json.Unmarshal.

Signed-off-by: Bin Shi <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type/enhancement The issue or PR belongs to an enhancement.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant