用于从磁盘 : MySQL keeps crashing on every second UDF call 读取文件的 MySQL UDF

Question

我正在尝试创建一个 MySQL UDF getFile()，它应该从磁盘上的某个目录返回文本文件的内容。问题是调用一次或两次有效，但在第二次或第三次调用 UDF 时，MySQL 服务器崩溃。

我无法通过直接从 mysql 控制台调用 getFile() 来重现错误，在这里它似乎工作正常 - 它似乎只在我从存储过程调用 UDF 时发生。当我只调用小的(2.5 k)“ session ”文件而忽略较大的“mailConfirmation”(45 k)和“mailProtocol”(88 k)文件时，错误也会消失，所以它似乎与文件有关大小。

MySQL版本:5.1.49-3

操作系统:Debian 6 Squeeze

如有任何建议或想法，我们将不胜感激 - 提前致谢!

这是 UDF:

/*
 * Skeleton libary for MySQL.
 * A set of MySQL user defined functions (UDF) to [DESCRIPTION]
 *
 * Copyright (C) [YYYY YOUR NAME <YOU@EXAMPLE.COM>]
 *
 * This library is free software; you can redistribute it and/or modify it
 * under the terms of the GNU Lesser General Public License as published by
 * the Free Software Foundation; either version 2.1 of the License, or (at
 * your option) any later version.
 *
 * This library is distributed in the hope that it will be useful, but
 * WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU Lesser
 * General Public License for more details.
 *
 * You should have received a copy of the GNU Lesser General Public License
 * along with this library; if not, write to the Free Software Foundation, Inc.,
 * 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
 */

#include "mysqludf.h"

/* For Windows, define PACKAGE_STRING in the VS project */
#ifndef __WIN__
#include "config.h"
#endif

/* These must be right or mysqld will not find the symbol! */
#ifdef  __cplusplus
extern "C" {
#endif
    DLLEXP my_bool getFile_init(UDF_INIT *initid, UDF_ARGS *args, char *message);
    DLLEXP void getFile_deinit(UDF_INIT *initid);
    DLLEXP char *getFile(UDF_INIT *initid, UDF_ARGS *args, char *result, unsigned long *length, char *is_null, char *error);
#ifdef  __cplusplus
}
#endif


/*
 * Output the library version.
 * dbrw_info()
 */

my_bool getFile_init(UDF_INIT *initid, UDF_ARGS *args, char *message)
{
    if(!(args->arg_count == 3))
    {
        strcpy(message, "Three arguments expected! (table, uuid, column)");
        //strcpy(message, "Error");
        return 1;
    }

    char *input_file_name;
    asprintf(&input_file_name, "%s%s%s%s%s%s", "/var/lib/mysqlFiles/", args->args[0], "/", args->args[1], "_", args->args[2]);

    if (FILE * file = fopen(input_file_name, "r"))
    {
        fclose(file);
    }
    else
    {
        strcpy(message, "File not found!");
        //strcpy(message, "Error");
        return 1;
    }

    return 0;
}

void getFile_deinit(UDF_INIT *initid)
{
}

char* getFile(UDF_INIT *initid, UDF_ARGS *args, char* result, unsigned long* length,    char *is_null, char *error)
{
    char *input_file_name;
    asprintf(&input_file_name, "%s%s%s%s%s%s", "/var/lib/mysqlFiles/", args->args[0], "/", args->args[1], "_", args->args[2]);

    char *file_contents;
    long input_file_size;
    FILE *input_file = fopen(input_file_name, "rb");
    fseek(input_file, 0, SEEK_END);
    input_file_size = ftell(input_file);
    rewind(input_file);
    file_contents = (char*) malloc(input_file_size * (sizeof(char)));
    fread(file_contents, sizeof(char), input_file_size, input_file);
    fclose(input_file);

    result=file_contents;

    *length = strlen(result);       
    return result;
}

正在从存储过程调用 UDF:

CREATE PROCEDURE getOrder
(
    IN authKey_in CHAR(255),
    IN orderNumber  CHAR(255)
)

