[AMBARI-19153] "Create Principals" fails intermittently

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 2.5.0
• Fix Version/s: 2.5.0
• Component/s: ambari-server
• Assignee: Dmitry Lysnichenko
• Reporter: Dmitry Lysnichenko
• Created: 09/Dec/16 17:22
• Updated: 12/Dec/16 15:41
• Resolved: 12/Dec/16 14:48

Description

stderr

2016-12-05 21:08:15,369 - Failed to create principal, activity_explorer/[e-mail] - Failed to execute the command: Broken pipe

stdout

2016-12-05 21:07:40,114 - Processing identities...\n2016-12-05 21:07:40,120 - Processing principal, activity_explorer/[e-mail]

from ambari-server.log

05 Dec 2016 21:08:55,686 INFO [Server Action Executor Worker 166] KerberosServerAction:353 - Processing identities...
05 Dec 2016 21:08:55,689 INFO [Server Action Executor Worker 166] CreatePrincipalsServerAction:203 - Processing principal, HTTP/[e-mail]
05 Dec 2016 21:09:05,698 WARN [Server Action Executor Worker 166] MITKerberosOperationHandler:481 - Retrying to execute kadmin after a wait of 10 seconds :
Command: [/usr/bin/kadmin, -s, host-5.domain, -p, admin/[e-mail], -r, EXAMPLE.COM, -q, add_principal HTTP/[e-mail]]
05 Dec 2016 21:09:05,709 ERROR [Server Action Executor Worker 166] KerberosOperationHandler:739 - Failed to execute the command: Broken pipe
java.io.IOException: Broken pipe
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:345)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
at org.apache.ambari.server.utils.ShellCommandUtil.runCommand(ShellCommandUtil.java:451)
at org.apache.ambari.server.serveraction.kerberos.KerberosOperationHandler.executeCommand(KerberosOperationHandler.java:736)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.invokeKAdmin(MITKerberosOperationHandler.java:464)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.createPrincipal(MITKerberosOperationHandler.java:195)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.createPrincipal(CreatePrincipalsServerAction.java:256)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.processIdentity(CreatePrincipalsServerAction.java:159)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processRecord(KerberosServerAction.java:532)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processIdentities(KerberosServerAction.java:414)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.execute(CreatePrincipalsServerAction.java:91)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.execute(ServerActionExecutor.java:555)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.run(ServerActionExecutor.java:492)
at java.lang.Thread.run(Thread.java:745)
05 Dec 2016 21:09:15,710 WARN [Server Action Executor Worker 166] MITKerberosOperationHandler:481 - Retrying to execute kadmin after a wait of 10 seconds :
Command: [/usr/bin/kadmin, -s, host-5.domain, -p, admin/[e-mail], -r, EXAMPLE.COM, -q, add_principal HTTP/[e-mail]]
05 Dec 2016 21:09:15,722 ERROR [Server Action Executor Worker 166] KerberosOperationHandler:739 - Failed to execute the command: Broken pipe
java.io.IOException: Broken pipe
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:345)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
at org.apache.ambari.server.utils.ShellCommandUtil.runCommand(ShellCommandUtil.java:451)
at org.apache.ambari.server.serveraction.kerberos.KerberosOperationHandler.executeCommand(KerberosOperationHandler.java:736)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.invokeKAdmin(MITKerberosOperationHandler.java:464)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.createPrincipal(MITKerberosOperationHandler.java:195)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.createPrincipal(CreatePrincipalsServerAction.java:256)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.processIdentity(CreatePrincipalsServerAction.java:159)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processRecord(KerberosServerAction.java:532)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processIdentities(KerberosServerAction.java:414)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.execute(CreatePrincipalsServerAction.java:91)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.execute(ServerActionExecutor.java:555)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.run(ServerActionExecutor.java:492)
at java.lang.Thread.run(Thread.java:745)
05 Dec 2016 21:09:21,267 INFO [ambari-heartbeat-processor-0] HeartbeatProcessor:626 - Security of service component ZOOKEEPER_CLIENT of service ZOOKEEPER of cluster cl1 has changed from UNSECURED to UNKNOWN on host host-2.domain
05 Dec 2016 21:09:21,302 INFO [ambari-heartbeat-processor-0] ServiceComponentHostImpl:1030 - Host role transitioned to a new state, serviceComponentName=SPARK_CLIENT, hostName=host-5.domain, oldState=INSTALLING, currentState=INSTALLED
05 Dec 2016 21:09:22,163 INFO [ambari-heartbeat-processor-0] HeartbeatProcessor:626 - Security of service component ZEPPELIN_MASTER of service ZEPPELIN of cluster cl1 has changed from UNSECURED to UNKNOWN on host host-2.domain
05 Dec 2016 21:09:23,158 INFO [ambari-heartbeat-processor-0] HeartbeatProcessor:626 - Security of service component SLIDER of service SLIDER of cluster cl1 has changed from UNSECURED to UNKNOWN on host host-5.domain
05 Dec 2016 21:09:23,236 INFO [ambari-heartbeat-processor-0] HeartbeatProcessor:626 - Security of service component ZOOKEEPER_SERVER of service ZOOKEEPER of cluster cl1 has changed from UNSECURED to ERROR on host host-2.domain
05 Dec 2016 21:09:24,709 INFO [ambari-client-thread-111] MetricsPropertyProvider:606 - METRICS_COLLECTOR host is not live. Skip populating resources with metrics, next message will be logged after 1000 attempts.
05 Dec 2016 21:09:25,722 WARN [Server Action Executor Worker 166] MITKerberosOperationHandler:481 - Retrying to execute kadmin after a wait of 10 seconds :
Command: [/usr/bin/kadmin, -s, host-5.domain, -p, admin/[e-mail], -r, EXAMPLE.COM, -q, add_principal HTTP/[e-mail]]
05 Dec 2016 21:09:25,739 ERROR [Server Action Executor Worker 166] KerberosOperationHandler:739 - Failed to execute the command: Broken pipe
java.io.IOException: Broken pipe
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:345)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
at org.apache.ambari.server.utils.ShellCommandUtil.runCommand(ShellCommandUtil.java:451)
at org.apache.ambari.server.serveraction.kerberos.KerberosOperationHandler.executeCommand(KerberosOperationHandler.java:736)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.invokeKAdmin(MITKerberosOperationHandler.java:464)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.createPrincipal(MITKerberosOperationHandler.java:195)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.createPrincipal(CreatePrincipalsServerAction.java:256)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.processIdentity(CreatePrincipalsServerAction.java:159)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processRecord(KerberosServerAction.java:532)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processIdentities(KerberosServerAction.java:414)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.execute(CreatePrincipalsServerAction.java:91)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.execute(ServerActionExecutor.java:555)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.run(ServerActionExecutor.java:492)
at java.lang.Thread.run(Thread.java:745)
05 Dec 2016 21:09:25,739 ERROR [Server Action Executor Worker 166] CreatePrincipalsServerAction:297 - Failed to create principal, HTTP/[e-mail] - Failed to execute the command: Broken pipe
org.apache.ambari.server.serveraction.kerberos.KerberosOperationException: Failed to execute the command: Broken pipe
at org.apache.ambari.server.serveraction.kerberos.KerberosOperationHandler.executeCommand(KerberosOperationHandler.java:740)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.invokeKAdmin(MITKerberosOperationHandler.java:464)
at org.apache.ambari.server.serveraction.kerberos.MITKerberosOperationHandler.createPrincipal(MITKerberosOperationHandler.java:195)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.createPrincipal(CreatePrincipalsServerAction.java:256)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.processIdentity(CreatePrincipalsServerAction.java:159)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processRecord(KerberosServerAction.java:532)
at org.apache.ambari.server.serveraction.kerberos.KerberosServerAction.processIdentities(KerberosServerAction.java:414)
at org.apache.ambari.server.serveraction.kerberos.CreatePrincipalsServerAction.execute(CreatePrincipalsServerAction.java:91)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.execute(ServerActionExecutor.java:555)
at org.apache.ambari.server.serveraction.ServerActionExecutor$Worker.run(ServerActionExecutor.java:492)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.io.IOException: Broken pipe
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:345)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
at org.apache.ambari.server.utils.ShellCommandUtil.runCommand(ShellCommandUtil.java:451)
at org.apache.ambari.server.serveraction.kerberos.KerberosOperationHandler.executeCommand(KerberosOperationHandler.java:736)
... 10 more
05 Dec 2016 21:09:25,739 INFO [Server Action Executor Worker 166] KerberosServerAction:457 - Processing identities completed.
05 Dec 2016 21:09:26,512 ERROR [ambari-action-scheduler] ActionScheduler:436 - Operation completely failed, aborting request id: 8
05 Dec 2016 21:09:26,513 INFO [ambari-action-scheduler] ActionScheduler:943 - Service name is , component name is AMBARI_SERVER_ACTIONskipping sending ServiceComponentHostOpFailedEvent for AMBARI_SERVER_ACTION
05 Dec 2016 21:09:26,549 INFO [ambari-action-scheduler] ActionDBAccessorImpl:218 - Aborting command. Hostname null role AMBARI_SERVER_ACTION requestId 8 taskId 167 stageId 3
05 Dec 2016 21:09:26,550 INFO [ambari-action-scheduler] ActionDBAccessorImpl:218 - Aborting command. Hostname host-2.domain role KERBEROS_CLIENT requestId 8 taskId 168 stageId 4
05 Dec 2016 21:09:26,550 INFO [ambari-action-scheduler] ActionDBAccessorImpl:218 - Aborting command. Hostname null role AMBARI_SERVER_ACTION requestId 8 taskId 169 stageId 5
05 Dec 2016 21:09:27,784 INFO [ambari-action-scheduler] ServiceComponentHostImpl:1030 - Host role transitioned to a new state, serviceComponentName=ZOOKEEPER_SERVER, hostName=host-2.domain, oldState=INSTALLED, currentState=STARTING

Issue Links

• links to: review_request_