[Fuego] [PATCH] run_test: enable jenkins to use it directly

Daniel Sangorrin daniel.sangorrin at toshiba.co.jp
Wed Sep 26 07:24:40 UTC 2018


This patch includes many small fixes. I could partition it into
smaller pieces but since there is no much time until the next
release, I prefer to send it as it is for now so that I
can get some feedback.

Main changes:
- Switch Jenkins jobs to call ftc run-test
- Identify and differentiate what environment variables need to
  be set depending on the caller. I have added some code to
  identify if we are calling ftc run-test nested, in case
  we need that in the future.
- FUEGO_DEBUG is still available, and can be set in the command
  line as well by using --debug (it basically forces set -x)
- I completely removed the log/tail_fd code and subsituted it
  to the standard logging library. Ideally, we should use
  the logging library for ftc print messages as well. The logging
  library allows setting debug/info/error.. levels, and
  you can have multiple handlers (in this case one is stdout
  and the other one is logdir/consolelog.txt). I am saving
  the whole log into the logdir now, even when it is called
  from jenkins. Please let me know what you think.
- I don't know how to notify jenkins of new runs made in
  console mode. This is something to fix.

Signed-off-by: Daniel Sangorrin <daniel.sangorrin at toshiba.co.jp>
---
 engine/scripts/ftc | 367 ++++++++++++++++++++++-------------------------------
 1 file changed, 153 insertions(+), 214 deletions(-)

diff --git a/engine/scripts/ftc b/engine/scripts/ftc
index fa3ee07..0f281ac 100755
--- a/engine/scripts/ftc
+++ b/engine/scripts/ftc
@@ -59,8 +59,6 @@ jenkins = None
 VERSION = (1, 3, 0)
 
 # define these as globals
-log = None
-tail_fd = None
 quiet = 0
 verbose = 0
 debug = 0
@@ -1332,14 +1330,9 @@ def create_job(board, test):
     <customWorkspace>$FUEGO_RW/buildzone</customWorkspace>
     <builders>
     <hudson.tasks.Shell>
-        <command>export Reboot={reboot}
-export Rebuild={rebuild}
-export Target_PreCleanup={precleanup}
-export Target_PostCleanup={postcleanup}
-export TESTDIR={testdir}
-export TESTSPEC={testspec}
+        <command>export FUEGO_CALLER="jenkins"
 #export FUEGO_DEBUG=1
-timeout --signal=9 {timeout} /bin/bash $FUEGO_CORE/engine/scripts/main.sh
+ftc run-test -b $NODE_NAME -t {testdir} -s {testspec} -k {timeout} --reboot {reboot} --rebuild {rebuild} --precleanup {precleanup} --postcleanup {postcleanup}
 </command>
     </hudson.tasks.Shell>
     </builders>
@@ -3102,18 +3095,22 @@ def alarm_handler(signum, frame):
 
 # this function executes the command, and shows the log file
 # while it is running
-def ftc_exec_command(command, timeout):
-    global log, tail_fd
+def ftc_exec_command(command, timeout, log_filename):
+    import logging
 
-    # fix Python's weird pipe handling, so subprocess command will handle pipe
-    # signals correctly.  Otherwhise, something like 'ftc... | head' will fail
+    log = logging.getLogger('fuego_logger')
+    log.setLevel(logging.DEBUG)
+    #formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
 
-    # well, the following doesn't work
-    #signal.signal(signal.SIGPIPE,signal.SIG_DFL)
+    fh = logging.FileHandler(log_filename)
+    fh.setLevel(logging.DEBUG)
+    #fh.setFormatter(formatter)
+    log.addHandler(fh)
 
-    print "ftc_exec_command: command=%s" % command
-
-    p = subprocess.Popen(command.split(), stdout=log, stderr=log)
+    ch = logging.StreamHandler()
+    ch.setLevel(logging.DEBUG)
+    #ch.setFormatter(formatter)
+    log.addHandler(ch)
 
     # specify timeout for command operation
     signal.signal(signal.SIGALRM, alarm_handler)
@@ -3127,17 +3124,11 @@ def ftc_exec_command(command, timeout):
     signal.alarm(time)
 
     try:
