Uploaded image for project: 'Hadoop Common'
  1. Hadoop Common
  2. HADOOP-10274

Lower the logging level from ERROR to WARN for UGI.doAs method

    Details

    • Type: Improvement
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 1.0.4
    • Fix Version/s: 2.3.0
    • Component/s: security
    • Labels:
      None
    • Environment:

      hadoop-1.0.4, hbase-0.94.16, krb5-server-1.6.1-31.el5_3.3, CentOS release 5.3 (Final)

    • Hadoop Flags:
      Reviewed

      Description

      Recently we got the error msg "Request is a replay (34) - PROCESS_TGS" while we are using the HBase client API to put data into HBase-0.94.16 with krb5-1.6.1 enabled. The related msg as follows...

      [2014-01-15 09:40:38,452][hbase-tablepool-1-thread-3][ERROR][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1124)): PriviledgedActionException as:takeshi_miao@LAB cause:javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Request is a replay (34) - PROCESS_TGS)]
      [2014-01-15 09:40:38,453][hbase-tablepool-1-thread-3][DEBUG][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation.logPriviledgedAction(UserGroupInformation.java:1143)): PriviledgedAction as:takeshi_miao@LAB from:sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)                                                                                          
      [2014-01-15 09:40:38,453][hbase-tablepool-1-thread-3][DEBUG][org.apache.hadoop.ipc.SecureClient](org.apache.hadoop.hbase.ipc.SecureClient$SecureConnection$1.run(SecureClient.java:213)): Exception encountered while connecting to the server : javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Request is a replay (34) - PROCESS_TGS)]
      [2014-01-15 09:40:38,454][hbase-tablepool-1-thread-3][INFO ][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation.reloginFromTicketCache(UserGroupInformation.java:657)): Initiating logout for takeshi_miao@LAB
      [2014-01-15 09:40:38,454][hbase-tablepool-1-thread-3][DEBUG][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation$HadoopLoginModule.logout(UserGroupInformation.java:154)): hadoop logout
      [2014-01-15 09:40:38,454][hbase-tablepool-1-thread-3][INFO ][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation.reloginFromTicketCache(UserGroupInformation.java:667)): Initiating re-login for takeshi_miao@LAB
      [2014-01-15 09:40:38,455][hbase-tablepool-1-thread-3][DEBUG][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation$HadoopLoginModule.login(UserGroupInformation.java:146)): hadoop login
      [2014-01-15 09:40:38,456][hbase-tablepool-1-thread-3][DEBUG][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation$HadoopLoginModule.commit(UserGroupInformation.java:95)): hadoop login commit
      [2014-01-15 09:40:38,456][hbase-tablepool-1-thread-3][DEBUG][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation$HadoopLoginModule.commit(UserGroupInformation.java:100)): using existing subject:[takeshi_miao@LAB, UnixPrincipal: takeshi_miao, UnixNumericUserPrincipal: 501, UnixNumericGroupPrincipal [Primary Group]: 501, UnixNumericGroupPrincipal [Supplementary Group]: 502, takeshi_miao@LAB]
      

      Finally, we found that the HBase would doing the retry (5 * 10 times) and recovery this 'request is a replay (34)' issue, but based on the HBase user viewpoint, the error msg at first line may be frightful, as we were afraid there was any data loss occurring at the first sight...

      [2014-01-15 09:40:38,452][hbase-tablepool-1-thread-3][ERROR][org.apache.hadoop.security.UserGroupInformation](org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1124)): PriviledgedActionException as:takeshi_miao@LAB cause:javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Request is a replay (34) - PROCESS_TGS)]
      

      So I'd like to suggest to change the logging level from 'ERROR' to 'WARN' for o.a.hadoop.security.UserGroupInformation#doAs(PrivilegedExceptionAction<T>) method

        public <T> T doAs(PrivilegedExceptionAction<T> action
                          ) throws IOException, InterruptedException {
          try {
            // ...
          } catch (PrivilegedActionException pae) {
            Throwable cause = pae.getCause();
            LOG.error("PriviledgedActionException as:"+this+" cause:"+cause); // I mean here
            // ...
          }
        }
      

      Due to this method already throws _checked exception_s which can be handled by the client code, so the error may not really be an error if client code can handle it...such as this case.

      For more details pls refer to HBASE-10379

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                takeshi.miao takeshi.miao
                Reporter:
                takeshi.miao takeshi.miao
              • Votes:
                0 Vote for this issue
                Watchers:
                7 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: