LSWS Rails App MySQL Connection Errors

[malffred]

I don't know if this is specifically Rails related, but it might be.

I frequently get these types of errors:

1. Mysql::Error: Lost connection to MySQL server during query
2. Mysql::Error: Server has gone away

I definitely get the first one the most. Are there any settings in Litespeed (or Rails if you know them) I can tweak to either increase a timeout that causes this or force a reconnect? Do I need to tweak MySQL, LiteSpeed, LSAPI or Rails (We're running Rails 2.3.2)?

We have LiteSpeed to spawn up to (Max connections) 4 Rails instances and hte site feels really fast, also memory is not maxed out. Should we increase the instances? Or maybe the timeout limits on our current LSWS settings are too high? They are set to around 60-120sec. Some of our timeout settings in LSWS:

• Server Level: Keep-Alive Timeout - 2sec
• Server Level: Ruby on Rails - LSAPI_MAX_IDLE=300
• Server Level: Ruby on Rails - Initial Request Timeout - 120sec
• Server Level: Ruby on Rails - Connection Keepalive Timeout - 90sec
• Server Level: Ruby on Rails - Retry Timeout - 0sec
• Server Level: Ruby on Rails - Max Idle Time = -1
• Server Level: Ruby on Rails - Max Idle Time = -1
  

Some other details:

• 2GB Server Memory, about 800MB goes to LSWS
• Max Connections: 4 Rails Instances
• 550/600MB LSWS Rails Soft/Hard Limit
• LSWS 4.0+ Caching Disabled
• MySQL Ruby Gem = v2.7
• MySQL Version = 5.0.51a-3
• LSWS Version = 4.0.10

I have not specified any specific settings in MySQL to drop the connection, in fact in my my.cnf file I have this: max_connect_errors = 999999 also in config/database.yml we have reconnect: true

We also have memcached running with 350MB cache and is using well below that.

MySQLTuner script shows things are pretty good regarding mysql server settings:

-------- General Statistics --------------------------------------------------
[--] Skipped version check for MySQLTuner script
[OK] Currently running supported MySQL version 5.0.51a-3ubuntu5.3-log
[OK] Operating on 64-bit architecture

-------- Storage Engine Statistics -------------------------------------------
[--] Status: +Archive -BDB -Federated +InnoDB -ISAM -NDBCluster 
[--] Data in InnoDB tables: 145M (Tables: 121)
[OK] Total fragmented tables: 0

-------- Performance Metrics -------------------------------------------------
[--] Up for: 1d 7h 6m 3s (103K q [0.924 qps], 1K conn, TX: 502M, RX: 10M)
[--] Reads / Writes: 93% / 7%
[--] Total buffers: 745.0M global + 3.5M per thread (70 max threads)
[OK] Maximum possible memory usage: 990.5M (48% of installed RAM)
[OK] Slow queries: 0% (3/103K)
[OK] Highest usage of available connections: 10% (7/70)
[OK] Key buffer size / total MyISAM indexes: 200.0M/170.9M
[!!] Key buffer hit rate: 85.5% (942 cached / 137 reads)
[OK] Query cache efficiency: 51.1% (45K cached / 88K selects)
[OK] Query cache prunes per day: 0
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 2K sorts)
[!!] Temporary tables created on disk: 46% (7K on disk / 15K total)
[OK] Thread cache hit rate: 99% (7 created / 1K connections)
[OK] Table cache hit rate: 84% (143 open / 170 opened)
[OK] Open file limit used: 2% (36/1K)
[OK] Table locks acquired immediately: 100% (49K immediate / 49K locks)
[OK] InnoDB data size / buffer pool: 145.2M/250.0M

-------- Recommendations -----------------------------------------------------
General recommendations:
    Enable the slow query log to troubleshoot bad queries
    When making adjustments, make tmp_table_size/max_heap_table_size equal
    Reduce your SELECT DISTINCT queries without LIMIT clauses
