What have you done with the GUID function?

Posted by Fabian Frank on 14-Feb-2014 13:21

Today I got OpenEdge 11.3  (using 11.1 in production) and started testing.

ETIME(TRUE).
    
DEF VAR v-i AS INT NO-UNDO.
    
DO v-i = 1 TO 1000000:

    GUID.
END.
    
MESSAGE ETIME
    VIEW-AS ALERT-BOX.


Running this snippet in 11.1 takes 300 milliseconds, but in 11.3.2 it takes 50 seconds.

That is a remarkable difference.


All Replies

Posted by Peter Judge on 14-Feb-2014 13:57

That's a *very* polite way of saying WTF :) I see the same FWIW.

I've logged bug PSC00289912 for this. I've faith that it'll be triaged asap.

-- peter

Posted by Aidan Jeffery on 14-Feb-2014 14:46

This was the result of a bug fixed in 11.3. It was previously possible, in some circumstances, for a UUID not to be unique because of the speed with which it was generated.

Just out of interest, do you have a need to generate more than 20,000 UUIDs per second, or is this just a way of testing the performance of OpenEdge?

- aidan

Posted by Fabian Frank on 15-Feb-2014 11:44

It's the latter. The call to GUID was just a minor part of a larger script I used for performance comparison between 11.1 and 11.3. But it was not about GUID. Because the results looked very strange to mee, I analyzed the root cause and discovered the huge performance difference  in UUID creation.

Because you mentioned it was too fast in 11.1 because of the bug, I compared it to some other languages:

C# 0.5 seconds

var sw = new Stopwatch();
sw.Start();

for (int i = 0; i < 1000000; i++)
{
    Guid.NewGuid();
}

sw.Stop();
Console.WriteLine(sw.Elapsed);

Java 0.9 seconds

long start = System.currentTimeMillis();
        
for (int i = 0; i < 1000000; i++)
{
    UUID.randomUUID();
}
        
System.out.println(System.currentTimeMillis() - start);


Go 1 second

package main

import (
    "fmt"
    "time"
    "github.com/nu7hatch/gouuid"
)

func main() {
    
    start := time.Now()

    for i := 0; i < 1000000; i++ {
        uuid.NewV4()
    }

    fmt.Println(time.Since(start))
}

Ruby 8.7 seconds

require 'securerandom'

start = Time.now

for i in 1..1000000
   SecureRandom.uuid
end

puts Time.now - start

Python 12.9 seconds

import uuid, time

start = time.time()

for x in range(1, 1000000):
    uuid.uuid4()

print(time.time() - start)

This result shows that 300 ms for OE 11.1 is indeed a pretty unrealistic result. But 50 seconds seems to be too much. OpenEdge should at least be faster than the interpreted languages python and ruby.

Posted by eugenel on 16-Feb-2014 13:57

Taking 50 seconds to create 1 million GUIDs is indeed too long but it is possible for C/C++ code to do so in less than 200 milliseconds:

GUID guid;

int i;

for (i = 0; i < 1000000; i++)

{

   CoCreateGuid(&guid);

}

Posted by Thomas Mercer-Hursh on 16-Feb-2014 14:13

While admitted the change is dramatic, I'm not sure it really matters.  We are talking about 0.00005 seconds to create one.  Any time one is creating a GUID, there is some work associated with it ... not infrequently a DB update or maybe passing something to the UI.   Are you going to notice 0.00005 seconds in the midst of that?

There are a bunch of things in ABL which, if one runs similar benchmarks to compare to other languages, look very slow.  In many cases, that slowness is understandable because it is being executed by a virtual machine and the nature of ABL means a lot of interpretive overhead compared to the time needed to do the actual function.  But, much, perhaps most, of the time this is irrelevant because one is not executing the function in tight million iteration loops, but rather it is a small piece of some set of operations which take much more time than that one little piece.  In many cases, like the present, the actual time is negligible and only looks bad compared to other languages focusing on the tight loop.

Which is more important?   Creating 1 million GUIDs in a fraction of a second or making sure that there are no duplicates?

This thread is closed