Friday, September 22, 2006

[ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry,

So lately this error message has been appearing more and more in the log files of my slaves

060524 17:45:45 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060801 9:42:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060801 13:33:41 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060801 20:41:30 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060802 2:28:21 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060802 3:46:29 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060802 3:48:47 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060802 5:02:53 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060802 6:25:57 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060901 21:58:11 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060902 2:20:46 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060902 2:53:30 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060903 11:37:36 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060903 18:58:28 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060903 21:35:54 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060904 23:23:12 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060905 1:55:37 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060906 1:52:49 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060906 3:35:50 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060906 3:55:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060906 9:15:55 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060907 0:16:43 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060907 6:25:03 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060907 7:00:45 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060907 7:10:20 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060907 7:25:40 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060914 8:31:23 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060914 14:07:42 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060914 15:26:54 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060914 15:44:04 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060914 17:02:23 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060914 19:34:36 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060915 1:16:43 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060915 6:23:26 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060915 15:10:09 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060915 23:31:01 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 0:34:22 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 0:53:07 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 1:18:46 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 2:14:17 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 3:09:49 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 5:31:41 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 8:16:14 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060916 19:14:32 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 4:31:30 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 5:09:30 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 5:42:54 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 5:59:50 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 6:19:29 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 6:51:12 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 7:28:21 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 9:11:02 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060917 17:12:12 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 1:32:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 6:22:10 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 7:57:29 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 8:15:41 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 8:29:47 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 8:57:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 9:22:59 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 10:17:37 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060918 16:56:22 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 3:28:49 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 6:44:39 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 9:13:49 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 10:45:18 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 11:19:04 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 11:43:34 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 12:44:05 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 13:51:59 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060919 17:42:23 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 2:21:19 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 6:07:38 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 10:36:03 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 16:39:58 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 18:56:05 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 19:57:34 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 21:06:00 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 22:43:42 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060920 23:40:12 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060921 1:57:11 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060921 7:08:38 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060921 12:53:20 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 4:03:47 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 5:04:55 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 5:43:06 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 6:14:05 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 6:42:56 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 7:37:25 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
060922 10:50:05 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)


I have been investigating the reason for this. Matthew Lord suggested in this bug report that in at least some cases, this reconnection was expected due to the slave_net_timeout value, which on my server is set to default.

mysql> SHOW VARIABLES LIKE 'slave_net_timeout';
+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| slave_net_timeout | 3600 |
+-------------------+-------+
1 row in set (0.00 sec)


Other timeout variables
mysql> SHOW VARIABLES LIKE '%timeout%';
+--------------------------+-------+
| Variable_name | Value |
+--------------------------+-------+
| connect_timeout | 15 |
| delayed_insert_timeout | 300 |
| innodb_lock_wait_timeout | 50 |
| interactive_timeout | 28800 |
| net_read_timeout | 30 |
| net_write_timeout | 60 |
| slave_net_timeout | 3600 |
| sync_replication_timeout | 0 |
| wait_timeout | 28800 |
+--------------------------+-------+
9 rows in set (0.00 sec)

