Reasons for missing IP info in `last` output on pts logins?

6,517

Solution 1

script behavior differences between RedHat and Debian

Linked Libraries

CentOS 6.3 - script (util-linux-ng 2.17.2)

#ldd /usr/bin/script

linux-vdso.so.1 =>  (0x00007fff077ff000)
libutil.so.1 => /lib64/libutil.so.1 (0x00007f309f5d1000)
libutempter.so.0 => /usr/lib64/libutempter.so.0 (0x00007f309f3cf000)
libc.so.6 => /lib64/libc.so.6 (0x00007f309f03b000)
/lib64/ld-linux-x86-64.so.2 (0x00007f309f7e1000)

Ubuntu 12.04 - script (util-linux 2.20.1)

#ldd /usr/bin/script

linux-vdso.so.1 =>  (0x00007fff375ff000)
libutil.so.1 => /lib/x86_64-linux-gnu/libutil.so.1 (0x00007fc0d7ab0000)
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fc0d76f1000)
/lib64/ld-linux-x86-64.so.2 (0x00007fc0d7cdc000)

PTY

Base on upstream source code, script from both versions do open new pty. Following is test.

Ubuntu 12.04

john@U64D211:~/tmp$ ls /dev/pts
0  1  5  8  ptmx
john@U64D211:~/tmp$ script
Script started, file is typescript
john@U64D211:~/tmp$ ls /dev/pts
0  1  2  5  8  ptmx
john@U64D211:~/tmp$ last -i
john     pts/0        0.0.0.0          Sat Jan  5 09:09   still logged in   
reboot   system boot  0.0.0.0          Sat Jan  5 09:08 - 09:52  (00:44)    
john     pts/0        0.0.0.0          Thu Jan  3 00:50 - 01:42  (00:52)    
reboot   system boot  0.0.0.0          Thu Jan  3 00:48 - 01:43  (00:54)    

wtmp begins Tue Jan  1 20:48:28 2013
john@U64D211:~/tmp$ exit
exit
Script done, file is typescript
john@U64D211:~/tmp$ ls /dev/pts
0  1  5  8  ptmx
john@U64D211:~/tmp$ 

Ubuntu 12.04 script did open a new pts(2). It just did not update /var/log/wtmp.

CentOS 6

I am skipping the test as we already know that script do open pty and register with wtmp.

libutemper

  • Project: http://freecode.com/projects/libutempter
  • Description: libutempter provides a library interface for terminal emulators such as screen and xterm to record user sessions to utmp and wtmp files.

So the main difference seems to be the extra library(libutempter.so.0) CentOS script linked with.

Test with Ubuntu 12.04

Compiling script with libutempter

john@U64D211:~/tmp/util-linux-2.20.1$ sudo apt-get install libutempter-dev
john@U64D211:~/tmp/util-linux-2.20.1$ ./configure --with-utempter
john@U64D211:~/tmp/util-linux-2.20.1$ make
john@U64D211:~/tmp/util-linux-2.20.1$ cd term-utils/
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ ldd ./script
linux-vdso.so.1 =>  (0x00007fff54dff000)
libutil.so.1 => /lib/x86_64-linux-gnu/libutil.so.1 (0x00007f289e635000)
libutempter.so.0 => /usr/lib/libutempter.so.0 (0x00007f289e432000)
libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f289e072000)
/lib64/ld-linux-x86-64.so.2 (0x00007f289e861000)

Testing

Before running script

john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ ls /dev/pts
0  1  5  8  ptmx
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ last -i
john     pts/0        0.0.0.0          Sat Jan  5 09:09   still logged in   
reboot   system boot  0.0.0.0          Sat Jan  5 09:08 - 10:37  (01:28)    
john     pts/0        0.0.0.0          Thu Jan  3 00:50 - 01:42  (00:52)    
reboot   system boot  0.0.0.0          Thu Jan  3 00:48 - 01:43  (00:54)    

wtmp begins Tue Jan  1 20:48:28 2013

Within script

john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ ./script
Script started, file is typescript
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ ls /dev/pts
0  1  2  5  8  ptmx
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ last -i
john     pts/2        0.0.0.0          Sat Jan  5 10:37   still logged in   
john     pts/0        0.0.0.0          Sat Jan  5 09:09   still logged in   
reboot   system boot  0.0.0.0          Sat Jan  5 09:08 - 10:37  (01:29)    
john     pts/0        0.0.0.0          Thu Jan  3 00:50 - 01:42  (00:52)    
reboot   system boot  0.0.0.0          Thu Jan  3 00:48 - 01:43  (00:54)    

