Inconsistent utx.active?

[Vlad GALU-2]

Hi,

Has anyone else noticed erratic bookkeeping by utmpx in RELENG_9?

Thanks,
Vlad

--
Good, fast & cheap. Pick any two.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "[hidden email]"

[Ed Schouten-3]

Hi Vlad,

> Has anyone else noticed erratic bookkeeping by utmpx in RELENG_9?

Would you mind explaining to me what you're seeing? It's hard for me to
fix bugs if I don't get proper reports.

--
 Ed Schouten <[hidden email]>
 WWW: http://80386.nl/

[Vlad GALU-2]

On Friday, February 24, 2012 at 10:15 PM, Ed Schouten wrote:

> Hi Vlad,
>
> > Has anyone else noticed erratic bookkeeping by utmpx in RELENG_9?
>
> Would you mind explaining to me what you're seeing? It's hard for me to
> fix bugs if I don't get proper reports.
>
> --
> Ed Schouten <[hidden email] (mailto:[hidden email])>
> WWW: http://80386.nl/

Hi Ed,

Yes, sorry about that. I'm seeing stale (which sometimes turn into duplicate) entries when I log off and on again. The symptom seems to be exacerbated by unclean logouts (such as when my stateful corporate firewall kills my SSH sessions - I don't have keepalives active at either end).

In the example below, I'm actually logged on from IP address X.Y.Z.T, the first two entries belong to earlier sessions that have been long gone. The pts is the same, and the command displayed under WHAT is mirrored for all 3 entries.

-- cut here --
dudu@joint ~ $ w
11:30PM up 2 days, 6:17, 3 users, load averages: 0.00, 0.00, 0.00
USER TTY FROM LOGIN@ IDLE WHAT
dudu pts/0 A.B.C.D Thu05PM - w
dudu pts/0 A.B.C.D 1:10PM - w
dudu pts/0 X.Y.Z.T  11:30PM - w
dudu@joint ~ $ ps ax
PID TT STAT TIME COMMAND
82986 0 SJ 0:00.00 -bash (bash)
83323 0 R+J 0:00.00 ps ax
dudu@joint ~ $




-- and here --



_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "[hidden email]"

[Ed Schouten-3]

Hi Vlad,

* Vlad Galu <[hidden email]>, 20120224 23:35:

> Yes, sorry about that. I'm seeing stale (which sometimes turn into
> duplicate) entries when I log off and on again. The symptom seems to
> be exacerbated by unclean logouts (such as when my stateful corporate
> firewall kills my SSH sessions - I don't have keepalives active at
> either end).
>
> In the example below, I'm actually logged on from IP address X.Y.Z.T,
> the first two entries belong to earlier sessions that have been long
> gone. The pts is the same, and the command displayed under WHAT is
> mirrored for all 3 entries.

Would you mind pasting the output of `getent utmpx active'?

Thanks,
--
 Ed Schouten <[hidden email]>
 WWW: http://80386.nl/

[Vlad GALU-2]

On Friday, February 24, 2012 at 10:40 PM, Ed Schouten wrote:

> Hi Vlad,
>
> * Vlad Galu <[hidden email] (mailto:[hidden email])>, 20120224 23:35:
> > Yes, sorry about that. I'm seeing stale (which sometimes turn into
> > duplicate) entries when I log off and on again. The symptom seems to
> > be exacerbated by unclean logouts (such as when my stateful corporate
> > firewall kills my SSH sessions - I don't have keepalives active at
> > either end).
> >
> > In the example below, I'm actually logged on from IP address X.Y.Z.T,
> > the first two entries belong to earlier sessions that have been long
> > gone. The pts is the same, and the command displayed under WHAT is
> > mirrored for all 3 entries.
>
>
>
> Would you mind pasting the output of `getent utmpx active'?
>

Not at all, here it is:

-- cut here --
[1330014380.652067 -- Thu Feb 23 17:26:20 2012] user process: id="4f86d023f250d3c9" pid="39012" user="dudu" line="pts/0" host="A.B.C.D"
[1330014398.177818 -- Thu Feb 23 17:26:38 2012] user process: id="269d75b37f295346" pid="39221" user="dudu" line="pts/1" host="A.B.C.D"
[1330085459.796787 -- Fri Feb 24 13:10:59 2012] user process: id="d026e8e5c0648ec2" pid="38093" user="dudu" line="pts/0" host="A.B.C.D"
[1330122640.813570 -- Fri Feb 24 23:30:40 2012] user process: id="dd8d3dff2f3002a0" pid="82959" user="dudu" line="pts/0" host="X.Y.Z.T"
[1330122493.638088 -- Fri Feb 24 23:28:13 2012] user process: id="92b73279a543d99f" pid="73085" user="dudu" line="pts/1" host="X.Y.Z.T"
[1330122498.444614 -- Fri Feb 24 23:28:18 2012] user process: id="c0f3c404a3ca8565" pid="73573" user="dudu" line="pts/2" host="X.Y.Z.T"

[1330122634.538515 -- Fri Feb 24 23:30:34 2012] dead process: id="fea56df5dde26e4d" pid="76338"
-- and here --

