GOSC event doesn't report at once after customization process timer is reached

When process timer is reached, the command process is killed and function
ProcessRead is called to read all the output till EOF.  But EOF can't be
reached immediately.  The reason is pre-customization script is launched
by perl script, and killing perl script process doesn't kill the
pre-customization script process.
This code update includes:
1. Do not read stdout/stderr when gosc command process exits abnormally
   to avoid the EOF blocking.
2. Add READSTATUS_PENDING_TO_EOF in enum ReadStatus to avoid the confusion
   with READSTATUS_PENDING.
3. Close the write ends of pipes (stdout[1]/stderr[1]) for child command
   process before it exists.
4. In processPosix.c, the write ends of pipes have been closed in line 180,
   181, so the read ends should be closed in line 254, 255.
5. Add explicit note for the beginning and the end of the perl script log.

diff --git a/open-vm-tools/libDeployPkg/linuxDeployment.c b/open-vm-tools/libDeployPkg/linuxDeployment.c
index 0355e8bb547040fd0b210174174228dd8e7729ac..9121c618ed33f203106e10594fd31699f5b0ec8e 100644 (file)
--- a/open-vm-tools/libDeployPkg/linuxDeployment.c
+++ b/open-vm-tools/libDeployPkg/linuxDeployment.c
@@ -1720,6 +1720,7 @@ ForkExecAndWaitCommand(const char* command, bool ignoreStdErr)
    int retval;
    int i;
    char** args = GetFormattedCommandLine(command);
+   Bool isPerlCommand = (strcmp(args[0], "/usr/bin/perl") == 0) ? true : false;
 
    sLog(log_debug, "Command to exec : '%s'.\n", args[0]);
    Process_Create(&hp, args, sLog);
@@ -1731,7 +1732,15 @@ ForkExecAndWaitCommand(const char* command, bool ignoreStdErr)
    free(args);
 
    Process_RunToComplete(hp, gProcessTimeout);
-   sLog(log_info, "Customization command output: '%s'.\n", Process_GetStdout(hp));
+   if (isPerlCommand) {
+      sLog(log_info, "Customization command output:\n\n%s\n\n%s\n%s\n",
+         "=================== Perl script log start =================",
+         Process_GetStdout(hp),
+         "=================== Perl script log end =================");
+   } else {
+      sLog(log_info, "Customization command output:\n'%s'.\n",
+         Process_GetStdout(hp));
+   }
    retval = Process_GetExitCode(hp);
 
    if (retval == 0) {

diff --git a/open-vm-tools/libDeployPkg/processPosix.c b/open-vm-tools/libDeployPkg/processPosix.c
index cd99ce3025cd7e3f5cfde4b5a4f1376d49f0a7b3..6eb27c18acaddda734137d5776080a0882f4c853 100644 (file)
--- a/open-vm-tools/libDeployPkg/processPosix.c
+++ b/open-vm-tools/libDeployPkg/processPosix.c
@@ -1,5 +1,5 @@
 /*********************************************************
- * Copyright (C) 2007-2016,2019 VMware, Inc. All rights reserved.
+ * Copyright (C) 2007-2020 VMware, Inc. All rights reserved.
  *
  * This program is free software; you can redistribute it and/or modify it
  * under the terms of the GNU Lesser General Public License as published
@@ -47,6 +47,7 @@ typedef enum _ReadStatus {
    READSTATUS_UNDEFINED,
    READSTATUS_DONE,
    READSTATUS_PENDING,
+   READSTATUS_WAITING_EOF,
    READSTATUS_ERROR
 } ReadStatus;
 
@@ -154,6 +155,8 @@ Process_RunToComplete(ProcessHandle h, unsigned long timeoutSec)
    ReadStatus res_stdout = READSTATUS_UNDEFINED;
    ReadStatus res_stderr = READSTATUS_UNDEFINED;
 
+   Bool processExitedAbnormally = FALSE;
+
    p = (ProcessInternal*)h;
 
    stdout[0] = stdout[1] = 0;
@@ -187,6 +190,8 @@ Process_RunToComplete(ProcessHandle h, unsigned long timeoutSec)
       execv(p->args[0], p->args);
 
       // exec failed
+      close(stdout[1]);
+      close(stderr[1]);
       exit(127);
    }
 
@@ -227,6 +232,7 @@ Process_RunToComplete(ProcessHandle h, unsigned long timeoutSec)
                    "Process exited abnormally after %d sec, uncaught signal %d",
                    elapsedTimeLoopSleeps * LoopSleepMicrosec / OneSecMicroSec,
                    WTERMSIG(processStatus));
+            processExitedAbnormally = TRUE;
          }
 
          break;
@@ -255,18 +261,20 @@ Process_RunToComplete(ProcessHandle h, unsigned long timeoutSec)
    }
 
    // Process completed. Now read all the output to EOF.
-   ProcessRead(p, &res_stdout, TRUE, TRUE);
+   // PR 2367614, set readToEof to TRUE only if process exits normally.
+   // Otherwise just empty the pipe to avoid being blocked by read operation.
+   ProcessRead(p, &res_stdout, TRUE, !processExitedAbnormally);
    if (res_stdout == READSTATUS_ERROR) {
-      p->log(log_error, "Error while reading process output, killing...");
+      p->log(log_error, "Error while reading process stdout, killing...");
    }
 
-   ProcessRead(p, &res_stderr, FALSE, TRUE);
+   ProcessRead(p, &res_stderr, FALSE, !processExitedAbnormally);
    if (res_stderr == READSTATUS_ERROR) {
-      p->log(log_error, "Error while reading process output, killing...");
+      p->log(log_error, "Error while reading process stderr, killing...");
    }
 
-   close(stdout[1]);
-   close(stderr[1]);
+   close(stdout[0]);
+   close(stderr[0]);
    return PROCESS_SUCCESS;
 }
 
@@ -326,10 +334,11 @@ ProcessRead(ProcessInternal *p, ReadStatus *status, Bool stdout, Bool readToEof)
          return;
       } else if (count < 0) {
          if (errno == EAGAIN && readToEof) {
-            if (*status != READSTATUS_PENDING) {
+            if (*status != READSTATUS_WAITING_EOF) {
                // waiting for more output, sleep briefly and try again
-               p->log(log_info, "Pending output from %s, trying again", stdstr);
-               *status = READSTATUS_PENDING;
+               p->log(log_info, "Pending output from %s till EOF, trying again",
+                  stdstr);
+               *status = READSTATUS_WAITING_EOF;
             }
 
             usleep(1000);