I'm investigating this issue: pi's password is lost in every reboot. Issue summary: Change pi's password by passwd command -> reboot -> the changed password always will be changed to another which we don't know.
Yes, I know using default pi account is not good for security, but in this topic I just focus to the investigation of root cause.
After searching tons of result on Google (like these: https://raspberrypi.stackexchange.com/questions/73487/pis-password-is-lost-in-every-reboot and https://www.raspberrypi.org/forums/viewtopic.php?t=195378 etc...) but don't have the solution for this strangle issue, I decided to investigate by myself. And I have fond out a half of the root cause.
I used this command to trace auth log
sudo tail /var/log/auth.log -n 100
And I alway see this log at the shutdown step
May 19 01:02:41 raspberrypi usermod[866]: change user 'pi' password
Then I tried to rename usermod binary and shutdown
sudo mv /usr/sbin/usermod /usr/sbin/usermod-dell
Then it worked, the usermod binary wasn't called and the password of pi account isn't changed after rebooting anymore. So, it means something called usermod to change the password of pi account, but I still can't trace exactly something is what?
This is full log of auth.log -n 100 command.
rp@raspberrypi:~ $ sudo tail /var/log/auth.log -n 100
[sudo] password for rp:
May 19 00:19:20 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:19:31 raspberrypi sudo: rp : TTY=pts/1 ; PWD=/home/rp ; USER=roo t ; COMMAND=/sbin/reboot
May 19 00:19:31 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:19:38 raspberrypi systemd-logind[478]: New seat seat0.
May 19 00:19:39 raspberrypi sshd[847]: Server listening on 0.0.0.0 port 22.
May 19 00:19:39 raspberrypi sshd[847]: Server listening on :: port 22.
May 19 00:19:39 raspberrypi usermod[824]: change user 'pi' password
May 19 00:19:40 raspberrypi sshd[847]: Received SIGHUP; restarting.
May 19 00:19:41 raspberrypi sshd[847]: Server listening on 0.0.0.0 port 22.
May 19 00:19:41 raspberrypi sshd[847]: Server listening on :: port 22.
May 19 00:19:46 raspberrypi lightdm: pam_unix(lightdm-autologin:session): sessio n opened for user pi by (uid=0)
May 19 00:19:46 raspberrypi systemd-logind[478]: New session c1 of user pi.
May 19 00:19:46 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user pi by (uid=0)
May 19 00:19:55 raspberrypi polkitd(authority=local): Registered Authentication Agent for unix-session:c1 (system bus name :1.12 [lxpolkit], object path /org/fr eedesktop/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
May 19 00:22:24 raspberrypi sudo: pi : TTY=pts/0 ; PWD=/home/pi ; USER=roo t ; COMMAND=/usr/local/bin/noip2 -S
May 19 00:22:24 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by (uid=0)
May 19 00:22:24 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:22:36 raspberrypi passwd[2138]: pam_unix(passwd:chauthtok): authentica tion failure; logname= uid=1000 euid=0 tty= ruser= rhost= user=pi
May 19 00:22:47 raspberrypi sudo: pi : TTY=pts/0 ; PWD=/home/pi ; USER=roo t ; COMMAND=/usr/bin/passwd pi
May 19 00:22:47 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by (uid=0)
May 19 00:22:55 raspberrypi passwd[2152]: pam_unix(passwd:chauthtok): password c hanged for pi
May 19 00:22:55 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:23:11 raspberrypi passwd[2163]: pam_unix(passwd:chauthtok): password c hanged for pi
May 19 00:24:04 raspberrypi passwd[2235]: pam_unix(passwd:chauthtok): authentica tion failure; logname= uid=1000 euid=0 tty= ruser= rhost= user=pi
May 19 00:24:43 raspberrypi passwd[2254]: pam_unix(passwd:chauthtok): password c hanged for pi
May 19 00:24:49 raspberrypi sudo: pi : TTY=pts/0 ; PWD=/home/pi ; USER=roo t ; COMMAND=/sbin/reboot
May 19 00:24:50 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by (uid=0)
May 19 00:24:57 raspberrypi systemd-logind[477]: New seat seat0.
May 19 00:24:58 raspberrypi sshd[881]: Server listening on 0.0.0.0 port 22.
May 19 00:24:58 raspberrypi sshd[881]: Server listening on :: port 22.
May 19 00:24:58 raspberrypi usermod[861]: change user 'pi' password
May 19 00:25:03 raspberrypi lightdm: pam_unix(lightdm-autologin:session): sessio n opened for user pi by (uid=0)
May 19 00:25:04 raspberrypi systemd-logind[477]: New session c1 of user pi.
May 19 00:25:04 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user pi by (uid=0)
May 19 00:25:11 raspberrypi polkitd(authority=local): Registered Authentication Agent for unix-session:c1 (system bus name :1.12 [lxpolkit], object path /org/fr eedesktop/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
May 19 00:26:56 raspberrypi passwd[2064]: pam_unix(passwd:chauthtok): authentica tion failure; logname= uid=1000 euid=0 tty= ruser= rhost= user=pi
May 19 00:27:10 raspberrypi passwd[2068]: pam_unix(passwd:chauthtok): authentica tion failure; logname= uid=1000 euid=0 tty= ruser= rhost= user=pi
May 19 00:39:01 raspberrypi CRON[8534]: pam_unix(cron:session): session opened f or user root by (uid=0)
May 19 00:39:02 raspberrypi CRON[8534]: pam_unix(cron:session): session closed f or user root
May 19 00:44:32 raspberrypi sshd[9696]: pam_unix(sshd:auth): authentication fail ure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.1.155 user=rp
May 19 00:44:34 raspberrypi sshd[9696]: Failed password for rp from 192.168.1.15 5 port 51768 ssh2
May 19 00:44:41 raspberrypi sshd[9696]: Accepted password for rp from 192.168.1. 155 port 51768 ssh2
May 19 00:44:41 raspberrypi sshd[9696]: pam_unix(sshd:session): session opened f or user rp by (uid=0)
May 19 00:44:41 raspberrypi systemd-logind[477]: New session c2 of user rp.
May 19 00:44:41 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user rp by (uid=0)
May 19 00:44:57 raspberrypi sudo: pam_unix(sudo:auth): authentication failure; l ogname=rp uid=1003 euid=0 tty=/dev/pts/1 ruser=rp rhost= user=rp
May 19 00:45:03 raspberrypi sudo: rp : TTY=pts/1 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/sbin/update-rc.d noip2.sh enable
May 19 00:45:03 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:45:04 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:45:36 raspberrypi smbd[10031]: pam_unix(samba:session): session opened for user pi by (uid=0)
May 19 00:46:55 raspberrypi sudo: rp : TTY=pts/1 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/local/bin/noip2 -S
May 19 00:46:55 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:46:55 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:49:17 raspberrypi sudo: rp : TTY=pts/1 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/bin/tail /var/log/auth.log -n 100
May 19 00:49:17 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:49:17 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:51:24 raspberrypi sudo: rp : TTY=pts/1 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/bin/passwd pi
May 19 00:51:24 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:51:30 raspberrypi passwd[11384]: pam_unix(passwd:chauthtok): password changed for pi
May 19 00:51:30 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 00:51:39 raspberrypi sudo: rp : TTY=pts/1 ; PWD=/home/rp ; USER=roo t ; COMMAND=/sbin/reboot
May 19 00:51:39 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:51:39 raspberrypi sshd[9696]: pam_unix(sshd:session): session closed f or user rp
May 19 00:51:47 raspberrypi systemd-logind[475]: New seat seat0.
May 19 00:51:48 raspberrypi sshd[882]: Server listening on 0.0.0.0 port 22.
May 19 00:51:48 raspberrypi sshd[882]: Server listening on :: port 22.
May 19 00:51:48 raspberrypi usermod[859]: change user 'pi' password
May 19 00:51:55 raspberrypi lightdm: pam_unix(lightdm-autologin:session): sessio n opened for user pi by (uid=0)
May 19 00:51:55 raspberrypi systemd-logind[475]: New session c1 of user pi.
May 19 00:51:55 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user pi by (uid=0)
May 19 00:52:01 raspberrypi polkitd(authority=local): Registered Authentication Agent for unix-session:c1 (system bus name :1.12 [lxpolkit], object path /org/fr eedesktop/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
May 19 00:54:58 raspberrypi sshd[2091]: Accepted password for rp from 192.168.1. 155 port 51869 ssh2
May 19 00:54:58 raspberrypi sshd[2091]: pam_unix(sshd:session): session opened f or user rp by (uid=0)
May 19 00:54:58 raspberrypi systemd-logind[475]: New session c2 of user rp.
May 19 00:54:58 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user rp by (uid=0)
May 19 00:55:08 raspberrypi sudo: rp : TTY=pts/0 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/bin/tail /var/log/auth.log -n 100
May 19 00:55:08 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 00:55:08 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 01:02:21 raspberrypi sudo: rp : TTY=pts/0 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/local/bin/noip2 -S
May 19 01:02:21 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 01:02:21 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 01:02:33 raspberrypi sudo: rp : TTY=pts/0 ; PWD=/home/rp ; USER=roo t ; COMMAND=/sbin/reboot
May 19 01:02:33 raspberrypi sudo: pam_unix(sudo:session): session opened for use r root by rp(uid=0)
May 19 01:02:33 raspberrypi sshd[2091]: pam_unix(sshd:session): session closed f or user rp
May 19 01:02:33 raspberrypi sudo: pam_unix(sudo:session): session closed for use r root
May 19 01:02:33 raspberrypi polkitd(authority=local): Unregistered Authenticatio n Agent for unix-session:c1 (system bus name :1.12, object path /org/freedesktop /PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8) (disconnected from bus)
May 19 01:02:40 raspberrypi systemd-logind[480]: New seat seat0.
May 19 01:02:41 raspberrypi sshd[879]: Server listening on 0.0.0.0 port 22.
May 19 01:02:41 raspberrypi sshd[879]: Server listening on :: port 22.
May 19 01:02:41 raspberrypi usermod[866]: change user 'pi' password
May 19 01:02:47 raspberrypi lightdm: pam_unix(lightdm-autologin:session): sessio n opened for user pi by (uid=0)
May 19 01:02:47 raspberrypi systemd-logind[480]: New session c1 of user pi.
May 19 01:02:47 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user pi by (uid=0)
May 19 01:02:53 raspberrypi polkitd(authority=local): Registered Authentication Agent for unix-session:c1 (system bus name :1.12 [lxpolkit], object path /org/fr eedesktop/PolicyKit1/AuthenticationAgent, locale en_GB.UTF-8)
May 19 01:04:53 raspberrypi sshd[2010]: Accepted password for rp from 192.168.1. 155 port 51907 ssh2
May 19 01:04:53 raspberrypi sshd[2010]: pam_unix(sshd:session): session opened f or user rp by (uid=0)
May 19 01:04:53 raspberrypi systemd-logind[480]: New session c2 of user rp.
May 19 01:04:53 raspberrypi systemd: pam_unix(systemd-user:session): session ope ned for user rp by (uid=0)
May 19 01:05:01 raspberrypi sudo: rp : TTY=pts/0 ; PWD=/home/rp ; USER=roo t ; COMMAND=/usr/bin/tail /var/log/auth.log -n 100
May 19 01:05:01 raspberrypi sudo: pam_unix(sudo:session): session opened for use
I tried to create a fake usermod bash below to debug
#!/bin/bash
(
echo "usermod called at $(date)"
echo "env"
env
echo
echo "command line"
echo "$@"
) >>/tmp/usermod.log
And this is the log result, but unfortunately I still can't trace exactly what called usermod?
usermod called at Sun 19 May 10:03:01 +07 2019
env
TERM=linux
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
PWD=/
LANG=en_GB.UTF-8
SHLVL=2
_=/usr/bin/env
command line
-p $6$vGkGPKUr$heqvOhUzvbQ66Nb0JGCijh/81sG1WACcZgzPn8A0Wn58hHXWqy5yOgTlYJEbOjhk$
grep -lr heqvOhUzvbQ66Nb0JGCijh /
to find what's calling yourusermod
instance, or capture$PPID
andps -wef
in your fakeusermod
script and wait for it to be run again.