BEGIN
    DECLARE customerId INTEGER(11);
    DECLARE orderUUID CHAR(32);

    SET customerId=getCustomerId(authKey_in);

    IF customerId=-1 THEN
        SELECT 'authKey_expired' AS error;
    ELSEIF customerId=-2 THEN
        SELECT 'authKey_invalid' AS error;
    ELSE

        SELECT order_uuid
        FROM `order`
        WHERE 
            order_orderNumber=orderNumber AND
            order_customer_id=customerId
        INTO orderUUID;


        SELECT
            order_customer_id,
            order_hasBeenCollected,
            order_id,
            order_orderNumber,
            order_orderValue,
            order_paymentMethod,
            order_sofortConfirmation,
            order_synced,
            order_timestamp,
            order_timestamp_lastChange,
            order_uuid,
            getFile("order", orderUUID, "session") AS order_session,
            getFile("order", orderUUID, "mailProtocol") AS order_confirmationMail_protocol,
            getFile("order", orderUUID, "mailConfirmation") AS order_confirmationMail_text,
            DATE_FORMAT(
                        order_timestamp,
                        "%d.%m.%Y"
                       ) AS order_timestamp_readable
        FROM `order`
        WHERE
            order_orderNumber=orderNumber AND
            order_customer_id=customerId;

    END IF;
END|

这是来自/var/log/syslog 的 MySQL 输出:

