Skip to content

Instantly share code, notes, and snippets.

@makmanalp
Created March 11, 2019 19:27
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save makmanalp/ddffd79bdbd75fbff5126c69eb07c1bb to your computer and use it in GitHub Desktop.
Save makmanalp/ddffd79bdbd75fbff5126c69eb07c1bb to your computer and use it in GitHub Desktop.
ads-0-backup-1552296000-l2zs8 backu
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:22:01 tablet prod_iad-1360915300 still has decreasing replication lag of 208.710618394 seconds, will continue waiting
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:01 tablet prod_iad-1360915300 has caught up on replication
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:01 (prod_iad-1360915300) checking health
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:06 (prod_iad-1360915300) succeeded 1 of 3 healthchecks
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:11 (prod_iad-1360915300) succeeded 2 of 3 healthchecks
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:16 (prod_iad-1360915300) succeeded 3 of 3 healthchecks
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:16 getting replication status for replicas
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:16 getting replication status for master
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:16 comparing GTIDSets for errant GTID
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:19 replication is healthy
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:19 backing up tablet prod_iad-1360915300
ads-0-backup-1552296000-l2zs8 backup E0311 19:24:19.738127 73 syslogger.go:84] no connection, dropping syslog event: &events.TabletChange{Tablet:topodata.Tablet{Alias:(*topodata.TabletAlias)(0xc00136aac0), Hostname:"172.16.39.111", PortMap:map[string]int32{"mysql":3306, "vt":15101, "grpc":16101}, Keyspace:"Ads", Shard:"0", KeyRange:(*topodata.KeyRange)(nil), Type:6, DbNameOverride:"Ads", Tags:map[string]string(nil), MysqlHostname:"172.16.39.111", MysqlPort:3306, XXX_NoUnkeyedLiteral:struct {}{}, XXX_unrecognized:[]uint8(nil), XXX_sizecache:98}, Status:"updated"}
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.738193 73 state_change.go:130] Executing post-action state refresh: before backup
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741471 73 state_change.go:167] Running tablet callback because: before backup
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741504 73 state_change.go:281] Disabling query service on type change, reason: not a serving tablet type(BACKUP)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741524 73 tabletserver.go:312] TabletServer state: SERVING -> SHUTTING_DOWN (Shutting Down)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741562 73 binlog_streamer.go:299] stopping early due to binlog Streamer service shutdown or client disconnect
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741572 73 slave_connection.go:275] closing slave socket to unblock reads
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741615 73 slave_connection.go:149] connection closed during binlog stream (possibly intentional): io.ReadFull(header size) failed: read unix @->/vt/tablet/mysql.sock: use of closed network connection (errno 2013) (sqlstate HY000)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741638 73 slave_connection.go:283] waiting for slave dump thread to end
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741648 73 slave_connection.go:289] closing slave MySQL client, recycling slaveID 1
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741682 73 binlog_streamer.go:181] stream ended @ 01fa297c-2c27-11e6-8546-12867b6e5799:1-9795674,4f574d0f-5c4c-11e7-bb48-12565ecab2b2:1-723850799,71f6e7a4-00af-11e9-ae7c-0edd9e3125c0:1-335925336,9241a44b-c0fc-11e8-9dfb-0eb9ac6cbb3c:1-1118825106,943d33b3-c100-11e8-800a-12034a9e9944:1-874852286,962fd9eb-c100-11e8-810c-0a58a1944b56:1-2143624527,aa370d94-48d8-11e7-9849-0e3bb810e708:1-85082128,e0c59b60-3765-11e8-b958-0ae7cb1b6bf8:1-1396483377,f0268031-81fd-11e6-8502-0a27159a7b75:1-157631932,fd3a9915-0040-11e9-ad76-1287364c5e3a:1-16729205,feb360bd-a5b4-11e5-8612-1263ee7c7dc3:1-13500064, err = stream error @ 01fa297c-2c27-11e6-8546-12867b6e5799:1-9795674,4f574d0f-5c4c-11e7-bb48-12565ecab2b2:1-723850799,71f6e7a4-00af-11e9-ae7c-0edd9e3125c0:1-335925336,9241a44b-c0fc-11e8-9dfb-0eb9ac6cbb3c:1-1118825106,943d33b3-c100-11e8-800a-12034a9e9944:1-874852286,962fd9eb-c100-11e8-810c-0a58a1944b56:1-2143624527,aa370d94-48d8-11e7-9849-0e3bb810e708:1-85082128,e0c59b60-3765-11e8-b958-0ae7cb1b6bf8:1-1396483377,f0268031-81fd-11e6-8502-0a27159a7b75:1-157631932,fd3a9915-0040-11e9-ad76-1287364c5e3a:1-16729205,feb360bd-a5b4-11e5-8612-1263ee7c7dc3:1-13500064: context canceled
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741709 73 replication_watcher.go:139] Streamer stopped: stream error @ 01fa297c-2c27-11e6-8546-12867b6e5799:1-9795674,4f574d0f-5c4c-11e7-bb48-12565ecab2b2:1-723850799,71f6e7a4-00af-11e9-ae7c-0edd9e3125c0:1-335925336,9241a44b-c0fc-11e8-9dfb-0eb9ac6cbb3c:1-1118825106,943d33b3-c100-11e8-800a-12034a9e9944:1-874852286,962fd9eb-c100-11e8-810c-0a58a1944b56:1-2143624527,aa370d94-48d8-11e7-9849-0e3bb810e708:1-85082128,e0c59b60-3765-11e8-b958-0ae7cb1b6bf8:1-1396483377,f0268031-81fd-11e6-8502-0a27159a7b75:1-157631932,fd3a9915-0040-11e9-ad76-1287364c5e3a:1-16729205,feb360bd-a5b4-11e5-8612-1263ee7c7dc3:1-13500064: context canceled
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741726 73 tabletserver.go:312] TabletServer state: SHUTTING_DOWN (Shutting Down) -> NOT_SERVING (Not Serving)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741759 73 state_change.go:156] Done with post-action state refresh
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.741782 73 s3.go:240] StartBackup: [s3] dir: Ads/0, name: 2019-03-11.192419.prod_iad-1360915300, bucket: hubspot-backups-mysql-vitess-prod-iad
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.772231 73 backup.go:315] getting current replication status
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:19 I0311 19:24:19.772246 backup.go:315] getting current replication status
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.775797 73 hook.go:171] preflight_stop_slave hook doesn't exist
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.775949 73 query.go:73] exec STOP SLAVE
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.781414 73 backup.go:356] using replication position: 01fa297c-2c27-11e6-8546-12867b6e5799:1-9795674,4f574d0f-5c4c-11e7-bb48-12565ecab2b2:1-723850799,71f6e7a4-00af-11e9-ae7c-0edd9e3125c0:1-335925336,9241a44b-c0fc-11e8-9dfb-0eb9ac6cbb3c:1-1118825106,943d33b3-c100-11e8-800a-12034a9e9944:1-874852286,962fd9eb-c100-11e8-810c-0a58a1944b56:1-2143624527,aa370d94-48d8-11e7-9849-0e3bb810e708:1-85082128,e0c59b60-3765-11e8-b958-0ae7cb1b6bf8:1-1396483377,f0268031-81fd-11e6-8502-0a27159a7b75:1-157631932,fd3a9915-0040-11e9-ad76-1287364c5e3a:1-16729208,feb360bd-a5b4-11e5-8612-1263ee7c7dc3:1-13500064
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.781464 73 mysqld.go:329] Mysqld.Shutdown
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.781470 73 mysqld.go:333] executing Mysqld.Shutdown() remotely via mysqlctld server: /vt/mysqlctld.sock
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.782014 32 mysqld.go:329] Mysqld.Shutdown
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.782116 32 mysqld.go:367] No mysqld_shutdown hook, running mysqladmin directly
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:19.782291 32 mysqld.go:433] execCmd: /usr/bin/mysqladmin /usr/bin/mysqladmin [--defaults-extra-file=/tmp/example667372858 --shutdown-timeout=300 --connect-timeout=30 --wait=10 shutdown]
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:19 I0311 19:24:19.781433 backup.go:356] using replication position: 01fa297c-2c27-11e6-8546-12867b6e5799:1-9795674,4f574d0f-5c4c-11e7-bb48-12565ecab2b2:1-723850799,71f6e7a4-00af-11e9-ae7c-0edd9e3125c0:1-335925336,9241a44b-c0fc-11e8-9dfb-0eb9ac6cbb3c:1-1118825106,943d33b3-c100-11e8-800a-12034a9e9944:1-874852286,962fd9eb-c100-11e8-810c-0a58a1944b56:1-2143624527,aa370d94-48d8-11e7-9849-0e3bb810e708:1-85082128,e0c59b60-3765-11e8-b958-0ae7cb1b6bf8:1-1396483377,f0268031-81fd-11e6-8502-0a27159a7b75:1-157631932,fd3a9915-0040-11e9-ad76-1287364c5e3a:1-16729208,feb360bd-a5b4-11e5-8612-1263ee7c7dc3:1-13500064
ads-0-backup-1552296000-l2zs8 backup E0311 19:24:20.330117 73 reader.go:227] HeartbeatReporter: Failed to read most recent heartbeat: Server shutdown in progress (errno 1053) (sqlstate 08S01) during query: SELECT ts FROM `_vt`.heartbeat WHERE keyspaceShard='Ads:0'
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330589 73 tabletserver.go:312] TabletServer state: NOT_SERVING (Not Serving) -> NOT_SERVING (Transitioning)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330662 73 tabletserver.go:312] TabletServer state: NOT_SERVING (Transitioning) -> NOT_SERVING (Not Serving)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330678 73 tabletserver.go:672] Check MySQL failed. Shutting down query service
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330689 73 tabletserver.go:312] TabletServer state: NOT_SERVING (Not Serving) -> SHUTTING_DOWN (Shutting Down)
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330697 73 tabletserver.go:574] Executing complete shutdown.
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330774 73 reader.go:134] Stopped heartbeat reads
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330783 73 tabletserver.go:580] Shutdown complete.
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:21.330791 73 tabletserver.go:312] TabletServer state: SHUTTING_DOWN (Shutting Down) -> NOT_SERVING (Not Connected)
^[[Bads-0-backup-1552296000-l2zs8 backup I0311 19:24:35.531266 32 mysqld.go:247] Mysqld.Start(1552313950) stdout: 2019-03-11T19:24:35.530866Z mysqld_safe mysqld from pid file /vt/tablet/mysql.pid ended
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:35.532191 32 mysqld.go:260] Mysqld.Start(1552313950) exit: <nil>
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:35.793695 32 mysqld.go:447] execCmd: /usr/bin/mysqladmin output:
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:35.793719 32 mysqld.go:408] Mysqld.Shutdown: waiting for socket file (/vt/tablet/mysql.sock) and pid file (/vt/tablet/mysql.pid) to disappear
ads-0-backup-1552296000-l2zs8 backup I0311 19:24:35.796157 73 backup.go:413] found 379 files to backup
ads-0-backup-1552296000-l2zs8 backup INFO 2019/03/11 19:24:35 I0311 19:24:35.796173 backup.go:413] found 379 files to backup
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment