Project

General

Profile

Actions

action #25844

closed

os-autoinst build test stuck on Debian - "unexpected end of string while parsing JSON string, at character offset 8000"

Added by henrich_debian over 6 years ago. Updated over 6 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
Support
Target version:
-
Start date:
2017-10-09
Due date:
% Done:

0%

Estimated time:

Description

Hi,

Building recent master branch on Debian system would be stuck during tests.

    make -j4 check VERBOSE=1

make[1]: Entering directory '/build/os-autoinst-4.3+git20171005'
Making check in t
make[2]: Entering directory '/build/os-autoinst-4.3+git20171005/t'
make PERL5OPT="-MDevel::Cover=-db,/build/os-autoinst-4.3+git20171005/t/cover_db" check-TESTS
make[3]: Entering directory '/build/os-autoinst-4.3+git20171005/t'
make[4]: Entering directory '/build/os-autoinst-4.3+git20171005/t'
PASS: 02-test_ocr.t
PASS: 04-check_vars_docu.t
PASS: 03-testapi.t
PASS: 05-pod.t
PASS: 01-test_needle.t
PASS: 06-pod-coverage.t
PASS: 08-autotest.t
PASS: 09-lockapi.t
PASS: 11-image-ppm.t
PASS: 12-bmwqemu.t
PASS: 13-osutils.t
PASS: 07-commands.t
PASS: 20-openqa-benchmark-stopwatch-utils.t
PASS: 10-terminal.t
PASS: 00-compile-check-all.t

and I cannot get any response.

At that time, 99-full-stack.t.log (and t/pool/autoinst-log.txt says)

unexpected end of string while parsing JSON string, at character offset 8000 (before "(end of string)") at /build/os-autoinst-4.3+git20171005/myjsonrpc.pm line 67.

and processes like below.

20827 pts/5 S 0:00 _ make -j4 check VERBOSE=1
20828 pts/5 S 0:00 _ /bin/bash -c fail=; \ if (target_option=k; case ${target_option-} in ?) ;; ) echo "am__make_running_with_option: internal error: invalid" "target
option '${target_option-}' specified" >&2; exit 1;; esac; has_opt=no; sane_makeflags=$MAKEFLAGS; if { if test -z '1'; then false; elif test -n 'x86_64-pc-linux-gnu'; then true; elif
test -n '4.1' && test -n '/build/os-autoinst-4.3+git20171005'; then true; else false; fi; }; then sane_makeflags=$MFLAGS; else case $MAKEFLAGS in *\[\ \?]
) bs=\; sane_makeflags=p
rintf '%s\n' "$MAKEFLAGS" | sed "s/$bs$bs[$bs $bs?]*//g"
;; esac; fi; skip_next=no; strip_trailopt () { flg=printf '%s\n' "$flg" | sed "s/$1.*$//"; }; for flg in $sane_makeflags; d
o test $skip_next = yes && { skip_next=no; continue; }; case $flg in =|--) continue;; -*I) strip_trailopt 'I'; skip_next=yes;; -*I?) strip_trailopt 'I';; -O) strip_trailopt 'O';
skip_next=yes;; -*O?
) strip_trailopt 'O';; -l) strip_trailopt 'l'; skip_next=yes;; -*l?) strip_trailopt 'l';; -[dEDm]) skip_next=yes;; -[JT]) skip_next=yes;; esac; case $flg in *
$target_option*) has_opt=yes; break;; esac; done; test $has_opt = yes); then \ failcom='fail=yes'; \ else \ failcom='exit 1'; \ fi; \ dot_seen=no; \ target=echo check-recursive
| sed s/-recursive//
; \ case "check-recursive" in \ distclean-* | maintainer-clean-) list='t debugviewer snd2png' ;; \ *) list='t debugviewer snd2png' ;; \ esac; \ for subdir i
n $list; do \ echo "Making $target in $subdir"; \ if test "$subdir" = "."; then \ dot_seen=yes; \ local_target="$target-am"; \ else \ local_target="$target"; \ fi
; \ (CDPATH="${ZSH_VERSION+.}:" && cd $subdir && make $local_target) \ || eval $failcom; \ done; \ if test "$dot_seen" = "no"; then \ make "$target-am" || exit 1; \ fi; test
-z "$fail"
20833 pts/5 S 0:00 _ /bin/bash -c fail=; \ if (target_option=k; case ${target_option-} in ?) ;; *) echo "am__make_running_with_option: internal error: invalid" "tar
get option '${target_option-}' specified" >&2; exit 1;; esac; has_opt=no; sane_makeflags=$MAKEFLAGS; if { if test -z '1'; then false; elif test -n 'x86_64-pc-linux-gnu'; then true; e
lif test -n '4.1' && test -n '/build/os-autoinst-4.3+git20171005'; then true; else false; fi; }; then sane_makeflags=$MFLAGS; else case $MAKEFLAGS in *\[\ \?]
) bs=\; sane_makeflag
s=printf '%s\n' "$MAKEFLAGS" | sed "s/$bs$bs[$bs $bs?]*//g";; esac; fi; skip_next=no; strip_trailopt () { flg=printf '%s\n' "$flg" | sed "s/$1.*$//"; }; for flg in $sane_makeflag
s; do test $skip_next = yes && { skip_next=no; continue; }; case $flg in =|--) continue;; -*I) strip_trailopt 'I'; skip_next=yes;; -*I?) strip_trailopt 'I';; -O) strip_trailopt
'O'; skip_next=yes;; -*O?
) strip_trailopt 'O';; -l) strip_trailopt 'l'; skip_next=yes;; -*l?) strip_trailopt 'l';; -[dEDm]) skip_next=yes;; -[JT]) skip_next=yes;; esac; case $flg
in $target_option) has_opt=yes; break;; esac; done; test $has_opt = yes); then \ failcom='fail=yes'; \ else \ failcom='exit 1'; \ fi; \ dot_seen=no; \ target=echo check-recurs
ive | sed s/-recursive//
; \ case "check-recursive" in \ distclean-* | maintainer-clean-) list='t debugviewer snd2png' ;; \ *) list='t debugviewer snd2png' ;; \ esac; \ for subd
ir in $list; do \ echo "Making $target in $subdir"; \ if test "$subdir" = "."; then \ dot_seen=yes; \ local_target="$target-am"; \ else \ local_target="$target"; \
fi; \ (CDPATH="${ZSH_VERSION+.}:" && cd $subdir && make $local_target) \ || eval $failcom; \ done; \ if test "$dot_seen" = "no"; then \ make "$target-am" || exit 1; \ fi; t
est -z "$fail"
20834 pts/5 S 0:00 _ make check
20835 pts/5 S 0:00 _ make PERL5OPT=-MDevel::Cover=-db,/build/os-autoinst-4.3+git20171005/t/cover_db check-TESTS
20841 pts/5 S 0:00 _ /bin/bash -c set +e; bases='00-compile-check-all.t.log 01-test_needle.t.log 02-test_ocr.t.log 03-testapi.t.log 04-check_vars_docu.t
.log 05-pod.t.log 06-pod-coverage.t.log 07-commands.t.log 08-autotest.t.log 09-lockapi.t.log 10-terminal.t.log 11-image-ppm.t.log 12-bmwqemu.t.log 13-osutils.t.log 20-openqa-benchmar
k-stopwatch-utils.t.log 99-full-stack.t.log'; bases=for i in $bases; do echo $i; done | sed 's/\.log$//'; bases=echo $bases; \ log_list=for i in $bases; do echo $i.log; done; \
trs_list=for i in $bases; do echo $i.trs; done; \ log_list=echo $log_list; trs_list=echo $trs_list; \ make PERL5OPT="-MDevel::Cover=-db,/build/os-autoinst-4.3+git20171005/t/co
ver_db" test-suite.log TEST_LOGS="$log_list"; \ exit $?;
20851 pts/5 S 0:00 _ make PERL5OPT=-MDevel::Cover=-db,/build/os-autoinst-4.3+git20171005/t/cover_db test-suite.log TEST_LOGS=00-compile-check-all.t.
log 01-test_needle.t.log 02-test_ocr.t.log 03-testapi.t.log 04-check_vars_docu.t.log 05-pod.t.log 06-pod-coverage.t.log 07-commands.t.log 08-autotest.t.log 09-lockapi.t.log 10-termin
al.t.log 11-image-ppm.t.log 12-bmwqemu.t.log 13-osutils.t.log 20-openqa-benchmark-stopwatch-utils.t.log 99-full-stack.t.log
21102 pts/5 S 0:00 _ /bin/bash -c p='99-full-stack.t'; \ b='99-full-stack.t'; \ case $- in *e
) set +e;; esac; srcdirstrip=echo "." | sed 's|.|
.|g'
; case $p in ./) f=echo "$p" | sed "s|^$srcdirstrip/||";; *) f=$p;; esac; { mgn= red= grn= lgn= blu= brg= std=; am_color_tests=no; if test "X" = Xno; then amcolor_tests=no
; elif test "X" = Xalways; then am
color_tests=yes; elif test "X$TERM" != Xdumb && { test -t 1; } 2>/dev/null; then amcolor_tests=yes; fi; if test $am_color_tests = yes; then red
='?[0;31m'; grn='?[0;32m'; lgn='?[1;32m'; blu='?[1;34m'; mgn='?[0;35m'; brg='?[1m'; std='?[m'; fi; }; srcdir=.; export srcdir; case "99-full-stack.t.log" in */
) am_odir=echo "./99
-full-stack.t.log" | sed 's|/[^/]*$||'
;; *) am
odir=.;; esac; test "x$amodir" = x"." || test -d "$amodir" || /bin/mkdir -p "$amodir" || exit $?; if test -f "./$f"; then dir=.
/; elif test -f "$f"; then dir=; else dir="./"; fi; tst=$dir$f; log='99-full-stack.t.log'; if test -n ''; then am
enable_hard_errors=no; else amenable_hard_errors=yes; fi; case "
" in [\ \?]$f[\ \?] | [\ \?]$dir$f[\ \?]) am
expect_failure=yes;; *) amexpect_failure=no;; esac; /bin/bash ../test-driver --test-name "$f" \ --log-file $b.log --trs-file $b
.trs \ --color-tests "$am
color_tests" --enable-hard-errors "$amenable_hard_errors" --expect-failure "$am_expect_failure" -- \ "$tst"
21106 pts/5 S 0:00 _ /bin/bash ../test-driver --test-name 99-full-stack.t --log-file 99-full-stack.t.log --trs-file 99-full-stack.t.trs --co
lor-tests no --enable-hard-errors yes --expect-failure no -- ./99-full-stack.t
21107 pts/5 S 0:00 _ /usr/bin/perl ./99-full-stack.t
22922 pts/5 S 0:00 _ sh -c perl /build/os-autoinst-4.3+git20171005/isotovideo -d 2>&1 | tee autoinst-log.txt
22923 pts/5 S 0:00 _ perl /build/os-autoinst-4.3+git20171005/isotovideo -d
22963 pts/5 S 0:00 | _ /build/os-autoinst-4.3+git20171005/isotovideo: commands
22964 pts/5 Sl 0:00 | _ /build/os-autoinst-4.3+git20171005/isotovideo: autotest
22967 pts/5 Sl 0:00 | _ /build/os-autoinst-4.3+git20171005/isotovideo: backend
22972 pts/5 SNl 0:00 | _ /build/os-autoinst-4.3+git20171005/videoencoder /build/os-autoinst-4.3+git20171005/t/pool/video.ogv

22975 pts/5 Sl 0:17 | _ /usr/bin/qemu-system-i386 -serial file:serial0 -soundhw ac97 -vga cirrus -m 1024 -netdev user,id=qa
net0 -device virtio-net,netdev=qanet0,mac=52:54:00:12:34:56 -device ide-drive,drive=hd1,serial=1 -drive file=raid/l1,cache=unsafe,if=none,id=hd1,format=qcow2 -drive media=cdrom,if=no
ne,id=cd0,format=raw,file=/build/os-autoinst-4.3+git20171005/t/data//Core-7.2.iso -device ide-cd,drive=cd0 -boot once=d,menu=on,splash-time=5000 -smp 1 -no-shutdown -vnc :90,share=fo
rce-shared -qmp unix:qmp_socket,server,nowait -monitor unix:hmp_socket,server,nowait -S -monitor telnet:127.0.0.1:15222,server,nowait
22924 pts/5 S 0:00

Could you give me any hint, please?


Files

99-full-stack.t.log (5.27 KB) 99-full-stack.t.log henrich_debian, 2017-10-09 05:49
ps.txt (9.54 KB) ps.txt process status henrich_debian, 2017-10-09 05:50
Actions #1

Updated by coolo over 6 years ago

First of all: tried without -j4?

Updated by henrich_debian over 6 years ago

