The following is a bug/oddity I've encountered while using activerecord along with the seemingly problematic mysql "LOAD DATA LOCAL INFILE" functionality. As any trivial google search will show, this error in mysql points very strongly to the cases where either the client or the server are not configured to allowed the operation. Of course this is configured correctly in my case on both the server and client sides. I can repro this in at least a couple of different odd ways detailed in the console sessions below.
mysqld version:
rwoodrum@frums:~$ sudo mysqld --version
mysqld Ver 5.0.45-Debian_1-log for pc-linux-gnu on i486 (Debian etch distribution)
mysql command line:
mysql 28095 28058 43 16:03 pts/3 00:00:01 /usr/sbin/mysqld --basedir=/usr --datadir=/home/rwoodrum/mysql_data --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --skip-external-locking --port=3306 --socket=/var/run/mysqld/mysqld.sock
Using activerecord version:
activerecord-1.15.2
Trivial test mysql table:
mysql> describe foos \G
*************************** 1. row ***************************
Field: a
Type: int(11)
Null: YES
Key:
Default: NULL
Extra:
*************************** 2. row ***************************
Field: b
Type: int(11)
Null: YES
Key:
Default: NULL
Extra:
2 rows in set (0.00 sec)
Contents of test csv file
rwoodrum@frums:~/tmp$ cat x.csv
1,2;3,4;5,6
Create trivial rails app and derive a class from ActiveRecord::Base, ala:
$ rails foo
app/models/foo.rb:
class Foo < ActiveRecord::Base
end
Console session where 'LOAD DATA LOCAL INFILE' fails until a reconnect is issued on the connection:
rwoodrum@frums:~/tmp/x/foo$ ./script/console
Loading development environment.
>> bar = Foo.new
=> #<Foo:0xb6f1edf0 @attributes={"a"=>nil, "b"=>nil}, @new_record=true>
>> bar.connection.raw_connection.options(8, true)
=> 128
>> bar.connection.execute "load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'"
ActiveRecord::StatementInvalid: Mysql::Error: #42000The used command is not allowed with this MySQL version: load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'
from ./script/../config/../config/../vendor/rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:128:in `log'
from ./script/../config/../config/../vendor/rails/activerecord/lib/active_record/connection_adapters/mysql_adapter.rb:243:in `execute'
from (irb):3
>>
?>
?>
?> bar.connection.reconnect!
=> nil
>> bar.connection.execute "load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'"
=> nil
Console session where shutting down and bringing back the mysql server with a subsequent connection.reconnect! makes everything work fine.
rwoodrum@frums:~/tmp/x/foo$ ./script/console
Loading development environment.
>> bar = Foo.new
=> #<Foo:0xb6f07380 @attributes={"a"=>nil, "b"=>nil}, @new_record=true>
>> bar.connection.active?
=> true
>> bar.connection.raw_connection.options(8, true)
=> 128
>> bar.connection.raw_connection.client_info
=> "4.0-ruby-0.2.6-plus-changes"
>> results = bar.connection.execute "show session variables"
=> #<Mysql::Result>
>> results.each do |k,v|
?> puts "#{k} => #{v}"
>> end
auto_increment_increment => 1
auto_increment_offset => 1
automatic_sp_privileges => ON
back_log => 50
basedir => /usr/
binlog_cache_size => 32768
bulk_insert_buffer_size => 8388608
character_set_client => latin1
character_set_connection => latin1
character_set_database => latin1
character_set_filesystem => binary
character_set_results => latin1
character_set_server => latin1
character_set_system => utf8
character_sets_dir => /usr/share/mysql/charsets/
collation_connection => latin1_swedish_ci
collation_database => latin1_swedish_ci
collation_server => latin1_swedish_ci
completion_type => 0
concurrent_insert => 1
connect_timeout => 5
datadir => /home/rwoodrum/mysql_data/
date_format => %Y-%m-%d
datetime_format => %Y-%m-%d %H:%i:%s
default_week_format => 0
delay_key_write => ON
delayed_insert_limit => 100
delayed_insert_timeout => 300
delayed_queue_size => 1000
div_precision_increment => 4
engine_condition_pushdown => OFF
expire_logs_days => 10
flush => OFF
flush_time => 0
ft_boolean_syntax => + -><()~*:""&|
ft_max_word_len => 84
ft_min_word_len => 4
ft_query_expansion_limit => 20
ft_stopword_file => (built-in)
group_concat_max_len => 1024
have_archive => YES
have_bdb => NO
have_blackhole_engine => YES
have_compress => YES
have_crypt => YES
have_csv => YES
have_dynamic_loading => YES
have_example_engine => NO
have_federated_engine => YES
have_geometry => YES
have_innodb => YES
have_isam => NO
have_merge_engine => YES
have_ndbcluster => DISABLED
have_openssl => DISABLED
have_ssl => DISABLED
have_query_cache => YES
have_raid => NO
have_rtree_keys => YES
have_symlink => YES
hostname => frums
init_connect =>
init_file =>
init_slave =>
innodb_additional_mem_pool_size => 1048576
innodb_autoextend_increment => 8
innodb_buffer_pool_awe_mem_mb => 0
innodb_buffer_pool_size => 8388608
innodb_checksums => ON
innodb_commit_concurrency => 0
innodb_concurrency_tickets => 500
innodb_data_file_path => ibdata1:10M:autoextend
innodb_data_home_dir =>
innodb_doublewrite => ON
innodb_fast_shutdown => 1
innodb_file_io_threads => 4
innodb_file_per_table => OFF
innodb_flush_log_at_trx_commit => 1
innodb_flush_method =>
innodb_force_recovery => 0
innodb_lock_wait_timeout => 50
innodb_locks_unsafe_for_binlog => OFF
innodb_log_arch_dir =>
innodb_log_archive => OFF
innodb_log_buffer_size => 1048576
innodb_log_file_size => 5242880
innodb_log_files_in_group => 2
innodb_log_group_home_dir => ./
innodb_max_dirty_pages_pct => 90
innodb_max_purge_lag => 0
innodb_mirrored_log_groups => 1
innodb_open_files => 300
innodb_rollback_on_timeout => OFF
innodb_support_xa => ON
innodb_sync_spin_loops => 20
innodb_table_locks => ON
innodb_thread_concurrency => 8
innodb_thread_sleep_delay => 10000
interactive_timeout => 28800
join_buffer_size => 131072
key_buffer_size => 16777216
key_cache_age_threshold => 300
key_cache_block_size => 1024
key_cache_division_limit => 100
language => /usr/share/mysql/english/
large_files_support => ON
large_page_size => 0
large_pages => OFF
lc_time_names => en_US
license => GPL
local_infile => ON
locked_in_memory => OFF
log => OFF
log_bin => ON
log_bin_trust_function_creators => OFF
log_error =>
log_queries_not_using_indexes => OFF
log_slave_updates => OFF
log_slow_queries => OFF
log_warnings => 1
long_query_time => 10
low_priority_updates => OFF
lower_case_file_system => OFF
lower_case_table_names => 0
max_allowed_packet => 16776192
max_binlog_cache_size => 4294967295
max_binlog_size => 104857600
max_connect_errors => 10
max_connections => 100
max_delayed_threads => 20
max_error_count => 64
max_heap_table_size => 16777216
max_insert_delayed_threads => 20
max_join_size => 18446744073709551615
max_length_for_sort_data => 1024
max_prepared_stmt_count => 16382
max_relay_log_size => 0
max_seeks_for_key => 4294967295
max_sort_length => 1024
max_sp_recursion_depth => 0
max_tmp_tables => 32
max_user_connections => 0
max_write_lock_count => 4294967295
multi_range_count => 256
myisam_data_pointer_size => 6
myisam_max_sort_file_size => 2147483647
myisam_recover_options => OFF
myisam_repair_threads => 1
myisam_sort_buffer_size => 8388608
myisam_stats_method => nulls_unequal
ndb_autoincrement_prefetch_sz => 32
ndb_force_send => ON
ndb_use_exact_count => ON
ndb_use_transactions => ON
ndb_cache_check_time => 0
ndb_connectstring =>
net_buffer_length => 16384
net_read_timeout => 30
net_retry_count => 10
net_write_timeout => 60
new => OFF
old_passwords => OFF
open_files_limit => 1024
optimizer_prune_level => 1
optimizer_search_depth => 62
pid_file => /var/run/mysqld/mysqld.pid
port => 3306
preload_buffer_size => 32768
profiling => OFF
profiling_history_size => 15
protocol_version => 10
query_alloc_block_size => 8192
query_cache_limit => 1048576
query_cache_min_res_unit => 4096
query_cache_size => 16777216
query_cache_type => ON
query_cache_wlock_invalidate => OFF
query_prealloc_size => 8192
range_alloc_block_size => 2048
read_buffer_size => 131072
read_only => OFF
read_rnd_buffer_size => 262144
relay_log_purge => ON
relay_log_space_limit => 0
rpl_recovery_rank => 0
secure_auth => OFF
secure_file_priv =>
server_id => 1
skip_external_locking => ON
skip_networking => OFF
skip_show_database => OFF
slave_compressed_protocol => OFF
slave_load_tmpdir => /tmp/
slave_net_timeout => 3600
slave_skip_errors => OFF
slave_transaction_retries => 10
slow_launch_time => 2
socket => /var/run/mysqld/mysqld.sock
sort_buffer_size => 2097144
sql_big_selects => ON
sql_mode =>
sql_notes => ON
sql_warnings => OFF
ssl_ca =>
ssl_capath =>
ssl_cert =>
ssl_cipher =>
ssl_key =>
storage_engine => MyISAM
sync_binlog => 0
sync_frm => ON
system_time_zone => PDT
table_cache => 64
table_lock_wait_timeout => 50
table_type => MyISAM
thread_cache_size => 8
thread_stack => 131072
time_format => %H:%i:%s
time_zone => SYSTEM
timed_mutexes => OFF
tmp_table_size => 33554432
tmpdir => /tmp
transaction_alloc_block_size => 8192
transaction_prealloc_size => 4096
tx_isolation => REPEATABLE-READ
updatable_views_with_limit => YES
version => 5.0.45-Debian_1-log
version_comment => Debian etch distribution
version_compile_machine => i486
version_compile_os => pc-linux-gnu
wait_timeout => 28800
=> nil
>> #
>> #note that local_infile is ON
>> #
>> bar.connection.execute "load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'"
ActiveRecord::StatementInvalid: Mysql::Error: #42000The used command is not allowed with this MySQL version: load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'
from ./script/../config/../config/../vendor/rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:128:in `log'
from ./script/../config/../config/../vendor/rails/activerecord/lib/active_record/connection_adapters/mysql_adapter.rb:243:in `execute'
from (irb):8
>>
?>
?>
?> #externally shutdown mysql server
?> bar.connection.execute "load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'"
ActiveRecord::StatementInvalid: Mysql::Error: Lost connection to MySQL server during query: load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'
from ./script/../config/../config/../vendor/rails/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb:128:in `log'
from ./script/../config/../config/../vendor/rails/activerecord/lib/active_record/connection_adapters/mysql_adapter.rb:243:in `execute'
from (irb):13
>>
?>
?> #mysql lost connection error is not unexpected
?> #restart mysql server
?>
>> bar.connection.reconnect!
=> nil
>> bar.connection.active?
=> true
>> bar.connection.execute "load data local infile '/home/rwoodrum/tmp/x.csv' replace into table foos fields terminated by ',' lines terminated by ';'"
=> nil
>> #works....... but why?!
?>
Using the C bindings, this will work fine UNTIL I issue a reconnect, at which time it breaks resulting in even more confusion.
Could something be going on here where config options are not being recycled on a reconnect? If this was the case, however, why would the session variables indicate that the local_infile is set to on.
As a workaround in our production application, we have decided to tear down and create a new connection if we ever feel like we could be in a state where the mysql server could have gone away (e.g. due to timeout). This is an ugly solution and in some circumstances could produce unreasonable overhead.
I've run this through the Netbeans ruby debugger and have not been able to discern anything changing to point in the direction of the problem.
Any thoughts appreciated!
-ryan woodrum
