standard-test-roles

Clone
Source Code
GIT

#229 Rewrite standard-inventory-qcow2 with using logging module.
Merged 5 years ago by astepano. Opened 5 years ago by astepano.
inventory_log  into  master

file modified
+82 -57 
@@ -8,6 +8,7 @@ 
 

  import shutil
 

  import shlex
 

  import signal
 

+ import logging
 

  import StringIO
 

  import random
 

  import socket
 
@@ -74,8 +75,42 @@ 
 

    expire: False
 

  """.format(DEF_USER, DEF_PASSWD, AUTH_KEY)
 

  

- 

  EMPTY_INVENTORY = {}
 

+ LOG_FILE = "default_provisioners.log"
 

+ 

+ 

+ def get_artifact_path(path=""):
 

+     """Return path to an artifact file in artifacts directory. If path == ""
 

+     than return path artifacts dir.  Create artifacts dir if necessary.
 

+     """
 

+     artifacts = os.environ.get("TEST_ARTIFACTS", os.path.join(os.getcwd(), "artifacts"))
 

+     try:
 

+         os.makedirs(artifacts)
 

+     except OSError as exc:
 

+         if exc.errno != errno.EEXIST or not os.path.isdir(artifacts):
 

+             raise
 

+     return os.path.join(artifacts, path)
 

+ 

+ 

+ logger = logging.getLogger(__name__)
 

+ logger.setLevel(logging.DEBUG)
 

+ # stderr output
 

+ conhandler = logging.StreamHandler()
 

+ # Print to strerr by default messages with level >= warning, can be changed
 

+ # with setting TEST_DEBUG=1.
 

+ try:
 

+     diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0"))
 

+ except ValueError:
 

+     diagnose = 0
 

+ conhandler.setLevel(logging.WARNING)
 

+ if diagnose:
 

+     # Collect all messages with any log level to stderr.
 

+     conhandler.setLevel(logging.NOTSET)
 

+ # Log format for stderr.
 

+ log_format = "[%(levelname)-5.5s] {}: %(message)s".format(os.path.basename(__file__))
 

+ formatter = logging.Formatter(log_format)
 

+ conhandler.setFormatter(formatter)
 

+ logger.addHandler(conhandler)
 

  

  

  def main(argv):
 
@@ -84,19 +119,23 @@ 
 

      parser.add_argument('--host', help="Get host variables")
 

      parser.add_argument("subjects", nargs="*", default=shlex.split(os.environ.get("TEST_SUBJECTS", "")))
 

      opts = parser.parse_args()
 

- 

-     try:
 

-         if opts.host:
 

-             data = inv_host(opts.host)
 

-         else:
 

-             data = inv_list(opts.subjects)
 

-         sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': ')))
 

-     except RuntimeError as ex:
 

-         sys.stderr.write("{0}: {1}\n".format(os.path.basename(sys.argv[0]), str(ex)))
 

-         sys.stdout.write(json.dumps(EMPTY_INVENTORY, indent=4, separators=(',', ': ')))
 

-         return 1
 

- 

-     return 0
 

+     # Send logs to common logfile for all default provisioners.
 

+     log_file = get_artifact_path(LOG_FILE)
 

+     fhandler = logging.FileHandler(log_file)
 

+     # Collect all messages with any log level to log file.
 

+     fhandler.setLevel(logging.NOTSET)
 

+     log_format = ("%(asctime)s [{}/%(threadName)-12.12s] [%(levelname)-5.5s]:"
 

+                   "%(message)s").format(os.path.basename(__file__))
 

+     logFormatter = logging.Formatter(log_format)
 

+     fhandler.setFormatter(logFormatter)
 

+     logger.addHandler(fhandler)
 

+     logger.info("Start provisioner.")
 

+     if opts.host:
 

+         data = inv_host(opts.host)
 

+     else:
 

+         data = inv_list(opts.subjects)
 

+     # Dump Ansible inventory.
 

+     sys.stdout.write(json.dumps(data, indent=4, separators=(',', ': ')))
 

  

  

  def inv_list(subjects):
 
@@ -196,7 +235,7 @@ 
 

      return value
 

  

  

- def start_qemu(image, cloudinit, artifacts, portrange=(2222, 5555)):
 

+ def start_qemu(image, cloudinit, portrange=(2222, 5555)):
 

      for _ in range(10):
 

          port = random.randint(*portrange)
 

          sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
 
@@ -212,12 +251,9 @@ 
 

      else:
 

          raise RuntimeError("unable to find free local port to map SSH to")
 

  

-     try:
 

-         diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0"))
 

-     except ValueError:
 

-         diagnose = 0
 

      # Log all traffic received from the guest to a file.
 

-     log_guest = os.path.join(artifacts, "{0}.guest.log".format(os.path.basename(image)))
 

+     log_file = "{0}.guest.log".format(os.path.basename(image))
 

+     log_guest = get_artifact_path(log_file)
 

      # Log from qemu itself.
 

      log_qemu = log_guest.replace(".guest.log", ".qemu.log")
 

      # Parameters from FMF:
 
@@ -239,14 +275,15 @@ 
 

      qemu_proc = subprocess.Popen(qemu_cmd, stdout=open(log_qemu, 'a'), stderr=subprocess.STDOUT)
 

  

      if qemu_proc and diagnose:
 

-         sys.stderr.write("DIAGNOSE: qemu-kvm is running with VNC server. PID: {}\n".format(qemu_proc.pid))
 

-         sys.stderr.write("DIAGNOSE: netstat -ltpn4 | grep {0} # to find VNC server port\n".format(qemu_proc.pid))
 

+         logger.info("qemu-kvm is running with VNC server. PID: {}".format(qemu_proc.pid))
 

+         logger.info("netstat -ltpn4 | grep {0} # to find VNC server port".format(qemu_proc.pid))
 

  

      return qemu_proc, port
 

  

  

  def inv_host(image):
 

      if not image.endswith((".qcow2", ".qcow2c")):
 

+         logger.info("Return empty inventory for image: %s.", image)
 

          return EMPTY_INVENTORY
 

  

      null = open(os.devnull, 'w')
 
@@ -276,27 +313,15 @@ 
 

                             "-volid", "cidata", "-joliet", "-rock", "-quiet",
 

                             "-output", cloudinit, userdata, metadata], stdout=null)
 

  

-     # Determine if virtual machine should be kept available for diagnosis after completion
 

-     try:
 

-         diagnose = distutils.util.strtobool(os.getenv("TEST_DEBUG", "0"))
 

-     except ValueError:
 

-         diagnose = 0
 

- 

-     sys.stderr.write("Launching virtual machine for {0}\n".format(image))
 

+     logger.info("Launching virtual machine for {0}".format(image))
 

  

      # And launch the actual VM
 

-     artifacts = os.environ.get("TEST_ARTIFACTS", os.path.join(os.getcwd(), "artifacts"))
 

-     try:
 

-         os.makedirs(artifacts)
 

-     except OSError as exc:
 

-         if exc.errno != errno.EEXIST or not os.path.isdir(artifacts):
 

-             raise
 

  

      proc = None  # for failure detection
 

      cpe = None  # for exception scoping
 

      for _ in range(0, 5):
 

          try:
 

-             proc, port = start_qemu(image, cloudinit, artifacts)
 

+             proc, port = start_qemu(image, cloudinit)
 

              break
 

          except subprocess.CalledProcessError as cpe:
 

              time.sleep(1)
 
@@ -373,7 +398,7 @@ 
 

              except subprocess.CalledProcessError:
 

                  pass
 

          else:
 

-             sys.stderr.write("ERROR: Could not set ansible_python_interpreter")
 

+             logger.error("Could not set ansible_python_interpreter.")
 

              return None
 

          variables["ansible_python_interpreter"] = ansible_python_interpreter
 

          # Update inventory file
 
@@ -395,12 +420,19 @@ 
 

  

      # alternatively, lock on a file
 

      lock_file = os.environ.get("LOCK_ON_FILE", None)
 

+     ssh_cmd = ("ssh -p {port} -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i {identity} {user}@{host}"
 

+                ).format(port=port, identity=identity, user=DEF_USER, host=DEF_HOST)
 

+     logger.info(ssh_cmd)
 

+     logger.info("Password is: {}".format(DEF_PASSWD))
 

+     logger.info("Cloudinit init location: {}".format(directory))
 

+     logger.info("export ANSIBLE_INVENTORY={0}".format(inventory))
 

+     logger.info("Wait until parent for provision-script (ansible-playbook) dies or qemu.")
 

      while True:
 

          time.sleep(3)
 

  

          if lock_file:
 

              if not os.path.exists(lock_file):
 

-                 sys.stderr.write("Lock file is gone.")
 

+                 logger.error("Lock file is gone.")
 

                  break
 

          else:
 

              # Now wait for the parent process to go away, then kill the VM
 
@@ -408,36 +440,29 @@ 
 

                  os.kill(ppid, 0)
 

                  os.kill(proc.pid, 0)
 

              except OSError:
 

-                 sys.stderr.write("Either parent process or VM process is gone.")
 

-                 break  # Either of the processes no longer exist
 

- 

+                 logger.info("Either parent process or VM process is gone.")
 

+                 break
 

      if diagnose:
 

-         sys.stderr.write("\n")
 

-         sys.stderr.write("DIAGNOSE: ssh -p {port} -o StrictHostKeyChecking=no "
 

-                          "-o UserKnownHostsFile=/dev/null -i {identity} "
 

-                          "{user}@{host}\n".format(port=port, identity=identity,
 

-                                                   user=DEF_USER, host=DEF_HOST
 

-                                                   )
 

-                          )
 

-         sys.stderr.write("DIAGNOSE: Passwort is: {}".format(DEF_PASSWD))
 

-         sys.stderr.write("DIAGNOSE: export ANSIBLE_INVENTORY={0}\n".format(inventory))
 

-         sys.stderr.write("DIAGNOSE: kill {0} # when finished\n".format(os.getpid()))
 

- 

          def _signal_handler(*args):
 

-             sys.stderr.write("\nDIAGNOSE ending...\n")
 

- 

+             logger.info("Diagnose ending.")
 

          signal.signal(signal.SIGTERM, _signal_handler)
 

+         logger.info("kill {0} # when finished to debug VM.".format(os.getpid()))
 

          signal.pause()
 

- 

      # Kill the qemu process
 

      try:
 

          os.kill(proc.pid, signal.SIGTERM)
 

      except OSError:
 

          pass
 

- 

      shutil.rmtree(directory)
 

      sys.exit(0)
 

  

  

  if __name__ == '__main__':
 

-     sys.exit(main(sys.argv))
 

+     ret = -1
 

+     try:
 

+         main(sys.argv)
 

+         ret = 0
 

+     except Exception:
 

+         # Backtrace stack goes to log file. If TEST_DEBUG == 1, it goes to stderr too.
 

+         logger.info("Fatal error in provision script.", exc_info=True)
 

+     sys.exit(ret)

Signed-off-by: Andrei Stepanov astepano@redhat.com

Examples:

[root@qeos-21 ~]# export TEST_SUBJECTS=/tmp/atomi.qcow2
[root@qeos-21 ~]# ./standard-inventory-qcow2 --list
[root@qeos-21 ~]# cat artifacts/default_provisioners.log 
2018-06-25 10:24:33,108 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Start provisioner.
2018-06-25 10:24:33,116 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Launching virtual machine for /tmp/atomi.qcow2
2018-06-25 10:24:36,814 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Fatal error in provision script.
Traceback (most recent call last):
  File "./standard-inventory-qcow2", line 402, in <module>
    main(sys.argv)
  File "./standard-inventory-qcow2", line 131, in main
    data = inv_list(opts.subjects)
  File "./standard-inventory-qcow2", line 140, in inv_list
    host_vars = inv_host(subject)
  File "./standard-inventory-qcow2", line 302, in inv_host
    raise RuntimeError("qemu failed to launch qcow2 image: {0}".format(image))
RuntimeError: qemu failed to launch qcow2 image: /tmp/atomi.qcow2

[root@qeos-21 ~]# export TEST_SUBJECTS=/tmp/atomic.qcow
[root@qeos-21 ~]# ./standard-inventory-qcow2 --list
{}[root@qeos-21 ~]cat artifacts/default_provisioners.log 
2018-06-25 10:25:38,620 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Start provisioner.
2018-06-25 10:25:38,620 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Return empty inventory for image: /tmp/atomic.qcow.

Or your script have bug, like echo(a)

[root@qeos-21 ~]# export TEST_SUBJECTS=/tmp/atomic.qcow2
[root@qeos-21 ~]# ./standard-inventory-qcow2 --list
[root@qeos-21 ~]# cat artifacts/default_provisioners.log 
2018-06-25 10:28:01,922 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Start provisioner.
2018-06-25 10:28:01,922 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Fatal error in provision script.
Traceback (most recent call last):
  File "./standard-inventory-qcow2", line 403, in <module>
    main(sys.argv)
  File "./standard-inventory-qcow2", line 128, in main
    echo(a)
NameError: global name 'echo' is not defined

Good run, when:
1. stdout is Ansible inventory.
1. logs have additional info

[root@qeos-21 ~]# ./standard-inventory-qcow2 --list
{
    "subjects": {
        "hosts": [
            "/tmp/atomic.qcow2"
        ],
        "vars": {}
    },
    "_meta": {
        "hostvars": {
            "/tmp/atomic.qcow2": {
                "ansible_ssh_common_args": "-o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no",
                "ansible_port": "5350",
                "ansible_ssh_private_key_file": "/tmp/inventory-cloudyfnkha/identity",
                "ansible_python_interpreter": "/usr/bin/python2",
                "ansible_ssh_pass": "foobar",
                "ansible_user": "root",
                "ansible_host": "127.0.0.3"
            }
        }
    },
    "localhost": {
        "hosts": [
            "/tmp/atomic.qcow2"
        ],
        "vars": {}
    }
}[root@qeos-21 ~]# cat artifacts/default_provisioners.log
2018-06-25 10:29:18,640 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Start provisioner.
2018-06-25 10:29:18,649 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Launching virtual machine for /tmp/atomic.qcow2
2018-06-25 10:30:51,333 [standard-inventory-qcow2/MainThread  ] [INFO ]:  ssh -p 5350 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /tmp/inventory-cloudyfnkha/identity root@127.0.0.3
2018-06-25 10:30:51,334 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Password is: foobar
2018-06-25 10:30:51,334 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Cloudinit init location: /tmp/inventory-cloudyfnkha
2018-06-25 10:30:51,334 [standard-inventory-qcow2/MainThread  ] [INFO ]:  export ANSIBLE_INVENTORY=/tmp/inventory-cloudyfnkha/inventory
2018-06-25 10:30:51,334 [standard-inventory-qcow2/MainThread  ] [INFO ]:  Wait until parent for provision-script (ansible-playbook) dies or qemu.

Good run when:
1. TEST_DEBUG=1
2. stderr has all messages as logfile.

TEST_DEBUG=1 ./standard-inventory-qcow2 --list
[INFO ] standard-inventory-qcow2: Start provisioner.
[INFO ] standard-inventory-qcow2: Launching virtual machine for /tmp/atomic.qcow2
[INFO ] standard-inventory-qcow2: qemu-kvm is running with VNC server. PID: 4146
[INFO ] standard-inventory-qcow2: netstat -ltpn4 | grep 4146 # to find VNC server port
[INFO ] standard-inventory-qcow2: ssh -p 2405 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -i /tmp/inventory-cloudt42WkD/identity root@127.0.0.3
[INFO ] standard-inventory-qcow2: Password is: foobar
[INFO ] standard-inventory-qcow2: Cloudinit init location: /tmp/inventory-cloudt42WkD
[INFO ] standard-inventory-qcow2: export ANSIBLE_INVENTORY=/tmp/inventory-cloudt42WkD/inventory
[INFO ] standard-inventory-qcow2: Wait until parent for provision-script (ansible-playbook) dies or qemu.
{
    "subjects": {
        "hosts": [
            "/tmp/atomic.qcow2"
        ],
        "vars": {}
    },
    "_meta": {
        "hostvars": {
            "/tmp/atomic.qcow2": {
                "ansible_ssh_common_args": "-o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no",
                "ansible_port": "2405",
                "ansible_ssh_private_key_file": "/tmp/inventory-cloudt42WkD/identity",
                "ansible_python_interpreter": "/usr/bin/python2",
                "ansible_ssh_pass": "foobar",
                "ansible_user": "root",
                "ansible_host": "127.0.0.3"
            }
        }
    },
    "localhost": {
        "hosts": [
            "/tmp/atomic.qcow2"
        ],
        "vars": {}
    }
}[root@qeos-21 ~]#

fixes #206

rebased onto d71b197e19ff21e28f9b9a2696dd721a27cf7658
5 years ago

pretty please pagure-ci rebuild

rebased onto e062120
5 years ago

pretty please pagure-ci rebuild

Commit bb3bb90 fixes this pull-request

Pull-Request has been merged by astepano
5 years ago

Pull-Request has been merged by astepano
5 years ago
Changes Summary 1
+82 -57
file changed
inventory/standard-inventory-qcow2
Powered by Pagure 5.13.3
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.