Seeing the time when the above errors appeared, it is clear that in some cases the reconnection is occuring multiple times within an hour. This leads me to indicate that something else is going on here. One thing I noticed is that the reconnection is happening everytime slave switches to a new log file.
060524 17:45:45 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.001628' position 587419455
060801 9:42:13 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002268' position 754471449
060801 13:33:41 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002269' position 318959997
060801 20:41:30 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002270' position 318856904
060802 2:28:21 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002271' position 318933307
060802 3:46:29 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002272' position 318843694
060802 3:48:47 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002272' position 716398470
060802 5:02:53 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002273' position 318901405
060802 6:25:57 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002274' position 318930542
060830 9:57:59 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002554' position 926355659
060901 21:58:11 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002580' position 1015598952
060902 2:20:46 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002581' position 1015599182
060902 2:53:30 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002582' position 1015592759
060903 11:37:36 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002595' position 544695514
060903 18:58:29 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002596' position 544696110
060903 21:35:54 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002597' position 544609673
060904 23:23:13 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002605' position 149900829
060905 1:55:37 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002606' position 149901053
060906 1:52:50 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002612' position 450457914
060906 3:35:50 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002613' position 450443729
060906 3:55:14 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002614' position 450459188
060906 9:15:55 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002615' position 238998569
060907 0:16:43 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002616' position 238969084
060907 6:25:03 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002617' position 238982702
060907 7:00:45 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002618' position 238992216
060907 7:10:20 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002619' position 238927275
060907 7:25:40 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002619' position 924791139
060914 8:31:23 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002677' position 908960062
060914 14:07:42 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002678' position 908904132
060914 15:26:55 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002679' position 908886495
060914 15:44:04 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002680' position 908915040
060914 17:02:23 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002681' position 192263658
060914 19:34:36 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002682' position 192288645
060915 1:16:44 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002683' position 192314960
060915 6:23:27 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002684' position 192313581
060915 15:10:09 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002685' position 192302436
060915 23:31:01 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002686' position 192257517
060916 0:34:22 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002687' position 192209960
060916 0:53:07 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002688' position 192330206
060916 1:18:47 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002688' position 968380500
060916 2:14:17 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002689' position 968393724
060916 3:09:49 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002690' position 968428073
060916 5:31:41 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002691' position 968448699
060916 8:16:14 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002692' position 968365497
060916 19:14:32 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002693' position 968446897
060917 4:31:30 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002694' position 968446979
060917 5:09:30 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002695' position 968399196
060917 5:42:54 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002696' position 192228405
060917 5:59:50 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002697' position 192266326
060917 6:19:29 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002698' position 192287578
060917 6:51:12 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002699' position 192233081
060917 7:28:21 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002700' position 192219086
060917 9:11:02 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002701' position 192225663
060917 17:12:12 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002702' position 192222395
060918 1:32:13 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002703' position 192232114
060918 6:22:10 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002703' position 968461872
060918 7:57:29 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002704' position 968442279
060918 8:15:41 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002705' position 968373031
060918 8:29:47 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002706' position 968440179
060918 8:57:13 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002707' position 968447052
060918 9:22:59 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002708' position 968443197
060918 10:17:37 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002709' position 968439668
060918 16:56:22 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002710' position 968438755
060919 3:28:49 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002711' position 968427682
060919 6:44:39 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002712' position 968444779
060919 9:13:49 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002713' position 968450077
060919 10:45:18 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002714' position 968435044
060919 11:19:04 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002715' position 968338956
060919 11:43:34 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002716' position 968432120
060919 12:44:05 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002717' position 968443215
060919 13:51:59 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002718' position 968443892
060919 17:42:23 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002719' position 968409684
060920 2:21:19 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002720' position 968436935
060920 6:07:38 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002721' position 968443697
060920 10:36:03 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002722' position 968397302
060920 16:39:58 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002723' position 968383643
060920 18:56:05 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002724' position 968437352
060920 19:57:34 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002725' position 968502168
060920 21:06:00 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002726' position 968409788
060920 22:43:42 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002727' position 968402634
060920 23:40:12 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002728' position 968390187
060921 1:57:11 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002729' position 968358219
060921 7:08:38 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002730' position 968442367
060921 12:53:20 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002731' position 968382723
060922 4:03:48 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002732' position 968402053
060922 5:04:55 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002734' position 968379386
060922 5:43:06 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002735' position 968396895
060922 6:14:05 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002737' position 968438049
060922 6:42:56 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002738' position 968348169
060922 7:37:25 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002739' position 968438301
060922 10:50:05 [ERROR] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'db2-bin.002740' position 968444121


I have the relay_log_space_limit specified and am now wondering if these reconnections are made everytime the slave thread pauses for more space to be freed up.

mysql> SHOW VARIABLES LIKE 'relay_log_space_limit';
+-----------------------+-------------+
| Variable_name | Value |
+-----------------------+-------------+
| relay_log_space_limit | 12884901888 |
+-----------------------+-------------+
1 row in set (0.00 sec)


Actually that makes quite sense. However the reason I would like to investigate it even further is because yesterday MySQL restarted itself immediately after one of these reconnections causing once again, a MyISAM corruption. Your comments, as always are welcome and appreciated.

Tuesday, September 19, 2006

Connecting to MySQL without a password

Things have been quite busy lately. I took Friday off as my mom was scheduled to leave on Sunday. She was visiting me after 6 years. My long weekend however flew faster than I could spell MySQL.

Now that I have my plane tickets booked for the MySQL camp, I am very excited as I cannot wait to see my friends there. If you are planning to come, and your name isn't listed, please take a few moments to add it to the participants list.

