Skip to content

Instantly share code, notes, and snippets.

@dsalazar32

dsalazar32/split-prof-threaded.txt

Created October 23, 2015 19:55
Show Gist options
  • Save dsalazar32/a69c6cfd7ad16a5f788f to your computer and use it in GitHub Desktop.
Save dsalazar32/a69c6cfd7ad16a5f788f to your computer and use it in GitHub Desktop.
Download ZIP
csvspltr ruby-prof with thread results.
Raw
split-prof-threaded.txt
root@vagrant-ubuntu-trusty-64:~/csvspltr/ruby# ruby csvspltr splt ../sample/star2002-1.csv --lines=500 --prof=true --threads=1
Measure Mode: wall_time
Thread ID: 70190973860240
Fiber ID: 70190975775960
Total Time: 12.301637887954712
Sort by: total_time
%total %self total self wait child calls Name
--------------------------------------------------------------------------------
100.00% 0.00% 12.302 0.000 0.000 12.302 1 Csvspltr#splt
12.302 0.000 0.000 12.302 1/1 Csvspltr#execute
--------------------------------------------------------------------------------
12.302 0.000 0.000 12.302 1/1 Csvspltr#splt
100.00% 0.00% 12.302 0.000 0.000 12.302 1 Csvspltr#execute
12.302 0.000 0.000 12.302 1/1 <Class::IO>#open
0.000 0.000 0.000 0.000 1/2 Class#new
0.000 0.000 0.000 0.000 1/1 Csvspltr::Sprntr#finish!
0.000 0.000 0.000 0.000 3/3 Thor::CoreExt::HashWithIndifferentAccess#[]
--------------------------------------------------------------------------------
12.302 0.000 0.000 12.302 1/1 Csvspltr#execute
100.00% 0.00% 12.302 0.000 0.000 12.302 1 <Class::IO>#open
12.302 4.321 3.384 4.596 1/1 IO#each
0.000 0.000 0.000 0.000 1/1 File#initialize
0.000 0.000 0.000 0.000 1/1 IO#closed?
0.000 0.000 0.000 0.000 1/1 IO#close
--------------------------------------------------------------------------------
12.302 4.321 3.384 4.596 1/1 <Class::IO>#open
100.00% 35.13% 12.302 4.321 3.384 4.596 1 IO#each
3.188 2.793 0.031 0.364 5000000/5000000 Csvspltr#flush_to_file
0.827 0.827 0.000 0.000 5000000/5000000 IO#lineno
0.582 0.553 0.029 0.000 4990000/4990000 IO#eof?
--------------------------------------------------------------------------------
3.188 2.793 0.031 0.364 5000000/5000000 IO#each
25.91% 22.71% 3.188 2.793 0.031 0.364 5000000 Csvspltr#flush_to_file
0.279 0.017 0.024 0.238 10000/10000 Csvspltr::Sprntr#run
0.070 0.018 0.000 0.052 10000/10000 Csvspltr#filename
0.015 0.012 0.000 0.003 10000/10000 <Class::Proc>#new
--------------------------------------------------------------------------------
0.827 0.827 0.000 0.000 5000000/5000000 IO#each
6.72% 6.72% 0.827 0.827 0.000 0.000 5000000 IO#lineno
--------------------------------------------------------------------------------
0.582 0.553 0.029 0.000 4990000/4990000 IO#each
4.73% 4.49% 0.582 0.553 0.029 0.000 4990000 IO#eof?
--------------------------------------------------------------------------------
0.279 0.017 0.024 0.238 10000/10000 Csvspltr#flush_to_file
2.27% 0.14% 0.279 0.017 0.024 0.238 10000 Csvspltr::Sprntr#run
0.238 0.009 0.000 0.230 10000/10000 Csvspltr::Sprntr#asyncrun
--------------------------------------------------------------------------------
0.238 0.009 0.000 0.230 10000/10000 Csvspltr::Sprntr#run
1.94% 0.07% 0.238 0.009 0.000 0.230 10000 Csvspltr::Sprntr#asyncrun
0.230 0.230 0.000 0.000 10000/10000 Thread::Queue#push
--------------------------------------------------------------------------------
0.230 0.230 0.000 0.000 10000/10000 Csvspltr::Sprntr#asyncrun
1.87% 1.87% 0.230 0.230 0.000 0.000 10000 Thread::Queue#push
--------------------------------------------------------------------------------
0.070 0.018 0.000 0.052 10000/10000 Csvspltr#flush_to_file
0.57% 0.15% 0.070 0.018 0.000 0.052 10000 Csvspltr#filename
0.023 0.023 0.000 0.000 10000/10000 String#%
0.016 0.016 0.000 0.000 10000/10000 <Class::File>#join
0.012 0.012 0.000 0.000 10000/10000 String#gsub
0.000 0.000 0.000 0.000 1/1 Csvspltr#filepath
0.000 0.000 0.000 0.000 1/1 Csvspltr#fileptrn
--------------------------------------------------------------------------------
0.023 0.023 0.000 0.000 10000/10000 Csvspltr#filename
0.19% 0.19% 0.023 0.023 0.000 0.000 10000 String#%
--------------------------------------------------------------------------------
0.016 0.016 0.000 0.000 10000/10000 Csvspltr#filename
0.13% 0.13% 0.016 0.016 0.000 0.000 10000 <Class::File>#join
--------------------------------------------------------------------------------
0.015 0.012 0.000 0.003 10000/10000 Csvspltr#flush_to_file
0.12% 0.10% 0.015 0.012 0.000 0.003 10000 <Class::Proc>#new
0.003 0.003 0.000 0.000 10000/10000 BasicObject#initialize
--------------------------------------------------------------------------------
0.012 0.012 0.000 0.000 10000/10000 Csvspltr#filename
0.10% 0.10% 0.012 0.012 0.000 0.000 10000 String#gsub
--------------------------------------------------------------------------------
0.003 0.003 0.000 0.000 10000/10000 <Class::Proc>#new
0.02% 0.02% 0.003 0.003 0.000 0.000 10000 BasicObject#initialize
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#filename
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Csvspltr#filepath
0.000 0.000 0.000 0.000 1/1 FileUtils#mkdir_p
0.000 0.000 0.000 0.000 1/1 <Class::File>#dirname
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#filepath
0.00% 0.00% 0.000 0.000 0.000 0.000 1 FileUtils#mkdir_p
0.000 0.000 0.000 0.000 1/2 Array#each
0.000 0.000 0.000 0.000 1/1 FileUtils#fu_check_options
0.000 0.000 0.000 0.000 1/1 FileUtils#fu_list
0.000 0.000 0.000 0.000 1/2 Array#map
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/2 Csvspltr::Sprntr#runners
0.000 0.000 0.000 0.000 1/2 Csvspltr#execute
0.00% 0.00% 0.000 0.000 0.000 0.000 2 *Class#new
0.000 0.000 0.000 0.000 1/1 Csvspltr::Sprntr#initialize
0.000 0.000 0.000 0.000 1/1 Thread::Queue#initialize
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Class#new
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Csvspltr::Sprntr#initialize
0.000 0.000 0.000 0.000 1/1 Csvspltr::Sprntr#runners
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr::Sprntr#initialize
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Csvspltr::Sprntr#runners
0.000 0.000 0.000 0.000 1/1 Integer#times
0.000 0.000 0.000 0.000 1/2 Class#new
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/2 FileUtils#fu_check_options
0.000 0.000 0.000 0.000 1/2 FileUtils#mkdir_p
0.00% 0.00% 0.000 0.000 0.000 0.000 2 Array#each
0.000 0.000 0.000 0.000 1/1 FileUtils#fu_mkdir
0.000 0.000 0.000 0.000 3/3 Hash#delete
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr::Sprntr#runners
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Integer#times
0.000 0.000 0.000 0.000 1/1 <Class::Thread>#new
0.000 0.000 0.000 0.000 1/1 Kernel#method
0.000 0.000 0.000 0.000 1/1 Method#to_proc
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Array#each
0.00% 0.00% 0.000 0.000 0.000 0.000 1 FileUtils#fu_mkdir
0.000 0.000 0.000 0.000 1/1 <Class::Dir>#mkdir
0.000 0.000 0.000 0.000 1/2 FileUtils#remove_tailing_slash
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 FileUtils#fu_mkdir
0.00% 0.00% 0.000 0.000 0.000 0.000 1 <Class::Dir>#mkdir
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Integer#times
0.00% 0.00% 0.000 0.000 0.000 0.000 1 <Class::Thread>#new
0.000 0.000 0.000 0.000 1/1 Thread#initialize
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 <Class::Thread>#new
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Thread#initialize
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#execute
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Csvspltr::Sprntr#finish!
0.000 0.000 0.000 0.000 2/2 Csvspltr::Sprntr#idle?
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 <Class::IO>#open
0.00% 0.00% 0.000 0.000 0.000 0.000 1 File#initialize
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 FileUtils#mkdir_p
0.00% 0.00% 0.000 0.000 0.000 0.000 1 FileUtils#fu_check_options
0.000 0.000 0.000 0.000 1/1 Kernel#dup
0.000 0.000 0.000 0.000 1/2 Array#each
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/2 FileUtils#fu_list
0.000 0.000 0.000 0.000 1/2 FileUtils#mkdir_p
0.00% 0.00% 0.000 0.000 0.000 0.000 2 Array#map
0.000 0.000 0.000 0.000 1/2 FileUtils#remove_tailing_slash
0.000 0.000 0.000 0.000 1/1 <Class::File>#path
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 2/2 Csvspltr::Sprntr#finish!
0.00% 0.00% 0.000 0.000 0.000 0.000 2 Csvspltr::Sprntr#idle?
0.000 0.000 0.000 0.000 2/2 Array#count
0.000 0.000 0.000 0.000 2/2 Thread::Queue#num_waiting
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 FileUtils#mkdir_p
0.00% 0.00% 0.000 0.000 0.000 0.000 1 FileUtils#fu_list
0.000 0.000 0.000 0.000 1/2 Array#map
0.000 0.000 0.000 0.000 1/1 Array#flatten
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 3/3 Csvspltr#execute
0.00% 0.00% 0.000 0.000 0.000 0.000 3 Thor::CoreExt::HashWithIndifferentAccess#[]
0.000 0.000 0.000 0.000 3/3 Thor::CoreExt::HashWithIndifferentAccess#convert_key
0.000 0.000 0.000 0.000 3/3 Hash#[]
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#filename
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Csvspltr#fileptrn
0.000 0.000 0.000 0.000 1/1 <Class::File>#basename
0.000 0.000 0.000 0.000 1/1 String#split
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 3/3 Thor::CoreExt::HashWithIndifferentAccess#[]
0.00% 0.00% 0.000 0.000 0.000 0.000 3 Thor::CoreExt::HashWithIndifferentAccess#convert_key
0.000 0.000 0.000 0.000 3/3 Symbol#to_s
0.000 0.000 0.000 0.000 3/3 Kernel#is_a?
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/2 FileUtils#fu_mkdir
0.000 0.000 0.000 0.000 1/2 Array#map
0.00% 0.00% 0.000 0.000 0.000 0.000 2 FileUtils#remove_tailing_slash
0.000 0.000 0.000 0.000 2/2 String#chomp
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 FileUtils#fu_check_options
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Kernel#dup
0.000 0.000 0.000 0.000 1/1 Kernel#initialize_dup
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 2/2 Csvspltr::Sprntr#idle?
0.00% 0.00% 0.000 0.000 0.000 0.000 2 Array#count
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 <Class::IO>#open
0.00% 0.00% 0.000 0.000 0.000 0.000 1 IO#closed?
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#fileptrn
0.00% 0.00% 0.000 0.000 0.000 0.000 1 <Class::File>#basename
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Array#map
0.00% 0.00% 0.000 0.000 0.000 0.000 1 <Class::File>#path
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Kernel#dup
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Kernel#initialize_dup
0.000 0.000 0.000 0.000 1/1 Hash#initialize_copy
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Class#new
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Thread::Queue#initialize
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 2/2 Csvspltr::Sprntr#idle?
0.00% 0.00% 0.000 0.000 0.000 0.000 2 Thread::Queue#num_waiting
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 <Class::IO>#open
0.00% 0.00% 0.000 0.000 0.000 0.000 1 IO#close
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#fileptrn
0.00% 0.00% 0.000 0.000 0.000 0.000 1 String#split
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Integer#times
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Kernel#method
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 2/2 FileUtils#remove_tailing_slash
0.00% 0.00% 0.000 0.000 0.000 0.000 2 String#chomp
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 FileUtils#fu_list
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Array#flatten
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 3/3 Array#each
0.00% 0.00% 0.000 0.000 0.000 0.000 3 Hash#delete
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Csvspltr#filepath
0.00% 0.00% 0.000 0.000 0.000 0.000 1 <Class::File>#dirname
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Integer#times
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Method#to_proc
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 3/3 Thor::CoreExt::HashWithIndifferentAccess#[]
0.00% 0.00% 0.000 0.000 0.000 0.000 3 Hash#[]
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 1/1 Kernel#initialize_dup
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Hash#initialize_copy
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 3/3 Thor::CoreExt::HashWithIndifferentAccess#convert_key
0.00% 0.00% 0.000 0.000 0.000 0.000 3 Symbol#to_s
--------------------------------------------------------------------------------
0.000 0.000 0.000 0.000 3/3 Thor::CoreExt::HashWithIndifferentAccess#convert_key
0.00% 0.00% 0.000 0.000 0.000 0.000 3 Kernel#is_a?
* indicates recursively called methods
Measure Mode: wall_time
Thread ID: 70190975775200
Fiber ID: 70190975755720
Total Time: 12.300384044647217
Sort by: total_time
%total %self total self wait child calls Name
--------------------------------------------------------------------------------
100.00% 0.00% 12.300 0.000 0.000 12.300 1 Csvspltr::Sprntr#running
12.300 0.016 0.000 12.284 1/1 Kernel#loop
--------------------------------------------------------------------------------
12.300 0.016 0.000 12.284 1/1 Csvspltr::Sprntr#running
100.00% 0.13% 12.300 0.016 0.000 12.284 1 Kernel#loop
8.181 0.137 8.045 0.000 10001/10001 Thread::Queue#pop
4.103 0.012 0.000 4.091 10000/10000 Proc#call
--------------------------------------------------------------------------------
8.181 0.137 8.045 0.000 10001/10001 Kernel#loop
66.51% 1.11% 8.181 0.137 8.045 0.000 10001 Thread::Queue#pop
--------------------------------------------------------------------------------
4.103 0.012 0.000 4.091 10000/10000 Kernel#loop
33.36% 0.10% 4.103 0.012 0.000 4.091 10000 Proc#call
4.091 0.023 0.000 4.069 10000/10000 <Class::IO>#open
--------------------------------------------------------------------------------
4.091 0.023 0.000 4.069 10000/10000 Proc#call
33.26% 0.18% 4.091 0.023 0.000 4.069 10000 <Class::IO>#open
3.692 1.044 0.019 2.629 10000/10000 Array#each
0.226 0.169 0.058 0.000 10000/10000 File#initialize
0.148 0.082 0.066 0.000 10000/10000 IO#close
0.002 0.002 0.000 0.000 10000/10000 IO#closed?
--------------------------------------------------------------------------------
3.692 1.044 0.019 2.629 10000/10000 <Class::IO>#open
30.02% 8.49% 3.692 1.044 0.019 2.629 10000 Array#each
2.629 1.984 0.646 0.000 5000000/5000000 IO#write
--------------------------------------------------------------------------------
2.629 1.984 0.646 0.000 5000000/5000000 Array#each
21.38% 16.13% 2.629 1.984 0.646 0.000 5000000 IO#write
--------------------------------------------------------------------------------
0.226 0.169 0.058 0.000 10000/10000 <Class::IO>#open
1.84% 1.37% 0.226 0.169 0.058 0.000 10000 File#initialize
--------------------------------------------------------------------------------
0.148 0.082 0.066 0.000 10000/10000 <Class::IO>#open
1.21% 0.67% 0.148 0.082 0.066 0.000 10000 IO#close
--------------------------------------------------------------------------------
0.002 0.002 0.000 0.000 10000/10000 <Class::IO>#open
0.02% 0.02% 0.002 0.002 0.000 0.000 10000 IO#closed?
--------------------------------------------------------------------------------
0.00% 0.00% 0.000 0.000 0.000 0.000 1 Fixnum#to_s
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment