1

(crosspost from here after being advised this is not a programming question)

I'm trying to drop a few columns from a fairly large table in my database (about 110GB) and it seems like the server is freezing. After creating a (journal?) file called something similar to #sql-ib43-1640985772.ibd, which grows to about the same size as the table, the file sizes stop changing and nothing seems to be happening, even though I still see high CPU and disk writes about 10MB/s from mysqld, though absolutely 0B/s in reads. It sat like this for over an hour, then I cancelled the query and tried it again, now its been stuck at the same point for a while.

I'm using the default config file, except I have updated innodb-buffer-pool-size = 54G since my system has 64GB RAM.

Table structure

mysql> show create table tx_out2;
+---------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table   | Create Table                                                                                                                                                                                            |
+---------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| tx_out2 | CREATE TABLE `tx_out2` (
  `txid` tinytext,
  `indexOut` int(8) DEFAULT NULL,
  `btc_value` double DEFAULT NULL,
  `scriptPubKey` tinytext,
  `address` tinytext
) ENGINE=InnoDB DEFAULT CHARSET=latin1 |

Count of records

mysql> select count(*) from tx_out2;
    695377848

The query its running

ALTER TABLE tx_out2
DROP COLUMN indexOut, DROP COLUMN scriptPubKey;

I don't see anything interesting in the mysql.log, but I'm gonna dump my error.log in case I've missed something.

2017-10-16T11:36:51.445140Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4107ms. The settings might not be optimal. (flushed=0 and evicted=7932, during the time
.)
2017-10-16T11:37:48.064416Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4089ms. The settings might not be optimal. (flushed=0 and evicted=8192, during the time
.)
2017-10-16T11:38:26.360996Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4177ms. The settings might not be optimal. (flushed=0 and evicted=8192, during the time
.)
2017-10-16T11:40:04.313444Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4218ms. The settings might not be optimal. (flushed=0 and evicted=8192, during the time
.)
2017-10-16T11:42:27.768420Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 4308ms. The settings might not be optimal. (flushed=0 and evicted=8004, during the time
.)
2017-10-16T12:57:27.170952Z 0 [Note] Giving 1 client threads a chance to die gracefully
2017-10-16T12:57:27.171139Z 0 [Note] Shutting down slave threads
2017-10-16T12:57:29.171455Z 0 [Note] Forcefully disconnecting 1 remaining clients
2017-10-16T12:57:29.171515Z 0 [Warning] /usr/sbin/mysqld: Forcing close of thread 8  user: 'root'

2017-10-16T12:57:29.171588Z 0 [Note] Event Scheduler: Purging the queue. 0 events
2017-10-16T12:57:29.172163Z 0 [Note] Binlog end
2017-10-16T12:57:29.186138Z 0 [Note] Shutting down plugin 'ngram'
2017-10-16T12:57:29.186172Z 0 [Note] Shutting down plugin 'partition'
2017-10-16T12:57:29.186182Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2017-10-16T12:57:29.186191Z 0 [Note] Shutting down plugin 'ARCHIVE'
2017-10-16T12:57:29.186198Z 0 [Note] Shutting down plugin 'CSV'
2017-10-16T12:57:29.186208Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2017-10-16T12:57:29.186336Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-10-16T12:57:29.186367Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-10-16T12:57:29.186376Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-10-16T12:57:29.186384Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-10-16T12:57:29.186391Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-10-16T12:57:29.186398Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-10-16T12:57:29.186423Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-10-16T12:57:29.186430Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-10-16T12:57:29.186436Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-10-16T12:57:29.186442Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-10-16T12:57:29.186448Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-10-16T12:57:29.186454Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-10-16T12:57:29.186461Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-10-16T12:57:29.186467Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-10-16T12:57:29.186473Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-10-16T12:57:29.186479Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2017-10-16T12:57:29.186485Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2017-10-16T12:57:29.186491Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-10-16T12:57:29.186497Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-10-16T12:57:29.186503Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-10-16T12:57:29.186509Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-10-16T12:57:29.186516Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-10-16T12:57:29.186522Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-10-16T12:57:29.186528Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-10-16T12:57:29.186534Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-10-16T12:57:29.186540Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2017-10-16T12:57:29.186546Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-10-16T12:57:29.186552Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-10-16T12:57:29.186558Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2017-10-16T12:57:29.186564Z 0 [Note] Shutting down plugin 'InnoDB'
2017-10-16T12:57:29.186659Z 0 [Note] InnoDB: FTS optimize thread exiting.
2017-10-16T12:57:29.186909Z 0 [Note] InnoDB: Starting shutdown...
2017-10-16T12:57:29.288209Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2017-10-16T12:57:29.493814Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 171016  8:57:29
2017-10-16T12:57:35.879563Z 0 [Note] InnoDB: Shutdown completed; log sequence number 350941746874
2017-10-16T12:57:35.879867Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-10-16T12:57:35.879979Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-10-16T12:57:35.880472Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2017-10-16T12:57:35.880477Z 0 [Note] Shutting down plugin 'MyISAM'
2017-10-16T12:57:35.880575Z 0 [Note] Shutting down plugin 'MEMORY'
2017-10-16T12:57:35.880577Z 0 [Note] Shutting down plugin 'sha256_password'
2017-10-16T12:57:35.880579Z 0 [Note] Shutting down plugin 'mysql_native_password'
2017-10-16T12:57:35.882166Z 0 [Note] Shutting down plugin 'binlog'
2017-10-16T12:57:35.882618Z 0 [Note] /usr/sbin/mysqld: Shutdown complete

