Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

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

share|improve this question
    
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. –  ewwhite Dec 4 '12 at 21:36
    
@ewwhite, thank you... all logins should be ssh (and occasionally via GUI console, but I only login from the GUI when turning the box up). No other remote login protocol is enabled. –  Mike Pennington Dec 4 '12 at 21:38
    
Does the output of last -i mpenning show the blanks? –  JeffG Dec 13 '12 at 17:27
    
Oh, right.. I need to replicate this on an EL6.3 server... –  ewwhite Dec 21 '12 at 13:32
    
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? –  Matthew Ife Dec 21 '12 at 20:11

14 Answers 14

up vote 4 down vote accepted

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.

share|improve this answer
    
What about CentOS 5? –  ewwhite Jan 5 '13 at 16:47
    
@ewwhite Can you give me the coreutils rpm version CentOS 5 is using? I have to check the source code. –  John Siu Jan 5 '13 at 16:52
    
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. –  ewwhite Jan 5 '13 at 16:56
    
I see. BTW, script is in util-linux. –  John Siu Jan 5 '13 at 17:02
1  
@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. –  Iain Jan 5 '13 at 17:18

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.

share|improve this answer
1  
+1 for digging into actual source code for the command in question. –  Chris Smith Dec 21 '12 at 14:34
    
Great information, this is the kind of authoritative source I'm looking for. Thank you for doing the hard work to find the code. –  Mike Pennington Dec 21 '12 at 14:59

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.

share|improve this answer
    
Could you add some specific instructions on how to use pam_lastlog as mentioned above ? –  Mike Pennington Dec 26 '12 at 16:43

