Skip to content

Instantly share code, notes, and snippets.

@rafael

rafael/gist:d136d12b827aee94fece67c9e05c2e22

Created September 13, 2017 03:44
Show Gist options
  • Save rafael/d136d12b827aee94fece67c9e05c2e22 to your computer and use it in GitHub Desktop.
Save rafael/d136d12b827aee94fece67c9e05c2e22 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
gistfile1.txt
2017/09/13 03:01:39 local.vtgate_buffer: -- 2017-09-13 03:01:07,230 mysql_flavor:208 DEBUG Using MySQL flavor: MySQL56, setting MYSQL_FLAVOR=MySQL56 (<class 'mysql_flavor.MySQL56'>)
-- 2017-09-13 03:01:07,453 environment:228 DEBUG Using protocols flavor 'grpc'
-- 2017-09-13 03:01:07,453 server:66 DEBUG Using topo server flavor 'zk2'
-- 2017-09-13 03:01:07,453 gateway:69 DEBUG Using VTGate gateway flavor 'discoverygateway'
-- 2017-09-13 03:01:07,459 environment:136 DEBUG run: ['/vagrant/bin/zkctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-zk.cfg', '1@vitess:17206:17207:17208', 'init']
-- 2017-09-13 03:01:08,540 environment:136 DEBUG run: ['/vagrant/bin/zk', '-server', 'localhost:17208', 'touch', '-p', '/global']
-- 2017-09-13 03:01:08,703 environment:136 DEBUG run: ['/vagrant/bin/zk', '-server', 'localhost:17208', 'touch', '-p', '/test_nj']
-- 2017-09-13 03:01:08,842 environment:136 DEBUG run: ['/vagrant/bin/zk', '-server', 'localhost:17208', 'touch', '-p', '/test_ny']
-- 2017-09-13 03:01:08,956 environment:136 DEBUG run: ['/vagrant/bin/zk', '-server', 'localhost:17208', 'touch', '-p', '/test_ca']
-- 2017-09-13 03:01:09,107 utils:267 DEBUG run: ['/vagrant/bin/vtctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-enable_queries', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-tablet_manager_protocol', 'grpc', '-tablet_protocol', 'grpc', '-throttler_client_protocol', 'grpc', '-vtgate_protocol', 'grpc', '--wait_for_drain_sleep_rdonly', '0s', '--wait_for_drain_sleep_replica', '0s', 'AddCellInfo', '-root', '/test_nj', '-server_address', 'localhost:17208', 'test_nj']
-- 2017-09-13 03:01:09,330 utils:267 DEBUG run: ['/vagrant/bin/vtctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-enable_queries', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-tablet_manager_protocol', 'grpc', '-tablet_protocol', 'grpc', '-throttler_client_protocol', 'grpc', '-vtgate_protocol', 'grpc', '--wait_for_drain_sleep_rdonly', '0s', '--wait_for_drain_sleep_replica', '0s', 'AddCellInfo', '-root', '/test_ny', '-server_address', 'localhost:17208', 'test_ny']
-- 2017-09-13 03:01:09,507 utils:267 DEBUG run: ['/vagrant/bin/vtctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-enable_queries', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-tablet_manager_protocol', 'grpc', '-tablet_protocol', 'grpc', '-throttler_client_protocol', 'grpc', '-vtgate_protocol', 'grpc', '--wait_for_drain_sleep_rdonly', '0s', '--wait_for_drain_sleep_replica', '0s', 'UpdateCellInfo', '-root', '/test_ca', '-server_address', 'localhost:17208', 'test_ca']
-- 2017-09-13 03:01:09,646 utils:306 DEBUG run: ['/vagrant/bin/mysqlctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-tablet_uid', '62344', '-port', '17200', '-mysql_port', '17201', '-db-config-dba-uname', 'vt_dba', '-db-config-dba-charset', 'utf8', 'init', '-init_db_sql_file', '/vagrant/src/github.com/youtube/vitess/config/init_db.sql'] extra_env={'EXTRA_MY_CNF': '/vagrant/src/github.com/youtube/vitess/config/mycnf/default-fast.cnf:/vagrant/src/github.com/youtube/vitess/config/mycnf/master_mysql56.cnf'}
-- 2017-09-13 03:01:09,651 utils:306 DEBUG run: ['/vagrant/bin/mysqlctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-tablet_uid', '62345', '-port', '17203', '-mysql_port', '17204', '-db-config-dba-uname', 'vt_dba', '-db-config-dba-charset', 'utf8', 'init', '-init_db_sql_file', '/vagrant/src/github.com/youtube/vitess/config/init_db.sql'] extra_env={'EXTRA_MY_CNF': '/vagrant/src/github.com/youtube/vitess/config/mycnf/default-fast.cnf:/vagrant/src/github.com/youtube/vitess/config/mycnf/master_mysql56.cnf'}
-- 2017-09-13 03:01:09,657 utils:306 DEBUG run: ['/vagrant/bin/vtctld', '-enable_queries', '-cell', 'test_nj', '-web_dir', '/vagrant/src/github.com/youtube/vitess/web/vtctld', '-web_dir2', '/vagrant/src/github.com/youtube/vitess/web/vtctld2/dist', '--log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '--port', '17209', '-tablet_manager_protocol', 'grpc', '-tablet_protocol', 'grpc', '-throttler_client_protocol', 'grpc', '-vtgate_protocol', 'grpc', '-workflow_manager_init', '-workflow_manager_use_election', '-schema_swap_delay_between_errors', '1s', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '--wait_for_drain_sleep_rdonly', '0s', '--wait_for_drain_sleep_replica', '0s', '-service_map', 'grpc-tabletmanager,grpc-throttler,grpc-queryservice,grpc-updatestream,grpc-vtctl,grpc-vtworker,grpc-vtgateservice', '-grpc_port', '17210'] stderr=<open file '/tmp/vtdata-dev/vt_710485808/tmp/vtctld.stderr', mode 'w' at 0x7f1f2488c660>, stdout=<open file '/tmp/vtdata-dev/vt_710485808/tmp/vtctld.stdout', mode 'w' at 0x7f1f24b20810>
-- 2017-09-13 03:01:09,662 utils:373 DEBUG Sleeping for 0.200000 seconds waiting for condition "waiting for vtctld to start"
-- 2017-09-13 03:01:09,863 utils:373 DEBUG Sleeping for 0.200000 seconds waiting for condition "waiting for vtctld to start"
-- 2017-09-13 03:01:14,466 utils:306 DEBUG run: ['/vagrant/bin/vttablet', '-tablet_hostname', 'localhost', '-tablet-path', 'test_nj-0000062344', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-binlog_player_protocol', 'grpc', '-tablet_manager_protocol', 'grpc', '-tablet_protocol', 'grpc', '-binlog_player_healthcheck_topology_refresh', '1s', '-binlog_player_healthcheck_retry_delay', '1s', '-binlog_player_retry_delay', '1s', '-pid_file', '/tmp/vtdata-dev/vt_710485808/vt_0000062344/vttablet.pid', '-health_check_interval', '2s', '-enable_replication_reporter', '-degraded_threshold', '5s', '-watch_replication_stream', '-enable_semi_sync', '-init_tablet_type', 'replica', '-init_keyspace', 'ks1', '-init_shard', '0', '-restore_from_backup', '-backup_storage_implementation', 'file', '-file_backup_storage_root', '/tmp/vtdata-dev/vt_710485808/tmp/backupstorage', '-port', '17200', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-db-config-dba-uname', 'vt_dba', '-db-config-dba-charset', 'utf8', '-db-config-allprivs-uname', 'vt_allprivs', '-db-config-allprivs-charset', 'utf8', '-db-config-app-uname', 'vt_app', '-db-config-app-charset', 'utf8', '-db-config-app-dbname', 'vt_ks1', '-db-config-repl-uname', 'vt_repl', '-db-config-repl-charset', 'utf8', '-db-config-repl-dbname', 'vt_ks1', '-db-config-filtered-uname', 'vt_filtered', '-db-config-filtered-charset', 'utf8', '-service_map', 'grpc-tabletmanager,grpc-throttler,grpc-queryservice,grpc-updatestream,grpc-vtctl,grpc-vtworker,grpc-vtgateservice', '-grpc_port', '17202', '-grpc_max_message_size', '5242880', '-serving_state_grace_period', '1s', '-enable-autocommit'] extra_env={'EXTRA_MY_CNF': '/vagrant/src/github.com/youtube/vitess/config/mycnf/default-fast.cnf:/vagrant/src/github.com/youtube/vitess/config/mycnf/master_mysql56.cnf'}, stderr=<open file '/tmp/vtdata-dev/vt_710485808/tmp/vttablet-62344.stderr', mode 'w' at 0x7f1f2488cdb0>
-- 2017-09-13 03:01:14,470 tablet:625 DEBUG Started vttablet: 62344 (test_nj-0000062344) with pid: 29204 - Log files: /tmp/vtdata-dev/vt_710485808/tmp/vttablet.*.{INFO,WARNING,ERROR,FATAL}.*.29204
-- 2017-09-13 03:01:14,470 utils:306 DEBUG run: ['/vagrant/bin/vttablet', '-tablet_hostname', 'localhost', '-tablet-path', 'test_nj-0000062345', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-binlog_player_protocol', 'grpc', '-tablet_manager_protocol', 'grpc', '-tablet_protocol', 'grpc', '-binlog_player_healthcheck_topology_refresh', '1s', '-binlog_player_healthcheck_retry_delay', '1s', '-binlog_player_retry_delay', '1s', '-pid_file', '/tmp/vtdata-dev/vt_710485808/vt_0000062345/vttablet.pid', '-health_check_interval', '2s', '-enable_replication_reporter', '-degraded_threshold', '5s', '-watch_replication_stream', '-enable_semi_sync', '-init_tablet_type', 'replica', '-init_keyspace', 'ks1', '-init_shard', '0', '-restore_from_backup', '-backup_storage_implementation', 'file', '-file_backup_storage_root', '/tmp/vtdata-dev/vt_710485808/tmp/backupstorage', '-port', '17203', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-db-config-dba-uname', 'vt_dba', '-db-config-dba-charset', 'utf8', '-db-config-allprivs-uname', 'vt_allprivs', '-db-config-allprivs-charset', 'utf8', '-db-config-app-uname', 'vt_app', '-db-config-app-charset', 'utf8', '-db-config-app-dbname', 'vt_ks1', '-db-config-repl-uname', 'vt_repl', '-db-config-repl-charset', 'utf8', '-db-config-repl-dbname', 'vt_ks1', '-db-config-filtered-uname', 'vt_filtered', '-db-config-filtered-charset', 'utf8', '-service_map', 'grpc-tabletmanager,grpc-throttler,grpc-queryservice,grpc-updatestream,grpc-vtctl,grpc-vtworker,grpc-vtgateservice', '-grpc_port', '17205', '-grpc_max_message_size', '5242880', '-serving_state_grace_period', '1s', '-enable-autocommit'] extra_env={'EXTRA_MY_CNF': '/vagrant/src/github.com/youtube/vitess/config/mycnf/default-fast.cnf:/vagrant/src/github.com/youtube/vitess/config/mycnf/master_mysql56.cnf'}, stderr=<open file '/tmp/vtdata-dev/vt_710485808/tmp/vttablet-62345.stderr', mode 'w' at 0x7f1f2488cdb0>
-- 2017-09-13 03:01:14,473 tablet:625 DEBUG Started vttablet: 62345 (test_nj-0000062345) with pid: 29205 - Log files: /tmp/vtdata-dev/vt_710485808/tmp/vttablet.*.{INFO,WARNING,ERROR,FATAL}.*.29205
-- 2017-09-13 03:01:14,474 tablet:649 DEBUG vttablet test_nj-0000062344 not answering at /debug/vars, waiting...
-- 2017-09-13 03:01:14,474 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for test_nj-0000062344 state NOT_SERVING (last seen state: ?)"
-- 2017-09-13 03:01:14,575 tablet:649 DEBUG vttablet test_nj-0000062344 not answering at /debug/vars, waiting...
-- 2017-09-13 03:01:14,575 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for test_nj-0000062344 state NOT_SERVING (last seen state: ?)"
-- 2017-09-13 03:01:14,676 tablet:649 DEBUG vttablet test_nj-0000062344 not answering at /debug/vars, waiting...
-- 2017-09-13 03:01:14,676 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for test_nj-0000062344 state NOT_SERVING (last seen state: ?)"
-- 2017-09-13 03:01:14,828 vtctl_client:145 WARNING master-elect tablet test_nj-0000062344 is not the shard master, proceeding anyway as -force was used
-- 2017-09-13 03:01:14,829 vtctl_client:145 WARNING master-elect tablet test_nj-0000062344 is not a master in the shard, proceeding anyway as -force was used
-- 2017-09-13 03:01:14,829 vtctl_client:141 DEBUG resetting replication on tablet test_nj-0000062344
-- 2017-09-13 03:01:14,830 vtctl_client:141 DEBUG resetting replication on tablet test_nj-0000062345
-- 2017-09-13 03:01:15,832 vtctl_client:141 DEBUG initializing master on test_nj-0000062344
-- 2017-09-13 03:01:16,853 vtctl_client:141 DEBUG initializing slave test_nj-0000062345
-- 2017-09-13 03:01:16,854 vtctl_client:141 DEBUG populating reparent journal on new master test_nj-0000062344
-- 2017-09-13 03:01:17,077 utils:306 DEBUG run: ['/vagrant/bin/vtgate', '-port', '17211', '-cell', 'test_nj', '-retry-count', '2', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-srv_topo_cache_ttl', '1s', '-tablet_protocol', 'grpc', '-stderrthreshold', '0', '-normalize_queries', '-healthcheck_conn_timeout', '2s', '-gateway_implementation', 'discoverygateway', '-cells_to_watch', 'test_nj', '-tablet_types_to_wait', 'MASTER,REPLICA', '-grpc_port', '17212', '-grpc_max_message_size', '5242880', '-service_map', 'grpc-tabletmanager,grpc-throttler,grpc-queryservice,grpc-updatestream,grpc-vtctl,grpc-vtworker,grpc-vtgateservice', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-enable_buffer', '-buffer_window', '10m', '-buffer_max_failover_duration', '10m', '-buffer_min_time_between_failovers', '20m']
-- 2017-09-13 03:01:17,080 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
I0913 03:01:17.162226 29272 buffer.go:119] vtgate buffer enabled. MASTER requests will be buffered during detected failovers.
I0913 03:01:17.163258 29272 discoverygateway.go:103] loading tablets for cells: test_nj
I0913 03:01:17.163557 29272 gateway.go:84] Gateway waiting for serving tablets...
I0913 03:01:17.166887 29272 logutil.go:31] log: Connected to 127.0.0.1:17208
I0913 03:01:17.171912 29272 logutil.go:31] log: Authenticated: id=98649484031623182, timeout=30000
I0913 03:01:17.172143 29272 conn.go:323] zk conn: session for addr localhost:17208 event: {EventSession StateHasSession <nil> 127.0.0.1:17208}
I0913 03:01:17.175549 29272 logutil.go:31] log: Connected to 127.0.0.1:17208
I0913 03:01:17.176722 29272 logutil.go:31] log: Authenticated: id=98649484031623183, timeout=30000
I0913 03:01:17.176774 29272 conn.go:323] zk conn: session for addr localhost:17208 event: {EventSession StateHasSession <nil> 127.0.0.1:17208}
-- 2017-09-13 03:01:17,181 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:17,282 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:17,383 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:17,485 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:17,586 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:17,687 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:17,788 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
I0913 03:01:17.887347 29272 gateway.go:91] Waiting for tablets completed
I0913 03:01:17.887369 29272 vtgate.go:66] Transaction mode: 'MULTI'
-- 2017-09-13 03:01:17,889 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17211/debug/vars of vtgate (no vars yet)"
I0913 03:01:17.891452 29272 grpc_server.go:114] Setting grpc max message size to 5242880
I0913 03:01:17.894786 29272 service_map.go:65] Registering vtgateservice for grpc, disable it with -grpc-vtgateservice service_map parameter
I0913 03:01:17.895062 29272 grpc_server.go:139] Listening for gRPC calls on port 17212
I0913 03:01:17.895286 29272 unix_socket.go:36] Not listening on socket file
-- 2017-09-13 03:01:18,018 utils:79 INFO ===== test_buffer_external_reparent (__main__.TestBuffer)
-- 2017-09-13 03:01:18,019 utils:79 INFO ===== test_buffer_external_reparent (__main__.TestBuffer) ...
I0913 03:01:18.019675 29272 run.go:53] Entering lameduck mode for at least 50ms
I0913 03:01:18.019704 29272 run.go:54] Firing asynchronous OnTerm hooks
I0913 03:01:18.019710 29272 servenv.go:151] Firing synchronous OnTermSync hooks and waiting up to 10s for them
I0913 03:01:18.019774 29272 grpc_server.go:149] Initiated graceful stop of gRPC server
I0913 03:01:18.019880 29272 grpc_server.go:151] gRPC server stopped
I0913 03:01:18.019892 29272 servenv.go:164] OnTermSync hooks finished
I0913 03:01:18.019897 29272 run.go:59] Sleeping an extra 49.770435ms after OnTermSync to finish lameduck period
I0913 03:01:18.072113 29272 run.go:63] Shutting down gracefully
I0913 03:01:18.073928 29272 logutil.go:31] log: Recv loop terminated: err=EOF
I0913 03:01:18.073942 29272 logutil.go:31] log: Send loop terminated: err=<nil>
W0913 03:01:18.073992 29272 executor.go:671] Error while watching vschema for cell test_nj (will wait 5s before retrying): received a non-OK event for /test_nj/SrvVSchema: zk: zookeeper is closing
E0913 03:01:18.074169 29272 resilient_srv_topo_server.go:296] watch for SrvKeyspace ks1 in cell test_nj failed: received a non-OK event for /test_nj/keyspaces/ks1/SrvKeyspace: zk: zookeeper is closing
I0913 03:01:18.074034 29272 conn.go:320] zk conn: session for addr localhost:17208 ended: {EventSession StateDisconnected <nil> 127.0.0.1:17208}
I0913 03:01:18.075776 29272 logutil.go:31] log: Recv loop terminated: err=EOF
-- 2017-09-13 03:01:18,076 utils:306 DEBUG run: ['/vagrant/bin/vtgate', '-port', '17213', '-cell', 'test_nj', '-retry-count', '2', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-srv_topo_cache_ttl', '1s', '-tablet_protocol', 'grpc', '-stderrthreshold', '0', '-normalize_queries', '-healthcheck_conn_timeout', '2s', '-gateway_implementation', 'discoverygateway', '-cells_to_watch', 'test_nj', '-tablet_types_to_wait', 'MASTER,REPLICA', '-grpc_port', '17214', '-grpc_max_message_size', '5242880', '-service_map', 'grpc-tabletmanager,grpc-throttler,grpc-queryservice,grpc-updatestream,grpc-vtctl,grpc-vtworker,grpc-vtgateservice', '-topo_implementation', 'zk2', '-topo_global_server_address', 'localhost:17208', '-topo_global_root', '/global', '-enable_buffer', '-buffer_window', '10m', '-buffer_max_failover_duration', '10m', '-buffer_min_time_between_failovers', '20m']
-- 2017-09-13 03:01:18,080 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17213/debug/vars of vtgate (no vars yet)"
-- 2017-09-13 03:01:18,181 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17213/debug/vars of vtgate (no vars yet)"
I0913 03:01:18.193156 29286 buffer.go:119] vtgate buffer enabled. MASTER requests will be buffered during detected failovers.
I0913 03:01:18.194399 29286 discoverygateway.go:103] loading tablets for cells: test_nj
I0913 03:01:18.194762 29286 gateway.go:84] Gateway waiting for serving tablets...
I0913 03:01:18.198529 29286 logutil.go:31] log: Connected to 127.0.0.1:17208
I0913 03:01:18.200125 29286 logutil.go:31] log: Authenticated: id=98649484031623184, timeout=30000
I0913 03:01:18.200260 29286 conn.go:323] zk conn: session for addr localhost:17208 event: {EventSession StateHasSession <nil> 127.0.0.1:17208}
I0913 03:01:18.203768 29286 logutil.go:31] log: Connected to 127.0.0.1:17208
I0913 03:01:18.206094 29286 logutil.go:31] log: Authenticated: id=98649484031623185, timeout=30000
I0913 03:01:18.206167 29286 conn.go:323] zk conn: session for addr localhost:17208 event: {EventSession StateHasSession <nil> 127.0.0.1:17208}
-- 2017-09-13 03:01:18,281 utils:373 DEBUG Sleeping for 0.100000 seconds waiting for condition "waiting for http://localhost:17213/debug/vars of vtgate (no vars yet)"
I0913 03:01:18.310766 29286 gateway.go:91] Waiting for tablets completed
I0913 03:01:18.310819 29286 vtgate.go:66] Transaction mode: 'MULTI'
I0913 03:01:18.313597 29286 grpc_server.go:114] Setting grpc max message size to 5242880
I0913 03:01:18.314379 29286 service_map.go:65] Registering vtgateservice for grpc, disable it with -grpc-vtgateservice service_map parameter
I0913 03:01:18.316982 29286 grpc_server.go:139] Listening for gRPC calls on port 17214
I0913 03:01:18.317198 29286 unix_socket.go:36] Not listening on socket file
-- 2017-09-13 03:01:18,402 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,415 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,446 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,461 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,474 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,488 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,505 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,519 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,534 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,547 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,561 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,574 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,589 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,602 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,612 vtgate_buffer:160 DEBUG UPDATE 1 affected 1 row(s).
-- 2017-09-13 03:01:18,616 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,629 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,646 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,660 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,677 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,693 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,708 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,724 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,741 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,760 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,776 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,792 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,808 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,824 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,839 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,855 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,870 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,890 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,907 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,922 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,939 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,955 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,969 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:18,985 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,000 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,017 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,032 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,049 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,064 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,081 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,093 vtgate_buffer:160 DEBUG UPDATE 2 affected 1 row(s).
-- 2017-09-13 03:01:19,094 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,094 tablet:294 DEBUG mysql(62344,): SET GLOBAL read_only = ON
-- 2017-09-13 03:01:19,095 tablet:294 DEBUG mysql(62344,): FLUSH TABLES WITH READ LOCK
-- 2017-09-13 03:01:19,095 tablet:294 DEBUG mysql(62344,): UNLOCK TABLES
-- 2017-09-13 03:01:19,096 tablet:316 DEBUG mysql(62344): setting semi-sync mode: master=False, slave=None
-- 2017-09-13 03:01:19,108 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,125 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,140 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,152 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,169 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,187 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,200 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,214 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,226 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,239 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,255 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,269 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,282 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,298 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,311 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,325 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,337 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,350 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,367 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,384 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,399 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,421 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,437 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,453 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,469 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,485 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,501 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,516 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,533 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,545 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,558 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,574 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,590 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,606 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,622 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,637 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,653 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,667 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,684 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,699 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,715 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,731 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,747 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,763 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,779 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,795 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,810 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,830 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,850 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,867 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,883 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,905 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,920 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,936 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,957 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,974 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:19,989 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,001 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,017 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,035 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,051 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,066 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,082 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,097 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,113 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,129 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,145 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,160 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,173 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,185 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,198 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,210 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,222 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,235 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,249 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,261 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,274 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,289 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,315 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,327 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,340 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,352 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,365 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,377 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,417 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,429 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,463 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,475 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,488 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,500 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,512 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,524 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,555 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,567 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,580 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,593 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,605 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,617 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,629 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,643 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,658 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,671 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,683 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,696 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,708 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,720 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,732 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,761 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,774 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,786 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,798 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,810 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,823 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,836 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,863 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,875 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,888 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,901 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,914 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,926 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,938 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,955 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,971 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,983 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:20,996 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,008 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,021 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,033 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,067 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,084 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,097 vtgate_buffer:129 DEBUG read returned 1 row(s).
I0913 03:01:21.099400 29286 vtgate.go:1042] ExecuteShards: target: ks1.0.master, used tablet: test_nj-62344 (localhost), vttablet: Write(c.buffer) failed: write unix @->/tmp/vtdata-dev/vt_710485808/vt_0000062344/mysql.sock: write: broken pipe (errno 2006) (sqlstate HY000) during query: update buffer set msg = 'update 3' where id in (2) /* _stream buffer (id ) (2 ); *//* vtgate:: filtered_replication_unfriendly */, CallerID: unsecure_grpc_client, request: map[Sql:UPDATE buffer SET msg='update 3' WHERE id = :id/* vtgate:: filtered_replication_unfriendly */ BindVariables:map[id:type:INT64 value:"2" ] Keyspace:ks1 Shards:[0] Session:in_transaction:true shard_sessions:<target:<keyspace:"ks1" shard:"0" tablet_type:MASTER > transaction_id:1505271674692309152 > NotInTransaction:false TabletType:master Options:<nil>]
-- 2017-09-13 03:01:21,100 vtdb_logger:54 INFO Additional exception data {'id': 2}
-- 2017-09-13 03:01:21,101 vtdb_logger:47 WARNING vtclient_exception for ks1.None.master: ('VitessError', u"vtgate: http://vitess:17213/: target: ks1.0.master, used tablet: test_nj-62344 (localhost), vttablet: Write(c.buffer) failed: write unix @->/tmp/vtdata-dev/vt_710485808/vt_0000062344/mysql.sock: write: broken pipe (errno 2006) (sqlstate HY000) during query: update buffer set msg = 'update 3' where id in (2) /* _stream buffer (id ) (2 ); *//* vtgate:: filtered_replication_unfriendly */, CallerID: unsecure_grpc_client", 'ExecuteShards', 14, 'ExecuteShards', "keyspace=ks1, not_in_transaction=False, shards=unknown, sql=UPDATE buffer SET msg='update 3' WHERE id = :id, tablet_type=master")
-- 2017-09-13 03:01:21,101 vtdb_logger:47 WARNING vtclient_exception for None.None.None: ('VitessError', u"vtgate: http://vitess:17213/: target: ks1.0.master, used tablet: test_nj-62344 (localhost), vttablet: Write(c.buffer) failed: write unix @->/tmp/vtdata-dev/vt_710485808/vt_0000062344/mysql.sock: write: broken pipe (errno 2006) (sqlstate HY000) during query: update buffer set msg = 'update 3' where id in (2) /* _stream buffer (id ) (2 ); *//* vtgate:: filtered_replication_unfriendly */, CallerID: unsecure_grpc_client", 'ExecuteShards', 14, 'ExecuteShards', "keyspace=ks1, not_in_transaction=False, shards=unknown, sql=UPDATE buffer SET msg='update 3' WHERE id = :id, tablet_type=master")
-- 2017-09-13 03:01:21,103 vtdb_logger:47 WARNING vtclient_exception for None.None.None: ('_Rendezvous', 'Rollback', <StatusCode.ABORTED: (10, 'aborted')>, 'vtgate: http://vitess:17213/: target: ks1.0.master, used tablet: test_nj-62344 (localhost), vttablet: rpc error: code = Aborted desc = transaction 1505271674692309152: not found, CallerID: unsecure_grpc_client')
-- 2017-09-13 03:01:21,103 vtgate_buffer:166 WARNING rollback failed: ('_Rendezvous', 'Rollback', <StatusCode.ABORTED: (10, 'aborted')>, 'vtgate: http://vitess:17213/: target: ks1.0.master, used tablet: test_nj-62344 (localhost), vttablet: rpc error: code = Aborted desc = transaction 1505271674692309152: not found, CallerID: unsecure_grpc_client')
-- 2017-09-13 03:01:21,103 vtgate_buffer:170 DEBUG UPDATE 3 failed before COMMIT. This should not happen. Re-raising exception.
-- 2017-09-13 03:01:21,104 vtgate_buffer:104 DEBUG thread: UpdateThread query failed: ('_Rendezvous', 'Rollback', <StatusCode.ABORTED: (10, 'aborted')>, 'vtgate: http://vitess:17213/: target: ks1.0.master, used tablet: test_nj-62344 (localhost), vttablet: rpc error: code = Aborted desc = transaction 1505271674692309152: not found, CallerID: unsecure_grpc_client')
-- 2017-09-13 03:01:21,109 vtgate_buffer:129 DEBUG read returned 1 row(s).
I0913 03:01:21.116464 29286 shard_buffer.go:281] Starting buffering for shard: ks1/0 (window: 10m0s, size: 10, max failover duration: 10m0s) (A failover was detected by this seen error: vttablet: The MySQL server is running with the --read-only option so it cannot execute this statement (errno 1290) (sqlstate HY000) during query: update buffer set msg = 'update 4' where id in (2) /* _stream buffer (id ) (2 ); *//* vtgate:: filtered_replication_unfriendly */, CallerID: unsecure_grpc_client.)
-- 2017-09-13 03:01:21,226 tablet:294 DEBUG mysql(62345,): STOP SLAVE
-- 2017-09-13 03:01:21,227 tablet:294 DEBUG mysql(62345,): RESET SLAVE ALL
-- 2017-09-13 03:01:21,229 tablet:294 DEBUG mysql(62345,): SET GLOBAL read_only = OFF
-- 2017-09-13 03:01:21,230 tablet:316 DEBUG mysql(62345): setting semi-sync mode: master=True, slave=None
-- 2017-09-13 03:01:21,231 vtgate_buffer:371 DEBUG New master position: MySQL56/cb6ad276-982f-11e7-a483-020a02a54f74:1-10
-- 2017-09-13 03:01:21,231 tablet:294 DEBUG mysql(62344,): RESET SLAVE
-- 2017-09-13 03:01:21,232 tablet:294 DEBUG mysql(62344,): RESET MASTER
-- 2017-09-13 03:01:21,234 tablet:294 DEBUG mysql(62344,): SET GLOBAL gtid_purged = 'cb6ad276-982f-11e7-a483-020a02a54f74:1-10'
-- 2017-09-13 03:01:21,234 tablet:294 DEBUG mysql(62344,): CHANGE MASTER TO MASTER_HOST='localhost', MASTER_PORT=17204, MASTER_USER='vt_repl', MASTER_AUTO_POSITION = 1
-- 2017-09-13 03:01:21,238 tablet:294 DEBUG mysql(62344,): START SLAVE
-- 2017-09-13 03:01:21,239 utils:917 DEBUG vtctl: TabletExternallyReparented test_nj-0000062345
I0913 03:01:21.272173 29286 healthcheck.go:482] HealthCheckUpdate(Type Change): test_nj-0000062345, tablet: test_nj-62345 (localhost), target ks1/0 (REPLICA) => ks1/0 (MASTER), reparent time: 1505271681
I0913 03:01:21.272391 29286 shard_buffer.go:545] Stopping buffering for shard: ks1/0 after: 0.2 seconds due to: failover end detected. Draining 2 buffered requests now.
I0913 03:01:21.288185 29286 shard_buffer.go:565] Draining finished for shard: ks1/0 Took: 15.712926ms for: 2 requests.
-- 2017-09-13 03:01:21,288 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,302 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,315 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,328 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,343 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,376 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,408 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,422 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,435 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,448 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,477 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,491 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,505 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,517 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,529 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,542 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,559 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,575 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,589 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,602 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,616 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,628 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,641 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,653 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,667 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,682 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,696 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,710 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,723 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,736 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,750 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,764 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,780 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,793 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,806 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,819 vtgate_buffer:129 DEBUG read returned 1 row(s).
W0913 03:01:21.830897 29286 tablet_stats_cache.go:204] not marking healthy master test_nj-0000062344 as Up for ks1/0 because its externally reparented timestamp is smaller than the highest known timestamp from previous MASTERs test_nj-0000062345: 1505271675 < 1505271681
-- 2017-09-13 03:01:21,832 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,845 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,858 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,887 vtgate_buffer:160 DEBUG UPDATE 4 affected 1 row(s).
-- 2017-09-13 03:01:21,888 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,902 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,917 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,934 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,947 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,960 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,975 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:21,991 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,007 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,022 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,038 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,053 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,069 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,082 vtgate_buffer:160 DEBUG UPDATE 5 affected 1 row(s).
-- 2017-09-13 03:01:22,082 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,101 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,115 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,131 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,145 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,162 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,177 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,190 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,203 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,216 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,234 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,236 vtgate_buffer:160 DEBUG UPDATE 6 affected 1 row(s).
-- 2017-09-13 03:01:22,250 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,263 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,278 vtgate_buffer:129 DEBUG read returned 1 row(s).
I0913 03:01:22.288762 29286 healthcheck.go:482] HealthCheckUpdate(Type Change): test_nj-0000062344, tablet: test_nj-62344 (localhost), target ks1/0 (MASTER) => ks1/0 (REPLICA), reparent time: 1505271675
-- 2017-09-13 03:01:22,291 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,303 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,316 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,329 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,342 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,359 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,376 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,393 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,412 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,428 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,446 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,461 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,475 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,491 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,506 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,522 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,537 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,552 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,568 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,589 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,604 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,621 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,627 vtgate_buffer:160 DEBUG UPDATE 7 affected 1 row(s).
-- 2017-09-13 03:01:22,638 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,651 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,664 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,677 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,686 vtgate_buffer:160 DEBUG UPDATE 8 affected 1 row(s).
-- 2017-09-13 03:01:22,693 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,705 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,720 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,733 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,745 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,759 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,773 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,790 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,806 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,822 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,837 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,852 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,868 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,884 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,900 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,917 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,930 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,946 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,962 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,978 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:22,993 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,008 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,024 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,040 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,056 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,072 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,087 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,103 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,119 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,135 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,149 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,166 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,182 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,183 vtgate_buffer:160 DEBUG UPDATE 9 affected 1 row(s).
-- 2017-09-13 03:01:23,196 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,211 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,227 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,244 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,260 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,275 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,293 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,308 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,324 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,340 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,355 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,371 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,387 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,403 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,424 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,444 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,460 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,476 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,497 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,512 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,527 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,548 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,564 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,579 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,595 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,611 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,627 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,643 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,659 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,667 vtgate_buffer:160 DEBUG UPDATE 10 affected 1 row(s).
-- 2017-09-13 03:01:23,674 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,687 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,699 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,713 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,726 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,747 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,763 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,778 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,799 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,820 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,837 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,852 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,869 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,885 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,900 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,913 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,927 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,942 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,959 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,975 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:23,991 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,005 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,021 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,037 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,054 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,075 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,092 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,106 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,122 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,137 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,153 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,168 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,184 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,199 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,219 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,235 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,252 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,268 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,282 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,297 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,314 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,334 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,335 vtgate_buffer:160 DEBUG UPDATE 11 affected 1 row(s).
-- 2017-09-13 03:01:24,351 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,366 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,381 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,395 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,412 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,428 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,444 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,460 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,476 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,493 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,509 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,526 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,541 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,557 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,569 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,587 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,602 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,618 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,633 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,649 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,666 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,680 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,696 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,711 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,723 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,737 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,753 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,769 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,785 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,802 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,817 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,833 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,848 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,863 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,879 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,895 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,912 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,928 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,943 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,960 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,975 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:24,991 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,006 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,022 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,038 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,054 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,069 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,086 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,101 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,118 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,133 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,148 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,152 vtgate_buffer:160 DEBUG UPDATE 12 affected 1 row(s).
-- 2017-09-13 03:01:25,161 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,177 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,190 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,204 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,221 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,237 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,253 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,269 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,285 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,300 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,316 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,332 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,347 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,362 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,377 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,394 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,410 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,427 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,448 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,463 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,484 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,500 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,521 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,540 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,557 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,571 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,588 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,604 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,619 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,634 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,650 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,666 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,680 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,696 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,712 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,728 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,744 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,760 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,776 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,793 vtgate_buffer:160 DEBUG UPDATE 13 affected 1 row(s).
-- 2017-09-13 03:01:25,794 vtgate_buffer:129 DEBUG read returned 1 row(s).
-- 2017-09-13 03:01:25,813 utils:79 INFO ===== test_buffer_external_reparent (__main__.TestBuffer) ... FAIL
-- 2017-09-13 03:01:25,813 utils:306 DEBUG run: ['/vagrant/bin/mysqlctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-tablet_uid', '62345', '-port', '17203', '-mysql_port', '17204', '-db-config-dba-uname', 'vt_dba', '-db-config-dba-charset', 'utf8', 'shutdown'] extra_env={'EXTRA_MY_CNF': '/vagrant/src/github.com/youtube/vitess/config/mycnf/default-fast.cnf:/vagrant/src/github.com/youtube/vitess/config/mycnf/master_mysql56.cnf'}
-- 2017-09-13 03:01:25,816 utils:306 DEBUG run: ['/vagrant/bin/mysqlctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-tablet_uid', '62344', '-port', '17200', '-mysql_port', '17201', '-db-config-dba-uname', 'vt_dba', '-db-config-dba-charset', 'utf8', 'shutdown'] extra_env={'EXTRA_MY_CNF': '/vagrant/src/github.com/youtube/vitess/config/mycnf/default-fast.cnf:/vagrant/src/github.com/youtube/vitess/config/mycnf/master_mysql56.cnf'}
-- 2017-09-13 03:01:38,023 environment:136 DEBUG run: ['/vagrant/bin/zkctl', '-log_dir', '/tmp/vtdata-dev/vt_710485808/tmp', '-zk.cfg', '1@vitess:17206:17207:17208', 'shutdown']
I0913 03:01:38.153148 29286 logutil.go:31] log: Recv loop terminated: err=EOF
I0913 03:01:38.153172 29286 logutil.go:31] log: Send loop terminated: err=<nil>
I0913 03:01:38.153217 29286 conn.go:320] zk conn: session for addr localhost:17208 ended: {EventSession StateDisconnected <nil> 127.0.0.1:17208}
I0913 03:01:38.153241 29286 logutil.go:31] log: Recv loop terminated: err=EOF
I0913 03:01:38.153246 29286 logutil.go:31] log: Send loop terminated: err=<nil>
I0913 03:01:38.153266 29286 conn.go:320] zk conn: session for addr localhost:17208 ended: {EventSession StateDisconnected <nil> 127.0.0.1:17208}
-- 2017-09-13 03:01:39,154 utils:79 INFO ===== ======================================================================
-- 2017-09-13 03:01:39,154 utils:79 INFO ===== FAIL: test_buffer_external_reparent (__main__.TestBuffer)
-- 2017-09-13 03:01:39,154 utils:79 INFO ===== ----------------------------------------------------------------------
-- 2017-09-13 03:01:39,154 utils:79 INFO ===== Traceback (most recent call last):
File "test/vtgate_buffer.py", line 401, in test_buffer_external_reparent
self._test_buffer(self.external_reparent)
File "test/vtgate_buffer.py", line 314, in _test_buffer
self.assertEqual(0, update_thread.errors)
AssertionError: 0 != 1
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment