May 21, 2012

Planning

Two weeks ago I had a long chat with my mentor about the project. For the rest of the week I was busy with university, so I did not work much on my project in that time. This week we just had a short call.

Some more requirements

In our chat we came across some requirements that I had not taken into account before:
  1. Debugging and logging should happen around streams. Each module can either write to an existing stream or start a new one. This way, a developer can pick and choose the level of debugging info he wants to receive.
  2. Log Streams are loosely coupled to modules by a naming convention: sapphire_sql.
  3. The developer needs to be able to choose what he is interested in. For that, there needs to be a list of all available streams. Therefore, any module (including the sapphire framework code itself) that can publish debug streams needs a way to say "I generate this, this and this". It should be able to tell the logging framework what streams they generate. Setup could be a matter of classes implementing an interface, or calling a method to register the stream.
  4. Performance: When debugging is disabled, we should cause only a low overhead . The modules need to be aware of what streams of debugging they should be producing. Sometimes it is expensive for modules to generate and collect the debugging information, so they shouldn't do anything if nobody wants to look at the result. Something like: if(Debug::streamEnabled($streamID)) Debug::log(blah);
  5. Debugging info can be generated in the framework before the framework is set up. e.g. before there is a DB connection. So the mechanism should not be at too high a level of abstraction. Early parts of the request have to be able to generate debugging info too, in case the developer has enabled the streams.
  6. The dashboard controller could record the debug events in the session, and maybe keep the last n requests there. That way, the developer dashboard could show details across multiple requests.
  7. Easy way to print out debugging information. It should be as simple as calling Debug::show().
  8. Filtering / sorting into tabs probably has to be done client side, because a interleaved display is also possible (i.e. output from all streams, sorted by time).

Structure

Starting from these requirements, the logging framework breaks down into three components:
  1. Registering a capability to generate debugging events.
  2. Capturing those debugging events while a request is processing.
  3. Forwarding them to the dashboard and displaying them.
The first part is setup; it happens when the developer turns debugging on. The second part is gathering information during the request and the third part is presentation.

For information gathering we need to come up with a way of representing objects that should be logged. The logger should be context aware and support both HTML and command line output. The functions that call the logger should not include HTML output.

Workflow

  1. The developer selects a control somewhere to turn on the dashboard
  2. The dashboard has a list of debugging streams to choose from.
  3. The dashboard saves the developer's preferences to his session.
  4. During the processing of the next requests (could be a normal page view or via AJAX), code on the execution path writes to it's debug stream (in case the stream is enabled).
  5. The dashboard controller sends the event data to the dashboard.
  6. the dashboard displays that event data in an organized way.
The HTML of the dashboard is sent along inside any page that is requested. It offers a link to detach it into a separate window (it opens inside a new window after clicking a certain link). The attached version just displays the current request (it may also include past requests). The detached window uses AJAX polling (or websockets as an optional feature) to display new log messages.

Setup

We discussed two versions how the setup could work:
  • The code that wants to have something logged can just say "put this text there" and the logging code sorts out the rest - Much like you currently add fields to the CMS back end
  • Modules generate data streams.
The second version would make it possible to add a flexible mapping of streams (stream identifiers) to targets. However, I am not completely convinced that this is necessary. It also allows to move on from passing strings to passing message objects.
In the initial implementation, the dashboard will use the stream identifier as the tab name. If needed, we could extend it later by separating the tab concept out from the stream identifier.

Timeline

Not all things that are discussed here might end up in the project. Nevertheless, this blog is a first step to documented them as future enhancements.

Before Midterm

In the first two weeks I will work on a proof of concept (POC) implementation. It consist of an implementation of the log writer including the log() support method and a simple front end with no fancy bits. It writes the event data to a simple list in session. This will include some basic AJAX capability. Furthermore, I want to complete ticket 2644. Therefore, I will write a global error handler and provide event streams for exceptions and user errors.
At the midterm goal I will have completed the POC, fleshed out the server side debugging capabilities, and a basic interaction with the front end working. This includes a view to display some of the current debugging options in the new dashboard and an expanded ajax handler to provide this additional data to the dashboard.

After Midterm

After the midterm I will be away for a week, so I only have three weeks. In the second part, I will flesh out the UI of the dashboard itself. This consist of:
  • organization of events by tab,
  • an option to view the events sequentially (i.e. information from all tabs combined, ordered by time),
  • ability to expand and collapse different parts to control the level of detail,
  • ability for the developer to select the streams they want to have generated and displayed (client side UI) and
  • server side preference storage - number of requests to store, which streams should be generated, etc.
My mentor advised me to reserve a lot of time for this part. Until now we did not focus on the UI a lot, so we might run into unexpected problems. I plan to write tests during all parts of the
  • May 21st - June 3rd: Proof of Concept Implementation
  • June 4th - June 17th: Server Side debugging: Reorganize the way debugging is done.
  • June 18th - July 1st: Front End Interaction, include existing urlvariabletools in dashboard
  • July 2nd - July 13th: Finish leftovers from previous tasks, start working on frontend UI
  • July 13th: Mid term
  • July 15th-July 21st: Not working on GSOC
  • July 22nd-August 5th: Work on frontend UI
  • August 6th-August 9th: Cleanup
  • August 9th: Pencils down
  • August 10th-August 19th: Not working on GSOC

May 7, 2012

Additional Requirements

In the last post I did not include everything that was covered by my initial proposal and the discussion on the mailing list.

Context Awareness

