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

2 comments:

  1. Hey Jakob, there's a lot of highlevel talk about streams/writers etc. - I just want to make sure we're still basing this work off Zend_Log, right? It already has the concept of loggers listening to various error levels etc, plus different writers for different contexts like HTML vs. CLI.

    By the way, the Zend_Log::log() method also allows to pass in extra data as as simple map, which is available to all formatters.

    ReplyDelete
  2. Yes, it's still based on Zend_Log.

    ReplyDelete