HBASE-27528 log duplication issues in MasterRpcServices.

[curie71]

HBASE-27528 MasterRpcServices record audit log in privileged operations (grant, revoke).

  public RevokeResponse revoke(RpcController controller, RevokeRequest request)
    throws ServiceException {
    try {
      ......
        server.cpHost.preRevoke(userPermission); // has audit log in AccessChecker
       ...... // removeUserPermission
        User caller = RpcServer.getRequestUser().orElse(null);
        if (AUDITLOG.isTraceEnabled()) {
          String remoteAddress = RpcServer.getRemoteAddress().map(InetAddress::toString).orElse("");
          AUDITLOG.trace("User {} (remote address: {}) revoked permission {}", caller,
            remoteAddress, userPermission); // duplicate auditlog
        }
        ......
  }

but I found a path from server.cpHost.preRevoke(userPermission); to AccessChecker audit log
(preRevoke -> MasterCoprocessorHost.preRevoke -> AccessController.preRevoke -> preGrantOrRevoke -> accessChecker.requireXXXPermission -> logResult -> AUDITLOG.trace...), which caused log duplication:

public void requireGlobalPermission(User user, String request, Action perm, String namespace)
    throws IOException {
    AuthResult authResult;
    if (authManager.authorizeUserGlobal(user, perm)) {
      authResult = AuthResult.allow(request, "Global check allowed", user, perm, null);
      authResult.getParams().setNamespace(namespace);
      logResult(authResult);
    } else {
      authResult = AuthResult.deny(request, "Global check failed", user, perm, null);
      authResult.getParams().setNamespace(namespace);
      logResult(authResult);
      throw new AccessDeniedException(
        "Insufficient permissions for user '" + (user != null ? user.getShortName() : "null")
          + "' (global, action=" + perm.toString() + ")");
    }
  }

the logResult auditlog contain all the infomation recorded by MasterRpcServices.revoke (user, remote address, permission) :

  public static void logResult(AuthResult result) {
    if (AUDITLOG.isTraceEnabled()) {
      User user = result.getUser();
      UserGroupInformation ugi = user != null ? user.getUGI() : null;
      AUDITLOG.trace(
        "Access {} for user {}; reason: {}; remote address: {}; request: {}; context: {};"
          + "auth method: {}",
        (result.isAllowed() ? "allowed" : "denied"),
        (user != null ? user.getShortName() : "UNKNOWN"), result.getReason(),
        RpcServer.getRemoteAddress().map(InetAddress::toString).orElse(""), result.getRequest(),
        result.toContextString(), ugi != null ? ugi.getAuthenticationMethod() : "UNKNOWN");
    }
  }

Since AccessChecker integrates auditlogs for permission check, I'll delete the log in MasterRpcServices.
And grant has the same problem.

[Apache-HBase]

🎊 +1 overall

Vote	Subsystem	Runtime	Comment
+0 🆗	reexec	0m 17s	Docker mode activated.
		_ Prechecks _
+1 💚	dupname	0m 0s	No case conflicting files found.
+1 💚	hbaseanti	0m 0s	Patch does not have any anti-patterns.
+1 💚	@author	0m 0s	The patch does not contain any @author tags.
		_ master Compile Tests _
+1 💚	mvninstall	2m 42s	master passed
+1 💚	compile	2m 21s	master passed
+1 💚	checkstyle	0m 34s	master passed
+1 💚	spotless	0m 43s	branch has no errors when running spotless:check.
+1 💚	spotbugs	1m 28s	master passed
		_ Patch Compile Tests _
+1 💚	mvninstall	2m 32s	the patch passed
+1 💚	compile	2m 21s	the patch passed
+1 💚	javac	2m 21s	the patch passed
+1 💚	checkstyle	0m 35s	the patch passed
+1 💚	whitespace	0m 0s	The patch has no whitespace issues.
+1 💚	hadoopcheck	8m 36s	Patch does not cause any errors with Hadoop 3.2.4 3.3.4.
+1 💚	spotless	0m 40s	patch has no errors when running spotless:check.
+1 💚	spotbugs	1m 35s	the patch passed
		_ Other Tests _
+1 💚	asflicense	0m 12s	The patch does not generate ASF License warnings.
		30m 25s

Subsystem	Report/Notes
Docker	ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4951/1/artifact/yetus-general-check/output/Dockerfile
GITHUB PR	#4951
Optional Tests	dupname asflicense javac spotbugs hadoopcheck hbaseanti spotless checkstyle compile
uname	Linux bf1addd02ddb 5.4.0-135-generic #152-Ubuntu SMP Wed Nov 23 20:19:22 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build tool	maven
Personality	dev-support/hbase-personality.sh
git revision	master / 3f1087f
Default Java	Eclipse Adoptium-11.0.17+8
Max. process+thread count	79 (vs. ulimit of 30000)
modules	C: hbase-server U: hbase-server
Console output	https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4951/1/console
versions	git=2.34.1 maven=3.8.6 spotbugs=4.7.3
Powered by	Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

[Apache-HBase]

🎊 +1 overall

Vote	Subsystem	Runtime	Comment
+0 🆗	reexec	1m 7s	Docker mode activated.
-0 ⚠️	yetus	0m 4s	Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
		_ Prechecks _
		_ master Compile Tests _
+1 💚	mvninstall	2m 38s	master passed
+1 💚	compile	0m 47s	master passed
+1 💚	shadedjars	3m 50s	branch has no errors when building our shaded downstream artifacts.
+1 💚	javadoc	0m 27s	master passed
		_ Patch Compile Tests _
+1 💚	mvninstall	2m 30s	the patch passed
+1 💚	compile	0m 47s	the patch passed
+1 💚	javac	0m 47s	the patch passed
+1 💚	shadedjars	4m 20s	patch has no errors when building our shaded downstream artifacts.
+1 💚	javadoc	0m 28s	the patch passed
		_ Other Tests _
+1 💚	unit	218m 5s	hbase-server in the patch passed.
		239m 4s

Subsystem	Report/Notes
Docker	ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4951/1/artifact/yetus-jdk11-hadoop3-check/output/Dockerfile
GITHUB PR	#4951
Optional Tests	javac javadoc unit shadedjars compile
uname	Linux 44cb333c8455 5.4.0-135-generic #152-Ubuntu SMP Wed Nov 23 20:19:22 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build tool	maven
Personality	dev-support/hbase-personality.sh
git revision	master / 3f1087f
Default Java	Eclipse Adoptium-11.0.17+8
Test Results	https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4951/1/testReport/
Max. process+thread count	2579 (vs. ulimit of 30000)
modules	C: hbase-server U: hbase-server
Console output	https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4951/1/console
versions	git=2.34.1 maven=3.8.6
Powered by	Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

[Apache9]

So the intention here is that, only if we have already enabled AccessChecker, calling grant and revoke is useful?
AccessChecker is a coprocessor, so we will not always enable it.

[curie71]

@Apache9
I see, so the AccessChecker log access deny/allow at warn/info level may solve the log duplication problems?

[Apache9]

I mean the removal seems OK, as if we do not enable AccessChecker, it does not make sense to call grant and revoke methods.

[Apache9]

Request review from @apurtell and @wchevreuil. Will merge later if no objections.

Thanks.

[curie71]

I mean the removal seems OK, as if we do not enable AccessChecker, it does not make sense to call grant and revoke methods.

Thanks for your review!