[0KRunning with gitlab-runner 13.1.1 (6fbc7474) [0;m[0K on ci-02.labs.nic.cz RYQ6yyqH [0;msection_start:1615892288:prepare_executor [0K[0K[36;1mPreparing the "docker" executor[0;m [0;m[0KUsing Docker executor with image registry.nic.cz/knot/knot-resolver/ci/debian-buster:knot-3.0 ... [0;m[0KAuthenticating with credentials from job payload (GitLab Registry) [0;m[0KPulling docker image registry.nic.cz/knot/knot-resolver/ci/debian-buster:knot-3.0 ... [0;m[0KUsing docker image sha256:5eed268bb278abe2484d895a308e124cfc342facf102d4756fc2087fa04444d4 for registry.nic.cz/knot/knot-resolver/ci/debian-buster:knot-3.0 ... [0;msection_end:1615892298:prepare_executor [0Ksection_start:1615892298:prepare_script [0K[0K[36;1mPreparing environment[0;m [0;mRunning on runner-ryq6yyqh-project-147-concurrent-3 via ci-new-02... section_end:1615892302:prepare_script [0Ksection_start:1615892302:get_sources [0K[0K[36;1mGetting source from Git repository[0;m [0;m[32;1mFetching changes...[0;m Initialized empty Git repository in /builds/knot/knot-resolver/.git/ [32;1mCreated fresh repository.[0;m [32;1mChecking out 7c2c6537 as ci-gc-sanity-check...[0;m [32;1mUpdating/initializing submodules recursively...[0;m Submodule 'modules/policy/lua-aho-corasick' (https://gitlab.nic.cz/knot/3rdparty/lua-aho-corasick.git) registered for path 'modules/policy/lua-aho-corasick' Submodule 'tests/config/tapered' (https://gitlab.nic.cz/knot/3rdparty/lua-tapered.git) registered for path 'tests/config/tapered' Submodule 'tests/integration/deckard' (https://gitlab.nic.cz/knot/deckard.git) registered for path 'tests/integration/deckard' Cloning into '/builds/knot/knot-resolver/modules/policy/lua-aho-corasick'... Cloning into '/builds/knot/knot-resolver/tests/config/tapered'... Cloning into '/builds/knot/knot-resolver/tests/integration/deckard'... Submodule path 'modules/policy/lua-aho-corasick': checked out '88f08a8777ab231b259e008507879806cd9f268b' Submodule path 'tests/config/tapered': checked out 'be84b64d18293a29ca0acdf0431b0345084afe33' Submodule path 'tests/integration/deckard': checked out 'ff1e8471785cedada669bf2304442ac0e86b7988' Entering 'modules/policy/lua-aho-corasick' Entering 'tests/config/tapered' Entering 'tests/integration/deckard' section_end:1615892313:get_sources [0Ksection_start:1615892313:download_artifacts [0K[0K[36;1mDownloading artifacts[0;m [0;m[32;1mDownloading artifacts for build-asan (506920)...[0;m Downloading artifacts from coordinator... ok [0;m id[0;m=506920 responseStatus[0;m=200 OK token[0;m=KbEwbhNt section_end:1615892321:download_artifacts [0Ksection_start:1615892321:step_script [0K[0K[36;1mExecuting "step_script" stage of the job script[0;m [0;m[32;1m$ ninja -C build_ci* &>/dev/null[0;m [32;1m$ rm build_ci*/meson-logs/testlog*.txt[0;m [32;1m$ ulimit -n "$(ulimit -Hn)"[0;m [32;1m$ ./ci/respdiff/start-resolvers.sh[0;m Starting DNS server: unbound. unbound is running. Starting domain name service...: bind9. bind9 is running. [32;1m$ ./ci/respdiff/run-respdiff-tests.sh udp[0;m + NDIFFREPRO=3 + wget -qO- 'https://gitlab.nic.cz/knot/respdiff/snippets/238/raw?inline=false' + head -n 5000 + mkdir results + rm -rf respdiff.db ++ pwd + CONFIG=/builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf + /var/opt/respdiff/qprep.py respdiff.db 2021-03-16 10:59:19,201 DEBUG Comitting LMDB transaction... + /var/opt/respdiff/orchestrator.py respdiff.db -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf 2021-03-16 11:00:11,248 DEBUG Comitting LMDB transaction... real 0m52.136s user 0m2.268s sys 0m1.560s + /var/opt/respdiff/msgdiff.py respdiff.db -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf real 0m3.429s user 0m38.864s sys 0m2.408s ++ seq 3 + for i in $(seq $NDIFFREPRO) + /var/opt/respdiff/diffrepro.py -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf respdiff.db Stopping domain name service...: bind9waiting for pid 439 to die . Starting domain name service...: bind9. Restarting DNS server: unbound. 2021-03-16 11:00:30,941 DEBUG Processed 5 queries real 0m16.036s user 0m1.328s sys 0m2.340s + for i in $(seq $NDIFFREPRO) + /var/opt/respdiff/diffrepro.py -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf respdiff.db 2021-03-16 11:00:31,669 DEBUG Skipping QID 729: unstable upstream 2021-03-16 11:00:31,670 DEBUG Skipping QID 420: unstable upstream 2021-03-16 11:00:31,670 DEBUG Skipping QID 830: unstable upstream 2021-03-16 11:00:31,670 DEBUG Skipping QID 2366: not 100 % reproducible Stopping domain name service...: bind9waiting for pid 814 to die . Starting domain name service...: bind9. Restarting DNS server: unbound. 2021-03-16 11:00:47,143 DEBUG Processed 1 queries real 0m18.731s user 0m1.176s sys 0m2.184s + for i in $(seq $NDIFFREPRO) + /var/opt/respdiff/diffrepro.py -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf respdiff.db 2021-03-16 11:00:50,387 DEBUG Skipping QID 830: unstable upstream 2021-03-16 11:00:50,388 DEBUG Skipping QID 2366: not 100 % reproducible 2021-03-16 11:00:50,388 DEBUG Skipping QID 3126: unstable upstream 2021-03-16 11:00:50,388 DEBUG Skipping QID 729: unstable upstream 2021-03-16 11:00:50,388 DEBUG Skipping QID 420: unstable upstream real 0m0.802s user 0m0.992s sys 0m1.884s + /var/opt/respdiff/diffsum.py respdiff.db -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf + /var/opt/respdiff/histogram.py respdiff.db -c /builds/knot/knot-resolver/ci/respdiff/respdiff-udp.conf -o results/histogram.svg + : minimize LMDB and log size so they can be effectively archived + mkdir results/respdiff.db + mdb_copy -c respdiff.db results/respdiff.db + xz -9 results/respdiff.db/data.mdb + xz kresd.log [32;1m$ $PREFIX/sbin/kres-cache-gc -c . -u 0[0;m Knot Resolver Cache Garbage Collector, version 5.3.0 Usage: 0.35% Cache analyzed in 25 msecs, 26319 records, limit category is 51. kres-cache-gc: ../utils/cache_gc/kr_cache_gc.c:280: int kr_cache_gc(kr_cache_gc_cfg_t *, kr_cache_gc_state_t **): Assertion `entry_type != NULL' failed. 5886 records to be deleted using 0.14 MBytes of temporary memory, 0 records skipped due to memory limit. /bin/bash: line 126: 1200 Aborted $PREFIX/sbin/kres-cache-gc -c . -u 0 section_end:1615892465:step_script [0Ksection_start:1615892465:after_script [0K[0K[36;1mRunning after_script[0;m [0;m[32;1mRunning after script...[0;m [32;1m$ killall --wait kresd[0;m kresd: no process found section_end:1615892467:after_script [0Ksection_start:1615892467:upload_artifacts_on_failure [0K[0K[36;1mUploading artifacts for failed job[0;m [0;m[32;1mUploading artifacts...[0;m kresd.log*: found 1 matching files and directories[0;m results/*.txt: found 1 matching files and directories[0;m [0;33mWARNING: results/*.png: no matching files [0;m results/respdiff.db/data.mdb*: found 1 matching files and directories[0;m [0;33mWARNING: ./*.info: no matching files [0;m Uploading artifacts as "archive" to coordinator... ok[0;m id[0;m=506931 responseStatus[0;m=201 Created token[0;m=fyxdsB7B section_end:1615892470:upload_artifacts_on_failure [0K[31;1mERROR: Job failed: exit code 1 [0;m