Is there any specific reason why you store two values of microtime() instead of just using local variable and storing the difference?

Yes, it is for also displaying the delay between 2 queries: That allows to see the time taken to fetch the data from the previous query and to handle it in PHP.

Btw, I'm continuing work on this to add the very detailed profiling information for each query: That way there will be no reasons to copy-paste the query into PhpMyAdmin to see the internal MySQL profiling, and that will win additional time in analysis. Also highlighted NULL keys, so it's immediately visible which parts run without using indexes.

So please wait for my next commit and next comment here before testing and accepting pull request.

Very cool.
Would also be more useful if there was some visual indication of which queries are the time-hoggers. Maybe color-label them based on their time vs the average query time. Or show a time bar representing the time it took.
And maybe an ordering option to show the longest times first.

Side note: Ordering of the stuff under Profile Information would be good to have flipped too. So afterRender is at the top of the list.

Ok, added visual indications for problems and time-hoggers (color-based). Sorting is not really needed with the visible red-on-yellow color-indications.

Improvements as always welcome with pull request now here, or later on CMS.

I'm considering now this pull request final for now. It is already a much better output for SQL optimizations than in any other CMS I know of.

Just to complete the instructions:

• hover on query shows EXPLAIN table (with red highlighting of NULL keys)
• hover on time shows SHOW PROFILE information (with red highlighting of 2 slowest times when more than 1 ms)
• hover on filename shows call-stack (outside JDatabase)

Just applied the PR to the joomla-cms master branch and all works as explained except for the hovers. The tables are not rendered in the tooltip and just shows the html code. Can someone reproduce that?

There is a fix for that here: #1239

Indeed, it fixes it but it still doesn't look pretty to me. Attached is the screenshot as it shows now:

@beat Could you take a look at this branch? https://github.com/nonumber/joomla-cms/tree/debug

Changed output. Bootstrapped it a bit and added a nice visual bar thing:

@roland-d,
Does function work as expected before we speak of style ?

Regarding styling of tooltips: Please feel free to contribute improvements. I have looked at styling them the best I could, however without any specific class for that dynamically added div at end of body by the tooltip code it looks like not possible to style them specifically to the debug module tooltips. E.g. the tooltip itself is fixed 200px max-width and can't be changed, it also has that oppacity of 0.8 that doesn't look great. The way I found to get rid of the 200px width is to CSS-float the div inside the tooltip. the very small black rectangle at top is the remaining part of the tooltip.

Also make sure to clear your cache before testing, as the debug.css file is changed by this patch and Joomla doesn't have a "?r=revisionXYZ" differenciator to make sure caches do not stay with new releases.

Also debug module executes at very of the php lifetime. Actually even after the mysql database is disconnected by the destructor of JDatabaseDriver called by PHP ending! So it is way too late to add javascript into the header. I'm also reluctant to add debug-specific Javascript to the document head or end of body too, as we want the debug ON behavior to be as near as possible from the normal one. That's also why I do EXPLAIN and SHOW PROFILE statements in a new database disconnectHandler at very end of PHP execution, to not change the execution timing and behavior of the rest of the page. I believe that for the backtrace popup, we can live with it for a few weeks/months, before the tooltip is changed from Mootools to jQuery.

@nonumber,
Thanks for the improvement, great! I will be looking at it as soon as I get a bit more time. So if needed, you have a bit more time to refine it and get feedbacks from @roland-d

Please make a pull-request towards my branch beat:mysqlprofiling so I can review diffs and merge into the existing pull-request to joomla:master.

@beat can't seem to be able to PR towards your branch :S
I see a lot of different joomla-cms branches in the pulldown, but yours ain't there...
Trying to create a PR via online edit of file on your branch, gives a 404 page after send.

PS: Can you merge your branch with latest J master? It seems to be behind a bit...

@beat: Functional wise it is good, I see all the info in tables. Just a little hard to read at the moment. I will see what I can do about the styling. I just wasn't sure if this was supposed to look like. Maybe you already added some cool styling and if I would change it, it would be useless ;)

Peter's addition looks finger licking good ;)

Maybe good to have the EXPLAIN and other stuff in sliders or tabs instead of in tooltips...
Maybe I'll play with it some more.

This looks awesome. Seems like Joomla! is finally reaching the pro league ;)
Normally good coders are not good designers, so don't worry about the styling right now - we have some good designers in our community :)

