Bug #76164 InnoDB FTS with MeCab parser prints empty error message
Submitted: 5 Mar 2015 6:28 Modified: 17 Mar 2015 23:48
Reporter: tsubasa tanaka (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: FULLTEXT search Severity:S3 (Non-critical)
Version:5.7.6, 5.7.7 OS:Linux (CentOS 6.5)
Assigned to: CPU Architecture:Any
Tags: error, fulltext, MeCab

[5 Mar 2015 6:28] tsubasa tanaka
Description:
InnoDB FTS with MeCab parser prints empty error message.
Please see "How to repeat" in detail.

How to repeat:
mysql> CREATE TABLE t1 (val longtext, FULLTEXT KEY (val) WITH PARSER MeCab);
mysql> INSERT INTO t1 VALUES (LOAD_FILE('/tmp/sample.txt'));

And see error-log, you can find error message without any information from MeCab library.

2015-03-05T06:16:39.877914Z 54 [ERROR] Mecab:

Maybe mecab_parser_print_error doesn't handle error message from MeCab library correctly.

(gdb) bt
#0  error_log_print(loglevel, const char *, typedef __va_list_tag __va_list_tag *) (level=ERROR_LEVEL,
    format=0x7fad382ee9a0 "Mecab: %s", args=0x7fad381c61f0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/log.cc:1889
#1  0x0000000000a4d687 in sql_print_error (format=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/log.cc:1915
#2  0x00007fad382a68e6 in mecab_parser_print_error (mecab_lattice=0x7facd003d7a0, param=0x7fad381c6450,
    doc=<value optimized out>, len=<value optimized out>, bool_info=0x7fad381c63e0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/plugin/fulltext/mecab_parser/plugin_mecab.cc:49
#3  mecab_parse (mecab_lattice=0x7facd003d7a0, param=0x7fad381c6450, doc=<value optimized out>, len=<value optimized out>,
    bool_info=0x7fad381c63e0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/plugin/fulltext/mecab_parser/plugin_mecab.cc:201
#4  0x00007fad382a69e2 in mecab_parser_parse (param=0x7fad381c6450)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/plugin/fulltext/mecab_parser/plugin_mecab.cc:289
#5  0x0000000000f2e995 in fts_tokenize_by_parser (doc=<value optimized out>, result=<value optimized out>,
    parser=0x7fad385c0ce0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:4837
#6  fts_tokenize_document (doc=<value optimized out>, result=<value optimized out>, parser=0x7fad385c0ce0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:4864
#7  0x0000000000f32f7a in fts_fetch_doc_from_rec (ftt=<value optimized out>, doc_id=3, fts_indexes=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:3380
#8  fts_add_doc_by_id (ftt=<value optimized out>, doc_id=3, fts_indexes=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:3517
#9  0x0000000000f341eb in fts_add (trx=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:2890
#10 fts_commit_table (trx=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:3106
#11 fts_commit (trx=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/fts/fts0fts.cc:3155
#12 0x0000000000e51970 in trx_commit_low (trx=0x7fad38963748, mtr=0x7fad381c6e20)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/trx/trx0trx.cc:2068
#13 0x0000000000e51d04 in trx_commit (trx=0x7fad38963748)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/trx/trx0trx.cc:2151
#14 0x0000000000e54197 in trx_commit_for_mysql (trx=0x7fad38963748)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/trx/trx0trx.cc:2381
#15 0x0000000000d0d248 in innobase_commit_low (trx=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/handler/ha_innodb.cc:3536
#16 0x0000000000d1b766 in innobase_commit (hton=<value optimized out>, thd=0x7facd0011ce0, commit_trx=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/innobase/handler/ha_innodb.cc:3695
#17 0x0000000000736e4f in ha_commit_low (thd=0x7facd0011ce0, all=false, run_after_commit=false)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/handler.cc:1677
#18 0x0000000000c969a6 in MYSQL_BIN_LOG::process_commit_stage_queue (this=0x1af6e40, thd=<value optimized out>,
    first=<value optimized out>) at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/binlog.cc:7852
#19 0x0000000000ca07c5 in MYSQL_BIN_LOG::ordered_commit (this=0x1af6e40, thd=0x7facd0011ce0, all=<value optimized out>,
    skip_commit=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/binlog.cc:8376
