vtexplain broken by new healthcheck implementation

[aquarapid]

In current master (41c356e), vtexplain will fail in a completely valid case with a "no valid tablet" error, e.g.:

schema.sql:

CREATE TABLE t1 (
  id int NOT NULL,
  PRIMARY KEY (id)
);

vschema.json:

{
    "ks1": {
        "sharded": true,
        "tables": {
            "t1": {
                "column_vindexes": [
                    {
                        "column": "id",
                        "name": "hash"
                    }
                ]
            }
        },
        "vindexes": {
            "hash": {
                "type": "hash"
            }
        }
    }
}

vtexplain run:

$ vtexplain -schema-file=schema.sql -vschema-file=vschema.json -shards 2 -sql 'SELECT * from t1'
ERROR: vtexplain execute error in 'SELECT * from t1': target: ks1.-80.master: no valid tablet
target: ks1.80-.master: no valid tablet

Reverting to a checkin before bcbee47 (e.g. 9778957), it works as expected:

$ vtexplain -schema-file=schema.sql -vschema-file=vschema.json -shards 2 -sql 'SELECT * from t1'
----------------------------------------------------------------------
SELECT * from t1

1 ks1/-80: select * from t1 limit 10001
1 ks1/80-: select * from t1 limit 10001

----------------------------------------------------------------------

Reverting the default gateway_implementation to discoverygateway instead of the new healthcheck implementation of tabletgateway in gateway.go will also fix vtexplain.

[deepthi]

Either #6247 or #6248 will get vtexplain working again, but with the old healthcheck. I would like to keep the issue open until we get vtexplain working with new healthcheck.

[deepthi]

Fixed in #6460

[jamisonhyatt]

@deepthi I think this broke the docker-compose setup but I just encountered it, and haven't had a chance to dig in yet.

e.g., it's my understanding that something like this should naturally work at the root there, or at least did last week:

docker-compose -f docker-compose.beginners.yml --env-file template.env  up -d
docker exec -it <vtgate container id> mysql -u root -h 127.0.0.1 -P 15306 -e 'select * from information_schema.tables;' 
ERROR 1105 (HY000) at line 1: vtgate: http://<vtgate container id>:8080/: target: test_keyspace.0.master: no valid tablet

[aquarapid]

The docker-compose issue is probably unrelated to this change. I can't run compose locally right now, but it seems like docker-compose.beginners.yml still has -gateway_implementation discoverygateway; which should just be removed, as we did for example for examples/local in 17ef346

[deepthi]

With a local release-7.0 build I can run docker-compose using vtcompose and do this:

docker-compose up -d
docker exec -it compose_vtgate_1 mysql -u root -h 127.0.0.1 -P 15306 -D test_keyspace -e 'select * from information_schema.tables;'

This works fine. I do have to specify -D test_keyspace, otherwise I get a no keyspace in database name specified. error.

[jamisonhyatt]

did you update your images first? Mine was working locally where I had cached images, but breaking in CI (where images were downloaded fresh) and then I updated my local images and continued to get this behavior:

This is from today with a fresh docker pull vitess/base:v7.0.0 matching the v7.0.0 head:

 ▲ vitess/examples/compose docker ps -a                                                                                                                                                                      ⇡ a3a52322d :: 5h :: ⬡
CONTAINER ID        IMAGE               COMMAND             CREATED             STATUS              PORTS               NAMES

 ▲ vitess/examples/compose git checkout v7.0.0                                                                                                                                                               ⇡ a3a52322d :: 5h :: ⬡
HEAD is now at a3a52322d Merge pull request #6488 from planetscale/settings-tweak-backport

 ▲ vitess/examples/compose go run vtcompose/vtcompose.go -keyspaceData="test_keyspace:0:2:create_messages.sql"                                                                                               ⇡ a3a52322d :: 5h :: ⬡

 ▲ vitess/examples/compose docker-compose up -d                                                                                                                                                              ⇡ a3a52322d :: 5h :: ⬡
Creating compose_consul1_1 ... done
Creating compose_consul2_1 ... done
Creating compose_consul3_1 ... done
Creating compose_vtctld_1  ... done
Creating compose_vttablet102_1 ... done
Creating compose_vtwork_1      ... done
Creating compose_vttablet103_1 ... done
Creating compose_vtgate_1      ... done
Creating compose_vttablet101_1 ... done
Creating compose_schemaload_test_keyspace_1 ... done

 ▲ vitess/examples/compose docker ps                                                                                                                                                                    33s  ⇡ a3a52322d :: 5h :: ⬡