One small remark about the file links: I already implemented the "xdebug:// protocol" that is set using the php.ini., and does basically the same as the "editor:// protocol".
See: http://xdebug.org/docs/all_settings#file_link_format
This way the links are only displayed, if the user has set up his/her system to use them.
See: https://github.com/joomla/joomla-cms/blob/master/plugins/system/debug/debug.php#L866
And you will save some lines of code ;)

Another idea that came to my mind is using the logger to pass the information to the plugin (or whoever set the logger), so it doesn't have to be stored in the internal log of the database driver.
I'm playing with it right now in our JTracker thingy and it looks nice.

Also I've implemented it with tabs instead of tooltips. Seems that I'm getting old or I need some new glasses, because the tooltips are way to small

Excellent work

@elkuku : Great find, I'm fine with myide://%f@%l

@nonumber : Tabs are not loaded by default on most pages, to the contrary of tooltips, and tabs are not suitable here, as when analyzing you want to look at same time at EXPLAIN and at query, otherwise it's not understandable. I believe we can tweak a bit more the table's CSS to make it less tall (if last column doesn't wrap it would do it).

@nonumber and others with improvement proposals: Please fork my fork, then change only the files changed and do pull request towards my mysqlprofiling branch, so I can merge them.

@elkuku : The logger arrays don't eat space when not used, and when used they eat the same space. Keep in mind that there is normally only one JDatabaseDriver instance. Also the log and Disconnect handler could be useful for other applications (e.g. to make sure that session handler gets always the chance to store the session before database is closed ;-) ).

@beat It is not possible to simply fork a fork. And like stated earlier, the other methods of creating a PR towards your branch fail.

@nonumber wierd. A year back @elkuku added a pull request to my other fork here https://github.com/joomla/joomla-platform/pull/736/commits (but it was the "master" branch of the fork)... That's why I thought it was possible here too.

You can attach here a patch file as well (hm :-D no attach function here either, looks like GitHub lacks features that GitLabs (open-source!) has LOL.

You can email or skype me a patch file (my mail is my username here "at" our website). That should work :-)

Easiest to just copy/paste code from: https://github.com/nonumber/joomla-cms/blob/debug/plugins/system/debug/debug.php

Well, I believe the easiest way to do stuff like this is communication.
Git allows you to add multiple "remotes" to your local clone.
For example: @beat opened this pull request, so he is basically "the owner".
Now while this PR is open, other people could manifest in some way that they might also have to contribute something.

Example:
@nonumber

Hi @beat, I did some changes in my debug branch, have a look at 8ff8f17

(Note: the last link is written as 8ff8f177b782307330147d4de7b30f71e842bedc and automagically converted by GitHub to the correct href. See: github-flavored-markdown#references)

Now what @beat does (if he has the time and will to do so) is just adding @nonumber as a new remote to his local clone.

cd path/to/repo
git remote add nonumber git://github.com/nonumber/joomla-cms.git
git fetch nonumber

From here on @beat uses his favorite git tool to examine @nonumber's repo and do whatever he feels apropiate.
For example he wants to merge the changes from @nonumber's debug branch into his mysqprofiling branch:

cd path/to/repo
git checkout mysqlprofiling
git merge nonumber/debug

Now @beat pushes to his mysqlprofiling branch to GitHub, so his pull request will include also @nonumber's additions.

git push origin mysqlprofiling

That would be it.

(Note on the example: It might have been easier if @nonumber had added @beat's repo as a remote first, and then based his work off @beat's mysqlprofiling branch if both are working on the same "feature" ;) )

I admit that this process might seem a bit complicated and if you only have one contribution, a simple pull request would be much easier.
But if you work on some feature over some period of time, this form of collaboration is really awesome.

Of course, this implies that all persons involved in this process "have time" - not like me right now - see ya ;)

Oh - BTW..... this could be a nice example of a contribution of several persons. It would be really cool if our new tracker could reflect this in "some way", so everybody gets his/her credits. (I know that nobody cares, but yes they do..)
Any ideas ?

Another BTW: I can't send a PR to beat either. Seems like GitHub limits the list to the most active repos or something like that... that's really bad :(

@elkuku
You wrote:

One small remark about the file links: I already implemented the "xdebug:// protocol" that is set using the php.ini., and does basically the same as the "editor:// protocol".
See: http://xdebug.org/docs/all_settings#file_link_format

Did you mean by this of reading php.ini setting "xdebug.file_link_format" (how?) and then replace %f with the filename and %l with the line number in that string ?

Sure, the setting is just read with ini_get() here: debug.php#L67 in the __construct() method and stored to the $linkFormat member, so you call the formatLink() function which gives you back a link or just the plain file route if the setting is not found.

The debug plugn really needs refactoring as it is about to reach the 1k line limit ;)

I've had that issue with sending PRS to @davidhurley and @andreatarr before, it was very mysterious but eventually magically resolved..

I have sent this support request to github: http://quick-markup.com/p/51b3112230d85

Ok, I have now added contributions from @nonumber ( Thank you for the nice additions for Bootstrap styling and progress-bar idea) and from @elkuku ( Thanks for the cool links tip).

I have extended the contribution from @nonumber to have a cool bargraph of progression in time of the queries. So all is proportional.

I have also used the color-schemes for progress-bars to indicate missing indexes and expensive file sorts in addition of long queries-times, and also styled long query-times in red.

I have also re-styled a bit more using Popovers with automatic width.

I have also added a bit more red warnings in explains, e.g. when Extra indicates time-consuming "Using filesort", which can be avoided with proper indexes and are very time-consuming on larger tables.

So thanks to @nonumber's styling and the last improvements, I believe we got about as far as we can in helping optimizing database and queries without going into something much more complex...

Sorry, it needs 2 more tests before being ready to commit. But I'm sure you'll enjoy this new version.

nice to be a part of it !

@beat: please see my latest changes.
https://github.com/nonumber/joomla-cms/tree/debug
(Unfortunately I still can't make a PR towards your branch)

PS: Why the need for that link to the link config? http://xdebug.org/docs/all_settings#file_link_format

I would say, let's display some info message (including the link) if the setting is not found. So the user knows what he/she is missing ;)

That is how the info message is already working. If it doesn't find the xdebug setting, this message is shown.

ups, good to know.. thx ;)

Ok, managed to create a pull request (beat#1) by manipulating the url:
https://github.com/nonumber/joomla-cms/pull/new/beat:mysqlprofiling...nonumber:debug
As described here: http://srcmvn.com/blog/2013/03/14/sending-a-pull-request-on-github-even-when-the-base-repository-you-want-is-missing/

Very nice find. Thanks for sharing ;)

Hi @nonumber,

Great find indeed !

I have now tried your pull request and now understand the benefit of your improvements, well thought! Nothing like trying something out and the 1+1=11 of working in teams

I'm not yet done in merging but will try to finish as soon as possible the merge.

The terrible thing is that it gave me again some more ideas that I would like to try out tomorrow to make this the absolute Joomla SQL queries debugging killer tool... :-D

:) I know the feeling. This PR can grow out to be a complete rewrite of Joomla.
Joomla V, here we come ;)

I will keep my eye out for this Joomla V feature to test it further :)

@roland-d I should have a new version to pull within a couple of workhours. :)
@nonumber Thanks for your great ideas, they make it look clean . I have now merged your changes, and am now adding the V-features, but before I'm fixing the algorithm for the multiple bar graphs, because roundings for each timing sum up to not match the end of the bargraph, and thus arrow at end of barograph is pointing not at the right bar (arrow is correctly placed but not the bar: Actually this happens in Safari and not in Firefox!!!). :)

Ok, merged the pull request beat#1 from @nonumber into mysqlprofiling branch, and did some more work to make things functionally smoother:

Switched to accordions for Explain and call stacks, added helpful tooltips for EXPLAIN warning conditions, dimmed bars of other queries in bargraphs (except for first bargraph so it's well visible) and added TODO FIXME statements for Safari/Opera and IE browsers:
http://ejohn.org/blog/sub-pixel-problems-in-css/

I also added the forcing of html mode as reported by @roland-d on the feature tracker (thanks!).

So it's pretty good for functional testing, but ideally we should fix the FIXME for bargraphs on Safari and IE and probably Chrome too.

But I'm reaching my CSS limits here. So if one of you could find a way to make these multi-bargraphs position absolutely their bars instead of relatively, we wouldn't have that sub-pixel problem.

I believe that despite this small purely esthetic barograph issue, this last version could be marked as ready for 2tests+commit, and another pull request could be made against Joomla trunk for improving those esthetics.

@beat It looks all pretty neat now. The only real annoying issue I have is that things jump around with the accrodion. See attached screenshot. I tracked it down to the line saying:

I also noticed that, so could replicate. What's really strange is that this happens only on hover. Wondering if it is a bug in the bootstrap accordions, and if yes, if the latest bootstrap releases fixes it.

My first feeling was that maybe there is a missing clear:both; of floats somewhere, but the strange thing is that this looks like missing only on hovers.

If you have time to dig this, it would be great if you could:

• play with CSS to add a clear:both; CSS rule on the last topmost div inside the opening content of the accordion
• try upgrading to latest bootstrap javascript
• hunt deeper if none of the above works.
• there is still the minor issue in Safari (+IE+Chrome) on the bars widths roundings and the issue that bars don't have a minimum width, and that some are are rounded down to width 0, thus invisible, and we are loosing the bar and its significant color.

My time is running out on this for the next weeks, and I figured out that despite the small quirks, it's still much better than without it, so that's why i decided to push it into this pull request.

Fixed + other changes :)
beat#2

