Mailing List Archive: 49091 messages
  • Home
  • Script library
  • AltME Archive
  • Mailing list
  • Articles Index
  • Site search
 

[REBOL] Profiling Rebol API to DyBASE

From: knizhnik::garret::ru at: 18-Dec-2003 20:43

Hello Konstantin, Looks there is no profiler in Rebol:( So, I have to do profiling myself using now/time/precise. I got the following results which seems to be interesting: Elapsed time for inserting 100000 records: 0:01:01 Elapsed time for performing 200000 index searches: 0:02:06 Time spent in lookup 0:01:24.312 Time spent in lookup/select 0:00:53.348 Time spent in lookup/make 0:00:11.418 Time spent in lookup/insert 0:00:01.501 Time spent in lookup/fetch 0:00:11.401 Time spent in find 0:01:58.464 Time spent in find/iterator creation 0:00:14.281 Time spent in find/append 0:01:36.118 Elapsed time for iterating through 200000 records: 0:03:02 Time spent in lookup 0:02:54.861 Time spent in lookup/select 0:01:56.736 Time spent in lookup/make 0:00:23.251 Time spent in lookup/insert 0:00:03.774 Time spent in lookup/fetch 0:00:23.006 Elapsed time for deleting 100000 records: 0:03:53 Time spent in lookup 0:01:52.034 Time spent in lookup/select 0:01:21.9 Time spent in lookup/make 0:00:11.587 Time spent in lookup/insert 0:00:01.703 Time spent in lookup/fetch 0:00:12.389 So, during index search 1.5 minutes from 2 were spent in lookup function. And 14 seconds takes searching index itself. From these 1.5 minutes most of the time was spent in this line: obj: select obj-by-oid-map oid I wrote a large number of test scripts experimenting with hashes, but could not find the reason of the problem - 100000 searches can be executed for less then one second. Below is text of _lookup-function with inserted profiling statement. May be somebody can explain to me such strange behavior? obj-by-oid-map maps OID (integer number - object identifier) to object instances. It is periodically cleared (using "clear obj-by-oid-map"), so number of elements in hash should not be larger than 100. And select should always return none. _lookup-object: function[oid recursive] [h this obj hnd class-name field-name start start2] [ either oid = 0 [ none ] [ start: now/time/precise obj: select obj-by-oid-map oid elapsed-select: elapsed-select + (now/time/precise - start) either not obj [ start2: now/time/precise hnd: dybase_begin_load db oid cls: to word! dybase_get_class_name hnd this: self obj: make get cls [__oid__: oid __storage__: this __class__: cls] if not recursive [ either obj/recursive-loading? [ recursive: true ] [ obj/__raw__: true ] ] elapsed-make: elapsed-make + (now/time/precise - start2) start2: now/time/precise insert insert tail obj-by-oid-map oid obj elapsed-insert: elapsed-insert + (now/time/precise - start2) start2: now/time/precise either find [string-index integer-index decimal-index] cls [ dybase_next_field hnd obj/index: dybase_get_ref hnd dybase_next_field hnd ] [ while [not empty? field-name: dybase_next_field hnd] [ set in obj (to word! field-name) _fetch-component hnd recursive ] if recursive [obj/on-load] ] elapsed-fetch: elapsed-fetch + (now/time/precise - start2) ] [ if recursive and obj/__raw__ [load-object obj] ] elapsed-lookup: elapsed-lookup + (now/time/precise - start) obj ] ] -- Thanks in advance, Konstantin mailto:[knizhnik--garret--ru]