2017-10-16T12:57:35.997070Z 0 [Warning] Changed limits: max_open_files: 1024 (requested 5000)
2017-10-16T12:57:35.997103Z 0 [Warning] Changed limits: table_open_cache: 431 (requested 2000)
2017-10-16T12:57:36.130275Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-10-16T12:57:36.131185Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.19-0ubuntu0.16.04.1-log) starting as process 14818 ...
2017-10-16T12:57:36.136951Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-10-16T12:57:36.136970Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-10-16T12:57:36.136973Z 0 [Note] InnoDB: Uses event mutexes
2017-10-16T12:57:36.136975Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-10-16T12:57:36.136978Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-10-16T12:57:36.136980Z 0 [Note] InnoDB: Using Linux native AIO
2017-10-16T12:57:36.137117Z 0 [Note] InnoDB: Number of pools: 1
2017-10-16T12:57:36.137179Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-10-16T12:57:36.137939Z 0 [Note] InnoDB: Initializing buffer pool, total size = 54G, instances = 8, chunk size = 128M
2017-10-16T12:57:37.833908Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-10-16T12:57:37.926601Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-10-16T12:57:37.939931Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-10-16T12:57:38.305711Z 0 [Warning] InnoDB: Resizing redo log from 2*32768 to 2*3072 pages, LSN=350941746883
2017-10-16T12:57:38.421912Z 0 [Warning] InnoDB: Starting to delete and rewrite log files.
2017-10-16T12:57:38.519476Z 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
2017-10-16T12:57:38.591866Z 0 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
2017-10-16T12:57:38.704063Z 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-10-16T12:57:38.704167Z 0 [Warning] InnoDB: New log files created, LSN=350941746883
2017-10-16T12:57:38.704600Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-10-16T12:57:38.704666Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-10-16T12:57:38.739187Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-10-16T12:57:38.740727Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-10-16T12:57:38.740750Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-10-16T12:57:38.741403Z 0 [Note] InnoDB: 5.7.19 started; log sequence number 350941746874
2017-10-16T12:57:38.742225Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-10-16T12:57:38.742678Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-10-16T12:57:38.751873Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
2017-10-16T12:57:38.751905Z 0 [Note] Server hostname (bind-address): '127.0.0.1'; port: 3306
2017-10-16T12:57:38.751921Z 0 [Note]   - '127.0.0.1' resolves to '127.0.0.1';
2017-10-16T12:57:38.751952Z 0 [Note] Server socket created on IP: '127.0.0.1'.
2017-10-16T12:57:38.781275Z 0 [Note] Event Scheduler: Loaded 0 events
2017-10-16T12:57:38.781430Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.19-0ubuntu0.16.04.1-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)
2017-10-16T12:57:38.781441Z 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.
2017-10-16T12:57:38.781445Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-10-16T12:57:38.800160Z 0 [Note] End of list of non-natively partitioned tables
2017-10-16T12:57:39.006214Z 3 [Note] Access denied for user 'root'@'localhost' (using password: NO)
2017-10-16T12:57:44.574183Z 0 [Note] InnoDB: Buffer pool(s) load completed at 171016  8:57:44

Thanks for any help diagnosing this, it seems highly unusual and I'm worried I'm waiting for nothing.

2

The "page_cleaner" message is bogus.

ALTER takes time. The bigger the table, the longer it takes.

Newer versions of MySQL can do certain ALTERs faster; what version are you running? 5.6 introduced ALGORITHM=INPLACE', which should have run fast. (It may have needed doing the twoDROPs` in separate steps.)

"After creating ... #sql-ib43-1640985772.ibd ..." -- This tells me that the ALTER was the slower version, namely "copy the table over, making the changes as it goes".

I don't see a PRIMARY KEY or any other index. Do you ever read from this table without having to scan the entire thing? What good is the table?

A future tip: Don't use TINYTEXT, use VARCHAR(255); the former is slower in some situations.

54G/64G -- good (but irrelevant for this situation)

More

Since it is very important to have a PRIMARY KEY, and since adding a PRIMARY KEY requires "copy", not "inplace", the best bet is to do a single ALTER with all the changes -- column drops, adding index(es), tinytext -> varchar(255) -- all in a single alter.

It will take a long time, probably longer than your 3-hour experience. This is because adding indexes cannot be done in a simple, linear, pass over the data.

Yes, you will need disk space -- do you have more space than the table currently occupies? Adding a PRIMARY KEY to an InnoDB table that is in PK order will add a little bit of overhead. If the data is not in PK order, the overhead might be 40%. Adding other indexes will cost space, too.

Please provide the desired CREATE TABLE, I may have more tips on things.

Would FLOAT (4 bytes, ~7 significant digits) suffice instead of DOUBLE (8 bytes)? If you weren't dropping the INT(8) (4 bytes), I would lecture on MEDIUMINT (3 bytes, 0..16M) and UNSIGNED.

More 2

If the data came from LOAD DATA, there are ways to drop columns as you load. Maybe reloading would be the 'right' thing to do? Simply load into @indexOut instead of indexOut (and not have such a column in the table).

It is always best to have the PRIMARY KEY defined before loading into the table. Without it, InnoDB provides a 6-byte, hidden, PK. You are now trying to throw that away!

PRIMARY KEY

Since you have nothing that is currently "unique", it is probably best to have an artificial

id INT UNSIGNED AUTO_INCREMENT NOT NULL,
PRIMARY KEY(id)

That will take 4 bytes (better than 6 bytes, when omitted) and let you get up to 4 billion rows. (I assume your 695M rows is not going to change?) The rows will insert "at the end" of the table, thereby being very efficient. (Ignore the 40% I mentioned.)

5
  • I'm planning to add indexes after dropping the columns, space is at a premium so I needed to make room first. Thanks for the tip about ALGORITHM=INPLACE though I'll look into that.
    – jamzsabb
    Oct 16 '17 at 16:56
  • 1
    I added several more paragraphs.
    – Rick James
    Oct 16 '17 at 17:20
  • Oh wow, it sounds like I've made things more difficult. I'm a data analyst trying to stage my own database for some research so I'm making some dumb mistakes. I think the data type changes and loading selectively instead of dropping columns will help tremendously, but I havne't been using a Primary Key since none of my columns are completely unique. It's building the indexes now so that should help a lot too. I've been focusing all my optimization efforts on server side, it sounds like I could do a lot from the query and data storage standpoint as well. Thanks so much for all the advice!
    – jamzsabb
    Oct 16 '17 at 18:21
  • 1
    Let's say 'ignorant', not 'dumb'. There are a lot of subtleties in MySQL's ALTER TABLE, and there have been significant changes in 5.6 and 5.7. I have tried to impart the details that would help your case. (As opposed to throwing the lengthy manual at your.)
    – Rick James
    Oct 16 '17 at 18:33
  • 1
    I added something about the PK (which is not found on the ALTER pages anyway).
    – Rick James
    Oct 16 '17 at 18:38
1

The operation finally completed after more than 3 hours. I suspect I have a major bottleneck somewhere but I'm not sure where as CPU and IO seemed normal.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.