-        # p.poll returns exit code when process completes
-        # and None while it is still running
-        while p.poll() is None:
-            #print "test command is running in the background"
-
-            # output the log while the command is running
-            log.flush()
-            data = os.read(tail_fd, 4096)
-            if data:
-                print data
-
+        p = subprocess.Popen(command.split(), stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
+        with p.stdout:
+            for line in iter(p.stdout.readline, b''):
+                log.info(line.rstrip())
+        p.wait()
     except FTC_INTERRUPT:
         print "Job interrupted!"
         # abort with prejudice...
@@ -3297,8 +3288,6 @@ def get_test_arg(cmd, conf, options):
     return (test_name, options)
 
 def do_run_test(conf, options):
-    global log, tail_fd
-
     board, options = get_board_arg("Run-test", conf, options)
     board_name = board.name
 
@@ -3418,38 +3407,8 @@ def do_run_test(conf, options):
         options.remove('-p')
         os.environ["FUEGO_TEST_PHASES"] = test_phases
 
-    # detect whether this is a Jenkins job or not:
-    try:
-        jenkins_url = os.environ("JENKINS_URL")
-        fuego_caller = "jenkins"
-    except:
-        jenkins_url = None
-        fuego_caller = "ftc"
-        print "Notice: non-Jenkins test request detected"
-
     print "Running test '%s' on board '%s' using spec '%s'" % (test_name, board_name, test.spec)
 
-    # check if there's a Jenkins job that matches this request
-    # Job names have the syntax: <board>.<spec>.<test_name>
-    job_name = "%s.%s.%s" % (board_name, test.spec, test_name)
-    job_dir = conf.JENKINS_HOME+"/jobs/"+job_name
-    if not os.path.isfile(job_dir+"/config.xml"):
-        print "Warning: no matching Jenkins job found.  Not populating Jenkins build directory"
-        job_dir = None
-
-    #pvar("job_dir")
-
-    print "!!! >>> Ready to run test! <<< !!!"
-
-    # make sure environment variables are set:
-
-    # export stuff from configuration into environment
-    export_list = ["FUEGO_CORE", "FUEGO_RO", "FUEGO_RW"]
-    for var in export_list:
-        os.environ[var] = conf.__dict__[var]
-
-    os.environ["FUEGO_HOST"] = conf.host
-
     # construct the build_data map to hold information about this build
     build_data = data_class()
     build_data.board_name = board_name
@@ -3469,47 +3428,36 @@ def do_run_test(conf, options):
     # set job description in run json file
     build_data.description = "Test %s run by ftc" % build_data.test_name
 
-    # export other vars (that Jenkins would export)
-    # FIXTHIS: do_run_test: variables have changed (e.g. TESTSPEC, ..)
-    os.environ["TESTPLAN"] = build_data.testplan_name
-    os.environ["JOB_NAME"] = build_data.job_name
-    os.environ["NODE_NAME"] = build_data.board_name
-    os.environ["NODE_LABELS"] = build_data.board_name
-    os.environ["Device"] = build_data.board_name
-    os.environ["TESTDIR"] = build_data.testdir
-    os.environ["WORKSPACE"] = build_data.workspace
-    os.environ["TESTSPEC"] = build_data.spec_name
-    # FIXTHIS - set this if user specifies --debug in options
-    os.environ["FUEGO_DEBUG"] = "1"
+    # run_test can be used in different situations
+    #    - called from jenkins
+    #        - FUEGO_CALLER="jenkins"
+    #    - called from the command line (ftc)
+    #        - FUEGO_CALLER not set
+    #    - called from fuego_test.sh (nested)
+    #        - FUEGO_CALLER="ftc"
 
-    for var_name in board.env_vars.keys():
-        os.environ[var_name] = board.env_vars[var_name]
-
-    # and do synchronization with jenkins job at end, if possible
-
-    # set BUILD_NUMBER, BUILD_ID, BUILD_TAG and EXECUTOR_NUMBER
-    timestamp = time.strftime("%FT%T%z")
-    build_data.timestamp = timestamp
+    try:
+        fuego_caller = os.environ["FUEGO_CALLER"]
+        if fuego_caller == "jenkins":
+            print("ftc was called from Jenkins")
+        elif fuego_caller == "ftc":
+            print("ftc was called from fuego_test (nested)")
+        else:
+            error_out("fuego_caller has an unexpected value: " + fuego_caller)
+    except:
+        print("ftc was called from the command line")
+        fuego_caller = "ftc"
+        os.environ["FUEGO_CALLER"] = "ftc"
 
-    if job_dir:
-        build_number = find_next_build_number(job_dir)
-        pvar("build_number")
-        filename = job_dir + "/nextBuildNumber"
-        next_build_number = str(int(build_number)+1)
-        # update nextBuildNumber
-        try:
-            fd = open(filename, "w+")
-            fd.write(next_build_number+'\n')
-            fd.close()
-        except:
-            print "Error: problem writing to file %s" % filename
+    # set build_data.build_number depending on the situation
+    if fuego_caller == "jenkins":
+        build_data.build_number = os.environ["BUILD_NUMBER"]
     else:
         logs_dir = conf.FUEGO_RW + "/logs/%s" % test_name
         if not os.path.isdir(logs_dir):
              os.mkdir(logs_dir)
-        build_number = find_next_build_number_by_log_scan(logs_dir)
+        build_data.build_number = find_next_build_number_by_log_scan(logs_dir)
 
-    build_data.build_number = build_number
     build_data.test_logdir = conf.FUEGO_RW + '/logs/' + \
         build_data.test_name    + '/' + \
         build_data.board_name   + '.' + \
@@ -3522,36 +3470,42 @@ def do_run_test(conf, options):
         build_data.build_number + '-' + \
         build_data.board_name
 
-    os.environ["EXECUTOR_NUMBER"] = "0"
-    os.environ["BUILD_ID"] = build_data.build_number
-    os.environ["BUILD_NUMBER"] = build_data.build_number
-    os.environ["BUILD_TIMESTAMP"] = build_data.timestamp
-
-    # logdir path is ${NODE_NAME}.${TESTSPEC}.${BUILD_NUMBER}.${BUILD_ID}
-    # FIXTHIS - do_run_test: logdir path should have timestamp in it
-    log_dir = conf.FUEGO_RW + "/logs/%(test_name)s/%(board_name)s.%(spec_name)s.%(build_number)s.%(build_number)s"  % build_data
-
-    if not os.path.isdir(log_dir):
-        os.mkdir(log_dir)
-
-    # create build_number directory
-    if job_dir:
-        run_dir = job_dir + "/builds/" + build_number
-        os.mkdir(run_dir)
-        console_log_filename = "log"
-    else:
-        run_dir = log_dir
-        console_log_filename = "consolelog.txt"
-
-    os.environ["BUILD_TAG"] = "ftc-%s-%s" % (test_name, build_number)
-
-    os.environ["JENKINS_HOME"] = conf.JENKINS_HOME
-    os.environ["JENKINS_URL"] = conf.JENKINS_URL
-
+    # set environment variables
+    ## set environment variables that Jenkins would export
+    if fuego_caller != "jenkins":
+        os.environ["BUILD_NUMBER"] = build_data.build_number
+        os.environ["BUILD_ID"] = build_data.build_number
+        os.environ["EXECUTOR_NUMBER"] = "0"
+        os.environ["BUILD_TAG"] = "ftc-%s-%s" % (test_name, build_data.build_number)
+        os.environ["JENKINS_HOME"] = conf.JENKINS_HOME
+        os.environ["JENKINS_URL"] = conf.JENKINS_URL
+        os.environ["JOB_NAME"] = build_data.job_name
+        os.environ["NODE_NAME"] = build_data.board_name
+        os.environ["NODE_LABELS"] = build_data.board_name
+        os.environ["WORKSPACE"] = build_data.workspace
+        global debug
+        if debug:
+            os.environ["FUEGO_DEBUG"] = "1"
+
+    ## set Fuego-only environment variables
     os.environ["Reboot"] = build_data.reboot_flag
     os.environ["Rebuild"] = build_data.rebuild_flag
     os.environ["Target_PreCleanup"] = build_data.precleanup_flag
     os.environ["Target_PostCleanup"] = build_data.postcleanup_flag
+    os.environ["TESTSPEC"] = build_data.spec_name
+    os.environ["TESTDIR"] = build_data.testdir
+    os.environ["TESTPLAN"] = build_data.testplan_name
+    os.environ["Device"] = build_data.board_name
+    os.environ["FUEGO_HOST"] = conf.host
+    os.environ["LOGDIR"] = build_data.test_logdir
+
+    for var_name in board.env_vars.keys():
+        os.environ[var_name] = board.env_vars[var_name]
+    for var in ["FUEGO_CORE", "FUEGO_RO", "FUEGO_RW"]:
+        os.environ[var] = conf.__dict__[var]
+    timestamp = time.strftime("%FT%T%z")
+    build_data.timestamp = timestamp
+    os.environ["BUILD_TIMESTAMP"] = build_data.timestamp
 
     # prepare a per-run spec.json file
     specpath = '%s/engine/tests/%s/spec.json' % (conf.FUEGO_CORE, test_name)
@@ -3577,48 +3531,22 @@ def do_run_test(conf, options):
 
     print "test spec data" + str(test_spec_data)
 
-    # FIXTHIS: use a more pythonic way
-    os.system("mkdir -p " + build_data.test_logdir)
+    if os.path.isdir(build_data.test_logdir):
+        error_out("log folder %s already exists" % build_data.test_logdir)
+    else:
+        # FIXTHIS: use a more pythonic way
+        os.system("mkdir -p " + build_data.test_logdir)
 
     with open(build_data.test_logdir + '/spec.json', 'w+') as spec_file:
         json.dump(test_spec_data, spec_file)
 
-    # cd to buildzone directory
+    # execute the test
+    print("Running on '%(board_name)s' in workspace %(workspace)s" % build_data)
     saved_cur_dir = os.getcwd()
     os.chdir(build_data.workspace)
-
-    print("Running remotely on '%(board_name)s' in workspace %(workspace)s" % build_data)
-
-    command = "/bin/bash $FUEGO_CORE/engine/scripts/main.sh"
-    pvar("command")
-
-    # write command to temp file, and execute that with
-    #    '/bin/sh -xe /tmp/hudson123456.sh'
-    try:
-        tempfilename = make_temp_file(command)
-    except:
-        os.chdir(saved_cur_dir)
-        error_out("Could not make temp file")
-
-    pvar("tempfilename")
-
-    # stream output to log file while test is running
-
-    # create log file
-    log_filename = run_dir + os.sep + console_log_filename
-    log = open(log_filename, "w+")
-    log.write("LOG HEADER from FTC")
-    log.flush()
-
-    # create another file descriptor for 'tail'ing  the data
-    log_tail = open(log_filename, "r")
-    tail_fd = log_tail.fileno()
-    flag = fcntl.fcntl(tail_fd, fcntl.F_GETFL)
-    fcntl.fcntl(tail_fd, fcntl.F_SETFL, flag | os.O_NONBLOCK)
-
-    command = "/bin/bash -xe %s" % (tempfilename)
-    rcode = ftc_exec_command(command, test.timeout)
-    log.flush()
+    command = '/bin/bash -e ' + conf.FUEGO_CORE + '/engine/scripts/main.sh'
+    log_filename = build_data.test_logdir + '/consolelog.txt'
+    rcode = ftc_exec_command(command, test.timeout, log_filename)
 
     build_data.result = "UNKNOWN"
     if rcode != 0:
@@ -3651,12 +3579,6 @@ def do_run_test(conf, options):
     pvar("rcode2")
     """
 
-    # drain the log, in case there's more there
-    data = os.read(tail_fd, 4096)
-    while data:
-        sys.stdout.write(data)
-        data = os.read(tail_fd, 4096)
-
     if rcode == 0:
         build_data.result = "SUCCESS"
 
@@ -3668,7 +3590,7 @@ def do_run_test(conf, options):
                 build_data.test_name,
                 conf.host,
                 build_data.board_name,
-                run_dir,
+                build_data.test_logdir,
                 build_data.build_number)
 
     # fake a few entries
@@ -3681,65 +3603,82 @@ def do_run_test(conf, options):
     #run.write_run_json_file(log_dir)
 
     # update all the Jenkins build-related files
-    if job_dir:
-        write_build_xml_file(run_dir, build_data)
-
-        # write changelog.xml file
-        filename = run_dir + "/changelog.xml"
-        fd = open(filename, "w+")
-        fd.write("<log/>")
-        fd.close()
-
-        # update last.. symlinks
-        # lastStableBuild, lastSuccessfulBuild
-        # lastUnstableBuild, lastUnsuccessfulBuild, lastFailedBuild
-        # How does Jenkins calculate UnstableBuilds?
-        if build_data.result == "SUCCESS":
-            linkname = job_dir + "/builds/lastStableBuild"
+    if fuego_caller != "jenkins":
+        job_dir = conf.JENKINS_HOME + "/jobs/" + build_data.job_name
+        if not os.path.isdir(job_dir):
+            print "Warning: no matching Jenkins job found. Not populating Jenkins build directory"
+        else:
+            # update next build number
+            build_number = find_next_build_number(job_dir)
+            pvar("build_number")
+            filename = job_dir + "/nextBuildNumber"
+            next_build_number = str(int(build_number)+1)
+            # update nextBuildNumber
             try:
-                os.unlink(linkname)
+                fd = open(filename, "w+")
+                fd.write(next_build_number+'\n')
+                fd.close()
             except:
-                pass
-            os.symlink(build_number, linkname)
+                print "Error: problem writing to file %s" % filename
 
-            linkname = job_dir + "/builds/lastSuccessfulBuild"
-            try:
-                os.unlink(linkname)
-            except:
-                pass
-            os.symlink(build_number, linkname)
+            # create jenkins directory for this run
+            run_dir = job_dir + "/builds/" + build_number
+            if not os.path.isdir(run_dir):
+                os.mkdir(run_dir)
 
-        if build_data.result == "FAILED":
-            linkname = job_dir + "/builds/lastUnsuccessfulBuild"
-            try:
-                os.unlink(linkname)
-            except:
-                pass
-            os.symlink(build_number, linkname)
+            # write a build file
+            write_build_xml_file(run_dir, build_data)
 
-            linkname = job_dir + "/builds/lastFailedBuild"
-            try:
-                os.unlink(linkname)
-            except:
-                pass
-            os.symlink(build_number, linkname)
+            # write changelog.xml file
+            filename = run_dir + "/changelog.xml"
+            fd = open(filename, "w+")
+            fd.write("<log/>")
+            fd.close()
 
-        if build_data.result == "ABORTED":
-            linkname = job_dir + "/builds/lastUnsuccessfulBuild"
-            try:
-                os.unlink(linkname)
-            except:
-                pass
-            os.symlink(build_number, linkname)
+            # update last.. symlinks
+            # lastStableBuild, lastSuccessfulBuild
+            # lastUnstableBuild, lastUnsuccessfulBuild, lastFailedBuild
+            # How does Jenkins calculate UnstableBuilds?
+            if build_data.result == "SUCCESS":
+                linkname = job_dir + "/builds/lastStableBuild"
+                try:
+                    os.unlink(linkname)
+                except:
+                    pass
+                os.symlink(build_number, linkname)
 
-    os.chdir(saved_cur_dir)
+                linkname = job_dir + "/builds/lastSuccessfulBuild"
+                try:
+                    os.unlink(linkname)
+                except:
+                    pass
+                os.symlink(build_number, linkname)
 
-    # remove the tempfiles
-    os.unlink(tempfilename)
-    #os.unlink(tempfilename2)
+            if build_data.result == "FAILED":
+                linkname = job_dir + "/builds/lastUnsuccessfulBuild"
+                try:
+                    os.unlink(linkname)
+                except:
+                    pass
+                os.symlink(build_number, linkname)
 
-    log.close()
-    log_tail.close()
+                linkname = job_dir + "/builds/lastFailedBuild"
+                try:
+                    os.unlink(linkname)
+                except:
+                    pass
+                os.symlink(build_number, linkname)
+
+            if build_data.result == "ABORTED":
+                linkname = job_dir + "/builds/lastUnsuccessfulBuild"
+                try:
+                    os.unlink(linkname)
+                except:
+                    pass
+                os.symlink(build_number, linkname)
+
+    # FIXTHIS: if called as root, we may need to become root again before moving here
+    os.chdir(saved_cur_dir)
 
     # FIXTHIS - do something to make the build/run appear in Jenkins
     # Note: builds seem to appears when Jenkins reloads it's configuration
-- 
2.7.4



More information about the Fuego mailing list