Support Questions
Find answers, ask questions, and share your expertise

Ambari services are not comming up after kerberos enable

Ambari services are not comming up after kerberos enable

Explorer

Hi All,

After enabling kerberos Ambari services are not comming up .Only zookeeper service comming up and going down as all other services fails. its able to regenerate key tab and successfully stop services but fails to start services.

Caused by: KrbException: Identifier doesn't match expected value (906)

log file attached below :

stderr: Traceback (most recent call last): File "/var/lib/ambari-agent/cache/common-services/HDFS/2.1.0.2.0/package/scripts/datanode.py", line 177, in <module> DataNode().execute() File "/usr/lib/python2.6/site-packages/resource_management/libraries/script/script.py", line 314, in execute method(env) File "/var/lib/ambari-agent/cache/common-services/HDFS/2.1.0.2.0/package/scripts/datanode.py", line 64, in start datanode(action="start") File "/usr/lib/python2.6/site-packages/ambari_commons/os_family_impl.py", line 89, in thunk return fn(*args, **kwargs) File "/var/lib/ambari-agent/cache/common-services/HDFS/2.1.0.2.0/package/scripts/hdfs_datanode.py", line 68, in datanode create_log_dir=True File "/var/lib/ambari-agent/cache/common-services/HDFS/2.1.0.2.0/package/scripts/utils.py", line 271, in service Execute(daemon_cmd, not_if=process_id_exists_command, environment=hadoop_env_exports) File "/usr/lib/python2.6/site-packages/resource_management/core/base.py", line 155, in __init__ self.env.run() File "/usr/lib/python2.6/site-packages/resource_management/core/environment.py", line 160, in run self.run_action(resource, action) File "/usr/lib/python2.6/site-packages/resource_management/core/environment.py", line 124, in run_action provider_action() File "/usr/lib/python2.6/site-packages/resource_management/core/providers/system.py", line 262, in action_run tries=self.resource.tries, try_sleep=self.resource.try_sleep) File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 72, in inner result = function(command, **kwargs) File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 102, in checked_call tries=tries, try_sleep=try_sleep, timeout_kill_strategy=timeout_kill_strategy) File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 150, in _call_wrapper result = _call(command, **kwargs_copy) File "/usr/lib/python2.6/site-packages/resource_management/core/shell.py", line 303, in _call raise ExecutionFailed(err_msg, code, out, err) resource_management.core.exceptions.ExecutionFailed: Execution of 'ambari-sudo.sh -H -E /usr/hdp/current/hadoop-client/sbin/hadoop-daemon.sh --config /usr/hdp/current/hadoop-client/conf start datanode' returned 1. starting datanode, logging to /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out stdout: 2017-11-15 16:09:32,516 - Using hadoop conf dir: /usr/hdp/current/hadoop-client/conf 2017-11-15 16:09:32,619 - Stack Feature Version Info: stack_version=2.5, version=2.5.5.0-157, current_cluster_version=2.5.5.0-157 -> 2.5.5.0-157 2017-11-15 16:09:32,620 - Using hadoop conf dir: /usr/hdp/current/hadoop-client/conf User Group mapping (user_group) is missing in the hostLevelParams 2017-11-15 16:09:32,621 - Group['livy'] {} 2017-11-15 16:09:32,622 - Group['spark'] {} 2017-11-15 16:09:32,622 - Group['hadoop'] {} 2017-11-15 16:09:32,622 - Group['users'] {} 2017-11-15 16:09:32,622 - Group['knox'] {} 2017-11-15 16:09:32,623 - User['hive'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,623 - User['storm'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,624 - User['zookeeper'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,624 - User['infra-solr'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,625 - User['ams'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,625 - User['tez'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['users']} 2017-11-15 16:09:32,626 - User['livy'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,626 - User['spark'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,627 - User['ambari-qa'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['users']} 2017-11-15 16:09:32,627 - User['hdfs'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,628 - User['sqoop'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,628 - User['yarn'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,629 - User['mapred'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,629 - User['hbase'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,630 - User['knox'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,630 - User['hcat'] {'gid': 'hadoop', 'fetch_nonlocal_groups': True, 'groups': ['hadoop']} 2017-11-15 16:09:32,631 - File['/var/lib/ambari-agent/tmp/changeUid.sh'] {'content': StaticFile('changeToSecureUid.sh'), 'mode': 0555} 2017-11-15 16:09:32,632 - Execute['/var/lib/ambari-agent/tmp/changeUid.sh ambari-qa /tmp/hadoop-ambari-qa,/tmp/hsperfdata_ambari-qa,/home/ambari-qa,/tmp/ambari-qa,/tmp/sqoop-ambari-qa'] {'not_if': '(test $(id -u ambari-qa) -gt 1000) || (false)'} 2017-11-15 16:09:32,635 - Skipping Execute['/var/lib/ambari-agent/tmp/changeUid.sh ambari-qa /tmp/hadoop-ambari-qa,/tmp/hsperfdata_ambari-qa,/home/ambari-qa,/tmp/ambari-qa,/tmp/sqoop-ambari-qa'] due to not_if 2017-11-15 16:09:32,636 - Directory['/tmp/hbase-hbase'] {'owner': 'hbase', 'create_parents': True, 'mode': 0775, 'cd_access': 'a'} 2017-11-15 16:09:32,636 - File['/var/lib/ambari-agent/tmp/changeUid.sh'] {'content': StaticFile('changeToSecureUid.sh'), 'mode': 0555} 2017-11-15 16:09:32,637 - Execute['/var/lib/ambari-agent/tmp/changeUid.sh hbase /home/hbase,/tmp/hbase,/usr/bin/hbase,/var/log/hbase,/tmp/hbase-hbase'] {'not_if': '(test $(id -u hbase) -gt 1000) || (false)'} 2017-11-15 16:09:32,641 - Skipping Execute['/var/lib/ambari-agent/tmp/changeUid.sh hbase /home/hbase,/tmp/hbase,/usr/bin/hbase,/var/log/hbase,/tmp/hbase-hbase'] due to not_if 2017-11-15 16:09:32,643 - Group['hdfs'] {} 2017-11-15 16:09:32,643 - User['hdfs'] {'fetch_nonlocal_groups': True, 'groups': ['hadoop', 'hdfs']} 2017-11-15 16:09:32,644 - FS Type: 2017-11-15 16:09:32,644 - Directory['/etc/hadoop'] {'mode': 0755} 2017-11-15 16:09:32,656 - File['/usr/hdp/current/hadoop-client/conf/hadoop-env.sh'] {'content': InlineTemplate(...), 'owner': 'root', 'group': 'hadoop'} 2017-11-15 16:09:32,656 - Directory['/var/lib/ambari-agent/tmp/hadoop_java_io_tmpdir'] {'owner': 'hdfs', 'group': 'hadoop', 'mode': 01777} 2017-11-15 16:09:32,667 - Execute[('setenforce', '0')] {'not_if': '(! which getenforce ) || (which getenforce && getenforce | grep -q Disabled)', 'sudo': True, 'only_if': 'test -f /selinux/enforce'} 2017-11-15 16:09:32,672 - Skipping Execute[('setenforce', '0')] due to not_if 2017-11-15 16:09:32,672 - Directory['/var/log/hadoop'] {'owner': 'root', 'create_parents': True, 'group': 'hadoop', 'mode': 0775, 'cd_access': 'a'} 2017-11-15 16:09:32,674 - Directory['/var/run/hadoop'] {'owner': 'root', 'create_parents': True, 'group': 'root', 'cd_access': 'a'} 2017-11-15 16:09:32,674 - Directory['/tmp/hadoop-hdfs'] {'owner': 'hdfs', 'create_parents': True, 'cd_access': 'a'} 2017-11-15 16:09:32,678 - File['/usr/hdp/current/hadoop-client/conf/commons-logging.properties'] {'content': Template('commons-logging.properties.j2'), 'owner': 'root'} 2017-11-15 16:09:32,679 - File['/usr/hdp/current/hadoop-client/conf/health_check'] {'content': Template('health_check.j2'), 'owner': 'root'} 2017-11-15 16:09:32,685 - File['/usr/hdp/current/hadoop-client/conf/log4j.properties'] {'content': InlineTemplate(...), 'owner': 'hdfs', 'group': 'hadoop', 'mode': 0644} 2017-11-15 16:09:32,694 - File['/usr/hdp/current/hadoop-client/conf/hadoop-metrics2.properties'] {'content': Template('hadoop-metrics2.properties.j2'), 'owner': 'hdfs', 'group': 'hadoop'} 2017-11-15 16:09:32,694 - File['/usr/hdp/current/hadoop-client/conf/task-log4j.properties'] {'content': StaticFile('task-log4j.properties'), 'mode': 0755} 2017-11-15 16:09:32,695 - File['/usr/hdp/current/hadoop-client/conf/configuration.xsl'] {'owner': 'hdfs', 'group': 'hadoop'} 2017-11-15 16:09:32,699 - File['/etc/hadoop/conf/topology_mappings.data'] {'owner': 'hdfs', 'content': Template('topology_mappings.data.j2'), 'only_if': 'test -d /etc/hadoop/conf', 'group': 'hadoop'} 2017-11-15 16:09:32,702 - File['/etc/hadoop/conf/topology_script.py'] {'content': StaticFile('topology_script.py'), 'only_if': 'test -d /etc/hadoop/conf', 'mode': 0755} 2017-11-15 16:09:32,704 - Testing the JVM's JCE policy to see it if supports an unlimited key length. 2017-11-15 16:09:32,705 - Execute['/usr/jdk64/jdk1.8.0_112/bin/java -jar /var/lib/ambari-agent/tools/jcepolicyinfo.jar -tu'] {'logoutput': True, 'environment': {'JAVA_HOME': '/usr/jdk64/jdk1.8.0_112'}} Unlimited Key JCE Policy: true 2017-11-15 16:09:32,873 - The unlimited key JCE policy is required, and appears to have been installed. 2017-11-15 16:09:33,035 - Using hadoop conf dir: /usr/hdp/current/hadoop-client/conf 2017-11-15 16:09:33,039 - Stack Feature Version Info: stack_version=2.5, version=2.5.5.0-157, current_cluster_version=2.5.5.0-157 -> 2.5.5.0-157 2017-11-15 16:09:33,041 - Using hadoop conf dir: /usr/hdp/current/hadoop-client/conf 2017-11-15 16:09:33,047 - checked_call['rpm -q --queryformat '%{version}-%{release}' hdp-select | sed -e 's/\.el[0-9]//g''] {'stderr': -1} 2017-11-15 16:09:33,079 - checked_call returned (0, '2.5.5.0-157', '') 2017-11-15 16:09:33,083 - Directory['/etc/security/limits.d'] {'owner': 'root', 'create_parents': True, 'group': 'root'} 2017-11-15 16:09:33,088 - File['/etc/security/limits.d/hdfs.conf'] {'content': Template('hdfs.conf.j2'), 'owner': 'root', 'group': 'root', 'mode': 0644} 2017-11-15 16:09:33,089 - XmlConfig['hadoop-policy.xml'] {'owner': 'hdfs', 'group': 'hadoop', 'conf_dir': '/usr/hdp/current/hadoop-client/conf', 'configuration_attributes': {}, 'configurations': ...} 2017-11-15 16:09:33,097 - Generating config: /usr/hdp/current/hadoop-client/conf/hadoop-policy.xml 2017-11-15 16:09:33,097 - File['/usr/hdp/current/hadoop-client/conf/hadoop-policy.xml'] {'owner': 'hdfs', 'content': InlineTemplate(...), 'group': 'hadoop', 'mode': None, 'encoding': 'UTF-8'} 2017-11-15 16:09:33,105 - XmlConfig['ssl-client.xml'] {'owner': 'hdfs', 'group': 'hadoop', 'conf_dir': '/usr/hdp/current/hadoop-client/conf', 'configuration_attributes': {}, 'configurations': ...} 2017-11-15 16:09:33,112 - Generating config: /usr/hdp/current/hadoop-client/conf/ssl-client.xml 2017-11-15 16:09:33,113 - File['/usr/hdp/current/hadoop-client/conf/ssl-client.xml'] {'owner': 'hdfs', 'content': InlineTemplate(...), 'group': 'hadoop', 'mode': None, 'encoding': 'UTF-8'} 2017-11-15 16:09:33,118 - Directory['/usr/hdp/current/hadoop-client/conf/secure'] {'owner': 'root', 'create_parents': True, 'group': 'hadoop', 'cd_access': 'a'} 2017-11-15 16:09:33,119 - XmlConfig['ssl-client.xml'] {'owner': 'hdfs', 'group': 'hadoop', 'conf_dir': '/usr/hdp/current/hadoop-client/conf/secure', 'configuration_attributes': {}, 'configurations': ...} 2017-11-15 16:09:33,125 - Generating config: /usr/hdp/current/hadoop-client/conf/secure/ssl-client.xml 2017-11-15 16:09:33,126 - File['/usr/hdp/current/hadoop-client/conf/secure/ssl-client.xml'] {'owner': 'hdfs', 'content': InlineTemplate(...), 'group': 'hadoop', 'mode': None, 'encoding': 'UTF-8'} 2017-11-15 16:09:33,131 - XmlConfig['ssl-server.xml'] {'owner': 'hdfs', 'group': 'hadoop', 'conf_dir': '/usr/hdp/current/hadoop-client/conf', 'configuration_attributes': {}, 'configurations': ...} 2017-11-15 16:09:33,137 - Generating config: /usr/hdp/current/hadoop-client/conf/ssl-server.xml 2017-11-15 16:09:33,138 - File['/usr/hdp/current/hadoop-client/conf/ssl-server.xml'] {'owner': 'hdfs', 'content': InlineTemplate(...), 'group': 'hadoop', 'mode': None, 'encoding': 'UTF-8'} 2017-11-15 16:09:33,144 - XmlConfig['hdfs-site.xml'] {'owner': 'hdfs', 'group': 'hadoop', 'conf_dir': '/usr/hdp/current/hadoop-client/conf', 'configuration_attributes': {'final': {'dfs.support.append': 'true', 'dfs.datanode.data.dir': 'true', 'dfs.namenode.http-address': 'true', 'dfs.namenode.name.dir': 'true', 'dfs.webhdfs.enabled': 'true', 'dfs.datanode.failed.volumes.tolerated': 'true'}}, 'configurations': ...} 2017-11-15 16:09:33,151 - Generating config: /usr/hdp/current/hadoop-client/conf/hdfs-site.xml 2017-11-15 16:09:33,151 - File['/usr/hdp/current/hadoop-client/conf/hdfs-site.xml'] {'owner': 'hdfs', 'content': InlineTemplate(...), 'group': 'hadoop', 'mode': None, 'encoding': 'UTF-8'} 2017-11-15 16:09:33,195 - XmlConfig['core-site.xml'] {'group': 'hadoop', 'conf_dir': '/usr/hdp/current/hadoop-client/conf', 'mode': 0644, 'configuration_attributes': {'final': {'fs.defaultFS': 'true'}}, 'owner': 'hdfs', 'configurations': ...} 2017-11-15 16:09:33,203 - Generating config: /usr/hdp/current/hadoop-client/conf/core-site.xml 2017-11-15 16:09:33,203 - File['/usr/hdp/current/hadoop-client/conf/core-site.xml'] {'owner': 'hdfs', 'content': InlineTemplate(...), 'group': 'hadoop', 'mode': 0644, 'encoding': 'UTF-8'} 2017-11-15 16:09:33,226 - File['/usr/hdp/current/hadoop-client/conf/slaves'] {'content': Template('slaves.j2'), 'owner': 'root'} 2017-11-15 16:09:33,227 - Directory['/var/lib/hadoop-hdfs'] {'owner': 'hdfs', 'create_parents': True, 'group': 'hadoop', 'mode': 0751} 2017-11-15 16:09:33,227 - Directory['/var/lib/ambari-agent/data/datanode'] {'create_parents': True, 'mode': 0755} 2017-11-15 16:09:33,230 - Host contains mounts: ['/', '/proc', '/sys', '/dev/pts', '/dev/shm', '/tmp', '/datanode1', '/datanode2', '/proc/sys/fs/binfmt_misc']. 2017-11-15 16:09:33,230 - Mount point for directory /datanode1 is /datanode1 2017-11-15 16:09:33,230 - Mount point for directory /datanode2 is /datanode2 2017-11-15 16:09:33,230 - Mount point for directory /datanode1 is /datanode1 2017-11-15 16:09:33,230 - Forcefully ensuring existence and permissions of the directory: /datanode1 2017-11-15 16:09:33,231 - Directory['/datanode1'] {'group': 'hadoop', 'cd_access': 'a', 'create_parents': True, 'ignore_failures': True, 'mode': 0755, 'owner': 'hdfs'} 2017-11-15 16:09:33,231 - Mount point for directory /datanode2 is /datanode2 2017-11-15 16:09:33,231 - Forcefully ensuring existence and permissions of the directory: /datanode2 2017-11-15 16:09:33,231 - Directory['/datanode2'] {'group': 'hadoop', 'cd_access': 'a', 'create_parents': True, 'ignore_failures': True, 'mode': 0755, 'owner': 'hdfs'} 2017-11-15 16:09:33,234 - Host contains mounts: ['/', '/proc', '/sys', '/dev/pts', '/dev/shm', '/tmp', '/datanode1', '/datanode2', '/proc/sys/fs/binfmt_misc']. 2017-11-15 16:09:33,234 - Mount point for directory /datanode1 is /datanode1 2017-11-15 16:09:33,234 - Mount point for directory /datanode2 is /datanode2 2017-11-15 16:09:33,235 - File['/var/lib/ambari-agent/data/datanode/dfs_data_dir_mount.hist'] {'content': '\n# This file keeps track of the last known mount-point for each dir.\n# It is safe to delete, since it will get regenerated the next time that the component of the service starts.\n# However, it is not advised to delete this file since Ambari may\n# re-create a dir that used to be mounted on a drive but is now mounted on the root.\n# Comments begin with a hash (#) symbol\n# dir,mount_point\n/datanode2,/datanode2\n/datanode1,/datanode1\n', 'owner': 'hdfs', 'group': 'hadoop', 'mode': 0644} 2017-11-15 16:09:33,236 - Directory['/var/run/hadoop'] {'owner': 'hdfs', 'group': 'hadoop', 'mode': 0755} 2017-11-15 16:09:33,236 - Changing owner for /var/run/hadoop from 0 to hdfs 2017-11-15 16:09:33,236 - Changing group for /var/run/hadoop from 0 to hadoop 2017-11-15 16:09:33,237 - Directory['/var/run/hadoop/hdfs'] {'owner': 'hdfs', 'group': 'hadoop', 'create_parents': True} 2017-11-15 16:09:33,237 - Directory['/var/log/hadoop/hdfs'] {'owner': 'hdfs', 'group': 'hadoop', 'create_parents': True} 2017-11-15 16:09:33,238 - File['/var/run/hadoop/hdfs/hadoop-hdfs-datanode.pid'] {'action': ['delete'], 'not_if': 'ambari-sudo.sh -H -E test -f /var/run/hadoop/hdfs/hadoop-hdfs-datanode.pid && ambari-sudo.sh -H -E pgrep -F /var/run/hadoop/hdfs/hadoop-hdfs-datanode.pid'} 2017-11-15 16:09:33,248 - Deleting File['/var/run/hadoop/hdfs/hadoop-hdfs-datanode.pid'] 2017-11-15 16:09:33,248 - Execute['ambari-sudo.sh -H -E /usr/hdp/current/hadoop-client/sbin/hadoop-daemon.sh --config /usr/hdp/current/hadoop-client/conf start datanode'] {'environment': {'HADOOP_LIBEXEC_DIR': '/usr/hdp/current/hadoop-client/libexec'}, 'not_if': 'ambari-sudo.sh -H -E test -f /var/run/hadoop/hdfs/hadoop-hdfs-datanode.pid && ambari-sudo.sh -H -E pgrep -F /var/run/hadoop/hdfs/hadoop-hdfs-datanode.pid'} 2017-11-15 16:09:37,296 - Execute['find /var/log/hadoop/hdfs -maxdepth 1 -type f -name '*' -exec echo '==> {} <==' \; -exec tail -n 40 {} \;'] {'logoutput': True, 'ignore_failures': True, 'user': 'root'} ==> /var/log/hadoop/hdfs/gc.log-201711151019 <== Java HotSpot(TM) 64-Bit Server VM (25.112-b15) for linux-amd64 JRE (1.8.0_112-b15), built on Sep 22 2016 21:10:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8) Memory: 4k page, physical 66093268k(62720916k free), swap 8388604k(8388604k free) CommandLine flags: -XX:CMSInitiatingOccupancyFraction=70 -XX:ErrorFile=/var/log/hadoop/hdfs/hs_err_pid%p.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=209715200 -XX:MaxTenuringThreshold=6 -XX:NewSize=209715200 -XX:OldPLABSize=16 -XX:ParallelGCThreads=4 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2017-11-15T10:19:03.555+0000: 1.286: [GC (Allocation Failure) 2017-11-15T10:19:03.555+0000: 1.286: [ParNew: 163840K->13709K(184320K), 0.0097530 secs] 163840K->13709K(1028096K), 0.0098261 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-11-15T10:19:05.565+0000: 3.296: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(843776K)] 142966K(1028096K), 0.0094206 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-11-15T10:19:05.574+0000: 3.306: [CMS-concurrent-mark-start] 2017-11-15T10:19:05.582+0000: 3.314: [CMS-concurrent-mark: 0.008/0.008 secs] [Times: user=0.00 sys=0.01, real=0.01 secs] 2017-11-15T10:19:05.582+0000: 3.314: [CMS-concurrent-preclean-start] 2017-11-15T10:19:05.584+0000: 3.315: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:19:05.584+0000: 3.315: [CMS-concurrent-abortable-preclean-start] Heap par new generation total 184320K, used 144604K [0x00000000c0000000, 0x00000000cc800000, 0x00000000cc800000) eden space 163840K, 79% used [0x00000000c0000000, 0x00000000c7fd3fb0, 0x00000000ca000000) from space 20480K, 66% used [0x00000000cb400000, 0x00000000cc163438, 0x00000000cc800000) to space 20480K, 0% used [0x00000000ca000000, 0x00000000ca000000, 0x00000000cb400000) concurrent mark-sweep generation total 843776K, used 0K [0x00000000cc800000, 0x0000000100000000, 0x0000000100000000) Metaspace used 26596K, capacity 26956K, committed 27272K, reserved 1073152K class space used 3219K, capacity 3328K, committed 3376K, reserved 1048576K ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out.2 <== ulimit -a for secure datanode user hdfs core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 257533 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 128000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 65536 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited ==> /var/log/hadoop/hdfs/gc.log-201711151030 <== Java HotSpot(TM) 64-Bit Server VM (25.112-b15) for linux-amd64 JRE (1.8.0_112-b15), built on Sep 22 2016 21:10:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8) Memory: 4k page, physical 66093268k(60902568k free), swap 8388604k(8388604k free) CommandLine flags: -XX:CMSInitiatingOccupancyFraction=70 -XX:ErrorFile=/var/log/hadoop/hdfs/hs_err_pid%p.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=209715200 -XX:MaxTenuringThreshold=6 -XX:NewSize=209715200 -XX:OldPLABSize=16 -XX:ParallelGCThreads=4 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2017-11-15T10:30:51.116+0000: 1.326: [GC (Allocation Failure) 2017-11-15T10:30:51.116+0000: 1.326: [ParNew: 163840K->13675K(184320K), 0.0099165 secs] 163840K->13675K(1028096K), 0.0099936 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-11-15T10:30:53.126+0000: 3.335: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(843776K)] 143623K(1028096K), 0.0094666 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-11-15T10:30:53.135+0000: 3.345: [CMS-concurrent-mark-start] 2017-11-15T10:30:53.144+0000: 3.353: [CMS-concurrent-mark: 0.008/0.008 secs] [Times: user=0.01 sys=0.01, real=0.01 secs] 2017-11-15T10:30:53.144+0000: 3.353: [CMS-concurrent-preclean-start] 2017-11-15T10:30:53.145+0000: 3.355: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:30:53.145+0000: 3.355: [CMS-concurrent-abortable-preclean-start] Heap par new generation total 184320K, used 145262K [0x00000000c0000000, 0x00000000cc800000, 0x00000000cc800000) eden space 163840K, 80% used [0x00000000c0000000, 0x00000000c8080a78, 0x00000000ca000000) from space 20480K, 66% used [0x00000000cb400000, 0x00000000cc15adb0, 0x00000000cc800000) to space 20480K, 0% used [0x00000000ca000000, 0x00000000ca000000, 0x00000000cb400000) concurrent mark-sweep generation total 843776K, used 0K [0x00000000cc800000, 0x0000000100000000, 0x0000000100000000) Metaspace used 26598K, capacity 26956K, committed 27272K, reserved 1073152K class space used 3219K, capacity 3328K, committed 3376K, reserved 1048576K ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out.1 <== ulimit -a for secure datanode user hdfs core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 257533 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 128000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 65536 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited ==> /var/log/hadoop/hdfs/gc.log-201711151021 <== Java HotSpot(TM) 64-Bit Server VM (25.112-b15) for linux-amd64 JRE (1.8.0_112-b15), built on Sep 22 2016 21:10:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8) Memory: 4k page, physical 66093268k(61788236k free), swap 8388604k(8388604k free) CommandLine flags: -XX:CMSInitiatingOccupancyFraction=70 -XX:ErrorFile=/var/log/hadoop/hdfs/hs_err_pid%p.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=209715200 -XX:MaxTenuringThreshold=6 -XX:NewSize=209715200 -XX:OldPLABSize=16 -XX:ParallelGCThreads=4 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2017-11-15T10:21:21.831+0000: 1.306: [GC (Allocation Failure) 2017-11-15T10:21:21.831+0000: 1.306: [ParNew: 163840K->13669K(184320K), 0.0111553 secs] 163840K->13669K(1028096K), 0.0112318 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-11-15T10:21:23.842+0000: 3.317: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(843776K)] 155282K(1028096K), 0.0111901 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-11-15T10:21:23.854+0000: 3.329: [CMS-concurrent-mark-start] 2017-11-15T10:21:23.861+0000: 3.336: [CMS-concurrent-mark: 0.008/0.008 secs] [Times: user=0.01 sys=0.01, real=0.01 secs] 2017-11-15T10:21:23.861+0000: 3.336: [CMS-concurrent-preclean-start] 2017-11-15T10:21:23.863+0000: 3.338: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:21:23.863+0000: 3.338: [CMS-concurrent-abortable-preclean-start] Heap par new generation total 184320K, used 156921K [0x00000000c0000000, 0x00000000cc800000, 0x00000000cc800000) eden space 163840K, 87% used [0x00000000c0000000, 0x00000000c8be4c88, 0x00000000ca000000) from space 20480K, 66% used [0x00000000cb400000, 0x00000000cc1597b8, 0x00000000cc800000) to space 20480K, 0% used [0x00000000ca000000, 0x00000000ca000000, 0x00000000cb400000) concurrent mark-sweep generation total 843776K, used 0K [0x00000000cc800000, 0x0000000100000000, 0x0000000100000000) Metaspace used 27715K, capacity 28012K, committed 28268K, reserved 1075200K class space used 3340K, capacity 3424K, committed 3504K, reserved 1048576K ==> /var/log/hadoop/hdfs/jsvc.out <== ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out.4 <== ulimit -a for user hdfs core file size (blocks, -c) unlimited data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 257533 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 128000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 65536 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited ==> /var/log/hadoop/hdfs/hdfs-audit.log <== ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out.3 <== SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. g signals (-i) 257533 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 128000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 65536 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.log <== at org.apache.hadoop.hdfs.server.datanode.DataNode.secureMain(DataNode.java:2671) at org.apache.hadoop.hdfs.server.datanode.SecureDataNodeStarter.start(SecureDataNodeStarter.java:77) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.commons.daemon.support.DaemonLoader.start(DaemonLoader.java:243) Caused by: javax.security.auth.login.LoginException: Pre-authentication information was invalid (24) at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:804) at com.sun.security.auth.module.Krb5LoginModule.login(Krb5LoginModule.java:617) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755) at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680) at javax.security.auth.login.LoginContext.login(LoginContext.java:587) at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytab(UserGroupInformation.java:1088) ... 10 more Caused by: KrbException: Pre-authentication information was invalid (24) at sun.security.krb5.KrbAsRep.<init>(KrbAsRep.java:76) at sun.security.krb5.KrbAsReqBuilder.send(KrbAsReqBuilder.java:316) at sun.security.krb5.KrbAsReqBuilder.action(KrbAsReqBuilder.java:361) at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:776) ... 23 more Caused by: KrbException: Identifier doesn't match expected value (906) at sun.security.krb5.internal.KDCRep.init(KDCRep.java:140) at sun.security.krb5.internal.ASRep.init(ASRep.java:64) at sun.security.krb5.internal.ASRep.<init>(ASRep.java:59) at sun.security.krb5.KrbAsRep.<init>(KrbAsRep.java:60) ... 26 more 2017-11-15 16:09:34,310 INFO util.ExitUtil (ExitUtil.java:terminate(124)) - Exiting with status 1 2017-11-15 16:09:34,312 INFO datanode.DataNode (LogAdapter.java:info(47)) - SHUTDOWN_MSG: /************************************************************ SHUTDOWN_MSG: Shutting down DataNode at ip-192-168-0-37.eu-west-1.compute.internal/192.168.0.37 ************************************************************/ ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out <== ulimit -a for secure datanode user hdfs core file size (blocks, -c) 0 data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 257533 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 128000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 65536 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited ==> /var/log/hadoop/hdfs/gc.log-201711151025 <== Java HotSpot(TM) 64-Bit Server VM (25.112-b15) for linux-amd64 JRE (1.8.0_112-b15), built on Sep 22 2016 21:10:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8) Memory: 4k page, physical 66093268k(61757988k free), swap 8388604k(8388604k free) CommandLine flags: -XX:CMSInitiatingOccupancyFraction=70 -XX:ErrorFile=/var/log/hadoop/hdfs/hs_err_pid%p.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=209715200 -XX:MaxTenuringThreshold=6 -XX:NewSize=209715200 -XX:OldPLABSize=16 -XX:ParallelGCThreads=4 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2017-11-15T10:25:43.400+0000: 1.336: [GC (Allocation Failure) 2017-11-15T10:25:43.400+0000: 1.336: [ParNew: 163840K->13681K(184320K), 0.0131699 secs] 163840K->13681K(1028096K), 0.0132582 secs] [Times: user=0.05 sys=0.01, real=0.02 secs] 2017-11-15T10:25:45.413+0000: 3.348: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(843776K)] 142884K(1028096K), 0.0126406 secs] [Times: user=0.05 sys=0.00, real=0.01 secs] 2017-11-15T10:25:45.425+0000: 3.361: [CMS-concurrent-mark-start] 2017-11-15T10:25:45.433+0000: 3.369: [CMS-concurrent-mark: 0.008/0.008 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2017-11-15T10:25:45.433+0000: 3.369: [CMS-concurrent-preclean-start] 2017-11-15T10:25:45.435+0000: 3.370: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:25:45.435+0000: 3.370: [CMS-concurrent-abortable-preclean-start] Heap par new generation total 184320K, used 147472K [0x00000000c0000000, 0x00000000cc800000, 0x00000000cc800000) eden space 163840K, 81% used [0x00000000c0000000, 0x00000000c82a78b8, 0x00000000ca000000) from space 20480K, 66% used [0x00000000cb400000, 0x00000000cc15c770, 0x00000000cc800000) to space 20480K, 0% used [0x00000000ca000000, 0x00000000ca000000, 0x00000000cb400000) concurrent mark-sweep generation total 843776K, used 0K [0x00000000cc800000, 0x0000000100000000, 0x0000000100000000) Metaspace used 26588K, capacity 26892K, committed 27272K, reserved 1073152K class space used 3218K, capacity 3328K, committed 3376K, reserved 1048576K ==> /var/log/hadoop/hdfs/gc.log-201711151015 <== Java HotSpot(TM) 64-Bit Server VM (25.112-b15) for linux-amd64 JRE (1.8.0_112-b15), built on Sep 22 2016 21:10:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8) Memory: 4k page, physical 66093268k(62723240k free), swap 8388604k(8388604k free) CommandLine flags: -XX:CMSInitiatingOccupancyFraction=70 -XX:ErrorFile=/var/log/hadoop/hdfs/hs_err_pid%p.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=209715200 -XX:MaxTenuringThreshold=6 -XX:NewSize=209715200 -XX:OldPLABSize=16 -XX:ParallelGCThreads=4 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2017-11-15T10:15:34.350+0000: 1.611: [GC (Allocation Failure) 2017-11-15T10:15:34.350+0000: 1.611: [ParNew: 163840K->13715K(184320K), 0.0101096 secs] 163840K->13715K(1028096K), 0.0101994 secs] [Times: user=0.03 sys=0.01, real=0.01 secs] 2017-11-15T10:15:36.360+0000: 3.621: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(843776K)] 132237K(1028096K), 0.0085585 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-11-15T10:15:36.369+0000: 3.630: [CMS-concurrent-mark-start] 2017-11-15T10:15:36.377+0000: 3.638: [CMS-concurrent-mark: 0.008/0.008 secs] [Times: user=0.00 sys=0.01, real=0.00 secs] 2017-11-15T10:15:36.377+0000: 3.638: [CMS-concurrent-preclean-start] 2017-11-15T10:15:36.378+0000: 3.639: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 2017-11-15T10:15:36.378+0000: 3.639: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 2017-11-15T10:15:41.402+0000: 8.664: [CMS-concurrent-abortable-preclean: 1.359/5.024 secs] [Times: user=1.55 sys=0.00, real=5.02 secs] 2017-11-15T10:15:41.403+0000: 8.664: [GC (CMS Final Remark) [YG occupancy: 142997 K (184320 K)]2017-11-15T10:15:41.403+0000: 8.664: [Rescan (parallel) , 0.0089383 secs]2017-11-15T10:15:41.412+0000: 8.673: [weak refs processing, 0.0000171 secs]2017-11-15T10:15:41.412+0000: 8.673: [class unloading, 0.0031303 secs]2017-11-15T10:15:41.415+0000: 8.676: [scrub symbol table, 0.0022981 secs]2017-11-15T10:15:41.417+0000: 8.678: [scrub string table, 0.0004424 secs][1 CMS-remark: 0K(843776K)] 142997K(1028096K), 0.0153866 secs] [Times: user=0.04 sys=0.00, real=0.02 secs] 2017-11-15T10:15:41.418+0000: 8.679: [CMS-concurrent-sweep-start] 2017-11-15T10:15:41.418+0000: 8.679: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:15:41.418+0000: 8.679: [CMS-concurrent-reset-start] 2017-11-15T10:15:41.420+0000: 8.681: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] Heap par new generation total 184320K, used 144635K [0x00000000c0000000, 0x00000000cc800000, 0x00000000cc800000) eden space 163840K, 79% used [0x00000000c0000000, 0x00000000c7fda088, 0x00000000ca000000) from space 20480K, 66% used [0x00000000cb400000, 0x00000000cc164e00, 0x00000000cc800000) to space 20480K, 0% used [0x00000000ca000000, 0x00000000ca000000, 0x00000000cb400000) concurrent mark-sweep generation total 843776K, used 0K [0x00000000cc800000, 0x0000000100000000, 0x0000000100000000) Metaspace used 26591K, capacity 26892K, committed 27272K, reserved 1073152K class space used 3221K, capacity 3328K, committed 3376K, reserved 1048576K ==> /var/log/hadoop/hdfs/gc.log-201711151057 <== Java HotSpot(TM) 64-Bit Server VM (25.112-b15) for linux-amd64 JRE (1.8.0_112-b15), built on Sep 22 2016 21:10:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8) Memory: 4k page, physical 66093268k(60441804k free), swap 8388604k(8388604k free) CommandLine flags: -XX:CMSInitiatingOccupancyFraction=70 -XX:ErrorFile=/var/log/hadoop/hdfs/hs_err_pid%p.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=209715200 -XX:MaxTenuringThreshold=6 -XX:NewSize=209715200 -XX:OldPLABSize=16 -XX:ParallelGCThreads=4 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 2017-11-15T10:57:48.921+0000: 1.284: [GC (Allocation Failure) 2017-11-15T10:57:48.921+0000: 1.284: [ParNew: 163840K->13679K(184320K), 0.0097478 secs] 163840K->13679K(1028096K), 0.0098245 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-11-15T10:57:50.930+0000: 3.293: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(843776K)] 175294K(1028096K), 0.0115010 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-11-15T10:57:50.942+0000: 3.304: [CMS-concurrent-mark-start] 2017-11-15T10:57:50.950+0000: 3.312: [CMS-concurrent-mark: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 2017-11-15T10:57:50.950+0000: 3.312: [CMS-concurrent-preclean-start] 2017-11-15T10:57:50.951+0000: 3.314: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:57:50.951+0000: 3.314: [CMS-concurrent-abortable-preclean-start] 2017-11-15T10:57:53.891+0000: 6.254: [GC (Allocation Failure) 2017-11-15T10:57:53.891+0000: 6.254: [ParNew: 177519K->16269K(184320K), 0.0253375 secs] 177519K->20980K(1028096K), 0.0254111 secs] [Times: user=0.07 sys=0.00, real=0.03 secs] CMS: abort preclean due to time 2017-11-15T10:57:55.993+0000: 8.356: [CMS-concurrent-abortable-preclean: 1.291/5.042 secs] [Times: user=1.51 sys=0.02, real=5.05 secs] 2017-11-15T10:57:55.994+0000: 8.356: [GC (CMS Final Remark) [YG occupancy: 28286 K (184320 K)]2017-11-15T10:57:55.995+0000: 8.358: [Rescan (parallel) , 0.0019891 secs]2017-11-15T10:57:55.997+0000: 8.360: [weak refs processing, 0.0000165 secs]2017-11-15T10:57:55.997+0000: 8.360: [class unloading, 0.0034043 secs]2017-11-15T10:57:56.000+0000: 8.363: [scrub symbol table, 0.0027747 secs]2017-11-15T10:57:56.003+0000: 8.366: [scrub string table, 0.0006049 secs][1 CMS-remark: 4710K(843776K)] 32996K(1028096K), 0.0107307 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 2017-11-15T10:57:56.004+0000: 8.367: [CMS-concurrent-sweep-start] 2017-11-15T10:57:56.007+0000: 8.369: [CMS-concurrent-sweep: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2017-11-15T10:57:56.007+0000: 8.369: [CMS-concurrent-reset-start] 2017-11-15T10:57:56.009+0000: 8.371: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-11-15T11:13:09.456+0000: 921.818: [GC (Allocation Failure) 2017-11-15T11:13:09.456+0000: 921.818: [ParNew: 180109K->11327K(184320K), 0.0103137 secs] 184820K->23879K(1028096K), 0.0103927 secs] [Times: user=0.03 sys=0.01, real=0.01 secs] 2017-11-15T11:55:19.882+0000: 3452.245: [GC (Allocation Failure) 2017-11-15T11:55:19.882+0000: 3452.245: [ParNew: 175167K->3596K(184320K), 0.0048509 secs] 187719K->16148K(1028096K), 0.0049374 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 2017-11-15T12:38:23.471+0000: 6035.834: [GC (Allocation Failure) 2017-11-15T12:38:23.471+0000: 6035.834: [ParNew: 167436K->3474K(184320K), 0.0050320 secs] 179988K->16026K(1028096K), 0.0051199 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-11-15T13:18:41.111+0000: 8453.474: [GC (Allocation Failure) 2017-11-15T13:18:41.111+0000: 8453.474: [ParNew: 167314K->5373K(184320K), 0.0053833 secs] 179866K->17925K(1028096K), 0.0054606 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-11-15T14:05:18.787+0000: 11251.149: [GC (Allocation Failure) 2017-11-15T14:05:18.787+0000: 11251.149: [ParNew: 169213K->4612K(184320K), 0.0050841 secs] 181765K->17164K(1028096K), 0.0051535 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] Heap par new generation total 184320K, used 112248K [0x00000000c0000000, 0x00000000cc800000, 0x00000000cc800000) eden space 163840K, 65% used [0x00000000c0000000, 0x00000000c691cfc8, 0x00000000ca000000) from space 20480K, 22% used [0x00000000cb400000, 0x00000000cb881180, 0x00000000cc800000) to space 20480K, 0% used [0x00000000ca000000, 0x00000000ca000000, 0x00000000cb400000) concurrent mark-sweep generation total 843776K, used 12552K [0x00000000cc800000, 0x0000000100000000, 0x0000000100000000) Metaspace used 36546K, capacity 36972K, committed 37268K, reserved 1083392K class space used 4028K, capacity 4135K, committed 4244K, reserved 1048576K ==> /var/log/hadoop/hdfs/SecurityAuth.audit <== 2017-11-15 13:00:47,701 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for yarn (auth:SIMPLE) 2017-11-15 13:02:47,688 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for yarn (auth:SIMPLE) ==> /var/log/hadoop/hdfs/jsvc.err <== Initializing secure datanode resources Opened streaming server at /0.0.0.0:1019 Successfully obtained privileged resources (streaming port = ServerSocket[addr=/0.0.0.0,localport=1019] ) (http listener port = 1022) Opened info server at /0.0.0.0:1022 Starting regular datanode initialization Service exit with a return value of 1 Initializing secure datanode resources Opened streaming server at /0.0.0.0:1019 Successfully obtained privileged resources (streaming port = ServerSocket[addr=/0.0.0.0,localport=1019] ) (http listener port = 1022) Opened info server at /0.0.0.0:1022 Starting regular datanode initialization Service exit with a return value of 1 Initializing secure datanode resources Opened streaming server at /0.0.0.0:1019 Successfully obtained privileged resources (streaming port = ServerSocket[addr=/0.0.0.0,localport=1019] ) (http listener port = 1022) Opened info server at /0.0.0.0:1022 Starting regular datanode initialization Service exit with a return value of 1 ==> /var/log/hadoop/hdfs/hadoop-hdfs-datanode-ip-192-168-0-37.eu-west-1.compute.internal.out.5 <== ulimit -a for user hdfs core file size (blocks, -c) unlimited data seg size (kbytes, -d) unlimited scheduling priority (-e) 0 file size (blocks, -f) unlimited pending signals (-i) 257533 max locked memory (kbytes, -l) 64 max memory size (kbytes, -m) unlimited open files (-n) 128000 pipe size (512 bytes, -p) 8 POSIX message queues (bytes, -q) 819200 real-time priority (-r) 0 stack size (kbytes, -s) 10240 cpu time (seconds, -t) unlimited max user processes (-u) 65536 virtual memory (kbytes, -v) unlimited file locks (-x) unlimited Command failed after 1 tries

2 REPLIES 2

Re: Ambari services are not comming up after kerberos enable

"Identifier doesn't match expected value" usually indicates there is something wrong with a Kerberos identity. My guess is that you have a DNS (or reverse DNS) issue. Check to make sure that the following return the hostname you expect on the Datanode host:

hostname -f

If this is correct, make sure that the name resolves to the expected IP address and vice-versa.

Another option could be that the Unlimited Key JCE policy is not installed on that (or any host). There are various ways to determine this, depending on which version of Ambari you are running. As of Ambari 2.5.1, you should be able to look at the Ambari web client's host view and in the summary section there will be an indicator. For example:

JCE Unlimited: true

Or (no matter which version of Ambari you are using) you can use the command line and doe the following:

$JAVA_HOME/bin/jrunscript -e 'exit (javax.crypto.Cipher.getMaxAllowedKeyLength("RC5") >= 256);'; echo $?

0 - unlimited key JCE policy IS NOT installed
1 - unlimited key JCE policy IS installed

If the unlimited key JCE policy is not installed you will need to make sure you install it on all hosts (including the Ambari server host). The restart Ambari server, regenerate keytab files, and restarted all of the services.

Re: Ambari services are not comming up after kerberos enable

Mentor