From: Dane M. <da...@gr...> - 2007-04-27 22:11:25
|
Hi Baron (and others?), I'm using innotop 1.4.1 from FreeBSD ports, and am confused by the S (Load Statistics) output. It mostly shows zeroes. Here's a snip running with a 2sec polling interval on a box doing 400 qps ... Uptime Questions Com_delete Cm_dlt_mlt Com_insert Cm_in_slct Cm_rplc Cm_rp_slct Com_select Com_update C_updt_mlt 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 What's going on? By comparison, innotop's Q output shows queries flying by. OS: FreeBSD 6.2 perl: v5.8.8 mysqld: 5.0.33 (started with --skip-innodb) innotop user has SUPER privs Dane |
From: Dane M. <da...@gr...> - 2007-04-27 22:24:46
|
Dane Miller wrote: > Uptime Questions Com_delete Cm_dlt_mlt Com_insert Cm_in_slct Cm_rplc > Cm_rp_slct Com_select Com_update C_updt_mlt > 0 0 0 0 0 0 > 0 0 0 0 0 > 0 0 0 0 0 0 > 0 0 0 0 0 more info... Sometimes I get correct values. When I first launch innotop I get this (truncated output): Uptime Questions 3718472 1338392876 0 0 3718482 1338395787 0 0 0 0 |
From: Baron S. <ba...@xa...> - 2007-04-28 19:13:07
|
Hi, Dane Miller wrote: > Dane Miller wrote: >> Uptime Questions Com_delete Cm_dlt_mlt Com_insert Cm_in_slct Cm_rplc >> Cm_rp_slct Com_select Com_update C_updt_mlt >> 0 0 0 0 0 0 >> 0 0 0 0 0 >> 0 0 0 0 0 0 >> 0 0 0 0 0 > > more info... > Sometimes I get correct values. When I first launch innotop I get this > (truncated output): > > Uptime Questions > 3718472 1338392876 > 0 0 > 3718482 1338395787 > 0 0 > 0 0 Almost certainly a bug involving an undefined value or division by zero in the extract_values() subroutine: eval { $result->{$key} = $info->{func}->($set) }; if ( $EVAL_ERROR ) { $result->{$key} = $info->{num} ? 0 : ''; } It's getting some error and assigning zero so it can continue without crashing. Any ideas what the error is? The only thing I can think is a) the results of SHOW STATUS are somehow wrong, but I can't think of how, or b) you are in 'incremental' mode to see the differences between sets, and something is wrong with subtracting sets. It might happen if you don't have high-resolution time support -- oh wait, there's actually a bug with that in 1.4.1 that might be the cause! Are you willing to run the latest trunk code in Subversion? That might help debug it. Baron |
From: Dane M. <da...@gr...> - 2007-04-29 23:39:46
|
----- "Baron Schwartz" <ba...@xa...> wrote: > It might happen if you don't have high-resolution time > support -- oh wait, there's actually a bug with that in > 1.4.1 that might be the cause! Sounds plausible. I'm not using the hi-res time patch (btw, is that now included in 5.0.37 ?) > Are you willing to run the latest trunk code in Subversion? That > might help debug it. Yeah, you bet. I imagine I can http download the sources from http://innotop.svn.sourceforge.net/viewvc/innotop/trunk/ I'll report back tonight or tomorrow. Dane |
From: Baron S. <ba...@xa...> - 2007-04-30 00:27:36
|
Dane Miller wrote: > ----- "Baron Schwartz" <ba...@xa...> wrote: >> It might happen if you don't have high-resolution time >> support -- oh wait, there's actually a bug with that in >> 1.4.1 that might be the cause! > > Sounds plausible. I'm not using the hi-res time patch (btw, is that now included in 5.0.37 ?) Actually, I refer to Perl's Time::HiRes, which I made non-optional recently. I had made it optional before, and thought it was therefore replacing Perl's built-in time() function with a high-resolution version of the same, but I discovered it wasn't after all. So many things won't work well without it that I decided to just make it mandatory in 1.4.2 anyway. It's part of Perl's core modules so it shouldn't be a big deal, except perhaps in weird third-party Perl distributions or something. >> Are you willing to run the latest trunk code in Subversion? That >> might help debug it. > > Yeah, you bet. I imagine I can http download the sources from http://innotop.svn.sourceforge.net/viewvc/innotop/trunk/ > > I'll report back tonight or tomorrow. Yes, that's it. If you press $, then g and set 'debug' to 1, the latest trunk code will throw a meaningful error message in the kinds of cases I think you might be hitting. Baron |
From: Dane M. <da...@gr...> - 2007-04-30 04:58:50
|
----- "Baron Schwartz" <ba...@xa...> wrote: > Dane Miller wrote: > > Sounds plausible. I'm not using the hi-res time patch (btw, is that > > now included in 5.0.37 ?) > > Actually, I refer to Perl's Time::HiRes, which I made non-optional > recently. oops. I misunderstood... was thinking about a hi-res time patch for mysql. I can confirm that my Perl has Time::HiRes > >> Are you willing to run the latest trunk code in Subversion? That > >> might help debug it. > > > > Yeah, you bet. I imagine I can http download the sources from > > http://innotop.svn.sourceforge.net/viewvc/innotop/trunk/ > > Yes, that's it. > > If you press $, then g and set 'debug' to 1, the latest trunk code > will throw a meaningful error message in the kinds of cases I think you > might be hitting. Ok. Here are fresh results with revision 235 (latest trunk code). The zeros are gone, but I don't get output every interval. It's hard to see below, but for an interval of 2, the data is refreshed at uptime 1443, 1469, 1537. Also worth noting I have all myisam tables, but my.cnf does not contain 'skip-innodb' (although it did when I started this experiment). ## innotop output: Enter a new value for 'interval' (The interval at which the display will be refreshed. Fractional values allowed.). Enter a value: 2 Uptime Qc_fr_blcks Qch_fr_mry Qcache_hits Qch_insrts Qc_lwm_prns Qch_nt_chd Qch_qrs_ch Qc_tl_blcks Error at tick 8 localhost Cannot call SHOW INNODB STATUS because skip-innodb is definedError at tick 8 localhost Cannot call SHOW INNODB STATUS because skip-innodb is defined 1443 1 16768448 0 0 0 22 0 1 Error at tick 21 localhost Cannot call SHOW INNODB STATUS because skip-innodb is definedError at tick 21 localhost Cannot call SHOW INNODB STATUS because skip-innodb is defined 1469 1 16768448 0 0 0 24 0 1 Error at tick 55 localhost Cannot call SHOW INNODB STATUS because skip-innodb is definedError at tick 55 localhost Cannot call SHOW INNODB STATUS because skip-innodb is defined 1537 1 16768448 0 0 0 29 0 1 Dane |
From: Baron S. <ba...@xa...> - 2007-04-30 13:38:41
|
Dane Miller wrote: > ----- "Baron Schwartz" <ba...@xa...> wrote: >> Dane Miller wrote: >>> Sounds plausible. I'm not using the hi-res time patch (btw, is that >>> now included in 5.0.37 ?) >> Actually, I refer to Perl's Time::HiRes, which I made non-optional >> recently. > > oops. I misunderstood... was thinking about a hi-res time patch for mysql. I can confirm that my Perl has Time::HiRes Good. Then the only trouble with that was the way I used it in 1.4.1, which was buggy :-) >>>> Are you willing to run the latest trunk code in Subversion? That >>>> might help debug it. >>> Yeah, you bet. I imagine I can http download the sources from >>> http://innotop.svn.sourceforge.net/viewvc/innotop/trunk/ >> Yes, that's it. >> >> If you press $, then g and set 'debug' to 1, the latest trunk code >> will throw a meaningful error message in the kinds of cases I think you >> might be hitting. > > Ok. Here are fresh results with revision 235 (latest trunk code). The zeros are gone, but I don't get output every interval. It's hard to see below, but for an interval of 2, the data is refreshed at uptime 1443, 1469, 1537. Also worth noting I have all myisam tables, but my.cnf does not contain 'skip-innodb' (although it did when I started this experiment). > > ## innotop output: > > Enter a new value for 'interval' (The interval at which the display will be refreshed. Fractional values allowed.). > Enter a value: 2 > Uptime Qc_fr_blcks Qch_fr_mry Qcache_hits Qch_insrts Qc_lwm_prns Qch_nt_chd Qch_qrs_ch Qc_tl_blcks > Error at tick 8 localhost Cannot call SHOW INNODB STATUS because skip-innodb is definedError at tick 8 localhost Cannot call SHOW INNODB STATUS because skip-innodb is defined 1443 1 16768448 0 0 0 22 0 1 > Error at tick 21 localhost Cannot call SHOW INNODB STATUS because skip-innodb is definedError at tick 21 localhost Cannot call SHOW INNODB STATUS because skip-innodb is defined 1469 1 16768448 0 0 0 24 0 1 > Error at tick 55 localhost Cannot call SHOW INNODB STATUS because skip-innodb is definedError at tick 55 localhost Cannot call SHOW INNODB STATUS because skip-innodb is defined 1537 1 16768448 0 0 0 29 0 1 > Okay, here's what's happening. Even though skip-innodb isn't really defined, you can't call SHOW INNODB STATUS for some reason. This can happen for many reasons. I wrote about some of them here: http://www.xaprb.com/blog/2007/03/08/what-to-do-when-mysql-says-skip-innodb-is-defined/ In any case, innotop sees the error and says "oh, it looks like localhost has a problem. I'll just try later." It avoids that connection for a while to avoid repeatedly erroring out (it waits for the Fibonacci series in fact), and retries. The real problem with this is you only want data from SHOW STATUS and SHOW VARIABLES. (Probably just SHOW STATUS, in fact). It shouldn't be trying to call SHOW INNODB STATUS unless it needs data from it. This is on the list of things to do. It requires that innotop keeps track of the source for each bit of data and only fetch the ones it needs. I'm not sure how much work this will be. As a workaround, I just added a skip_innodb config variable, and this will prevent SHOW INNODB STATUS being called and throwing an error if you set it. Would you mind getting the latest trunk source again, setting that variable and trying again? Thanks Baron |
From: Dane M. <da...@gr...> - 2007-04-30 16:40:11
|
Baron Schwartz wrote: > Okay, here's what's happening. Even though skip-innodb isn't really > defined, you can't call SHOW INNODB STATUS for some reason. This can > happen for many reasons. I wrote about some of them here: > > http://www.xaprb.com/blog/2007/03/08/what-to-do-when-mysql-says-skip-innodb-is-defined/ Thanks Baron. This is helpful and informative. > The real problem with this is you only want data from SHOW STATUS and > SHOW VARIABLES. (Probably just SHOW STATUS, in fact). It shouldn't be > trying to call SHOW INNODB STATUS unless it needs data from it. This is > on the list of things to do. It requires that innotop keeps track of > the source for each bit of data and only fetch the ones it needs. I'm > not sure how much work this will be. > > As a workaround, I just added a skip_innodb config variable, and this > will prevent SHOW INNODB STATUS being called and throwing an error if > you set it. > > Would you mind getting the latest trunk source again, setting that > variable and trying again? Using innotop revision 236 with skip_innodb set to 1 ($ -> g -> skip_innodb) works well. Thanks for the quick turnaround! Here's the (correct!) output of S mode, with a 2sec delay interval: Uptime 37946 37948 37950 37952 Dane |
From: Baron S. <ba...@xa...> - 2007-04-30 19:07:11
|
Dane Miller wrote: > Baron Schwartz wrote: >> Okay, here's what's happening. Even though skip-innodb isn't really >> defined, you can't call SHOW INNODB STATUS for some reason. This can >> happen for many reasons. I wrote about some of them here: >> >> http://www.xaprb.com/blog/2007/03/08/what-to-do-when-mysql-says-skip-innodb-is-defined/ > > Thanks Baron. This is helpful and informative. > >> The real problem with this is you only want data from SHOW STATUS and >> SHOW VARIABLES. (Probably just SHOW STATUS, in fact). It shouldn't be >> trying to call SHOW INNODB STATUS unless it needs data from it. This is >> on the list of things to do. It requires that innotop keeps track of >> the source for each bit of data and only fetch the ones it needs. I'm >> not sure how much work this will be. >> >> As a workaround, I just added a skip_innodb config variable, and this >> will prevent SHOW INNODB STATUS being called and throwing an error if >> you set it. >> >> Would you mind getting the latest trunk source again, setting that >> variable and trying again? > > Using innotop revision 236 with skip_innodb set to 1 ($ -> g -> > skip_innodb) works well. Thanks for the quick turnaround! > > Here's the (correct!) output of S mode, with a 2sec delay interval: > Uptime > 37946 > 37948 > 37950 > 37952 > > Dane > Great, I'm glad that works OK now. Only fetching from needed sources is one of the top things I want to work on next. Baron |
From: Baron S. <ba...@xa...> - 2007-04-28 18:56:29
|
Hi Dane, Dane Miller wrote: > Hi Baron (and others?), > > I'm using innotop 1.4.1 from FreeBSD ports, and am confused by the S > (Load Statistics) output. It mostly shows zeroes. Here's a snip > running with a 2sec polling interval on a box doing 400 qps ... > > Uptime Questions Com_delete Cm_dlt_mlt Com_insert Cm_in_slct Cm_rplc > Cm_rp_slct Com_select Com_update C_updt_mlt > 0 0 0 0 0 0 > 0 0 0 0 0 > 0 0 0 0 0 0 > 0 0 0 0 0 > 0 0 0 0 0 0 > 0 0 0 0 0 > 0 0 0 0 0 > > What's going on? By comparison, innotop's Q output shows queries flying > by. > > > OS: FreeBSD 6.2 > perl: v5.8.8 > mysqld: 5.0.33 (started with --skip-innodb) > innotop user has SUPER privs > I'm not sure what could be happening. It sounds like there is a bug somewhere, maybe an undefined value is making innotop throw and catch an exception, and when it does that it's just substituting a zero. I'll add code to catch what I think might be happening when debug is enabled (the debug variable in the global config section). A similar bug was the cause of quick-filters not working during my demo on Thursday. Baron |