| |
@@ -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