wtmp begins Tue Jan  1 20:48:28 2013
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ exit
exit
Script done, file is typescript

After script end

john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ ls /dev/pts
0  1  5  8  ptmx
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ last -i
john     pts/2        0.0.0.0          Sat Jan  5 10:37 - 10:37  (00:00)    
john     pts/0        0.0.0.0          Sat Jan  5 09:09   still logged in   
reboot   system boot  0.0.0.0          Sat Jan  5 09:08 - 10:37  (01:29)    
john     pts/0        0.0.0.0          Thu Jan  3 00:50 - 01:42  (00:52)    
reboot   system boot  0.0.0.0          Thu Jan  3 00:48 - 01:43  (00:54)    

wtmp begins Tue Jan  1 20:48:28 2013
john@U64D211:~/tmp/util-linux-2.20.1/term-utils$ last
john     pts/2                         Sat Jan  5 10:37 - 10:37  (00:00)    
john     pts/0        :0               Sat Jan  5 09:09   still logged in   
reboot   system boot  3.2.0-35-generic Sat Jan  5 09:08 - 10:38  (01:30)    
john     pts/0        :0               Thu Jan  3 00:50 - 01:42  (00:52)    
reboot   system boot  3.2.0-35-generic Thu Jan  3 00:48 - 01:43  (00:54)    

wtmp begins Tue Jan  1 20:48:28 2013

The root cause of emtpy hostname

And yes, script.c do create the wtmp entry with empty hostname. Look at following code block in util-linux-2.20.1/term-utils/script.c Line:245-247

#ifdef HAVE_LIBUTEMPTER
    utempter_add_record(master, NULL);
#endif

Base on libutempter-1.1.5/utempter.h

extern int utempter_add_record (int master_fd, const char *hostname);

So script.c is actually passing empty hostname into utempter_add_record.

RedHat Backport

The interesting thing is, upstream util-linux-ng-2.17.2 actually does not support libutempter. Seems Redhat decided to added that support back.

john@U64D211:~/tmp/util-linux-ng-2.17.2$ ./configure --help|grep utemp

The above command return empty result.

Conclusion

So the difference in behavior between the two distros is not a bug, but a choice. RedHat decided to support that feature, while Debian skipped it.

Solution 2

This looks absolutely puzzling to me. Either it should use some DNS name or IP address. I checked the last.c file also but I still can't find why it is not showing anything. Probably given some time, I can figure out the part about 0.0.0.0.

int dns_lookup(char *result, int size, int useip, int32_t *a)
307 {
308     struct sockaddr_in  sin;
309     struct sockaddr_in6 sin6;
310     struct sockaddr     *sa;
311     int         salen, flags;
312     int         mapped = 0;
313 
314     flags = useip ? NI_NUMERICHOST : 0;
315 
316     /*
317      *  IPv4 or IPv6 ?
318      *  1. If last 3 4bytes are 0, must be IPv4
319      *  2. If IPv6 in IPv4, handle as IPv4
320      *  3. Anything else is IPv6
321      *
322      *  Ugly.
323      */
324     if (a[0] == 0 && a[1] == 0 && a[2] == htonl (0xffff))
325         mapped = 1;
326 
327     if (mapped || (a[1] == 0 && a[2] == 0 && a[3] == 0)) {
328         /* IPv4 */
329         sin.sin_family = AF_INET;
330         sin.sin_port = 0;
331         sin.sin_addr.s_addr = mapped ? a[3] : a[0];
332         sa = (struct sockaddr *)&sin;
333         salen = sizeof(sin);
334     } else {
335         /* IPv6 */
336         memset(&sin6, 0, sizeof(sin6));
337         sin6.sin6_family = AF_INET6;
338         sin6.sin6_port = 0;
339         memcpy(sin6.sin6_addr.s6_addr, a, 16);
340         sa = (struct sockaddr *)&sin6;
341         salen = sizeof(sin6);
342     }
343 
344     return getnameinfo(sa, salen, result, size, NULL, 0, flags);
345 }

The two global variables used in the context are these.

int usedns = 0;     /* Use DNS to lookup the hostname. */
72 int useip = 0;       /* Print IP address in number format */

So, in theory, it should either use dns or IP.

I will see if I can dig anything further. But what ewwhite asked are valid questions.

