Using something like "trace" within the MAL interpreter
Hi, The "trace" commands works well when mclient is in the SQL interpreter mode. How about when mclient is in MAl interpreter mode? Is there a way to use the "trace" command in this mode? Best regards, Masood
Hi The best way to trace is to use the 'stethoscope' http://www.monetdb.org/Documentation/Manuals/MonetDB/Profiler/Stethoscope For MAL programs one can use something like: profiler.activate("ISTestmrw"); profiler.setAll(); profiler.openStream(); profiler.start(); ...MAL program to follow.... profiler.stop(); regards, Martin On 5/18/13 2:29 AM, Masood Mortazavi wrote:
Hi, The "trace" commands works well when mclient is in the SQL interpreter mode. How about when mclient is in MAl interpreter mode? Is there a way to use the "trace" command in this mode? Best regards, Masood
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
Hi. I'm working with Masood. When profiling an explained (MAL) version of TPCH Query 1 with stethoscope, we noticed something strange, and would appreciate your comments. First, the MAL program seems to take longer by about 75% (10 to 15 seconds on a given server) to produce output when run at TPCH scale factor 100. (We have similar results at other scale factors.) Second, the program doesn't produce output until about 10-15 seconds after completing sql.exportResult() when run as MAL, but does so immediately after completing sql.exportResult() when run as SQL. There doesn't seem to be anything going on in that final 10-15 second interval in the MAL program, at least according to stethoscope. What might be happening during that time? Perhaps naively, we imagined that the MAL and SQL timings would be about the same. Thanks, Steve ________________________________ From: Martin Kersten <Martin.Kersten@cwi.nl> To: users-list@monetdb.org Sent: Fri, May 17, 2013 5:35:50 PM Subject: Re: Using something like "trace" within the MAL interpreter Hi The best way to trace is to use the 'stethoscope' http://www.monetdb.org/Documentation/Manuals/MonetDB/Profiler/Stethoscope For MAL programs one can use something like: profiler.activate("ISTestmrw"); profiler.setAll(); profiler.openStream(); profiler.start(); ...MAL program to follow.... profiler.stop(); regards, Martin On 5/18/13 2:29 AM, Masood Mortazavi wrote:
Hi, The "trace" commands works well when mclient is in the SQL interpreter mode. How about when mclient is in MAl interpreter mode? Is there a way to use the "trace" command in this mode? Best regards, Masood
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
Hi. Thank you for the comments. Overall there is no immediate answer to your question, because the Mserver, OS and hardware characteristics are unkown. On a small (ATOM) system there may be swapping between client/server cost, or network-re-establishment cost in a distributed client/server (cloud) setup. Also some Linux versions show unstable behavior under some page mapping schemes. On 5/20/13 7:11 PM, Stephen P. Morgan wrote:
Hi. I'm working with Masood. When profiling an explained (MAL) version of TPCH Query 1 with stethoscope, we noticed something strange, and would appreciate your comments. First, the MAL program seems to take longer by about 75% (10 to 15 seconds on a given server) to produce output when run at TPCH scale factor 100. (We have similar results at other scale factors.) Second, the program doesn't produce output until about 10-15 seconds after completing sql.exportResult() when run as MAL, looks like a reload/re-establishment of processes.
but does so immediately after completing sql.exportResult() when run as SQL. There doesn't seem to be anything going on in that final 10-15 second interval in the MAL program, at least according to stethoscope. The stethoscope does not show OS behavior, but this can be triggered using the proper parameters. See stethoscope --help, which gives you access to the basis OS performance parameters. What might be happening during that time?
Perhaps naively, we imagined that the MAL and SQL timings would be about the same. They use the same protocol for interaction.
NOTE 1; be aware of the difference between hot and cold runs. NOTE 2; be aware that even starting a browser at the same time on the test machine can lead to resource (memory/cpu) fights and therefore possible performance differences. regards, Martin
Thanks,
Steve
------------------------------------------------------------------------ *From:* Martin Kersten <Martin.Kersten@cwi.nl> *To:* users-list@monetdb.org *Sent:* Fri, May 17, 2013 5:35:50 PM *Subject:* Re: Using something like "trace" within the MAL interpreter
Hi
The best way to trace is to use the 'stethoscope' http://www.monetdb.org/Documentation/Manuals/MonetDB/Profiler/Stethoscope
For MAL programs one can use something like: profiler.activate("ISTestmrw"); profiler.setAll(); profiler.openStream(); profiler.start(); ...MAL program to follow.... profiler.stop();
regards, Martin
On 5/18/13 2:29 AM, Masood Mortazavi wrote:
Hi, The "trace" commands works well when mclient is in the SQL interpreter mode. How about when mclient is in MAl interpreter mode? Is there a way to use the "trace" command in this mode? Best regards, Masood
_______________________________________________ users-list mailing list users-list@monetdb.org <mailto:users-list@monetdb.org> http://mail.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org <mailto:users-list@monetdb.org> http://mail.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
The environment comprises a dual Xeon E5-2680 CPU server clocked at 2.7 GHz running Ubuntu (12.10, I believe) x86_64 SMP Linux (3.5.0-17-generic kernel). /proc/cpuinfo reports that there are 32 CPUs, so I presume there are 16 cores in each CPU (or perhaps eight cores each with hyperthreading?). The machine has 198,062,144 KBytes of RAM according to /proc/meminfo (a strange number, admittedly). We're running a very slightly modified Feb2013-SP1 MonetDB system; however, none of the modifications relate to performance. (They relate to generating enough type information that we can automatically run explain-generated MAL.) The observation is that (consistently), when running TPCH Query 1 in MAL from mclient while tracing output via stethoscope, we see that the last event noted by stethoscope, i.e., sql.exportResult() completes about 10-15 seconds before mclient displays its results. And sql.exportResult() is the final MAL instruction in the program. (Well, that's not quite true. The program is run by calling the MAL function generated by explaining a SQL query, so I suppose there is a return from the function call. And we call sql.init() before calling the function.) We are ssh'ed into the system, and we are running in an LXC container, in case either of those might make a difference. But for the case in which we run SQL, we are also ssh'ed into an LXC container. And the results are consistently repeatable. I just tried setting all sorts of flags in stethoscope, but once it shows that sql.exportResult() has completed, I get no more output from it. The next thing that happens is that mclient returns its results (some 10-15 seconds later). Is mclient performing some sort of complex computation on the results prior to displaying them? Or is there some complex protocol between mserver and mclient in the case of MAL queries? (It's unlikely to be paging, due to the large amount of RAM.) There should be no other activity going on in the system. In the case of SQL queries, we get the results approximately simultaneously with stethoscope noting that sql.exportResult() has finished. I wonder whether you can think of something that we might be doing wrong or whether you can give us some idea what is happening in those 10-15 seconds? Thank you, Steve --- On Mon, 5/20/13, Martin Kersten <Martin.Kersten@cwi.nl> wrote: From: Martin Kersten <Martin.Kersten@cwi.nl> Subject: Re: Using something like "trace" within the MAL interpreter To: users-list@monetdb.org Date: Monday, May 20, 2013, 12:11 PM Hi. Thank you for the comments. Overall there is no immediate answer to your question, because the Mserver, OS and hardware characteristics are unkown. On a small (ATOM) system there may be swapping between client/server cost, or network-re-establishment cost in a distributed client/server (cloud) setup. Also some Linux versions show unstable behavior under some page mapping schemes. On 5/20/13 7:11 PM, Stephen P. Morgan wrote:
Hi. I'm working with Masood. When profiling an explained (MAL) version of TPCH Query 1 with stethoscope, we noticed something strange, and would appreciate your comments. First, the MAL program seems to take longer by about 75% (10 to 15 seconds on a given server) to produce output when run at TPCH scale factor 100. (We have similar results at other scale factors.) Second, the program doesn't produce output until about 10-15 seconds after completing sql.exportResult() when run as MAL, looks like a reload/re-establishment of processes.
but does so immediately after completing sql.exportResult() when run as SQL. There doesn't seem to be anything going on in that final 10-15 second interval in the MAL program, at least according to stethoscope. The stethoscope does not show OS behavior, but this can be triggered using the proper parameters. See stethoscope --help, which gives you access to the basis OS performance parameters. What might be happening during that time?
Perhaps naively, we imagined that the MAL and SQL timings would be about the same. They use the same protocol for interaction.
NOTE 1; be aware of the difference between hot and cold runs. NOTE 2; be aware that even starting a browser at the same time on the test machine can lead to resource (memory/cpu) fights and therefore possible performance differences. regards, Martin
Thanks,
Steve
------------------------------------------------------------------------ *From:* Martin Kersten <Martin.Kersten@cwi.nl> *To:* users-list@monetdb.org *Sent:* Fri, May 17, 2013 5:35:50 PM *Subject:* Re: Using something like "trace" within the MAL interpreter
Hi
The best way to trace is to use the 'stethoscope' http://www.monetdb.org/Documentation/Manuals/MonetDB/Profiler/Stethoscope
For MAL programs one can use something like: profiler.activate("ISTestmrw"); profiler.setAll(); profiler.openStream(); profiler.start(); ...MAL program to follow.... profiler.stop();
regards, Martin
On 5/18/13 2:29 AM, Masood Mortazavi wrote: > Hi, > The "trace" commands works well when mclient is in the SQL interpreter mode. > How about when mclient is in MAl interpreter mode? Is there a way to use > the "trace" command in this mode? > Best regards, > Masood > > > _______________________________________________ > users-list mailing list > users-list@monetdb.org <mailto:users-list@monetdb.org> > http://mail.monetdb.org/mailman/listinfo/users-list > _______________________________________________ users-list mailing list users-list@monetdb.org <mailto:users-list@monetdb.org> http://mail.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
Dear Steve Thanks for the additional information, which shows it does not relate to my earlier suspicions. I have never ran MAL TPCH Q1 versions (copied pasted from the SQL) separately. The protocol adhered to by all front-ends is the same and encapsulated in the mapi library. As such, the difference in output shipping is unexpected. Perhaps running mclient using valgrind --tool=callgrind using both variations (SQL and MAL) might show a difference in code execution. On 5/20/13 11:31 PM, Stephen P. Morgan wrote:
The environment comprises a dual Xeon E5-2680 CPU server clocked at 2.7 GHz running Ubuntu (12.10, I believe) x86_64 SMP Linux (3.5.0-17-generic kernel). /proc/cpuinfo reports that there are 32 CPUs, so I presume there are 16 cores in each CPU (or perhaps eight cores each with hyperthreading?). The machine has 198,062,144 KBytes of RAM according to /proc/meminfo (a strange number, admittedly). We're running a very slightly modified Feb2013-SP1 MonetDB system; however, none of the modifications relate to performance. (They relate to generating enough type information that we can automatically run explain-generated MAL.)
The observation is that (consistently), when running TPCH Query 1 in MAL from mclient while tracing output via stethoscope, we see that the last event noted by stethoscope, i.e., sql.exportResult() completes about 10-15 seconds before mclient displays its results. And sql.exportResult() is the final MAL instruction in the program. (Well, that's not quite true. The program is run by calling the MAL function generated by explaining a SQL query, so I suppose there is a return from the function call. And we call sql.init() before calling the function.)
We are ssh'ed into the system, and we are running in an LXC container, in case either of those might make a difference. But for the case in which we run SQL, we are also ssh'ed into an LXC container. And the results are consistently repeatable.
I just tried setting all sorts of flags in stethoscope, but once it shows that sql.exportResult() has completed, I get no more output from it. The next thing that happens is that mclient returns its results (some 10-15 seconds later).
Is mclient performing some sort of complex computation on the results prior to displaying them? Or is there some complex protocol between mserver and mclient in the case of MAL queries? (It's unlikely to be paging, due to the large amount of RAM.) There should be no other activity going on in the system.
In the case of SQL queries, we get the results approximately simultaneously with stethoscope noting that sql.exportResult() has finished.
I wonder whether you can think of something that we might be doing wrong or whether you can give us some idea what is happening in those 10-15 seconds?
Thank you,
Steve
--- On *Mon, 5/20/13, Martin Kersten /<Martin.Kersten@cwi.nl>/* wrote:
From: Martin Kersten <Martin.Kersten@cwi.nl> Subject: Re: Using something like "trace" within the MAL interpreter To: users-list@monetdb.org Date: Monday, May 20, 2013, 12:11 PM
Hi. Thank you for the comments. Overall there is no immediate answer to your question, because the Mserver, OS and hardware characteristics are unkown. On a small (ATOM) system there may be swapping between client/server cost, or network-re-establishment cost in a distributed client/server (cloud) setup.
Also some Linux versions show unstable behavior under some page mapping schemes.
On 5/20/13 7:11 PM, Stephen P. Morgan wrote: > Hi. I'm working with Masood. When profiling an explained (MAL) version > of TPCH Query 1 with stethoscope, we noticed something strange, and > would appreciate your comments. First, the MAL program seems to take > longer by about 75% (10 to 15 seconds on a given server) to produce > output when run at TPCH scale factor 100. (We have similar results at > other scale factors.) Second, the program doesn't produce output until > about 10-15 seconds after completing sql.exportResult() when run as MAL, looks like a reload/re-establishment of processes.
> but does so immediately after completing sql.exportResult() when run as > SQL. There doesn't seem to be anything going on in that final 10-15 > second interval in the MAL program, at least according to stethoscope. The stethoscope does not show OS behavior, but this can be triggered using the proper parameters. See stethoscope --help, which gives you access to the basis OS performance parameters. > What might be happening during that time? > > Perhaps naively, we imagined that the MAL and SQL timings would be about > the same. They use the same protocol for interaction.
NOTE 1; be aware of the difference between hot and cold runs. NOTE 2; be aware that even starting a browser at the same time on the test machine can lead to resource (memory/cpu) fights and therefore possible performance differences.
regards, Martin > > Thanks, > > Steve > > ------------------------------------------------------------------------ > *From:* Martin Kersten <Martin.Kersten@cwi.nl </mc/compose?to=Martin.Kersten@cwi.nl>> > *To:* users-list@monetdb.org </mc/compose?to=users-list@monetdb.org> > *Sent:* Fri, May 17, 2013 5:35:50 PM > *Subject:* Re: Using something like "trace" within the MAL interpreter > > Hi > > The best way to trace is to use the 'stethoscope' > http://www.monetdb.org/Documentation/Manuals/MonetDB/Profiler/Stethoscope > > For MAL programs one can use something like: > profiler.activate("ISTestmrw"); > profiler.setAll(); > profiler.openStream(); > profiler.start(); > ...MAL program to follow.... > profiler.stop(); > > > regards, Martin > > On 5/18/13 2:29 AM, Masood Mortazavi wrote: > > Hi, > > The "trace" commands works well when mclient is in the SQL > interpreter mode. > > How about when mclient is in MAl interpreter mode? Is there a way to use > > the "trace" command in this mode? > > Best regards, > > Masood > > > > > > _______________________________________________ > > users-list mailing list > > users-list@monetdb.org </mc/compose?to=users-list@monetdb.org> <mailto:users-list@monetdb.org </mc/compose?to=users-list@monetdb.org>> > > http://mail.monetdb.org/mailman/listinfo/users-list > > > _______________________________________________ > users-list mailing list > users-list@monetdb.org </mc/compose?to=users-list@monetdb.org> <mailto:users-list@monetdb.org </mc/compose?to=users-list@monetdb.org>> > http://mail.monetdb.org/mailman/listinfo/users-list > > > _______________________________________________ > users-list mailing list > users-list@monetdb.org </mc/compose?to=users-list@monetdb.org> > http://mail.monetdb.org/mailman/listinfo/users-list > _______________________________________________ users-list mailing list users-list@monetdb.org </mc/compose?to=users-list@monetdb.org> http://mail.monetdb.org/mailman/listinfo/users-list
_______________________________________________ users-list mailing list users-list@monetdb.org http://mail.monetdb.org/mailman/listinfo/users-list
participants (3)
-
Martin Kersten -
Masood Mortazavi -
Stephen P. Morgan