You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@river.apache.org by Mark Brouwer <ma...@cheiron.org> on 2007/03/27 11:55:18 UTC

Integrity.NO constraint results in selection of X500Provider instances

When I configure Integrity.NO for discovery the logging (see below)
reveals that the SHA1withDSA client provider is used while according to
DJ.3.2 this provider supports "integrity protection of multicast request
and announcement packet contents, and sender authentication".

27-Mar-2007 11:40:17 com.sun.jini.discovery.DiscoveryV2
     decodeMulticastAnnouncement (oid=1.3.6.1.4.12543.2.0,
                                  instance=master)
FINEST: decoded MulticastAnnouncement[0, polaris:8888, [],
         0bae0e43-cb40-4d98-81aa-9b61d45c038d] using
         com.sun.jini.discovery.x500.sha1withdsa.Client@1ffccd6,
         InvocationConstraints[reqs: {Integrity.NO}, prefs: {}]

To me it seems that Integrity.NO as constraint can't be fulfilled by
this provider and therefore should have failed. Is my reasoning correct
or is there language that allows the above to happen.
-- 
Mark

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Bob Scheifler <Bo...@Sun.COM>.
Mark Brouwer wrote:
> I looked into how the callers of Discovery instances dealt with these
> exceptions: in general one can say that failures for multicast discovery
> are logged at the HANDLED level, while failures for unicast discovery is
> logged at the INFO level, although I've seen deviations (e.g.
> UnsupportedConstraintException at HANDLED and other IOExceptions at INFO).
> 
> Can you, or somebody else, explain why this sharp distinction has been 
> made.

I don't recall, sorry.

- Bob

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Mark Brouwer <ma...@cheiron.org>.
Mark Brouwer wrote:

> I will go through a the JTSK code and see the usage of FAILED myself, as
> well as some other pieces of code as I think most of the times I used it
> as specified for Levels.FAILED. But as I have other obligation I won't
> be able to get back to this today.

Bob,

I think the usage of FAILED is indeed consistent throughout the JTSK
code with the logging principals posted. Going through a lot of my
own code it turns out my usage has been pretty consistent with the
principals too. The principals were also made available during the Davis
project on the jini.org website and I've used them as well for Jini
based systems but I must admit since a few years I haven't looked into them.

I looked into how the callers of Discovery instances dealt with these
exceptions: in general one can say that failures for multicast discovery
are logged at the HANDLED level, while failures for unicast discovery is
logged at the INFO level, although I've seen deviations (e.g.
UnsupportedConstraintException at HANDLED and other IOExceptions at INFO).

Can you, or somebody else, explain why this sharp distinction has been made.

I have a hunch, but given the fact that when none of the multicast
providers succeed in general you have a nasty enough situation too for
which you might have wanted some logging at INFO level. At the other
hand lately I've seen enough unicast discovery failures logged at INFO
level of which I already know that I will get plenty of support
questions when these get into log files as customers hate to see
stacktraces in log files even when there is a logical explanation for
them to be there. I've had to filter in the past messages at INFO level
and to direct these to a special log file just to give people a
comfortable feeling about how the system was functioning while still
giving the ISV the ability to analyze certain problems.
-- 
Mark


Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Mark Brouwer <ma...@cheiron.org>.
Bob Scheifler wrote:
> Mark Brouwer wrote:
>>  From com.sun.jini.logging.Levels.FAILED:
>>
>> "FAILED is a message level indicating that a facility has experienced a
>> failure that it will reflect to its caller.
>>
>> FAILED messages are intended to provide users with information about
>> failures produced by internal components in order to assist with
>> debugging problems in systems with multiple components. This level is
>> initialized to 600."
> 
>  From the logging principles document we used during Davis:
> 
>   FAILED  - serious, unexpected "problems" encountered by a component that
>             the user/deployer/administrator needs to know about, which the
>             component propagates to its caller, and which may ultimately be
>             logged by some other component at a higher level (such as 
> INFO).
> 
> http://archives.java.sun.com/cgi-bin/wa?A2=ind0406&L=jini-users&P=R6550&I=-3 

Ok,

So you suggest that the specs for Levels.FAILED should be changed
according to the principles. And are these principles followed
consistently throughout the JTSK code?

Can you indicate whether it would be handy to see the outcome of the
discovery provider operation and if so at what level do you envison the
logging to take place.

I will go through a the JTSK code and see the usage of FAILED myself, as
well as some other pieces of code as I think most of the times I used it
as specified for Levels.FAILED. But as I have other obligation I won't
be able to get back to this today.
-- 
Mark

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Bob Scheifler <Bo...@Sun.COM>.
Mark Brouwer wrote:
>  From com.sun.jini.logging.Levels.FAILED:
> 
> "FAILED is a message level indicating that a facility has experienced a
> failure that it will reflect to its caller.
> 
> FAILED messages are intended to provide users with information about
> failures produced by internal components in order to assist with
> debugging problems in systems with multiple components. This level is
> initialized to 600."

 From the logging principles document we used during Davis:

   FAILED  - serious, unexpected "problems" encountered by a component that
             the user/deployer/administrator needs to know about, which the
             component propagates to its caller, and which may ultimately be
             logged by some other component at a higher level (such as INFO).

http://archives.java.sun.com/cgi-bin/wa?A2=ind0406&L=jini-users&P=R6550&I=-3

- Bob

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Mark Brouwer <ma...@cheiron.org>.
Bob Scheifler wrote:
> Mark Brouwer wrote:
>> What and how to log is always a nice subject for slaughter parties, but
>> I think the semantics for FAILED suggest this is a proper case.
> 
> I don't think I followed what "this" case is, exactly.  FAILED
> was intended for serious unexpected problems, I didn't get the
> flavor that was the case here.

 From com.sun.jini.logging.Levels.FAILED:

"FAILED is a message level indicating that a facility has experienced a
failure that it will reflect to its caller.

FAILED messages are intended to provide users with information about
failures produced by internal components in order to assist with
debugging problems in systems with multiple components. This level is
initialized to 600."

I assume 'failure' in itselfs is not bound to being "serious unexpected
problems" so to me any exceptions thrown by a component, is expected to
be caught by a caller, that crosses a clear bounderay and helps with
debugging is subject to FAILED.
-- 
Mark

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Bob Scheifler <Bo...@Sun.COM>.
Mark Brouwer wrote:
> What and how to log is always a nice subject for slaughter parties, but
> I think the semantics for FAILED suggest this is a proper case.

I don't think I followed what "this" case is, exactly.  FAILED
was intended for serious unexpected problems, I didn't get the
flavor that was the case here.

- Bob

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Mark Brouwer <ma...@cheiron.org>.
Vinod Johnson - Sun Microsystems wrote:

>> You are probably right. I went through the log files and I found *no*
>> HANDLED messages that indicated a failure, but that turned out to be
>> logical as I only enabled logging for com.sun.jini.discovery. I didn't
>> configure the loggers for LookupDiscovery. It might be helpful to log
> Also, the constraint check is only done if LookupDiscovery decides that 
> the announcement is of interest (like the LUS has not been seen so far 
> or the groups have changed)

Thanks for the additional insight Vinod.

>> these kind of failures also at the FAILED level for the Discovery
>> implementations, that way we have a central point for all discovery
>> related 'logging' which seems to me more helpful than tracing the
>> entities calling the various Discovery methods, what do you think?
>>
> Seems like a value add, but I don't know if there is any consistent 
> theory in the code around logging all failures before an exception is 
> thrown.

What and how to log is always a nice subject for slaughter parties, but
I think the semantics for FAILED suggest this is a proper case. As in my
previous posting I see com.sun.jini.discovery as a component utilized by
components written on top of it. For troubleshooting purposes it seems
helpful not to rely on the consumers to see what is actually
happening by the discovery components.

I did a quick scan and it requires code changes at a reasonable amount
of places so others please chip in whether you think this needs to be
done as it is something I don't want to revert, or whether you have
objections.
-- 
Mark

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Vinod Johnson - Sun Microsystems <Th...@Sun.COM>.
Mark Brouwer wrote:
> Vinod Johnson - Sun Microsystems wrote:
>
>> This may just be a logging bug. If you happen to be invoking 
>> DiscvoeryV2.decodeMulticastAnnouncement with delayConstraintCheck set 
>> to true, this enables you to delay constraint checking until a more 
>> opportune time. This feature is currently used in LookupDiscovery 
>> (see http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=4867820 for 
>> more information on this). It looks like when this feature was added, 
>> the logging message was not updated to reflect the fact that 
>> constraint checking has been delayed.
>>
>> If you happen to be using LookupDiscovery, you should see a later 
>> logging message from LookupDiscovery (at HANDLED level) - "exception 
>> decoding multicast announcement", with the associated exception. This 
>> is the point at which the constraint check is actually done.
>
> Hi Vinod,
>
> You are probably right. I went through the log files and I found *no*
> HANDLED messages that indicated a failure, but that turned out to be
> logical as I only enabled logging for com.sun.jini.discovery. I didn't
> configure the loggers for LookupDiscovery. It might be helpful to log
Also, the constraint check is only done if LookupDiscovery decides that 
the announcement is of interest (like the LUS has not been seen so far 
or the groups have changed)
> these kind of failures also at the FAILED level for the Discovery
> implementations, that way we have a central point for all discovery
> related 'logging' which seems to me more helpful than tracing the
> entities calling the various Discovery methods, what do you think?
>
Seems like a value add, but I don't know if there is any consistent 
theory in the code around logging all failures before an exception is 
thrown.
> BTW you filed an issue for the 'confusing logging' and assigned it to
> yourself, given the fair number of improvements (context information) I
> already made in the discovery related code do you mind if I assign that
> issue to myself to prevent from extra work to resolve your code and mine
> code in the future.
>
> In case the full constraints verification is delayed the log message 
> will be appended with ", full constraints checking has been delayed" 
> but if you now a better description for what is actually happening 
> please let me know.
Thats fine.