Jan 11 00:01:21 devserver mysqld: 130111  0:01:21 - mysqld got signal 11 ;
Jan 11 00:01:21 devserver mysqld: This could be because you hit a bug. It is also possible that this binary
Jan 11 00:01:21 devserver mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Jan 11 00:01:21 devserver mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Jan 11 00:01:21 devserver mysqld: We will try our best to scrape up some info that will hopefully help diagnose
Jan 11 00:01:21 devserver mysqld: the problem, but since we have already crashed, something is definitely wrong
Jan 11 00:01:21 devserver mysqld: and this may fail.
Jan 11 00:01:21 devserver mysqld: 
Jan 11 00:01:21 devserver mysqld: key_buffer_size=4294967296
Jan 11 00:01:21 devserver mysqld: read_buffer_size=131072
Jan 11 00:01:21 devserver mysqld: max_used_connections=2
Jan 11 00:01:21 devserver mysqld: max_threads=50
Jan 11 00:01:21 devserver mysqld: threads_connected=2
Jan 11 00:01:21 devserver mysqld: It is possible that mysqld could use up to 
Jan 11 00:01:21 devserver mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4303618 K
Jan 11 00:01:21 devserver mysqld: bytes of memory
Jan 11 00:01:21 devserver mysqld: Hope that's ok; if not, decrease some variables in the equation.
Jan 11 00:01:21 devserver mysqld: 
Jan 11 00:01:21 devserver mysqld: thd: 0x7f8291eae3f0
Jan 11 00:01:21 devserver mysqld: Attempting backtrace. You can use the following information to find out
Jan 11 00:01:21 devserver mysqld: where mysqld died. If you see no messages after this, something went
Jan 11 00:01:21 devserver mysqld: terribly wrong...
Jan 11 00:01:21 devserver mysqld: stack_bottom = 0x7f81867e0e88 thread_stack 0x30000
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x29) [0x7f82910e8829]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(handle_segfault+0x404) [0x7f8290df2b14]
Jan 11 00:01:21 devserver mysqld: /lib/libpthread.so.0(+0xeff0) [0x7f8290654ff0]
Jan 11 00:01:21 devserver mysqld: /lib/libc.so.6(fseek+0x1) [0x7f828f12b891]
Jan 11 00:01:21 devserver mysqld: /usr/lib/mysql/plugin/dbrw.so(getFile+0x7e) [0x7f81867e2c1e]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(Item_func_udf_str::val_str(String*)+0x80) [0x7f8290d64900]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(Item::send(Protocol*, String*)+0x3e) [0x7f8290d30eae]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(select_send::send_data(List<Item>&)+0x107) [0x7f8290de05f7]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(+0x3d1b7a) [0x7f8290e53b7a]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(+0x3dda00) [0x7f8290e5fa00]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(JOIN::exec()+0xba5) [0x7f8290e748f5]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*)+0x142) [0x7f8290e70622]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(handle_select(THD*, st_lex*, select_result*, unsigned long)+0x174) [0x7f8290e75f24]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(+0x37edfa) [0x7f8290e00dfa]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(mysql_execute_command(THD*)+0x516) [0x7f8290e04df6]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(sp_instr_stmt::exec_core(THD*, unsigned int*)+0x1c) [0x7f8290f6047c]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*)+0x1c5) [0x7f8290f65c65]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(sp_instr_stmt::execute(THD*, unsigned int*)+0x124) [0x7f8290f65f74]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(sp_head::execute(THD*)+0x5d3) [0x7f8290f62fa3]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(sp_head::execute_procedure(THD*, List<Item>*)+0x51c) [0x7f8290f6472c]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(mysql_execute_command(THD*)+0x2736) [0x7f8290e07016]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x3fb) [0x7f8290e0a30b]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0xb34) [0x7f8290e0ae54]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(do_command(THD*)+0xea) [0x7f8290e0bd3a]
Jan 11 00:01:21 devserver mysqld: /usr/sbin/mysqld(handle_one_connection+0x235) [0x7f8290dfda25]
Jan 11 00:01:21 devserver mysqld: /lib/libpthread.so.0(+0x68ca) [0x7f829064c8ca]
Jan 11 00:01:21 devserver mysqld: /lib/libc.so.6(clone+0x6d) [0x7f828f19492d]
Jan 11 00:01:21 devserver mysqld: Trying to get some variables.
Jan 11 00:01:21 devserver mysqld: Some pointers may be invalid and cause the dump to abort...
Jan 11 00:01:21 devserver mysqld: thd->query at 0x7f8291eea5c8 = SELECT
Jan 11 00:01:21 devserver mysqld:             order_customer_id,
Jan 11 00:01:21 devserver mysqld:             order_hasBeenCollected,
Jan 11 00:01:21 devserver mysqld:             order_id,
Jan 11 00:01:21 devserver mysqld:             order_orderNumber,
Jan 11 00:01:21 devserver mysqld:             order_orderValue,
Jan 11 00:01:21 devserver mysqld:             order_paymentMethod,
Jan 11 00:01:21 devserver mysqld:             order_sofortConfirmation,
Jan 11 00:01:21 devserver mysqld:             order_synced,
Jan 11 00:01:21 devserver mysqld:             order_timestamp,
Jan 11 00:01:21 devserver mysqld:             order_timestamp_lastChange,
Jan 11 00:01:21 devserver mysqld:             order_uuid,
Jan 11 00:01:21 devserver mysqld:             getFile("order",  NAME_CONST('orderUUID',_latin1'8A507ECC5B4F11E2B385F526BF61D66D' COLLATE 'latin1_swedish_ci'), "session") AS order_session,
Jan 11 00:01:21 devserver mysqld:             getFile("order",  NAME_CONST('orderUUID',_latin1'8A507ECC5B4F11E2B385F526BF61D66D' COLLATE 'latin1_swedish_ci'), "mailProtocol") AS order_confirmationMail_protocol,
Jan 11 00:01:21 devserver mysqld:             getFile("order",  NAME_CONST('orderUUID',_latin1'8A507ECC5B4F11E2B385F526BF61D66D' COLLATE 'latin1_swedish_ci'), "mailConfirmation") AS order_confirmationMail_text,
Jan 11 00:01:21 devserver mysqld:             DATE_FORMAT(
Jan 11 00:01:21 devserver mysqld:                         order_timestamp,
Jan 11 00:01:21 devserver mysqld:                         "%d.%m.%Y"
Jan 11 00:01:21 devserver mysqld:                        ) AS order_timestamp_readable
Jan 11 00:01:21 devserver mysqld:         FROM `o
Jan 11 00:01:21 devserver mysqld: thd->thread_id=17
Jan 11 00:01:21 devserver mysqld: thd->killed=NOT_KILLED
Jan 11 00:01:21 devserver mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Jan 11 00:01:21 devserver mysqld: information that should help you find out what is causing the crash.
Jan 11 00:01:21 devserver mysqld_safe: Number of processes running now: 0
Jan 11 00:01:21 devserver mysqld_safe: mysqld restarted
Jan 11 00:01:22 devserver mysqld: 130111  0:01:22 [Note] Plugin 'FEDERATED' is disabled.
Jan 11 00:01:22 devserver mysqld: InnoDB: Log scan progressed past the checkpoint lsn 38 555424888
Jan 11 00:01:22 devserver mysqld: 130111  0:01:22  InnoDB: Database was not shut down normally!
Jan 11 00:01:22 devserver mysqld: InnoDB: Starting crash recovery.
Jan 11 00:01:22 devserver mysqld: InnoDB: Reading tablespace information from the .ibd files...
Jan 11 00:01:25 devserver mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
Jan 11 00:01:25 devserver mysqld: InnoDB: buffer...
Jan 11 00:01:25 devserver mysqld: InnoDB: Doing recovery: scanned up to log sequence number 38 555424898
Jan 11 00:01:26 devserver mysqld: 130111  0:01:26  InnoDB: Started; log sequence number 38 555424898
Jan 11 00:01:26 devserver mysqld: 130111  0:01:26 [ERROR] Can't open shared library 'lib_mysqludf_preg.so' (errno: 0 /usr/lib/mysql/plugin/lib_mysqludf_preg.so: cannot open shared object file: No such file or directory)
Jan 11 00:01:26 devserver last message repeated 5 times
Jan 11 00:01:26 devserver mysqld: 130111  0:01:26 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--relay-log=mysqld-relay-bin' to avoid this problem.
Jan 11 00:01:26 devserver mysqld: 130111  0:01:26 [Note] Event Scheduler: Loaded 0 events
Jan 11 00:01:26 devserver mysqld: 130111  0:01:26 [Note] /usr/sbin/mysqld: ready for connections.
Jan 11 00:01:26 devserver mysqld: Version: '5.1.49-3'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)
Jan 11 00:01:27 devserver mysqld: 130111  0:01:27 [ERROR] /usr/sbin/mysqld: Table './mysql/proc' is marked as crashed and should be repaired
Jan 11 00:01:27 devserver mysqld: 130111  0:01:27 [Warning] Checking table:   './mysql/proc'

这些是正在读取的文件:

[root@devserver order]# ls -l
total 140
-rw-rw-rw- 1 mysql staff 45366 Jan 10 18:59 8A507ECC5B4F11E2B385F526BF61D66D_mailConfirmation
-rw-rw-rw- 1 mysql staff 88389 Jan 10 18:59 8A507ECC5B4F11E2B385F526BF61D66D_mailProtocol
-rw-rw-rw- 1 mysql staff  2518 Jan 10 18:59 8A507ECC5B4F11E2B385F526BF61D66D_session

最后是创建 UDF 的语句:

USE mysql;

DROP FUNCTION IF EXISTS getFile;
CREATE FUNCTION getFile RETURNS STRING SONAME 'dbrw.so';

Answer 1

经过几个小时的测试和搜索，我终于发现问题似乎不是 UDF 本身，而是它从存储过程调用 - 只有当从 SPROC 调用它时才会发生错误，而不是从 mysql 控制台调用它。

我偶然发现了这个 mysql 错误报告:

http://bugs.mysql.com/bug.php?id=25207

[20 Dec 2006 10:16] Zigmund Bulinsh
Description:
I have a function defined thgrough UDF DLL.
it is named as RaiseError (RaiseError_init alwais returns 1 and error message always equals to first parameter).

How to repeat:
select RaiseError('Some error'); raises MySQL error: 'Some error'

Now I define procedure which call this function (more comfortable way to use it)

CREATE PROCEDURE `Error`(p_text char(255))
begin
  declare x int;
  set x = RaiseError(p_text);
end

After calling this procedure from anywhere - MySQL crashes...

But this version works fine:

CREATE PROCEDURE `Error`(p_text VARchar(255))
begin
  declare x int;
  set x = RaiseError(p_text);
end

这份错误报告给了我关键线索。我试着玩弄 UDF 参数的数据类型，我注意到当我使用字符串而不是变量时不会发生错误。

这会导致服务器崩溃:

DECLARE orderUUID CHAR(32);
...
getFile("order", orderUUID, "session") AS order_session,
getFile("order", orderUUID, "mailProtocol") AS order_confirmationMail_protocol,
getFile("order", orderUUID, "mailConfirmation") AS order_confirmationMail_text,

虽然这很完美:

getFile("order", '8A507ECC5B4F11E2B385F526BF61D66D', "session") AS order_session,
getFile("order", '8A507ECC5B4F11E2B385F526BF61D66D', "mailProtocol") AS order_confirmationMail_protocol,
getFile("order", '8A507ECC5B4F11E2B385F526BF61D66D', "mailConfirmation") AS order_confirmationMail_text,

所以我将数据类型从 CHAR(32) 更改为 VARCHAR(255)，服务器不再崩溃:

DECLARE orderUUID VARCHAR(255);
...
getFile("order", orderUUID, "session") AS order_session,
getFile("order", orderUUID, "mailProtocol") AS order_confirmationMail_protocol,
getFile("order", orderUUID, "mailConfirmation") AS order_confirmationMail_text,

它不适用于 CHAR(255) 和 VARCHAR(32)，它只适用于 VARCHAR(255)。不过，我还没有尝试过其他字符串长度。