Solution 3

So I've ran last in a debugger which hopefully will give you at least some answers to your question. My feeling is the root cause is deeper though.

Why does last -i show 0.0.0.0 for pts line entries

The best way to explain this is what happens when you dont pass -i.

The reason for this is in this code section of last.c

if (usedns || useip)
  r = dns_lookup(domain, sizeof(domain), useip, p->ut_addr_v6);
if (r < 0) {
   len = UT_HOSTSIZE;
   if (len >= sizeof(domain)) len = sizeof(domain) - 1;
   domain[0] = 0;
   strncat(domain, p->ut_host, len);
}

Both usedns and useip (using the default options) are not flagged. This causes the logic to copy out of the struct p->ut_host which according to man utmp contains the remote login name as recorded by whatever wrote into the utmp.

char ut_host[UT_HOSTSIZE]; /* Hostname for remote login, or
                              kernel version for run-level
                              messages */

In your case, the value in here is zeroes. This is why when you run last nothing appears for you.

In the case of last -i then dns_lookup is invoked. This will pass the entry (p->ut_addr_v6) to be resolved via DNS. In your case this value also contains zeroes.

Most of dns_lookup is window dressing and heusteric. Basically what matters is the function getnameinfo. This is a library call which in this case will try its best to resolve the binary value stored in the ut_addr_v6. When this entry contains zeroes (such as in your case) you are actually resolving this to 0.0.0.0 as is what happens with your last -i output.

Is there anything (other than malicious activity) that would reasonably explain the behavior?

Well, its probably a bug or oversight. Its unlikely to be malicious since it seems stupid to leave any trace as an attacker rather than omitting a source address.

The focus of answers so far have been looking at the wrong place. last just reads utmp or wtmp. However last is doing its best with the data it has.

Your root cause lies somewhere in the manner to which utmp is being written to!

While a few applications directly write into utmp I guess the source of your problems lie in the way sshd is handling the session management.

Other than bash history timestamping, are there other things I can do to track the issue down?

utmp is not typically writable and is not meant to be. utmp is written by applications designed to log you in and setup your session. In your case that is sshd.

Why sshd is not handling your user properly is very strange as it should be properly copying in the hostname you came in from. This is where debugging efforts should probably be focused. Start with adding debug output of sshd to your logs and see if anything anomalous comes up.

If you want to work around the problem (or, maybe even possibly discover more about the issue) you can use pam_lastlog to manage utmp by adding it to the session entry to /etc/pam.d/sshd.

As a matter of fact it wont hurt to check if it is already there -- because pam_lastlog contains a nohost option which would definitely explain your behaviour you are experiencing.

Finally, you could not use last at all. aulast does the same job via the audit subsystem.

Might be worth a try to see if that has managed to at least write the correct address. If it hasn't then your problem must be with sshd as sshd is passing the DNS names around different subsystems like utmp or audit.

Solution 4

(1) Base on OP last output

After log in via ssh, one can ssh to localhost and get 0.0.0.0 in last -i for the later.

Base on first four lines of OP's log

mpenning pts/19                        Fri Nov 16 10:32 - 10:35  (00:03)
mpenning pts/17                        Fri Nov 16 10:21 - 10:42  (00:21)
bill     pts/15       sol-bill.local   Fri Nov 16 10:19 - 10:36  (00:16)
mpenning pts/1        192.0.2.91       Fri Nov 16 10:17 - 10:49 (12+00:31)

pts/19 log in was within pts/17 log in period.

pts/17 log in was within pts/1 log in period.

For this specific occurrence, it is logical to guess that OP ssh from 192.0.2.91(pty/1), then within that ssh session, log in locally (ssh localhost) to the server again(pts/17), and again(pts/19).

Please check if this overlapping happen with other occurrence.

Following may help pin point the cause

  • Do you use ssh-key? If so, on the server, did you setup ssh-key to log in locally?
  • Check or post /var/log/secure of the same time frame. It may provide some hint.
  • Check scripts you use
  • Check shell aliases you use
  • Check your command history

(2) Additional Secnario

Scenario 1 - sudo and terminal

  1. UserA login X Window
  2. Open a terminal windows, do xhost + localhost
  3. su - UserB or sudo su - UserB then open a new terminal (xterm, gnome-terminal, etc)
  4. UserB will show up as 0.0.0.0 in last -i

su - UserB will not register as a UserB login in last, but opening a terminal will.