In ticket 5768 context awareness is brought up. Some parts of SilverStripe can be run from the command line. The logging/debugging functionality should be aware of this, i.e. no html output in command line mode. This fits well with my idea that the all code that is concerned with formatting / output should be in a central place, either in the logging class or somewhere else

Debugging Fatal Errors

Sometimes we will need to debug fatal errors. Since we cannot send any output after the error occurred, we will need to bypass any caching that we do and dump messages as soon as they come in.

Author Toolbar

This feature is not included in the default blackcandy theme and therefore probably not well known (at least I never heard about it before this project). I should check if any things that I introduce for the developer dashboard can be applied to this toolbar as well.

Additional Features

  • Debugging/Displaying the generated YAML configuration
  • other things

Optional Stuff

FirePHP integration and anything else we come up with if I finish early and get bored.

May 4, 2012

Rough Ideas

On April 25th I had a first chat with my mentor. First, we got to know each other a bit. We then started to talk about the project. We agreed that I will post the results of our weekly meetings on this blog.

My next steps are to
  1. get familiar with git,
  2. start working with my fork of the sapphire framework and
  3. flesh out my project plan in more detail.
In this post, I will summarize my current understanding of the things I talked about with my mentor in our first chat.

In my original proposal I talked about a toolbar. This term is usually used for one or more rows of icons, but my toolbar will also contain other information, such as debug output. Therefore, I will talk about a dashboard instead. This dashboard contains several tabs, any tab can be a toolbar (in the conventional sense).

Debugging vs. logging

In the context of my project "debugging" will be short for "displaying debug information". Of course there is much more to debugging (like the ability to set breakpoints, inspect variables and to step through code, etc.), but this is excluded from the project. Logging is a more general form of displaying debug information, I will therefore treat debugging as a special type of logging.

Debugging is mostly concerned with what happens within one request. The data is usually displayed but not kept around. Logging is used to check for things that change between different requests. Debugging will therefore be concerned with things like displaying the values of variables, checking if a statement is reached ("I'm here") and viewing the generated SQL statements.

Logging is more about aggregating information from multiple requests to check if everything works, and what changes in a case that triggers a bug.

Role within SilverStripe

The project will touch several parts of sapphire (the SilverStripe framework). I will unify and improve upon the existing logging functionalities.

Front End

The front end part is the "developer dashboard". When a site is in development mode and an administrator is logged on, a button is displayed on the front end. If the admin clicks on this button, the dashboard opens. It contains tabs that display information, such as the output of debug statements, the contents of $_GET and $_POST and SQL queries. It also contains an easily way to access the urlvariabletools. This might be in form of a toolbar, i.e. a list of icons.

Some of the content and settings will have to be persisted in some way, to be available across different requests. This could be done in a log file or in the user session.

When dumping objects, it would be very nice to be able to
  • expand and collapse branches and to
  • explore their relations.
An open question is how to debug AJAX requests. One way of doing this would be to open a separate browser window that automatically refreshes to display lines added to the log, similar to the tail -f command in UNIX.

Grouping Information

In most cases, we would want to group information by type. All SQL statements are on the "SQL" tab, debug output is on the "Debug" tab, etc.
In some cases, however, it would be useful to have all information in one place. This would make it easier to see which value of a variable results in which SQL statement. I am not sure how well this fits with the way I imagine the toolbar to work.

Back End

The project basically breaks up into two parts. The first is responsible for collecting and displaying information for logging and debugging. The second part is the infrastructure that allows modules to add information to the developer dashboard.

Logging

One aim of this project is to unify the existing logging functionality, which is spread around SS_Log, Debug as well as many other places. Like the existing logging system, this will be based on Zend_Log.

One question is how feasible it is to generalize debugging/logging of objects. Dumping should be relatively straightforward, but in many cases it would be interesting to display only the relevant parts of an object's state. Usually only the object itself knows which information is most relevant in the current context.

Logging is possible on various levels (e.g. warn, info, debug), and the developer is able to configure the required level of detail on a per module basis, e.g. LoggerClass::setLogLevel('MyModule', LoggerClass::LEVEL_DEBUG).
So far I haven't had a look at the new way configuration is done in SS3, so the way that this works might be actually a little different. Regardless of the way configuration is done, a developer will be able to specify which type of information he is currently interested in.

Dashboard

The dashboard should in principle be agnostic of the rest of the logging functionality. It is a thing that displays information. Any module can display information on this dashboard. The urlvariabletools could add icons to a toolbar. The database driver could add the SQL tab. A custom module could add another tab.

Therefore, we need an API that allows modules to add tabs and content to the dashboard.

In between

Some things are needed in between these two parts. I currently think about:
  • A way to register URL parameters. Per module this can be done in the controller, but I don't know how "global" URL paramters, like isDev are currently handled.
  • A way to persist settings in the user session. Some of the global settings should be persisted. This way, a developer can navigate the site without having to apply a certain parameter to every URL.
  • Some general code to dump an object.
  • And probably many other things I overlooked.

Personal Notes

I am still trying to grasp the whole project, to come up with a list of the features that are needed and how they relate to the existing framework. It is quite difficult for me to turn the high level ideas into "bullet points", i.e. break them up into tasks and milestones.
For me, the front end features are much more tangible. Therefore, they are much easier to think and talk about. The back end components are much more vague.

About this blog

My proposal for this year's (2012) Google Summer of Code (GSoC) has been accepted, and I am looking forward to working with my mentor for the SilverStripe CMS. I will be working on tools that support SilverStripe developers. The proposal that I submitted can be found on Google melange and on the SilverStripe GSoC Wiki.

I will use this blog to share my experiences during the GSoC.