Re: [jira] Updated: (QPID-2835) Implement connections (CON) operational logging on 0-10

Tue, 07 Sep 2010 23:30:46 -0700 

Hi.
The way I see this is that the logging is currently too fragmented and still manages to be quite tightly coupled to the model objects, via the LogSubjects. Unless we had a generic subject that could produce an identifier for anything it was presented with, this will always be the case. 

To recap, what is being proposed is something like this:


Model object x performs action 'a', which is logged. The logging uses  
a LogActor, which is passed a reference to a model object 'x' which  
knows how to output an identifying bit of text. This 'x' object's log  
message also references object 'y' and in turn that references 'z'.  
The model objects 'x' and 'a' may be the same, or different, and in  
fact, *both* could be passed t the actor. The message itself that is  
logged will be generated by a LogMessage object.


The log message looks something like this:

        MSG-<id> [x-info/y-info/z-info] action : properties...


The responsibility for *generating* the 'action' message (itself  
defined by a property file) lies with the model object that performed  
the action, with the 'properties' being obtained from that same  
object as it is performing the action. The subject of the message  
(between the square brackets) is formed from the output of the  
'getLogSubject' method of the model object. This will often refer to  
the log subject text of other model objects, so the 'x' object  
outputs 'x-info' followed by the result of the log subject for the  
'y' object, which in turn asks the 'z' object for its log subject text.



This gives us the ability to, say, change the way a virtual host is  
represented in the logs, by modifying the 'getLogSubject()' method of  
the virtual host object - all other logging will use this output and  
no other changes are needed. This would also be the canonical  
location for subject formats, such as 'vh(\{0\})' for the virtual  
host. This does lead to the situation where, for instance 0-8/0-9  
connections and 0-10 connections (which are disparate model objects),  
will have separate formats, due to the differences in make-up,  
although the output may be identical.



This produces the detailed subject message shown, and delegates  
responsibility to the only objects that *can* know how to represent  
themselves in a log file, the model objects.



The only objects that need to look at a model object's internal state  
are the model objects themselves, in their role as LogSubject. The  
only objects that interact with the actual logging system are the  
LogActors. The LogMessages represent the action being logged, and are  
passed, with a suitable set of LogSubjects to the LogActor, which has  
the responsibility of collating them into a String for output. Note  
that the LogSubject is free to do pre-processing on the String  
representation it returns, or perform cacheing to increase  
performance, but this in no way breaks encapsulation.



The following is an attempt to start explaining the relationships,  
however ASCII art is not my strong point. I can expand if this is too  
vague.


        Model is-a LogSubject
        LogSubject#toLogString calls LogSubject#toLogString
        Model references LogActor references RootLogger
        Model references LogMessage
        Model#action calls LogActor#get with LogMessage#message
        LogMessage#message takes LogSubject* and Object*

Cheerz,
Andrew.
--
-- andrew d kennedy ? do not fold, bend, spindle, or mutilate ;
-- http://grkvlt.blogspot.com/ ? edinburgh : +44 7941 197 134 ;

On 6 Sep 2010, at 02:35, Martin Ritchie wrote:

On 2 September 2010 10:53, Sorin S. <ssu...@gmail.com> wrote:

Hi Martin,
Thanks very much for your feedback.

The main problem I had with the current framework is the fact that  
the

LogSubject objects seem to have knowledge about broker hierarchy (eg
the SubscriptionLogSubject instantiates a QueueLogSubject, also the
ConnectionLogSubject takes a AMQProtocolSession which is pre 0-10,
etc) -
this makes those LogSubject(s) hard to re-use and things can get even
harder if 1-0 comes with a different Model Object hierarchy.


Hi Sorin,

Thanks for taking the time to add some explanation, but I still can't
see the need for the changes you are proposing.

A subscription is a 'subscription to a queue' therefore it delegates
to the QueueLogSubject to perform that logging. It would be wrong for
the SubscriptionLogSubject to know how to log queues. There is no
knowledge of a broker hierarchy only that a subscription involves a
queue, but I don't think this is much of a mental leap.

I totally agree with you about the AMQProtocolSession, as you
highlight this is a concrete implementation class for a particular
protocol. As I mentioned off list I would have expected the
LogSubjects to use the Model classes AMQConnectionModel and
AMQSessionModel. At this level of abstraction the logging would not
know about the protocol in use only the details that it was desirable
to log about. These model classes were added after the Logging
framework so it is only natural that they are not being used.


Given the LogSubject role is to provide a subject (ultimately a  
label)
to the business message pertaining to a broker specific Object  
state I
thought that the object itself is in the best position to have all  
the

information needed to generate the log subject and therefore the
logging framework can consist of a GenericLogActor which would take
something like:
(LogSubject) Object
and format it using the selected method from a class generated from
o.a.q.server.logging.messages.*_logmessages.properties (where the

formatting takes place). So our Model Object encapsulates all the  
info

needed to log itself up.


The business objects should only perform their primary function so
should not have anything to do with logging. If you make it perform
more than one primary operation then it becomes difficult to replace
or extend only one of those functions. Keeping the functionality
isolated is part of a good design. The role of the LogSubject is to
provide an coupling between the broker code and the logging code. The
LogSubjects allow the creation of an identifier for each of the broker
Model objects. This information is not required by the Model objects
to do their job and it is not required by the logging framework, the
LogSubjects are there to encapsulate the extraction of Model
properties and ultimately the formatting of a log string.

I really don't see why the Broker model should know anything about
logging its primary purpose is message delivery not logging.


This allows decoupling of the logging framework from the need to know
anything about the objects it logs, it only needs to call the
toLogString method defined in the LogSubject interface. It could also
log anything implementing a LogSubject interface via the same
GenericActor. Otherwise we might need to create new Actors and
LogSubject's to fit any new Model Object which doesn't seem right to
me.


By doing this you are coupling the the format of the log message with
the business of maintaining a connection or a session. Sure the
logging logging framework doesn't need to know about the the objects
it is logging but that was the case before you started this work. The
Loggers would work in any application, the binding between Qpid and
the LogActor framework are the LogSubjects. By having the three
components each with a single responsibility we can maintain a series
of clean interfaces which are easier to test and maintain and
therefore understand.


As of now, with the proposed patches, the 0-10 operational logging
works independent of the pre 0-10 one and I think it is simpler and
more flexible.


However, your current patches are suggesting that the 0-8/9, 0-10 and
future 1-0 objects will all have to have their own log formatting.
This will lead to inconsistency at best, at worse we will have three
copies of the same log format to maintain. By abstracting and using a
model the LogSubjects become independent of implementation details and
provide a single place to maintain and understand how logging of a
broker model is performed.


This is why Qpid-2835 seems inconsistent with the 0-8/0-9, as it is
designed to sit alongside the current framework.
If agreed and within the planned October release scope, we can
refactor the current implementation also, effectively reducing the
logging framework to a LogSubject interface, a GenericActor and
o.a.q.server.logging.messages.* classes, still obeying the schema you
highlighted:

LogActors <-> Logging Framework
LogActors <-> Model Objects

but we might as well leave it as it is.


What you are suggesting does not follow the clean abstraction
highlighted above. If you remove the the Logging framework you will be
left with dead code in your model objects in the form of the
toLogString() methods. How is this a good design?

I really think the removal of the concrete LogSubjects and LogActors
is a backward step for logging. Introducing logging to the 0-10
protocol should be a very quick process, it is just a case of adding
the right logging calls in the 0-10 code base, exposing the required
state from the 0-10 model objects and changing the LogSubjects to use
model interfaces. Logging should know nothing about the protocol
version. I see your patches have the new 0-10 code calls, we just need
finish the integration of the 0-10 protocol to the broker.


The move to slf4j is something very good to have, but it requires
major changes as you know. Once we have it, we can hook it at the

o.a.q.server.logging.rawloggers level. But to achieve that, we  
need to
give up the log4j.xml file watching, the org.apache.log4j packages  
(eg

the QpidCompositeRollingAppender), we have jmx console issues to take
care of, couple of hardcoded places to look at and about 94 straight

changes, not to mention the testing framework as well. All in all,  
not

a trivial move but doable nevertheless.


I'm not sure what you mean by moving to slf4j as requiring major
changes. It has never been mentioned that we should migrate the broker
code base away from log4j. I can see how once we have fully split the
broker in to modules and are able to load them into an OSGi container
that being able to select a logger other than log4j may have benefits.
The current framework does not and should not reference log4j anywhere
outside of the Log4jMessageLogger. If you wanted to use slf4j then it
is a simple matter of making a new MessageLogger.


I would be very interested to hear thoughts on the above from anyone
on the list.


As I mentioned above I have had a quick look through your patches and
I'm not in favour of moving the logging into the business logic. Think
of it this way, if you can't test a piece of functionality in
isolation then there is a problem with the design. To test your
logging formatters you are going to have to instantiate or mock out
the entire connection. Logging has nothing to do with the connection
logic only attributes of the connection. So you should only need a
mock connection, but by embedding the logging formatters in the
connection you cannot use a mock connection.


Martin


Thank you,

Sorin




On Wed, Sep 1, 2010 at 7:12 PM, Martin Ritchie  
<ritch...@apache.org> wrote:

Hi Sorin,

I've been watching your changes wrt the Operational Logging  
apologies

for not replying to your thread over the weekend but I wasn't at a
computer.


I think the addition of the toLogString() is the wrong approach  
here.

The responsibility for the logging format should not lie with the
individual model objects.

From our discussion on QPID-2780 this doesn't seem like the same
approach you are now taking, what changed?

The change suggested by the patch on QPID-2835 will introduce
inconsistency in the operation logging. Something that its
introduction was designed to reduce.

The LogActors are that point where the consistency is gained.
By locating the LogFormat and the string builder in one location the
LogActor has full responsibility of formatting log messages.

The approach that I would have taken here is to expose the required

common methods for logging on our Session and Connection models.  
This

would then mean that we would have two clean interfaces boundaries:
LogActors <-> Logging Framework
LogActors <-> Model Objects


This would mean that the desire to move to slf4j would be a  
matter of
adjusting the Logging Framework and the adding consistent 1-0  
logging

would be simply a matter of implementing the model interfaces.


The only code that I would expect to see added to the 0-10  
Connection

code paths is the introduction of Logging commands. The 0-10 Model

Objects should have nothing to do with formatting logging  
statements.


Cheers
Martin

On 31 August 2010 12:18, Sorin Suciu (JIRA)
<qpid-...@incubator.apache.org> wrote:



    [ https://issues.apache.org/jira/browse/QPID-2835? 
page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]


Sorin Suciu updated QPID-2835:
------------------------------

   Attachment: qpid-2835.patch


Implement connections (CON) operational logging on 0-10
-------------------------------------------------------

                Key: QPID-2835

                URL: https://issues.apache.org/jira/browse/ 
QPID-2835

            Project: Qpid
         Issue Type: Improvement
         Components: Java Broker
   Affects Versions: 0.7
           Reporter: Sorin Suciu
           Priority: Minor
            Fix For: 0.7

        Attachments: qpid-2835.patch



This is part of the Qpid-2801, dealing with connection  
operational logging on 0-10 code path.


--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.



------------------------------------------------------------------- 
--

Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:dev-subscr...@qpid.apache.org






--
Martin Ritchie


-------------------------------------------------------------------- 
-

Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:dev-subscr...@qpid.apache.org






--
Sorin S

---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:dev-subscr...@qpid.apache.org






--
Martin Ritchie

---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:dev-subscr...@qpid.apache.org




---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:dev-subscr...@qpid.apache.org























					Reply via email to