Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-3758

LP:1035271 - ruby dbi connection to Mariadb break after beeing idle for 10 minutes

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Resolution: Incomplete
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None
    • Labels:

      Description

      ruby dbi connection to Mariadb break after beeing idle for 10 minutes

      I use:

      • debian squeeze
      • mariadb 5.3.7-mariadb116~squeeze
      • libdbd-mysql-ruby1.8 0.4.4-1
      • libdbi-ruby1.8 0.4.3-2
      • libmysql-ruby1.8 2.8.2-1
      • libruby1.8 1.8.7.302-2squeeze1
      • libmysqlclient16 5.3.7-mariadb116~squeeze

      ruby dbi connection to Mariadb break after beeing idle for 10 minutes and doing
      a query again. Code to reproduce:

      #!/usr/bin/env ruby

      require 'dbi'
      require 'date'

      DBNAME='test'
      DBSOCKET='/var/run/mysqld/mysqld.sock'
      DBUSER='test'
      DBPASS='test'

      1. for testing purpose just create a test db:
      2. create database test;
      3. and grant select:
      4. grant select on test.* to 'test'@'localhost' identified by 'test';

      wait_min=[9,10,11]

      db = DBI.connect("DBI:Mysql:database=#

      {DBNAME}

      ;socket=#

      {DBSOCKET}

      ", DBUSER, DBPASS)

      wait_min.each do | n |
      i = n*60
      puts DateTime.now()
      puts "do query: SELECT 1;"
      query=db.prepare("SELECT 1;")
      query.execute
      query.fetch_array
      query.finish
      puts "sleep for #

      {n}

      min."
      sleep
      end

      puts "Disconnect:"
      db.disconnect

      Waiting for 9 minutes and doing a 'SELECT 1;' works, waiting for 10 minutes lead to the error:

      /usr/lib/ruby/1.8/dbd/Mysql.rb:106:in `error': MySQL server has gone away (DBI::DatabaseError)
      from /usr/lib/ruby/1.8/dbd/mysql/statement.rb:42:in `execute'
      from /usr/lib/ruby/1.8/dbi/handles/statement.rb:116:in `execute'
      from test_db2.rb:25
      from test_db2.rb:20:in `each'
      from test_db2.rb:20

      An excerpt of an strace log running these program:

      connect(3,

      {sa_family=AF_FILE, path="/var/run/mysqld/mysqld.sock"}

      , 110) = 0
      setsockopt(3, SOL_SOCKET, SO_RCVTIMEO, "\2003\341\1\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 0
      setsockopt(3, SOL_SOCKET, SO_SNDTIMEO, "\2003\341\1\0\0\0\0\0\0\0\0\0\0\0\0", 16) = 0
      brk(0xde7000) = 0xde7000
      setsockopt(3, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported)
      setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
      read(3, "c\0\0\0\n5.3.7-MariaDB-mariadb116~sq"..., 16384) = 103
      stat("/usr/share/mysql/charsets/Index.xml",

      {st_mode=S_IFREG|0644, st_size=18261, ...}

      ) = 0
      open("/usr/share/mysql/charsets/Index.xml", O_RDONLY) = 4
      read(4, "<?xml version='1.0' encoding=\"ut"..., 18261) = 18261
      close(4) = 0
      write(3, "U\0\0\1\215\242\10\0\0\0\0@\10\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 89) = 89
      read(3, "\7\0\0\2\0\0\0\2\0\0\0", 16384) = 11
      stat("/etc/localtime",

      {st_mode=S_IFREG|0644, st_size=2309, ...}) = 0
      fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
      mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f489e3d4000
      write(1, "2012-08-10T11:51:16+02:00\n", 26) = 26
      write(1, "do query: SELECT 1;\n", 20) = 20
      poll([{fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
      write(3, "\n\0\0\0\3SELECT 1;", 14) = 14
      read(3, "\1\0\0\1\1\27\0\0\2\3def\0\0\0\0011\0\f?\0\1\0\0\0\10\201\0\0\0\0"..., 16384) = 56
      write(1, "sleep for 9 min.\n", 17) = 17
      select(0, NULL, NULL, NULL, {540, 0}) = 0 (Timeout)
      stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2309, ...}

      ) = 0
      write(1, "2012-08-10T12:00:16+02:00\n", 26) = 26
      write(1, "do query: SELECT 1;\n", 20) = 20
      poll([

      {fd=3, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
      write(3, "\n\0\0\0\3SELECT 1;", 14) = 14
      read(3, "\1\0\0\1\1\27\0\0\2\3def\0\0\0\0011\0\f?\0\1\0\0\0\10\201\0\0\0\0"..., 16384) = 56
      write(1, "sleep for 10 min.\n", 18) = 18
      select(0, NULL, NULL, NULL, {600, 0}) = 0 (Timeout)
      stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2309, ...}) = 0
      brk(0xe0a000) = 0xe0a000
      brk(0xe05000) = 0xe05000
      write(1, "2012-08-10T12:10:16+02:00\n", 26) = 26
      write(1, "do query: SELECT 1;\n", 20) = 20
      poll([{fd=3, events=POLLIN|POLLPRI}

      ], 1, 0) = 1 ([

      {fd=3, revents=POLLIN|POLLHUP}

      ])
      read(3, "", 8192) = 0
      shutdown(3, 2 /* send and receive */) = 0
      close(3) = 0
      rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
      rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
      write(2, "/usr/lib/ruby/1.8/dbd/Mysql.rb:1"..., 45) = 45
      write(2, ": ", 2) = 2
      write(2, "MySQL server has gone away", 26) = 26
      write(2, " (", 2) = 2
      write(2, "DBI::DatabaseError", 18) = 18
      write(2, ")\n", 2) = 2
      write(2, "\tfrom /usr/lib/ruby/1.8/dbd/mysq"..., 63) = 63
      write(2, "\tfrom /usr/lib/ruby/1.8/dbi/hand"..., 66) = 66
      write(2, "\tfrom test_db2.rb:25\n", 21) = 21
      write(2, "\tfrom test_db2.rb:20:in `each'\n", 31) = 31
      write(2, "\tfrom test_db2.rb:20\n", 21) = 21
      rt_sigaction(SIGINT,

      {SIG_DFL, [INT], SA_RESTORER|SA_RESTART, 0x7f489d0a8230}

      ,

      {0x7f489df4fd60, [], SA_RESTORER, 0x7f489dcabff0}

      , 8) = 0
      exit_group(1) = ?

      I have tested this Program with mysqld 5.1.63 and it works as expected. The difference between mysqld 5.1.63 and
      mariadb 5.3.7-mariadb116~squeeze is that the poll before sending the new query will be answered by Mariadb after 10 minutes idle,
      but not by mysqld 5.1.63. (look at line 19,27,37 of the strace log).

      The only workaround I can imagin is to do keep alive querys on idle connections.

        Attachments

          Activity

            People

            Assignee:
            Unassigned
            Reporter:
            hubertkrause Hubert Krause (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: