Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Heisenbug: tests/su/10_su_sulog_success/su.test #956

Open
alejandro-colomar opened this issue Feb 21, 2024 · 2 comments
Open

Heisenbug: tests/su/10_su_sulog_success/su.test #956

alejandro-colomar opened this issue Feb 21, 2024 · 2 comments
Assignees

Comments

@alejandro-colomar
Copy link
Collaborator

alejandro-colomar commented Feb 21, 2024

I've seen that test fail in a PR, in which I wouldn't expect it to fail. When trying to reproduce it, I wasn't able, not even in the same PR. Let's just document that it has happened, in case we see it again.

The only thing we know until now, is that the following failed once:

tests/su/10_su_sulog_success/su.test

And it was in

@alejandro-colomar
Copy link
Collaborator Author

Here's the action that failed:

@alejandro-colomar alejandro-colomar changed the title Heisenbug: tests/su/10_su_sulog_success/su.test tests/su/10_su_sulog_success/su.test Heisenbug: tests/su/10_su_sulog_success/su.test Mar 4, 2024
@alejandro-colomar
Copy link
Collaborator Author

alejandro-colomar commented Apr 15, 2024

I've experienced it again, spuriously in a branch that has been working for a long time, and without any changes (just reorganizing the commits internally), it failed in one rebase, and worked again in the next. Here are the logs:

  set -e
  cd tests
  trap 'cat testsuite.log' ERR
  sudo ./run_some
  trap - ERR
  shell: /usr/bin/script -q -e -c "bash {0}"
+: test passed
-: test failed
.+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++-++++++++++++
75 test(s) passed
1 test(s) failed
log written in 'testsuite.log'
the following tests failed:
 ./su/10_su_sulog_success/su.test
###############################################################################
#
# Test: ./su/10_su_sulog_success/su.test
#
###############################################################################
#
# Rationale: su can be used to switch to a non-root user
#
###############################################################################
# switch to the passwordless 'testsuite' user
# and expect a '$ ' prompt
spawn /bin/su testsuite

<r/work/shadow/shadow/tests/su/10_su_sulog_success$ 
# make sure we are now 'testsuite'
# id should return 'uid=424243(testsuite) gid=424243 groups=424243'

<r/work/shadow/shadow/tests/su/10_su_sulog_success$ id

uid=424243(testsuite) gid=424243 groups=424243

<r/work/shadow/shadow/tests/su/10_su_sulog_success$ 

# now switch to user 'myuser'
# and expect a password prompt

<r/work/shadow/shadow/tests/su/10_su_sulog_success$ su myuser

Password: 
# password 'myuserF00barbaz' sent

# expect prompt '$ '

myuser@fv-az665-93:~/runner/work/shadow/shadow/tests/su/10_su_sulog_success$ 

# make sure we are 'myuser'
# id should return '(myuser).*(myuser).*(myuser)

myuser@fv-az665-93:~/runner/work/shadow/shadow/tests/su/10_su_sulog_success$ 
<work/shadow/shadow/tests/su/10_su_sulog_success$ id                         �������������������������

uid=424242(myuser) gid=424242(myuser) groups=424242(myuser)

myuser@fv-az665-93:~/runner/work/shadow/shadow/tests/su/10_su_sulog_success$ 
<rk/shadow/shadow/tests/su/10_su_sulog_success$ exit                         �������������������������

exit


PASS
Check /var/log/sulog...--- tmp/sulog	2024-04-15 09:46:00.007612162 +0000
+++ data/sulog	2024-04-15 09:41:43.570603193 +0000
@@ -1,3 +1 @@
 2 /var/log/sulog
-SU 04/15 09:45 + /dev/pts/2 root-testsuite
-SU 04/15 09:45 + /dev/pts/2 testsuite-myuser
###############################################################################
#
# Status of test ./su/10_su_sulog_success/su.test: FAILURE
#
###############################################################################

Here are the logs:
https://github.com/shadow-maint/shadow/actions/runs/8686919201/job/23819371890#step:9:3544

This sounds like Undefined Behavior somewhere? @hallyn , would you mind having a look at it?

It could be a race condition in the test, maybe? I hope it's not a bug in id(1) (although id(1) is not setuid, so it wouldn't be that bad).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants