[Glass] UUID new >100x slower than Pharo?

Dale K. Henrichs dale.henrichs at gemtalksystems.com
Tue Sep 17 10:44:41 PDT 2013


Paul,

First the call to userAction:onClient: does not imply that the operation is being done on the client. HostRandom operates against /dev/urandom on the server side so the cost you are seeing is likely just the overhead of accessing the file.

On my laptop the expression

  [1000 timesRepeat:[UUID new]] timeToRun

takes 800ms using HostRandom and 400ms using Lag25000CmwcRandom (not file-based although HostRandom is used to define initial seed) ... 

Still, there is a fair amount of Smalltalk code being executed here so a primitive call (which is what pharo does) would be the way to speed this up ...

I'll look into this for 3.2...(or at least making random number generation a lot faster)...


Dale


| From: "Paul DeBruicker" <pdebruic at gmail.com>
| To: glass at lists.gemtalksystems.com
| Sent: Tuesday, September 17, 2013 6:43:46 PM
| Subject: [Glass] UUID new >100x slower than Pharo?
| 
| Hi-
| 
| This is on Glass 1.0.beta9.1 and Gemstone 3.1.0.4 using GemTools
| 1.0.b71.  as the client.
| 
| Seems like its spending time looking up random numbers using file
| accesses on the client.
| 
| [1000 timesRepeat:[UUID new]] timeToRun
| 
| On my laptop in pharo this takes 14ms and in gemstone it takes 1920
| ms
| 
| 
| Is there a way to get it to use the server as I thought that was much
| faster?
| 
| Or is there a setting I need to fiddle with?
| 
| Thanks
| 
| Paul
| 
| 
| 
| Here is the output from:
| 
| ProfMonitor monitorBlock:[1000 timesRepeat:[UUID new]]
| 
| 
| 
| '================
| STATISTICAL SAMPLING RESULTS
| elapsed CPU time:    12308 ms
| monitoring interval: 1.0 ms
| 
|  tally       %   class and method name
| ------   -----   --------------------------------------
|   2298   18.69   GsFile                    >> userAction:onClient:
|   1258   10.23   HostRandom                >> integer
|   1111    9.04   SmallInteger              >> bitShift:
|    944    7.68   GsFile                    >> next
|    914    7.43   Character                 >> asciiValue
|    906    7.37   GsFile                    >> nextByte
|    302    2.46   SymbolDictionary          >>
|    associationAt:otherwise:
|    288    2.34   SmallInteger              >> >
|    281    2.29   System class              >> __sessionStateAt:
|    280    2.28   Integer                   >> *
|    276    2.24   Semaphore                 >> _exitCritical
|    260    2.11   HostRandom                >> file
|    258    2.10   GsFile                    >> isOpen
|    218    1.77   SessionTemps class        >> current
|    217    1.77   Semaphore                 >> critical:
|    216    1.76   SymbolDictionary          >> at:otherwise:
|    196    1.59   Float                     >> *
|    168    1.37   Float                     >> +
|    157    1.28   SmallInteger              >> <
|    147    1.20   block in UUIDGenerator    >> generateOneOrZero
|    137    1.11   block in Semaphore        >> critical:
|    129    1.05   UUIDGenerator             >> generateOneOrZero
|    126    1.02   Random                    >> float
|    125    1.02   Random                    >> next
|    124    1.01   Float                     >> <
|    124    1.01   Integer                   >> asFloat
|    119    0.97   SmallInteger              >> bitOr:
|    114    0.93   UUIDGenerator             >>
|    generateRandomBitsOfLength:
|    113    0.92   Number                    >> _retry:coercing:
|    111    0.90   Semaphore                 >> wait
|    111    0.90   Object                    >> size
|    110    0.89   Semaphore                 >> signal
|    103    0.84   Float                     >> _coerce:
|     20    0.16   Object                    >> at:put:
|      9    0.07   UUIDGenerator             >> placeFields:
|      3    0.02   SymbolDictionary          >> at:ifAbsent:
|      3    0.02   UUID class                >> new
|      2    0.02   Symbol                    >> =
|      2    0.02   MCPlatformSupport class   >> transientGlobals
|      2    0.02   Dictionary                >>
|      associationAt:otherwise:
|      2    0.02   UUID                      >> initialize
|      1    0.01   AbstractDictionary        >> _at:
|      1    0.01   String                    >> hash
|      1    0.01   Dictionary                >> at:ifAbsent:
|      1    0.01   AbstractDictionary        >> hashFunction:
|      1    0.01   SmallInteger              >> \\
|      1    0.01   block in executed code
|      1    0.01   UUID                      >> primMakeUUID
|      1    0.01   UUIDGenerator             >>
|      generateBytes:forVersion:
|      1    0.01   UUIDGenerator             >> generateFieldsVersion4
|      1    0.01   System class              >> _readClock
|      0    0.00   9 other methods
|  12294  100.00   Total
| 
| 
| ================
| STATISTICAL STACK SAMPLING RESULTS
| elapsed CPU time:    12308 ms
| monitoring interval: 1.0 ms
| 
|  total       %   class and method name
| ------   -----   --------------------------------------
|  12265   99.76   UUIDGenerator             >>
|  generateBytes:forVersion:
|  12220   99.40   UUIDGenerator             >> generateFieldsVersion4
|  12217   99.37   UUIDGenerator             >>
|  generateRandomBitsOfLength:
|  11873   96.58   UUIDGenerator             >> generateOneOrZero
|  11744   95.53   Semaphore                 >> critical:
|  11193   91.04   ExecBlock                 >> ensure:
|  10682   86.89   block in UUIDGenerator    >> generateOneOrZero
|  10223   83.15   Random                    >> next
|  10098   82.14   Random                    >> float
|   8831   71.83   HostRandom                >> integer
|   6541   53.20   UUID                      >> primMakeUUID
|   4546   36.98   GsFile                    >> nextByte
|   2726   22.17   GsFile                    >> next
|   2317   18.85   UUID                      >> initialize
|   2298   18.69   GsFile                    >> userAction:onClient:
|   1383   11.25   UUID class                >> new
|   1270   10.33   HostRandom                >> file
|   1111    9.04   SmallInteger              >> bitShift:
|    973    7.91   Integer                   >> *
|    914    7.43   Character                 >> asciiValue
|    774    6.30   GsFile                    >> isOpen
|    758    6.17   block in executed code
|    693    5.64   Number                    >> _retry:coercing:
|    518    4.21   SymbolDictionary          >> at:otherwise:
|    511    4.16   block in Semaphore        >> critical:
|    499    4.06   SessionTemps class        >> current
|    374    3.04   Semaphore                 >> signal
|    334    2.72   Semaphore                 >> wait
|    302    2.46   SymbolDictionary          >>
|    associationAt:otherwise:
|    288    2.34   SmallInteger              >> >
|    281    2.29   System class              >> __sessionStateAt:
|    276    2.24   Semaphore                 >> _exitCritical
|    227    1.85   Float                     >> _coerce:
|    196    1.59   Float                     >> *
|    171    1.39   ProfMonitor               >> monitorBlock:
|    168    1.37   Float                     >> +
|    157    1.28   SmallInteger              >> <
|    124    1.01   Float                     >> <
|    124    1.01   Integer                   >> asFloat
|    119    0.97   SmallInteger              >> bitOr:
|    111    0.90   Object                    >> size
|     44    0.36   UUIDGenerator             >> placeFields:
|     21    0.17   UUIDGenerator class       >> default
|     21    0.17   MCPlatformSupport class   >> transientGlobalForKey:
|     20    0.16   Object                    >> at:put:
|     12    0.10   MCPlatformSupport class   >> transientGlobalNamed:
|      9    0.07   MCPlatformSupport class   >> transientGlobals
|      9    0.07   Dictionary                >> at:ifAbsent:
|      9    0.07   ProfMonitor class         >> monitorBlock:
|      8    0.07   Dictionary                >>
|      associationAt:otherwise:
|      7    0.06   executed code
|      3    0.02   SymbolDictionary          >> at:ifAbsent:
|      3    0.02   AbstractDictionary        >> hashFunction:
|      2    0.02   Symbol                    >> =
|      1    0.01   AbstractDictionary        >> _at:
|      1    0.01   String                    >>
|      evaluateInContext:symbolList:
|      1    0.01   String                    >> hash
|      1    0.01   SmallInteger              >> \\
|      1    0.01   System class              >> _readClock
|      1    0.01   ProfMonitor               >> startMonitoring
|  12294  100.00   Total
| 
| 
| ================
| STATISTICAL METHOD SENDERS RESULTS
| elapsed CPU time:    12308 ms
| monitoring interval: 1.0 ms
| 
|      %       %                     Parent
|   self  total   total  local  Method
|   Time   Time      ms    %         Child
| ------ ------  ------  -----  -----------
| 
|                  6526.4   53.2       UUID         >> primMakeUUID
| =    0.0   99.8  12279.0    0.0  UUIDGenerator >>
| generateBytes:forVersion:
|                    44.1    0.4       UUIDGenerator >> placeFields:
|                  12233.9   99.6       UUIDGenerator >>
| generateFieldsVersion4
| -----------------------------------------------------
| 
|                  12233.9  100.0       UUIDGenerator >>
| generateBytes:forVersion:
| =    0.0   99.4  12233.9    0.0  UUIDGenerator >>
| generateFieldsVersion4
|                     2.0    0.0       SmallInteger >> bitOr:
|                  12230.9  100.0       UUIDGenerator >>
| generateRandomBitsOfLength:
| -----------------------------------------------------
| 
|                  12230.9  100.0       UUIDGenerator >>
| generateFieldsVersion4
| =    0.9   99.4  12230.9    0.9  UUIDGenerator >>
| generateRandomBitsOfLength:
|                   117.1    1.0       SmallInteger >> bitOr:
|                   113.1    0.9       SmallInteger >> bitShift:
|                  11886.5   97.2       UUIDGenerator >>
|                  generateOneOrZero
| -----------------------------------------------------
| 
|                  11886.5  100.0       UUIDGenerator >>
| generateRandomBitsOfLength:
| =    1.0   96.6  11886.5    1.1  UUIDGenerator >> generateOneOrZero
|                  11757.4   98.9       Semaphore    >> critical:
| -----------------------------------------------------
| 
|                  11757.4  100.0       UUIDGenerator >>
|                  generateOneOrZero
| =    1.8   95.5  11757.4    1.8  Semaphore    >> critical:
|                   334.4    2.8       Semaphore    >> wait
|                  11205.7   95.3       ExecBlock    >> ensure:
| -----------------------------------------------------
| 
|                  11205.7  100.0       Semaphore    >> critical:
| =    0.0   91.0  11205.7    0.0  ExecBlock    >> ensure:
|                   511.6    4.6       block in Semaphore >> critical:
|                  10694.2   95.4       block in UUIDGenerator >>
| generateOneOrZero
| -----------------------------------------------------
| 
|                  10694.2  100.0       ExecBlock    >> ensure:
| =    1.2   86.9  10694.2    1.4  block in UUIDGenerator >>
| generateOneOrZero
|                   124.1    1.2       Float        >> <
|                   188.2    1.8       SmallInteger >> >
|                  10234.6   95.7       Random       >> next
| -----------------------------------------------------
| 
|                  10234.6  100.0       block in UUIDGenerator >>
| generateOneOrZero
| =    1.0   83.2  10234.6    1.2  Random       >> next
|                  10109.5   98.8       Random       >> float
| -----------------------------------------------------
| 
|                  10109.5  100.0       Random       >> next
| =    1.0   82.1  10109.5    1.2  Random       >> float
|                   974.1    9.6       Integer      >> *
|                   168.2    1.7       Float        >> +
|                  8841.1   87.5       HostRandom   >> integer
| -----------------------------------------------------
| 
|                  8841.1  100.0       Random       >> float
| =   10.2   71.8  8841.1   14.2  HostRandom   >> integer
|                   774.9    8.8       GsFile       >> isOpen
|                   984.1   11.1       SmallInteger >> bitShift:
|                  4551.2   51.5       GsFile       >> nextByte
|                  1271.4   14.4       HostRandom   >> file
| -----------------------------------------------------
| 
|                  2317.6   35.4       UUID         >> initialize
| =    0.0   53.2  6548.4    0.0  UUID         >> primMakeUUID
|                    21.0    0.3       UUIDGenerator class >> default
|                  6526.4   99.7       UUIDGenerator >>
| generateBytes:forVersion:
| -----------------------------------------------------
| 
|                  4551.2  100.0       HostRandom   >> integer
| =    7.4   37.0  4551.2   19.9  GsFile       >> nextByte
|                   915.0   20.1       Character    >> asciiValue
|                  2729.1   60.0       GsFile       >> next
| -----------------------------------------------------
| 
|                  2729.1  100.0       GsFile       >> nextByte
| =    7.7   22.2  2729.1   34.6  GsFile       >> next
|                  1784.0   65.4       GsFile       >>
|                  userAction:onClient:
| -----------------------------------------------------
| 
|                  1381.6   59.6       UUID class   >> new
| =    0.0   18.8  2319.6    0.1  UUID         >> initialize
|                  2317.6   99.9       UUID         >> primMakeUUID
| -----------------------------------------------------
| 
|                  1784.0   77.5       GsFile       >> next
|                   516.6   22.5       GsFile       >> isOpen
| =   18.7   18.7  2300.6  100.0  GsFile       >> userAction:onClient:
| -----------------------------------------------------
| 
|                   757.9   54.7       block in executed code
| =    0.0   11.2  1384.6    0.2  UUID class   >> new
|                  1381.6   99.8       UUID         >> initialize
| -----------------------------------------------------
| 
|                  1271.4  100.0       HostRandom   >> integer
| =    2.1   10.3  1271.4   20.5  HostRandom   >> file
|                   492.6   38.7       SessionTemps class >> current
|                   518.6   40.8       SymbolDictionary >>
|                   at:otherwise:
| -----------------------------------------------------
| 
|                    15.0    1.4       UUIDGenerator >> placeFields:
|                   113.1   10.2       UUIDGenerator >>
| generateRandomBitsOfLength:
|                   984.1   88.5       HostRandom   >> integer
| =    9.0    9.0  1112.3  100.0  SmallInteger >> bitShift:
| -----------------------------------------------------
| 
|                   974.1  100.0       Random       >> float
| =    2.3    7.9   974.1   28.8  Integer      >> *
|                   693.8   71.2       Number       >> _retry:coercing:
| -----------------------------------------------------
| 
|                   915.0  100.0       GsFile       >> nextByte
| =    7.4    7.4   915.0  100.0  Character    >> asciiValue
| -----------------------------------------------------
| 
|                   774.9  100.0       HostRandom   >> integer
| =    2.1    6.3   774.9   33.3  GsFile       >> isOpen
|                   516.6   66.7       GsFile       >>
|                   userAction:onClient:
| -----------------------------------------------------
| 
|                   170.2   22.4       ProfMonitor  >> monitorBlock:
| =    0.0    6.2   758.9    0.1  block in executed code
|                   757.9   99.9       UUID class   >> new
| -----------------------------------------------------
| 
|                   693.8  100.0       Integer      >> *
| =    0.9    5.6   693.8   16.3  Number       >> _retry:coercing:
|                   196.2   28.3       Float        >> *
|                   227.3   32.8       Float        >> _coerce:
|                   157.2   22.7       SmallInteger >> <
| -----------------------------------------------------
| 
|                   518.6  100.0       HostRandom   >> file
| =    1.8    4.2   518.6   41.7  SymbolDictionary >> at:otherwise:
|                   302.3   58.3       SymbolDictionary >>
| associationAt:otherwise:
| -----------------------------------------------------
| 
|                   511.6  100.0       ExecBlock    >> ensure:
| =    1.1    4.2   511.6   26.8  block in Semaphore >> critical:
|                   374.4   73.2       Semaphore    >> signal
| -----------------------------------------------------
| 
|                   492.6   98.6       HostRandom   >> file
|                     7.0    1.4       MCPlatformSupport class >>
| transientGlobals
| =    1.8    4.1   499.6   43.7  SessionTemps class >> current
|                   281.3   56.3       System class >>
|                   __sessionStateAt:
| -----------------------------------------------------
| 
|                   374.4  100.0       block in Semaphore >> critical:
| =    0.9    3.0   374.4   29.4  Semaphore    >> signal
|                   153.2   40.9       Semaphore    >> _exitCritical
|                   111.1   29.7       Object       >> size
| -----------------------------------------------------
| 
|                   334.4  100.0       Semaphore    >> critical:
| =    0.9    2.7   334.4   33.2  Semaphore    >> wait
|                   100.1   29.9       SmallInteger >> >
|                   123.1   36.8       Semaphore    >> _exitCritical
| -----------------------------------------------------
| 
|                   302.3  100.0       SymbolDictionary >>
|                   at:otherwise:
| =    2.5    2.5   302.3  100.0  SymbolDictionary >>
| associationAt:otherwise:
| -----------------------------------------------------
| 
|                   100.1   34.7       Semaphore    >> wait
|                   188.2   65.3       block in UUIDGenerator >>
| generateOneOrZero
| =    2.3    2.3   288.3  100.0  SmallInteger >> >
| -----------------------------------------------------
| 
|                   281.3  100.0       SessionTemps class >> current
| =    2.3    2.3   281.3  100.0  System class >> __sessionStateAt:
| -----------------------------------------------------
| 
|                   123.1   44.6       Semaphore    >> wait
|                   153.2   55.4       Semaphore    >> signal
| =    2.2    2.2   276.3  100.0  Semaphore    >> _exitCritical
| -----------------------------------------------------
| 
|                   227.3  100.0       Number       >> _retry:coercing:
| =    0.8    1.8   227.3   45.4  Float        >> _coerce:
|                   124.1   54.6       Integer      >> asFloat
| -----------------------------------------------------
| 
|                   196.2  100.0       Number       >> _retry:coercing:
| =    1.6    1.6   196.2  100.0  Float        >> *
| -----------------------------------------------------
| 
|                     9.0    5.3       ProfMonitor class >>
|                     monitorBlock:
| =    0.0    1.4   171.2    0.0  ProfMonitor  >> monitorBlock:
|                   170.2   99.4       block in executed code
|                     1.0    0.6       ProfMonitor  >> startMonitoring
| -----------------------------------------------------
| 
|                   168.2  100.0       Random       >> float
| =    1.4    1.4   168.2  100.0  Float        >> +
| -----------------------------------------------------
| 
|                   157.2  100.0       Number       >> _retry:coercing:
| =    1.3    1.3   157.2  100.0  SmallInteger >> <
| -----------------------------------------------------
| 
|                   124.1  100.0       block in UUIDGenerator >>
| generateOneOrZero
| =    1.0    1.0   124.1  100.0  Float        >> <
| -----------------------------------------------------
| 
|                   124.1  100.0       Float        >> _coerce:
| =    1.0    1.0   124.1  100.0  Integer      >> asFloat
| -----------------------------------------------------
| 
|                     2.0    1.7       UUIDGenerator >>
|                     generateFieldsVersion4
|                   117.1   98.3       UUIDGenerator >>
| generateRandomBitsOfLength:
| =    1.0    1.0   119.1  100.0  SmallInteger >> bitOr:
| -----------------------------------------------------
| 
|                   111.1  100.0       Semaphore    >> signal
| =    0.9    0.9   111.1  100.0  Object       >> size
| -----------------------------------------------------
| 
|                    44.1  100.0       UUIDGenerator >>
| generateBytes:forVersion:
| =    0.1    0.4    44.1   20.5  UUIDGenerator >> placeFields:
|                    20.0   45.5       Object       >> at:put:
|                    15.0   34.1       SmallInteger >> bitShift:
| -----------------------------------------------------
| 
|                    21.0  100.0       UUID         >> primMakeUUID
| =    0.0    0.2    21.0    0.0  UUIDGenerator class >> default
|                    21.0  100.0       MCPlatformSupport class >>
| transientGlobalForKey:
| -----------------------------------------------------
| 
|                    21.0  100.0       UUIDGenerator class >> default
| =    0.0    0.2    21.0    0.0  MCPlatformSupport class >>
| transientGlobalForKey:
|                    12.0   57.1       MCPlatformSupport class >>
| transientGlobalNamed:
|                     9.0   42.9       Dictionary   >> at:ifAbsent:
| -----------------------------------------------------
| 
|                    20.0  100.0       UUIDGenerator >> placeFields:
| =    0.2    0.2    20.0  100.0  Object       >> at:put:
| -----------------------------------------------------
| 
|                    12.0  100.0       MCPlatformSupport class >>
| transientGlobalForKey:
| =    0.0    0.1    12.0    0.0  MCPlatformSupport class >>
| transientGlobalNamed:
|                     3.0   25.0       SymbolDictionary >> at:ifAbsent:
|                     9.0   75.0       MCPlatformSupport class >>
| transientGlobals
| -----------------------------------------------------
| 
|                     9.0  100.0       MCPlatformSupport class >>
| transientGlobalNamed:
| =    0.0    0.1     9.0   22.2  MCPlatformSupport class >>
| transientGlobals
|                     7.0   77.8       SessionTemps class >> current
| -----------------------------------------------------
| 
|                     9.0  100.0       MCPlatformSupport class >>
| transientGlobalForKey:
| =    0.0    0.1     9.0   11.1  Dictionary   >> at:ifAbsent:
|                     8.0   88.9       Dictionary   >>
| associationAt:otherwise:
| -----------------------------------------------------
| 
|                     7.0   77.8       executed code
| =    0.0    0.1     9.0    0.0  ProfMonitor class >> monitorBlock:
|                     9.0  100.0       ProfMonitor  >> monitorBlock:
| -----------------------------------------------------
| 
|                     8.0  100.0       Dictionary   >> at:ifAbsent:
| =    0.0    0.1     8.0   25.0  Dictionary   >>
| associationAt:otherwise:
|                     1.0   12.5       AbstractDictionary >> _at:
|                     2.0   25.0       Symbol       >> =
|                     3.0   37.5       AbstractDictionary >>
|                     hashFunction:
| -----------------------------------------------------
| 
|                     1.0   14.3       String       >>
| evaluateInContext:symbolList:
| =    0.0    0.1     7.0    0.0  executed code
|                     7.0  100.0       ProfMonitor class >>
|                     monitorBlock:
| -----------------------------------------------------
| 
|                     3.0  100.0       MCPlatformSupport class >>
| transientGlobalNamed:
| =    0.0    0.0     3.0  100.0  SymbolDictionary >> at:ifAbsent:
| -----------------------------------------------------
| 
|                     3.0  100.0       Dictionary   >>
| associationAt:otherwise:
| =    0.0    0.0     3.0   33.3  AbstractDictionary >> hashFunction:
|                     1.0   33.3       String       >> hash
|                     1.0   33.3       SmallInteger >> \\
| -----------------------------------------------------
| 
|                     2.0  100.0       Dictionary   >>
| associationAt:otherwise:
| =    0.0    0.0     2.0  100.0  Symbol       >> =
| -----------------------------------------------------
| 
|                     1.0  100.0       Dictionary   >>
| associationAt:otherwise:
| =    0.0    0.0     1.0  100.0  AbstractDictionary >> _at:
| -----------------------------------------------------
| 
| =    0.0    0.0     1.0    0.0  String       >>
| evaluateInContext:symbolList:
|                     1.0  100.0       executed code
| -----------------------------------------------------
| 
|                     1.0  100.0       AbstractDictionary >>
|                     hashFunction:
| =    0.0    0.0     1.0  100.0  String       >> hash
| -----------------------------------------------------
| 
|                     1.0  100.0       AbstractDictionary >>
|                     hashFunction:
| =    0.0    0.0     1.0  100.0  SmallInteger >> \\
| -----------------------------------------------------
| 
|                     1.0  100.0       ProfMonitor  >> startMonitoring
| =    0.0    0.0     1.0  100.0  System class >> _readClock
| -----------------------------------------------------
| 
|                     1.0  100.0       ProfMonitor  >> monitorBlock:
| =    0.0    0.0     1.0    0.0  ProfMonitor  >> startMonitoring
|                     1.0  100.0       System class >> _readClock
| -----------------------------------------------------
| 
| 
| '
| 
| _______________________________________________
| Glass mailing list
| Glass at lists.gemtalksystems.com
| http://lists.gemtalksystems.com/mailman/listinfo/glass
| 


More information about the Glass mailing list