Uploaded image for project: 'Directory Client API'
  1. Directory Client API
  2. DIRAPI-206

BindRequest logs exception on valid call to setter

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 1.0.0-M24
    • Fix Version/s: 1.0.0-M25
    • Labels:
      None

      Description

      We are using DIRAPI to connect to our corporate ActiveDirectory and it seems impossible to do so without getting an exception logged in our application log, even on successful operations. This is a concern since the exception creates noise potentially hiding real issues.

      The problem is described in http://t211471.apache-directory-api.apachetalks.us/binding-and-active-directory-t211471.html but the resolution is not sufficient for our purposes.

      The issue is caused by this bit of code in BindRequestImpl:

          public BindRequest setName( String name )
          {
              this.name = name;
      
              try
              {
                  this.dn = new Dn( name );
              }
              catch ( LdapInvalidDnException e )
              {
                  // This might still be a valid DN (Windows AD binding for instance)
                  LOG.info( "Unable to convert the name to a DN.", e );
                  this.dn = null;
              }
      
              return this;
          }
      

      The comment even indicates that the call might be perfectly valid. I think it would be much better to either drop the exception completely, or – if it is required in other scenarios – to skip the attempt of creating the DN field completely if some flag is set (extra parameter / field / subclass). Since the name field is private it can not be done from the client side.

      This is a potential showstopper for us – we do not like telling our support staff to ignore exceptions in logs.

        Activity

        Hide
        elecharny Emmanuel Lecharny added a comment -

        One simple solution that fits your need, add this line in your logger property file :

        log4j.logger.org.apache.directory.api.ldap.model.message.BindRequestImpl=NONE

        The logger for the BindRequestImpl class has been created specifically to handle this kind of message, so if you don't want to know about it, disable it.

        Show
        elecharny Emmanuel Lecharny added a comment - One simple solution that fits your need, add this line in your logger property file : log4j.logger.org.apache.directory.api.ldap.model.message.BindRequestImpl=NONE The logger for the BindRequestImpl class has been created specifically to handle this kind of message, so if you don't want to know about it, disable it.
        Hide
        elecharny Emmanuel Lecharny added a comment -

        Reopeing the issue. The proposed solution is theorically right, but from a pragmatic POV, it's a bit blind.

        The best solution, as Kiran suggest, is to switch the LOG to debug for this case.

        Show
        elecharny Emmanuel Lecharny added a comment - Reopeing the issue. The proposed solution is theorically right, but from a pragmatic POV, it's a bit blind. The best solution, as Kiran suggest, is to switch the LOG to debug for this case.
        Hide
        akiran Kiran Ayyagari added a comment -

        Changed the log level to debug. See http://svn.apache.org/r1635915.

        Show
        akiran Kiran Ayyagari added a comment - Changed the log level to debug. See http://svn.apache.org/r1635915 .
        Hide
        peter.becker.de Peter Becker added a comment -

        The solution still breaks the rule of using exceptions only for exceptional cases. The performance overhead doesn't matter much here since the LDAP part will be much more expensive, but I still don't think it's a good idea. And having a stack trace in any log for me is a massive warning sign, it should happen only if something went wrong.

        As a developer I constantly run code with debug logging on across the board, the new solution will still force me to tweak my logging configuration. Worse: every new person to this will first have to do research as to why they see the exception, to then realize it's not their fault.

        Also: if I would be in a mixed scenario where I would talk to Active Directory and other LDAPs (which I might be in the future), then there is no logging configuration that is correct: either I get stack traces that shouldn't be there, or I might miss a problem.

        Switching to debug reduces the pain, but it doesn't really solve the real problem.

        Show
        peter.becker.de Peter Becker added a comment - The solution still breaks the rule of using exceptions only for exceptional cases. The performance overhead doesn't matter much here since the LDAP part will be much more expensive, but I still don't think it's a good idea. And having a stack trace in any log for me is a massive warning sign, it should happen only if something went wrong. As a developer I constantly run code with debug logging on across the board, the new solution will still force me to tweak my logging configuration. Worse: every new person to this will first have to do research as to why they see the exception, to then realize it's not their fault. Also: if I would be in a mixed scenario where I would talk to Active Directory and other LDAPs (which I might be in the future), then there is no logging configuration that is correct: either I get stack traces that shouldn't be there, or I might miss a problem. Switching to debug reduces the pain, but it doesn't really solve the real problem.
        Hide
        akiran Kiran Ayyagari added a comment -

        The solution still breaks the rule of using exceptions only for exceptional cases.

        This is exactly the reason why the error is thrown/logged. Cause what AD accepts as user's DN is not a valid DN.

        Show
        akiran Kiran Ayyagari added a comment - The solution still breaks the rule of using exceptions only for exceptional cases. This is exactly the reason why the error is thrown/logged. Cause what AD accepts as user's DN is not a valid DN.
        Hide
        peter.becker.de Peter Becker added a comment -

        I'm not a big fan of Microsoft technologies, but no matter how I want things to be different, fact of the matter is that when connecting to AD these user names are normal. I am not going out to tell our customers not to use AD just because I don't like that – chances are that would reduce the number of customers significantly.

        If you feel like putting a snarky comment in, feel free to call the AD toggle something in the spirit of POI-HSSF, I think that's quite funny. For all I care you can use a property "usersAreOnTheDarkSide". But throwing exceptions into my logs is not nice at all, I perceive it as a political statement that causes pain to me without much chance of making an actual difference. That is obviously just my opinion, but I have a feeling I'm not alone.

        Show
        peter.becker.de Peter Becker added a comment - I'm not a big fan of Microsoft technologies, but no matter how I want things to be different, fact of the matter is that when connecting to AD these user names are normal. I am not going out to tell our customers not to use AD just because I don't like that – chances are that would reduce the number of customers significantly. If you feel like putting a snarky comment in, feel free to call the AD toggle something in the spirit of POI-HSSF, I think that's quite funny. For all I care you can use a property "usersAreOnTheDarkSide". But throwing exceptions into my logs is not nice at all, I perceive it as a political statement that causes pain to me without much chance of making an actual difference. That is obviously just my opinion, but I have a feeling I'm not alone.
        Hide
        akiran Kiran Ayyagari added a comment -

        No, it wasn't snarky (IMHO email/text is terrible at times for expressing opinions).
        I just mentioned why the exception was considered as a norm, though we perfectly agree that with AD things are different.

        We even considered adding 'activeDirectoryMode' flag but later I proposed setting it to 'debug' should be sufficient assuming
        production systems would run at levels INFO or above. The above fix was a result of this discussion.

        Show
        akiran Kiran Ayyagari added a comment - No, it wasn't snarky (IMHO email/text is terrible at times for expressing opinions). I just mentioned why the exception was considered as a norm, though we perfectly agree that with AD things are different. We even considered adding 'activeDirectoryMode' flag but later I proposed setting it to 'debug' should be sufficient assuming production systems would run at levels INFO or above. The above fix was a result of this discussion.
        Hide
        elecharny Emmanuel Lecharny added a comment -

        The mistake we have made was to keep the exception in the log.

                     LOG.info( "Unable to convert the name to a DN." ); // No exception stored in the log
        

        should be enough. No pollution, just one single line of potentially useful info.

        Show
        elecharny Emmanuel Lecharny added a comment - The mistake we have made was to keep the exception in the log. LOG.info( "Unable to convert the name to a DN." ); // No exception stored in the log should be enough. No pollution, just one single line of potentially useful info.
        Hide
        peter.becker.de Peter Becker added a comment -

        Emmanuel: that seems sensible assuming the exception itself is not important in any scenario. Otherwise you would potentially lose information in those cases where you did not expect the conversion to fail. I can't judge that.

        Having it at info still means every log in attempt could log a line in production, which could raise concerns with support staff. After all it is still a failure message they will see. I'd prefer debug level. Or at least to re-phrase that it is normal, e.g. "Unable to convert the user name to a DN, we assume the server allows non-DN user names." (or something like that).

        For me the activeDirectoryMode still seems the best option, or something more specific like convertUsernameToDn. If on -> don't even try to convert to DN; if off -> conversion failure is a real problem and needs to be reported. But my main goal is to get rid of the stack traces, they make people nervous.

        Show
        peter.becker.de Peter Becker added a comment - Emmanuel: that seems sensible assuming the exception itself is not important in any scenario. Otherwise you would potentially lose information in those cases where you did not expect the conversion to fail. I can't judge that. Having it at info still means every log in attempt could log a line in production, which could raise concerns with support staff. After all it is still a failure message they will see. I'd prefer debug level. Or at least to re-phrase that it is normal, e.g. "Unable to convert the user name to a DN, we assume the server allows non-DN user names." (or something like that). For me the activeDirectoryMode still seems the best option, or something more specific like convertUsernameToDn . If on -> don't even try to convert to DN; if off -> conversion failure is a real problem and needs to be reported. But my main goal is to get rid of the stack traces, they make people nervous.
        Hide
        elecharny Emmanuel Lecharny added a comment -

        oops, I took the wrong line from the wrong source. It's not anymore a INFO level, but a DEBUG level, thanks to Kiran change, lately.

        We could define a dedicated logger for this case, instead of using one which is associated with a class name.

        Show
        elecharny Emmanuel Lecharny added a comment - oops, I took the wrong line from the wrong source. It's not anymore a INFO level, but a DEBUG level, thanks to Kiran change, lately. We could define a dedicated logger for this case, instead of using one which is associated with a class name.
        Hide
        elecharny Emmanuel Lecharny added a comment -

        I forgot to mention that using a flag that would be disabled or enabled through an AP configuration is not going to happen : that would require to expose some dedicated configuration, something we want to avoid at all cost.

        I have removed the stacktrace, and the log is only produce when DEBUG is one for this class (org.apache.directory.api.ldap.model.message.BindRequestImpl). It's enough to set this logger to something different to DEBUg to not have it in the logs.

        Show
        elecharny Emmanuel Lecharny added a comment - I forgot to mention that using a flag that would be disabled or enabled through an AP configuration is not going to happen : that would require to expose some dedicated configuration, something we want to avoid at all cost. I have removed the stacktrace, and the log is only produce when DEBUG is one for this class (org.apache.directory.api.ldap.model.message.BindRequestImpl). It's enough to set this logger to something different to DEBUg to not have it in the logs.
        Hide
        elecharny Emmanuel Lecharny added a comment -

        Closing the resolved issues.

        Show
        elecharny Emmanuel Lecharny added a comment - Closing the resolved issues.

          People

          • Assignee:
            elecharny Emmanuel Lecharny
            Reporter:
            peter.becker.de Peter Becker
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development