[IMPALA-4162] Extensive logging in HDFS NameNode during metadata load when dfs.namenode.acls.enabled=false

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: Impala 2.5.0
• Fix Version/s: Impala 2.10.0
• Component/s: Catalog
• Labels: performance
• Target Version: Impala 2.9.0
• Assignee: Unassigned
• Reporter: Mostafa Mokhtar
• Created: 19/Sep/16 18:07
• Updated: 13/Jun/17 05:28
• Resolved: 13/Jun/17 05:27

Description

I noticed that during metadata loading or after running "invalidate metadata" is that there is an extensive amount of CPU spent and memory allocated

org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(Object, Method, Object[])

When I checked the NameNode log I found thousands of entries with the error message below

2016-09-17 11:04:31,980 WARN org.apache.hadoop.security.UserGroupInformation: PriviledgedActionException as:impala (auth:SIMPLE) cause:org.apache.hadoop.hdfs.protocol.AclException: The ACL operation has been rejected.  Support for ACLs has been disabled by setting dfs.namenode.acls.enabled to false.
2016-09-17 11:04:31,980 INFO org.apache.hadoop.ipc.Server: IPC Server handler 15 on 8020, call org.apache.hadoop.hdfs.protocol.ClientProtocol.getAclStatus from 10.17.193.6:54224 Call#15696 Retry#0: org.apache.hadoop.hdfs.protocol.AclException: The ACL operation has been rejected.  Support for ACLs has been disabled by setting dfs.namenode.acls.enabled to false.

By default dfs.namenode.acls.enabled is false.

When I enabled dfs.namenode.acls.enabled the warning and INFO messages stopped and metadata loading after "invalidate metadata" was 5-10% faster.

This is the call stack for the exception

                        com.cloudera.impala.catalog.HdfsTable.getAvailableAccessLevel(FileSystem, Path)	1,020.475	814,602,776	3.494
                           com.cloudera.impala.util.FsPermissionChecker.getPermissions(FileSystem, Path)	1,195.04	680,677,832	2.92
                              org.apache.hadoop.hdfs.DistributedFileSystem.getAclStatus(Path)	1,546.947	541,678,944	2.323
                                 org.apache.hadoop.fs.FileSystemLinkResolver.resolve(FileSystem, Path)	1,546.947	541,678,944	2.323
                                    org.apache.hadoop.hdfs.DistributedFileSystem$41.doCall(Path)	1,546.947	541,678,944	2.323
                                       org.apache.hadoop.hdfs.DistributedFileSystem$41.doCall(Path)	1,546.947	541,678,944	2.323
                                          org.apache.hadoop.hdfs.DFSClient.getAclStatus(String)	1,675.657	506,929,328	2.174
                                             com.sun.proxy.$Proxy14.getAclStatus(String)	1,770.424	468,924,760	2.011
                                                org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(Object, Method, Object[])	1,770.424	468,924,760	2.011
                                                   org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(Method, Object[])	2,236	373,004,328	1.6
                                                      java.lang.reflect.Method.invoke(Object, Object[])	2,236	373,004,328	1.6
                                                         sun.reflect.DelegatingMethodAccessorImpl.invoke(Object, Object[])	2,236	373,004,328	1.6
                                                            sun.reflect.GeneratedMethodAccessor11.invoke(Object, Object[])	2,236	373,004,328	1.6
                                                               org.apache.hadoop.hdfs.protocolPB.ClientNamenodeProtocolTranslatorPB.getAclStatus(String)	2,236	373,004,328	1.6
                                                                  com.sun.proxy.$Proxy13.getAclStatus(RpcController, AclProtos$GetAclStatusRequestProto)	2,236	373,004,328	1.6
                                                                     org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(Object, Method, Object[])	2,236	373,004,328	1.6
                                                                        com.google.protobuf.ServiceException.<init>(Throwable)	2,514.783	338,254,552	1.451
                                                                           java.lang.Exception.<init>(Throwable)	2,514.783	338,254,552	1.451
                                                                              java.lang.Throwable.<init>(Throwable)	2,514.783	338,254,552	1.451
                                                                                 org.apache.hadoop.ipc.RemoteException.toString()	2,746.667	315,088,072	1.351
                                                                                    java.lang.StringBuilder.toString()	3,016	181,142,096	0.777
                                                                                       java.lang.String.<init>(char[], int, int)	3,016	181,142,096	0.777
                                                                                          java.util.Arrays.copyOfRange(char[], int, int)	3,016	181,142,096	0.777
                                                                                    java.lang.StringBuilder.append(String)	2,680	122,362,768	0.525
                                                                                       java.lang.AbstractStringBuilder.append(String)	2,680	122,362,768	0.525
                                                                                          java.lang.AbstractStringBuilder.ensureCapacityInternal(int)	2,680	122,362,768	0.525
                                                                                             java.lang.AbstractStringBuilder.expandCapacity(int)	2,680	122,362,768	0.525
                                                                                                java.util.Arrays.copyOf(char[], int)	2,680	122,362,768	0.525

Query timeline with ACLs enabled

 Query Timeline: 30m55s
       - Start execution: 118.666us (118.666us)
       - Planning finished: 29m8s (29m8s)

Query timeline with ACLs disable

    Query Timeline: 36m53s
       - Start execution: 116.024us (116.024us)
       - Planning finished: 34m46s (34m46s)

Issue Links

• is related to: IMPALA-5420 Check If HDFS ACLs are enabled before trying to get the ACLs