GNU bug report logs - #51391
Guile-SSH 0.13.1 test suite fails non-deterministically

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 51391 in the body.
You can then email your comments to 51391 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: bug-guix <bug-guix <at> gnu.org>
Subject: Guile-SSH 0.13.1 test suite fails non-deterministically
Date: Mon, 25 Oct 2021 14:14:40 -0400

Hello Guix!

I encountered the following Guile-SSH test failure while testing the
core-updates-frozen-batched-changes branch:

--8<---------------cut here---------------start------------->8---
Test suite failed, dumping logs.

--- ./tests/test-suite.log --------------------------------------------------

============================================
   Guile-SSH 0.13.1: tests/test-suite.log
============================================

# TOTAL: 11
# PASS:  10
# SKIP:  0
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: session
=============

%%%% Starting test session
Group begin: session
Test begin:
  test-name: "%make-session"
  source-file: "tests/session.scm"
  source-line: 38
  source-form: (test-assert "%make-session" (%make-session))
Test end:
  result-kind: pass
  actual-value: #<session #<undefined>@#<undefined>:22 (disconnected) 7fffefd6dfe0>
Test begin:
  test-name: "%make-session, gc test"
  source-file: "tests/session.scm"
  source-line: 41
  source-form: (test-assert "%make-session, gc test" (begin (set-log-userdata! "%make-session, gc test") (let ((max-sessions 1000)) (do ((idx 1 (+ idx 1))) ((> idx max-sessions)) (when (zero? (euclidean-remainder idx 100)) (format-log/scm (quote nolog) "" (format #f "~d / ~d sessions created ..." idx max-sessions))) (%make-session)) #t)))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "session?"
  source-file: "tests/session.scm"
  source-line: 51
  source-form: (test-assert "session?" (let ((session (%make-session)) (x "string")) (and (session? session) (not (session? x)))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "comparison of sessions"
  source-file: "tests/session.scm"
  source-line: 57
  source-form: (test-assert "comparison of sessions" (let ((s1 (%make-session)) (s2 (%make-session))) (and (equal? s1 s1) (not (equal? s1 s2)))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "session-set!, valid values"
  source-file: "tests/session.scm"
  source-line: 63
  source-form: (test-assert "session-set!, valid values" (let ((session (%make-session)) (options (quasiquote ((host "localhost") (port 22) (bindaddr "127.0.0.1") (user "Random J. User") (timeout 15) (timeout-usec 15000) (ssh1 #f #t) (ssh2 #f #t) (log-verbosity nolog rare protocol packet functions nolog) (compression-level 1 2 3 4 5 6 7 8 9) (compression "yes" "no") (callbacks ((user-data . "hello") (global-request-callback unquote (const #f))))))) (res #t)) (if (>= %libssh-minor-version 8) (set! options (cons (quote (nodelay #f #t)) options))) (for-each (lambda (opt) (for-each (lambda (val) (session-set! session (car opt) val)) (cdr opt))) options) res))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "session-set!, invalid values"
  source-file: "tests/session.scm"
  source-line: 93
  source-form: (test-assert "session-set!, invalid values" (let ((session (%make-session)) (options (quote ((host 12345 #t) (port "string" -22) (bindaddr 12345 -12345) (user 12345 -12345) (timeout "string" -15) (timeout-usec "string" -15000) (ssh1 12345 "string") (ssh2 12345 "string") (log-verbosity "string" -1 0 1 2 3 4 5) (compression 12345) (compression-level -1 0 10) (callbacks "not a list" ((global-request-callback . #f)))))) (res #t)) (if (>= %libssh-minor-version 8) (set! options (cons (quote (nodelay 12345 "string")) options))) (for-each (lambda (opt) (for-each (lambda (val) (catch #t (lambda () (session-set! session (car opt) val) (let* ((r (test-runner-current)) (l (test-runner-aux-value r))) (format l "  opt: ~a, val: ~a -- passed mistakenly~%" (car opt) val) (set! res #f))) (const #t))) (cdr opt))) options) res))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "session-set!, invalid option type"
  source-file: "tests/session.scm"
  source-line: 130
  source-form: (test-error "session-set!, invalid option type" (quote wrong-type-arg) (let ((session (%make-session))) (session-set! session "non-valid type" "value")))
Test end:
  result-kind: pass
  actual-error: (wrong-type-arg "session-set!" "Wrong type argument in position ~A: ~S" (2 "non-valid type") ("non-valid type"))
  expected-error: wrong-type-arg
Test begin:
  test-name: "session-get"
  source-file: "tests/session.scm"
  source-line: 135
  source-form: (test-assert "session-get" (let* ((host "example.com") (port 12345) (user "alice") (proxycommand "test") (callbacks (quote ((user-data . "test")))) (session (make-session #:host host #:port port #:user user #:identity %rsakey #:proxycommand proxycommand #:callbacks callbacks))) (and (string=? (session-get session (FAIL session.scm (exit status: 139)


error: in phase 'check': uncaught exception:
%exception #<&invoke-error program: "make" arguments: ("check" "-j" "24") exit-status: 2 term-signal: #f stop-signal: #f> 
phase `check' failed after 4.8 seconds
command "make" "check" "-j" "24" failed with status 2
builder for `/gnu/store/4winz6sffwfw5xkvkig1n8chzfxg51an-guile-ssh-0.13.1.drv' failed with exit code 1
@ build-failed /gnu/store/4winz6sffwfw5xkvkig1n8chzfxg51an-guile-ssh-0.13.1.drv - 1 builder for `/gnu/store/4winz6sffwfw5xkvkig1n8chzfxg51an-guile-ssh-0.13.1.drv' failed with exit code 1
--8<---------------cut here---------------end--------------->8---

It seems easy to trigger it by building tens of times in a row (say,
with --rounds=100).

Here's anothe, different failure:

--8<---------------cut here---------------start------------->8---
Test suite failed, dumping logs.

--- ./tests/test-suite.log --------------------------------------------------

============================================
   Guile-SSH 0.13.1: tests/test-suite.log
============================================

# TOTAL: 11
# PASS:  10
# SKIP:  0
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: dist
==========

%%%% Starting test dist
Group begin: dist
Test begin:
  test-name: "make-node"
  source-file: "tests/dist.scm"
  source-line: 44
  source-form: (test-assert "make-node" (begin (set-log-userdata! "make-node") (run-client-test (lambda (server) (start-server/exec server (const #t))) (lambda () (call-with-connected-session/shell (lambda (session) (let ((n (make-node session))) (and n (eq? (node-session n) session)))))))))
Test end:
  result-kind: fail
  actual-value: #f
  actual-error: (quit 1)
Test begin:
  test-name: "split, 1"
  source-file: "tests/dist.scm"
  source-line: 57
  source-form: (test-equal "split, 1" (quote ((a b) (c d) (e f g))) (split (quote (a b c d%%%% Starting test dist  (Writing full log to "dist.log")
tests/dist.scm:44: FAIL make-node
# of expected passes      18
# of unexpected failures  1
lit, 2"
  source-file: "tests/dist.scm"
  source-line: 61
  source-form: (test-equal "split, 2" (quote ((a))) (split (quote (a)) 2))
Test end:
  result-kind: pass
  actual-value: ((a))
  expected-value: ((a))
Test begin:
  test-name: "make-job"
  source-file: "tests/dist.scm"
  source-line: 66
  source-form: (test-assert "make-job" (begin (set-log-userdata! "make-job") (run-client-test (lambda (server) (start-server/exec server (const #f))) (lambda () (call-with-connected-session/shell (lambda (session) (let* ((node (make-node session)) (data (quote (1 2 3))) (proc (quote (lambda (n) (#{1+}# n)))) (j (make-job (quote map) node data proc))) (and (eq? (job-type j) (quote map)) (eq? (job-node j) node) (eq? (job-data j) data) (eq? (job-proc j) proc)))))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "set-job-node"
  source-file: "tests/dist.scm"
  source-line: 85
  source-form: (test-assert "set-job-node" (begin (set-log-userdata! "set-job-node") (run-client-test (lambda (server) (start-server/exec server (const #t))) (lambda () (call-with-connected-session/shell (lambda (session) (let* ((n1 (make-node session)) (n2 (make-node session)) (data (quote ())) (proc (quote (lambda (n) (#{1+}# n)))) (j1 (make-job (quote map) n1 data proc)) (j2 (set-job-node j1 n2))) (and (not (eq? j1 j2)) (eq? (job-type j1) (job-type j2)) (eq? (job-node j1) n1) (eq? (job-node j2) n2) (eq? (job-data j1) (job-data j2)) (eq? (job-proc j1) (job-proc j2))))))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "hand-out-job, invalid type"
  source-file: "tests/dist.scm"
  source-line: 107
  source-form: (test-assert "hand-out-job, invalid type" (begin (set-log-userdata! "hand-out-job, invalid type") (catch #t (lambda () (run-client-test (lambda (server) (start-server/exec server (const #t))) (lambda () (call-with-connected-session/shell (lambda (session) (let ((n (make-node session))) (hand-out-job (make-job (quote invalid-job) n (quote ()) (const #t)))))))) #f) (const #t))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "assign-eval"
  source-file: "tests/dist.scm"
  source-line: 120
  source-form: (test-assert "assign-eval" (begin (set-log-userdata! "assign-eval") (run-client-test (lambda (server) (start-server/exec server (const #t))) (lambda () (call-with-connected-session/shell (lambda (session) (let* ((nodes (make-list 2 (make-node session))) (exprs (make-list 10 (quote (lambda (x) (#{1+}# x))))) (jobs (assign-eval nodes exprs))) (and (eq? (length jobs) 2) (eq? (job-type (car jobs)) (quote eval)) (eq? (length (job-proc (car jobs))) 5)))))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result"
  source-file: "tests/dist.scm"
  source-line: 141
  source-form: (test-assert "rrepl-get-result" (receive (result eval-num module-name lang) (call-with-input-string "scheme@(guile-user)> $0 = test" rrepl-get-result) (and (eq? result (quote test)) (= eval-num 0) (string=? module-name "(guile-user)") (string=? lang "scheme"))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, unspecified"
  source-file: "tests/dist.scm"
  source-line: 150
  source-form: (test-assert "rrepl-get-result, unspecified" (receive (result eval-num module-name lang) (call-with-input-string "scheme@(guile-user)> " rrepl-get-result) (and (eq? result *unspecified*) (eq? eval-num *unspecified*) (string=? module-name "(guile-user)") (string=? lang "scheme"))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, error"
  source-file: "tests/dist.scm"
  source-line: 159
  source-form: (test-assert "rrepl-get-result, error" (begin (set-log-userdata! "rrepl-get-result, error") (catch #t (lambda () (call-with-input-string "scheme@(guile-user)> ERROR: error." rrepl-get-result) #f) (lambda (key . args) (if (equal? key (quote node-repl-error)) (let* ((message (cadr args)) (result (string=? message "scheme@(guile-user)> ERROR: error."))) (unless result (format-log/scm (quote nolog) "rrepl-get-result, error" (string-append "Messages do not match: " "expected \"~a\", got \"~a\"") result "scheme@(guile-user)> ERROR: error.")) result) (begin (format-log/scm (quote nolog) "rrepl-get-result, error" (string-append "Errors do not match: " "expected '~a', got '~a' (args: ~a)") (quote node-repl-error) key args) #f))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, compilation error"
  source-file: "tests/dist.scm"
  source-line: 165
  source-form: (test-assert "rrepl-get-result, compilation error" (begin (set-log-userdata! "rrepl-get-result, compilation error") (catch #t (lambda () (call-with-input-string (string-append "scheme@(guile-user)> While compiling expression:\n" "ERROR: no code for module (module-that-doesnt-exist)") rrepl-get-result) #f) (lambda (key . args) (if (equal? key (quote node-repl-error)) (let* ((message (cadr args)) (result (string=? message "scheme@(guile-user)> While compiling expression:\nERROR: no code for module (module-that-doesnt-exist)"))) (unless result (format-log/scm (quote nolog) "rrepl-get-result, compilation error" (string-append "Messages do not match: " "expected \"~a\", got \"~a\"") result "scheme@(guile-user)> While compiling expression:\nERROR: no code for module (module-that-doesnt-exist)")) result) (begin (format-log/scm (quote nolog) "rrepl-get-result, compilation error" (string-append "Errors do not match: " "expected '~a', got '~a' (args: ~a)") (quote node-repl-error) key args) #f))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, unbound variable error"
  source-file: "tests/dist.scm"
  source-line: 172
  source-form: (test-assert "rrepl-get-result, unbound variable error" (begin (set-log-userdata! "rrepl-get-result, unbound variable error") (catch #t (lambda () (call-with-input-string (string-append (string-append "scheme@(guile-user)> ;;; socket:9:7: warning: " "possibly unbound variable `e'\nsocket:9:7: " "In procedure #<procedure 1a44920 at socket:9:7 ()>:\n" "socket:9:7: In procedure module-lookup: Unbound variable: e")) rrepl-get-result) #f) (lambda (key . args) (if (equal? key (quote node-repl-error)) (let* ((message (cadr args)) (result (string=? message "scheme@(guile-user)> ;;; socket:9:7: warning: possibly unbound variable `e'\nsocket:9:7: In procedure #<procedure 1a44920 at socket:9:7 ()>:\nsocket:9:7: In procedure module-lookup: Unbound variable: e"))) (unless result (format-log/scm (quote nolog) "rrepl-get-result, unbound variable error" (string-append "Messages do not match: " "expected \"~a\", got \"~a\"") result "scheme@(guile-user)> ;;; socket:9:7: warning: possibly unbound variable `e'\nsocket:9:7: In procedure #<procedure 1a44920 at socket:9:7 ()>:\nsocket:9:7: In procedure module-lookup: Unbound variable: e")) result) (begin (format-log/scm (quote nolog) "rrepl-get-result, unbound variable error" (string-append "Errors do not match: " "expected '~a', got '~a' (args: ~a)") (quote node-repl-error) key args) #f))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, unknown # object error"
  source-file: "tests/dist.scm"
  source-line: 185
  source-form: (test-assert "rrepl-get-result, unknown # object error" (begin (set-log-userdata! "rrepl-get-result, unknown # object error") (catch #t (lambda () (call-with-input-string (string-append "scheme@(guile-user)> $4 = " "#<session #<undefined>@#<undefined>:22 (disconnected) 453fff>") rrepl-get-result) #f) (lambda (key . args) (if (equal? key (quote node-repl-error)) (let* ((message (cadr args)) (result (string=? message "Reader error: #f: #<unknown port>:1:3: Unknown # object: (\"#<\"): scheme@(guile-user)> $4 = #<session #<undefined>@#<undefined>:22 (disconnected) 453fff>"))) (unless result (format-log/scm (quote nolog) "rrepl-get-result, unknown # object error" (string-append "Messages do not match: " "expected \"~a\", got \"~a\"") result "Reader error: #f: #<unknown port>:1:3: Unknown # object: (\"#<\"): scheme@(guile-user)> $4 = #<session #<undefined>@#<undefined>:22 (disconnected) 453fff>")) result) (begin (format-log/scm (quote nolog) "rrepl-get-result, unknown # object error" (string-append "Errors do not match: " "expected '~a', got '~a' (args: ~a)") (quote node-repl-error) key args) #f))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, elisp"
  source-file: "tests/dist.scm"
  source-line: 194
  source-form: (test-assert "rrepl-get-result, elisp" (receive (result eval-num module-name lang) (call-with-input-string "elisp@(guile-user)> $0 = #nil" rrepl-get-result) (and (eq? result (quote #nil)) (= eval-num 0) (string=? module-name "(guile-user)") (string=? lang "elisp"))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-get-result, multiple values"
  source-file: "tests/dist.scm"
  source-line: 203
  source-form: (test-assert "rrepl-get-result, multiple values" (receive (result eval-num module-name lang) (call-with-input-string "scheme@(guile-user)> $0 = v1\n$1 = v2" rrepl-get-result) (and (vector? eval-num) (vector? result) (eq? (vector-ref result 0) (quote v1)) (eq? (vector-ref result 1) (quote v2)) (= (vector-ref eval-num 0) 0) (= (vector-ref eval-num 1) 1) (string=? module-name "(guile-user)") (string=? lang "scheme"))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-skip-to-prompt, valid input"
  source-file: "tests/dist.scm"
  source-line: 217
  source-form: (test-assert "rrepl-skip-to-prompt, valid input" (begin (call-with-input-string "Enter `,help' for help." (lambda (port) (rrepl-skip-to-prompt port))) #t))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "rrepl-skip-to-prompt, invalid input"
  source-file: "tests/dist.scm"
  source-line: 224
  source-form: (test-assert "rrepl-skip-to-prompt, invalid input" (begin (set-log-userdata! "rrepl-skip-to-prompt, invalid input") (catch #t (lambda () (call-with-input-string "invalid input" (lambda (port) (rrepl-skip-to-prompt port))) #f) (lambda (key . args) (let ((result (equal? key (quote node-error)))) (unless result (format-log/scm (quote nolog) "rrepl-skip-to-prompt, invalid input" (string-append "Errors do not match: " "expected ~a, got ~a (args: ~a)") (quote node-error) key args)) result)))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "node-guile-version, valid response"
  source-file: "tests/dist.scm"
  source-line: 229
  source-form: (test-assert "node-guile-version, valid response" (begin (set-log-userdata! "node-guile-version, valid response") (run-client-test (lambda (server) (start-server/exec server (const #t))) (lambda () (call-with-connected-session/shell (lambda (session) (format-log/scm (quote nolog) "client" "session: ~a" session) (let ((n (make-node session))) (string=? (node-guile-version n) "GNU Guile 2.2.3"))))))))
Test end:
  result-kind: pass
  actual-value: #t
Test begin:
  test-name: "with-ssh"
  source-file: "tests/dist.scm"
  source-line: 249
  source-form: (test-assert "with-ssh" (begin (set-log-userdata! "with-ssh") (run-client-test (lambda (server) (start-server/exec server (lambda (session message channel) (let ((line (read-line channel))) (format-log/scm (quote nolog) "with-ssh" "client request: ~A" line) (write-line "$1 = 42\n" channel))))) (lambda () (call-with-connected-session/shell (lambda (session) (format-log/scm (quote nolog) "client" "session: ~a" session) (let ((n (make-node session))) (= (with-ssh n (+ 21 21)) 42))))))))
Test end:
  result-kind: pass
  actual-value: #t
Group end: dist
# of expected passes      18
# of unexpected failures  1
FAIL dist.scm (exit status: 1)


error: in phase 'check': uncaught exception:
%exception #<&invoke-error program: "make" arguments: ("check" "-j" "24") exit-status: 2 term-signal: #f stop-signal: #f> 
phase `check' failed after 4.8 seconds
command "make" "check" "-j" "24" failed with status 2
builder for `/gnu/store/4winz6sffwfw5xkvkig1n8chzfxg51an-guile-ssh-0.13.1.drv' failed with exit code 1
--8<---------------cut here---------------end--------------->8---

Thanks,

Maxim

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.