On 08/03/2019 11:18, Aki Tuomi via dovecot wrote:
On 7.3.2019 23.37, A. Schulze via dovecot wrote:
Am 07.03.19 um 17:33 schrieb Aki Tuomi via dovecot:
test-http-client-errors.c:2989: Assert failed: FALSE connection timed out ................................................. : FAILED Hello Aki,
Are you running with valgrind or on really slow system? I'm not aware my buildsystem use valgrind ...
How do you define "a really slow system"? All I can mention as reference is a build time of 11 minutes until the error occur.
Does it happen if you run env NOVALGRIND=yes make check? yes,
Andreas
The assertion occurs because it seems to take too long to complete the test, that's why it's asserting FALSE (see the comment above the line). Can you run the test with strace and provide strace output?
Hi, I have this same error building dovecot 2.3.5 + pigeonhole 0.5.5 in a debian system, payload tests seems to be passed, I've run the test with sctrace and this is the output (just after the last "ok" test)
Plese, let me know yf you need the full strace output and I'll send an URL.
Regards Juan C. Blanco
% uname -a Linux druida 4.9.0-8-amd64 #1 SMP Debian 4.9.144-3.1 (2019-02-19) x86_64 GNU/Linux
write(1, "connection lost after 100-contin"..., 76connection lost after 100-continue ................................... : ok ) = 76 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 5 setsockopt(5, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 setsockopt(5, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 bind(5, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("127.0.0.1")}, 16) = 0 getsockname(5, {sa_family=AF_INET, sin_port=htons(41571), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 listen(5, 128) = 0 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 6 setsockopt(6, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 setsockopt(6, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 bind(6, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("127.0.0.1")}, 16) = 0 getsockname(6, {sa_family=AF_INET, sin_port=htons(33519), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 listen(6, 128) = 0 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7feb580a69d0) = 336 close(5) = 0 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7feb580a69d0) = 337 close(6) = 0 nanosleep({tv_sec=0, tv_nsec=100000000}, NULL) = 0 epoll_create(128) = 5 fcntl(5, F_GETFD) = 0 fcntl(5, F_SETFD, FD_CLOEXEC) = 0 nanosleep({tv_sec=0, tv_nsec=0}, NULL) = 0 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 6 setsockopt(6, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 setsockopt(6, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 fcntl(6, F_GETFL) = 0x2 (flags O_RDWR) fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0 connect(6, {sa_family=AF_INET, sin_port=htons(41571), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) epoll_ctl(5, EPOLL_CTL_ADD, 6, {EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=858285952, u64=94911045592960}}) = 0 epoll_wait(5, [{EPOLLOUT, {u32=858285952, u64=94911045592960}}], 1, 10000) = 1 epoll_ctl(5, EPOLL_CTL_DEL, 6, 0x7ffd3310d74c) = 0 getsockopt(6, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 fstat(6, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fcntl(6, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) lseek(6, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) getsockname(6, {sa_family=AF_INET, sin_port=htons(42206), sin_addr=inet_addr("127.0.0.1")}, [28->16]) = 0 epoll_ctl(5, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=858285952, u64=94911045592960}}) = 0 setsockopt(6, SOL_TCP, TCP_NODELAY, [1], 4) = 0 epoll_wait(5, [], 1, 0) = 0 setsockopt(6, SOL_TCP, TCP_CORK, [1], 4) = 0 write(6, "GET /connection-lost-sub-ioloop."..., 175) = 175 setsockopt(6, SOL_TCP, TCP_CORK, [0], 4) = 0 epoll_wait(5, [{EPOLLIN, {u32=858285952, u64=94911045592960}}], 1, 2000) = 1 read(6, "HTTP/1.1 200 OK\r\nContent-Length:"..., 8192) = 38 epoll_create(128) = 7 fcntl(7, F_GETFD) = 0 fcntl(7, F_SETFD, FD_CLOEXEC) = 0 epoll_ctl(7, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=858284832, u64=94911045591840}}) = 0 epoll_ctl(5, EPOLL_CTL_DEL, 6, 0x7ffd3310d4fc) = 0 epoll_wait(7, [], 1, 0) = 0 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 8 setsockopt(8, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 setsockopt(8, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 fcntl(8, F_GETFL) = 0x2 (flags O_RDWR) fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0 connect(8, {sa_family=AF_INET, sin_port=htons(33519), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) epoll_ctl(7, EPOLL_CTL_ADD, 8, {EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=858330688, u64=94911045637696}}) = 0 epoll_wait(7, [{EPOLLOUT, {u32=858330688, u64=94911045637696}}], 2, 60000) = 1 epoll_ctl(7, EPOLL_CTL_DEL, 8, 0x7ffd3310d49c) = 0 getsockopt(8, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 fstat(8, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0 fcntl(8, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) lseek(8, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) getsockname(8, {sa_family=AF_INET, sin_port=htons(43994), sin_addr=inet_addr("127.0.0.1")}, [28->16]) = 0 epoll_ctl(7, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=858330688, u64=94911045637696}}) = 0 setsockopt(8, SOL_TCP, TCP_NODELAY, [1], 4) = 0 epoll_wait(7, [], 2, 0) = 0 setsockopt(8, SOL_TCP, TCP_CORK, [1], 4) = 0 write(8, "GET /connection-lost-sub-ioloop3"..., 133) = 133 setsockopt(8, SOL_TCP, TCP_CORK, [0], 4) = 0 epoll_wait(7, [{EPOLLIN, {u32=858330688, u64=94911045637696}}], 2, 60000) = 1 read(8, "HTTP/1.1 200 OK\r\nContent-Length:"..., 8192) = 38 read(8, 0x565233294d56, 8154) = -1 EAGAIN (Resource temporarily unavailable) epoll_ctl(5, EPOLL_CTL_ADD, 8, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=858317600, u64=94911045624608}}) = 0 epoll_ctl(7, EPOLL_CTL_DEL, 8, 0x7ffd3310d4fc) = 0 epoll_ctl(5, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=858285952, u64=94911045592960}}) = 0 epoll_ctl(7, EPOLL_CTL_DEL, 6, 0x7ffd3310d4fc) = 0 close(7) = 0 read(6, 0x56523328b266, 8154) = -1 EAGAIN (Resource temporarily unavailable) epoll_wait(5, [], 2, 0) = 0 setsockopt(6, SOL_TCP, TCP_CORK, [1], 4) = 0 write(6, "GET /connection-lost-sub-ioloop2"..., 176) = 176 setsockopt(6, SOL_TCP, TCP_CORK, [0], 4) = 0 epoll_wait(5, [{EPOLLIN|EPOLLERR|EPOLLHUP, {u32=858317600, u64=94911045624608}}], 2, 100) = 1 read(8, 0x565233294d56, 8154) = -1 ECONNRESET (Connection reset by peer) epoll_ctl(5, EPOLL_CTL_DEL, 8, 0x7ffd3310d5ac) = 0 close(8) = 0 epoll_wait(5, [], 2, 0) = 0 epoll_wait(5, [{EPOLLIN|EPOLLERR|EPOLLHUP, {u32=858285952, u64=94911045592960}}], 2, 99) = 1 read(6, 0x56523328b266, 8154) = -1 ECONNRESET (Connection reset by peer) write(1, "test-http-client-errors.c:1319: "..., 67test-http-client-errors.c:1319: Assert failed: resp->status == 200 ) = 67 epoll_create(128) = 7 fcntl(7, F_GETFD) = 0 fcntl(7, F_SETFD, FD_CLOEXEC) = 0 epoll_ctl(7, EPOLL_CTL_ADD, 6, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=858286304, u64=94911045593312}}) = 0 epoll_ctl(5, EPOLL_CTL_DEL, 6, 0x7ffd3310d46c) = 0 epoll_wait(7, [{EPOLLIN|EPOLLHUP, {u32=858286304, u64=94911045593312}}], 1, 0) = 1 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 8 setsockopt(8, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0 setsockopt(8, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 fcntl(8, F_GETFL) = 0x2 (flags O_RDWR) fcntl(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0 connect(8, {sa_family=AF_INET, sin_port=htons(33519), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS (Operation now in progress) epoll_ctl(7, EPOLL_CTL_ADD, 8, {EPOLLOUT|EPOLLERR|EPOLLHUP, {u32=858326480, u64=94911045633488}}) = 0 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0x30} --- kill(336, SIGKILL) = 0 wait4(336, NULL, 0, NULL) = -1 ECHILD (No child processes) kill(337, SIGKILL) = 0 wait4(337, NULL, 0, NULL) = -1 ECHILD (No child processes) rt_sigaction(SIGSEGV, {sa_handler=SIG_DFL, sa_mask=[SEGV], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7feb57931060}, {sa_handler=0x565231d69b50, sa_mask=[SEGV], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7feb57931060}, 8) = 0 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [SEGV], 8) = 0 rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [SEGV], 8) = 0 getpid() = 301 gettid() = 301 tgkill(301, 301, SIGSEGV) = 0 rt_sigprocmask(SIG_SETMASK, [SEGV], NULL, 8) = 0 rt_sigreturn({mask=[]}) = 94911045584064 --- SIGSEGV {si_signo=SIGSEGV, si_code=SI_TKILL, si_pid=301, si_uid=0} --- +++ killed by SIGSEGV +++
Aki
-- +-------------------------------------------------------------------+ | Juan C. Blanco | | | | Centro de Calculo | | | E.T.S. Ingenieros Informáticos | E-mail: jcblanco@fi.upm.es | | Universidad Politécnica de Madrid | | | Campus de Montegancedo | | | Boadilla del Monte | Tel.: (+34) 91 067 2771 | | 28660 MADRID (Spain) | Fax : (+34) 91 336 7412 | +-------------------------------------------------------------------+