coolo wrote:

First of all: tried without -j4?

Unfortunately, still stuck...

Actions #3

Updated by okurz over 6 years ago

  • Category set to Support

Are you sure the test does not just take very very long? For me the full-stack test takes about 5 minutes, much longer than all <99 tests.

Actions #4

Updated by henrich_debian over 6 years ago

Yes, I've waiting it for 10 hours or so (in a first time with -j4).
And now, it takes 30 minutes, at least.

My desktop is Intel Core i5, mem16GB, SSD machine, so I guess it doesn't take long time.
Old git snapshot (at 20160919) is built fine (but, yes, I know there are lots of changes from then).

Actions #5

Updated by coolo over 6 years ago

this JSON parsing is the problem - triggering a bug that makes the whole thing hang. But let's concentrate on the JSON parse problem, add debug there - 8000 bytes sound cut off to me

Actions #6

Updated by okurz over 6 years ago

  • Subject changed from os-autoinst build test stuck to os-autoinst build test stuck on Debian - "unexpected end of string while parsing JSON string, at character offset 8000"
  • Category changed from Support to Regressions/Crashes
Actions #7

Updated by henrich_debian over 6 years ago

Just a note, it's same result on Debian8 "Jessie" and Debian9 "Stretch" cowbuilder environment.

$ tail 99-full-stack.t.log
08:44:22.5568 12485 no change: 10.0s
08:44:22.6663 12485 MATCH(boot-core:0.00)
08:44:22.6665 12485 no match: 9.9s
08:44:22.7679 12485 no change: 9.8s
08:44:22.8690 12485 no change: 9.7s
08:44:22.9704 12485 no change: 9.6s
08:44:23.0722 12485 no change: 9.5s
08:44:23.1838 12485 MATCH(boot-core:0.97)
unexpected end of string while parsing JSON string, at character offset 8000 (before "(end of string)") at /build/os-autoinst-4.3+git20171005/myjsonrpc.pm line 67.
08:44:23.2434 12466 killing backend process 12485
Actions #8

Updated by henrich_debian over 6 years ago

coolo wrote:

this JSON parsing is the problem - triggering a bug that makes the whole thing hang. But let's concentrate on the JSON parse problem, add debug there - 8000 bytes sound cut off to me

Well, how to debug it in a smart way, please let me know.

Actions #9

Updated by henrich_debian over 6 years ago

I'm very sorry, I didn't notice that os-autoinst dependency was largely changed since last year,
after update dependencies all goes smooth (tiny change is necessary so I'll put PR later).

Actions #10

Updated by okurz over 6 years ago

  • Category changed from Regressions/Crashes to Support
  • Status changed from New to In Progress
  • Assignee set to okurz

great! Btw, I'm curious. Is this endeavour of yours related to openqa.debian.net ?

Actions #11

Updated by henrich_debian over 6 years ago

Currently openqa.debian.net (runs by Phil) is not set up with Debian package. But after finish packaging, it will migrate to deb package based one.

Actions #12

Updated by okurz over 6 years ago

  • Status changed from In Progress to Resolved

According to #25844#note-9 I assume it's fixed

Actions

Also available in: Atom PDF