modularity-testing-framework

#57 Test is stuck with no indication what is going on
Closed: upstream Opened by ttomecek.

Closed: upstream
Reopen Issue

stdout output

MODULE=nspawn CONFIG=./config.yaml avocado run *.py  # /usr/share/moduleframework/tools/modulelint/*.py
JOB ID     : 2c2909e7326036c20b0cefc0a37170d94aba974b
JOB LOG    : /home/tt/avocado/job-results/job-2017-05-25T15.29-2c2909e/job.log
Avocado crashed: TestError: Unable to receive test's early-status in 60s, something wrong happened probably in the avocado framework.
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/avocado/core/job.py", line 457, in run_tests
    replay_map)
  File "/usr/lib/python2.7/site-packages/avocado/core/runner.py", line 563, in run_suite
    summary, deadline)
  File "/usr/lib/python2.7/site-packages/avocado/core/runner.py", line 382, in run_test
    test_status.wait_for_early_status(proc, 60)
  File "/usr/lib/python2.7/site-packages/avocado/core/runner.py", line 164, in wait_for_early_status
    raise exceptions.TestError(msg)
TestError: Unable to receive test's early-status in 60s, something wrong happened probably in the avocado framework.
Please include the traceback info and command line used on your bug report
Report bugs visiting https://github.com/avocado-framework/avocado/issues/new
JOB HTML   : /home/tt/avocado/job-results/job-2017-05-25T15.29-2c2909e/html/results.html
make: *** [Makefile:10: check] Error 4

logs

2017-05-25 15:29:42,872 job              L0388 INFO | Temporary dir: /var/tmp/avocado_7nsnaa
2017-05-25 15:29:42,872 job              L0389 INFO | 
2017-05-25 15:29:42,872 job              L0314 INFO | Job ID: 2c2909e7326036c20b0cefc0a37170d94aba974b
2017-05-25 15:29:42,872 job              L0317 INFO | 
2017-05-25 15:29:42,961 sysinfo          L0109 DEBUG| Not logging /proc/pci (file does not exist)
2017-05-25 15:29:42,974 sysinfo          L0107 DEBUG| Not logging /proc/slabinfo (lack of permissions)
2017-05-25 15:29:42,982 sysinfo          L0109 DEBUG| Not logging /sys/kernel/debug/sched_features (file does not exist)
2017-05-25 15:29:43,038 sysinfo          L0413 INFO | Commands configured by file: /etc/avocado/sysinfo/commands
2017-05-25 15:29:43,039 sysinfo          L0424 INFO | Files configured by file: /etc/avocado/sysinfo/files
2017-05-25 15:29:43,039 sysinfo          L0444 INFO | Profilers configured by file: /etc/avocado/sysinfo/profilers
2017-05-25 15:29:43,039 sysinfo          L0452 INFO | Profiler disabled
2017-05-25 15:29:43,053 varianter        L0116 DEBUG| PARAMS (key=timeout, path=*, default=None) => None
2017-05-25 15:29:43,053 test             L0239 INFO | START 1-basic_tests.py:BasicTests.test_dockerd_is_running

config.yaml

---
document: modularity-testing
version: 1
name: container-runtime
modulemd-url: http://pkgs.fedoraproject.org/cgit/modules/container-runtime.git/plain/container-runtime.yaml?h=f26
compose-url: https://kojipkgs.fedoraproject.org/compose/latest-Fedora-Modular-26/compose/Server/x86_64/os/
service:
    unix_socket: /var/run/docker.sock
packages:
    rpms:
        - docker
testdependecies:
    rpms:
        - procps-ng
module:
    rpm:
        start: systemctl start docker.service
        stop: systemctl stop docker.service
        status: systemctl status docker.service
        repos:
            - https://kojipkgs.fedoraproject.org/repos/module-b5c69ed20c975d8a-build/latest/x86_64/

tests

#!/usr/bin/python
import json
import socket
from avocado import main
from moduleframework import module_framework
class BasicTests(module_framework.AvocadoTest):
    """
    :avocado: enable
    """
    def test_dockerd_is_running(self):
        self.start()
        self.run("pgrep dockerd")
    def test_info_endpoint(self):
        self.start()
        command_result = self.run("curl -s --unix-socket /var/run/docker.sock \"http:/latest/info\"")
        json.loads(command_result.stdout)
if __name__ == '__main__':
    main()

Hi Tomas,
this unreadable issue is caused by avocado, it hides tracebacks in init methods. so it is harder to debug that.
Lukas Doktor from avocado team suggest to use
AVOCADO_LOG_DEBUG=yes
env variable for avocado command, to see whats happen, could you rerun it and post log.
I'll fix it asap, when I'll know what happened there.

otherwise try to use:
these options:
MTF_REMOTE_REPOS=yes MODULE=nspawn AVOCADO_LOG_DEBUG=yes avocado run s.py --show-job-log
it will be much faster then (becuse it will not download baseruntime packages from koji, but use built repos from koji (but this is workarouround, and jkaluza promised to remove these repos), so do not rely that it will work forewer)

When I've run your command, it seems that in repositories, there is missing dependency of docker, so that unable to install docker:

stderr] Error: conflicting requests
[stderr]   - nothing provides python-rhsm-certificates needed by docker-2:1.13.1-7.git14cc629.module_b5c69ed2.x86_64
Command 'dnf -y --nogpgcheck install --installroot /opt/chroot_container-runtime_1495785747.427584 --allowerasing --disablerepo=* --enablerepo=container-runtime*  --repofrompath container-runtime1,https://kojipkgs.fedoraproject.org/repos/module-b5c69ed20c975d8a-build/latest/x86_64/ systemd rpm glibc-minimal-langpack shadow-utils coreutils filesystem docker util-linux microdnf bash libcrypt' finished with 1 after 8.01320290565s

So that there is some issue in module itself
Edited by jscotka

Yep, that is probably the issue. I am also seeing this:

Running 'dnf -y install systemd-container'
[stderr] Error: This command has to be run under the root user.
Command 'dnf -y install systemd-container' finished with 1 after 1.23308801651s
Reproduced traceback from: /usr/lib/python2.7/site-packages/avocado/core/test.py:574
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/moduleframework/module_framework.py", line 1022, in setUp
    return self.backend.setUp()
  File "/usr/lib/python2.7/site-packages/moduleframework/module_framework.py", line 720, in setUp
    self.__prepareSetup()
  File "/usr/lib/python2.7/site-packages/moduleframework/module_framework.py", line 756, in __prepareSetup
    self.runHost("{HOSTPACKAGER} install systemd-container".format(**trans_dict))
  File "/usr/lib/python2.7/site-packages/moduleframework/module_framework.py", line 88, in runHost
    return utils.process.run("%s" % command, **kwargs)
  File "/usr/lib/python2.7/site-packages/avocado/utils/process.py", line 1117, in run
    raise CmdError(cmd, sp.result)
CmdError: Command 'dnf -y install systemd-container' failed (rc=1)

Hm, actually Honzo that's pretty odd you are seeing the error, b/c the package, python-rhsm-certificates, is part of shared userspace module.

yep, plase in your config, replace
repos:
- .....

by
repo: ...
repos is obsolote and have little bit another login. it is also fixed in container template + in oficial example config

and yep, this systemd NSPAWN has to be run under root.
Edited by jscotka

I hope that I've fixed this issue by moving init of rpmhelper to setup.
by commit: https://pagure.io/modularity-testing-framework/c/cdcc80e001641345c35b5460ae57ae1e115d07b0?branch=master

Metadata Update from @jscotka:
- Issue assigned to jscotka
- Issue close_status updated to: upstream
- Issue status updated to: Closed (was: Open)
- Issue tagged with: Bug, Prio1

anyway, it's resolved, thank you!

Metadata Update from @ttomecek:
- Assignee reset
- Issue untagged with: Bug, Prio1
- Issue status updated to: Open (was: Closed)

Metadata Update from @ttomecek:
- Issue close_status updated to: upstream
- Issue status updated to: Closed (was: Open)
Metadata
None
None
None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.