· 8 years ago · Jun 21, 2018, 01:06 AM
12018-05-31T07:59:50.880143Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not set.
22018-05-31T07:59:50.881641Z 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
32018-05-31T07:59:50.885191Z 0 [Note] /rdsdbbin/mysql/bin/mysqld (mysqld 5.7.19-log) starting as process 3470 ...
42018-05-31T07:59:51.126014Z 0 [Note] InnoDB: PUNCH HOLE support available
52018-05-31T07:59:51.126054Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
62018-05-31T07:59:51.126060Z 0 [Note] InnoDB: Uses event mutexes
72018-05-31T07:59:51.126064Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
82018-05-31T07:59:51.126068Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
92018-05-31T07:59:51.126071Z 0 [Note] InnoDB: Using Linux native AIO
102018-05-31T07:59:51.150879Z 0 [Note] InnoDB: Number of pools: 1
112018-05-31T07:59:51.182600Z 0 [Note] InnoDB: Using CPU crc32 instructions
122018-05-31T07:59:51.184624Z 0 [Note] InnoDB: Initializing buffer pool, total size = 1G, instances = 8, chunk size = 128M
132018-05-31T07:59:51.245944Z 0 [Note] InnoDB: Completed initialization of buffer pool
142018-05-31T07:59:51.274809Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
152018-05-31T07:59:51.661104Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
162018-05-31T07:59:52.079538Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 205460220725
172018-05-31T07:59:53.616196Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 205460333516
182018-05-31T07:59:54.463445Z 0 [Note] InnoDB: Database was not shutdown normally!
192018-05-31T07:59:54.463472Z 0 [Note] InnoDB: Starting crash recovery.
202018-05-31T07:59:56.869876Z 0 [Note] InnoDB: Transaction 1712897897 was in the XA prepared state.
212018-05-31T07:59:57.059082Z 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo
222018-05-31T07:59:57.059107Z 0 [Note] InnoDB: Trx id counter is 1712898304
232018-05-31T07:59:57.060227Z 0 [Note] InnoDB: Starting an apply batch of log records to the database...
24InnoDB: Progress in percent: 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
252018-05-31T07:59:57.606094Z 0 [Note] InnoDB: Apply batch completed
262018-05-31T07:59:57.606126Z 0 [Note] InnoDB: Last MySQL binlog file position 0 7766, file name mysql-bin-changelog.196126
272018-05-31T08:01:05.616244Z 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions
282018-05-31T08:01:05.616271Z 0 [Note] InnoDB: Rollback of non-prepared transactions completed
292018-05-31T08:01:05.617146Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
302018-05-31T08:01:05.617158Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
312018-05-31T08:01:05.617203Z 0 [Note] InnoDB: Setting file '/rdsdbdata/db/innodb/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
322018-05-31T08:01:07.653103Z 0 [Note] InnoDB: File '/rdsdbdata/db/innodb/ibtmp1' size is now 12 MB.
332018-05-31T08:01:07.654148Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
342018-05-31T08:01:07.654159Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
352018-05-31T08:01:07.870099Z 0 [Note] InnoDB: Waiting for purge to start
362018-05-31T08:01:07.920296Z 0 [Note] InnoDB: 5.7.19 started; log sequence number 205460333516
372018-05-31T08:01:07.920583Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 76646ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
382018-05-31T08:01:07.920723Z 0 [Note] InnoDB: Loading buffer pool(s) from /rdsdbdata/db/innodb/ib_buffer_pool
392018-05-31T08:01:07.924167Z 0 [Note] Plugin 'FEDERATED' is disabled.
402018-05-31T08:01:07.938375Z 0 [Note] Recovering after a crash using /rdsdbdata/log/binlog/mysql-bin-changelog
412018-05-31T08:01:07.938453Z 0 [Note] Starting crash recovery...
422018-05-31T08:01:07.938489Z 0 [Note] InnoDB: Starting recovery for XA transactions...
432018-05-31T08:01:07.938496Z 0 [Note] InnoDB: Transaction 1712897897 in prepared state after recovery
442018-05-31T08:01:07.938500Z 0 [Note] InnoDB: Transaction contains changes to 1 rows
452018-05-31T08:01:07.938504Z 0 [Note] InnoDB: 1 transactions in prepared state after recovery
462018-05-31T08:01:07.938506Z 0 [Note] Found 1 prepared transaction(s) in InnoDB
472018-05-31T08:01:07.975797Z 0 [Note] Crash recovery finished.
482018-05-31T08:01:08.009971Z 0 [Note] Salting uuid generator variables, current_pid: 3470, server_start_time: 1527753590, bytes_sent: 0,
492018-05-31T08:01:08.013725Z 0 [Note] Generated uuid: 'c65e1206-64a8-11e8-acdc-0642b77ee370', server_start_time: 976718170713733380, bytes_sent: 47057241759744
502018-05-31T08:01:08.013758Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: c65e1206-64a8-11e8-acdc-0642b77ee370.
512018-05-31T08:01:08.044320Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
522018-05-31T08:01:08.044373Z 0 [Note] IPv6 is available.
532018-05-31T08:01:08.044384Z 0 [Note] - '::' resolves to '::';
542018-05-31T08:01:08.044401Z 0 [Note] Server socket created on IP: '::'.
552018-05-31T08:01:09.042028Z 0 [Note] Event Scheduler: Loaded 0 events
562018-05-31T08:01:09.042160Z 0 [Note] /rdsdbbin/mysql/bin/mysqld: ready for connections.
57Version: '5.7.19-log' socket: '/tmp/mysql.sock' port: 3306 MySQL Community Server (GPL)
582018-05-31T08:01:09.042169Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
592018-05-31T08:01:09.042171Z 0 [Note] Beginning of list of non-natively partitioned tables
602018-05-31T08:01:09.889603Z 0 [Note] InnoDB: Buffer pool(s) load completed at 180531 8:01:09
612018-05-31T08:01:14.839437Z 0 [Note] End of list of non-natively partitioned tables
62----------------------- END OF LOG ----------------------
63
64+---------------+-------------------------+-------------------------------+------------+--------+---------+------------+------------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+------------+--------------------+----------+----------------+---------------+
65| TABLE_CATALOG | TABLE_SCHEMA | TABLE_NAME | TABLE_TYPE | ENGINE | VERSION | ROW_FORMAT | TABLE_ROWS | AVG_ROW_LENGTH | DATA_LENGTH | MAX_DATA_LENGTH | INDEX_LENGTH | DATA_FREE | AUTO_INCREMENT | CREATE_TIME | UPDATE_TIME | CHECK_TIME | TABLE_COLLATION | CHECKSUM | CREATE_OPTIONS | TABLE_COMMENT |
66+---------------+-------------------------+-------------------------------+------------+--------+---------+------------+------------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+------------+--------------------+----------+----------------+---------------+
67| def | promosolutions_co_nz | w90h1_finder_tokens | BASE TABLE | MEMORY | 10 | Fixed | 0 | 459 | 0 | 15040512 | 0 | 0 | NULL | 2018-05-31 08:20:13 | NULL | NULL | utf8_general_ci | NULL | | |
68| def | promosolutions_co_nz | w90h1_finder_tokens_aggregate | BASE TABLE | MEMORY | 10 | Fixed | 0 | 474 | 0 | 15061350 | 0 | 0 | NULL | 2018-05-31 08:20:13 | NULL | NULL | utf8_general_ci | NULL | | |
69| def | vc | CORE | BASE TABLE | MEMORY | 10 | Fixed | 0 | 777 | 0 | 16627023 | 0 | 0 | NULL | 2018-05-31 08:20:23 | NULL | NULL | latin1_swedish_ci | NULL | | |
70| def | vc | CORErs | BASE TABLE | MEMORY | 10 | Fixed | 0 | 786 | 0 | 16649838 | 0 | 0 | NULL | 2018-05-31 08:20:23 | NULL | NULL | latin1_swedish_ci | NULL | | |
71| def | vc | vw_mygroups | BASE TABLE | MyISAM | 10 | Fixed | 0 | 0 | 0 | 1970324836974591 | 1024 | 0 | NULL | 2018-05-01 04:44:19 | 2018-05-01 04:44:19 | NULL | utf8_general_ci | NULL | | |
72| def | www_automatem_co_nz | jos_finder_tokens | BASE TABLE | MEMORY | 10 | Fixed | 0 | 623 | 0 | 15553818 | 0 | 0 | NULL | 2018-05-31 08:20:27 | NULL | NULL | utf8mb4_general_ci | NULL | | |
73| def | www_automatem_co_nz | jos_finder_tokens_aggregate | BASE TABLE | MEMORY | 10 | Fixed | 0 | 639 | 0 | 15582015 | 0 | 0 | NULL | 2018-05-31 08:20:27 | NULL | NULL | utf8mb4_general_ci | NULL | | |
74| def | www_bayautomotive_co_nz | jos_finder_tokens | BASE TABLE | MEMORY | 10 | Fixed | 0 | 623 | 0 | 15553818 | 0 | 0 | NULL | 2018-05-31 08:20:28 | NULL | NULL | utf8mb4_general_ci | NULL | | |
75| def | www_bayautomotive_co_nz | jos_finder_tokens_aggregate | BASE TABLE | MEMORY | 10 | Fixed | 0 | 639 | 0 | 15582015 | 0 | 0 | NULL | 2018-05-31 08:20:28 | NULL | NULL | utf8mb4_general_ci | NULL | | |
76| def | www_xpanda_co_nz | jos_finder_tokens | BASE TABLE | MEMORY | 10 | Fixed | 0 | 623 | 0 | 15553818 | 0 | 0 | NULL | 2018-05-31 08:20:36 | NULL | NULL | utf8mb4_general_ci | NULL | | |
77| def | www_xpanda_co_nz | jos_finder_tokens_aggregate | BASE TABLE | MEMORY | 10 | Fixed | 0 | 639 | 0 | 15582015 | 0 | 0 | NULL | 2018-05-31 08:20:36 | NULL | NULL | utf8mb4_general_ci | NULL | | |
78+---------------+-------------------------+-------------------------------+------------+--------+---------+------------+------------+----------------+-------------+------------------+--------------+-----------+----------------+---------------------+---------------------+------------+--------------------+----------+----------------+---------------+
79
80********* update from service team ***********
81
82This is decoded DDL in the binary log that blocked point-in-time restore for restore-markovina-aws-support. It is a "create table if not exists" for the drsarahhart_com.wp_wfBlocks7 table. I had to manually skip it (as the table already existed) to push the restore to completion (there was also a similar DDL in a later binary log).
83
84# at 375050
85#180523 19:10:46 server id 153211832 end_log_pos 375115 CRC32 0x1eec997a Anonymous_GTID last_committed=301 sequence_number=302 rbr_only=no
86SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
87# at 375115
88#180523 19:10:46 server id 153211832 end_log_pos 375785 CRC32 0xc43c076b Query thread_id=584850 exec_time=0 error_code=0
89SET TIMESTAMP=1527102646/*!*/;
90create table IF NOT EXISTS wp_wfBlocks7 (
91 `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
92 `type` int(10) unsigned NOT NULL DEFAULT '0',
93 `IP` binary(16) NOT NULL DEFAULT '^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@',
94 `blockedTime` bigint(20) NOT NULL,
95 `reason` varchar(255) NOT NULL,
96 `lastAttempt` int(10) unsigned DEFAULT '0',
97 `blockedHits` int(10) unsigned DEFAULT '0',
98 `expiration` bigint(20) unsigned NOT NULL DEFAULT '0',
99 `parameters` text,
100 PRIMARY KEY (`id`),
101 KEY `type` (`type`),
102 KEY `IP` (`IP`),
103 KEY `expiration` (`expiration`)
104) DEFAULT CHARSET=utf8
105/*!*/;
106# at 375785
107
108The problematic characters were in the sequence: '^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@'
109This corresponds to this ASCII code point sequence: 5c 27 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 5c 00 27 00
110
111How is the customer executing the DDL in the first place to create this table? Is the DDL being auto-generated or is someone running a script? If using a script how are they encoding the script contents?
112
113********* end update from service team ********