Variables to adjust:
    tmp_table_size (> 100M)
    max_heap_table_size (> 100M)

Thanks for any help or ideas.

[mistwang]

Mysql connection was not closed before ruby process forked, so if one process close the connection, the other processes will get the error.

To verify this, you can "lsof -p <pid_of_ruby_process>", check the mysql unix socket, all of them must be referencing to the same one, and the parent ruby process should not have it opened.

In lsws/fcgi-bin/RailsRunner.rb, we have code tries to close MySQL connections after initialization

ActiveRecord::Base.clear_active_connections! if defined?(ActiveRecord::Base)

Seems it works for one version of Rails, then stop working for another. If you can figure out the right way to close MySQL DB connection, we will update RailsRunner.rb

[malffred]

Ok thanks. If I do a ps -aux now I get this:

1000     15860  0.0  0.1  20116  4164 pts/2    Ss+  13:36   0:00 -bash
root     15923  0.0  0.1   5528  2344 ?        S<   13:37   0:00 lshttpd
root     15924  0.0  0.0   1656   364 ?        S<   13:37   0:00 httpd (lscgid)
nobody   15925  0.0  0.1   6248  2904 ?        S<   13:37   0:01 lshttpd
1000     15926  0.1  8.3 313232 174276 ?       S<sl 13:37   0:23 ruby /opt/lsws/fcgi-bin/RailsRunner.rb
1000     16626  4.1  9.6 342852 201824 ?       S<   16:52   2:38 ruby /opt/lsws/fcgi-bin/RailsRunner.rb
1000     16899  1.2  8.4 319024 176620 ?       S<   17:51   0:03 ruby /opt/lsws/fcgi-bin/RailsRunner.rb
1000     16913  0.0  0.0  14776  1000 pts/0    R+   17:55   0:00 ps -aux

I assume the first ruby process is 15926 so I run lsof -p 15926 and get this:

