affected_rows doesn't seem to be threadsafe

[ihanick]

Exception raised from: https://github.com/rails/rails/blob/v4.2.7/activerecord/lib/active_record/connection_adapters/mysql2_adapter.rb#L253

The issue could be related to:
#461 (comment)

With break point inside libmysqlclient18 (ubuntu 14.04 5.5.57):
b mysql_affected_rows if mysql->affected_rows > 100000

Buffer contains normal confirmation to server response and part of previous server response:

(gdb) xxd mysql->net->buff 256
0000000: 0500 0000 194c 0000 006f 7773 206d 6174  .....L...ows mat
0000010: 6368 6564 3a20 3120 2043 6861 6e67 6564  ched: 1  Changed
0000020: 3a20 3020 2057 6172 6e69 6e67 733a 2030  : 0  Warnings: 0
0000030: 003d 2027 3230 3137 2d30 382d 3330 2030  .= '2017-08-30 0

(gdb) p *mysql
$21 = {net = {vio = 0x55556497df20, buff = 0x55557c727fe0 "\005", buff_end = 0x55557c72dfe0 "p\366\222{UU", write_pos = 0x55557c727fe0 "\005", read_pos = 0x55557c727fe0 "\005", fd = 39, 
    remain_in_buf = 0, length = 0, buf_length = 0, where_b = 0, max_packet = 24576, max_packet_size = 1073741824, pkt_nr = 1, compress_pkt_nr = 0, write_timeout = 31536000, 
    read_timeout = 31536000, retry_count = 1, fcntl = 0, return_status = 0x0, reading_or_writing = 0 '\000', save_char = 0 '\000', unused1 = 0 '\000', unused2 = 0 '\000', 
    compress = 0 '\000', unused3 = 0 '\000', unused = 0x0, last_errno = 0, error = 0 '\000', unused4 = 0 '\000', unused5 = 0 '\000', 
    last_error = "\000uplicate entry '54045-test@email.com' for key 'index_contact_profiles_on_user_id_and_email'", '\000' <repeats 419 times>, sqlstate = "00000", extension = 0x0}, 
  connector_fd = 0x0, host = 0x555564996148 "127.0.0.1", user = 0x55556497d850 "root", passwd = 0x55556497ded0 "", unix_socket = 0x0, 
  server_version = 0x555564996160 "5.6.33-0ubuntu0.14.04.1", host_info = 0x555564996130 "127.0.0.1 via TCP/IP", info = 0x0, db = 0x55556497def0 "etison_test", 
  charset = 0x7fffebb8fa20 <my_charset_utf8_general_ci>, fields = 0x0, field_alloc = {free = 0x0, used = 0x0, pre_alloc = 0x0, min_malloc = 32, block_size = 8160, block_num = 4, 
    first_block_usage = 0, error_handler = 0x0}, affected_rows = 18446744073709551615, insert_id = 0, extra_info = 0, thread_id = 127, packet_length = 7, port = 3306, 
  client_flag = 2148442639, server_capabilities = 18446744071570454527, protocol_version = 10, field_count = 0, server_status = 3, server_language = 8, warning_count = 0, options = {
    connect_timeout = 120, read_timeout = 0, write_timeout = 0, port = 0, protocol = 0, client_flag = 0, host = 0x0, user = 0x0, password = 0x0, unix_socket = 0x0, db = 0x0, 
    init_commands = 0x0, my_cnf_file = 0x0, my_cnf_group = 0x0, charset_dir = 0x0, charset_name = 0x555564967170 "utf8", ssl_key = 0x0, ssl_cert = 0x0, ssl_ca = 0x0, ssl_capath = 0x0, 
    ssl_cipher = 0x0, shared_memory_base_name = 0x0, max_allowed_packet = 0, use_ssl = 0 '\000', compress = 0 '\000', named_pipe = 0 '\000', unused1 = 0 '\000', unused2 = 0 '\000', 
    unused3 = 0 '\000', unused4 = 0 '\000', methods_to_use = MYSQL_OPT_GUESS_CONNECTION, client_ip = 0x0, secure_auth = 0 '\000', report_data_truncation = 1 '\001', 
    local_infile_init = 0x7fffebc0bfd0 <mysql2_local_infile_init>, local_infile_read = 0x7fffebc0c0b0 <mysql2_local_infile_read>, 
    local_infile_end = 0x7fffebc0bf90 <mysql2_local_infile_end>, local_infile_error = 0x7fffebc0bf40 <mysql2_local_infile_error>, local_infile_userdata = 0x555564966ae0, extension = 0x0}, 
  status = MYSQL_STATUS_READY, free_me = 0 '\000', reconnect = 1 '\001', scramble = "E)=529i&}fgSGL&xMVHH", unused1 = 0 '\000', unused2 = 0x0, unused3 = 0x0, unused4 = 0x0, unused5 = 0x0, 
  stmts = 0x555578cf0f28, methods = 0x7fffebb7f8c0 <client_methods>, thd = 0x0, unbuffered_fetch_owner = 0x0, info_buffer = 0x0, extension = 0x0}

Another run with same affected_rows == -1 error under strace:

26416 write(39, "[\0\0\0\3UPDATE `users` SET `users`.`updated_at` = '2017-08-25 09:56:05' WHERE `users`.`id` = 31641", 95) = 95
26416 ppoll([{fd=39, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=39, revents=POLLIN}])
26416 read(39, "0\0\0\1\0\1\0\3\0\0\0(Rows matched: 1  Changed: 0  Warnings: 0", 16384) = 52
26416 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
26416 clock_gettime(CLOCK_REALTIME, {1503654898, 923452728}) = 0
26416 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
26416 clock_gettime(CLOCK_REALTIME, {1503654898, 923621698}) = 0
26416 clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {488, 923456987}) = 0
26416 clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {488, 923515584}) = 0
26416 poll([{fd=39, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
26416 write(39, "\5\0\0\0\31\201\0\0\0", 9) = 9
26416 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
26416 clock_gettime(CLOCK_REALTIME, {1503654898, 924371833}) = 0
26416 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
26416 clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {488, 924112922}) = 0
26416 clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {488, 924157442}) = 0
26416 clock_gettime(CLOCK_REALTIME, {1503654898, 924648111}) = 0
26416 poll([{fd=39, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
26416 write(39, "&\0\0\0\3ROLLBACK TO SAVEPOINT active_record_1", 42) = 42

Again mysqlclient communication looks valid, but everything looks like affected_rows cleared between query execution and mysql_affected_rows call (e.g. with mysql_next_result).

[sodabrew]

[Edited the OP to add triple-backtick blocks]

It's definitely not thread-safe. You must not share a MySQL connection concurrently across threads. Using a thread pool is safe iff all uses of the connection in thread A are fully retired before the connection is made usable again by thread B.

I'm not sure I'm following the issue? Active Record provides a thread pool that is compliant to the restriction above.

[sodabrew]

Hi, I want to check in again to see if you were able to resolve the thread-safety issue reported here?

[sodabrew]

Closing due to lack of updates.