Strange query performance

24 May 2014

      Hi all,

Can someone explain me why this simple query takes so long to execute on
MonetDB 5 server v11.17.13 "Jan2014-SP1"?

sql>select * from fp_tree limit 1;
+-----------------------------+
| path                        |
+=============================+
| ;8;60;379;519;1241;174;692; |
+-----------------------------+
1 tuple (1.2s)

Table fp_tree has one column path with data type string.

Some useful statistics of table fp_tree:

sql>select count(*) from fp_tree;
+--------+
| L1     |
+========+
| 416499 |
+--------+
1 tuple (2.801ms)
sql>select max(length(path)) from fp_tree;
+------+
| L1   |
+======+
| 1275 |
+------+
1 tuple (254.742ms)
sql>select min(length(path)) from fp_tree;
+------+
| L1   |
+======+
|    3 |
+------+
1 tuple (272.186ms)
sql>select avg(length(path)) from fp_tree;
+--------------------------+
| L1                       |
+==========================+
|       202.73579288305606 |
+--------------------------+
1 tuple (331.306ms)

Query trace:

+---------+-------------------------------------------------------------------+
| ticks   | stmt
   |
+=========+===================================================================+
|       3 | X_2 := sql.mvc();
  |
|      29 | X_35:bat[:oid,:oid] =<tmp_440>[104124] :=
sql.tid(X_2=0,"sys","fp |
:         : _tree",0,4);
   :
|       6 | X_8=<tmp_3501>[0] := sql.bind(X_2=0,"sys","fp_tree","path",1);
   |
|      40 | (X_52:bat[:oid,:oid] =<tmp_2110>[0],X_53:bat[:oid,:str]
=<tmp_350 |
:         : 1>[0]) := sql.bind(X_2=0,"sys","fp_tree","path",2,3,4);
  :
|       8 | X_45:bat[:oid,:str] =<tmp_1357>[104127] :=
sql.bind(X_2=0,"sys"," |
:         : fp_tree","path",0,3,4);
  :
|       3 | X_57=<tmp_1357>[104127] :=
sql.delta(X_45=<tmp_1357>:bat[:oid,:st |
:         :
r][104127],X_52=<tmp_2110>:bat[:oid,:oid][0],X_53=<tmp_3501>:bat[ :
:         : :oid,:str][0],X_8=<tmp_3501>[0]);
  :
|       4 | X_41:bat[:oid,:oid] =<tmp_1256>[104127] :=
sql.tid(X_2=0,"sys","f |
:         : p_tree",3,4);
  :
|       8 | X_61=<tmp_302>[104127] :=
algebra.leftfetchjoin(X_41=<tmp_1256>:b |
:         : at[:oid,:oid][104127],X_57=<tmp_1357>[104127]);
  :
|      10 | X_65=<tmpr_1256>[1] :=
algebra.subslice(X_61=<tmp_302>[104127],0: |
:         : wrd,0:wrd);
  :
|       6 | X_71=<tmp_1357>[1] :=
algebra.leftfetchjoin(X_65=<tmpr_1256>[1],X |
:         : _61=<tmp_302>[104127]);
  :
|       1 | language.pass(X_61=<tmp_302>[104127]);
   |
|      24 | (X_50:bat[:oid,:oid] =<tmp_2110>[0],X_51:bat[:oid,:str]
=<tmp_350 |
:         : 1>[0]) := sql.bind(X_2=0,"sys","fp_tree","path",2,2,4);
  :
|       5 | X_44:bat[:oid,:str] =<tmp_1560>[104124] :=
sql.bind(X_2=0,"sys"," |
:         : fp_tree","path",0,2,4);
  :
|       3 | X_56=<tmp_1560>[104124] :=
sql.delta(X_44=<tmp_1560>:bat[:oid,:st |
:         :
r][104124],X_50=<tmp_2110>:bat[:oid,:oid][0],X_51=<tmp_3501>:bat[ :
:         : :oid,:str][0]);
  :
|       3 | X_39:bat[:oid,:oid] =<tmp_1760>[104124] :=
sql.tid(X_2=0,"sys","f |
:         : p_tree",2,4);
  :
|       5 | X_60=<tmp_302>[104124] :=
algebra.leftfetchjoin(X_39=<tmp_1760>:b |
:         : at[:oid,:oid][104124],X_56=<tmp_1560>[104124]);
  :
|       8 | X_64=<tmpr_1760>[1] :=
algebra.subslice(X_60=<tmp_302>[104124],0: |
:         : wrd,0:wrd);
  :
|       4 | X_70=<tmp_1560>[1] :=
algebra.leftfetchjoin(X_64=<tmpr_1760>[1],X |
:         : _60=<tmp_302>[104124]);
  :
|       1 | language.pass(X_60=<tmp_302>[104124]);
   |
|      21 | (X_48:bat[:oid,:oid] =<tmp_2110>[0],X_49:bat[:oid,:str]
=<tmp_350 |
:         : 1>[0]) := sql.bind(X_2=0,"sys","fp_tree","path",2,1,4);
  :
|       5 | X_43:bat[:oid,:str] =<tmp_1660>[104124] :=
sql.bind(X_2=0,"sys"," |
:         : fp_tree","path",0,1,4);
  :
|       1 | X_55=<tmp_1660>[104124] :=
sql.delta(X_43=<tmp_1660>:bat[:oid,:st |
:         :
r][104124],X_48=<tmp_2110>:bat[:oid,:oid][0],X_49=<tmp_3501>:bat[ :
:         : :oid,:str][0]);
  :
|       3 | X_37:bat[:oid,:oid] =<tmp_1054>[104124] :=
sql.tid(X_2=0,"sys","f |
:         : p_tree",1,4);
  :
|       5 | X_59=<tmp_302>[104124] :=
algebra.leftfetchjoin(X_37=<tmp_1054>:b |
:         : at[:oid,:oid][104124],X_55=<tmp_1660>[104124]);
  :
|       8 | X_63=<tmpr_1054>[1] :=
algebra.subslice(X_59=<tmp_302>[104124],0: |
:         : wrd,0:wrd);
  :
|       5 | X_69=<tmp_1660>[1] :=
algebra.leftfetchjoin(X_63=<tmpr_1054>[1],X |
:         : _59=<tmp_302>[104124]);
  :
|       1 | language.pass(X_59=<tmp_302>[104124]);
   |
|      23 | (X_46:bat[:oid,:oid] =<tmp_2110>[0],X_47:bat[:oid,:str]
=<tmp_350 |
:         : 1>[0]) := sql.bind(X_2=0,"sys","fp_tree","path",2,0,4);
  :
|       9 | X_42:bat[:oid,:str] =<tmp_462>[104124] :=
sql.bind(X_2=0,"sys","f |
:         : p_tree","path",0,0,4);
   :
|       2 | X_54=<tmp_462>[104124] :=
sql.delta(X_42=<tmp_462>:bat[:oid,:str] |
:         :
[104124],X_46=<tmp_2110>:bat[:oid,:oid][0],X_47=<tmp_3501>:bat[:o :
:         : id,:str][0]);
  :
|       6 | X_58=<tmp_764>[104124] :=
algebra.leftfetchjoin(X_35=<tmp_440>:ba |
:         : t[:oid,:oid][104124],X_54=<tmp_462>[104124]);
  :
|       8 | X_62=<tmpr_440>[1] :=
algebra.subslice(X_58=<tmp_764>[104124],0:w |
:         : rd,0:wrd);
   :
|      10 | X_72=<tmp_462>[1] := mat.packIncrement(X_62=<tmpr_440>[1],4);
  |
|       3 | X_74=<tmp_462>[2] :=
mat.packIncrement(X_72=<tmp_462>[2],X_63=<tm |
:         : pr_1054>[1]);
  :
|       1 | language.pass(X_63=<tmpr_1054>[1]);
  |
|       2 | X_75=<tmp_462>[3] :=
mat.packIncrement(X_74=<tmp_462>[3],X_64=<tm |
:         : pr_1760>[1]);
  :
|       1 | language.pass(X_64=<tmpr_1760>[1]);
  |
|       3 | X_66=<tmp_462>[4] :=
mat.packIncrement(X_75=<tmp_462>[4],X_65=<tm |
:         : pr_1256>[1]);
  :
|       1 | language.pass(X_65=<tmpr_1256>[1]);
  |
|       9 | X_11=<tmpr_1206>[1] :=
algebra.subslice(X_66=<tmp_462>[4],0:wrd,0 |
:         : :wrd);
   :
|       5 | X_68=<tmp_1760>[1] :=
algebra.leftfetchjoin(X_62=<tmpr_440>[1],X_ |
:         : 58=<tmp_764>[104124]);
   :
|       1 | language.pass(X_62=<tmpr_440>[1]);
   |
|       6 | language.pass(X_58=<tmp_764>[104124]);
   |
| 1019824 | X_77=<tmp_1256>[1] := mat.packIncrement(X_68=<tmp_1760>[1],4);
   |
|       8 | X_78=<tmp_1256>[2] :=
mat.packIncrement(X_77=<tmp_1256>[2],X_69=< |
:         : tmp_1660>[1]);
   :
|       7 | X_79=<tmp_1256>[3] :=
mat.packIncrement(X_78=<tmp_1256>[3],X_70=< |
:         : tmp_1560>[1]);
   :
|      18 | X_67=<tmp_1256>[4] :=
mat.packIncrement(X_79=<tmp_1256>[4],X_71=< |
:         : tmp_1357>[1]);
   :
|      18 | X_12=<tmp_1357>[1] :=
algebra.leftfetchjoin(X_11=<tmpr_1206>[1],X |
:         : _67=<tmp_1256>[4]);
  :
| 1095479 | barrier X_89 := language.dataflow();
   |
|      13 | X_13 := sql.resultSet(1,1,X_12=<tmp_1357>[1]);
   |
|       7 |
sql.rsColumn(X_13=7,"sys.fp_tree","path","clob",0,0,X_12=<tmp_135 |
:         : 7>[1]);
  :
|       2 | X_17 := io.stdout();
   |
|      33 | sql.exportResult(X_17=="104d2":streams,X_13=7);
  |
|       0 | end s2_2;
  |
| 1095725 | function user.s2_2();
  |
| 1095772 | X_5:void  := user.s2_2();
  |
+---------+-------------------------------------------------------------------+
56 tuples (1.1s)

Why does mat.packIncrement takes so much time?

Thanks in advance,

Nik

N.H. Schuiling

tags

participants (1)