MySQL Bugs: #14467: Occasionally connect or query problems under load conditions

Bug #14467	Occasionally connect or query problems under load conditions
Submitted:	29 Oct 2005 16:01	Modified:	2 Nov 2005 10:39
Reporter:	Thomas Adamek	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server	Severity:	S2 (Serious)
Version:	MySQL 5.0.15	OS:	Linux (Linux glibc 2.3 / Kernel 2.4.31)
Assigned to:		CPU Architecture:	Any

Description:
Since we upgraded from MySQL 4.1.14 to the current release 5.0.15, the following problems occur when the server works under production conditions:

In PHP and Perl scripts connection is not possible, the scripts complain about "Cannot connect to local MySQL server through socket '/var/lib/mysql/mysql.sock'", sometimes in queries with error 2006, message "MySQL server has gone away" but definitely MySQL server is still running and up, queries with mysql shell command still work. max_connections is set to 250 and should not been exceeded.

Tables have been upgraded with fix privileges script, all tables are in MYISAM format, all tables have been optimized/repaired lately to ensure data consistency.

MySQL has been compiled using the following options:

./configure --prefix=/usr/local/mysql-5.0.15 \
--enable-assembler \
--enable-local-infile \
--with-archive-storage-engine \
--with-berkeley-db \
--with-blackhole-storage-engine \
--with-charset=latin1 \
--with-collation=latin1_german1_ci \
--with-csv-storage-engine \
--with-embedded-server \
--with-extra-charsets=all \
--with-federated-storage-engine \
--with-innodb \
--with-openssl \
--with-openssl-includes=/usr/local/ssl/include \
--with-openssl-libs=/usr/local/ssl/lib \
--with-mysqlfs \
--with-server-suffix=TRIO \
--with-unix-socket-path=/var/lib/mysql/mysql.sock \
--with-vio

How to repeat:
This is hard to repeat because it occurs only sometimes (I get e-mail reports from the machine whenever a mysql connect or query fails and it happened every few minutes). Downgrading to MySQL 4.1.4 without changing anything (only necessity to recompile Perl DBD-mysql-3.0002 because libmysqlclient is version dependent).

Suggested fix:
It seems that one of the MySQL sub processes which are running the daemon dies.

P.S.: Of course I have recompiled PHP 5.0.5 and DBD-mysql perl module using the new 5.0 client libraries after installing MySQL 5.0 to ensure version consistency of client and server side.

Thank you for a problem report.

Please, send the results of SHOW PROCESSLIST and SHOW STATUS commands executed next time this connect problem happens. Your error log may be useful too. The ideas of how to reproduce your typical workload that leads to such a results are welcomed.

I changed the severity, because according to your description you have no server crashes.

Hello Valeriy,

thank you very much for your fast reply. Below you can find a section of the . The process crash of a mysqld sub process seems to appear whenever a "INSERT DELAYED" command is executed. I am not sure if it is really the reason but all clues seem to point that:

051029 17:32:06 InnoDB: Started; log sequence number 0 59352
051029 17:32:06 [Note] Recovering after a crash using SERVERNAME-bin
051029 17:32:06 [Note] Starting crash recovery...
051029 17:32:06 [Note] Crash recovery finished.
051029 17:32:06 [Note] /usr/local/mysql-5.0.15/libexec/mysqld: ready for connections.
Version: '5.0.15TRIO-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Source distribution
mysqld got signal 11;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=33554432
read_buffer_size=2093056
max_used_connections=2
max_connections=250
threads_connected=2
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 1055766 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x8b3dc58
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
Cannot determine thread, fp=0x45ff3978, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x8170b7e
0x4018f96c
0x403831ba
0x80f76d2
0x81b66fa
0x81dd07a
0x818c463
0x8191230
0x8186987
0x8185dde
0x8184cdd
0x40189f60
0x403e4327
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Reso
lved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8bcac18 = INSERT DELAYED INTO globallog (
shopid,
systime,
clientip,
identuser,
authuser,
logtime,
request,
status,
bytes,
referer,
useragent,
shophost
) VALUES (
100,
1130599930,
'84.177.165.106',
'-',
'-',
'[29/Oct/2005:17:10:10 +0200]',
'"GET /DE/cms.php HTTP/1.1"',
200,
'-',
'"http://www.XYZ.de/xyz/cms.php?page=welcome"',
'"Mozilla/5.0 (Windows; U; Windows NT 5.1; de-DE; rv:1.7.12) Gecko/20050919 Firefox/1.0.7"',
'www.XYZ.de'
)
thd->thread_id=6
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
Number of processes running now: 0
051029 17:32:10 mysqld restarted