@nonumber Well done!

(repeating the comment hidden in '...' of the merge just above:

Actually if you feel like doing it, you could apply the same kind of bargraphs to the PHP+Memory+Total SQL queries time total in there in the profiling section. That way it would be immediately visible if a badly written small module kills a site's performance, as that is not visible without deep understanding in the SQL area. Even more, with correlating the PHP profiling utime-timestamps with the SQL queries ones, the PHP section could be spitting out really useful information. ;)

But it can be done in a separate pull request to Joomla from you as well. I don't have to be in your way ;)

The only left very minor known issue here is the bargraph filling exactly 100.0% of the width of the bargraph area only in Firefox (a bit less in Safari/Chrome and a bit more in IE-incl.latest), making the arrow not showing precisely the last queries in those browsers. We can perfectly live with that very minor known issue.

I'm thus still considering this as ready-to-2tests-and-commit.

I'll look into the arrow alignment thing asap...

It is looking awesome

Now I do have a feature request which may or may not suit here. If it would be possible to click on the bargraph on a colored section and then jump to that query. This makes it easier to find the offending query faster :)

Not sure if this is by design but the first bargraph is full color as where the subsequent ones are greyed out except for the part where the query is on the bargraph. I was just wondering if the first bargraph should alsy be greyed out. Either way it is fine by me.

@nonumber great! only way I see is with positioning of each bar relatively to left, using position or maybe z-index (not a CSS expert lol).
@roland-d

• First bargraph is not greyed on purpose to have an overview.
• And also to indicate that it's clickable ;) (I had that in mind using small anchors, it's easy to do, you could provide a pull request to this pull request for this)

@beat I figured that the first bargraph is not greyed out to make it readable :) I am going to give it a shot to make them clickable. Please bear with me ;)

That PR is a nightmare, it gives me 175 changed files and 56 commits :-S Sometimes I really just wan to kick git to the curb.

So how to get the changes your way?

@roland-d Just to prevent double work: It's probably best to leave the linking thing for me, as I am changing the way the bar is rendered (codewise) to fix some css issues, make it more stable and a more lightweight on rendering.

@nonumber The work was already done but go ahead. I won't touch anything anymore.

Tadaaa: beat#3

See live demo: http://ndev.nl/debug

@nonumber Just seen demo, looks awesome!

Commenting on the pull request.

It's getting better and better.
The live demo looks awesome.
What do you think if we include the query itself also in a slider ? that would make things more compact ;)

I think the actual query is something you always want to see. As that is what you are inspecting. So when viewing the Explain or Profile Info, you still want to see the specific query to see what it refers to and see if you can spot why the info in there is like it is.
So I don't really see it as a useful/necessary thing to be able to hide the query.

I agree with @nonumber :) : Queries should always stay visible.

correct, bad idea. :(

Ok, I've now merged after review this new version and many improvements suggestions that @nonumber implemented brilliantly (Thank you)

I'm now declaring this pull request feature-complete and tested by its authors.
Si we are now doing a features-freeze on this pull request. ;-)

Warning: It has become a powerful tool to show that a page is slow-loading and to help pinpoint reasons for slow-loading pages :D

So we are ready for final testing at tracker, so that it can be committed.

Tested and commented on the tracker. All looks great :)

Updated branch (merged from latest joomla-cms/master), solving trivial conflicts (a variable has been renamed in some of the drivers in joomla-cms/master).

The $sql to $query? :) That was my doing in a global database cleanup PR: #856

Ok, as language tests had failed and new tests are required, I fixed those, and also added a handy display of size of database query result in memory and rows for each query. :-)

Ready for final tests and review.

I believe that for PRs like this one, it would be nice if actually all commits would be included when merging. But well, it has been merged