CONTAINER ID        IMAGE               COMMAND                  CREATED              STATUS                        PORTS                                                                                                            NAMES
7e188245b819        vitess/base         "sh -c '/script/vtta…"   About a minute ago   Up About a minute (healthy)   0.0.0.0:32791->3306/tcp, 0.0.0.0:15101->8080/tcp, 0.0.0.0:32789->15999/tcp                                       compose_vttablet101_1
69552d653a7a        vitess/base         "sh -c '/script/vtta…"   About a minute ago   Up About a minute (healthy)   0.0.0.0:32790->3306/tcp, 0.0.0.0:15103->8080/tcp, 0.0.0.0:32785->15999/tcp                                       compose_vttablet103_1
d4a105336483        vitess/base         "sh -c '$VTROOT/bin/…"   About a minute ago   Up About a minute             0.0.0.0:15100->8080/tcp, 0.0.0.0:32788->15999/tcp                                                                compose_vtwork_1
92519149a582        vitess/base         "sh -c '/script/run-…"   About a minute ago   Up About a minute             0.0.0.0:15306->15306/tcp, 0.0.0.0:15099->8080/tcp, 0.0.0.0:32786->15999/tcp                                      compose_vtgate_1
fa4d665a96c2        vitess/base         "sh -c '/script/vtta…"   About a minute ago   Up About a minute (healthy)   0.0.0.0:32787->3306/tcp, 0.0.0.0:15102->8080/tcp, 0.0.0.0:32784->15999/tcp                                       compose_vttablet102_1
46be4ae6d23a        vitess/base         "sh -c ' $VTROOT/bin…"   About a minute ago   Up About a minute             0.0.0.0:15000->8080/tcp, 0.0.0.0:32783->15999/tcp                                                                compose_vtctld_1
b75654385b8d        consul:latest       "docker-entrypoint.s…"   About a minute ago   Up About a minute             8300-8302/tcp, 8400/tcp, 8500/tcp, 8301-8302/udp, 8600/tcp, 8600/udp                                             compose_consul2_1
9c91982ce73d        consul:latest       "docker-entrypoint.s…"   About a minute ago   Up About a minute             8300-8302/tcp, 8400/tcp, 8500/tcp, 8301-8302/udp, 8600/tcp, 8600/udp                                             compose_consul3_1
e33cb170ec6a        consul:latest       "docker-entrypoint.s…"   About a minute ago   Up About a minute             0.0.0.0:8400->8400/tcp, 8301-8302/udp, 0.0.0.0:8500->8500/tcp, 8300-8302/tcp, 8600/udp, 0.0.0.0:8600->8600/tcp   compose_consul1_1

 ▲ vitess/examples/compose docker logs compose_vtgate_1                                                                                                                                                      ⇡ a3a52322d :: 5h :: ⬡