Today, I was asked by a friend if there was a way to login to MySQL without having to specify password each time.

Sure, there is. If MySQL finds a .my.cnf file in your home directory it will read it and apply the configuration specified there. What that means is that if you place your user name and password in that file then you don't have to keep specifying the username and password.

For instance, you can put something like:
[mysql]
user=user
password=pass
[mysqladmin]
user=user
password=pass


This will save you having to type the boring username and password every time.

Wednesday, September 13, 2006

MySQL Repair table doing "repair by sort" with no TMD tables?

This is really weird.
Today, a few of my MyISAM tables got corrupted, MySQL started repairing them. However here are the few interesting/weird things about this repair:

1. the "Repair by sorting" command was being run by User "system user"
2. No TMD tables were being created (I checked the entire drive to see if they were being created)
3. Although the "SHOW PROCESSLIST" shows the thread repairing the table, I believe it is NOT as more than 3 hours have gone by and generally the table repairs in less than an hour.

It will be great to check the process of the repair interactively. Why was the repair command issued by the slave thread? It seems like the slave thread was going to update a table, found it crashed and started repairing it.

Now that the slave thread is "hung," I am just giving it more time for graceful exit. In case it doesn't exit I will just have to kill the SLAVE_SQL thread as SLAVE_IO thread is already stopped.

I am continuing to investigate but appreciate any feedback.

The joys of having MyISAM tables,
Frank

MySQL: Pure virtual function called

Today after I noticed MySQL repairing some MyISAM tables and after investigation I found the following errors:
Today Pure virtual function called
Fatal signal 6 while backtracing
060913 15:48:40 mysqld restarted

Now I am working on finding the cause for these errors. The error seems to indicate a situation where objects that are not fully initialize call the virtual functions, however I am still investigating. Comments are welcome.

Monday, September 11, 2006

Case Sensitive MySQL

Today I was asked an interesting question: "Can we make MySQL to be case sensitive for SELECT queries and can we force a column in MySQL to be always lowercase?"

My response was that yes, we can have "instruct" MySQL to be case sensitive. One way to do that is to set the collation for the table (or column) to be either binary or case sensitive as shown below.

The naming convention for collation in mysql is as follows:

*_bin: represents binary case sensitive collation
*_cs: case sensitive collation
*_ci: case insensitive collation

###########
# Start binary collation example
###########
mysql> create table case_bin_test (word VARCHAR(10)) CHARACTER SET latin1 COLLATE latin1_bin;
Query OK, 0 rows affected (0.02 sec)

mysql> INSERT INTO case_bin_test VALUES ('Frank'),('Google'),('froogle'),('flickr'),('FlicKr');
Query OK, 5 rows affected (0.00 sec)
Records: 5 Duplicates: 0 Warnings: 0

mysql> SELECT * FROM case_bin_test WHERE word LIKE 'f%';
+---------+
| word |
+---------+
| froogle |
| flickr |
+---------+
2 rows in set (0.00 sec)

mysql> SELECT * FROM case_bin_test WHERE word LIKE 'F%';
+---------+
| word |
+---------+
| Frank |
| FlicKr |
+---------+
4 rows in set (0.00 sec)

###########
# End
###########


Here's another way

###########
# Start case sensitive collation example
###########

mysql> create table case_cs_test (word VARCHAR(10)) CHARACTER SET latin1 COLLATE latin1_general_cs;
Query OK, 0 rows affected (0.08 sec)

mysql> INSERT INTO case_cs_test VALUES ('Frank'),('Google'),('froogle'),('flickr'),('FlicKr');
Query OK, 5 rows affected (0.00 sec)
Records: 5 Duplicates: 0 Warnings: 0

mysql> SELECT * FROM case_cs_test WHERE word LIKE 'F%';
+---------+
| word |
+---------+
| Frank |
| FlicKr |
+---------+
4 rows in set (0.00 sec)

mysql> SELECT * FROM case_cs_test WHERE word LIKE 'f%';
+---------+
| word |
+---------+
| froogle |
| flickr |
+---------+
2 rows in set (0.00 sec)

###########
# end
###########


Yet another way is to specify the collation during query in case the collation cannot be specified for the entire table. Following are a few different ways of specifying this.


mysql> create table case_test (word VARCHAR(10)) CHARACTER SET latin1;
Query OK, 0 rows affected (0.01 sec)

mysql> INSERT INTO case_test VALUES ('Frank'),('Google'),('froogle'),('flickr'),('FlicKr');
Query OK, 7 rows affected (0.01 sec)
Records: 7 Duplicates: 0 Warnings: 0
mysql> SELECT * FROM case_test WHERE word LIKE 'f%';
+---------+
| word |
+---------+
| Frank |
| froogle |
| flickr |
| FlicKr |
+---------+
6 rows in set (0.01 sec)

mysql> SELECT * FROM case_test WHERE word LIKE 'F%';
+---------+
| word |
+---------+
| Frank |
| froogle |
| flickr |
| FlicKr |
+---------+
6 rows in set (0.01 sec)


mysql> SELECT * FROM case_test WHERE word COLLATE latin1_bin LIKE 'F%';
+---------+
| word |
+---------+
| Frank |
| FlicKr |
+---------+
4 rows in set (0.05 sec)

mysql> SELECT * FROM case_test WHERE word COLLATE latin1_bin LIKE 'f%';
+---------+
| word |
+---------+
| froogle |
| flickr |
+---------+
2 rows in set (0.00 sec)



mysql> SELECT * FROM case_test WHERE word LIKE 'f%' COLLATE latin1_bin;
+---------+
| word |
+---------+
| froogle |
| flickr |
+---------+
2 rows in set (0.00 sec)

mysql> SELECT * FROM case_test WHERE word LIKE 'F%' COLLATE latin1_bin;
+---------+
| word |
+---------+
| Frank |
| FlicKr |
+---------+
4 rows in set (0.01 sec)


mysql> SELECT * FROM case_test WHERE word LIKE 'F%' COLLATE latin1_general_cs;
+---------+
| word |
+---------+
| Frank |
| FlicKr |
+---------+
4 rows in set (0.04 sec)



Now regarding "forcing" a column to always be lower case.

Unfortunately, we cannot do that in MySQL 4.x, other than converting a value to lower case before inserting at the application side.

Starting with MySQL 5, however we can use triggers as the following example shows:


mysql> create table case_test (word VARCHAR(10)) CHARACTER SET latin1;
Query OK, 0 rows affected (0.05 sec)
mysql> DELIMITER //
mysql> CREATE TRIGGER lowercased BEFORE INSERT ON case_test FOR EACH ROW BEGIN SET NEW.word=LOWER(NEW.word);
END;//
Query OK, 0 rows affected (0.00 sec)
mysql> INSERT INTO case_test VALUES ('Frank'),('Google'),('froogle'),('flickr'),('FlicKr');
Query OK, 7 rows affected (0.00 sec)
Records: 7 Duplicates: 0 Warnings: 0

mysql> SELECT * FROM case_test;
+---------+
| word |
+---------+
| frank |
| google |
| froogle |
| flickr |
| flickr |
+---------+
7 rows in set (0.00 sec)


I am interested in hearing about other approaches to achieving the same results.

Friday, September 08, 2006

MySQL Benchmarking 3: Installing Sysbench on Solaris 10

So I have been really busy lately dealing with a bunch of stuff including having to reset replication (twice) on some of the slaves that started lagging behind seriously. While I am determined to find and fix this replication lag issue, the majority of it comes from the huge spec differences between the master and the slaves.

Anyway, yesterday I got my plane ticket to go to MySQL Camp which is really exciting. I will be arriving there on Thursday night and leaving Sunday night on an overnight flight.

Last time when I blogged I was writing about MySQL benchmarking, so I will try to pick up where I left off.

I was having some compile issues when trying to compile sysbench on Solaris. When I was running ./configure I was getting the following warnings:

###############################
./configure output
###############################
configure: WARNING: signal.h: present but cannot be compiled
configure: WARNING: signal.h: check for missing prerequisite headers?
configure: WARNING: signal.h: see the Autoconf documentation
configure: WARNING: signal.h: section "Present But Cannot Be Compiled"
configure: WARNING: signal.h: proceeding with the preprocessor's result
configure: WARNING: signal.h: in the future, the compiler will take precedence
configure: WARNING: ## -------------------------------- ##
configure: WARNING: ## Report this to alexeyk at mysql dot com ##
configure: WARNING: ## -------------------------------- ##
configure: WARNING: thread.h: present but cannot be compiled
configure: WARNING: thread.h: check for missing prerequisite headers?
configure: WARNING: thread.h: see the Autoconf documentation
configure: WARNING: thread.h: section "Present But Cannot Be Compiled"
configure: WARNING: thread.h: proceeding with the preprocessor's result
configure: WARNING: thread.h: in the future, the compiler will take precedence
configure: WARNING: ## -------------------------------- ##
configure: WARNING: ## Report this to alexeyk at mysql dot com ##
configure: WARNING: ## -------------------------------- ##

