Created
June 7, 2019 21:45
-
-
Save zmoazeni/e40ba08113bc5f8e3843443d51e03b66 to your computer and use it in GitHub Desktop.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
% ./force-failure | |
Building linux binary in build/bin | |
Building darwin binary in build/bin | |
# command-line-arguments | |
clang: warning: argument unused during compilation: '-nopie' | |
Binaries found in: | |
build/dist/gh-ost-binary-linux-20190607173922.tar.gz | |
build/dist/gh-ost-binary-osx-20190607173922.tar.gz | |
### Building docker image for 5.7.21 | |
Sending build context to Docker daemon 4.608kB | |
Step 1/9 : FROM buildpack-deps:stretch | |
---> ed706ee09078 | |
Step 2/9 : RUN apt update && apt install -y libaio1 libnuma1 | |
---> Using cache | |
---> 80a04e09aa6d | |
Step 3/9 : ENV DBDEPLOYER_VERSION=1.30.1 DB_DEPLOYER_SHA256=b54eb047fdea2d3bece820c8c309f6610cfcea858a268b6c51be7ee53c9812bc | |
---> Using cache | |
---> d5278bc62c1f | |
Step 4/9 : RUN origin=https://github.com/datacharmer/dbdeployer/releases/download/v$DBDEPLOYER_VERSION && tarball=dbdeployer-$DBDEPLOYER_VERSION.linux.tar.gz && mkdir /dbdeployer && cd /dbdeployer && wget --progress=bar:force:noscroll $origin/$tarball && sha256sum $tarball | grep $DBDEPLOYER_VERSION && tar -xzf $tarball && chmod +x dbdeployer-$DBDEPLOYER_VERSION.linux && mv dbdeployer-$DBDEPLOYER_VERSION.linux /usr/local/bin/dbdeployer && cd / && rm -rf /dbdeployer | |
---> Using cache | |
---> 8b4f9f9dcc8a | |
Step 5/9 : ARG MYSQL_VERSION | |
---> Using cache | |
---> 94e2e90b36a9 | |
Step 6/9 : ARG DBDEPLOYER_ARGS | |
---> Using cache | |
---> cc2a2393eae4 | |
Step 7/9 : RUN wget --progress=bar:force:noscroll https://github.com/github/gh-ost-ci-env/raw/master/mysql-tarballs/${MYSQL_VERSION}.tar.gz && mkdir -p /sandbox/binary && mkdir /sandboxes && dbdeployer unpack ${MYSQL_VERSION}.tar.gz --unpack-version=${MYSQL_VERSION} --flavor mysql --sandbox-binary /sandbox/binary/ && dbdeployer deploy replication ${MYSQL_VERSION} --nodes 2 --sandbox-binary /sandbox/binary --sandbox-home /sandboxes/ --sandbox-directory rsandbox --my-cnf-options bind_address=0.0.0.0 --my-cnf-options log_slave_updates --my-cnf-options log_bin --my-cnf-options binlog_format=ROW --my-cnf-options event_scheduler=ON ${DBDEPLOYER_ARGS} && /sandboxes/rsandbox/test_replication && /sandboxes/rsandbox/m -uroot -e "grant all on *.* to 'gh-ost'@'%' identified by 'gh-ost'; flush privileges" | |
---> Using cache | |
---> 74c02da48c5b | |
Step 8/9 : COPY start.sh /usr/local/bin/start.sh | |
---> Using cache | |
---> 47477b443f05 | |
Step 9/9 : CMD ["/usr/local/bin/start.sh"] | |
---> Using cache | |
---> 8e63791a726a | |
Successfully built 8e63791a726a | |
Successfully tagged gh-ost/dbdeployer:5.7.21 | |
### Running gh-ost tests for 5.7.21 | |
Testing: rename-none-comment.......... | |
+ pass | |
----- attempt: 1---- | |
### Building docker image for 5.7.21 | |
Sending build context to Docker daemon 4.608kB | |
Step 1/9 : FROM buildpack-deps:stretch | |
---> ed706ee09078 | |
Step 2/9 : RUN apt update && apt install -y libaio1 libnuma1 | |
---> Using cache | |
---> 80a04e09aa6d | |
Step 3/9 : ENV DBDEPLOYER_VERSION=1.30.1 DB_DEPLOYER_SHA256=b54eb047fdea2d3bece820c8c309f6610cfcea858a268b6c51be7ee53c9812bc | |
---> Using cache | |
---> d5278bc62c1f | |
Step 4/9 : RUN origin=https://github.com/datacharmer/dbdeployer/releases/download/v$DBDEPLOYER_VERSION && tarball=dbdeployer-$DBDEPLOYER_VERSION.linux.tar.gz && mkdir /dbdeployer && cd /dbdeployer && wget --progress=bar:force:noscroll $origin/$tarball && sha256sum $tarball | grep $DBDEPLOYER_VERSION && tar -xzf $tarball && chmod +x dbdeployer-$DBDEPLOYER_VERSION.linux && mv dbdeployer-$DBDEPLOYER_VERSION.linux /usr/local/bin/dbdeployer && cd / && rm -rf /dbdeployer | |
---> Using cache | |
---> 8b4f9f9dcc8a | |
Step 5/9 : ARG MYSQL_VERSION | |
---> Using cache | |
---> 94e2e90b36a9 | |
Step 6/9 : ARG DBDEPLOYER_ARGS | |
---> Using cache | |
---> cc2a2393eae4 | |
Step 7/9 : RUN wget --progress=bar:force:noscroll https://github.com/github/gh-ost-ci-env/raw/master/mysql-tarballs/${MYSQL_VERSION}.tar.gz && mkdir -p /sandbox/binary && mkdir /sandboxes && dbdeployer unpack ${MYSQL_VERSION}.tar.gz --unpack-version=${MYSQL_VERSION} --flavor mysql --sandbox-binary /sandbox/binary/ && dbdeployer deploy replication ${MYSQL_VERSION} --nodes 2 --sandbox-binary /sandbox/binary --sandbox-home /sandboxes/ --sandbox-directory rsandbox --my-cnf-options bind_address=0.0.0.0 --my-cnf-options log_slave_updates --my-cnf-options log_bin --my-cnf-options binlog_format=ROW --my-cnf-options event_scheduler=ON ${DBDEPLOYER_ARGS} && /sandboxes/rsandbox/test_replication && /sandboxes/rsandbox/m -uroot -e "grant all on *.* to 'gh-ost'@'%' identified by 'gh-ost'; flush privileges" | |
---> Using cache | |
---> 74c02da48c5b | |
Step 8/9 : COPY start.sh /usr/local/bin/start.sh | |
---> Using cache | |
---> 47477b443f05 | |
Step 9/9 : CMD ["/usr/local/bin/start.sh"] | |
---> Using cache | |
---> 8e63791a726a | |
Successfully built 8e63791a726a | |
Successfully tagged gh-ost/dbdeployer:5.7.21 | |
### Running gh-ost tests for 5.7.21 | |
Testing: rename-none-comment.......... | |
+ pass | |
----- attempt: 2---- | |
### Building docker image for 5.7.21 | |
Sending build context to Docker daemon 4.608kB | |
Step 1/9 : FROM buildpack-deps:stretch | |
---> ed706ee09078 | |
Step 2/9 : RUN apt update && apt install -y libaio1 libnuma1 | |
---> Using cache | |
---> 80a04e09aa6d | |
Step 3/9 : ENV DBDEPLOYER_VERSION=1.30.1 DB_DEPLOYER_SHA256=b54eb047fdea2d3bece820c8c309f6610cfcea858a268b6c51be7ee53c9812bc | |
---> Using cache | |
---> d5278bc62c1f | |
Step 4/9 : RUN origin=https://github.com/datacharmer/dbdeployer/releases/download/v$DBDEPLOYER_VERSION && tarball=dbdeployer-$DBDEPLOYER_VERSION.linux.tar.gz && mkdir /dbdeployer && cd /dbdeployer && wget --progress=bar:force:noscroll $origin/$tarball && sha256sum $tarball | grep $DBDEPLOYER_VERSION && tar -xzf $tarball && chmod +x dbdeployer-$DBDEPLOYER_VERSION.linux && mv dbdeployer-$DBDEPLOYER_VERSION.linux /usr/local/bin/dbdeployer && cd / && rm -rf /dbdeployer | |
---> Using cache | |
---> 8b4f9f9dcc8a | |
Step 5/9 : ARG MYSQL_VERSION | |
---> Using cache | |
---> 94e2e90b36a9 | |
Step 6/9 : ARG DBDEPLOYER_ARGS | |
---> Using cache | |
---> cc2a2393eae4 | |
Step 7/9 : RUN wget --progress=bar:force:noscroll https://github.com/github/gh-ost-ci-env/raw/master/mysql-tarballs/${MYSQL_VERSION}.tar.gz && mkdir -p /sandbox/binary && mkdir /sandboxes && dbdeployer unpack ${MYSQL_VERSION}.tar.gz --unpack-version=${MYSQL_VERSION} --flavor mysql --sandbox-binary /sandbox/binary/ && dbdeployer deploy replication ${MYSQL_VERSION} --nodes 2 --sandbox-binary /sandbox/binary --sandbox-home /sandboxes/ --sandbox-directory rsandbox --my-cnf-options bind_address=0.0.0.0 --my-cnf-options log_slave_updates --my-cnf-options log_bin --my-cnf-options binlog_format=ROW --my-cnf-options event_scheduler=ON ${DBDEPLOYER_ARGS} && /sandboxes/rsandbox/test_replication && /sandboxes/rsandbox/m -uroot -e "grant all on *.* to 'gh-ost'@'%' identified by 'gh-ost'; flush privileges" | |
---> Using cache | |
---> 74c02da48c5b | |
Step 8/9 : COPY start.sh /usr/local/bin/start.sh | |
---> Using cache | |
---> 47477b443f05 | |
Step 9/9 : CMD ["/usr/local/bin/start.sh"] | |
---> Using cache | |
---> 8e63791a726a | |
Successfully built 8e63791a726a | |
Successfully tagged gh-ost/dbdeployer:5.7.21 | |
### Running gh-ost tests for 5.7.21 | |
Testing: rename-none-comment......... | |
ERROR rename-none-comment execution failure. cat /tmp/gh-ost-test-5.7.21.log: | |
2019-06-07 17:40:18 INFO starting gh-ost 1.0.48 | |
2019-06-07 17:40:18 INFO Migrating `test`.`gh_ost_test` | |
2019-06-07 17:40:18 INFO connection validated on 127.0.0.1:5722 | |
2019-06-07 17:40:18 INFO User has ALL privileges | |
2019-06-07 17:40:18 INFO binary logs validated on 127.0.0.1:5722 | |
2019-06-07 17:40:18 INFO Inspector initiated on d5384f4d58ab:5722, version 5.7.21-log | |
2019-06-07 17:40:18 INFO Table found. Engine=InnoDB | |
2019-06-07 17:40:18 DEBUG Estimated number of rows via STATUS: 0 | |
2019-06-07 17:40:18 DEBUG Validated no foreign keys exist on table | |
2019-06-07 17:40:18 DEBUG Validated no triggers exist on table | |
2019-06-07 17:40:18 INFO Estimated number of rows via EXPLAIN: 1 | |
2019-06-07 17:40:18 DEBUG Potential unique keys in gh_ost_test: [PRIMARY (auto_increment): [id]; has nullable: false] | |
2019-06-07 17:40:18 INFO Master forced to be 127.0.0.1:5721 | |
2019-06-07 17:40:18 INFO --test-on-replica or --migrate-on-replica given. Will not execute on master 127.0.0.1:5721 but rather on replica d5384f4d58ab:5722 itself | |
2019-06-07 17:40:18 INFO log_slave_updates validated on 127.0.0.1:5722 | |
2019-06-07 17:40:18 INFO connection validated on 127.0.0.1:5722 | |
2019-06-07 17:40:18 DEBUG Streamer binlog coordinates: mysql-bin.000002:817 | |
2019-06-07 17:40:18 INFO Connecting binlog streamer at mysql-bin.000002:817 | |
[2019/06/07 17:40:18] [info] binlogsyncer.go:133 create BinlogSyncer with config {99999 mysql 127.0.0.1 5722 gh-ost false false <nil> false UTC true 0 0s 0s 0 false} | |
[2019/06/07 17:40:18] [info] binlogsyncer.go:354 begin to sync binlog from position (mysql-bin.000002, 817) | |
[2019/06/07 17:40:18] [info] binlogsyncer.go:203 register slave for master server 127.0.0.1:5722 | |
2019-06-07 17:40:18 DEBUG Beginning streaming | |
[2019/06/07 17:40:18] [info] binlogsyncer.go:723 rotate to (mysql-bin.000002, 817) | |
2019-06-07 17:40:18 INFO rotate to next log from mysql-bin.000002:0 to mysql-bin.000002 | |
2019-06-07 17:40:18 INFO connection validated on 127.0.0.1:5722 | |
2019-06-07 17:40:18 INFO connection validated on 127.0.0.1:5722 | |
2019-06-07 17:40:18 INFO will use time_zone='SYSTEM' on applier | |
2019-06-07 17:40:18 INFO Examining table structure on applier | |
2019-06-07 17:40:18 INFO Applier initiated on d5384f4d58ab:5722, version 5.7.21-log | |
2019-06-07 17:40:18 INFO Dropping table `test`.`_gh_ost_test_gho` | |
2019-06-07 17:40:18 INFO Table dropped | |
2019-06-07 17:40:18 INFO Dropping table `test`.`_gh_ost_test_del` | |
2019-06-07 17:40:18 INFO Table dropped | |
2019-06-07 17:40:18 INFO Dropping table `test`.`_gh_ost_test_ghc` | |
2019-06-07 17:40:18 INFO Table dropped | |
2019-06-07 17:40:18 INFO Creating changelog table `test`.`_gh_ost_test_ghc` | |
2019-06-07 17:40:18 INFO Changelog table created | |
2019-06-07 17:40:18 INFO Creating ghost table `test`.`_gh_ost_test_gho` | |
2019-06-07 17:40:18 INFO Ghost table created | |
2019-06-07 17:40:18 INFO Altering ghost table `test`.`_gh_ost_test_gho` | |
2019-06-07 17:40:18 DEBUG ALTER statement: alter /* gh-ost */ table `test`.`_gh_ost_test_gho` add column exchange_rate double comment 'change rate used for pay in your own currency' | |
2019-06-07 17:40:18 INFO Ghost table altered | |
2019-06-07 17:40:18 INFO Intercepted changelog state GhostTableMigrated | |
2019-06-07 17:40:18 INFO Waiting for ghost table to be migrated. Current lag is 0s | |
2019-06-07 17:40:18 DEBUG ghost table migrated | |
2019-06-07 17:40:18 INFO Handled changelog state GhostTableMigrated | |
2019-06-07 17:40:18 DEBUG Potential unique keys in _gh_ost_test_gho: [PRIMARY (auto_increment): [id]; has nullable: false] | |
2019-06-07 17:40:18 INFO Chosen shared unique key is PRIMARY | |
2019-06-07 17:40:18 INFO Shared columns are id,c1 | |
2019-06-07 17:40:18 INFO Listening on unix socket file: /tmp/gh-ost.test.sock | |
2019-06-07 17:40:18 INFO As instructed, counting rows in the background; meanwhile I will use an estimated count, and will update it later on | |
2019-06-07 17:40:18 DEBUG Reading migration range according to key: PRIMARY | |
2019-06-07 17:40:18 INFO As instructed, I'm issuing a SELECT COUNT(*) on the table. This may take a while | |
2019-06-07 17:40:18 INFO Migration min values: [<nil>] | |
2019-06-07 17:40:18 DEBUG Reading migration range according to key: PRIMARY | |
2019-06-07 17:40:18 INFO Exact number of rows via COUNT: 0 | |
2019-06-07 17:40:18 INFO Migration max values: [<nil>] | |
2019-06-07 17:40:18 INFO Waiting for first throttle metrics to be collected | |
2019-06-07 17:40:18 INFO First throttle metrics collected | |
2019-06-07 17:40:18 DEBUG Operating until row copy is complete | |
# Migrating `test`.`gh_ost_test`; Ghost table is `test`.`_gh_ost_test_gho` | |
# Migrating d5384f4d58ab:5722; inspecting d5384f4d58ab:5722; executing on dagobah | |
# Migration started at Fri Jun 07 17:40:18 -0400 2019 | |
# chunk-size: 100; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000 | |
# throttle-flag-file: /tmp/gh-ost-test.ghost.throttle.flag | |
# throttle-additional-flag-file: /tmp/gh-ost.throttle | |
# throttle-query: select timestampdiff(second, min(last_update), now()) < 5 from _gh_ost_test_ghc | |
# throttle-control-replicas count: 1 | |
# Serving on unix socket: /tmp/gh-ost.test.sock | |
2019-06-07 17:40:18 DEBUG Getting nothing in the write queue. Sleeping... | |
2019-06-07 17:40:18 DEBUG No rows found in table. Rowcopy will be implicitly empty | |
2019-06-07 17:40:18 INFO Row copy complete | |
# Migrating `test`.`gh_ost_test`; Ghost table is `test`.`_gh_ost_test_gho` | |
# Migrating d5384f4d58ab:5722; inspecting d5384f4d58ab:5722; executing on dagobah | |
# Migration started at Fri Jun 07 17:40:18 -0400 2019 | |
# chunk-size: 100; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000 | |
# throttle-flag-file: /tmp/gh-ost-test.ghost.throttle.flag | |
# throttle-additional-flag-file: /tmp/gh-ost.throttle | |
# throttle-query: select timestampdiff(second, min(last_update), now()) < 5 from _gh_ost_test_ghc | |
# throttle-control-replicas count: 1 | |
# Serving on unix socket: /tmp/gh-ost.test.sock | |
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000002:3385; State: migrating; ETA: due | |
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 0s(total), 0s(copy); streamer: mysql-bin.000002:3385; State: migrating; ETA: due | |
2019-06-07 17:40:18 DEBUG checking for cut-over postpone | |
2019-06-07 17:40:18 DEBUG checking for cut-over postpone: complete | |
2019-06-07 17:40:18 DEBUG testing on replica. Stopping replication IO thread | |
2019-06-07 17:40:18 INFO Stopping replication IO thread | |
2019-06-07 17:40:18 INFO Replication IO thread stopped | |
2019-06-07 17:40:18 INFO Verifying SQL thread is stopped | |
2019-06-07 17:40:18 INFO SQL thread stopped | |
2019-06-07 17:40:18 INFO Replication IO thread at mysql-bin.000002:817. SQL thread is at mysql-bin.000002:817 | |
2019-06-07 17:40:18 INFO Grabbing voluntary lock: gh-ost.17.lock | |
2019-06-07 17:40:18 INFO Setting LOCK timeout as 6 seconds | |
2019-06-07 17:40:18 INFO Looking for magic cut-over table | |
2019-06-07 17:40:18 INFO Creating magic cut-over table `test`.`_gh_ost_test_del` | |
2019-06-07 17:40:18 INFO Magic cut-over table created | |
2019-06-07 17:40:18 INFO Locking `test`.`gh_ost_test`, `test`.`_gh_ost_test_del` | |
2019-06-07 17:40:18 INFO Tables locked | |
2019-06-07 17:40:18 INFO Session locking original & magic tables is 17 | |
2019-06-07 17:40:18 INFO Writing changelog state: AllEventsUpToLockProcessed:1559943618681871362 | |
2019-06-07 17:40:18 INFO Intercepted changelog state AllEventsUpToLockProcessed | |
2019-06-07 17:40:18 INFO Handled changelog state AllEventsUpToLockProcessed | |
2019-06-07 17:40:18 INFO Waiting for events up to lock | |
2019-06-07 17:40:18 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 28 [running]: | |
runtime/debug.Stack(0x5c, 0x100, 0xc000022550) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0002625b0, 0xc0002625b0, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:18 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 70 [running]: | |
runtime/debug.Stack(0x5c, 0x100, 0xc000240320) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc000208e70, 0xc000208e70, 0x7264e5) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:18 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 58 [running]: | |
runtime/debug.Stack(0x5c, 0x100, 0xc000240410) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc000209030, 0xc000209030, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 71 [running]: | |
runtime/debug.Stack(0x5c, 0xc0, 0xc00021a1e0) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0001a8dd0, 0xc0001a8dd0, 0x7264e5) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 59 [running]: | |
runtime/debug.Stack(0x5c, 0x100, 0xc000240500) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0002092b0, 0xc0002092b0, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 60 [running]: | |
runtime/debug.Stack(0x5c, 0x100, 0xc000022640) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc000262800, 0xc000262800, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 29 [running]: | |
runtime/debug.Stack(0x5c, 0x100, 0xc0002405f0) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0002093e0, 0xc0002093e0, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 39 [running]: | |
runtime/debug.Stack(0x5c, 0xc0, 0xc0002362d0) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0001fae60, 0xc0001fae60, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 72 [running]: | |
runtime/debug.Stack(0x5c, 0xc0, 0xc00021a2d0) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0001a9140, 0xc0001a9140, 0x7264e5) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
2019-06-07 17:40:19 DEBUG Getting nothing in the write queue. Sleeping... | |
2019-06-07 17:40:19 INFO Waiting for events up to lock: got AllEventsUpToLockProcessed:1559943618681871362 | |
2019-06-07 17:40:19 INFO Done waiting for events up to lock; duration=937.134972ms | |
# Migrating `test`.`gh_ost_test`; Ghost table is `test`.`_gh_ost_test_gho` | |
# Migrating d5384f4d58ab:5722; inspecting d5384f4d58ab:5722; executing on dagobah | |
# Migration started at Fri Jun 07 17:40:18 -0400 2019 | |
# chunk-size: 100; max-lag-millis: 1500ms; dml-batch-size: 10; max-load: ; critical-load: ; nice-ratio: 0.000000 | |
# throttle-flag-file: /tmp/gh-ost-test.ghost.throttle.flag | |
# throttle-additional-flag-file: /tmp/gh-ost.throttle | |
# throttle-query: select timestampdiff(second, min(last_update), now()) < 5 from _gh_ost_test_ghc | |
# throttle-control-replicas count: 1 | |
# Serving on unix socket: /tmp/gh-ost.test.sock | |
2019-06-07 17:40:19 ERROR replication not running; Slave_IO_Running=No, Slave_SQL_Running=No | |
goroutine 30 [running]: | |
runtime/debug.Stack(0x5c, 0xc0, 0xc00021a3c0) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x2, 0x87f040, 0xc0001a9320, 0xc0001a9320, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Errore(...) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:224 | |
github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag.func1(0x1, 0x0) | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:145 +0xbc | |
created by github.com/github/gh-ost/go/logic.(*Throttler).collectReplicationLag | |
/go/src/github.com/github/gh-ost/go/logic/throttler.go:167 +0xca | |
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 1s(total), 0s(copy); streamer: mysql-bin.000002:12525; State: migrating; ETA: due | |
2019-06-07 17:40:19 INFO Setting RENAME timeout as 3 seconds | |
2019-06-07 17:40:19 INFO Session renaming tables is 18 | |
2019-06-07 17:40:19 INFO Issuing and expecting this to block: rename /* gh-ost */ table `test`.`gh_ost_test` to `test`.`_gh_ost_test_del`, `test`.`_gh_ost_test_gho` to `test`.`gh_ost_test` | |
we had a problem finding the connection | |
map[connection_id:{16 true} id:{3 true} info:{ false} state:{Waiting on empty queue true}] | |
map[connection_id:{16 true} id:{16 true} info:{select | |
id, | |
connection_id() as connection_id, | |
state, | |
info | |
from information_schema.processlist true} state:{executing true}] | |
map[connection_id:{16 true} id:{17 true} info:{ false} state:{ true}] | |
map[connection_id:{16 true} id:{15 true} info:{ false} state:{ true}] | |
map[connection_id:{16 true} id:{13 true} info:{ false} state:{Master has sent all binlog to slave; waiting for more updates true}] | |
map[connection_id:{16 true} id:{14 true} info:{ false} state:{ true}] | |
map[connection_id:{16 true} id:{18 true} info:{ false} state:{ true}] | |
map[connection_id:{16 true} id:{19 true} info:{insert /* gh-ost */ into `test`.`_gh_ost_test_ghc` | |
(id, hint, value) | |
values | |
(NULLIF(0, 0), 'throttle at 1559943619623768733', 'throttle-query') | |
on duplicate key update | |
last_update=NOW(), | |
value=VALUES(value) true} state:{query end true}] | |
sessionId: 18 | |
stateHint: metadata lock | |
infoHint: rename | |
2019-06-07 17:40:19 INFO Looking for magic cut-over table | |
2019-06-07 17:40:19 INFO Will now proceed to drop magic table and unlock tables | |
2019-06-07 17:40:19 INFO Dropping magic cut-over table | |
2019-06-07 17:40:19 INFO Releasing lock from `test`.`gh_ost_test`, `test`.`_gh_ost_test_del` | |
2019-06-07 17:40:19 INFO Tables unlocked | |
Copy: 0/0 100.0%; Applied: 0; Backlog: 0/1000; Time: 1s(total), 0s(copy); streamer: mysql-bin.000002:13382; State: migrating; ETA: due | |
2019-06-07 17:40:19 INFO Tables renamed | |
2019-06-07 17:40:19 INFO Renaming back both tables | |
2019-06-07 17:40:19 DEBUG testing on replica. Starting replication IO thread after cut-over failure | |
2019-06-07 17:40:19 INFO Starting replication IO thread | |
2019-06-07 17:40:19 INFO Replication IO thread started | |
2019-06-07 17:40:19 INFO Verifying SQL thread is running | |
2019-06-07 17:40:19 INFO SQL thread started | |
2019-06-07 17:40:19 INFO Replication started | |
2019-06-07 17:40:19 INFO Removing socket file: /tmp/gh-ost.test.sock | |
2019-06-07 17:40:19 INFO Tearing down inspector | |
2019-06-07 17:40:19 FATAL Cannot find process. Hints: metadata lock, rename | |
goroutine 10 [running]: | |
runtime/debug.Stack(0x4b, 0x100, 0xc00001e9c0) | |
/usr/local/go/src/runtime/debug/stack.go:24 +0x9d | |
runtime/debug.PrintStack() | |
/usr/local/go/src/runtime/debug/stack.go:16 +0x22 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.logErrorEntry(0x0, 0x87f040, 0xc0003a8570, 0x1, 0x101) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:178 +0xe7 | |
github.com/github/gh-ost/vendor/github.com/outbrain/golib/log.Fatale(0x87f040, 0xc0003a8570, 0x0, 0x0) | |
/go/src/github.com/github/gh-ost/vendor/github.com/outbrain/golib/log/log.go:255 +0x3e | |
github.com/github/gh-ost/go/logic.(*Migrator).listenOnPanicAbort(0xc0000e2480) | |
/go/src/github.com/github/gh-ost/go/logic/migrator.go:252 +0x60 | |
created by github.com/github/gh-ost/go/logic.(*Migrator).Migrate | |
/go/src/github.com/github/gh-ost/go/logic/migrator.go:323 +0x21d | |
+ FAIL |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment