Loading ...
Sorry, an error occurred while loading the content.

Declarative Logging (PED)

Expand Messages
  • MarvinToll.com
    A recent post on the TDD site triggered the recollection that the following has not previously been shared with this group. As part of our Pattern Enabled
    Message 1 of 9 , May 21, 2011
    View Source
    • 0 Attachment
      A recent post on the TDD site triggered the recollection that the following has not previously been shared with this group.

      As part of our 'Pattern Enabled Development' approach we have a strategy called "Declarative Logging". Said another way, we have found the notion of level-based logging to be inadequate. Here is an example from the SOAP Web Services space currently configured for the development environment:

      <!-- Declarative Logging - Log statements are on (true) or off (false).
      Success messages are normally activated (true) during development only.
      -->
      <property-group name="DeclarativeLogging">
      <property name="logProviderRequestReceived">true</property>
      <property name="logProviderSuccessInboundMessage">true</property>
      <property name="logProviderSuccessOutboundMessage">true</property>
      <property name="logProviderFailedInboundMessage">true</property>
      <property name="logProviderFailedOutboundMessage">true</property>
      <property name="logProviderDurationsSummary">true</property>
      <property name="logConsumerMessageSent">true</property>
      <property name="logConsumerSuccessOutboundMessage">true</property>
      <property name="logConsumerSuccessInboundMessage">true</property>
      <property name="logConsumerFailedOutboundMessage">true</property>
      <property name="logConsumerFailedInboundMessage">true</property>
      <property name="logConsumerDurationSummary">true</property>
      </property-group>

      "Declarative Logging" is often used to expose processing occuring within frameworks... to offset the objection that abstraction limits visibility. Here is an example from our wrapper around Struts:

      <property-group name="DeclarativeLogging">
      <property name="requestReceived">true</property>
      <property name="requestLifecycle">true</property>
      </property-group>

      ...Here is an example of the type of logging available during development:

      << StrutsCore v. 1.1; Method=POST; URI=/JCOEAdventureBuilderStrutsWeb/authenticatePost.do; Reentrant #=1; RequestContext(UserId=[mtoll2] RequestId=[204567297] SessionId=[pJWWdAv3YW6EtTgdw8sbnam] ContextId=[7]) >>

      StrutsCore ==> Lifecycle phase [ProcessMapping] - ActionConfig[cancellable=false,path=/authenticatePost,validate=false,name=authenticationForm,parameter=method,scope=session,type=com.ford.jcoe.jab.action.authenticate.AuthenticatePostAction |RequestContext(UserId=[mtoll2] RequestId=[204567297] SessionId=[pJWWdAv3YW6EtTgdw8sbnam] ContextId=[7])|

      StrutsCore ==> Lifecycle phase [ProcessAuthorization] - Note: This request is *not* declared for authorization. |RequestContext(UserId=[mtoll2] RequestId=[204567297] SessionId=[pJWWdAv3YW6EtTgdw8sbnam] ContextId=[7])|

      StrutsCore ==> Lifecycle phase [ProcessActionForm] - The form [com.ford.jcoe.jab.formbean.AuthenticationForm] was retrieved. |RequestContext(UserId=[mtoll2] RequestId=[204567297] SessionId=[pJWWdAv3YW6EtTgdw8sbnam] ContextId=[7])|

      StrutsCore ==> Lifecycle phase [ProcessActionPerform] - The resource value [Enter As Agent] resolved to an action method [navigateAsAgent]. |RequestContext(UserId=[mtoll2] RequestId=[204567297] SessionId=[pJWWdAv3YW6EtTgdw8sbnam] ContextId=[7])|


      So, you might legitimately ask, "What's the connection with XP?"

      What has emerged is that declarative logging not only provides granular control in production - which was the original intent - it has provided the positive side effect of being useful in a development unit testing context.

      In other words, as we began thinking in 'sets of log statements' (rather than levels) we have explored how the strategy can compensate for that major objection in using advanced frameworks that perform tasks historically coded in an application... that is, they work great when everything works but I'm not always clear what the framework is doing 'under the covers' when something breaks.

      I'm curious... has anyone else been this deliberate in using this technique? Have you been advantaged during unit testing?

      _Marvin
      http://PatternEnabled.com
    • Adam Sroka
      ... Right. You stated the objection pretty well. I think that most of us who have encountered that situation (don t know what the framework is doing, which
      Message 2 of 9 , May 21, 2011
      View Source
      • 0 Attachment
        On Sat, May 21, 2011 at 7:09 AM, MarvinToll.com <MarvinToll@...> wrote:
        >
        >
        > In other words, as we began thinking in 'sets of log statements' (rather than levels) we have explored how the strategy can compensate for that major objection in using advanced frameworks that perform tasks historically coded in an application... that is, they work great when everything works but I'm not always clear what the framework is doing 'under the covers' when something breaks.
        >

        Right. You stated the objection pretty well. I think that most of us
        who have encountered that situation (don't know what the framework is
        doing, which suddenly becomes an issue when something doesn't work)
        have used logging to try to understand it. In my experience it is a
        bit like putting a bandaid on an amputated limb. It does help, but
        it's not a good long term solution.

        Logging is superficially similar to, and often serves as a substitute
        (albeit a poor one) to unit testing.

        The thread on the TDD list was talking about something different. It
        was talking about how to use TDD to implement logging as a feature.
        Logging as a feature implies that the customer wants the log for some
        purpose. Often when you understand what that purpose is you can
        discover that logging isn't the best way to achieve it either.

        (Because the customer wants to be notified of something, but the
        customer probably doesn't want to be notified of *everything* ...not
        really. In fact, too much info in the log -- and there is always too
        much info in logs -- probably makes finding the thing they are looking
        for much harder than it needs to be. They just don't know how to ask
        for exactly what they want.)
      • MarvinToll.com
        The distinction I m drawing is between a reactive use of logging... in contrast to a deliberate and systemic design goal of exposing the thread-of-execution
        Message 3 of 9 , May 21, 2011
        View Source
        • 0 Attachment
          The distinction I'm drawing is between a reactive use of logging... in contrast to a deliberate and systemic design goal of exposing the thread-of-execution functions in a manner that does not require reactive logging --- or use of the debugger --- as a 'first-course' of action when going from red to green.

          Said another way, the need for a band-aid when using a higher-order framework is an indication of a design difficency.

          Many of us have presumed that the deficiency could not be resolved --- therefore higher-order frameworks are a bad idea.

          I'm seeking out those that have discovered how (or attempted) to solve the objection that higher-order frameworks 'get in the way' when something goes wrong.

          _Marvin
          PatternEnabled.com

          --- In extremeprogramming@yahoogroups.com, Adam Sroka <adam.sroka@...> wrote:
          >
          > Right. You stated the objection pretty well. I think that most of us
          > who have encountered that situation (don't know what the framework is
          > doing, which suddenly becomes an issue when something doesn't work)
          > have used logging to try to understand it. In my experience it is a
          > bit like putting a bandaid on an amputated limb. It does help, but
          > it's not a good long term solution.
          >
        • JeffGrigg
          ... I think you re using red to green in a different sense than would be meant by most Test-Driven Development practitioners. Assuming that you mean what
          Message 4 of 9 , May 21, 2011
          View Source
          • 0 Attachment
            --- "MarvinToll.com" <MarvinToll@...> wrote:
            > The distinction I'm drawing is between a reactive use of
            > logging... in contrast to a deliberate and systemic design
            > goal of exposing the thread-of-execution functions in a
            > manner that does not require reactive logging --- or use
            > of the debugger --- as a 'first-course' of action when
            > going from red to green.

            I think you're using "red to green" in a different sense than would be meant by most Test-Driven Development practitioners.

            Assuming that you mean "what tools should you use when the framework code that your application code uses does not seem to be working right"...

            Adjusting logging levels (by category or whatever) is probably one of the last things I'd try. A well-designed framework will report problems with exceptions. It can make sense to log detailed error information instead of putting it on the GUI -- especially a public-facing GUI. (Want to talk about security risks?) Most problems should be visible with error messages.

            I have adjusted logging levels in order to monitor communication with other systems. I think that the need to do this might be a symptom of inadequate tooling for monitoring.
          • MarvinToll.com
            The notion of Declarative Logging asserts that a well-designed framework must do more than report problems with exceptions. Or said another way, simply
            Message 5 of 9 , May 22, 2011
            View Source
            • 0 Attachment
              The notion of "Declarative Logging" asserts that a well-designed framework must do more than report problems with exceptions. Or said another way, simply reporting problems with exceptions is a 30-year old paradigm that has limited the effectiveness of higher-order frameworks.

              A well-designed higher-order framework exposes a functional perspective to the developer during unit test creation. It anticipates the information desired (80/20 rule) without the verbosity of trace logging.

              This discussion is causing me to realize a different label for this capability is warranted:

              * Framework Functional Visibility
              * Functional Logging
              * Functional Declarative Logging
              * Visibility Logging
              * TDD Visibility Logging
              * Framework Functional Logging


              _Marvin
              PatternEnabled.com

              --- In extremeprogramming@yahoogroups.com, "JeffGrigg" <jeffreytoddgrigg@...> wrote:
              >
              A well-designed framework will report problems with exceptions.
            • Ron Jeffries
              Hello, MarvinToll.com. On Saturday, May 21, 2011, at 10:09:57 AM, ... I m not seeing how this is different from any other logging. Let s see if I understand
              Message 6 of 9 , May 22, 2011
              View Source
              • 0 Attachment
                Hello, MarvinToll.com. On Saturday, May 21, 2011, at 10:09:57 AM,
                you wrote:

                > In other words, as we began thinking in 'sets of log statements'
                > (rather than levels) we have explored how the strategy can
                > compensate for that major objection in using advanced frameworks
                > that perform tasks historically coded in an application... that
                > is, they work great when everything works but I'm not always clear
                > what the framework is doing 'under the covers' when something breaks.

                > I'm curious... has anyone else been this deliberate in using this
                > technique? Have you been advantaged during unit testing?

                I'm not seeing how this is different from any other logging. Let's
                see if I understand the idea:

                There are various named sets of information that can be logged.

                Any of these sets can be turned on or off separately.

                I would imagine that this would be implemented by a set of (more or
                less) globally accessible logging flags, named by set name, and the
                code would be strewn with logging statements, each checking the
                appropriate set-name flag.

                Is that the case? Is there something else?

                Ron Jeffries
                www.XProgramming.com
                If another does not intend offense, it is wrong for me to seek it;
                if another does indeed intend offense, it is foolish for me to permit it.
                -- Kelly Easterley
              • MarvinToll.com
                Thanks for asking Is there something else to Framework Declarative Logging. a. If one studies the two examples provided an appreciation for the limited and
                Message 7 of 9 , May 23, 2011
                View Source
                • 0 Attachment
                  Thanks for asking "Is there something else" to Framework Declarative Logging.

                  a. If one studies the two examples provided an appreciation for the limited and targetted type of information provided that is useful when implementing unit tests. This avoids "strewing" framework code with log statements - or having the console output strewn with the type of verbosity that occurs when trying to set log levels that are effective across multiple technologies.

                  b. An unanticipated positive side effect has occurred. Our Global Java Community has a discussion board. We probably average at least 20 posts a day (many of which come from newer employees/contractors) that could be characterized as 'trouble-shooting'. Generally, if someone attaches their unit test and the console log with Framework Declarative Logging active there is a very good chance that someone in the community can quickly identitfy or postulate a solution. Since there is a consistent set of output across and within Frameworks the community gets accustomed to quick discernment. We continually mature the sets of declarative log statements so that they provide the key insight useful for writing unit tests.

                  _Marvin
                  PatternEnabled.com

                  --- In extremeprogramming@yahoogroups.com, Ron Jeffries <ronjeffries@...> wrote:
                  >
                  > Hello, MarvinToll.com. On Saturday, May 21, 2011, at 10:09:57 AM,
                  > you wrote:
                  >
                  > > In other words, as we began thinking in 'sets of log statements'
                  > > (rather than levels) we have explored how the strategy can
                  > > compensate for that major objection in using advanced frameworks
                  > > that perform tasks historically coded in an application... that
                  > > is, they work great when everything works but I'm not always clear
                  > > what the framework is doing 'under the covers' when something breaks.
                  >
                  > > I'm curious... has anyone else been this deliberate in using this
                  > > technique? Have you been advantaged during unit testing?
                  >
                  > I'm not seeing how this is different from any other logging. Let's
                  > see if I understand the idea:
                  >
                  > There are various named sets of information that can be logged.
                  >
                  > Any of these sets can be turned on or off separately.
                  >
                  > I would imagine that this would be implemented by a set of (more or
                  > less) globally accessible logging flags, named by set name, and the
                  > code would be strewn with logging statements, each checking the
                  > appropriate set-name flag.
                  >
                  > Is that the case? Is there something else?
                  >
                  > Ron Jeffries
                  > www.XProgramming.com
                  > If another does not intend offense, it is wrong for me to seek it;
                  > if another does indeed intend offense, it is foolish for me to permit it.
                  > -- Kelly Easterley
                  >
                • JeffGrigg
                  ... I have reexamined your original post, which I assume contains the two examples you mention above:
                  Message 8 of 9 , May 24, 2011
                  View Source
                  • 0 Attachment
                    --- "MarvinToll.com" <MarvinToll@...> wrote:
                    > Thanks for asking "Is there something else" to Framework
                    > Declarative Logging.
                    >
                    > a. If one studies the two examples provided an appreciation for
                    > the limited and targetted type of information provided that
                    > is useful when implementing unit tests. This avoids
                    > "strewing" framework code with log statements - or having the
                    > console output strewn with the type of verbosity that occurs
                    > when trying to set log levels that are effective across
                    > multiple technologies.

                    I have reexamined your original post, which I assume contains the two examples you mention above:
                    http://tech.groups.yahoo.com/group/extremeprogramming/message/156566

                    However, I would assert that achieving this would require log statements (calls) in a number of places in the framework code. (Or strong AOP with tight coupling to the framework code's low level implementation details.) So I would side with Ron on that point.

                    I do agree with you about your claim that your logging approach will avoid cluttering the console (or log files) with unwanted extraneous detail, while enabling extreme detail where wanted. But it still appears to me that this is a solution to the problem that your people don't really know how to use the existing logging frameworks properly. The most common logging frameworks already offer all of this functionality and more -- but only if you know how to configure and operate them effectively.



                    > b. ... Generally, if someone attaches their unit test and the
                    > console log with Framework Declarative Logging active there
                    > is a very good chance that someone in the community can
                    > quickly identify or postulate a solution.

                    Yes. I would kind of expect that, at a minimum. That's how things work now out on the message boards with most frameworks and libraries now.


                    > Since there is a consistent set of output across and within
                    > Frameworks the community gets accustomed to quick discernment.
                    > We continually mature the sets of declarative log statements
                    > so that they provide the key insight useful for writing unit
                    > tests.

                    I see the above as evidence that you have good and useful corporate standards and norms, and that you're doing an effective job of responding to feedback and improving the usefulness of the libraries over time.

                    But...
                  • JeffGrigg
                    ... When I try to imagine how this could help with TDD, I run into some problems: First, a well-done library to be used by others should have effective
                    Message 9 of 9 , May 24, 2011
                    View Source
                    • 0 Attachment
                      > --- "MarvinToll.com" <MarvinToll@> wrote:
                      >> Since there is a consistent set of output across and within
                      >> Frameworks the community gets accustomed to quick discernment.
                      >> We continually mature the sets of declarative log statements
                      >> so that they provide the key insight useful for writing unit
                      >> tests.

                      --- "JeffGrigg" <jeffreytoddgrigg@...> wrote:
                      > I see the above as evidence that you have good and useful
                      > corporate standards and norms, and that you're doing an
                      > effective job of responding to feedback and improving the
                      > usefulness of the libraries over time.
                      >
                      > But...

                      When I try to imagine how this could help with TDD, I run into some problems:

                      First, a well-done library to be used by others should have effective documentation (probably including examples). It should be easy to figure out how to correctly use the library without having to run tests through it to find out how it really works. If a person has a problem using your library, and you can tell them how to correct their usage so that it works, but you can NOT point to published documentation or examples that show (the essence of) your correction, then your library is inadequately documented for 3rd party use.

                      Second, if logging the parameters enables an expert to tell a beginner that the mysterious failure of the framework as caused by passing in an invalid set of parameter values, then I have to ask why the framework code did not throw an exception with a useful error message telling what combination of parameters is invalid.

                      If the frameworks are failing in "mysterious" (to the new users) ways, given usage informed by documentation and examples, then I would suspect design problems in the frameworks, rather than a need for more logging and debugging tools.
                    Your message has been successfully submitted and would be delivered to recipients shortly.