#############################


Eventually the warnings went away when I used cc instead of gcc.

Running make after configure was producing
###########################
output of make
###########################
Making all in doc
make[1]: Entering directory `/home/fmashraqi/install/bench/sysbench-0.4.7/doc'
make[1]: Nothing to be done for `all'.
make[1]: Leaving directory `/home/fmashraqi/install/bench/sysbench-0.4.7/doc'
Making all in scripts
make[1]: Entering directory `/home/fmashraqi/install/bench/sysbench-0.4.7/scripts'
make[1]: Nothing to be done for `all'.
make[1]: Leaving directory `/home/fmashraqi/install/bench/sysbench-0.4.7/scripts'
Making all in sysbench
make[1]: Entering directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench'
Making all in drivers
make[2]: Entering directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench/drivers'
Making all in mysql
make[3]: Entering directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench/drivers/mysql'
if gcc -DHAVE_CONFIG_H -I. -I. -I../../../config -I/usr/local/mysql/include -xO3 -mt -D_FORTEC_ -xarch=v9 -xc99=none -I../.. -D_REENTRANT -D_XOPEN_SOURCE=500 -D_GNU_SOURCE -D_REENTRANT -g -O2 -MT libsbmysql_a-drv_mysql.o -MD -MP -MF ".deps/libsbmysql_a-drv_mysql.Tpo" -c -o libsbmysql_a-drv_mysql.o `test -f 'drv_mysql.c' || echo './'`drv_mysql.c; then mv -f ".deps/libsbmysql_a-drv_mysql.Tpo" ".deps/libsbmysql_a-drv_mysql.Po"; else rm -f ".deps/libsbmysql_a-drv_mysql.Tpo"; exit 1; fi
gcc: language c99=none not recognized
gcc: drv_mysql.c: linker input file unused because linking not done
mv: cannot access .deps/libsbmysql_a-drv_mysql.Tpo
make[3]: *** [libsbmysql_a-drv_mysql.o] Error 2
make[3]: Leaving directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench/drivers/mysql'
make[2 ]: *** [all-recursive] Error 1
make[2]: Leaving directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench/drivers'
make[1]: *** [all-recursive] Error 1
make[1]: Leaving directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench'
make: *** [all-recursive] Error 1


######################################


The problem was the flag
-xc99=none

which I removed using the following one liner
find . -name Makefile -print | while read i; do  sed -e "s/-xc99=none//g" $i > $i.orig; mv $i.orig $i; done