The local time is UTC+1. The current (and only) bash PID (82986) is not even on that list.


_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "[hidden email]"

[Ed Schouten-3]

Hello Vlad,

* Vlad Galu <[hidden email]>, 20120224 23:54:
> [1330014380.652067 -- Thu Feb 23 17:26:20 2012] user process: id="4f86d023f250d3c9" pid="39012" user="dudu" line="pts/0" host="A.B.C.D"
> [1330014398.177818 -- Thu Feb 23 17:26:38 2012] user process: id="269d75b37f295346" pid="39221" user="dudu" line="pts/1" host="A.B.C.D"
> [1330085459.796787 -- Fri Feb 24 13:10:59 2012] user process: id="d026e8e5c0648ec2" pid="38093" user="dudu" line="pts/0" host="A.B.C.D"
> [1330122640.813570 -- Fri Feb 24 23:30:40 2012] user process: id="dd8d3dff2f3002a0" pid="82959" user="dudu" line="pts/0" host="X.Y.Z.T"
> [1330122493.638088 -- Fri Feb 24 23:28:13 2012] user process: id="92b73279a543d99f" pid="73085" user="dudu" line="pts/1" host="X.Y.Z.T"
> [1330122498.444614 -- Fri Feb 24 23:28:18 2012] user process: id="c0f3c404a3ca8565" pid="73573" user="dudu" line="pts/2" host="X.Y.Z.T"
> [1330122634.538515 -- Fri Feb 24 23:30:34 2012] dead process: id="fea56df5dde26e4d" pid="76338"

You mentioned in a previous email that these entries belong to SSH
sessions. Are you sure about this? The identifiers seem to contain
randomly generated data, just like pam_lastlog(8) does. OpenSSH uses
identifiers based on the TTY name, like so:

> [1330124273.955165 -- Fri Feb 24 23:57:53 2012] user process: id="7074732f30000000" pid="15880" user="ed" line="pts/0" host="m.fxq.nl"

0x7074732f30 is equal to "pts/0".

Maybe they're generated by some different login service or you've
configured PAM/OpenSSH/etc. in a non-default way?

Thanks so far,
--
 Ed Schouten <[hidden email]>
 WWW: http://80386.nl/

[Vlad GALU-2]

On Friday, February 24, 2012 at 11:00 PM, Ed Schouten wrote:

> Hello Vlad,
>
> * Vlad Galu <[hidden email] (mailto:[hidden email])>, 20120224 23:54:
> > [1330014380.652067 -- Thu Feb 23 17:26:20 2012] user process: id="4f86d023f250d3c9" pid="39012" user="dudu" line="pts/0" host="A.B.C.D"
> > [1330014398.177818 -- Thu Feb 23 17:26:38 2012] user process: id="269d75b37f295346" pid="39221" user="dudu" line="pts/1" host="A.B.C.D"
> > [1330085459.796787 -- Fri Feb 24 13:10:59 2012] user process: id="d026e8e5c0648ec2" pid="38093" user="dudu" line="pts/0" host="A.B.C.D"
> > [1330122640.813570 -- Fri Feb 24 23:30:40 2012] user process: id="dd8d3dff2f3002a0" pid="82959" user="dudu" line="pts/0" host="X.Y.Z.T"
> > [1330122493.638088 -- Fri Feb 24 23:28:13 2012] user process: id="92b73279a543d99f" pid="73085" user="dudu" line="pts/1" host="X.Y.Z.T"
> > [1330122498.444614 -- Fri Feb 24 23:28:18 2012] user process: id="c0f3c404a3ca8565" pid="73573" user="dudu" line="pts/2" host="X.Y.Z.T"
> > [1330122634.538515 -- Fri Feb 24 23:30:34 2012] dead process: id="fea56df5dde26e4d" pid="76338"
>
>
>
> You mentioned in a previous email that these entries belong to SSH
> sessions. Are you sure about this? The identifiers seem to contain
> randomly generated data, just like pam_lastlog(8) does. OpenSSH uses
> identifiers based on the TTY name, like so:
>
> > [1330124273.955165 -- Fri Feb 24 23:57:53 2012] user process: id="7074732f30000000" pid="15880" user="ed" line="pts/0" host="m.fxq.nl (http://m.fxq.nl)"
>
> 0x7074732f30 is equal to "pts/0".
>
> Maybe they're generated by some different login service or you've
> configured PAM/OpenSSH/etc. in a non-default way?
>

Sigh, you are right. I had UseLogin set to yes in sshd_config. Sorry for the noise and thanks!
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "[hidden email]"

[Ed Schouten-3]

Hello Vlad,

* Vlad Galu <[hidden email]>, 20120225 00:24:
> Sigh, you are right. I had UseLogin set to yes in sshd_config. Sorry
> for the noise and thanks!

Even with UseLogin I fail to reproduce it on my system. Even with
UseLogin enabled it shouldn't cause utmpx entries to be `leaked'. I'll
keep UseLogin enabled on one of my systems from now on to see whether it
occurs sporadically.

Thanks for reporting the issue.

--
 Ed Schouten <[hidden email]>
 WWW: http://80386.nl/