Skip to content

Add support for logging services output into job's trace

Tomasz Maczukin requested to merge feature/services-logs into master

What does this MR do?

Adds CI_DEBUG_SERVICES variable which, if set to trace, prints the output of all used services to the job's trace, e.g.:

without CI_DEBUG_SERVICES variable:

Running with gitlab-ci-multi-runner 9.3.0~beta.31.g34151514 (34151514)
  on  ()
Using Docker executor with image alpine ...
Starting service docker:dind ...
Using locally found image version due to if-not-present pull policy
Using docker image docker:dind ID=sha256:dee518b729774dca2b75e356b4e5d288f4abd00daea5a934c63c4a5a20fe6655 for docker service...
Waiting for services to be up and running...
Using docker image sha256:26e52dd033d4116759722e2f48d742d8f6fd26aa7d6aec045a2d5d7a44b8a0d1 for predefined container...
Using locally found image version due to if-not-present pull policy
Using docker image alpine ID=sha256:a41a7446062d197dd4b21b38122dcc7b2399deb0750c4110925a7dd37c80f118 for build container...
Running on runner--project-0-concurrent-0 via apollo.h.maczukin.pl...
Cloning repository...
Cloning into '/builds/project-0'...
done.
Checking out ca76bb21 as master...
Skipping Git submodules setup
$ i=0
$ while [ $i -lt 5 ]; do echo "${CI_JOB_NAME} ${i}"; i=$((i + 1)); sleep 1; done
job3 0
job3 1
job3 2
job3 3
job3 4
$ echo "done"
done
Running after script...
Job succeeded

with CI_DEBUG_SERVICES=trace variable:

Running with gitlab-ci-multi-runner 9.3.0~beta.31.g34151514 (34151514)
  on  ()
Using Docker executor with image alpine ...
Starting service docker:dind ...
Using locally found image version due to if-not-present pull policy
Using docker image docker:dind ID=sha256:dee518b729774dca2b75e356b4e5d288f4abd00daea5a934c63c4a5a20fe6655 for docker service...
Waiting for services to be up and running...
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:36.360349745Z" level=warning msg="could not change group /var/run/docker.sock to docker: group docker not found" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:36.360483302Z" level=warning msg="[!] DON'T BIND ON ANY IP ADDRESS WITHOUT setting --tlsverify IF YOU DON'T KNOW WHAT YOU'RE DOING [!]" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:36.361169393Z" level=info msg="libcontainerd: new containerd process, pid: 25" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.414726298Z" level=info msg="Graph migration to content-addressability took 0.00 seconds" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.414940969Z" level=warning msg="Your kernel does not support cgroup rt period" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.414954396Z" level=warning msg="Your kernel does not support cgroup rt runtime" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.415262018Z" level=info msg="Loading containers: start." 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.415978008Z" level=warning msg="Running modprobe bridge br_netfilter failed with message: modprobe: can't change directory to '/lib/modules': No such file or directory\n, error: exit status 1" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.416522557Z" level=warning msg="Running modprobe nf_nat failed with message: `modprobe: can't change directory to '/lib/modules': No such file or directory`, error: exit status 1" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.417023029Z" level=warning msg="Running modprobe xt_conntrack failed with message: `modprobe: can't change directory to '/lib/modules': No such file or directory`, error: exit status 1" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.486462608Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.18.0.0/16. Daemon option --bip can be used to set a preferred IP address" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.546004433Z" level=info msg="Loading containers: done." 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.557178020Z" level=info msg="Daemon has completed initialization" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.557240992Z" level=info msg="Docker daemon" commit=89658be graphdriver=vfs version=17.05.0-ce 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.573730716Z" level=info msg="API listen on [::]:2375" 
[runner--project-0-concurrent-0-docker] time="2017-06-07T20:53:37.573817608Z" level=info msg="API listen on /var/run/docker.sock" 
Using docker image sha256:26e52dd033d4116759722e2f48d742d8f6fd26aa7d6aec045a2d5d7a44b8a0d1 for predefined container...
Using locally found image version due to if-not-present pull policy
Using docker image alpine ID=sha256:a41a7446062d197dd4b21b38122dcc7b2399deb0750c4110925a7dd37c80f118 for build container...
Running on runner--project-0-concurrent-0 via apollo.h.maczukin.pl...
Cloning repository...
Cloning into '/builds/project-0'...
done.
Checking out ca76bb21 as master...
Skipping Git submodules setup
$ i=0
$ while [ $i -lt 5 ]; do echo "${CI_JOB_NAME} ${i}"; i=$((i + 1)); sleep 1; done
job1 0
job1 1
job1 2
job1 3
job1 4
$ echo "done"
done
Running after script...
Job succeeded

Why was this MR needed?

Please read #2119 for a reference. It may also help to investigate problems like #2347 where nothing helpful is logged into Runners logs and service's logs seems to be the only source of information (linked issue seems to be not related to services feature).

Are there points in the code the reviewer needs to double check?

Does this MR meet the acceptance criteria?

  • Documentation created/updated
  • Tests
    • Added for this feature/bug
    • All builds are passing
  • Branch has no merge conflicts with master (if you do - rebase it please)

What are the relevant issue numbers?

Closes #2119

Edited by Tomasz Maczukin

Merge request reports