Bug 1215383

Summary: [Build 20230914] pam_lastlog2: user 'bernhard' not found (101)
Product: [openSUSE] openSUSE Tumbleweed Reporter: Dominique Leuenberger <dimstar>
Component: BasesystemAssignee: Thorsten Kukuk <kukuk>
Status: RESOLVED FIXED QA Contact: E-mail List <qa-bugs>
Severity: Normal    
Priority: P5 - None CC: fvogt, gyribeiro
Version: Current   
Target Milestone: ---   
Hardware: Other   
OS: Other   
URL: https://openqa.opensuse.org/tests/3578789/modules/journal_check/steps/23
Whiteboard:
Found By: openQA Services Priority:
Business Priority: Blocker: Yes
Marketing QA Status: --- IT Deployment: ---

Description Dominique Leuenberger 2023-09-15 12:40:19 UTC 
## Observation

In some microos tests, the journal_check reports an error logged by lastlog:

Sep 14 03:24:36.859112 localhost.localdomain login[1594]: pam_unix(login:session): session opened for user bernhard(uid=1000) by bernhard(uid=0)
Sep 14 03:24:36.872684 localhost.localdomain login[1594]: pam_lastlog2(login:session): User 'bernhard' not found (101)
Sep 14 03:24:36.894968 localhost.localdomain login[1594]: LOGIN ON tty4 BY bernhard

The error'user "bernhard" not found sounds quite strange - considering the user manages to login. Likely, this is not supposed to be recorded as an error in the journal to start with

openQA test in scenario microos-Tumbleweed-MicroOS-Image-x86_64-microos-wizard@64bit fails in
[journal_check](https://openqa.opensuse.org/tests/3578789/modules/journal_check/steps/23)

## Test suite description
Like MicroOS, but use neither combustion nor ignition for the intial configuration, so jeos-firstboot runs.


## Reproducible

Fails since (at least) Build [20230914](https://openqa.opensuse.org/tests/3576909)


## Expected result

Last good: [20230913](https://openqa.opensuse.org/tests/3574584) (or more recent)


## Further details

Always latest result in this scenario: [latest](https://openqa.opensuse.org/tests/latest?arch=x86_64&distri=microos&flavor=MicroOS-Image&machine=64bit&test=microos-wizard&version=Tumbleweed)
Comment 1 Thorsten Kukuk 2023-09-15 13:42:43 UTC 
(In reply to Dominique Leuenberger from comment #0)
> The error'user "bernhard" not found sounds quite strange - considering the
> user manages to login. Likely, this is not supposed to be recorded as an
> error in the journal to start with

It's not strange. If he never logged in before, he does not exist in the database and sqlite reports an error.
Comment 2 Dominique Leuenberger 2023-09-18 08:01:10 UTC 
(In reply to Thorsten Kukuk from comment #1)
> (In reply to Dominique Leuenberger from comment #0)
> > The error'user "bernhard" not found sounds quite strange - considering the
> > user manages to login. Likely, this is not supposed to be recorded as an
> > error in the journal to start with
> 
> It's not strange. If he never logged in before, he does not exist in the
> database and sqlite reports an error.

not having logged in is not an 'error' condition. So I'd argue that this info should at best be info/warning (or debug) in the journal
Comment 3 Thorsten Kukuk 2023-11-27 09:01:32 UTC 
That warning shouldn't be there anymore since a longer time.
Comment 4 Fabian Vogt 2024-01-15 13:24:46 UTC 
Still happens in snapshot 20240114: https://openqa.opensuse.org/tests/3870655#step/journal_check/21
Comment 5 Fabian Vogt 2024-02-06 16:28:20 UTC 
I reproduced it locally with the "debug" flag passed to the pam module.

Result:

Feb 06 17:08:59 localhost.localdomain sshd[1580]: pam_unix(sshd:session): session opened for user bernhard(uid=1000) by bernhard(uid=0)
Feb 06 17:08:59 localhost.localdomain sshd[1580]: pam_lastlog2(sshd:session): user=bernhard
Feb 06 17:08:59 localhost.localdomain sshd[1580]: pam_lastlog2(sshd:session): User 'bernhard' not found (101)
Feb 06 17:08:59 localhost.localdomain sshd[1580]: pam_lastlog2(sshd:session): tty=ssh
Feb 06 17:08:59 localhost.localdomain sshd[1580]: pam_lastlog2(sshd:session): rhost(PAM_RHOST)=192.168.100.1

This shows that the error was produced by the call to show_lastlogin here:

https://github.com/util-linux/util-linux/blob/c0207d354ee47fb56acfa64b03b5b559bb301280/pam_lastlog2/src/pam_lastlog2.c#L329

Apparently this doesn't handle the "user has never logged in" case gracefully enough.
Comment 7 Thorsten Kukuk 2024-03-13 08:26:40 UTC 
Still, this is no bug. But with the other changes you will not see this message in this form anymore, too.
Comment 8 Fabian Vogt 2024-03-13 08:33:29 UTC 
It was clearly a bug, but it's been fixed now so set it appropriately.