-- 
- vinod

Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Mark Brouwer <ma...@cheiron.org>.
Vinod Johnson - Sun Microsystems wrote:

> This may just be a logging bug. If you happen to be invoking 
> DiscvoeryV2.decodeMulticastAnnouncement with delayConstraintCheck set to 
> true, this enables you to delay constraint checking until a more 
> opportune time. This feature is currently used in LookupDiscovery (see 
> http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=4867820 for more 
> information on this). It looks like when this feature was added, the 
> logging message was not updated to reflect the fact that constraint 
> checking has been delayed.
> 
> If you happen to be using LookupDiscovery, you should see a later 
> logging message from LookupDiscovery (at HANDLED level) - "exception 
> decoding multicast announcement", with the associated exception. This is 
> the point at which the constraint check is actually done.

Hi Vinod,

You are probably right. I went through the log files and I found *no*
HANDLED messages that indicated a failure, but that turned out to be
logical as I only enabled logging for com.sun.jini.discovery. I didn't
configure the loggers for LookupDiscovery. It might be helpful to log
these kind of failures also at the FAILED level for the Discovery
implementations, that way we have a central point for all discovery
related 'logging' which seems to me more helpful than tracing the
entities calling the various Discovery methods, what do you think?

BTW you filed an issue for the 'confusing logging' and assigned it to
yourself, given the fair number of improvements (context information) I
already made in the discovery related code do you mind if I assign that
issue to myself to prevent from extra work to resolve your code and mine
code in the future.

In case the full constraints verification is delayed the log message 
will be appended with ", full constraints checking has been delayed" but 
if you now a better description for what is actually happening please 
let me know.
-- 
Mark



Re: Integrity.NO constraint results in selection of X500Provider instances

Posted by Vinod Johnson - Sun Microsystems <Th...@Sun.COM>.
Mark Brouwer wrote:
> When I configure Integrity.NO for discovery the logging (see below)
> reveals that the SHA1withDSA client provider is used while according to
> DJ.3.2 this provider supports "integrity protection of multicast request
> and announcement packet contents, and sender authentication".
>
> 27-Mar-2007 11:40:17 com.sun.jini.discovery.DiscoveryV2
>     decodeMulticastAnnouncement (oid=1.3.6.1.4.12543.2.0,
>                                  instance=master)
> FINEST: decoded MulticastAnnouncement[0, polaris:8888, [],
>         0bae0e43-cb40-4d98-81aa-9b61d45c038d] using
>         com.sun.jini.discovery.x500.sha1withdsa.Client@1ffccd6,
>         InvocationConstraints[reqs: {Integrity.NO}, prefs: {}]
>
> To me it seems that Integrity.NO as constraint can't be fulfilled by
> this provider and therefore should have failed. Is my reasoning correct
> or is there language that allows the above to happen.
This may just be a logging bug. If you happen to be invoking 
DiscvoeryV2.decodeMulticastAnnouncement with delayConstraintCheck set to 
true, this enables you to delay constraint checking until a more 
opportune time. This feature is currently used in LookupDiscovery (see 
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=4867820 for more 
information on this). It looks like when this feature was added, the 
logging message was not updated to reflect the fact that constraint 
checking has been delayed.

If you happen to be using LookupDiscovery, you should see a later 
logging message from LookupDiscovery (at HANDLED level) - "exception 
decoding multicast announcement", with the associated exception. This is 
the point at which the constraint check is actually done.
-- 
- vinod