Scenario 2 - login

  1. ssh into server
  2. type sudo login
  3. login as yourself
  4. check last and last -i

last show no hostname or IP for the login session. last -i will IP 0.0.0.0 for the login session.

john@U64D211:~$ last -5
john     pts/0                         Sun Dec 23 20:50   still logged in   
john     pts/0                         Sun Dec 23 20:50 - 20:50  (00:00)    
john     pts/0        :0               Sun Dec 23 20:50 - 20:50  (00:00)    
reboot   system boot  3.2.0-35-generic Sun Dec 23 20:49 - 20:50  (00:01)    
john     pts/2        js.example.com   Sun Dec 23 17:14 - crash  (03:34)    

wtmp begins Sat Dec  1 06:30:46 2012
john@U64D211:~$ last -5i
john     pts/0        0.0.0.0          Sun Dec 23 20:50   still logged in   
john     pts/0        0.0.0.0          Sun Dec 23 20:50 - 20:50  (00:00)    
john     pts/0        0.0.0.0          Sun Dec 23 20:50 - 20:50  (00:00)    
reboot   system boot  0.0.0.0          Sun Dec 23 20:49 - 20:50  (00:01)    
john     pts/2        192.168.1.90     Sun Dec 23 17:14 - crash  (03:34)    

wtmp begins Sat Dec  1 06:30:46 2012

Mife's answer already show code block of last.c. The reason last display empty hostname/IP is because ut_host for those records are actually empty. For complete wtmp structure, do man wtmp on any linux system.

The 2 scenarios here shows that even standard packages, under certain situation, do create them as such.

(3) Bash History Hack

It will only work if the session use bash as interactive shell.

.bashrc and .bash_profile are only used by bash.

They won't be sourced automatically if the session use any other shell(sh, csh, etc) or execute program directly, and there will be no bash history either.

(4) Process Accounting

Since OP mention nothing about secure file, I will assume that is a dead end and it actually provide now hint.

If the following assumption is correct

`last` 0.0.0.0 entries are actually created with in OP own session

auth.log(debian)/secure(CentOS) will not help. As only authentication related action is recorded in it.

wtmp/utmp, with the limitation in their data structure, is also a dead end. There is no information about what created them.

That leave us with one option, process accounting. This is a big gun and has to be used with caution.

  1. Maybe against company policy
  2. Other users on a shared system maybe unhappy/uncomfortable with it enabled
  3. The log file can use a lot of disk space. Keep an eye on the file size growth rate.

The psacct package version should be 6.3.2-56 or above, according to this post.

If this is to be used, and /var/log has limited space, change the acct log file to a directory(root only access) under /home, which usually has much more space.

This is really the big gun. With OP 10% occurrence rate, there should be result within a week. If during that period, empty entry show up in last but nothing from acct log, it become a mystery situation, and would require some drastic action.

Following is a sample output of lastcomm

lesspipe               john     pts/8      0.02 secs Mon Dec 24 17:10
lesspipe          F    john     pts/8      0.00 secs Mon Dec 24 17:10
dirname                john     pts/8      0.00 secs Mon Dec 24 17:10
basename               john     pts/8      0.00 secs Mon Dec 24 17:10
kworker/1:2       F    root     __         0.00 secs Mon Dec 24 16:54
tty                    john     pts/6      0.01 secs Mon Dec 24 17:09
tty                    john     pts/4      0.01 secs Mon Dec 24 17:09
cron              F    root     __         0.05 secs Mon Dec 24 17:09
sh               S     root     __         0.01 secs Mon Dec 24 17:09
find                   root     __         0.01 secs Mon Dec 24 17:09
maxlifetime            root     __         0.00 secs Mon Dec 24 17:09
php5                   root     __         0.23 secs Mon Dec 24 17:09
which                  root     __         0.00 secs Mon Dec 24 17:09
lastcomm               root     pts/0      0.01 secs Mon Dec 24 17:08
tty                    john     pts/1      0.01 secs Mon Dec 24 17:08
dconf worker         X john     __         5.46 secs Mon Dec 24 16:58
lastcomm               root     pts/7      0.04 secs Mon Dec 24 17:05
mesg             S     root     pts/7      0.00 secs Mon Dec 24 17:05
bash              F    root     pts/7      0.00 secs Mon Dec 24 17:05
dircolors              root     pts/7      0.00 secs Mon Dec 24 17:05

You can also use 'dump-acct' to show more info.

