2009-02-01 23 views
0

我最近將其中一個應用程序升級到了Rails 2.2.2。做完這些之後,我遇到了一個奇怪的性能問題,它導致在幾秒鐘內完成的渲染花費了10秒鐘的時間。Rails 2.2.2性能問題/錯誤

我已經介紹了該問題,並here are the results I've come up with。它看起來像是Mysql類的real_connect方法中的問題。我的理解是,Ruby real_connect方法是圍繞C mysql_real_connect()函數的封裝。這會讓我相信這個問題必須在數據庫中,因爲在Windows和Linux上運行代碼(數據庫服務器是一個單獨的系統)時遇到了同樣的問題。然而,我並不認爲這是事實,因爲當我從我的Subversion版本庫回滾到以前的版本(pre Rails 2.2.2)時,性能問題就會消失。這似乎表明ActiveRecord中存在某種錯誤。

我該如何去識別和修復這個bug?有沒有人有任何見解?有什麼我失蹤?

更新:我剛剛創建了一個小的profiler腳本來測試Mysql.real_connect方法,並且它看起來問題不在於Rails,而是在MySQL gem或數據庫服務器本身。

在運行下面的代碼:

result = RubyProf.profile do 
    5.times do 
    begin 
    # connect to the MySQL server 
    dbh = Mysql.real_connect(ip, user, pass, db) 
    # get server version string and display it 
    puts "Server version: " + dbh.get_server_info 
    rescue Mysql::Error => e 
    puts "Error code: #{e.errno}" 
    puts "Error message: #{e.error}" 
    puts "Error SQLSTATE: #{e.sqlstate}" if e.respond_to?("sqlstate") 
    ensure 
    # disconnect from server 
    dbh.close if dbh 
    end 
    end 
end 

printer = RubyProf::FlatPrinter.new(result) 
printer.print(STDOUT, 0) 

我想出了這樣的性能結果:

Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Thread ID: 18998180 
Total: 50.402000 

%self  total  self  wait child calls name 
99.99  50.40 50.40  0.00  0.00  5 <Class::Mysql>#real_connect (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  10 IO#write (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 Mysql#get_server_info (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 Kernel#puts (ruby_runtime: 0} 
    0.00  0.00  0.00  0.00  0.00  5 String#+ (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 Mysql#initialize (ruby_runtime:0} 
    0.00  50.40  0.00  0.00 50.40  1 Integer#times (ruby_runtime:0} 
    0.00  50.40  0.00  0.00 50.40  1 Global#[No method] (tmp/mysql_test/test.rb:12} 
    0.00  0.00  0.00  0.00  0.00  5 Mysql#close (ruby_runtime: 0} 

這好像這個問題是不是在ActiveRecord的,它要麼在MySQL寶石還是在數據庫中。我從哪裏出發?

回答

1

我能夠找出問題。我從使用命令mysql --host=ip --user=user --password=passworddb的開發機器上的MySQL命令連接到主機開始。這是非常緩慢的,所以我ssh'ed到服務器,並從那裏使用相同的命令連接。這也很慢。

我將命令更改爲mysql --host=localhost --user=user --password=passworddb,我能夠立即連接。我在/etc/hosts文件中爲我的開發系統添加了一個條目,並且能夠即時連接。顯然,MySQL服務器試圖執行反向dns查找來解析與該IP地址關聯的主機名,如MySQL Manual中所列,並且超時。

我將--skip-name-resolve選項添加到/etc/init.d/mysql腳本的開始部分,以便跳過此檢查並重新啓動服務器。當我運行我之前創建的配置文件腳本時,我得到以下結果:

Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Server version: 5.0.32-Debian_7etch3-log 
Thread ID: 52978590 
Total: 0.016000 

%self  total  self  wait child calls name 
87.50  0.01  0.01  0.00  0.00  5 <Class::Mysql>#real_connect (ruby_runtime:0} 
    6.25  0.00  0.00  0.00  0.00  10 IO#write (ruby_runtime:0} 
    6.25  0.00  0.00  0.00  0.00  5 Mysql#close (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 Kernel#puts (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 Mysql#initialize (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 String#+ (ruby_runtime:0} 
    0.00  0.02  0.00  0.00  0.02  1 Global#[No method] (tmp/mysql_test/test.rb:12} 
    0.00  0.02  0.00  0.00  0.02  1 Integer#times (ruby_runtime:0} 
    0.00  0.00  0.00  0.00  0.00  5 Mysql#get_server_info (ruby_runtime:0}