#20 0x0000000000ca0c4f in MYSQL_BIN_LOG::write_binlog_and_commit_engine (this=0x1af6e40, thd=0x7facd0011ce0,
    all=<value optimized out>) at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/binlog.cc:7658
#21 0x0000000000ca0fb4 in MYSQL_BIN_LOG::commit (this=<value optimized out>, thd=0x7facd0011ce0, all=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/binlog.cc:7475
#22 0x0000000000737b43 in ha_commit_trans (thd=0x7facd0011ce0, all=<value optimized out>,
    ignore_global_read_lock=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/handler.cc:1587
#23 0x0000000000b9c2fe in trans_commit_stmt (thd=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/transaction.cc:395
#24 0x0000000000aef7f4 in mysql_execute_command (thd=0x7facd0011ce0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/sql_parse.cc:4566
#25 0x0000000000af1c18 in mysql_parse (thd=0x7facd0011ce0, parser_state=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/sql_parse.cc:5129
#26 0x0000000000af3158 in dispatch_command (command=COM_QUERY, thd=0x7facd0011ce0,
    packet=0x7facd0000941 "INSERT INTO t1 VALUES (LOAD_FILE('/data/tmp/sample.txt'))", packet_length=57)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/sql_parse.cc:1249
#27 0x0000000000bb5e74 in handle_connection (arg=<value optimized out>)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/sql/conn_handler/connection_handler_per_thread.cc:298
#28 0x0000000000f760ba in pfs_spawn_thread (arg=0x3e52ed0)
    at /export/home/pb2/build/sb_0-14375196-1423567394.7/mysql-5.7.6-m16/storage/perfschema/pfs.cc:2147
#29 0x0000003effe079d1 in start_thread () from /lib64/libpthread.so.0
#30 0x0000003eff6e88fd in clone () from /lib64/libc.so.6
[5 Mar 2015 7:24] Umesh Shastry
Hello tanaka-san,

Thank you for the report and test case.

Thanks,
Umesh
[5 Mar 2015 7:25] Umesh Shastry
// 5.7.7

[umshastr@hod03]/export/umesh/mysql-5.7.7: bin/mysql -uroot -p -S /tmp/mysql_ushastry.sock
Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.7.7-rc-enterprise-commercial-advanced MySQL Enterprise Server - Advanced Edition (Commercial)

Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> show plugins;
+----------------------------+----------+--------------------+-------------------+-------------+
| Name                       | Status   | Type               | Library           | License     |
+----------------------------+----------+--------------------+-------------------+-------------+
..
| mecab                      | ACTIVE   | FTPARSER           | libpluginmecab.so | PROPRIETARY |
+----------------------------+----------+--------------------+-------------------+-------------+
44 rows in set (0.00 sec)

mysql> use test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> CREATE TABLE t1 (val longtext, FULLTEXT KEY (val) WITH PARSER MeCab)Engine= InnoDB CHARACTER SET= utf8;
Query OK, 0 rows affected (0.01 sec)

mysql> INSERT INTO t1 VALUES (LOAD_FILE('/export/umesh/mysql-5.7.7/sample.txt'));
Query OK, 1 row affected (0.08 sec)

mysql> quit
Bye

// Extract from error log

2015-03-05T07:19:02.452734Z 0 [Note] /export/umesh/mysql-5.7.7/bin/mysqld: ready for connections.
Version: '5.7.7-rc-enterprise-commercial-advanced'  socket: '/tmp/mysql_ushastry.sock'  port: 15000  MySQL Enterprise Server - Advanced Edition (Commercial)
2015-03-05T07:20:19.047071Z 2 [ERROR] Mecab:
[13 Mar 2015 13:56] Shaohua Wang
Posted by developer:
 
The actual error is "too long sentence", but I don't know what exactly is the limit in mecab yet.
[13 Mar 2015 15:44] tsubasa tanaka
I've confirmed that is "too long sentence" error too.

But that isn't problem.

The issue is "mecab_parser_print_error can't handle error-message from mecab library".

MeCab library's limit doesn't matter.
[16 Mar 2015 2:14] Shaohua Wang
Posted by developer:
 
Yes, we will fix the message issue. Thanks for reporting the bug!
[17 Mar 2015 23:48] Daniel Price
Posted by developer:
 
Fixed as of the upcoming 5.7.8, 5.8.0 releases, and here's the changelog entry:

The "InnoDB" full-text search feature with the mecab parser plugin would
print an empty error message.