PS1: I tried to open a few terminal and ssh session. It is not clear (or not easy to pin point) what open a new pts. However, it does show everything that ran within that pts/session.

PS2: A blog post about using acct by a Mike.

Solution 5

When you login to a Machine, these could be few entries in the last command.

geekride   tty2                        Fri Dec 21 15:45 - 15:45  (00:00)    
geekride   pts/1                       Fri Dec 21 13:45   still logged in   
geekride   pts/1        :pts/0:S.0     Thu Dec  6 12:49 - 00:40  (11:50)    
geekride   pts/1        10.31.33.47    Thu Dec  6 12:49 - 00:40  (11:50)    

The First entry with tty* comes when you login through the terminal or console by pressing CTRL+ALT+F1-6. Its pretty much clear from the terminal it's using.

The second Entry normally comes into picture when you log into a Machine and open up a terminal window in GUI. There will also be a entry even if you open a new Tab in the same terminal window.

The Third type of Entry comes when you open a screen session after loggin into through SSH. That will also create a entry there and without any IP address.

The fourth entry is pretty normal which everyone understands.

If you do last -i with the following entries, you will see something like this:

geekride   tty2         0.0.0.0        Fri Dec 21 15:45 - 15:45  (00:00)    
geekride   pts/9        0.0.0.0        Fri Dec 21 13:45   still logged in   
geekride   pts/1        0.0.0.0        Thu Dec  6 12:49 - 00:40  (11:50)    

I am pretty much sure that your case comes under in any of the 2 cases, one with the terminal Window in GUI and the other with the screen session.

Hope this Helped.

Share:
6,517

Related videos on Youtube

Mike Pennington
Author by

Mike Pennington

--&gt;

Updated on September 18, 2022

