[Monetdb-developers] Another big group by query
Hi All, Might be better to go by the mailinglist instead of adding many people to the CC. Currently I am running the latest CVS code disabled mitosis and am running the following code: CREATE TABLE "sys"."way_nds" ( "way" int NOT NULL, "idx" int NOT NULL, "to_node" int, CONSTRAINT "pk_way_nds" PRIMARY KEY ("way", "idx") ); select count(way), way, to_node from way_nds group by way, to_node having count(way) > 1; The table contains about 362420451 rows, and I realised too late there could be many results comming from it. top - 03:12:15 up 1 day, 17:28, 8 users, load average: 1.00, 1.00, 1.00 Tasks: 193 total, 1 running, 192 sleeping, 0 stopped, 0 zombie Cpu(s): 0.0%us, 0.1%sy, 0.0%ni, 94.6%id, 5.2%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 66113464k total, 39353192k used, 26760272k free, 326968k buffers Swap: 134215032k total, 94284k used, 134120748k free, 8489128k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 11856 konink 20 0 51.5g 34g 5.9g S 0.3 54.6 45:34.93 mserver5 But again the load is low, the memory empty and it seems to do so few. Is there something that would be interesting to look at? Stefan
On Sun, Apr 12, 2009 at 03:15:36AM +0200, Stefan de Konink wrote:
Hi All,
Might be better to go by the mailinglist instead of adding many people to the CC.
Good. Exactly that is why we have mailing lists ;-)
Currently I am running the latest CVS code disabled mitosis and am running the following code:
CREATE TABLE "sys"."way_nds" ( "way" int NOT NULL, "idx" int NOT NULL, "to_node" int, CONSTRAINT "pk_way_nds" PRIMARY KEY ("way", "idx") );
select count(way), way, to_node from way_nds group by way, to_node having count(way) > 1;
The table contains about 362420451 rows, and I realised too late there could be many results comming from it.
I don't know, whether the fact that is does/might create "many result" is related to the "hanging" situation at all ...
top - 03:12:15 up 1 day, 17:28, 8 users, load average: 1.00, 1.00, 1.00 Tasks: 193 total, 1 running, 192 sleeping, 0 stopped, 0 zombie Cpu(s): 0.0%us, 0.1%sy, 0.0%ni, 94.6%id, 5.2%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 66113464k total, 39353192k used, 26760272k free, 326968k buffers Swap: 134215032k total, 94284k used, 134120748k free, 8489128k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
11856 konink 20 0 51.5g 34g 5.9g S 0.3 54.6 45:34.93 mserver5
But again the load is low, the memory empty and it seems to do so few.
load is 1.0 --- i.e., one thrad full throttle --- unless it is a "fake" load due to a Dead/Dummy/zombie process that is (e.g.) waiting for I/O --- in top, type "1" to get the summaries for all cores and "H" to list all threads and "u"+[Enter] to list processes of all users; then "P" to order on CPU usage and report; then "M" to oder on memory usage (34g res is IMHO everything but "empty") and report.
Is there something that would be interesting to look at?
Basically, it would be great to know which MAL statement is currently being executed on which inputs --- prefixing your SQL statement with TRACE is one option (though I don't know whether that flushes it's output instantly; if not, we should consider adding such functionality excatly for such "hanging" situations --- in any case, it list only a statement after it has finished; hence, comparing the TRACE output with that of EXPLAIN is required); running in the MAL debugger (prefix SQL statement with DEBUG) is the other option (though I don't know, whether the MAL debugger has some "automatic single stepping/tracing" functionality ...) Stefan
Stefan
------------------------------------------------------------------------------ This SF.net email is sponsored by: High Quality Requirements in a Collaborative Environment. Download a free trial of Rational Requirements Composer Now! http://p.sf.net/sfu/www-ibm-com _______________________________________________ Monetdb-developers mailing list Monetdb-developers@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/monetdb-developers
-- | Dr. Stefan Manegold | mailto:Stefan.Manegold@cwi.nl | | CWI, P.O.Box 94079 | http://www.cwi.nl/~manegold/ | | 1090 GB Amsterdam | Tel.: +31 (20) 592-4212 | | The Netherlands | Fax : +31 (20) 592-4312 |
Stefan Manegold wrote:
On Sun, Apr 12, 2009 at 03:15:36AM +0200, Stefan de Konink wrote:
Hi All,
Might be better to go by the mailinglist instead of adding many people to the CC.
Good. Exactly that is why we have mailing lists ;-)
Currently I am running the latest CVS code disabled mitosis and am running the following code:
CREATE TABLE "sys"."way_nds" ( "way" int NOT NULL, "idx" int NOT NULL, "to_node" int, CONSTRAINT "pk_way_nds" PRIMARY KEY ("way", "idx") );
select count(way), way, to_node from way_nds group by way, to_node having count(way) > 1;
The table contains about 362420451 rows, and I realised too late there could be many results comming from it.
I don't know, whether the fact that is does/might create "many result" is related to the "hanging" situation at all ...
top - 03:12:15 up 1 day, 17:28, 8 users, load average: 1.00, 1.00, 1.00 Tasks: 193 total, 1 running, 192 sleeping, 0 stopped, 0 zombie Cpu(s): 0.0%us, 0.1%sy, 0.0%ni, 94.6%id, 5.2%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 66113464k total, 39353192k used, 26760272k free, 326968k buffers Swap: 134215032k total, 94284k used, 134120748k free, 8489128k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
11856 konink 20 0 51.5g 34g 5.9g S 0.3 54.6 45:34.93 mserver5
But again the load is low, the memory empty and it seems to do so few.
load is 1.0 --- i.e., one thrad full throttle --- unless it is a "fake" load no full throttle, just 1 process... :( due to a Dead/Dummy/zombie process that is (e.g.) waiting for I/O --- in top, type "1" to get the summaries for all cores and "H" to list all threads and "u"+[Enter] to list processes of all users; then "P" to order on CPU usage and report; then "M" to oder on memory usage (34g res is IMHO everything but "empty") and report.
Is there something that would be interesting to look at?
Basically, it would be great to know which MAL statement is currently being executed on which inputs --- prefixing your SQL statement with TRACE is one option (though I don't know whether that flushes it's output instantly; if not, we should consider adding such functionality excatly for such "hanging" situations --- in any case, it list only a statement after it has finished; yes, because then you know the statistics. hence, comparing the TRACE output with that of EXPLAIN is required); running in the MAL debugger (prefix SQL statement with DEBUG) is the other option (though I don't know, whether the MAL debugger has some "automatic single stepping/tracing" functionality ...) in the MAL debugger, type 'help' et voila, it has a trace option ;)
You can trace the execution even for a server started already using the stethoscope. http://monetdb.cwi.nl/projects/monetdb/MonetDB/Documentation/Stethoscope.htm...
Stefan
Stefan
------------------------------------------------------------------------------ This SF.net email is sponsored by: High Quality Requirements in a Collaborative Environment. Download a free trial of Rational Requirements Composer Now! http://p.sf.net/sfu/www-ibm-com _______________________________________________ Monetdb-developers mailing list Monetdb-developers@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/monetdb-developers
Martin Kersten wrote:
You can trace the execution even for a server started already using the stethoscope.
p[ 605303, mt, # name
[ 51, "_30 := bat.mirror(ext35=
On Mon, Apr 13, 2009 at 02:30:44AM +0200, Stefan de Konink wrote:
Martin Kersten wrote:
You can trace the execution even for a server started already using the stethoscope.
What does this/you you want to tell/show us? I.e., does your query still hang, or did it finish now? ("end s27_1;" seem to suggest so, right?) Please try to be a bit more verbose in your statements/emails... I see that aggr.count() (not unexpectedly) is the most expensive one of the operations shown below --- but "only" ~100 sec --- not too extreme for counting the size of 362105182 groups over 365652137 BUNs ... The sum of all shown times is "only" 116865583 usec (i.e., just under 2 min). Did you compile from CVS or from tarball? Did you configure with either --disable-assert (CVS) or --enable-assert (tarball)? If you compiled from CVS without --disable-assert or from tarball with --enable-assert, you also might want to start your mserver5 with --performance (or at least --debug=33554432) to disable "cleaning" of to-be-freed memory just before free() is called --- this might make the ":= nil;" assignments (a bit?) faster ... Stefan
p [ 605303, mt, # name [ 51, "_30 := bat.mirror(ext35=
[362105182]);" ] [ 1282955, "grp20 := nil;"] [ 13, 955, "grp20 := nil;" ] [ 13, "ext35 := nil;" ] [ 103806553, "_31 := aggr.count(_17= [365652137],grp33= [365652137],_30= [362105182]);" ] [ 14, "_17 := nil;" ] [ 1088736, "grp33 := nil;" ] [ 2605761, "_33 := algebra.thetauselect(_31= :bat[:oid,:wrd][362105182],_32=2:wrd,">");" ] [ 45, "_36 := algebra.markT(_33= [6054],0@0);" ] [ 7, "_37 := bat.reverse(_36= [6054]);" ] [ 8, "_33 := nil;" ] [ 9, "_36 := nil;" ] [ 17917, "_38 := algebra.join(_37= [6054],_31= :bat[:oid,:wrd][362105182]);" ] [ 1283903, "_31 := nil;" ] [ 1314255, "_39 := algebra.joinPath(_37= [6054],_30= [362105182],_16= [365652137]);" ] [ 1314255, "_40 := algebra.joinPath(_37= [6054],_30= [362105182],_27= [365652137]);" ] [ 67, "_37 := nil;" ] [ 967626, "_27 := nil;" ] [ 1205150, "_16 := nil;" ] [ 1360389, "_30 := nil;" ] [ 28, "_41 := sql.resultSet(3,1,_38= [6054]);" ] [ 10, "sql.rsColumn(_41=32,"sys.way_nds","L6","wrd",32,0,_38= [6054]);" ] [ 7, "_38 := nil;" ] [ 6, "sql.rsColumn(_41=32,"sys.way_nds","way","int",32,0,_39= [6054]);" ] [ 2, "_39 := nil;" ] [ 5, "sql.rsColumn(_41=32,"sys.way_nds","to_node","int",32,0,_40= [6054]);" ] [ 2, "_40 := nil;" ] [ 2, "_51 := io.stdout();" ] [ 12489, "sql.exportResult(_51=27443088,_41=32);" ] [ 2, "end s27_1;" ] Stefan
------------------------------------------------------------------------------ This SF.net email is sponsored by: High Quality Requirements in a Collaborative Environment. Download a free trial of Rational Requirements Composer Now! http://p.sf.net/sfu/www-ibm-com _______________________________________________ Monetdb-developers mailing list Monetdb-developers@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/monetdb-developers
-- | Dr. Stefan Manegold | mailto:Stefan.Manegold@cwi.nl | | CWI, P.O.Box 94079 | http://www.cwi.nl/~manegold/ | | 1090 GB Amsterdam | Tel.: +31 (20) 592-4212 | | The Netherlands | Fax : +31 (20) 592-4312 |
Stefan Manegold wrote:
On Mon, Apr 13, 2009 at 02:30:44AM +0200, Stefan de Konink wrote:
Martin Kersten wrote:
You can trace the execution even for a server started already using the stethoscope.
What does this/you you want to tell/show us? I.e., does your query still hang, or did it finish now?
The query finishes as I wrote in the previous email, the output was merely an attempt to show were the pain might be.
I see that aggr.count() (not unexpectedly) is the most expensive one of the operations shown below --- but "only" ~100 sec --- not too extreme for counting the size of 362105182 groups over 365652137 BUNs ...
The sum of all shown times is "only" 116865583 usec (i.e., just under 2 min).
Then it is likely the output misses the last actual 'big time consumer', while Martin suggested it would show that event.
Did you compile from CVS or from tarball?
I use CVS head.
Did you configure with either --disable-assert (CVS) or --enable-assert (tarball)?
assert, profile, debug
If you compiled from CVS without --disable-assert or from tarball with --enable-assert, you also might want to start your mserver5 with --performance (or at least --debug=33554432) to disable "cleaning" of to-be-freed memory just before free() is called --- this might make the ":= nil;" assignments (a bit?) faster ...
I am more than happy to try this. Stefan
Stefan de Konink wrote:
Stefan Manegold wrote:
counting the size of 362105182 groups over 365652137 BUNs ...
The sum of all shown times is "only" 116865583 usec (i.e., just under 2 min).
Then it is likely the output misses the last actual 'big time consumer', while Martin suggested it would show that event.
Profiling instructions is an expensive operation and only enabled upon request. Moreover, you need to read the system counters before and after the instruction. This means when you start the stethoscope you will only see the results as of the *next* MAL instruction being executed.
Stefan Manegold wrote:
load is 1.0 --- i.e., one thrad full throttle --- unless it is a "fake" load due to a Dead/Dummy/zombie process that is (e.g.) waiting for I/O --- in top, type "1" to get the summaries for all cores and "H" to list all threads and "u"+[Enter] to list processes of all users; then "P" to order on CPU usage and report; then "M" to oder on memory usage (34g res is IMHO everything but "empty") and report.
I am rerunning the query with having > 2; basically same situation. top - 20:46:37 up 2 days, 11:03, 8 users, load average: 1.02, 1.01, 1.10 Tasks: 283 total, 1 running, 282 sleeping, 0 stopped, 0 zombie Cpu0 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu1 : 0.3%us, 0.0%sy, 0.0%ni, 99.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu2 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu3 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu4 : 0.0%us, 0.0%sy, 0.0%ni, 93.0%id, 7.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu5 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Cpu6 : 0.3%us, 0.3%sy, 0.0%ni, 92.4%id, 6.9%wa, 0.0%hi, 0.0%si, 0.0%st Cpu7 : 0.0%us, 0.0%sy, 0.0%ni,100.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 66113464k total, 39815632k used, 26297832k free, 438728k buffers Swap: 134215032k total, 89016k used, 134126016k free, 8093920k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 11870 konink 20 0 51.7g 33g 5.3g D 0.3 53.8 10:16.09 mserver5 In most cases mserver is the biggest; it seems to be one thread.
Is there something that would be interesting to look at?
Basically, it would be great to know which MAL statement is currently being executed on which inputs --- prefixing your SQL statement with TRACE is one option (though I don't know whether that flushes it's output instantly; if not, we should consider adding such functionality excatly for such "hanging" situations --- in any case, it list only a statement after it has finished; hence, comparing the TRACE output with that of EXPLAIN is required); running in the MAL debugger (prefix SQL statement with DEBUG) is the other option (though I don't know, whether the MAL debugger has some "automatic single stepping/tracing" functionality ...)
I'll go play with this too. Stefan
participants (3)
-
Martin Kersten -
Stefan de Konink -
Stefan Manegold