Endless looping around socket *:88 in krb5kdc with result -1 EAGAIN (Resource temporarily unavailable)

classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|

Endless looping around socket *:88 in krb5kdc with result -1 EAGAIN (Resource temporarily unavailable)

Дилян Палаузов
On my system krb5kdc got stuck.  I started it under systemd with:

/usr/local/sbin/krb5kdc -r A -r B -n -w5

The documentation of krb5kdc states:

   The -n option specifies that the KDC does not put itself in the background and does not disassociate itself from the
terminal.  In normal operation, you should always allow the KDC to place itself in the background.

What is the problem of having the process running in the foreground?

I have these processes:

# ps -eF|grep krb5
root     23199 20680  0  1209  2056   6 11:33 pts/1    00:00:00 grep --color=auto krb
root     30309     1  0  3292  3212   5 Apr19 ?        00:00:00 /usr/local/sbin/krb5kdc -r A -r B -n -w5
root     30313 30309  0  3652  3580   7 Apr19 ?        00:01:29 /usr/local/sbin/krb5kdc -r A -r B -n -w5
root     30314 30309  0  3665  3572   7 Apr19 ?        00:01:30 /usr/local/sbin/krb5kdc -r A -r B -n -w5
root     30315 30309  0  3670  3692   7 Apr19 ?        00:01:37 /usr/local/sbin/krb5kdc -r A -r B -n -w5
root     30316 30309  0  3677  3684   7 Apr19 ?        00:01:45 /usr/local/sbin/krb5kdc -r A -r B -n -w5
root     30317 30309  0  3691  3752   7 Apr19 ?        00:02:07 /usr/local/sbin/krb5kdc -r A -r B -n -w5

So PID 30309 is the master process and PID 30313, 30314, 30315, 30316 and 30317 are serving.

lsof -P|grep :88 shows:

saslauthd  7681                   root    8u     IPv4          954798949        0t0        UDP server.example.org:50240-
>server.example.org:88
saslauthd  7682                   root    8u     IPv4          954800125        0t0        UDP server.example.org:43670-
>server.example.org:88
saslauthd  7683                   root    8u     IPv4          954800669        0t0        UDP server.example.org:56808-
>server.example.org:88
saslauthd  7684                   root    8u     IPv4          954798973        0t0        UDP server.example.org:42328-
>server.example.org:88
saslauthd  7686                   root    8u     IPv4          954804419        0t0        UDP server.example.org:34084-
>server.example.org:88
saslauthd  7687                   root    8u     IPv4          954803415        0t0        UDP server.example.org:50986-
>server.example.org:88
saslauthd  7688                   root    8u     IPv4          954805293        0t0        UDP server.example.org:37353-
>server.example.org:88
saslauthd  7689                   root    8u     IPv4          954803408        0t0        UDP server.example.org:34199-
>server.example.org:88
saslauthd  7690                   root    8u     IPv4          954802146        0t0        UDP server.example.org:57263-
>server.example.org:88
saslauthd  7691                   root    8u     IPv4          954805307        0t0        UDP server.example.org:42824-
>server.example.org:88
saslauthd  7692                   root    8u     IPv4          954802113        0t0        UDP server.example.org:58793-
>server.example.org:88
saslauthd  7693                   root    8u     IPv4          954805418        0t0        UDP server.example.org:36439-
>server.example.org:88
saslauthd  7695                   root    8u     IPv4          954804353        0t0        UDP server.example.org:47413-
>server.example.org:88
krb5kdc   30313                   root   11u     IPv4          882110853        0t0        UDP *:88
krb5kdc   30313                   root   12u     IPv6          882110854        0t0        UDP *:88
krb5kdc   30313                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
krb5kdc   30313                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
krb5kdc   30314                   root   11u     IPv4          882110853        0t0        UDP *:88
krb5kdc   30314                   root   12u     IPv6          882110854        0t0        UDP *:88
krb5kdc   30314                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
krb5kdc   30314                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
krb5kdc   30315                   root   11u     IPv4          882110853        0t0        UDP *:88
krb5kdc   30315                   root   12u     IPv6          882110854        0t0        UDP *:88
krb5kdc   30315                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
krb5kdc   30315                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
krb5kdc   30316                   root   11u     IPv4          882110853        0t0        UDP *:88
krb5kdc   30316                   root   12u     IPv6          882110854        0t0        UDP *:88
krb5kdc   30316                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
krb5kdc   30316                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
krb5kdc   30317                   root   11u     IPv4          882110853        0t0        UDP *:88
krb5kdc   30317                   root   12u     IPv6          882110854        0t0        UDP *:88
krb5kdc   30317                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
krb5kdc   30317                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)