Comments

  • Mike Pennington
    Mike Pennington almost 2 years

    I have five CentOS 6 linux systems at work, and encountered a rather strange issue that only seems to happen with my userid across all the linux systems I have... This is an example of the problem from entries I excepted from the last command...

    mpenning pts/19                        Fri Nov 16 10:32 - 10:35  (00:03)
    mpenning pts/17                        Fri Nov 16 10:21 - 10:42  (00:21)
    bill     pts/15       sol-bill.local   Fri Nov 16 10:19 - 10:36  (00:16)
    mpenning pts/1        192.0.2.91       Fri Nov 16 10:17 - 10:49 (12+00:31)
    kkim14   pts/14       192.0.2.225      Thu Nov 15 18:02 - 15:17 (4+21:15)
    gduarte  pts/10       192.0.2.135      Thu Nov 15 12:33 - 08:10 (11+19:36)
    gduarte  pts/9        192.0.2.135      Thu Nov 15 12:31 - 08:10 (11+19:38)
    kkim14   pts/0        :0.0             Thu Nov 15 12:27 - 15:17 (5+02:49)
    gduarte  pts/6        192.0.2.135      Thu Nov 15 11:44 - 08:10 (11+20:25)
    kkim14   pts/13       192.0.2.225      Thu Nov 15 09:56 - 15:17 (5+05:20)
    kkim14   pts/12       192.0.2.225      Thu Nov 15 08:28 - 15:17 (5+06:49)
    kkim14   pts/11       192.0.2.225      Thu Nov 15 08:26 - 15:17 (5+06:50)
    dspencer pts/8        192.0.2.130      Wed Nov 14 18:24   still logged in
    mpenning pts/18       alpha-console-1. Mon Nov 12 14:41 - 14:46  (00:04)
    

    You can see two of my pts login entries above that do not have a source IP address associated with them. My CentOS machines have as many as six other users that share the systems. Approximately 10% of my logins see this issue, but no other usernames exhibit this behavior. There is no entry in /var/log/secure for the entries without a source IP address.

    Questions

    Given the kind of scripts I keep on these systems (which control much of our network infrastructure), I'm a little spooked by this and would like to understand what would cause my logins to occasionally miss source addresses.

    • Why does last -i show 0.0.0.0 for pts line entries (also see this answer)
    • Is there anything (other than malicious activity) that would reasonably explain the behavior?
    • Other than bash history timestamping, are there other things I can do to track the issue down?

    Informational

    Since this started happening, I enabled bash history time-stamping (i.e. HISTTIMEFORMAT="%y-%m-%d %T " in .bash_profile) and also added a few other bash history hacks; however, that does not give clues to what happened during the previous occurrences.

    All the systems run CentOS 6.3...

    [mpenning@typo ~]$ uname -a
    Linux typo.local 2.6.32-279.9.1.el6.x86_64 #1 SMP Tue Sep 25 21:43:11 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
    [mpenning@typo ~]$
    

    EDIT

    If I use last -i mpenning, I see entries like this...

    mpenning pts/19       0.0.0.0          Fri Nov 16 10:32 - 10:35  (00:03)
    mpenning pts/17       0.0.0.0          Fri Nov 16 10:21 - 10:42  (00:21)
    

    Note for those trying to answer: I have not logged in with the screen command or the GUI. All my logins are from SSH; to receive the bounty award, you must cite authoritative references to explain the last -i 0.0.0.0 entries sourced only via SSH.

    EDIT 2 (for ewwhite's questions)

    /etc/resolv.conf (note that I used .local addrs in last output above to hide my company's info)

    [mpenning@sasmars network]$ cat /etc/resolv.conf
    nameserver 192.0.2.40
    nameserver 192.0.2.60
    domain mycompany.com
    search mycompany.com
    [mpenning@sasmars network]$
    

    /etc/hosts info (note that this customized hosts file only exists on one of the machines that has these problems)

    [mpenning@sasmars network]$ cat /etc/hosts
    127.0.0.1       localhost.localdomain localhost
    192.0.2.44      sasmars.mycompany.com sasmars
    ::1             localhost6.localdomain6 localhost6
    
    ## Temporary kludge until I add reverse hostname mappings...
    ## Firewalls
    192.0.2.254     a2-inet-fw1
    192.0.2.253     a2-inet-fw2
    192.0.2.254     a2-wan-fw1
    192.0.2.253     a2-wan-fw2
    192.0.2.201     a2-fab-fw1
    192.0.2.202     a2-fab-fw2
    192.0.2.203     t1-eds-fw1
    192.0.2.42      sasvpn
    192.0.2.246     sasasa1
    192.0.2.10      sasoutfw1
    ## Wireless
    192.0.2.6       saswcs1
    192.0.2.2       l2wlc3
    192.0.2.4       l2wlc4
    192.0.2.12      f2wlc5
    192.0.2.16      f2wlc6
    192.0.2.14      f2wlc1
    192.0.2.8       f2wlc2
    [mpenning@sasmars network]$
    

    sftp Output from /var/log/secure*

    Dec 26 10:36:37 sasmars sshd[26016]: pam_sm_authenticate: called (pam_tacplus v1.3.7)
    Dec 26 10:36:37 sasmars sshd[26016]: pam_sm_authenticate: user [mpenning] obtained
    Dec 26 10:36:37 sasmars sshd[26016]: tacacs_get_password: called
    Dec 26 10:36:37 sasmars sshd[26016]: tacacs_get_password: obtained password
    Dec 26 10:36:37 sasmars sshd[26016]: pam_sm_authenticate: password obtained
    Dec 26 10:36:37 sasmars sshd[26016]: pam_sm_authenticate: tty [ssh] obtained
    Dec 26 10:36:37 sasmars sshd[26016]: pam_sm_authenticate: rhost [192.0.2.91] obtained
    Dec 26 10:36:37 sasmars sshd[26016]: pam_sm_authenticate: trying srv 0
    Dec 26 10:36:38 sasmars sshd[26016]: Accepted password for mpenning from 192.0.2.91 port 55118 ssh2
    Dec 26 10:36:38 sasmars sshd[26016]: pam_sm_setcred: called (pam_tacplus v1.3.7)
    Dec 26 10:36:38 sasmars sshd[26016]: pam_unix(sshd:session): session opened for user mpenning by (uid=0)
    Dec 26 10:36:38 sasmars sshd[26018]: pam_sm_setcred: called (pam_tacplus v1.3.7)
    Dec 26 10:36:38 sasmars sshd[26018]: subsystem request for sftp
    Dec 26 10:37:20 sasmars sshd[26016]: pam_unix(sshd:session): session closed for user mpenning
    Dec 26 10:37:20 sasmars sshd[26016]: pam_sm_setcred: called (pam_tacplus v1.3.7)
    

    FINAL RESOLUTION

    See my answer below

    • ewwhite
      ewwhite over 11 years
      Are they all connecting via ssh? I have a number of large multiuser CentOS 6.x systems. I'll see if I can see the same thing there.
    • JeffG
      JeffG over 11 years
      Does the output of last -i mpenning show the blanks?
    • ewwhite
      ewwhite over 11 years
      Oh, right.. I need to replicate this on an EL6.3 server...
    • Matthew Ife
      Matthew Ife over 11 years
      Can you provide the login output from /var/log/secure and /var/log/messages ? I believe that the IP value is a parameter passed in via PAM. Does PAM show the IP properly?
    • John Siu
      John Siu over 11 years
      You want to know why the hostname/ip is blank? Or you want to know why(what cause) those entries are there?
    • Mike Pennington
      Mike Pennington over 11 years
      @JohnSiu, I am trying to figure out what causes these blank entries; as part of finding that I'm interested in how the blank entries get there
    • John Siu
      John Siu over 11 years
      @MikePennington Good the heard that, as that is what I am after. Check (4) of my updated answer.
    • Muhammad
      Muhammad over 11 years
      Just want to add: on my systems(RHEL) - if users initiated xterm from a VNC session, it will get recorded as 0.0.0.0. So every new xterm will be recorded 0.0.0.0 with the related pts number. So its a non-remote connection.
    • Mike Pennington
      Mike Pennington over 11 years
      @Mlfe, the 0.0.0.0 entries have no corresponding entry in /var/log/secure... this is part of what is so disturbing
    • John Siu
      John Siu over 11 years
      @MikePennington Do you have some ssh tunnel setup in your putty?
    • Mike Pennington
      Mike Pennington over 11 years
      @JohnSiu, there are no putty tunnels
    • John Siu
      John Siu over 11 years
      @MikePennington In SuperPutty GUI, there is a Commands bar, expend the pull down list and see if you recognize anything that may open a new session.
    • John Siu
      John Siu over 11 years
      @MikePennington I know bounty is close, but did you track down the source(process/program) creating the entries?
  • Mike Pennington
    Mike Pennington over 11 years
    This answer looks wrong... all 0.0.0.0 entries in my logs are on a pts line
  • alterpub
    alterpub over 11 years
    It's a right answer, example from my system: # last -i |grep 0.0.0.0 \ reboot system boot 0.0.0.0 Wed Dec 5 20:09 - 17:18 (15+21:08) # last |grep reboot \ reboot system boot 2.6.32-10-pve Wed Dec 5 20:09 - 17:18 (15+21:08)
  • Mike Pennington
    Mike Pennington over 11 years
    What do you mean "you use local system"... please read my question closely... I only login with ssh. Are you suggesting that 0.0.0.0 is a valid entry for an ssh login to a pty?
  • Mike Pennington
    Mike Pennington over 11 years
    @alterpub, again, I only login with ssh; 0.0.0.0 is not a valid ssh pty entry unless someone can show me official documentation otherwise.
  • Chris Smith
    Chris Smith over 11 years
    +1 for digging into actual source code for the command in question.
  • Mike Pennington
    Mike Pennington over 11 years
    Regarding your questions about the local environment... Please see the latest edits to my question... keep in mind that no other users have this issue besides me... so global configs (such as /etc/hosts) should affect everyone... not just me
  • Mike Pennington
    Mike Pennington over 11 years
    Great information, this is the kind of authoritative source I'm looking for. Thank you for doing the hard work to find the code.
  • user9517
    user9517 over 11 years
    This may seem like it's not an answer but it really is, we've gone past the point of people just knowing this and really need to get debugging.
  • ewwhite
    ewwhite over 11 years
    It's environment-specific. I run enough of these servers and can't reproduce the behavior with any combination of normal activity.
  • ewwhite
    ewwhite over 11 years
    It would be helpful to know what timeframe this occurred over. Your log snippet is a month old. Is this reproducible? Is this occurring on all servers? Perhaps if the wtmp file has been rotated, you may have a wtmp and wtmp1. Can you run last -if against both of those files and see if you see the same results over time?
  • ewwhite
    ewwhite over 11 years
    Also, are you running commands; (p)sftp (p)scp? I ask since your no-IP sessions occur within the timeframe of a longer session. In your example, were you opening multiple connections from 192.0.2.91?
  • Mike Pennington
    Mike Pennington over 11 years
    good questions... I have to prepare for guests arriving today but I will endeavor to respond with those details this weekend
  • user9517
    user9517 over 11 years
    @ewwhite: I've a few too and I can't find it either.
  • Mike Pennington
    Mike Pennington over 11 years
    I dont know how you concluded tha a localhost login yields 0.0.0.0, it always shows up as localhost for me. I only login with ssh, I dont know what you mean by login locally
  • John Siu
    John Siu over 11 years
    Please do ssh localhost and check last -i.
  • John Siu
    John Siu over 11 years
    Regarding login locally, I mean doing ssh localhost within that ssh session. I modified that sentence, hope it is less confusing now.
  • John Siu
    John Siu over 11 years
    Additional scenario added.
  • Tonny
    Tonny over 11 years
    @ewwhite Tried a few CentOS machines myself and asked also some colleagues that maintain about 300 of these boxes. They can't recall ever having seen this before either.
  • Rahul
    Rahul over 11 years
    this was really useful and cleared few of really old doubts I had
  • ewwhite
    ewwhite over 11 years
    You didn't mention that you were using the script command in your initial question.
  • Mike Pennington
    Mike Pennington over 11 years
    That's a pretty lame complaint... blaming me for not mentioning this is Monday-morning QB-ing at its worst... if I knew script mattered, I would not need to ask the question
  • ewwhite
    ewwhite over 11 years
    I asked Have you changed ~/.bashrc or ~/.bash_profile from default? Are there any other special login scripts in the environment?. The script program makes a typescript of everything printed on your terminal. It's a pertinent detail.
  • Mike Pennington
    Mike Pennington over 11 years
    @ewwhite it's time for you to stop attacking and start thinking critically... 1) You are assuming script was in my .bashrc or .bash_profile, it was not; I execute script foo.log when I make major changes so I can have a change-log... ie that's why it only affects ~10% of my logins 2) If your accusation is correct (and it's not), I would never have an ssh login that did not have another 0.0.0.0 entry just after it 3) script only does this in CentOS... I have used it for over a decade and never saw this behavior in another distro... at this point I'm arguing it is likely a CentOS bug
  • user9517
    user9517 over 11 years
    This is also present in CentOS 5.8. FWIW it wouldn't be a bug in CentOS it would be a bug in RHEL as CentOS is just a rebuild of that.
  • Mike Pennington
    Mike Pennington over 11 years
    Fair point about RHEL bug... thanks for testing on 5.8... I will submit a ticket and see what happens
  • Mike Pennington
    Mike Pennington over 11 years
    @JohnSiu, Thank you for testing Ubuntu; had a feeling it wouldn't replicate CentOS' behavior since Ubuntu's development is so closely-linked to Debian. Regarding Gentoo: our corporate linux preference is CentOS... however, one of our full-time linux admins runs Gentoo on his personal linux desktop because he feels that he learns so much about linux by running Gentoo...
  • user9517
    user9517 over 11 years
    @MikePennington: It's also present in Fedora BTW, Michael Hampton checks for me.
  • ewwhite
    ewwhite over 11 years
    We'll follow the RHEL bug. It'll be interesting to see how they respond.
  • John Siu
    John Siu over 11 years
    @MikePennington Check my new answer for the new mystery :)
  • ewwhite
    ewwhite over 11 years
    What about CentOS 5?
  • ewwhite
    ewwhite over 11 years
    No need. libutempter is not linked in EL4 (via ldd), but it is linked in the EL5 and EL6 script command. This feature change has likely been in place for Red Hat-like systems since the 2007 introduction of RHEL 5. coreutils on EL4 is version 5.2.1. On EL5 it's version 5.97.
  • John Siu
    John Siu over 11 years
    I see. BTW, script is in util-linux.
  • user9517
    user9517 over 11 years
  • John Siu
    John Siu over 11 years
    @lain It is not default compile option for util-linux 2.20.1. Option --with-utempter is needed during source configuration for script to update wtmp.
  • user9517
    user9517 over 11 years
    @JohnSiu: Yes, that's the reason for the difference, it seems to me that they fixed the reported bug and (unintentionally) created a new one.
  • Mike Pennington
    Mike Pennington over 11 years
    very interesting find, thanks for digging this up! Lets se what RHEL does with the info
  • Mike Pennington
    Mike Pennington over 11 years
    at a minimum, this should be documentation bug... we need some indication that you will get blank wtmp entries when you use the centos version of script...
  • John Siu
    John Siu over 11 years
    That will be linux-util. Updated. See section The root cause of emtpy hostname. Seems to be lazy coding.
  • Hauke Laging
    Hauke Laging over 11 years
    This answer does not make much sense to me. The discussion is not about telnet. netstat -nae | grep 23 is not a useful way to find telnet connections. This command gives 92 results on my system, none of them being telnet.