1

I'm trying to create an MySQL UDF getFile() which is supposed to return the contents of a text file from a certain directory on disk. The problem is that the call works once or twice, but upon calling the UDF for a second or third time the MySQL server crashes.

I can't reproduce the error by calling getFile() directly from the mysql console, here it seems to work fine - it seems to occur only when I call the UDF from the stored procedure. The error also disappears when I call only the small (2.5 k) "session" file while omitting the bigger "mailConfirmation" (45 k) and "mailProtocol" (88 k) files, so it seems to have something to do with the file size.

MySQL version: 5.1.49-3

OS: Debian 6 Squeeze

Any suggestions or ideas will be greatly appreciated - thanks in advance!

This is the UDF:

/*
 * Skeleton libary for MySQL.
 * A set of MySQL user defined functions (UDF) to [DESCRIPTION]
 *
 * Copyright (C) [YYYY YOUR NAME <[email protected]>]
 *
 * 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;
}

The UDF is being called from a stored procedure:

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|

And this is MySQL's output from /var/log/syslog:

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'

These are the files that are being read:

[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

And finally the statement to create the UDF:

USE mysql;

DROP FUNCTION IF EXISTS getFile;
CREATE FUNCTION getFile RETURNS STRING SONAME 'dbrw.so';
1
  • You'll probably be more likely to get some help if you can greatly simplify your example. Chances are only a small part of your UDF and stored procedure is relevant to the problem. Commented Jan 10, 2013 at 23:43

3 Answers 3

1

After hours of testing and searching I finally found out that the problem doesn't seem to be the UDF itself but its call from the stored procedure - the error occurs only when calling it from the SPROC, not from the mysql console.

I stumbled across this mysql bug report:

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

This bug report gave me the crucial clue. I tried playing around with the data types of the UDF arguments and I noticed that the error does not occur when I use a string instead of a variable.

This causes the server to crash:

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,

while this works perfectly:

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

So I changed the data type from CHAR(32) to VARCHAR(255) and the server doesn't crash anymore:

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,

It doesn't work neither with CHAR(255) nor with VARCHAR(32), it works only with VARCHAR(255). I haven't tried other string lengths though.

Sign up to request clarification or add additional context in comments.

Comments

0

Hmmm. I see a malloc, but I don't see a corresponding free.

Isn't it the responsibility of the UDF to deallocate any memory that it's allocated? And isn't that the purpose of the server's call to the UDF x_deinit function?

Typically, we'd expect to see any malloc performed in the _init function, and the corresponding free to be in the _deinit function.

But, I am not a SME on MySQL UDFs. I'm just wondering where that memory is getting deallocated.

1 Comment

Thanks a lot for your hint, in fact I have been playing around with free() because I suspected the same problem with malloc() but as I'm not a C expert (perl is so much easier!!! ;-) ) I really didn't know what I was doing... how would you put free() in _deinit?
0

I suspect the line "*length = strlen(result)". strlen() will stop at '\0', and so something is obviously wrong.

I'm no UDF expert, but could it be that MySQL is expecting a "String" (REATE FUNCTION getFile RETURNS STRING) to be something other than null-terminated?

Also, as a side note: a char() is not always a byte. ftell() returns size in bytes, so multiplying by sizeof(char) is actually wrong -- if you pass this to malloc, you should be dividing by sizeof(char). Not that it matters in most architectures, since usually a char is a byte.

Finally -- are rewind() and fseek() safe to mix? is rewind completely equivalent to fseek(f, 0, SEEK_SET), or does it have something to do with C's runtime buffered IO?

1 Comment

Thanks for your answer. As you can see from my answer to my own question below I finally resolved the problem. But you still gave me some valuable hints, as I'm really not a C expert!

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.