I ran the query from the command line and piped the results. At the
bottom are them two numbers:
Timer 197.414 msec
Timer 1.690 msec
I'm assumming one represents the runtime, not sure about the other.
I also ran the query with trace. At the bottom it says:
Timer 245.435 msec
Timer 1.380 msec
In the trace file here are the 13 biggest lines:
[ 243 usec # _16 := nil; ]
[ 251 usec # _31 := nil; ]
[ 1538 usec # _30 :=
algebra.join(_27=<~tmp_21501>bat[:oid,:oid]{176871},
_28=bat[:oid,:oid]{4000000}) ]
[ 1877 usec # _104 :=
algebra.joinPath(_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_102=bat[:oid,:str]{32}) ]
[ 1883 usec # _121 :=
algebra.joinPath(_112=bat[:oid,:oid]{89},
_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_97=bat[:oid,:str]{32}) ]
[ 1885 usec # _122 :=
algebra.joinPath(_112=bat[:oid,:oid]{89},
_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_102=bat[:oid,:str]{32}) ]
[ 1900 usec # _120 :=
algebra.joinPath(_112=bat[:oid,:oid]{89},
_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_17=bat[:oid,:str]{32}) ]
[ 1906 usec # _119 :=
algebra.joinPath(_112=bat[:oid,:oid]{89},
_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_89=bat[:oid,:str]{32}) ]
[ 1910 usec # _94 :=
algebra.joinPath(_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_17=bat[:oid,:str]{32}) ]
[ 1969 usec # _91 :=
algebra.joinPath(_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_89=bat[:oid,:str]{32}) ]
[ 1979 usec # _99 :=
algebra.joinPath(_60=<~tmp_21352>bat[:oid,:oid]{89},
_43=<~tmp_21452>bat[:oid,:oid]{1304},
_88=<~tmp_21522>bat[:oid,:oid]{176871},
_97=bat[:oid,:str]{32}) ]
[ 3256 usec # sql.exportResult(_197=0, _242="") ]
[ 4921 usec # _39 :=
algebra.join(_38=bat[:oid,:oid]{210},
_31=<~tmp_21452>bat[:oid,:oid]{176871}) ]
[ 73885 usec # _23 :=
algebra.semijoin(_16=<~tmp_13761>bat[:oid,:oid]{4000000},
_20=bat[:oid,:oid]{1}) ]
(the above is piped through sort, not the last one is an order of
magnitude bigger than anything else). How do I go about starting to
understand/debug this?