COMMAND   PID       USER   FD   TYPE             DEVICE    SIZE    NODE NAME
ruby    15926 sugarstats  cwd    DIR                8,1    4096 6310912 /home/sugarstats/www/releases/20090830073147
ruby    15926 sugarstats  rtd    DIR                8,1    4096       2 /
ruby    15926 sugarstats  txt    REG                8,1    5264 3818406 /usr/bin/ruby1.8
ruby    15926 sugarstats  mem    REG                8,1  351448 3869786 /usr/lib/ruby/1.8/x86_64-linux/RMagick.so
ruby    15926 sugarstats  DEL    REG                0,8          342176 /dev/zero
ruby    15926 sugarstats  mem    REG                8,1  813856 3821068 /usr/lib/libWand.so.10.0.9
ruby    15926 sugarstats  mem    REG                8,1 1965352 3821062 /usr/lib/libMagick.so.10.0.9
ruby    15926 sugarstats  mem    REG                8,1  211504 3821270 /usr/lib/liblcms.so.1.0.16
ruby    15926 sugarstats  mem    REG                8,1  364632 3821401 /usr/lib/libtiff.so.4.2.1
ruby    15926 sugarstats  mem    REG                8,1  143496 3821261 /usr/lib/libjpeg.so.62.0.0
ruby    15926 sugarstats  mem    REG                8,1  200056 3821175 /usr/lib/libfontconfig.so.1.3.0
ruby    15926 sugarstats  mem    REG                8,1   70280 3821083 /usr/lib/libXext.so.6.4.0
ruby    15926 sugarstats  mem    REG                8,1  404312 3821098 /usr/lib/libXt.so.6.0.0
ruby    15926 sugarstats  mem    REG                8,1   64784 4440280 /lib/libbz2.so.1.0.4
ruby    15926 sugarstats  mem    REG                8,1  513592 3821181 /usr/lib/libfreetype.so.6.3.16
ruby    15926 sugarstats  mem    REG                8,1   32768 3821065 /usr/lib/libSM.so.6.0.0
ruby    15926 sugarstats  mem    REG                8,1   96928 3821046 /usr/lib/libICE.so.6.3.0
ruby    15926 sugarstats  mem    REG                8,1 1060528 3821071 /usr/lib/libX11.so.6.2.0
ruby    15926 sugarstats  mem    REG                8,1  149408 3821169 /usr/lib/libexpat.so.1.5.2
ruby    15926 sugarstats  mem    REG                8,1    9736 3821073 /usr/lib/libXau.so.6.0.0
ruby    15926 sugarstats  mem    REG                8,1    5864 3821414 /usr/lib/libxcb-xlib.so.0.0.0
ruby    15926 sugarstats  mem    REG                8,1  112080 3821416 /usr/lib/libxcb.so.1.0.0
ruby    15926 sugarstats  mem    REG                8,1   20128 3821081 /usr/lib/libXdmcp.so.6.0.0
ruby    15926 sugarstats  mem    REG                8,1  127480 4440272 /lib/ld-2.7.so
ruby    15926 sugarstats  mem    REG                8,1  879608 3821360 /usr/lib/libruby1.8.so.1.8.6
ruby    15926 sugarstats  mem    REG                8,1  130224 4440324 /lib/libpthread-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   14624 4440291 /lib/libdl-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   39120 4440287 /lib/libcrypt-2.7.so
ruby    15926 sugarstats  mem    REG                8,1  526560 4440304 /lib/libm-2.7.so
ruby    15926 sugarstats  mem    REG                8,1 1436976 4440281 /lib/libc-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   16272 3869828 /usr/lib/ruby/1.8/x86_64-linux/thread.so
ruby    15926 sugarstats  mem    REG                8,1   10936 3869799 /usr/lib/ruby/1.8/x86_64-linux/etc.so
ruby    15926 sugarstats  mem    REG                8,1   19952 3869823 /usr/lib/ruby/1.8/x86_64-linux/stringio.so
ruby    15926 sugarstats  mem    REG                8,1  119040 3869825 /usr/lib/ruby/1.8/x86_64-linux/syck.so
ruby    15926 sugarstats  mem    REG                8,1   35632 4440309 /lib/libnss_compat-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   93080 4440308 /lib/libnsl-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   43480 4440313 /lib/libnss_nis-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   47528 4440311 /lib/libnss_files-2.7.so
ruby    15926 sugarstats  mem    REG                8,1    8496 3869797 /usr/lib/ruby/1.8/x86_64-linux/enumerator.so
ruby    15926 sugarstats  mem    REG                8,1  267192 3869806 /usr/lib/ruby/1.8/x86_64-linux/nkf.so
ruby    15926 sugarstats  mem    REG                8,1   45272 3869787 /usr/lib/ruby/1.8/x86_64-linux/bigdecimal.so
ruby    15926 sugarstats  mem    REG                8,1   16384 3869802 /usr/lib/ruby/1.8/x86_64-linux/iconv.so
ruby    15926 sugarstats  mem    REG                8,1   25700 3851478 /usr/lib/gconv/gconv-modules.cache
ruby    15926 sugarstats  mem    REG                8,1   19272 3869824 /usr/lib/ruby/1.8/x86_64-linux/strscan.so
ruby    15926 sugarstats  mem    REG                8,1   16208 4145541 /usr/lib/ruby/gems/1.8/gems/hpricot-0.8.1/lib/fast_xs.so
ruby    15926 sugarstats  mem    REG                8,1  121046 4148270 /usr/lib/ruby/gems/1.8/gems/ruby-lsapi-3.5/lib/lsapi.so
ruby    15926 sugarstats  mem    REG                8,1   15248 3883513 /usr/lib/ruby/1.8/x86_64-linux/racc/cparse.so
ruby    15926 sugarstats  mem    REG                8,1   48512 3869821 /usr/lib/ruby/1.8/x86_64-linux/socket.so
ruby    15926 sugarstats  mem    REG                8,1  254120 3869808 /usr/lib/ruby/1.8/x86_64-linux/openssl.so
ruby    15926 sugarstats  mem    REG                8,1  304544 3821365 /usr/lib/libssl.so.0.9.8
ruby    15926 sugarstats  mem    REG                8,1 1559720 3821138 /usr/lib/libcrypto.so.0.9.8
ruby    15926 sugarstats  mem    REG                8,1   93536 3821423 /usr/lib/libz.so.1.2.3.3
ruby    15926 sugarstats  mem    REG                8,1    5120 3869800 /usr/lib/ruby/1.8/x86_64-linux/fcntl.so
ruby    15926 sugarstats  mem    REG                8,1 4344877 4212347 /usr/lib/ruby/gems/1.8/gems/memcached-0.15.3/lib/rlibmemcached.so
ruby    15926 sugarstats  mem    REG                8,1   95813 3986633 /usr/lib/ruby/gems/1.8/gems/mysql-2.7/lib/mysql.so
ruby    15926 sugarstats  mem    REG                8,1  273928 3821291 /usr/lib/libmysqlclient.so.12.0.0
ruby    15926 sugarstats  mem    REG                8,1   11344 3883510 /usr/lib/ruby/1.8/x86_64-linux/digest/sha1.so
ruby    15926 sugarstats  mem    REG                8,1   12776 3869792 /usr/lib/ruby/1.8/x86_64-linux/digest.so
ruby    15926 sugarstats  mem    REG                8,1  512899 4145897 /usr/lib/ruby/gems/1.8/gems/libxml-ruby-1.1.3/lib/libxml_ruby.so
ruby    15926 sugarstats  mem    REG                8,1 1335832 3821419 /usr/lib/libxml2.so.2.6.31
ruby    15926 sugarstats  mem    REG                8,1   47778 4145685 /usr/lib/ruby/gems/1.8/gems/json-1.1.7/ext/json/ext/parser.so
ruby    15926 sugarstats  mem    REG                8,1   58392 4145679 /usr/lib/ruby/gems/1.8/gems/json-1.1.7/ext/json/ext/generator.so
ruby    15926 sugarstats  mem    REG                8,1    8336 3883508 /usr/lib/ruby/1.8/x86_64-linux/digest/md5.so
ruby    15926 sugarstats  mem    REG                8,1   38160 3869831 /usr/lib/ruby/1.8/x86_64-linux/zlib.so
ruby    15926 sugarstats  mem    REG                8,1   22856 4440310 /lib/libnss_dns-2.7.so
ruby    15926 sugarstats  mem    REG                8,1   80760 4440326 /lib/libresolv-2.7.so
ruby    15926 sugarstats    0u  unix 0xffff880040898580          342044 /tmp/lshttpd/manage.sugarstats.com
ruby    15926 sugarstats    1u  unix 0xffff88002441ad40          342032 socket
ruby    15926 sugarstats    2u  unix 0xffff88002441ad40          342032 socket
ruby    15926 sugarstats    3w   REG                8,1 9165917 6146524 /home/sugarstats/www/shared/log/production.log
ruby    15926 sugarstats    4u  unix 0xffff880000036a80          342160 socket
ruby    15926 sugarstats    5w   REG                8,1 3313415 6146520 /home/sugarstats/www/shared/log/exceptional.log

[mistwang]

ruby 15926 sugarstats 4u unix 0xffff880000036a80 342160 socket

I think this is the connection to MySQL, should be closed.

[malffred]

Oh ok.

What would be the best way to remedy this? Restart MySQL?

Also, any idea why that process would be there to begin with so I can know in the future how to prevent it from happening again?

I do frequently need to restart LSWS after making Rails code changes, perhaps that made something out of sync with MySQL? Should I restart them both at the same time?

[mistwang]

The MySQL connection is because in your App initilization code accessing DB.

It is due to internal change in Rails,

ActiveRecord::Base.clear_active_connections! if defined?(ActiveRecord::Base)

used to be able to close MySQL connection, but cannot with your version of Rails.

Restart does not matter.