Centralise debug logging

[GoogleCodeExporter]

Currently, setting $debug=true creates a series of 'SQL' tags around the page, 
which show more information on click, via javascript. The code to create these 
messages is repeated here and there, mainly in the Database class.

I would like to:
- collect the output code in separate module
- collect the output itself in a continuous log, easier to scan and copy+paste 
for error reporting
- remove the many occurences of "global $debug;" in the Database class

Attached below are:
- my idea of a Log class, which stores messages and produces a formatted log
- a screenshot of the code in action

Using this class requires minimal changes to the main code: adding 

  if ($debug) Log::start();

at the beginning and

  if ($debug) Log::output();

at the end. Existing debug output can be replaced with either

  Log::info(...)    adds a basic message
  Log::error(...)   adds a message highlited in red
  Log::query(...)   adds a query highlited in blue, using a monospace font
  Log::dump(...)    dumps the content of a variable in the log

I tried to keep the code very light, but we can reduce wasted cycles further 
guarding the calls using

  if (Log::$enabled) Log::error(...);

or

  Log::$enabled  and  Log::error(...);

The code below also logs 'catchable' PHP errors, but does not produce output in 
case of a FATAL error. I can work around that using 
register_shutdown_function(), I'm just not sure if we want that or not.

Original issue reported on code.google.com by dreadnaut on 13 May 2014 at 4:43

Attachments:

• Log.php
• debug-log.png

[GoogleCodeExporter]

In general a good idea in the right direction.

What I think is the main problem here: With the log being collected and echoed 
later, it is difficult to see _where_ the log was produced. I mean SQL 
statements in the end all are logged by the query() method, but that's not what 
I want to know. I want to know where in the code the original call comes from.
With the SQL statement being echoed directly, I can easily see (guess) this. 
I'm not saying this is the clean way to do this. I am just saying that your 
suggestion makes debugging a little more difficult (at least for me :D) than 
what we currently have.

But we can fix this: We can send the current position in the code to the Log 
Class at all important points:
Log->position('Delete an existing database');
In the end this would be at the top of every method, currently it would be 
spread all around index.php (where the "//-" comments are, I guess).
What do you think?

Another idea: Why not collecting Debug messages and other messages like errors, 
warnings and so on in the same place? It is more or less a matter of the level. 
There is not really a big difference between debug and normal messages. A Debug 
message could be a message like others, only normally not being echoed.

Original comment by crazy4ch...@gmail.com on 13 May 2014 at 7:05

[GoogleCodeExporter]

> With the log being collected and echoed later, it is difficult to see _where_
> the log was produced.

I'm getting the filename:line information form the stack trace, so I could skip 
the first level (Database->query) and show the second (the original caller). Or 
show both, for clarity.

If you want additional 'locations', we just need to add some calls to 

  Log::info('Delete an existing database')

which will make the debug log nice and structured.

About collecting everything together: uhmmmm... it could work, or it could be a 
very messy solution :) It definitely works for console programs for example, 
where there is a single flow of output. But we want important messages to 
appear near the top of the page, while the debug log should be out of the way, 
maybe even collapsed by default. Also, result/warning messages would be more 
complex than a single line, language dependent, etc.

Original comment by dreadnaut on 13 May 2014 at 7:30

• Changed state: Started

[GoogleCodeExporter]

Here's a screenshot of the revised log, showing the full call stack for each 
entry, and showing the four formats: query, info, error and dump.

Original comment by dreadnaut on 19 May 2014 at 4:28

Attachments:

• debug-log.png

[GoogleCodeExporter]

I like it. Go for it. Sorry for the late reply.

Original comment by crazy4ch...@gmail.com on 22 May 2014 at 8:06

[GoogleCodeExporter]

Here's a first patch then, with the following changes:
a) added a Log class;
b) initialize and output the Log in index.php;
c) replace output guarded by $debug with Log lines;
d) added css for the debug log.

A lot of debug output comes from alterTable(), could you double check my 
changes in that function?

Regarding (d), the new build system introduced css and js minification, so we 
can be more generous with comments and whitespace in new code :)

Original comment by dreadnaut on 26 May 2014 at 5:05

Attachments:

• debug-log.patch