0

I am trying to time how long a method takes to execute, so I record the start time and then at the end subtract it from the current time which should give me the difference in seconds. I get back 123 seconds when it actually took over 10 minutes to run.

  def perform_cluster_analysis
    start = Time.now

     # A whole lot of tasks performed here

     puts 'time taken: '
     puts (Time.now - start)
   end

The output I get is:

 time taken: 
 123.395808311

But when timed with a stopwatch it actually took over 10 minutes, so why am I getting back 123 seconds instead of +- 600 (10 minutes)

Lee
  • 8,354
  • 14
  • 55
  • 90
  • What is your question? – sawa Oct 18 '13 at 11:49
  • Why I am getting an answer of 123 seconds (2 mins), when I should be getting back 10 minutes – Lee Oct 18 '13 at 11:52
  • Have you tried the solution mentioned here http://stackoverflow.com/questions/1679266/can-ruby-print-out-time-difference-duration-readily/1681553#1681553 ? – Abhishek Asthana Oct 18 '13 at 11:54
  • @Abhishek Asthana: OP is not trying to convert 123.39 into words, but wants to know why he measures 600 on a separate device, but sees 123.39 from the supplied code. – Neil Slater Oct 18 '13 at 12:02
  • @lee: Try, `$stderr.puts`, and check when the message appears, as opposed to when the system stops. It may be that the method stops and then Ruby spends 8 minutes cleaning up - this can occur if you have created a huge number of objects during processing. – Neil Slater Oct 18 '13 at 12:10
  • Sorry I thought i was giving link to the actual question not the to words answer. Try link to the tim_diff gem http://stackoverflow.com/a/5248633/1788964 answer. Thanks @Neil Slater for pointing that out to me. – Abhishek Asthana Oct 18 '13 at 12:10
  • @NeilSlater I was watching what was being logged to the console, and work was being performed the entire time – Lee Oct 18 '13 at 12:12
  • @lee: Your console was scrolling output the entire time. Was there a lot of output? – Neil Slater Oct 18 '13 at 12:14
  • 3
    Try it without any console output. Perhaps the code finishes in 2 mins but the output buffer doesn't completely flush until much later due to the huge amount. – Mark Thomas Oct 18 '13 at 12:35

0 Answers0