Then I started getting
Making all in .
make[2]: Entering directory `/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench'
/bin/bash ../libtool --tag=CC --mode=link /opt/SUNWspro/bin/cc -D_REENTRANT -g -lpthread -o sysbench -static sysbench.o sb_timer.o sb_options.o sb_logger.o db_driver.o tests/fileio/libsbfileio.a tests/threads/libsbthreads.a tests/memory/libsbmemory.a tests/cpu/libsbcpu.a tests/oltp/libsboltp.a tests/mutex/libsbmutex.a drivers/mysql/libsbmysql.a -xarch=v9 -L/usr/local/mysql/lib -lmysqlclient_r -lz -lposix4 -lcrypt -lgen -lsocket -lnsl -lm -lmtmalloc -lrt -lm
/opt/SUNWspro/bin/cc -D_REENTRANT -g -o sysbench sysbench.o sb_timer.o sb_options.o sb_logger.o db_driver.o -xarch=v9 -lpthread tests/fileio/libsbfileio.a tests/threads/libsbthreads.a tests/memory/libsbmemory.a tests/cpu/libsbcpu.a tests/oltp/libsboltp.a tests/mutex/libsbmutex.a drivers/mysql/libsbmysql.a -L/usr/local/mysql/lib -lmysqlclient_r -lz -lposix4 -lcrypt -lgen -lsocket -lnsl -lmtmalloc -lrt -lm
ld: fatal: file sysbench.o: wrong ELF class: ELFCLASS32
ld: fatal: File processing errors. No output written to sysbench


The reason for these errros was the conflict when trying to link 32-bit binaries with 64-bit binaries. To address that issue, I set the following in my environment.
CFLAGS=-xarch=v9

Then I tried to build once again. Here's the summarized process


# Removed the current sysbench source directory
rm -r -f sysbench-0.4.7
# Extracted a fresh copy from the tarball.
tar -xf sysbench-0.4.7.tar
# Changed my pwd to sysbench-0.4.7
cd sysbench-0.4.7
# Set up my environment
CC=/opt/SUNWspro/bin/cc
CFLAGS=-xarch=v9
LD_LIBRARY_PATH=/usr/local/mysql/lib:/usr/ccs/lib:/usr/lib:/usr/local/lib:/lib:/usr/ucblib
PATH=/opt/SUNWspro/bin:/opt/SUNWspro/bin:/usr/sbin:/usr/bin:/usr/local/bin:.:/usr/ccs/bin:/usr/local/mysql/bin:/usr/local/bin:.:/usr/ccs/bin:/usr/local/mysql/bin
# Cleaned out -xc99=none which was being produced by mysql_config by using a slightly modified version of the one liner recommended in this thread
find . -name Makefile -print | while read i; do sed -e "s/-xc99=none//g" $i > $i.orig; mv $i.orig $i; done
# run make
make
# finally install
make install


This time it worked! Yay!

Here's how my environment was setup
TERM=xterm
SHELL=/sbin/sh
SSH_CLIENT=192.168.1.11 34203 22
OLDPWD=/home/fmashraqi/install/bench/sysbench-0.4.7/sysbench
SSH_TTY=/dev/pts/5
USER=root
LD_LIBRARY_PATH=/usr/local/mysql/lib:/usr/ccs/lib:/usr/lib:/usr/local/lib:/lib:/usr/ucblib
PATH=/opt/SUNWspro/bin:/opt/SUNWspro/bin:/usr/sbin:/usr/bin:/usr/local/bin:.:/usr/ccs/bin:/usr/local/mysql/bin:/usr/local/bin:.:/usr/ccs/bin:/usr/local/mysql/bin
MAIL=/var/mail//root
PWD=/home/fmashraqi/install/bench/sysbench-0.4.7
TZ=US/Eastern
PS1=[\u@\h:\w]
SHLVL=1
HOME=/
CFLAGS=-xarch=v9
LOGNAME=root
SSH_CONNECTION=192.168.1.11 34203 192.168.1.192 22
CC=/opt/SUNWspro/bin/cc
_=/usr/bin/env


Now let's run sysbench and do a test run
[root@db32:/home/fmashraqi/install/bench/sysbench-0.4.7] sysbench --test=cpu --cpu-max-prime=20000 run
sysbench v0.4.7: multi-threaded system evaluation benchmark

Running the test with following options:
Number of threads: 1

Doing CPU performance benchmark

Threads started!
Done.

Maximum prime number checked in CPU test: 20000


Test execution summary:
total time: 281.8175s
total number of events: 10000
total time taken by event execution: 281.8014
per-request statistics:
min: 0.0281s
avg: 0.0282s
max: 0.0369s
approx. 95 percentile: 0.0283s

Threads fairness:
events (avg/stddev): 10000.0000/0.00
execution time (avg/stddev): 281.8014/0.00

Many thanks to folks at Sun and OpenSolaris.org for their assistance.

References:
Wrong ELF Class
Porting from Solaris to RedHat
Downloading cc (as part of Sun Studio 11)
Sun Studio 11
Compiling Sysbench on Solaris 10

Previously:
MySQL Benchmarking Part 1
MySQL Benchmarking Part 2

Some additional tips:
MySQL compile flags
[$] /usr/local/mysql/bin/mysql_config --cflags
-I/usr/local/mysql/include -xO3 -mt -D_FORTEC_ -xarch=v9 -xc99=none

The -xarch=v9 is a 64-bit flag
Don't confuse CC (C++) with cc.
-O2 -MT -MB are gcc options whereas -xO3 -md -xarch are cc options