mysql - ディスクからファイルを読み取るための MySQL UDF: MySQL は 2 回目の UDF 呼び出しごとにクラッシュし続けます

Question

ディスク上の特定のディレクトリからテキスト ファイルの内容を返すことになっている MySQL UDF getFile() を作成しようとしています。問題は、呼び出しが 1 回または 2 回機能することですが、UDF を 2 回または 3 回呼び出すと、MySQL サーバーがクラッシュします。

mysql コンソールから getFile() を直接呼び出してもエラーを再現できません。ここでは問題なく動作しているようです。ストアド プロシージャから UDF を呼び出した場合にのみ発生するようです。大きな「mailConfirmation」（45k）と「mailProtocol」（88k）ファイルを省略して、小さな（2.5k）「session」ファイルのみを呼び出すとエラーも消えるので、ファイルに関係があるようですサイズ。

MySQL バージョン: 5.1.49-3

OS: 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自体ではなく、ストアドプロシージャからの呼び出しにあるように見えることがわかりました.mysqlコンソールからではなく、SPROCから呼び出したときにのみエラーが発生します。

この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) でのみ機能します。ただし、他の文字列の長さは試していません。

Answer 2

うーん。が表示されmallocますが、対応するが表示されませんfree。

割り当てられたメモリの割り当てを解除するのはUDFの責任ではありませんか？そして、それはUDF x_deinit関数へのサーバーの呼び出しの目的ではありませんか？

通常、malloc_init関数で実行され、対応freeするものが_deinit関数で実行されることが期待されます。

しかし、私はMySQLUDFのSMEではありません。そのメモリがどこで割り当て解除されているのか疑問に思っています。

Answer 3

「*length = strlen(result)」という行を疑っています。strlen() は '\0' で停止するため、明らかに何かが間違っています。

私は UDF の専門家ではありませんが、MySQL は「文字列」(REATE FUNCTION getFile RETURNS STRING) がヌル終了以外のものであることを期待しているのでしょうか?

また、補足として、char() は必ずしもバイトではありません。ftell() はサイズをバイト単位で返すため、sizeof(char) を掛けるのは実際には間違っています。これを malloc に渡す場合は、sizeof(char) で割ります。通常、char はバイトであるため、ほとんどのアーキテクチャでは問題になりません。

最後に -- rewind() と fseek() を混在させても安全ですか? rewind は fseek(f, 0, SEEK_SET) と完全に同等ですか、それとも C のランタイム バッファ IO と関係がありますか?