一次Mysql故障诊断过程
那天因参加MS的新品发布大会，中午就离开办公室，当我正在出租车上前往会场的途中，同事打电话来说主数据库出现写保护错误。这可不得了，所有的应用都靠这个数据库呀，我心里默念：千万不要出漏子，否则就不能参会了！于是我在电话里交代同事重启mysql数据库试试，还好，重启后问题解决。
一散会，就赶紧上去找故障原因。这里先描述一下平台环境，把逻辑关系弄清楚。在这个应用中，由一个web前段服务器，一个tomcat应用服务器及一个mysql服务器构成，所有的系统都是linux。用户的请求先到前端的apache服务器，如果请求页面是.jsp，apache就把请求转交给tomcat服务器，tomcat再从数据库获取数据或向数据库插入记录。这是典型的3层应用逻辑。
登录到数据库mysql服务器，用mysql客户端连接mysql数据库，执行命令 mysql > show processlist; 没发现什么异常，负载也很低。看来从这里看不出什么名堂。接下来当然该看mysql错误日志，发现如下异常：
|
080313 11:25:35 InnoDB: Error: cannot allocate 1064960 bytes of
InnoDB: memory with malloc! Total allocated memory
InnoDB: by InnoDB 1233305429 bytes. Operating system errno: 12
InnoDB: Check if you should increase the swap file or
InnoDB: ulimits of your operating system.
InnoDB: On FreeBSD check you have compiled the OS with
InnoDB: a big enough maximum process size.
InnoDB: Note that in most 32-bit computers the process
InnoDB: memory space is limited to 2 GB or 4 GB.
InnoDB: We keep retrying the allocation for 60 seconds...
080313 11:26:08 [ERROR] /usr/local/mysql/bin/mysqld: Sort aborted
080313 11:26:19 InnoDB: Error: cannot allocate 1064960 bytes of
InnoDB: memory with malloc! Total allocated memory
|
这个报错的大意是：内存基本耗尽，没有再可以分配的空间。由此判断是什么东西产生巨大的负荷导致系统内存被榨干了。不过现在数据库服务器已经趋于平稳，暂时查不到什么原因引起这个故障。
基本情况掌握了，停下来休息片刻，于是顺手收一下邮件，乖乖，来了一封报警邮件，赶紧打开，其内容如下：
|
***** Nagios 2.9 *****
Notification Type: PROBLEM
Service: check_load
Host: tomcat nch100
Address: 61.154.105.100
State: WARNING
Date/Time: Thu Mar 13 10:59:53 CST 2008
Additional Info:
WARNING - load average: 3.94, 8.56, 9.17
|
报警消息表明主机61.154.105.100在10:59的这个时间负载过大。而这个主机正好是tomcat服务器,看来问题就在这个上面.为了近一步确认自己的想法,我来查看一下网络流量:
从流量图可以看出,产生异常流量的时间正好与报警信息的时间一致,再给同事打电话,问：“你们都在61.154.105.100 这个机器上干了啥?”，答：“执行了一条不正确的sql语句，发现问题后取消这个sql语句”。至此，原因查明！
