linux-nfs.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Sven Geggus <lists@fuchsschwanzdomain.de>
To: "J. Bruce Fields" <bfields@fieldses.org>
Cc: nfs@lists.sourceforge.net
Subject: Re: Kerberized NFS-Server Problem still present in 3.10.0-rc2
Date: Tue, 2 Jul 2013 10:05:30 +0200	[thread overview]
Message-ID: <20130702080530.GA17953@geggus.net> (raw)
In-Reply-To: <20130701205234.GF19945@fieldses.org>

J. Bruce Fields schrieb am Montag, den 01. Juli um 22:52 Uhr:

> It includes the contents of /etc/krb5.keytab, so I'm guessing so.

The server is a test-vm anyway.

> It'd be interesting to know exactly where nfsd decides to drop the
> rpc that uses this new context....  Turning on all the nfsd and rpc
> debugging *might* help there.  (rpcdebug -m rpc -s all; rpcdebug -m nfsd
> -s all).

 ~/ # rpcdebug -m rpc -s all
rpc        xprt call debug nfs auth bind sched trans svcsock svcdsp misc cache
 ~/ # rpcdebug -m nfsd -s all
nfsd       sock fh export svc proc fileop auth repcache xdr lockd

Here is what I get (Kernel is vanilla 3.10.0):