(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.

share|improve this answer
    
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 –  Mike Pennington Dec 23 '12 at 9:59
    
Please do ssh localhost and check last -i. –  John Siu Dec 23 '12 at 10:13
    
Regarding login locally, I mean doing ssh localhost within that ssh session. I modified that sentence, hope it is less confusing now. –  John Siu Dec 23 '12 at 10:19
    
Additional scenario added. –  John Siu Dec 23 '12 at 10:53

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|improve this answer
2  
I did not use the GUI or screen for any of the 0.0.0.0 entries. I only use the GUI when I installed the machines (around August / September). I see many 0.0.0.0 pts entries after that time. –  Mike Pennington Dec 21 '12 at 11:41
1  
this was really useful and cleared few of really old doubts I had –  rahulroc Dec 24 '12 at 5:52

I don't think we're going to get far with this without debugging last.c, but that shouldn't not too hard as it compiles readily ...

One possibility though is to dump the /var/log/wtmp file using the utmpdump command and have a look at the raw records this may shed some light for you. If not please post some relevant output from

utmpdump /var/log/wtmp 

so that we can recreate local copies of your wtmp to debug with

utmpdump -r <dumpfile >wtmp
share|improve this answer
    
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. –  Iain Dec 22 '12 at 10:52
    
It's environment-specific. I run enough of these servers and can't reproduce the behavior with any combination of normal activity. –  ewwhite Dec 22 '12 at 14:29
    
@ewwhite: I've a few too and I can't find it either. –  Iain Dec 22 '12 at 17:21
    
@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. –  Tonny Dec 23 '12 at 16:44

I checked across 12 multi-user CentOS and RHEL 6.3-based application servers. None exhibited this behavior. There were no missing entries in last output going back 4-5 weeks.

I think it would be important to see your /etc/hosts file entry to make sure it conforms to this format.

Also, what are you doing for DNS resolution? Can you post your /etc/resolv.conf?

The other responses indicating that 0.0.0.0 represents local connections are correct. The typical examples are reboot and console login events:

 reboot   system boot  0.0.0.0          Sat Dec  8 06:12 - 05:57 (12+23:45)  
 reboot   system boot  0.0.0.0          Sat Dec  8 05:25 - 06:09  (00:44)    
 reboot   system boot  0.0.0.0          Fri Nov 30 14:28 - 05:22 (7+14:54)   
 root     tty1         0.0.0.0          Fri Nov 30 13:52 - 13:55  (00:03)    
 reboot   system boot  0.0.0.0          Fri Nov 30 13:51 - 14:25  (00:34)    

Since this only seems to occur with named users, is there any change there's something funky being sourced or run in their login scripts? Have you changed ~/.bashrc or ~/.bash_profile from default? Are there any other special login scripts in the environment?

--Edit--

I'm still unable to reproduce this in any way. I look at two critical components, though. The last command is stable and has not been changed in a long time. Looking at the changelog for sysvinit-tools, there are no relevant bugs. Same for initscripts (wtmp).

If you can force this to happen, try it with a different user account from the same source machines. But I don't see any indication that this is an OS issue.

share|improve this answer
    
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 Dec 21 '12 at 14:55
    
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 Dec 22 '12 at 14:52
    
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? –  ewwhite Dec 22 '12 at 15:09
    
good questions... I have to prepare for guests arriving today but I will endeavor to respond with those details this weekend –  Mike Pennington Dec 22 '12 at 16:04
    
I sometimes use scp and sftp via the free WinSCP client; however, those entries produce valid /var/log/secure entries... the entries which show 0.0.0.0 show nothing in /var/log/secure –  Mike Pennington Dec 26 '12 at 16:38

FINAL RESOLUTION

I already awarded the bonus, so this is purely for future googlers with the same question.

The reason this only appears in ~10% of my logins is because when I make major changes to our routers or switches, I use script foo.log so I have a complete terminal log of the change. For reasons I still don't understand, CentOS creates a pts entry when you use the script command... I will demonstrate the output of last -i before and after running script...

[mpenning@sasmars net]$ last -i | head
kkim14   pts/13       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/12       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/10       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/9        192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/5        192.0.2.225   Wed Jan  2 09:43   still logged in
mpenning pts/17       192.0.2.29    Mon Dec 31 16:45 - 16:49  (00:03)
gduarte  pts/16       192.0.2.135   Thu Dec 27 10:54   still logged in
gduarte  pts/14       192.0.2.135   Thu Dec 27 10:44   still logged in
dspencer pts/14       192.0.2.4     Thu Dec 27 09:56 - 09:57  (00:01)
mpenning pts/14       192.0.2.91    Thu Dec 27 08:31 - 08:32  (00:00)
[mpenning@sasmars net]$ script ~/something_random.log
Script started, file is /home/mpenning/something_random.log
[mpenning@sasmars net]$ date
Thu Jan  3 16:14:19 CST 2013 # <--------------------------------------------------
[mpenning@sasmars net]$ exit
exit
Script done, file is /home/mpenning/something_random.log
[mpenning@sasmars net]$ last -i | head
mpenning pts/15       0.0.0.0          Thu Jan  3 16:14 - 16:14  (00:00) # <------
kkim14   pts/13       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/12       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/10       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/9        192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/5        192.0.2.225   Wed Jan  2 09:43   still logged in
mpenning pts/17       192.0.2.29    Mon Dec 31 16:45 - 16:49  (00:03)
gduarte  pts/16       192.0.2.135   Thu Dec 27 10:54   still logged in
gduarte  pts/14       192.0.2.135   Thu Dec 27 10:44   still logged in
dspencer pts/14       192.0.2.4     Thu Dec 27 09:56 - 09:57  (00:01)
[mpenning@sasmars net]$ cat /etc/redhat-release
CentOS release 6.3 (Final)
[mpenning@sasmars net]$

This behavior seems to be unique to CentOS 6... we have some CentOS 4.7 machines in the lab that don't put a blank entry in wtmp... Debian / Gentoo machines don't exhibit this behavior either. Our linux-admins are scratching their heads why CentOS would intentionally add another pts entry when you execute script... I suspect this is a RHEL bug.

EDIT: I filed this problem as RHEL Bug id 892134

NOTE

Some people have erroneously assumed I put script in my ~/.bashrc or ~/.bash_profile. This is a flawed argument... if that was true, my wtmp should have a 0.0.0.0 entry after every one of my ssh logins...

[mpenning@sasmars net]$ last -i | head
kkim14   pts/13       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/12       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/10       192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/9        192.0.2.225   Wed Jan  2 09:43   still logged in
kkim14   pts/5        192.0.2.225   Wed Jan  2 09:43   still logged in
mpenning pts/18       0.0.0.0       Mon Dec 31 16:45 - 16:49  (00:03)  # <-----
mpenning pts/17       192.0.2.29    Mon Dec 31 16:45 - 16:49  (00:03)  # <-----
gduarte  pts/16       192.0.2.135   Thu Dec 27 10:54   still logged in
gduarte  pts/14       192.0.2.135   Thu Dec 27 10:44   still logged in
dspencer pts/14       192.0.2.4     Thu Dec 27 09:56 - 09:57  (00:01)
mpenning pts/15       0.0.0.0       Thu Dec 27 08:31 - 08:32  (00:00)  # <-----
mpenning pts/14       192.0.2.91    Thu Dec 27 08:31 - 08:32  (00:00)  # <-----

Of course, that was not the case...

share|improve this answer
3  
You didn't mention that you were using the script command in your initial question. –  ewwhite Jan 3 '13 at 23:56
2  
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. –  ewwhite Jan 4 '13 at 3:50
2  
@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 –  Mike Pennington Jan 4 '13 at 9:35
1  
Thank you very very much for the update. I tested on Ubuntu 12.04, script will only fork a shell. Base on what you are showing here, CentOS/Redhat version of script actually fork a pty first. Though a bit disappointed (:P) that it is not something more generic/across distro, at least the mystery is gone from my mind. PS: I am surprise you have Gentoo in production @.@ –  John Siu Jan 5 '13 at 2:14
1  
@MikePennington: It's also present in Fedora BTW, Michael Hampton checks for me. –  Iain Jan 5 '13 at 12:16

Pseudo Terminal Slave (pts) connections are SSH or telnet connections that means indirect connections to the system. All of these connections can connect to a shell which will allow you to issue commands to the computer. So when you open up a terminal on your system from gui, it opens up a pts with source ip 0.0.0.0. From the information provided by you, it seems that it happening because of script running on this server or scheduled, which is using ssh or telnet service or local pts to throw output in terminal.

share|improve this answer
    
I never use the GUI –  Mike Pennington Dec 21 '12 at 11:34

Which ssh client do you use? Some ssh clients can multiplex multiple terminals over one connection and I notice all your sessions without IP fall within longer sessions which do have a logged IP.

I can't duplicate this behaviour with ssh here.

share|improve this answer
    
I usually use superputty, currently on version 1.4.0.1... but I have seen this issue with plain-ole putty as well –  Mike Pennington Dec 21 '12 at 14:58

Perhaps your IP address resolves to a blank string on one of your DNS servers, probably the secondary if it happens only 10 per cent of the time (or just possibly a hosts file if these are distributed from a central repository). That would account for the missing (or white space) entry and be consistent with Soham's reading of the source.

share|improve this answer

"0.0.0.0" means that's a local user (not a remote login), probably invoked by application e.g cronjob.

share|improve this answer
    
This answer looks wrong... all 0.0.0.0 entries in my logs are on a pts line –  Mike Pennington Dec 21 '12 at 9:48
    
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) –  alterpub Dec 21 '12 at 13:19
    
@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. –  Mike Pennington Dec 21 '12 at 13:36

It happens because you use local system and 0.0.0.0 means ip address of all interfaces. If you think that maybe somebody hacked you try to setup full logging of shell including commands via ssh - http://blog.pointsoftware.ch/index.php/howto-bash-audit-command-logger/

share|improve this answer
    
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 Dec 21 '12 at 13:34

I solved it by adding a script to ~/.bashrc the script finds the last telnet connection source IP address, Then you can add the IP to a log file or do whatever you need..

client_ip=$(echo $(netstat -nae | grep $(netstat -nae | grep 23 | awk  '{print $8}' | sort -n | tail -n1) | awk '{print $5}') | awk -F':' '{print $1}' )

echo "client_ip=$client_ip"

Sharon

share|improve this answer
1  
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. –  Hauke Laging Feb 23 '13 at 21:43

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.