I have a small test script (ruby 2.6.8p205)
x = 0
1000000.times do
x = Time.now.to_i
end
And when I profile it the biggest issue is
% cumulative self self total
time seconds seconds calls ms/call ms/call name
43.05 9.71 9.71 1000000 0.01 0.02 nil#
What is nil# and is there any way to mitigate it?
Use stackprof
On Oct 29, 2021, at 03:29, Peter Hickman <peterhickman386@googlemail.com> wrote:
I have a small test script (ruby 2.6.8p205)
x = 0
1000000.times do
x = Time.now.to_i
endAnd when I profile it the biggest issue is
% cumulative self self total
time seconds seconds calls ms/call ms/call name
43.05 9.71 9.71 1000000 0.01 0.02 nil#What is nil# and is there any way to mitigate it?
Unsubscribe: <mailto:ruby-talk-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-talk>
The "nil#" calls are the (anonymous) block being called:
$ ruby -rprofile -e '1.times do end' |& fgrep 'nil#'
0.00 0.00 0.00 1 0.00 0.00 nil#
$ ruby -rprofile -e '10.times do end' |& fgrep 'nil#'
1.41 0.00 0.00 10 0.00 0.00 nil#
$ ruby -rprofile -e '100.times do end' |& fgrep 'nil#'
9.80 0.00 0.00 100 0.00 0.00 nil#
$ ruby -rprofile -e '->{}.call' |& fgrep 'nil#'
0.33 0.00 0.00 1 0.01 0.01 nil#
$ ruby -rprofile -e '->{}' |& fgrep 'nil#'
0.35 0.00 0.00 1 0.01 0.01 nil#
$ ruby -rprofile -e '->{};->{}' |& fgrep 'nil#'
0.51 0.00 0.00 2 0.01 0.01 nil#
$ ruby -rprofile -e '->{};->{};->{}' |& fgrep 'nil#'
0.51 0.00 0.00 3 0.00 0.00 nil#
$ ruby -rprofile -e '->{};->{};->{};->{}' |& fgrep 'nil#'
0.99 0.00 0.00 4 0.01 0.01 nil#
On 10/29/21, Peter Hickman <peterhickman386@googlemail.com> wrote:
1000000.times do
end% cumulative self self total
time seconds seconds calls ms/call ms/call name
43.05 9.71 9.71 1000000 0.01 0.02 nil#What is nil# and is there any way to mitigate it?
And if inside a class method, those calls are counted as such:
$ ruby -rprofile -e 'class Foo;def bar;1.times do
end;end;end;Foo.new.bar' |& fgrep 'Foo#bar'
0.73 0.00 0.00 2 0.01 0.02 Foo#bar
$ ruby -rprofile -e 'class Foo;def bar;10.times do
end;end;end;Foo.new.bar' |& fgrep 'Foo#bar'
5.41 0.00 0.00 11 0.02 0.03 Foo#bar
$ ruby -rprofile -e 'class Foo;def bar;1000.times do
end;end;end;Foo.new.bar' |& fgrep 'Foo#bar'
24.53 0.01 0.00 1001 0.00 0.01 Foo#bar
key = Wrapper.new(tp.defined_class, tp.method_id)
def to_s
"#{defined_class.inspect}#".sub(/\A\#<Class:(.*)>#\z/, '\1.') <<
method_id.to_s
end
On 10/29/21, Frank J. Cameron <fjc@fastmail.net> wrote:
On 10/29/21, Peter Hickman <peterhickman386@googlemail.com> wrote:
1000000.times do
end% cumulative self self total
time seconds seconds calls ms/call ms/call name
43.05 9.71 9.71 1000000 0.01 0.02 nil#What is nil# and is there any way to mitigate it?
The "nil#" calls are the (anonymous) block being called:
$ ruby -rprofile -e '1.times do end' |& fgrep 'nil#'
0.00 0.00 0.00 1 0.00 0.00 nil#$ ruby -rprofile -e '10.times do end' |& fgrep 'nil#'
1.41 0.00 0.00 10 0.00 0.00 nil#
So nil# is just some cryptic internal function. tbh I thought it might be
but wanted to confirm. It is annoying that it takes up so much of the run
time
I was trying to make sense of the cost of Time.now.to_i In an application I
have this gets called a lot. Time object gets created, to_i is called and
the Time object is immediately discarded. Just wanted to get a feel for how
wasteful that might be. A ffi to a C function that just returns the rawtime
as an int (long in C) is faster
But adding a C function is it's own complexity for maintenance and
deployment
So nil# is just some cryptic internal function. tbh I thought it might be
but wanted to confirm. It is annoying that it takes up so much of the run
time
I believe Frank is saying that the report uses standard Ruby
"<Class>#<method_name>" notation for telling us what method is being
called. Because it's a Proc, there's no Class (i.e. nil), and no method
name (i.e. empty string), thus: `nil#`
I was trying to make sense of the cost of Time.now.to_i In an application
I have this gets called a lot. Time object gets created, to_i is called and
the Time object is immediately discarded. Just wanted to get a feel for how
wasteful that might be. A ffi to a C function that just returns the rawtime
as an int (long in C) is faster
But adding a C function is it's own complexity for maintenance and
deployment
I have no reason to suspect that this doesn't still work:
https://rubygems.org/gems/timestamp
And for quite a while now there's been this:
Cheers
On Sat, Oct 30, 2021 at 7:10 AM Peter Hickman < peterhickman386@googlemail.com> wrote:
--
Matthew Kerwin
https://matthew.kerwin.net.au/
$ cat epoch.rb ; ruby epoch.rb
require 'late'
require 'timestamp'
require 'benchmark'
p [Time.now.to_i,
Late.epoch,
Time::unix_timestamp,
Process.clock_gettime(Process::CLOCK_REALTIME, :second)]
Benchmark.bmbm do |x|
x.report("time") {
1_000_000.times {
Time.now.to_i
}
}
x.report("late") {
1_000_000.times {
Late.epoch
}
}
x.report("timestamp") {
1_000_000.times {
Time::unix_timestamp
}
}
x.report("process") {
1_000_000.times {
Process.clock_gettime(Process::CLOCK_REALTIME, :second)
}
}
end
[1635555199, 1635555199, 1635555199, 1635555199]
Rehearsal ---------------------------------------------
time 0.860677 0.331028 1.191705 ( 1.236668)
late 0.077804 0.000000 0.077804 ( 0.078566)
timestamp 0.075141 0.000000 0.075141 ( 0.075973)
process 0.444969 0.303556 0.748525 ( 0.768514)
------------------------------------ total: 2.093175sec
user system total real
time 0.826468 0.332544 1.159012 ( 1.181181)
late 0.076836 0.000000 0.076836 ( 0.077193)
timestamp 0.076191 0.000000 0.076191 ( 0.076319)
process 0.454212 0.328651 0.782863 ( 0.793092)
On 10/29/21, Peter Hickman <peterhickman386@googlemail.com> wrote:
I was trying to make sense of the cost of Time.now.to_i In an application I
have this gets called a lot. Time object gets created, to_i is called and
the Time object is immediately discarded. Just wanted to get a feel for how
wasteful that might be. A ffi to a C function that just returns the rawtime
as an int (long in C) is faster
But adding a C function is it's own complexity for maintenance and
deployment
So nil# is just some cryptic internal function. tbh I thought it might be
but wanted to confirm. It is annoying that it takes up so much of the run
timeI believe Frank is saying that the report uses standard Ruby
"<Class>#<method_name>" notation for telling us what method is being
called. Because it's a Proc, there's no Class (i.e. nil), and no method
name (i.e. empty string), thus: `nil#`I was trying to make sense of the cost of Time.now.to_i In an application
I have this gets called a lot. Time object gets created, to_i is called and
the Time object is immediately discarded. Just wanted to get a feel for how
wasteful that might be. A ffi to a C function that just returns the rawtime
as an int (long in C) is faster
But adding a C function is it's own complexity for maintenance and
deploymentI have no reason to suspect that this doesn't still work:
timestamp | RubyGems.org | your community gem host
And for quite a while now there's been this:
Module: Process (Ruby 3.0.2)
Ah, I thought that something like this (Process.clock_gettime) should exist
but I was looking in the Time class and searching for things like rawtime.
Thanks that I exactly what I am looking for
On Sat, 30 Oct 2021 at 01:12, Matthew Kerwin <matthew@kerwin.net.au> wrote:
On Sat, Oct 30, 2021 at 7:10 AM Peter Hickman < > peterhickman386@googlemail.com> wrote:
Cheers
--
Matthew Kerwin
https://matthew.kerwin.net.au/Unsubscribe: <mailto:ruby-talk-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-talk>
Seriously... Don't use it. Use stackprof for profiling and use benchmark-ips for comparative benchmarking.
On Oct 30, 2021, at 00:20, Peter Hickman <peterhickman386@googlemail.com> wrote:
On Sat, 30 Oct 2021 at 01:12, Matthew Kerwin <matthew@kerwin.net.au> wrote:
On Sat, Oct 30, 2021 at 7:10 AM Peter Hickman <peterhickman386@googlemail.com> wrote:
So nil# is just some cryptic internal function. tbh I thought it might be but wanted to confirm. It is annoying that it takes up so much of the run timeI believe Frank is saying that the report uses standard Ruby "<Class>#<method_name>" notation for telling us what method is being called. Because it's a Proc, there's no Class (i.e. nil), and no method name (i.e. empty string), thus: `nil#`
I was trying to make sense of the cost of Time.now.to_i In an application I have this gets called a lot. Time object gets created, to_i is called and the Time object is immediately discarded. Just wanted to get a feel for how wasteful that might be. A ffi to a C function that just returns the rawtime as an int (long in C) is faster
But adding a C function is it's own complexity for maintenance and deploymentI have no reason to suspect that this doesn't still work: timestamp | RubyGems.org | your community gem host
And for quite a while now there's been this: Module: Process (Ruby 3.0.2)Ah, I thought that something like this (Process.clock_gettime) should exist but I was looking in the Time class and searching for things like rawtime. Thanks that I exactly what I am looking for
Cheers
--
Matthew Kerwin
https://matthew.kerwin.net.au/Unsubscribe: <mailto:ruby-talk-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-talk>Unsubscribe: <mailto:ruby-talk-request@ruby-lang.org?subject=unsubscribe>
<http://lists.ruby-lang.org/cgi-bin/mailman/options/ruby-talk>