hashar added a comment.
With `TINY_VERBOSITY=3` and `docker -D -l debug run`:
08:58:27 [INFO tini (1)] Main child exited normally (with status '1')
08:58:28 time="2020-10-28T08:58:28Z" level=debug msg="[hijack] End of
stdout"
08:58:38 Build step 'Execute shell' marked build as failure
08:58:38 Archiving artifacts
I had strace attached to the `docker run` process:
lsof -p 25752
COMMAND PID USER FD TYPE DEVICE SIZE/OFF
NODE NAME
docker 25752 jenkins-deploy cwd DIR 253,1 4096
788000 /srv/jenkins/workspace/workspace/integration-quibble-fullrun
docker 25752 jenkins-deploy rtd DIR 254,3 4096
2 /
docker 25752 jenkins-deploy txt REG 254,3 88967576
396341 /usr/bin/docker
docker 25752 jenkins-deploy mem REG 254,3 102803208
262167 /var/cache/nscd/passwd
docker 25752 jenkins-deploy mem REG 254,3 1689360
1048605 /lib/x86_64-linux-gnu/libc-2.24.so
docker 25752 jenkins-deploy mem REG 254,3 14640
1048608 /lib/x86_64-linux-gnu/libdl-2.24.so
docker 25752 jenkins-deploy mem REG 254,3 135440
1048634 /lib/x86_64-linux-gnu/libpthread-2.24.so
docker 25752 jenkins-deploy mem REG 254,3 153288
1048601 /lib/x86_64-linux-gnu/ld-2.24.so
docker 25752 jenkins-deploy 0r FIFO 0,10 0t0
37856380 pipe
docker 25752 jenkins-deploy 1w FIFO 0,10 0t0
37856381 pipe
docker 25752 jenkins-deploy 2w FIFO 0,10 0t0
37856381 pipe
docker 25752 jenkins-deploy 3u unix 0xffff9c0f4c584800 0t0
37858369 type=STREAM
docker 25752 jenkins-deploy 4u a_inode 0,11 0
7575 [eventpoll]
docker 25752 jenkins-deploy 5u unix 0xffff9c0f40ca7400 0t0
37848939 type=STREAM
docker 25752 jenkins-deploy 6u unix 0xffff9c0f29f3e000 0t0
37855997 type=STREAM
docker 25752 jenkins-deploy 63r FIFO 0,10 0t0
37858367 pipe
File descriptor 5 comes from container-shim and is the process output. 1 is
stdout and 2 is stderr which are read by the Jenkins console.
name=strace -tt -yy
# Python traceback
08:58:27.167448 read(5<UNIX:[37848939->37856385]>,
"\2\0\0\0\0\0\4\262Traceback (most recent c"..., 32777) = 1210
08:58:27.167629 write(2<pipe:[37856381]>, "Traceback (most recent call
last"..., 1202) = 1202
08:58:27.168045 read(5<UNIX:[37848939->37856385]>, 0xc00060c000, 32777) =
-1 EAGAIN (Resource temporarily unavailable)
08:58:27.168210 epoll_pwait(4<anon_inode:[eventpoll]>, [], 128, 0, NULL, 0)
= 0
08:58:27.168356 epoll_pwait(4<anon_inode:[eventpoll]>, [{EPOLLIN|EPOLLOUT,
{u32=2869452344, u64=140645868527160}}], 128, -1, NULL, 0) = 1
08:58:27.216842 futex(0x56457b0f20d0, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:27.216992 futex(0x56457b0f1fd0, FUTEX_WAKE_PRIVATE, 1) = 1
# tiny output
08:58:27.217106 read(5<UNIX:[37848939->37856385]>, "\1\0\0\0\0\0\n\32[INFO
tini (1)] Spawned"..., 32777) = 2594
08:58:27.217293 write(1<pipe:[37856381]>, "[INFO tini (1)] Spawned child
p"..., 2586) = 2586
08:58:27.217471 read(5<UNIX:[37848939->37856385]>, 0xc00060c000, 32777) =
-1 EAGAIN (Resource temporarily unavailable)
08:58:27.217603 epoll_pwait(4<anon_inode:[eventpoll]>, [], 128, 0, NULL, 0)
= 0
08:58:27.217800 epoll_pwait(4<anon_inode:[eventpoll]>,
[{EPOLLIN|EPOLLOUT|EPOLLHUP|EPOLLRDHUP, {u32=2869452344,
u64=140645868527160}}], 128, -1, NULL, 0) = 1
08:58:28.230175 futex(0x56457b0f20d0, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:28.230378 futex(0x56457b0f1fd0, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:28.230586 read(5<UNIX:[37848939->37856385]>, "", 32777) = 0
08:58:28.231167 ioctl(2<pipe:[37856381]>, TCGETS, 0xc0002286b4) = -1 ENOTTY
(Inappropriate ioctl for device)
# Docker run debug message: time="2020-10-28T08:58:28Z" level=debug
msg="[hijack] End of stdout"
08:58:28.231596 openat(AT_FDCWD, "/etc//localtime", O_RDONLY) =
7</usr/share/zoneinfo/UCT>
08:58:28.231833 read(7</usr/share/zoneinfo/UCT>,
"TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0\0\0\0"..., 4096) = 127
08:58:28.232004 read(7</usr/share/zoneinfo/UCT>, "", 4096) = 0
08:58:28.232167 close(7</usr/share/zoneinfo/UCT>) = 0
08:58:28.232403 write(2<pipe:[37856381]>, "time=\"2020-10-28T08:58:28Z\"
leve"..., 69) = 69
08:58:28.232624 futex(0xc0004f2148, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:28.232860 epoll_pwait(4<anon_inode:[eventpoll]>, [], 128, 0, NULL,
824640192576) = 0
08:58:28.233009 futex(0x56457b0f2d88, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
08:58:31.637180 futex(0x56457b0f2d88, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
# five seconds delay??
08:58:36.637075 futex(0x56457b0f20c0, FUTEX_WAKE_PRIVATE, 1) = 0
08:58:36.637223 futex(0x56457b0f1fd0, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:36.641284 futex(0x56457b0f2d88, FUTEX_WAIT_PRIVATE, 0, NULL) = -1
EAGAIN (Resource temporarily unavailable)
08:58:36.641482 futex(0x56457b0f20e8, FUTEX_WAKE_PRIVATE, 1) = 0
08:58:36.641624 futex(0x56457b0f1fd0, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:36.641824 futex(0x56457b0f2d88, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
# Some more wait
08:58:38.146730 epoll_pwait(4<anon_inode:[eventpoll]>, [], 128, 0, NULL, 0)
= 0
08:58:38.147022 futex(0xc0000b8148, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:38.147191 futex(0xc0000b8148, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:38.147363 futex(0xc00045b2c8, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:38.147560 futex(0x56457b0f2d88, FUTEX_WAIT_PRIVATE, 0, NULL) = 0
08:58:38.147920 nanosleep({tv_sec=0, tv_nsec=3000}, NULL) = 0
08:58:38.148169 futex(0xc000502148, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:38.148300 futex(0xc000502148, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:38.148474 futex(0xc00045b2c8, FUTEX_WAKE_PRIVATE, 1) = 1
08:58:38.148661 futex(0x56457b0f2d88, FUTEX_WAIT_PRIVATE, 0, NULL) = ?
08:58:38.154553 +++ exited with 1 +++
I was **NOT** tracing threads (`strace -f`) ...
TASK DETAIL
https://phabricator.wikimedia.org/T265615
EMAIL PREFERENCES
https://phabricator.wikimedia.org/settings/panel/emailpreferences/
To: hashar
Cc: Daimona, thcipriani, hashar, awight, kostajh, Lucas_Werkmeister_WMDE,
Alter-paule, Beast1978, Un1tY, Akuckartz, Hook696, Kent7301, joker88john,
CucyNoiD, Nandana, NebulousIris, Gaboe420, Giuliamocci, Cpaulf30, Lahi, Gq86,
Af420, Bsandipan, GoranSMilovanovic, QZanden, LawExplorer, Lewizho99,
Maathavan, _jensen, rosalieper, Liudvikas, Scott_WUaS, Wikidata-bugs, aude,
Jdforrester-WMF, Mbch331, Jay8g
_______________________________________________
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs
