From: Wai-Sun Chia Date: 2001-08-22T14:32:29+09:00 Subject: [ruby-talk:20093] Hash test performance issue This is a multi-part message in MIME format. --------------080706020308050501090503 Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit Hello Rubyists, I've bumped into a performance issue when comparing a hash via an iterator. Included is the profiler output. Question: Why is foo = (bar == @bigHumonguosHash) : apple ? orange Soooo much slower than (almost 100%) foo = (bar.id == @bigHumongousHash.id) : apple ? orange What does ruby do internally when it is asked to compare objects via references (especially huge hashes, tens of thousands of records indexed by strings).. p.s. Notice that I just put into use all the "Ruby ways" which were discussed earlier? ;-) -- Wai-Sun "Squidster" Chia RHCE/Professional Services Linux/Unix/Web Developer --------------080706020308050501090503 Content-Type: text/plain; name="area.profile" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="area.profile" =========== ./profiler.rb Line time% time count 1 module LineProfiler__ 2 lastNow = Start = Process.times[0] 3 lastFile = '(toplevel)' 4 lastLine = 0 5 lastTimes = [0.0] 6 lastCounts = [0] 7 Files = {} 8 9 p = proc { |event, file, line, id, binding, klass| 10 if event == 'line' 11 now = Process.times[0] 12 lastTimes[ lastLine ] += now - lastNow 13 lastCounts[ lastLine ] += 1 14 if lastFile != file 15 (lastTimes, lastCounts) = Files.fetch(file) { |name| 16 Files[name] = [ Array.new(10000, 0.0), Array.new(10000, 0) ] 17 } 18 lastFile = file 19 end 20 lastLine = line 21 lastNow = Process.times[0] 22 end 23 } 24 25 END { 26 set_trace_func nil 27 total = Process.times[0] - Start 28 total /= 100.0 # convert to percent 29 f = STDERR 30 for file in Files.keys.sort 31 f.printf("=========== %s\n", file) 32 f.printf(" Line time%% time count\n", file) 33 lines = IO.readlines(file) 34 (times, counts) = Files[file] 35 lines.each_index do |line| 36 if counts[line+1] > 0 37 f.printf("%5d %3.0f%% %6.2f %6d %s", 38 line+1, times[line+1]/total, times[line+1], counts[line+1], 39 lines[line]) 40 else 41 f.printf("%5d %s", line+1, lines[line]) 42 end 43 end 44 end 45 f.close 46 } 47 48 set_trace_func p 49 end 50 51 =========== areacode_lookup.rb Line time% time count 1 #!/usr/bin/ruby 2 3 0% 0.00 1 class AreaCodeDB 4 0% 0.00 1 def initialize(filename) 5 0% 0.00 1 @oldDB = {} 6 0% 0.00 1 @newDB = {} 7 begin 8 0% 0.02 1 @dbfile = File.new(filename, "r") 9 rescue SystemCallError 10 puts "Fatal Error: #{$!}" 11 ensure 12 0% 0.00 1 @dbfile.close if @dbfile.nil? 13 0% 0.00 1 end 14 end 15 0% 0.00 1 attr_reader :oldDB, :newDB 16 17 0% 0.00 1 def load 18 0% 0.00 1 @dbfile.each_line { |line| 19 8% 0.37 1663 line.chomp!.gsub! /"|x/, "" 20 9% 0.40 1663 area, exchange_name, old_service_num, new_service_num = line.split ',' 21 22 4% 0.17 1663 [@newDB, @oldDB].each { |db| 23 # Note that the below is a performance hack... 24 # Apparently comparing object Object#id is SOOO MUCH faster!! 25 # service_num = (db == @newDB) ? new_service_num : old_service_num 26 23% 1.02 6652 service_num = (db.id == @newDB.id) ? new_service_num : old_service_num 27 db.store(service_num, [area, exchange_name]) \ 28 29% 1.25 3326 if db[service_num].nil? 29 } 30 } 31 0% 0.00 1 @dbfile.close 32 end 33 34 0% 0.00 1 def lookup(number) 35 0% 0.00 4 record = [] 36 catch :done do 37 0% 0.00 12 (1 .. number.size).each { |i| 38 0% 0.02 20 target_service_num = number[0..-i] 39 40 0% 0.00 20 [@newDB, @oldDB].each { |db| 41 0% 0.02 38 record = db[target_service_num] 42 0% 0.00 38 throw :done unless record.nil? 43 } 44 } 45 end 46 0% 0.00 4 return record 47 end 48 end 49 50 0% 0.00 1 def main 51 0% 0.00 1 db = AreaCodeDB.new("areacode_db.csv") 52 0% 0.00 1 db.load 53 54 0% 0.00 1 puts db.lookup("00320519999").inspect 55 0% 0.00 1 puts db.lookup("00321412222").inspect 56 0% 0.00 1 puts db.lookup("00302897333").inspect 57 0% 0.00 1 puts db.lookup("foobar").inspect 58 end 59 60 0% 0.00 1 main --------------080706020308050501090503 Content-Type: text/plain; name="foo.profile" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="foo.profile" =========== ./profiler.rb Line time% time count 1 module LineProfiler__ 2 lastNow = Start = Process.times[0] 3 lastFile = '(toplevel)' 4 lastLine = 0 5 lastTimes = [0.0] 6 lastCounts = [0] 7 Files = {} 8 9 p = proc { |event, file, line, id, binding, klass| 10 if event == 'line' 11 now = Process.times[0] 12 lastTimes[ lastLine ] += now - lastNow 13 lastCounts[ lastLine ] += 1 14 if lastFile != file 15 (lastTimes, lastCounts) = Files.fetch(file) { |name| 16 Files[name] = [ Array.new(10000, 0.0), Array.new(10000, 0) ] 17 } 18 lastFile = file 19 end 20 lastLine = line 21 lastNow = Process.times[0] 22 end 23 } 24 25 END { 26 set_trace_func nil 27 total = Process.times[0] - Start 28 total /= 100.0 # convert to percent 29 f = STDERR 30 for file in Files.keys.sort 31 f.printf("=========== %s\n", file) 32 f.printf(" Line time%% time count\n", file) 33 lines = IO.readlines(file) 34 (times, counts) = Files[file] 35 lines.each_index do |line| 36 if counts[line+1] > 0 37 f.printf("%5d %3.0f%% %6.2f %6d %s", 38 line+1, times[line+1]/total, times[line+1], counts[line+1], 39 lines[line]) 40 else 41 f.printf("%5d %s", line+1, lines[line]) 42 end 43 end 44 end 45 f.close 46 } 47 48 set_trace_func p 49 end 50 51 =========== foo.rb Line time% time count 1 #!/usr/bin/ruby 2 3 0% 0.00 1 class AreaCodeDB 4 0% 0.00 1 def initialize(filename) 5 0% 0.00 1 @oldDB = {} 6 0% 0.00 1 @newDB = {} 7 begin 8 0% 0.00 1 @dbfile = File.new(filename, "r") 9 rescue SystemCallError 10 puts "Fatal Error: #{$!}" 11 ensure 12 0% 0.00 1 @dbfile.close if @dbfile.nil? 13 0% 0.00 1 end 14 end 15 0% 0.00 1 attr_reader :oldDB, :newDB 16 17 0% 0.00 1 def load 18 0% 0.00 1 @dbfile.each_line { |line| 19 9% 0.50 1663 line.chomp!.gsub! /"|x/, "" 20 7% 0.38 1663 area, exchange_name, old_service_num, new_service_num = line.split ',' 21 22 5% 0.25 1663 [@newDB, @oldDB].each { |db| 23 # Note that the below is a performance hack... 24 # Apparently comparing object Object#id is SOOO MUCH faster!! 25 40% 2.17 6652 service_num = (db == @newDB) ? new_service_num : old_service_num 26 #service_num = (db.id == @newDB.id) ? new_service_num : old_service_num 27 db.store(service_num, [area, exchange_name]) \ 28 25% 1.33 3326 if db[service_num].nil? 29 } 30 } 31 0% 0.00 1 @dbfile.close 32 end 33 34 0% 0.00 1 def lookup(number) 35 0% 0.00 4 record = [] 36 catch :done do 37 0% 0.00 12 (1 .. number.size).each { |i| 38 0% 0.00 20 target_service_num = number[0..-i] 39 40 0% 0.00 20 [@newDB, @oldDB].each { |db| 41 0% 0.00 38 record = db[target_service_num] 42 0% 0.00 38 throw :done unless record.nil? 43 } 44 } 45 end 46 0% 0.02 4 return record 47 end 48 end 49 50 0% 0.00 1 def main 51 0% 0.00 1 db = AreaCodeDB.new("areacode_db.csv") 52 0% 0.00 1 db.load 53 54 0% 0.00 1 puts db.lookup("00320519999").inspect 55 0% 0.00 1 puts db.lookup("00321412222").inspect 56 0% 0.00 1 puts db.lookup("00302897333").inspect 57 0% 0.00 1 puts db.lookup("foobar").inspect 58 end 59 60 0% 0.00 1 main --------------080706020308050501090503--