Measuring elapsed time in lua (+love2D)

Question

I'm trying to measure time of my code execution with the os.time() function and display it with LOVE framework. But, to my surprise, the displayed times are changing... My code is:

function foo()
    start_time = os.time()
        <some code>
    end_time = os.time()
    elapsed_time = os.difftime(end_time-start_time)
    love.graphics.print('start time: '   .. start_time .. 's', 12, 12)
    love.graphics.print('end time: '     .. end_time .. 's', 12, 22)
    love.graphics.print('time elapsed: ' .. elapsed_time .. 's', 12, 32)
end

When I leave the window with my graphics open the times are changing (start and end growing and the difference changes between 1 and 2) - so the first question is how does that happen if os.time() returns a number. And also - is that a good way to measure the execution time of my application?

Solution 1

start and end should always be growing, unless time stops, in which case we're all in trouble.

The delta between them will change as a function of how long <some code> takes to execute.

os.time typically returns the number of seconds from some arbitrary point in the past (usually 1/1/1970 00:00:00). That's not guaranteed (it's implemented in terms of C's time function which makes no such guarantees). But it should definitely always be advancing, or it's not really giving you the time, right?

---

BTW, you're using difftime wrong. You're supposed to pass it two values, and it gives you the difference between them. You're passing it one value. It should barf on this, but instead it appears to be returning the first value, which in your case accidentally works because you happen to be on a machine where difftime is actually t2-t1. On other systems this can break. You should change the call to:

elapsed_time = os.difftime(end_time,start_time)

Solution 2

function foo()
    start_time = os.time()
        <some code>
    end_time = os.time()
    elapsed_time = os.difftime(end_time, start_time)
    love.graphics.print('start time: '   .. start_time .. 's', 12, 12)
    love.graphics.print('end time: '     .. end_time .. 's', 12, 22)
    love.graphics.print('time elapsed: ' .. elapsed_time .. 's', 12, 32)
end

First, information about os.time()

The returned value is a number, whose meaning depends on your system. In POSIX, Windows, and some other systems, this number counts the number of seconds since some given start time (the "epoch"). In other systems, the meaning is not specified, and the number returned by time can be used only as an argument to date and difftime.

Step by step iteration:

1. start_time stores the time as number.
2. Your code is executed taking some time.
3. end_time stores the numerical value of time now. It'll be a number greater than or equal to start_time.
4. The time difference is calculated by os.difftime() call(which is syntactically wrong).

---

The value of start and end will be changed for each iteration as your system has advanced a little bit into the future since epoch. Also, the value of elapsed_time is being reported as 1 or 2 seconds which is the time taken by your code to execute itself.

---

You can alternatively use the Lua's os.clock() to return the time taken(in seconds) to execute your code.

Solution 3

Try love.timer.getTime which as of 0.9.0 returns microsecond-accurate time. That link has an example of how to time something.

It's OK for relative times (subtracting to compare). If you want more of an absolute time, try something like:

do
    local _getTime = love.timer.getTime
    local initialTime = _getTime()

    function appTime()
        return _getTime() - initialTime
    end
end

Comments

[Ola M]

Hm... I still think that start_time should just store a snapshot of time, since the os.time() returns number. If I do in an interpreter t = os.time(); print(t);<some time>;print(t) - it returns the same value. It's a different story if I do t = os.time... Thank you for the remark about os. difftime!

[Mud]

It does store a snapshot of a time, and it is a number. Every time you run start_time = os.time() you overwrite the previous snapshot with a new one. I didn't mention that before, because it's.... very basic use of variables which I assumed you already knew.

[Ola M]

Many thanks for the patient answers. I guess I missed completely the fact that my display gets redrawn.