From: Jan Svitok Date: 2006-11-30T03:07:18+09:00 Subject: Re: ruby profile gave different result in Windows and Linux On 11/29/06, Luan wrote: > > Hi All, > > I am using "ruby -r profile prog" for the same program between Windows and > Linux. > > I got the different result. In Windows, I got > > calls > 9.52 0.35 0.06 865 0.07 0.07 Module#method_added > > but in Linux, I only got > calls > 0.00 0.23 0.00 17 0.00 0.00 Module#method_added > > > Do you know why there's a big different between the two? > > Thanks for your help. > Luan > > Here is the full result > > > Linux > > % cumulative self self total > time seconds seconds calls ms/call ms/call name > 42.86 0.10 0.10 62 1.61 6.72 Hash#each > 14.29 0.13 0.03 7 4.76 14.29 Array#each > 7.14 0.15 0.02 138 0.12 0.12 Fixnum#+ > 7.14 0.17 0.02 282 0.06 0.06 Hash#[] > 7.14 0.18 0.02 80 0.21 0.21 Float#/ > 7.14 0.20 0.02 1 16.67 133.33 Kernel.loop > 7.14 0.22 0.02 22 0.76 0.76 Ir#calc_doc_freq > 7.14 0.23 0.02 462 0.04 0.04 Float#** > 0.00 0.23 0.00 22 0.00 0.00 Ir#calc_term_weight > 0.00 0.23 0.00 1 0.00 83.33 > Ir#process_relevance_query > 0.00 0.23 0.00 5 0.00 0.00 Fixnum#- > 0.00 0.23 0.00 3 0.00 16.67 IO#open > 0.00 0.23 0.00 152 0.00 0.00 Hash#[]= > 0.00 0.23 0.00 2 0.00 0.00 Array#include? > 0.00 0.23 0.00 1 0.00 0.00 Ir#relevance_query > 0.00 0.23 0.00 1 0.00 33.33 Ir#process_query > 0.00 0.23 0.00 4 0.00 0.00 Hash#has_key? > 0.00 0.23 0.00 2 0.00 0.00 Float#- > 0.00 0.23 0.00 1 0.00 0.00 > Ir#calc_relevance_query > 0.00 0.23 0.00 7 0.00 0.00 Hash#clear > 0.00 0.23 0.00 67 0.00 0.00 Fixnum#> > 0.00 0.23 0.00 1 0.00 0.00 Dir#[] > 0.00 0.23 0.00 6 0.00 0.00 Float#to_s > 0.00 0.23 0.00 2 0.00 0.00 Kernel.== > 0.00 0.23 0.00 13 0.00 0.00 IO#write > 0.00 0.23 0.00 1 0.00 100.00 > Ir#create_docs_terms_hash > 0.00 0.23 0.00 52 0.00 0.00 Math.log10 > 0.00 0.23 0.00 1 0.00 0.00 Class#inherited > 0.00 0.23 0.00 2 0.00 0.00 > Ir#check_document_exists > 0.00 0.23 0.00 2 0.00 0.00 Ir#print > 0.00 0.23 0.00 20 0.00 0.00 Array#[] > 0.00 0.23 0.00 452 0.00 0.00 Float#+ > 0.00 0.23 0.00 72 0.00 0.00 Float#* > 0.00 0.23 0.00 48 0.00 0.00 Fixnum#to_f > 0.00 0.23 0.00 2 0.00 58.33 > Ir#build_query_similarity > 0.00 0.23 0.00 1 0.00 0.00 Ir#calc_query_weight > 0.00 0.23 0.00 22 0.00 0.76 Ir#calc_term_freq > 0.00 0.23 0.00 105 0.00 0.00 Hash#default > 0.00 0.23 0.00 6 0.00 0.00 IO#gets > 0.00 0.23 0.00 2 0.00 0.00 Hash#empty? > 0.00 0.23 0.00 12 0.00 0.00 Math.sqrt > 0.00 0.23 0.00 4 0.00 0.00 String#split > 0.00 0.23 0.00 17 0.00 5.88 Class#new > 0.00 0.23 0.00 2 0.00 0.00 String#== > 0.00 0.23 0.00 2 0.00 0.00 Hash#sort > 0.00 0.23 0.00 119 0.00 0.00 String#downcase > 0.00 0.23 0.00 1 0.00 100.00 Ir#initialize > 0.00 0.23 0.00 3 0.00 0.00 File#initialize > 0.00 0.23 0.00 1 0.00 0.00 Kernel.lambda > 0.00 0.23 0.00 17 0.00 0.00 Module#method_added > 0.00 0.23 0.00 6 0.00 0.00 Float#> > 0.00 0.23 0.00 13 0.00 0.00 Kernel.printf > 0.00 0.23 0.00 6 0.00 0.00 Proc#call > 0.00 0.23 0.00 16 0.00 0.00 Hash#initialize > 0.00 0.23 0.00 1 0.00 0.00 Ir#non_relevance_query > 0.00 0.23 0.00 2 0.00 0.00 String#chomp > 0.00 0.23 0.00 4 0.00 0.00 Float#<=> > 0.00 0.23 0.00 4 0.00 0.00 Kernel.gets > 0.00 0.23 0.00 1 0.00 50.00 > Ir#calc_term_weight_for_hash > 0.00 0.23 0.00 22 0.00 0.00 Float#to_f > 0.00 0.23 0.00 1 0.00 233.33 #toplevel > > > > > Windows > > > % cumulative self self total > time seconds seconds calls ms/call ms/call name > 22.31 0.14 0.14 30 4.77 37.43 Kernel.require > 22.00 0.28 0.14 63 2.24 8.94 Hash#each > 9.52 0.35 0.06 865 0.07 0.07 Module#method_added > 7.33 0.39 0.05 174 0.27 0.36 String#gsub! > 4.84 0.42 0.03 462 0.07 0.07 Float#** > 4.84 0.45 0.03 174 0.18 0.54 Config.expand > 4.84 0.49 0.03 16 1.94 4.94 Array#each > 4.84 0.52 0.03 452 0.07 0.07 Float#+ > 2.50 0.53 0.02 52 0.31 0.31 Math.log10 > 2.50 0.55 0.02 122 0.13 0.13 Kernel.dup > 2.50 0.56 0.02 1 16.00 94.00 Hash#each_value > 2.50 0.58 0.02 15 1.07 1.07 Module#private > 2.34 0.60 0.02 20 0.75 0.75 Module#module_eval > 2.34 0.61 0.02 105 0.14 0.14 Symbol#=== > 2.34 0.63 0.01 527 0.03 0.03 Hash#[]= > 0.00 0.63 0.00 19 0.00 0.00 > Gem::Specification#attribute > 0.00 0.63 0.00 48 0.00 0.00 Fixnum#to_f > 0.00 0.63 0.00 2 0.00 78.00 > Ir#build_query_similarity > 0.00 0.63 0.00 3 0.00 0.00 Array#join > 0.00 0.63 0.00 1 0.00 0.00 Gem.user_home > 0.00 0.63 0.00 1 0.00 0.00 > Ir#calc_relevance_query > 0.00 0.63 0.00 1 0.00 0.00 Module#extended > 0.00 0.63 0.00 70 0.00 0.00 Symbol#to_s > 0.00 0.63 0.00 28 0.00 0.00 Module#attr_accessor > 0.00 0.63 0.00 1 0.00 0.00 Ir#relevance_query > 0.00 0.63 0.00 3 0.00 0.00 Hash#keys > 0.00 0.63 0.00 7 0.00 0.00 > Gem::Specification#required_attribute > 0.00 0.63 0.00 44 0.00 0.00 Array#<< > 0.00 0.63 0.00 1 0.00 46.00 Ir#process_query > 0.00 0.63 0.00 13 0.00 0.00 Kernel.printf > 0.00 0.63 0.00 22 0.00 0.73 Ir#calc_doc_freq > 0.00 0.63 0.00 1 0.00 0.00 String#chomp! > 0.00 0.63 0.00 3 0.00 0.00 Module#public > 0.00 0.63 0.00 1 0.00 156.00 Kernel.loop > 0.00 0.63 0.00 2 0.00 0.00 Hash#empty? > 0.00 0.63 0.00 1 0.00 47.00 > Ir#calc_term_weight_for_hash > 0.00 0.63 0.00 2 0.00 0.00 String#chomp > 0.00 0.63 0.00 1 0.00 0.00 > Gem::Version::Requirement#default > 0.00 0.63 0.00 10 0.00 0.00 > Gem::Specification#overwrite_accessor > 0.00 0.63 0.00 1 0.00 0.00 > Forwardable.def_delegators > 0.00 0.63 0.00 1 0.00 0.00 Module#alias_method > 0.00 0.63 0.00 5 0.00 0.00 Hash#merge > 0.00 0.63 0.00 72 0.00 0.00 Float#* > 0.00 0.63 0.00 6 0.00 0.00 Proc#call > 0.00 0.63 0.00 1 0.00 110.00 > Ir#process_relevance_query > 0.00 0.63 0.00 2 0.00 0.00 Ir#print > 0.00 0.63 0.00 16 0.00 0.00 Hash#initialize > 0.00 0.63 0.00 6 0.00 0.00 Float#> > 0.00 0.63 0.00 2 0.00 0.00 Regexp#match > 0.00 0.63 0.00 1 0.00 94.00 Ir#initialize > 0.00 0.63 0.00 2 0.00 0.00 MatchData#[] > 0.00 0.63 0.00 3 0.00 5.33 IO#open > 0.00 0.63 0.00 75 0.00 0.00 String#[] > 0.00 0.63 0.00 9 0.00 1.67 > Gem::Specification#array_attribute > 0.00 0.63 0.00 6 0.00 0.00 Float#to_s > 0.00 0.63 0.00 2 0.00 0.00 Kernel.== > 0.00 0.63 0.00 2 0.00 0.00 > Module#private_class_method > 0.00 0.63 0.00 11 0.00 0.00 Module#included > 0.00 0.63 0.00 7 0.00 0.00 Hash#clear > 0.00 0.63 0.00 11 0.00 0.00 Module#include > 0.00 0.63 0.00 5 0.00 3.00 Hash#each_pair > 0.00 0.63 0.00 4 0.00 0.00 Hash#has_key? > 0.00 0.63 0.00 2 0.00 0.00 Array#collect > 0.00 0.63 0.00 1 0.00 0.00 > Gem::Version::Requirement#parse > 0.00 0.63 0.00 7 0.00 0.00 Array#first > 0.00 0.63 0.00 7 0.00 0.00 Regexp#quote > 0.00 0.63 0.00 11 0.00 0.00 Module#append_features > 0.00 0.63 0.00 2 0.00 0.00 Float#- > 0.00 0.63 0.00 2 0.00 0.00 Array#include? > 0.00 0.63 0.00 2 0.00 0.00 Module#module_function > 0.00 0.63 0.00 2 0.00 0.00 > Ir#check_document_exists > 0.00 0.63 0.00 22 0.00 0.00 Ir#calc_term_freq > 0.00 0.63 0.00 1 0.00 0.00 File#join > 0.00 0.63 0.00 1 0.00 0.00 Kernel.extend > 0.00 0.63 0.00 4 0.00 0.00 String#split > 0.00 0.63 0.00 22 0.00 0.00 Array#[] > 0.00 0.63 0.00 10 0.00 0.00 Module#remove_method > 0.00 0.63 0.00 12 0.00 0.00 Math.sqrt > 0.00 0.63 0.00 4 0.00 0.00 Kernel.gets > 0.00 0.63 0.00 8 0.00 0.00 Kernel.lambda > 0.00 0.63 0.00 1 0.00 0.00 Ir#non_relevance_query > 0.00 0.63 0.00 126 0.00 0.00 Hash#default > 0.00 0.63 0.00 138 0.00 0.00 Fixnum#+ > 0.00 0.63 0.00 3 0.00 0.00 > Module#method_undefined > 0.00 0.63 0.00 165 0.00 0.00 > Kernel.singleton_method_added > 0.00 0.63 0.00 6 0.00 0.00 Kernel.kind_of? > 0.00 0.63 0.00 5 0.00 0.00 Hash#initialize_copy > 0.00 0.63 0.00 2 0.00 0.00 Hash#sort > 0.00 0.63 0.00 5 0.00 0.00 Float#<=> > 0.00 0.63 0.00 1 0.00 94.00 > Ir#create_docs_terms_hash > 0.00 0.63 0.00 4 0.00 0.00 String#== > 0.00 0.63 0.00 2 0.00 8.00 > Gem::Specification#read_only > 0.00 0.63 0.00 2 0.00 0.00 > Forwardable.def_instance_delegator > 0.00 0.63 0.00 8 0.00 0.00 Kernel.eval > 0.00 0.63 0.00 2 0.00 7.50 Module#attr > 0.00 0.63 0.00 14 0.00 0.00 Regexp#to_s > 0.00 0.63 0.00 1 0.00 0.00 Gem.ssl_available? > 0.00 0.63 0.00 9 0.00 0.00 Module#class_eval > 0.00 0.63 0.00 80 0.00 0.00 Float#/ > 0.00 0.63 0.00 5 0.00 3.00 > Gem::Security::Policy#initialize > 0.00 0.63 0.00 1 0.00 0.00 Ir#calc_query_weight > 0.00 0.63 0.00 78 0.00 0.00 Fixnum#* > 0.00 0.63 0.00 119 0.00 0.00 String#downcase > 0.00 0.63 0.00 68 0.00 0.00 Fixnum#> > 0.00 0.63 0.00 1 0.00 0.00 Dir#[] > 0.00 0.63 0.00 2 0.00 0.00 Module#attr_writer > 0.00 0.63 0.00 10 0.00 0.00 Module#method_removed > 0.00 0.63 0.00 13 0.00 0.00 IO#write > 0.00 0.63 0.00 1 0.00 0.00 Gem.find_home > 0.00 0.63 0.00 4 0.00 0.00 Fixnum#- > 0.00 0.63 0.00 1 0.00 0.00 > Gem::Version::Requirement#initialize > 0.00 0.63 0.00 3 0.00 0.00 File#initialize > 0.00 0.63 0.00 22 0.00 0.00 Float#to_f > 0.00 0.63 0.00 3 0.00 0.00 ENV.[] > 0.00 0.63 0.00 2 0.00 0.00 > Gem::Specification#attributes > 0.00 0.63 0.00 122 0.00 0.00 String#initialize_copy > 0.00 0.63 0.00 355 0.00 0.00 Hash#[] > 0.00 0.63 0.00 1 0.00 0.00 > Gem::Version#initialize > 0.00 0.63 0.00 1 0.00 0.00 Gem::Version#correct? > 0.00 0.63 0.00 26 0.00 4.19 Class#new > 0.00 0.63 0.00 2 0.00 0.00 File#dirname > 0.00 0.63 0.00 119 0.00 0.00 Class#inherited > 0.00 0.63 0.00 1 0.00 0.00 Module#extend_object > 0.00 0.63 0.00 18 0.00 0.00 Module#define_method > 0.00 0.63 0.00 6 0.00 0.00 IO#gets > 0.00 0.63 0.00 22 0.00 0.00 Ir#calc_term_weight > 0.00 0.63 0.00 4 0.00 0.00 > Gem::Specification#attribute_alias_singular > 0.00 0.63 0.00 2 0.00 0.00 Regexp#initialize > 0.00 0.64 0.00 1 0.00 641.00 #toplevel You are using gems on windows. compare the function lists. Set RUBYOPT to empty string before running the program (in a cmd session): set RUBYOPT= ruby -r profile prog