ERROR: logging before flag.Parse: E0728 18:13:34.319917       8 syslogger.go:122] can't connect to syslog
I0728 18:13:34.352730       8 servenv.go:97] Version: 5bffd6faa (Git branch 'master') built on Mon Jul 27 21:38:14 UTC 2020 by root@c1477cbcf77d using go1.13.9 linux/amd64
E0728 18:13:34.352895       8 pid_file.go:40] Unable to create pid file '/vt/vtdataroot/tmp/vtgate.pid': open /vt/vtdataroot/tmp/vtgate.pid: no such file or directory
I0728 18:13:34.352972       8 server.go:64] Consul client auth is not set up. consul_auth_static_file was not provided
I0728 18:13:34.353044       8 buffer.go:144] vtgate buffer not enabled.
I0728 18:13:34.353149       8 discoverygateway.go:124] loading tablets for cells: test
I0728 18:13:34.353275       8 gateway.go:100] Gateway waiting for serving tablets of types [MASTER REPLICA RDONLY] ...
E0728 18:13:41.420539       8 legacy_topology_watcher.go:161] cannot get tablets for cell: test: Unexpected response code: 500
E0728 18:13:41.729837       8 resilient_server.go:310] GetSrvKeyspaceNames(context.Background.WithDeadline(2020-07-28 18:14:04.353312166 +0000 UTC m=+30.035623433 [22.623464127s]), test) failed: Unexpected response code: 500 (no cached value, caching and returning error)
F0728 18:13:41.729912       8 vtgate.go:488] gateway.WaitForTablets failed: Unexpected response code: 500
ERROR: logging before flag.Parse: E0728 18:13:43.738709      20 syslogger.go:122] can't connect to syslog
I0728 18:13:43.756530      20 servenv.go:97] Version: 5bffd6faa (Git branch 'master') built on Mon Jul 27 21:38:14 UTC 2020 by root@c1477cbcf77d using go1.13.9 linux/amd64
E0728 18:13:43.756656      20 pid_file.go:40] Unable to create pid file '/vt/vtdataroot/tmp/vtgate.pid': open /vt/vtdataroot/tmp/vtgate.pid: no such file or directory
I0728 18:13:43.756712      20 server.go:64] Consul client auth is not set up. consul_auth_static_file was not provided
I0728 18:13:43.756794      20 buffer.go:144] vtgate buffer not enabled.
I0728 18:13:43.756807      20 discoverygateway.go:124] loading tablets for cells: test
I0728 18:13:43.756842      20 gateway.go:100] Gateway waiting for serving tablets of types [MASTER REPLICA RDONLY] ...
I0728 18:13:43.759715      20 server.go:64] Consul client auth is not set up. consul_auth_static_file was not provided
I0728 18:13:43.764497      20 asm_amd64.s:1357] HealthCheckUpdate(Serving State): test-0000000103, tablet: test-103 (vttablet103) serving => false for test_keyspace/- (RDONLY) reason: healthCheck update error: vttablet error: no slave status
I0728 18:13:43.764544      20 asm_amd64.s:1357] HealthCheckUpdate(Serving State): test-0000000101, tablet: test-101 (vttablet101) serving => false for test_keyspace/- (REPLICA) reason: healthCheck update error: vttablet error: no slave status
I0728 18:13:43.764772      20 asm_amd64.s:1357] HealthCheckUpdate(Serving State): test-0000000102, tablet: test-102 (vttablet102) serving => false for test_keyspace/- (REPLICA) reason: healthCheck update error: vttablet error: no slave status
W0728 18:14:13.782236      20 gateway.go:113] Timeout waiting for all keyspaces / shards to have healthy tablets of types [MASTER REPLICA RDONLY], may be in degraded mode
I0728 18:14:13.782304      20 vtgate.go:80] Transaction mode: 'MULTI'
I0728 18:14:13.783547      20 streamlog.go:155] Streaming logs from VTGate at /debug/querylog.
I0728 18:14:13.783617      20 grpc_server.go:142] Setting grpc max message size to 16777216
I0728 18:14:13.783628      20 grpc_server.go:310] Building interceptors with 0 unary interceptors and 0 stream interceptors
I0728 18:14:13.783892      20 auth_server_clientcert.go:36] Not configuring AuthServerClientCert because mysql_server_ssl_ca is empty
I0728 18:14:13.783970      20 auth_server_ldap.go:57] Not configuring AuthServerLdap because mysql_ldap_auth_config_file and mysql_ldap_auth_config_string are empty
I0728 18:14:13.784036      20 auth_server_static.go:91] Not configuring AuthServerStatic, as mysql_auth_server_static_file and mysql_auth_server_static_string are empty
I0728 18:14:13.786396      20 service_map.go:64] Registering vtgateservice for grpc, disable it with -grpc-vtgateservice service_map parameter
I0728 18:14:13.788745      20 grpc_server.go:212] Listening for gRPC calls on port 15999
I0728 18:14:13.788806      20 unix_socket.go:36] Not listening on socket file

 ▲ vitess/examples/compose docker exec -it compose_vtgate_1 mysql -u root -h 127.0.0.1 -P 15306 -D test_keyspace -e 'select * from information_schema.tables;'                                               ⇡ a3a52322d :: 5h :: ⬡
ERROR 1105 (HY000) at line 1: vtgate: http://92519149a582:8080/: target: test_keyspace.-.master: no valid table

[deepthi]

good point. I might have had a cached docker image. Can you please open a new issue as a docker-compose example issue? Agree with @aquarapid that this seems unrelated to vtexplain.

[deepthi]

@jamisonhyatt I have tracked this down and created a new issue #6521