Jul  2 09:52:41 vnfsrv kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Jul  2 09:52:41 vnfsrv kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
Jul  2 09:52:41 vnfsrv kernel: NFSD: starting 90-second grace period (net ffffffff81556500)
Jul  2 09:54:11 vnfsrv kernel: NFSD: laundromat service - starting
Jul  2 09:54:11 vnfsrv kernel: NFSD: end of grace period
Jul  2 09:54:11 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul  2 09:55:42 vnfsrv kernel: NFSD: laundromat service - starting
Jul  2 09:55:42 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul  2 09:56:42 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff8800162147c0 TCP (listen) state change 1
Jul  2 09:56:42 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:56:42 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul  2 09:56:42 vnfsrv kernel: svc: svc_setup_socket ffff880016a2ed40
Jul  2 09:56:42 vnfsrv kernel: setting up TCP socket for reading
Jul  2 09:56:42 vnfsrv kernel: svc: svc_setup_socket created ffff880015259000 (inet ffff8800162147c0)
Jul  2 09:56:42 vnfsrv kernel: svc: transport ffff880015259000 served by daemon ffff8800167cc000
Jul  2 09:56:42 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff880015259000, inuse=3
Jul  2 09:56:42 vnfsrv kernel: svc: tcp_recv ffff880015259000 data 1 conn 0 close 0
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff8800152592a4, 0) = 4
Jul  2 09:56:42 vnfsrv kernel: svc: TCP record, 40 bytes
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff88001607c028, 4056) = 40
Jul  2 09:56:42 vnfsrv kernel: svc: TCP final record (40 bytes)
Jul  2 09:56:42 vnfsrv kernel: svc: got len=40
Jul  2 09:56:42 vnfsrv kernel: svc: svc_authenticate (0)
Jul  2 09:56:42 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul  2 09:56:42 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:56:42 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 09:56:42 vnfsrv kernel: svc: calling dispatcher
Jul  2 09:56:42 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul  2 09:56:42 vnfsrv kernel: nfsd_dispatch: vers 4 proc 0
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff880015259000 sendto([ffff8800165d4000 28... ], 28) = 28 (addr 10.1.7.30, port=740)
Jul  2 09:56:42 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul  2 09:56:42 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff8800167cc000
Jul  2 09:56:42 vnfsrv kernel: svc: socket ffff880015277500 TCP (listen) state change 1
Jul  2 09:56:42 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:56:42 vnfsrv kernel: \x014nfsd: connect from unprivileged port: 10.1.7.30, port=55093
Jul  2 09:56:42 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=55093
Jul  2 09:56:42 vnfsrv kernel: svc: svc_setup_socket ffff880016a10d00
Jul  2 09:56:43 vnfsrv kernel: setting up TCP socket for reading
Jul  2 09:56:43 vnfsrv kernel: svc: svc_setup_socket created ffff8800158ce000 (inet ffff880015277500)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 served by daemon ffff88001657a000
Jul  2 09:56:43 vnfsrv kernel: svc: server ffff88001657a000, pool 0, transport ffff8800158ce000, inuse=3
Jul  2 09:56:43 vnfsrv kernel: svc: tcp_recv ffff8800158ce000 data 1 conn 0 close 0
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff8800158ce000 recvfrom(ffff8800158ce2a4, 0) = 4
Jul  2 09:56:43 vnfsrv kernel: svc: TCP record, 1380 bytes
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff8800158ce000 recvfrom(ffff880016570564, 2716) = 1380
Jul  2 09:56:43 vnfsrv kernel: svc: TCP final record (1380 bytes)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul  2 09:56:43 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:56:43 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 09:56:43 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:56:43 vnfsrv kernel: svc: got len=1380
Jul  2 09:56:43 vnfsrv kernel: svc: svc_authenticate (6)
Jul  2 09:56:43 vnfsrv kernel: RPC:       svcauth_gss: argv->iov_len = 1352
Jul  2 09:56:43 vnfsrv kernel: RPC:       Want update, refage=120, age=0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       krb5_encrypt returns 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       gss_import_sec_context_kerberos: returning 0
Jul  2 09:56:43 vnfsrv kernel: RPC:       gss_get_mic_v2
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff8800158ce000 sendto([ffff880016571000 232... ], 232) = 232 (addr 10.1.7.30, port=55093)
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff880015277500 TCP data ready (svsk ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 served by daemon ffff880016576000
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff880015277500 TCP (connected) state change 8 (svsk ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 busy, not enqueued
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff880015277500 TCP data ready (svsk ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 busy, not enqueued
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff8800162147c0 TCP data ready (svsk ffff880015259000)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff880015259000 served by daemon ffff8800167cc000
Jul  2 09:56:43 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul  2 09:56:43 vnfsrv kernel: svc: svc_delete_xprt(ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff880015259000, inuse=2
Jul  2 09:56:43 vnfsrv kernel: svc: tcp_recv ffff880015259000 data 1 conn 0 close 0
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff8800152592a4, 0) = 4
Jul  2 09:56:43 vnfsrv kernel: svc: svc_sock_detach(ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 09:56:43 vnfsrv kernel: svc: transport ffff8800158ce000 busy, not enqueued
Jul  2 09:56:43 vnfsrv kernel: svc: svc_sock_free(ffff8800158ce000)
Jul  2 09:56:43 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul  2 09:56:43 vnfsrv kernel: svc: TCP record, 200 bytes
Jul  2 09:56:43 vnfsrv kernel: svc: socket ffff880015259000 recvfrom(ffff88001607c0c8, 3896) = 200
Jul  2 09:56:43 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul  2 09:56:43 vnfsrv kernel: svc: got len=200
Jul  2 09:56:43 vnfsrv kernel: svc: svc_authenticate (6)
Jul  2 09:56:43 vnfsrv kernel: RPC:       svcauth_gss: argv->iov_len = 172
Jul  2 09:56:43 vnfsrv kernel: RPC:       gss_verify_mic_v2
Jul  2 09:56:43 vnfsrv kernel: RPC:       gss_get_mic_v2
Jul  2 09:56:43 vnfsrv kernel: RPC:       Want update, refage=120, age=0
Jul  2 09:56:43 vnfsrv kernel: RPC:       Want update, refage=120, age=0
Jul  2 09:56:48 vnfsrv kernel: svc: svc_process dropit
Jul  2 09:56:48 vnfsrv kernel: svc: xprt ffff880015259000 dropped request
Jul  2 09:56:48 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:57:12 vnfsrv kernel: NFSD: laundromat service - starting
Jul  2 09:57:12 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul  2 09:57:42 vnfsrv kernel: RPC:       xs_close xprt ffff88001610b800
Jul  2 09:57:42 vnfsrv kernel: RPC:       disconnected transport ffff88001610b800
Jul  2 09:57:42 vnfsrv kernel: RPC:       wake_up_first(ffff88001610b978 "xprt_sending")
Jul  2 09:57:44 vnfsrv kernel: svc: socket ffff8800162147c0 TCP (connected) state change 8 (svsk ffff880015259000)
Jul  2 09:57:44 vnfsrv kernel: svc: transport ffff880015259000 served by daemon ffff8800167cc000
Jul  2 09:57:44 vnfsrv kernel: svc: socket ffff8800162147c0 TCP data ready (svsk ffff880015259000)
Jul  2 09:57:44 vnfsrv kernel: svc: transport ffff880015259000 busy, not enqueued
Jul  2 09:57:44 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul  2 09:57:44 vnfsrv kernel: svc: svc_delete_xprt(ffff880015259000)
Jul  2 09:57:44 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff880015259000)
Jul  2 09:57:44 vnfsrv kernel: svc: svc_sock_detach(ffff880015259000)
Jul  2 09:57:44 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:57:44 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul  2 09:57:44 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul  2 09:57:44 vnfsrv kernel: svc: socket ffff8800164ed540 TCP (listen) state change 1
Jul  2 09:57:44 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:57:44 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul  2 09:57:44 vnfsrv kernel: svc: svc_setup_socket ffff880016a2eac0
Jul  2 09:57:44 vnfsrv kernel: setting up TCP socket for reading
Jul  2 09:57:44 vnfsrv kernel: svc: svc_setup_socket created ffff88001669a000 (inet ffff8800164ed540)
Jul  2 09:57:44 vnfsrv kernel: svc: transport ffff88001669a000 served by daemon ffff8800167cc000
Jul  2 09:57:44 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff88001669a000, inuse=3
Jul  2 09:57:44 vnfsrv kernel: svc: tcp_recv ffff88001669a000 data 1 conn 0 close 0
Jul  2 09:57:44 vnfsrv kernel: svc: socket ffff88001669a000 recvfrom(ffff88001669a2a4, 0) = 4
Jul  2 09:57:44 vnfsrv kernel: svc: TCP record, 200 bytes
Jul  2 09:57:44 vnfsrv kernel: svc: socket ffff88001669a000 recvfrom(ffff88001607c0c8, 3896) = 200
Jul  2 09:57:44 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul  2 09:57:44 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul  2 09:57:44 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:57:44 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul  2 09:57:44 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 09:57:44 vnfsrv kernel: svc: got len=200
Jul  2 09:57:44 vnfsrv kernel: svc: svc_authenticate (6)
Jul  2 09:57:44 vnfsrv kernel: RPC:       svcauth_gss: argv->iov_len = 172
Jul  2 09:57:44 vnfsrv kernel: RPC:       gss_verify_mic_v2
Jul  2 09:57:44 vnfsrv kernel: RPC:       gss_get_mic_v2
Jul  2 09:57:44 vnfsrv kernel: RPC:       Want update, refage=120, age=61
Jul  2 09:57:49 vnfsrv kernel: svc: svc_process dropit
Jul  2 09:57:49 vnfsrv kernel: svc: xprt ffff88001669a000 dropped request
Jul  2 09:57:49 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:58:42 vnfsrv kernel: NFSD: laundromat service - starting
Jul  2 09:58:42 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul  2 09:59:45 vnfsrv kernel: svc: socket ffff8800164ed540 TCP (connected) state change 8 (svsk ffff88001669a000)
Jul  2 09:59:45 vnfsrv kernel: svc: transport ffff88001669a000 served by daemon ffff8800167cc000
Jul  2 09:59:45 vnfsrv kernel: svc: socket ffff8800164ed540 TCP data ready (svsk ffff88001669a000)
Jul  2 09:59:45 vnfsrv kernel: svc: transport ffff88001669a000 busy, not enqueued
Jul  2 09:59:45 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul  2 09:59:45 vnfsrv kernel: svc: svc_delete_xprt(ffff88001669a000)
Jul  2 09:59:45 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff88001669a000)
Jul  2 09:59:45 vnfsrv kernel: svc: svc_sock_detach(ffff88001669a000)
Jul  2 09:59:45 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:59:46 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul  2 09:59:46 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff8800167cc000
Jul  2 09:59:46 vnfsrv kernel: svc: socket ffff88001503f440 TCP (listen) state change 1
Jul  2 09:59:46 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:59:46 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul  2 09:59:46 vnfsrv kernel: svc: svc_setup_socket ffff880016accd40
Jul  2 09:59:46 vnfsrv kernel: setting up TCP socket for reading
Jul  2 09:59:46 vnfsrv kernel: svc: svc_setup_socket created ffff8800159f0000 (inet ffff88001503f440)
Jul  2 09:59:46 vnfsrv kernel: svc: transport ffff8800159f0000 served by daemon ffff880016576000
Jul  2 09:59:46 vnfsrv kernel: svc: server ffff880016576000, pool 0, transport ffff8800159f0000, inuse=3
Jul  2 09:59:46 vnfsrv kernel: svc: tcp_recv ffff8800159f0000 data 1 conn 0 close 0
Jul  2 09:59:46 vnfsrv kernel: svc: socket ffff8800159f0000 recvfrom(ffff8800159f02a4, 0) = 4
Jul  2 09:59:46 vnfsrv kernel: svc: TCP record, 200 bytes
Jul  2 09:59:46 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul  2 09:59:46 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 09:59:46 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul  2 09:59:46 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 09:59:46 vnfsrv kernel: svc: socket ffff8800159f0000 recvfrom(ffff8800166f80c8, 3896) = 200
Jul  2 09:59:46 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul  2 09:59:46 vnfsrv kernel: svc: got len=200
Jul  2 09:59:46 vnfsrv kernel: svc: svc_authenticate (6)
Jul  2 09:59:46 vnfsrv kernel: RPC:       svcauth_gss: argv->iov_len = 172
Jul  2 09:59:46 vnfsrv kernel: RPC:       gss_verify_mic_v2
Jul  2 09:59:46 vnfsrv kernel: RPC:       gss_get_mic_v2
Jul  2 09:59:46 vnfsrv kernel: RPC:       Want update, refage=120, age=0
Jul  2 09:59:51 vnfsrv kernel: svc: svc_process dropit
Jul  2 09:59:51 vnfsrv kernel: svc: xprt ffff8800159f0000 dropped request
Jul  2 09:59:51 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 10:00:12 vnfsrv kernel: NFSD: laundromat service - starting
Jul  2 10:00:12 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul  2 10:00:47 vnfsrv kernel: svc: socket ffff88001503f440 TCP (connected) state change 8 (svsk ffff8800159f0000)
Jul  2 10:00:47 vnfsrv kernel: svc: transport ffff8800159f0000 served by daemon ffff880016576000
Jul  2 10:00:47 vnfsrv kernel: svc: socket ffff88001503f440 TCP data ready (svsk ffff8800159f0000)
Jul  2 10:00:47 vnfsrv kernel: svc: transport ffff8800159f0000 busy, not enqueued
Jul  2 10:00:47 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul  2 10:00:47 vnfsrv kernel: svc: svc_delete_xprt(ffff8800159f0000)
Jul  2 10:00:47 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff8800159f0000)
Jul  2 10:00:47 vnfsrv kernel: svc: svc_sock_detach(ffff8800159f0000)
Jul  2 10:00:47 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 10:00:48 vnfsrv kernel: svc: socket ffff8800167aad40 TCP (listen) state change 10
Jul  2 10:00:48 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff880016576000
Jul  2 10:00:48 vnfsrv kernel: svc: socket ffff880015a44d80 TCP (listen) state change 1
Jul  2 10:00:48 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 10:00:48 vnfsrv kernel: nfsd: connect from 10.1.7.30, port=740
Jul  2 10:00:48 vnfsrv kernel: svc: svc_setup_socket ffff880016acc840
Jul  2 10:00:48 vnfsrv kernel: setting up TCP socket for reading
Jul  2 10:00:48 vnfsrv kernel: svc: svc_setup_socket created ffff8800152d7000 (inet ffff880015a44d80)
Jul  2 10:00:48 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff8800167cc000
Jul  2 10:00:48 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff8800152d7000, inuse=3
Jul  2 10:00:48 vnfsrv kernel: svc: tcp_recv ffff8800152d7000 data 1 conn 0 close 0
Jul  2 10:00:48 vnfsrv kernel: svc: socket ffff8800152d7000 recvfrom(ffff8800152d72a4, 0) = 4
Jul  2 10:00:48 vnfsrv kernel: svc: TCP record, 200 bytes
Jul  2 10:00:48 vnfsrv kernel: svc: socket ffff8800152d7000 recvfrom(ffff88001607c0c8, 3896) = 200
Jul  2 10:00:48 vnfsrv kernel: svc: TCP final record (200 bytes)
Jul  2 10:00:48 vnfsrv kernel: svc: got len=200
Jul  2 10:00:48 vnfsrv kernel: svc: svc_authenticate (6)
Jul  2 10:00:48 vnfsrv kernel: svc: transport ffff8800159c0000 served by daemon ffff88001657a000
Jul  2 10:00:48 vnfsrv kernel: svc: tcp_accept ffff8800159c0000 sock ffff880016a2e840
Jul  2 10:00:48 vnfsrv kernel: svc: server ffff88001657a000 waiting for data (to = 900000)
Jul  2 10:00:48 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 10:00:48 vnfsrv kernel: RPC:       svcauth_gss: argv->iov_len = 172
Jul  2 10:00:48 vnfsrv kernel: RPC:       gss_verify_mic_v2
Jul  2 10:00:48 vnfsrv kernel: RPC:       gss_get_mic_v2
Jul  2 10:00:48 vnfsrv kernel: RPC:       Want update, refage=120, age=62
Jul  2 10:00:53 vnfsrv kernel: svc: svc_process dropit
Jul  2 10:00:53 vnfsrv kernel: svc: xprt ffff8800152d7000 dropped request
Jul  2 10:00:53 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 10:01:42 vnfsrv kernel: NFSD: laundromat service - starting
Jul  2 10:01:42 vnfsrv kernel: NFSD: laundromat_main - sleeping for 90 seconds
Jul  2 10:02:00 vnfsrv kernel: revisit canceled
Jul  2 10:02:00 vnfsrv kernel: svc: svc_sock_free(ffff8800159f0000)
Jul  2 10:02:00 vnfsrv kernel: revisit queued
Jul  2 10:02:00 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff8800167cc000
Jul  2 10:02:00 vnfsrv kernel: svc: server ffff8800167cc000, pool 0, transport ffff8800152d7000, inuse=3
Jul  2 10:02:00 vnfsrv kernel: svc: got len=200
Jul  2 10:02:00 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff880016576000
Jul  2 10:02:00 vnfsrv kernel: svc: server ffff880016576000, pool 0, transport ffff8800152d7000, inuse=5
Jul  2 10:02:00 vnfsrv kernel: svc: tcp_recv ffff8800152d7000 data 0 conn 0 close 0
Jul  2 10:02:00 vnfsrv kernel: svc: socket ffff8800152d7000 recvfrom(ffff8800152d72a0, 4) = -11
Jul  2 10:02:00 vnfsrv kernel: RPC: TCP recv_record got -11
Jul  2 10:02:00 vnfsrv kernel: svc: svc_authenticate (6)
Jul  2 10:02:00 vnfsrv kernel: RPC:       svcauth_gss: argv->iov_len = 172
Jul  2 10:02:00 vnfsrv kernel: RPC:       gss_get_mic_v2
Jul  2 10:02:00 vnfsrv kernel: RPC: TCP recvfrom got EAGAIN
Jul  2 10:02:00 vnfsrv kernel: svc: got len=0
Jul  2 10:02:00 vnfsrv kernel: svc: server ffff880016576000 waiting for data (to = 900000)
Jul  2 10:02:00 vnfsrv kernel: RPC:       Want update, refage=120, age=0
Jul  2 10:02:05 vnfsrv kernel: svc: svc_process dropit
Jul  2 10:02:05 vnfsrv kernel: svc: xprt ffff8800152d7000 dropped request
Jul  2 10:02:05 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 10:02:23 vnfsrv kernel: svc: socket ffff880015a44d80 TCP (connected) state change 8 (svsk ffff8800152d7000)
Jul  2 10:02:23 vnfsrv kernel: svc: transport ffff8800152d7000 served by daemon ffff8800167cc000
Jul  2 10:02:23 vnfsrv kernel: svc: socket ffff880015a44d80 TCP data ready (svsk ffff8800152d7000)
Jul  2 10:02:23 vnfsrv kernel: svc: transport ffff8800152d7000 busy, not enqueued
Jul  2 10:02:23 vnfsrv kernel: svc_recv: found XPT_CLOSE
Jul  2 10:02:23 vnfsrv kernel: svc: svc_delete_xprt(ffff8800152d7000)
Jul  2 10:02:23 vnfsrv kernel: svc: svc_tcp_sock_detach(ffff8800152d7000)
Jul  2 10:02:23 vnfsrv kernel: svc: svc_sock_detach(ffff8800152d7000)
Jul  2 10:02:23 vnfsrv kernel: svc: server ffff8800167cc000 waiting for data (to = 900000)
Jul  2 10:02:43 vnfsrv kernel: svc_age_temp_xprts

Regards

Sven

-- 
"Das ist halt der Unterschied: Unix ist ein Betriebssystem mit Tradition,
 die anderen sind einfach von sich aus unlogisch."
                          (Anselm Lingnau in de.comp.os.unix.discussion)
/me ist giggls@ircnet, http://sven.gegg.us/ im WWW

  parent reply	other threads:[~2013-07-02  8:13 UTC|newest]

Thread overview: 19+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2013-06-19 13:47 Kerberized NFS-Server Problem still present in 3.10.0-rc2 Sven Geggus
2013-06-19 21:34 ` J. Bruce Fields
2013-06-20  8:03   ` Sven Geggus
2013-06-20 12:09     ` Sven Geggus
2013-06-20 14:49     ` J. Bruce Fields
2013-06-20 14:52       ` J. Bruce Fields
2013-06-21  8:32         ` Sven Geggus
2013-06-24 21:54           ` J. Bruce Fields
2013-06-25  9:46             ` Sven Geggus
2013-07-01 12:09               ` Sven Geggus
     [not found]               ` <20130701205234.GF19945@fieldses.org>
2013-07-02  8:05                 ` Sven Geggus [this message]
     [not found]                   ` <20130705181859.GA8288@fieldses.org>
     [not found]                     ` <20130705203435.GE8288@fieldses.org>
2013-07-08  8:08                       ` Sven Geggus
2013-07-08 13:35                         ` J. Bruce Fields
2013-07-08 15:54                           ` Sven Geggus
2013-07-08 19:41                             ` J. Bruce Fields
2013-07-09 16:03                               ` Sven Geggus
2013-07-09 16:57                         ` J. Bruce Fields
2013-07-09 17:23                           ` Chuck Lever
2013-07-10  7:55                           ` Sven Geggus

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20130702080530.GA17953@geggus.net \
    --to=lists@fuchsschwanzdomain.de \
    --cc=bfields@fieldses.org \
    --cc=nfs@lists.sourceforge.net \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).