Repository: oozie Updated Branches: refs/heads/master e68f723a3 -> 9491db0b8
OOZIE-3085 Improve logging in ActionExecutors: add log entry for start(), end() and kill() (kmarton via andras.piros) Project: http://git-wip-us.apache.org/repos/asf/oozie/repo Commit: http://git-wip-us.apache.org/repos/asf/oozie/commit/9491db0b Tree: http://git-wip-us.apache.org/repos/asf/oozie/tree/9491db0b Diff: http://git-wip-us.apache.org/repos/asf/oozie/diff/9491db0b Branch: refs/heads/master Commit: 9491db0b82e5dc9ccdb172576f12f91f16893521 Parents: e68f723 Author: Andras Piros <andras.pi...@cloudera.com> Authored: Tue Jan 16 14:29:18 2018 +0100 Committer: Andras Piros <andras.pi...@cloudera.com> Committed: Tue Jan 16 14:29:18 2018 +0100 ---------------------------------------------------------------------- .../action/control/ControlNodeActionExecutor.java | 4 ++++ .../action/decision/DecisionActionExecutor.java | 9 ++++----- .../oozie/action/email/EmailActionExecutor.java | 5 ++++- .../apache/oozie/action/hadoop/FsActionExecutor.java | 15 +++++++++++++++ .../oozie/action/hadoop/JavaActionExecutor.java | 3 ++- .../action/oozie/SubWorkflowActionExecutor.java | 4 ++++ .../apache/oozie/action/ssh/SshActionExecutor.java | 13 +++++++------ release-log.txt | 1 + 8 files changed, 41 insertions(+), 13 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/control/ControlNodeActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/control/ControlNodeActionExecutor.java b/core/src/main/java/org/apache/oozie/action/control/ControlNodeActionExecutor.java index cc1b610..c96142f 100644 --- a/core/src/main/java/org/apache/oozie/action/control/ControlNodeActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/control/ControlNodeActionExecutor.java @@ -41,18 +41,22 @@ import java.util.List; */ public abstract class ControlNodeActionExecutor extends ActionExecutor { + protected final XLog LOG = XLog.getLog(getClass()); + public ControlNodeActionExecutor(String type) { super(type); } @SuppressWarnings("unchecked") public void start(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Starting action"); context.setStartData("-", "-", "-"); context.setExecutionData("OK", null); } public void end(Context context, WorkflowAction action) throws ActionExecutorException { context.setEndData(WorkflowAction.Status.OK, getActionSignal(WorkflowAction.Status.OK)); + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); } public void check(Context context, WorkflowAction action) throws ActionExecutorException { http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/decision/DecisionActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/decision/DecisionActionExecutor.java b/core/src/main/java/org/apache/oozie/action/decision/DecisionActionExecutor.java index 8c235bd..472e376 100644 --- a/core/src/main/java/org/apache/oozie/action/decision/DecisionActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/decision/DecisionActionExecutor.java @@ -36,14 +36,15 @@ public class DecisionActionExecutor extends ActionExecutor { public static final String XML_ERROR = "XML_ERROR"; + private final XLog LOG = XLog.getLog(getClass()); + public DecisionActionExecutor() { super(ACTION_TYPE); } @SuppressWarnings("unchecked") public void start(Context context, WorkflowAction action) throws ActionExecutorException { - XLog log = XLog.getLog(getClass()); - log.trace("start() begins"); + LOG.info("Starting action"); try { String confStr = action.getConf(); context.setStartData("-", "-", "-"); @@ -75,13 +76,11 @@ public class DecisionActionExecutor extends ActionExecutor { catch (JDOMException ex) { throw new ActionExecutorException(ActionExecutorException.ErrorType.FAILED, XML_ERROR, ex.getMessage(), ex); } - finally { - log.trace("start() ends"); - } } public void end(Context context, WorkflowAction action) throws ActionExecutorException { context.setEndData(WorkflowAction.Status.OK, action.getExternalStatus()); + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); } public void check(Context context, WorkflowAction action) throws ActionExecutorException { http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/email/EmailActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/email/EmailActionExecutor.java b/core/src/main/java/org/apache/oozie/action/email/EmailActionExecutor.java index d59f1d7..f93b7ad 100644 --- a/core/src/main/java/org/apache/oozie/action/email/EmailActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/email/EmailActionExecutor.java @@ -87,7 +87,7 @@ public class EmailActionExecutor extends ActionExecutor { private final static String CONTENT_TYPE = "content_type"; private final static String DEFAULT_CONTENT_TYPE = "text/plain"; - private XLog LOG = XLog.getLog(getClass()); + private final XLog LOG = XLog.getLog(getClass()); public static final String EMAIL_ATTACHMENT_ERROR_MSG = "\n Note: This email is missing configured email attachments " + "as sending attachments in email action is disabled in the Oozie server. " @@ -104,6 +104,7 @@ public class EmailActionExecutor extends ActionExecutor { @Override public void start(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Starting action"); try { context.setStartData("-", "-", "-"); Element actionXml = XmlUtils.parseXml(action.getConf()); @@ -300,6 +301,7 @@ public class EmailActionExecutor extends ActionExecutor { throw new ActionExecutorException(ErrorType.ERROR, "EM007", "Encountered an error while sending the email message over SMTP.", e); } + LOG.info("Email sent to [{0}]", to); } @Override @@ -308,6 +310,7 @@ public class EmailActionExecutor extends ActionExecutor { WorkflowAction.Status status = externalStatus.equals("OK") ? WorkflowAction.Status.OK : WorkflowAction.Status.ERROR; context.setEndData(status, getActionSignal(status)); + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); } @Override http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/hadoop/FsActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/hadoop/FsActionExecutor.java b/core/src/main/java/org/apache/oozie/action/hadoop/FsActionExecutor.java index 63f6104..de55793 100644 --- a/core/src/main/java/org/apache/oozie/action/hadoop/FsActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/hadoop/FsActionExecutor.java @@ -51,6 +51,7 @@ import org.apache.oozie.service.Services; import org.apache.oozie.service.UserGroupInformationService; import org.apache.oozie.service.URIHandlerService; import org.apache.oozie.util.XConfiguration; +import org.apache.oozie.util.XLog; import org.apache.oozie.util.XmlUtils; import org.jdom.Element; @@ -63,6 +64,8 @@ public class FsActionExecutor extends ActionExecutor { private final int maxGlobCount; + private final XLog LOG = XLog.getLog(getClass()); + public FsActionExecutor() { super(ACTION_TYPE); maxGlobCount = ConfigurationService.getInt(LauncherAMUtils.CONF_OOZIE_ACTION_FS_GLOB_MAX); @@ -249,6 +252,7 @@ public class FsActionExecutor extends ActionExecutor { void chgrp(Context context, XConfiguration fsConf, Path nameNodePath, Path path, String user, String group, boolean dirFiles, boolean recursive) throws ActionExecutorException { + LOG.info("Setting ownership for [{0}] to group: [{1}], user: [{2}]. Recursive mode: [{3}]", path, group, user, recursive); HashMap<String, String> argsMap = new HashMap<String, String>(); argsMap.put("user", user); argsMap.put("group", group); @@ -352,6 +356,7 @@ public class FsActionExecutor extends ActionExecutor { } void mkdir(Context context, XConfiguration fsConf, Path nameNodePath, Path path) throws ActionExecutorException { + LOG.info("Creating directory [{0}]", path); try { path = resolveToFullPath(nameNodePath, path, true); FileSystem fs = getFileSystemFor(path, context, fsConf); @@ -361,6 +366,8 @@ public class FsActionExecutor extends ActionExecutor { throw new ActionExecutorException(ActionExecutorException.ErrorType.ERROR, "FS004", "mkdir, path [{0}] could not create directory", path); } + } else { + LOG.info("[{0}] already exist, no need for creation", path); } } catch (Exception ex) { @@ -391,6 +398,7 @@ public class FsActionExecutor extends ActionExecutor { */ public void delete(Context context, XConfiguration fsConf, Path nameNodePath, Path path, boolean skipTrash) throws ActionExecutorException { + LOG.info("Deleting [{0}]. Skipping trash: [{1}]", path, skipTrash); URI uri = path.toUri(); URIHandler handler; org.apache.oozie.dependency.URIHandler.Context hcatContext = null; @@ -494,6 +502,7 @@ public class FsActionExecutor extends ActionExecutor { */ public void move(Context context, XConfiguration fsConf, Path nameNodePath, Path source, Path target, boolean recovery) throws ActionExecutorException { + LOG.info("Moving [{0}] to [{1}]", source, target); try { source = resolveToFullPath(nameNodePath, source, true); validateSameNN(source, target); @@ -535,6 +544,7 @@ public class FsActionExecutor extends ActionExecutor { void chmod(Context context, XConfiguration fsConf, Path nameNodePath, Path path, String permissions, boolean dirFiles, boolean recursive) throws ActionExecutorException { + LOG.info("Setting permissions [{0}] on [{1}]. Recursive mode: [{2}]", permissions, path, recursive); HashMap<String, String> argsMap = new HashMap<String, String>(); argsMap.put("permissions", permissions); try { @@ -561,6 +571,8 @@ public class FsActionExecutor extends ActionExecutor { } void touchz(Context context, XConfiguration fsConf, Path nameNodePath, Path path) throws ActionExecutorException { + + LOG.info ("Performing touch on [{0}]", path); try { path = resolveToFullPath(nameNodePath, path, true); FileSystem fs = getFileSystemFor(path, context, fsConf); @@ -615,6 +627,7 @@ public class FsActionExecutor extends ActionExecutor { @Override public void start(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Starting action"); try { context.setStartData("-", "-", "-"); Element actionXml = XmlUtils.parseXml(action.getConf()); @@ -641,6 +654,7 @@ public class FsActionExecutor extends ActionExecutor { throw convertException(ex); } } + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); } @Override @@ -668,6 +682,7 @@ public class FsActionExecutor extends ActionExecutor { void setrep(Context context, Path path, short replicationFactor) throws ActionExecutorException, HadoopAccessorException { + LOG.info("Setting replication factor: [{0}] for [{1}]", replicationFactor, path); try { path = resolveToFullPath(null, path, true); FileSystem fs = getFileSystemFor(path, context, null); http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/hadoop/JavaActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/hadoop/JavaActionExecutor.java b/core/src/main/java/org/apache/oozie/action/hadoop/JavaActionExecutor.java index 5c8acae..85802b7 100644 --- a/core/src/main/java/org/apache/oozie/action/hadoop/JavaActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/hadoop/JavaActionExecutor.java @@ -1480,7 +1480,7 @@ public class JavaActionExecutor extends ActionExecutor { public void start(Context context, WorkflowAction action) throws ActionExecutorException { LogUtils.setLogInfo(action); try { - LOG.debug("Starting action " + action.getId() + " getting Action File System"); + LOG.info("Starting action. Getting Action File System"); FileSystem actionFs = context.getAppFileSystem(); LOG.debug("Preparing action Dir through copying " + context.getActionDir()); prepareActionDir(actionFs, context); @@ -1497,6 +1497,7 @@ public class JavaActionExecutor extends ActionExecutor { @Override public void end(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); try { String externalStatus = action.getExternalStatus(); WorkflowAction.Status status = externalStatus.equals(SUCCEEDED) ? WorkflowAction.Status.OK http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/oozie/SubWorkflowActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/oozie/SubWorkflowActionExecutor.java b/core/src/main/java/org/apache/oozie/action/oozie/SubWorkflowActionExecutor.java index d62cf68..e33056c 100644 --- a/core/src/main/java/org/apache/oozie/action/oozie/SubWorkflowActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/oozie/SubWorkflowActionExecutor.java @@ -164,6 +164,7 @@ public class SubWorkflowActionExecutor extends ActionExecutor { } public void start(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Starting action"); try { Element eConf = XmlUtils.parseXml(action.getConf()); Namespace ns = eConf.getNamespace(); @@ -235,6 +236,7 @@ public class SubWorkflowActionExecutor extends ActionExecutor { else { subWorkflowId = runningJobId; } + LOG.info("Sub workflow id: [{0}]", subWorkflowId); WorkflowJob workflow = oozieClient.getJobInfo(subWorkflowId); String consoleUrl = workflow.getConsoleUrl(); context.setStartData(subWorkflowId, oozieUri, consoleUrl); @@ -254,6 +256,7 @@ public class SubWorkflowActionExecutor extends ActionExecutor { WorkflowAction.Status status = externalStatus.equals("SUCCEEDED") ? WorkflowAction.Status.OK : WorkflowAction.Status.ERROR; context.setEndData(status, getActionSignal(status)); + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); } catch (Exception ex) { throw convertException(ex); @@ -284,6 +287,7 @@ public class SubWorkflowActionExecutor extends ActionExecutor { } public void kill(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Killing action"); try { String subWorkflowId = action.getExternalId(); String oozieUri = action.getTrackerUri(); http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/core/src/main/java/org/apache/oozie/action/ssh/SshActionExecutor.java ---------------------------------------------------------------------- diff --git a/core/src/main/java/org/apache/oozie/action/ssh/SshActionExecutor.java b/core/src/main/java/org/apache/oozie/action/ssh/SshActionExecutor.java index 5890b8c..0c97bb1 100644 --- a/core/src/main/java/org/apache/oozie/action/ssh/SshActionExecutor.java +++ b/core/src/main/java/org/apache/oozie/action/ssh/SshActionExecutor.java @@ -86,6 +86,8 @@ public class SshActionExecutor extends ActionExecutor { private static int maxLen; private static boolean allowSshUserAtHost; + private final XLog LOG = XLog.getLog(getClass()) +; protected SshActionExecutor() { super(ACTION_TYPE); } @@ -123,13 +125,12 @@ public class SshActionExecutor extends ActionExecutor { throw new ActionExecutorException(ActionExecutorException.ErrorType.ERROR, "ERR_XML_PARSE_FAILED", "unknown error", ex); } - XLog log = XLog.getLog(getClass()); - log.debug("Capture Output: {0}", captureOutput); + LOG.debug("Capture Output: {0}", captureOutput); if (status == Status.OK) { if (captureOutput) { String outFile = getRemoteFileName(context, action, "stdout", false, true); String dataCommand = SSH_COMMAND_BASE + action.getTrackerUri() + " cat " + outFile; - log.debug("Ssh command [{0}]", dataCommand); + LOG.debug("Ssh command [{0}]", dataCommand); try { Process process = Runtime.getRuntime().exec(dataCommand.split("\\s")); StringBuffer buffer = new StringBuffer(); @@ -172,6 +173,7 @@ public class SshActionExecutor extends ActionExecutor { */ @Override public void kill(Context context, WorkflowAction action) throws ActionExecutorException { + LOG.info("Killing action"); String command = "ssh " + action.getTrackerUri() + " kill -KILL " + action.getExternalId(); int returnValue = getReturnValue(command); if (returnValue != 0) { @@ -191,8 +193,7 @@ public class SshActionExecutor extends ActionExecutor { @SuppressWarnings("unchecked") @Override public void start(final Context context, final WorkflowAction action) throws ActionExecutorException { - XLog log = XLog.getLog(getClass()); - log.info("start() begins"); + LOG.info("Starting action"); String confStr = action.getConf(); Element conf; try { @@ -276,7 +277,6 @@ public class SshActionExecutor extends ActionExecutor { context.setStartData(pid, host, host); check(context, action); } - log.info("start() ends"); } private String checkIfRunning(String host, final Context context, final WorkflowAction action) { @@ -465,6 +465,7 @@ public class SshActionExecutor extends ActionExecutor { XLog.getLog(getClass()).warn("Cannot delete temp dir {0}", tmpDir); } } + LOG.info("Action ended with external status [{0}]", action.getExternalStatus()); } /** http://git-wip-us.apache.org/repos/asf/oozie/blob/9491db0b/release-log.txt ---------------------------------------------------------------------- diff --git a/release-log.txt b/release-log.txt index c4ace0b..e563aaa 100644 --- a/release-log.txt +++ b/release-log.txt @@ -1,5 +1,6 @@ -- Oozie 5.0.0 release (trunk - unreleased) +OOZIE-3085 Improve logging in ActionExecutors: add log entry for start(), end() and kill() (kmarton via andras.piros) OOZIE-3083 Make improved version Info backward compatible (gezapeti via asasvari) OOZIE-2150 Shell launcher should print shell script (jtolar via andras.piros) OOZIE-3147 Misleading documentation of oozie.service.PurgeService.purge.limit configuration property (okalinin via andras.piros)