So the krb5kdc processes are listening already on *:88.

strace -p 30313 shows:

strace: Process 30313 attached
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
epoll_wait(4, ^Cstrace: Process 30313 detached
 <detached ...>

The same happens also to 30317.  So all the krb5kdc processes are trying to bind to :88, but they cannot, as they posses
already the port.

I have krb-1.16.3.

Restarting has helped.  What shall I do the next time this happens, so that the cause is resolved?

Regards
  Dilyan

_______________________________________________
krbdev mailing list             [hidden email]
https://mailman.mit.edu/mailman/listinfo/krbdev
Reply | Threaded
Open this post in threaded view
|

Re: Endless looping around socket *:88 in krb5kdc with result -1 EAGAIN (Resource temporarily unavailable)

Greg Hudson
On 5/5/19 7:46 AM, Дилян Палаузов wrote:
> The documentation of krb5kdc states:
>
>    The -n option specifies that the KDC does not put itself in the background and does not disassociate itself from the
> terminal.  In normal operation, you should always allow the KDC to place itself in the background.
>
> What is the problem of having the process running in the foreground?

There's no problem if you're running under systemd.  The documentation
was written (many years ago) assuming krb5kdc would be started from a
shell or init.d script, and you wouldn't want the shell process to
block.  I will update it.

> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
[repeats]
> The same happens also to 30317.  So all the krb5kdc processes are trying to bind to :88, but they cannot, as they posses
> already the port.

There's no bind() call in the repeating system calls; the loop here is
trying to read a packet from UDP listener, after being told by poll()
that the socket is readable.

Because there are multiple worker processes in this setup, this sequence
is expected to happen some of the time.  When a packet arrives, all of
the krb5kdc processes waiting in poll() are alerted that the socket is
readable.  One of them successfully reads the packet, while the others
get EAGAIN and go back into poll().

If all of the workers are doing this in a tight loop and none of them
are doing anything else, that's unexpected.  I don't know how that state
would arise.

> Restarting has helped.  What shall I do the next time this happens, so that the cause is resolved?

You could strace all of the worker processes simultaneously, with
timestamps (strace -t), to confirm what is going on.  I'm still not sure
I would be able to identify the cause, though.  This is the first report
of this problem that I can recall.
_______________________________________________
krbdev mailing list             [hidden email]
https://mailman.mit.edu/mailman/listinfo/krbdev
Reply | Threaded
Open this post in threaded view
|

Re: Endless looping around socket *:88 in krb5kdc with result -1 EAGAIN (Resource temporarily unavailable)

Дилян Палаузов
In reply to this post by Дилян Палаузов
Hello,

at the end I altered the SASL code to uppercase the domain, after extracting it from the user name and converting it
into realm, but before passing it to krb5kdc and this just accelerated the handling of krb5kdc.  Or is a coincidence…

So the question below is obsolete.


Regards
  Дилян

On Sun, 2019-05-05 at 11:46 +0000, Дилян Палаузов wrote:

> On my system krb5kdc got stuck.  I started it under systemd with:
>
> /usr/local/sbin/krb5kdc -r A -r B -n -w5
>
> The documentation of krb5kdc states:
>
>    The -n option specifies that the KDC does not put itself in the background and does not disassociate itself from the
> terminal.  In normal operation, you should always allow the KDC to place itself in the background.
>
> What is the problem of having the process running in the foreground?
>
> I have these processes:
>
> # ps -eF|grep krb5
> root     23199 20680  0  1209  2056   6 11:33 pts/1    00:00:00 grep --color=auto krb
> root     30309     1  0  3292  3212   5 Apr19 ?        00:00:00 /usr/local/sbin/krb5kdc -r A -r B -n -w5
> root     30313 30309  0  3652  3580   7 Apr19 ?        00:01:29 /usr/local/sbin/krb5kdc -r A -r B -n -w5
> root     30314 30309  0  3665  3572   7 Apr19 ?        00:01:30 /usr/local/sbin/krb5kdc -r A -r B -n -w5
> root     30315 30309  0  3670  3692   7 Apr19 ?        00:01:37 /usr/local/sbin/krb5kdc -r A -r B -n -w5
> root     30316 30309  0  3677  3684   7 Apr19 ?        00:01:45 /usr/local/sbin/krb5kdc -r A -r B -n -w5
> root     30317 30309  0  3691  3752   7 Apr19 ?        00:02:07 /usr/local/sbin/krb5kdc -r A -r B -n -w5
>
> So PID 30309 is the master process and PID 30313, 30314, 30315, 30316 and 30317 are serving.
>
> lsof -P|grep :88 shows:
>
> saslauthd  7681                   root    8u     IPv4          954798949        0t0        UDP server.example.org:50240-
> > server.example.org:88
> saslauthd  7682                   root    8u     IPv4          954800125        0t0        UDP server.example.org:43670-
> > server.example.org:88
> saslauthd  7683                   root    8u     IPv4          954800669        0t0        UDP server.example.org:56808-
> > server.example.org:88
> saslauthd  7684                   root    8u     IPv4          954798973        0t0        UDP server.example.org:42328-
> > server.example.org:88
> saslauthd  7686                   root    8u     IPv4          954804419        0t0        UDP server.example.org:34084-
> > server.example.org:88
> saslauthd  7687                   root    8u     IPv4          954803415        0t0        UDP server.example.org:50986-
> > server.example.org:88
> saslauthd  7688                   root    8u     IPv4          954805293        0t0        UDP server.example.org:37353-
> > server.example.org:88
> saslauthd  7689                   root    8u     IPv4          954803408        0t0        UDP server.example.org:34199-
> > server.example.org:88
> saslauthd  7690                   root    8u     IPv4          954802146        0t0        UDP server.example.org:57263-
> > server.example.org:88
> saslauthd  7691                   root    8u     IPv4          954805307        0t0        UDP server.example.org:42824-
> > server.example.org:88
> saslauthd  7692                   root    8u     IPv4          954802113        0t0        UDP server.example.org:58793-
> > server.example.org:88
> saslauthd  7693                   root    8u     IPv4          954805418        0t0        UDP server.example.org:36439-
> > server.example.org:88
> saslauthd  7695                   root    8u     IPv4          954804353        0t0        UDP server.example.org:47413-
> > server.example.org:88
> krb5kdc   30313                   root   11u     IPv4          882110853        0t0        UDP *:88
> krb5kdc   30313                   root   12u     IPv6          882110854        0t0        UDP *:88
> krb5kdc   30313                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
> krb5kdc   30313                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
> krb5kdc   30314                   root   11u     IPv4          882110853        0t0        UDP *:88
> krb5kdc   30314                   root   12u     IPv6          882110854        0t0        UDP *:88
> krb5kdc   30314                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
> krb5kdc   30314                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
> krb5kdc   30315                   root   11u     IPv4          882110853        0t0        UDP *:88
> krb5kdc   30315                   root   12u     IPv6          882110854        0t0        UDP *:88
> krb5kdc   30315                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
> krb5kdc   30315                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
> krb5kdc   30316                   root   11u     IPv4          882110853        0t0        UDP *:88
> krb5kdc   30316                   root   12u     IPv6          882110854        0t0        UDP *:88
> krb5kdc   30316                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
> krb5kdc   30316                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
> krb5kdc   30317                   root   11u     IPv4          882110853        0t0        UDP *:88
> krb5kdc   30317                   root   12u     IPv6          882110854        0t0        UDP *:88
> krb5kdc   30317                   root   13u     IPv4          882110857        0t0        TCP *:88 (LISTEN)
> krb5kdc   30317                   root   14u     IPv6          882110858        0t0        TCP *:88 (LISTEN)
>
> So the krb5kdc processes are listening already on *:88.
>
> strace -p 30313 shows:
>
> strace: Process 30313 attached
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, [{EPOLLIN, {u32=11, u64=11}}], 32, -1) = 1
> getsockname(11, {sa_family=AF_INET, sin_port=htons(88), sin_addr=inet_addr("0.0.0.0")}, [128->16]) = 0
> recvmsg(11, {msg_namelen=128}, 0)       = -1 EAGAIN (Resource temporarily unavailable)
> epoll_wait(4, ^Cstrace: Process 30313 detached
>  <detached ...>
>
> The same happens also to 30317.  So all the krb5kdc processes are trying to bind to :88, but they cannot, as they posses
> already the port.
>
> I have krb-1.16.3.
>
> Restarting has helped.  What shall I do the next time this happens, so that the cause is resolved?
>
> Regards
>   Dilyan

_______________________________________________
krbdev mailing list             [hidden email]
https://mailman.mit.edu/mailman/listinfo/krbdev