BTW: In that latter report I have changed the domain name to "XYZ" just for some reasons  ...

Can you, please, send the resolved stack trace? The steps you need to perform to get it is described in the manual:

http://dev.mysql.com/doc/refman/5.0/en/using-stack-trace.html

Dear Valeriy,

thank you for posting a feedback. Below you can find the output of the stack analyzation:

0x8170b7e handle_segfault + 542
0x4018f96c _end + 934378076
0x403831ba _end + 936424106
0x80f76d2 _ZN11Item_string13save_in_fieldEP5Fieldb + 66
0x81b66fa _Z36fill_record_n_invoke_before_triggersP3THDR4ListI4ItemES4_bP19Table_triggers_list14trg_event_type + 90
0x81dd07a _Z12mysql_insertP3THDP13st_table_listR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb + 1594
0x818c463 _Z21mysql_execute_commandP3THD + 19251
0x8191230 _Z11mysql_parseP3THDPcj + 336
0x8186987 _Z16dispatch_command19enum_server_commandP3THDPcj + 2887
0x8185dde _Z10do_commandP3THD + 126
0x8184cdd handle_one_connection + 477
0x40189f60 _end + 934355024
0x403e4327 _end + 936821783

Best regards
Thomas

Thank you for the additional information. Please, send the results of SHOW CREATE TABLE globallog command.

How many rows are there in that table? Can you upload a dump of your real data from the database where this problem occures?

Are there any triggers defined for that table, by the way?

The CREATE TABLE is:

CREATE TABLE `globallog` (
  `countid` int(10) unsigned NOT NULL auto_increment,
  `shopid` int(10) unsigned NOT NULL default '0',
  `systime` int(10) unsigned NOT NULL default '0',
  `clientip` varchar(32) collate latin1_german1_ci NOT NULL default '',
  `identuser` varchar(16) collate latin1_german1_ci NOT NULL default '',
  `authuser` varchar(16) collate latin1_german1_ci NOT NULL default '',
  `logtime` varchar(40) collate latin1_german1_ci NOT NULL default '',
  `request` text collate latin1_german1_ci NOT NULL,
  `status` int(10) unsigned NOT NULL default '0',
  `bytes` varchar(8) collate latin1_german1_ci NOT NULL default '',
  `referer` text collate latin1_german1_ci NOT NULL,
  `useragent` varchar(200) collate latin1_german1_ci NOT NULL default '',
  `shophost` varchar(200) collate latin1_german1_ci default NULL,
  `timestamp` timestamp NOT NULL default CURRENT_TIMESTAMP on update CURRENT_TIMESTAMP,
  PRIMARY KEY  (`countid`),
  KEY `shopid` (`shopid`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1 COLLATE=latin1_german1_ci PACK_KEYS=1

The are no triggers in that table, the current row count is 464, the table is flushed 4 times a day after creating statistics from those entries, so it never exceeds a few thousand entries.

The crashes appeared over one day, before and after it was flushed and filled with new data.

- Thomas

OK. So, you have upgraded from 4.1.x, you have varchar columns in the table, and you have no triggers... Then it almost surely a duplicate of http://bugs.mysql.com/bug.php?id=13707. Please, wait for the fix to that bug to be released officially.