Hi,
this looks like an issue with kerberos, but not 100% sure:
##############
I have a working configuration for Kerberized NFSv4 using Active
Directory 2003 functional level using
Kernel 2.6.27 with krb5 1.6.3 and gssd 1.1.3. openSUSE 11.1 When I
switch to openSUSE 11.2 (Kernel 2.6.31, krb5 1.70, gssd 1.1.3)
rpc.gssd -fvvvvv shows this error message (Failed to create machine
krb5 context) and gives me more errros like "gss_create_upcall for uid
0 result -13" when I turn on rpc/nfs debugging using 'echo "65535" >
/proc/sys/sunrpc/rpc[nfs]_debug'
handling krb5 upcall
Full hostname for 'COMPUTRON.MYDOMAIN.ORG' is 'computron.mydomain.org'
Full hostname for 'phsgrid-03.fhcrc.org' is 'phsgrid-03.mydomain.org'
Key table entry not found while getting keytab entry for
'root/phsgrid-03.mydomain.org@xxxxxxxxxxxx'
Success getting keytab entry for 'nfs/phsgrid-03.mydomain.org@xxxxxxxxxxxx'
Successfully obtained machine credentials for principal
'nfs/phsgrid-03.mydomain.org@xxxxxxxxxxxx' stored in ccache
'FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG'
INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG' are
good until 1271522236
using FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG as credentials cache for
machine creds
using environment variable to select krb5 ccache
FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG
creating context using fsuid 0 (save_uid 0)
creating tcp client for server COMPUTRON.MYDOMAIN.ORG
DEBUG: port already set to 2049
creating context with server nfs@xxxxxxxxxxxxxxxxxxxxxx
WARNING: Failed to create krb5 context for user with uid 0 for server
COMPUTRON.MYDOMAIN.ORG
WARNING: Failed to create machine krb5 context with credentials cache
FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG for server
COMPUTRON.MYDOMAIN.ORG
WARNING: Failed to create machine krb5 context with any credentials
cache for server COMPUTRON.MYDOMAIN.ORG
doing error downcall
now when replace krb5-1.7 with krb5-1.6.3 on openSUSE 11.2 everything
works again:
handling krb5 upcall
Full hostname for 'computron.mydomain.org' is 'computron.mydomain.org'
Full hostname for 'panther5.mydomain.org' is 'panther5.mydomain.org'
Key table entry not found while getting keytab entry for
'root/panther5.mydomain.org@xxxxxxxxxxxx'
Success getting keytab entry for 'nfs/panther5.mydomain.org@xxxxxxxxxxxx'
INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG' are
good until 1271518766
INFO: Credentials in CC 'FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG' are
good until 1271518766
using FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG as credentials cache for
machine creds
using environment variable to select krb5 ccache
FILE:/tmp/krb5cc_machine_MYDOMAIN.ORG
creating context using fsuid 0 (save_uid 0)
creating tcp client for server computron.mydomain.org
creating context with server nfs@xxxxxxxxxxxxxxxxxxxxxx
DEBUG: serialize_krb5_ctx: lucid version!
prepare_krb5_rfc1964_buffer: serializing keys with enctype 4 and length 8
doing downcall
going to openSUSE11.3 (Kernel 2.6.34-rc3, gssd 1.2.1, krb5 1.8) does
not help either. executing
mount -t nfs4 -o rsize=65536,wsize=65536,sec=krb5 computron:/tmp_iscsi tmp_iscsi
gives me the very some error message
after that I tried to install the rpm package of krb5 1.8.1 and also
1.8.1 straight from source. I am always getting the same error message
"Failed to create krb5 context"
> cat /etc/krb5.conf
[libdefaults]
default_realm = FHCRC.ORG
clockskew = 300
allow_weak_crypto = true
default_tkt_enctypes = des-cbc-crc
default_tgs_enctypes = des-cbc-crc
#default_tkt_enctypes = des-cbc-md5
#default_tgs_enctypes = des-cbc-md5
#default_tkt_enctypes = rc4-hmac
#default_tgs_enctypes = rc4-hmac
#kdc_req_checksum_type = -138
#ap_req_checksum_type = -138
#safe_checksum_type = -138
#ccache_type = 3
#pkinit_eku_checking = kpServerAuth
>cat idmapd.conf
[General]
Verbosity = 0
Pipefs-Directory = /var/lib/nfs/rpc_pipefs
Domain = mydomain.org
Local-Realm = MYDOMAIN.ORG
> klist -k -e -t
Keytab name: WRFILE:/etc/krb5.keytab
KVNO Timestamp Principal
---- ----------------- --------------------------------------------------------
3 12/31/69 16:00:00 nfs/phsgrid-03.mydomain.org@xxxxxxxxxxxx (DES
cbc mode with CRC-32)
Thanks for your help
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124526] NFS: nfs mount opts='rsize=65536,wsize=65536,sec=krb5,addr=10.10.170.200,clientaddr=10.10.168.103'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124531] NFS: parsing nfs mount option 'rsize=65536'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124536] NFS: parsing nfs mount option 'wsize=65536'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124540] NFS: parsing nfs mount option 'sec=krb5'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124544] NFS: parsing sec=krb5 option
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124546] NFS: parsing nfs mount option 'addr=10.10.170.200'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124551] NFS: parsing nfs mount option 'clientaddr=10.10.168.103'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124556] NFS: MNTPATH: '/tmp_iscsi'
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124557] --> nfs4_try_mount()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124563] --> nfs4_create_server()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124572] --> nfs4_init_server()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124574] --> nfs4_set_client()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124576] --> nfs_get_client(computron,v4)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124579] RPC: looking up machine cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124584] NFS: get client cookie (0xf68a9c00/0xf6a6c634)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124586] --> nfs_get_client() = f68a9c00 [new]
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124592] RPC: set up xprt to 10.10.170.200 (port 2049) via tcp
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124595] RPC: created transport f5c95800 with 16 slots
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124597] RPC: creating nfs client for computron (xprt f5c95800)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124620] RPC: creating GSS authenticator for client f6aa0180
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124632] RPC: 0 holding NULL cred fa84a280
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124634] RPC: new task initialized, procpid 14964
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124636] RPC: allocated task f6534ec0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124638] RPC: 208 __rpc_execute flags=0x680
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124641] RPC: 208 call_start nfs4 proc NULL (sync)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124643] RPC: 208 call_reserve (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124645] RPC: 208 reserved req f5c87000 xid fc8c4e6c
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124647] RPC: 208 call_reserveresult (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124649] RPC: 208 call_allocate (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124656] RPC: 208 allocated buffer of size 92 at f71c4800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124658] RPC: 208 call_bind (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124660] RPC: 208 call_connect xprt f5c95800 is not connected
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124662] RPC: 208 xprt_connect xprt f5c95800 is not connected
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124665] RPC: 208 sleep_on(queue "xprt_pending" time 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124667] RPC: 208 added to queue f5c959f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124669] RPC: 208 setting alarm for 60000 ms
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124671] RPC: xs_connect scheduled xprt f5c95800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124675] RPC: 208 sync task going to sleep
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124840] RPC: rpc_release_client(f6aa0180)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124896] RPC: xs_bind4 0.0.0.0:728: ok (0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124898] RPC: worker connecting xprt f5c95800 via tcp to 10.10.170.200 (port 2049)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.124909] RPC: f5c95800 connect status 115 connected 0 sock state 2
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125434] RPC: xs_tcp_state_change client f5c95800...
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125436] RPC: state 1 conn 0 dead 0 zapped 1
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125439] RPC: 208 __rpc_wake_up_task (now 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125441] RPC: 208 disabling timer
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125443] RPC: 208 removed from queue f5c959f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125447] RPC: __rpc_wake_up_task done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125457] RPC: 208 sync task resuming
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125459] RPC: 208 xprt_connect_status: retrying
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125461] RPC: 208 call_connect_status (status -11)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125463] RPC: 208 call_transmit (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125465] RPC: 208 xprt_prepare_transmit
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125467] RPC: 208 rpc_xdr_encode (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125469] RPC: 208 marshaling NULL cred fa84a280
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125471] RPC: 208 using AUTH_NULL cred fa84a280 to wrap rpc data
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125473] RPC: 208 xprt_transmit(44)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125481] RPC: xs_tcp_send_request(44) = 44
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125482] RPC: 208 xmit complete
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125485] RPC: 208 sleep_on(queue "xprt_pending" time 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125487] RPC: 208 added to queue f5c959f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125489] RPC: 208 setting alarm for 60000 ms
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125491] RPC: wake_up_next(f5c95984 "xprt_resend")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125493] RPC: wake_up_next(f5c95914 "xprt_sending")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.125495] RPC: 208 sync task going to sleep
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126719] RPC: xs_tcp_data_ready...
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126722] RPC: xs_tcp_data_recv started
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126725] RPC: reading TCP record fragment of length 24
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126727] RPC: reading XID (4 bytes)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126729] RPC: reading request with XID fc8c4e6c
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126731] RPC: reading CALL/REPLY flag (4 bytes)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126733] RPC: reading reply for CALL/REPLY flag 01000000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126735] RPC: read reply XID fc8c4e6c
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126737] RPC: XID fc8c4e6c read 16 bytes
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126739] RPC: xprt = f5c95800, tcp_copied = 24, tcp_offset = 24, tcp_reclen = 24
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126742] RPC: 208 xid fc8c4e6c complete (24 bytes received)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126744] RPC: 208 __rpc_wake_up_task (now 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126745] RPC: 208 disabling timer
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126748] RPC: 208 removed from queue f5c959f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126751] RPC: __rpc_wake_up_task done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126752] RPC: xs_tcp_data_recv done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126761] RPC: 208 sync task resuming
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126763] RPC: 208 call_status (status 24)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126765] RPC: 208 call_decode (status 24)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126767] RPC: 208 validating NULL cred fa84a280
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126769] RPC: 208 using AUTH_NULL cred fa84a280 to unwrap rpc data
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126771] RPC: 208 call_decode result 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126773] RPC: 208 return 0, status 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126775] RPC: 208 release task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126778] RPC: freeing buffer of size 92 at f71c4800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126780] RPC: 208 release request f5c87000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126782] RPC: wake_up_next(f5c95a64 "xprt_backlog")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126784] RPC: 208 releasing NULL cred fa84a280
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126785] RPC: rpc_release_client(f6aa0180)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126787] RPC: 208 freeing task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126814] svc: initialising pool 0 for NFSv4 callback
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126817] RPC: unregistering [1073741824, 4, ''] with local rpcbind
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126819] RPC: 0 looking up UNIX cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126821] RPC: looking up UNIX cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126823] RPC: new task initialized, procpid 14964
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126825] RPC: allocated task f6534ec0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126827] RPC: 209 __rpc_execute flags=0x680
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126829] RPC: 209 call_start rpcbind4 proc UNSET (sync)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126831] RPC: 209 call_reserve (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126834] RPC: 209 reserved req f6590000 xid f032e0da
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126836] RPC: 209 call_reserveresult (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126837] RPC: 209 call_allocate (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126840] RPC: 209 allocated buffer of size 484 at f71c4800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126842] RPC: 209 call_bind (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126843] RPC: 209 call_connect xprt f5d22000 is not connected
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126845] RPC: 209 xprt_connect xprt f5d22000 is not connected
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126848] RPC: 209 sleep_on(queue "xprt_pending" time 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126850] RPC: 209 added to queue f5d221f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126852] RPC: 209 setting alarm for 60000 ms
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126854] RPC: xs_connect scheduled xprt f5d22000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126858] RPC: 209 sync task going to sleep
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126868] RPC: xs_bind4 0.0.0.0:760: ok (0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126871] RPC: worker connecting xprt f5d22000 via tcp to 127.0.0.1 (port 111)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126896] RPC: xs_tcp_state_change client f5d22000...
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126899] RPC: state 1 conn 0 dead 0 zapped 1
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126901] RPC: 209 __rpc_wake_up_task (now 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126903] RPC: 209 disabling timer
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126905] RPC: 209 removed from queue f5d221f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126908] RPC: __rpc_wake_up_task done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.126921] RPC: f5d22000 connect status 115 connected 1 sock state 1
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127007] RPC: 209 sync task resuming
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127009] RPC: 209 xprt_connect_status: retrying
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127012] RPC: 209 call_connect_status (status -11)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127014] RPC: 209 call_transmit (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127015] RPC: 209 xprt_prepare_transmit
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127017] RPC: 209 rpc_xdr_encode (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127019] RPC: 209 marshaling UNIX cred f67efcc0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127022] RPC: 209 using AUTH_UNIX cred f67efcc0 to wrap rpc data
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127025] RPC: 209 encoding RPCB_UNSET call (1073741824, 4, '', '')
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127027] RPC: 209 xprt_transmit(104)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127042] RPC: xs_tcp_send_request(104) = 104
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127044] RPC: 209 xmit complete
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127046] RPC: 209 sleep_on(queue "xprt_pending" time 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127048] RPC: 209 added to queue f5d221f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127050] RPC: 209 setting alarm for 60000 ms
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127052] RPC: wake_up_next(f5d22184 "xprt_resend")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127054] RPC: wake_up_next(f5d22114 "xprt_sending")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127056] RPC: 209 sync task going to sleep
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127198] RPC: xs_tcp_data_ready...
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127200] RPC: xs_tcp_data_recv started
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127203] RPC: reading TCP record fragment of length 28
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127205] RPC: reading XID (4 bytes)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127207] RPC: reading request with XID f032e0da
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127208] RPC: reading CALL/REPLY flag (4 bytes)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127210] RPC: reading reply for CALL/REPLY flag 01000000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127212] RPC: read reply XID f032e0da
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127214] RPC: XID f032e0da read 20 bytes
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127217] RPC: xprt = f5d22000, tcp_copied = 28, tcp_offset = 28, tcp_reclen = 28
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127219] RPC: 209 xid f032e0da complete (28 bytes received)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127221] RPC: 209 __rpc_wake_up_task (now 70347281)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127223] RPC: 209 disabling timer
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127225] RPC: 209 removed from queue f5d221f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127228] RPC: __rpc_wake_up_task done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127230] RPC: xs_tcp_data_recv done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127243] RPC: 209 sync task resuming
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127245] RPC: 209 call_status (status 28)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127247] RPC: 209 call_decode (status 28)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127249] RPC: 209 validating UNIX cred f67efcc0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127251] RPC: 209 using AUTH_UNIX cred f67efcc0 to unwrap rpc data
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127254] RPC: 209 RPCB_UNSET call succeeded
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127255] RPC: 209 call_decode result 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127257] RPC: 209 return 0, status 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127259] RPC: 209 release task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127261] RPC: freeing buffer of size 484 at f71c4800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127263] RPC: 209 release request f6590000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127265] RPC: wake_up_next(f5d22264 "xprt_backlog")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127267] RPC: 209 releasing UNIX cred f67efcc0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127269] RPC: rpc_release_client(f6aa0780)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127271] RPC: 209 freeing task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127273] svc: __svc_unregister(NFSv4 callbackv4), error 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127275] svc: creating transport tcp[0]
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127279] svc: svc_create_socket(NFSv4 callback, 6, 0.0.0.0, port=0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127289] svc: svc_setup_socket f3d09900
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127291] setting up TCP socket for listening
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127293] svc: svc_setup_socket created f68a9e00 (inet f6b74080)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127295] NFS: Callback listener port = 46833 (af 2)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127297] svc: creating transport tcp[0]
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127300] svc: svc_create_socket(NFSv4 callback, 6, 0000:0000:0000:0000:0000:0000:0000:0000, port=0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127311] svc: svc_setup_socket f3d09c80
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127313] setting up TCP socket for listening
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127314] svc: svc_setup_socket created f68a9200 (inet f6bbb580)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127317] NFS: Callback listener port = 38370 (af 10)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127341] svc: svc_destroy(NFSv4 callback, 2)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127343] svc: server f5cd4000 waiting for data (to = 2147483647)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127346] <-- nfs4_set_client() = 0 [new f68a9c00]
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127361] <-- nfs4_init_server() = 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127363] --> nfs4_path_walk(,,/)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127365] RPC: 0 looking up RPCSEC_GSS cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127367] RPC: looking up RPCSEC_GSS cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127369] RPC: gss_create_cred for uid 0, flavor 390003
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127372] RPC: gss_upcall for uid 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.127374] RPC: gss_find_upcall found nothing
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163612] RPC: gss_find_upcall found msg f68aca00
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163615] RPC: gss_fill_context returning 13
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163619] RPC: gss_pipe_downcall returning 16
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163623] RPC: gss_create_upcall for uid 0 result -13
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163626] RPC: new task initialized, procpid 14964
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163628] RPC: allocated task f6534ec0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163630] RPC: rpc_release_client(f688b1c0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163632] RPC: 0 freeing task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163635] nfs4_get_root: getroot error = 13
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163637] --> nfs_free_server()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163639] RPC: shutting down nfs client for computron
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163640] RPC: rpc_release_client(f688b1c0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163642] RPC: destroying nfs client for computron
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163657] RPC: rpc_release_client(f6aa0180)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163660] --> nfs_put_client({1})
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163662] --> nfs_free_client(4)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163710] svc: server f5cd4000, no data yet
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163722] svc: svc_destroy(NFSv4 callback, 1)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163724] svc: svc_delete_xprt(f68a9200)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163726] svc: svc_tcp_sock_detach(f68a9200)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163727] svc: svc_sock_detach(f68a9200)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163729] svc: svc_sock_free(f68a9200)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163736] svc: svc_delete_xprt(f68a9e00)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163737] svc: svc_tcp_sock_detach(f68a9e00)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163739] svc: svc_sock_detach(f68a9e00)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163740] svc: svc_sock_free(f68a9e00)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163745] RPC: unregistering [1073741824, 4, ''] with local rpcbind
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163747] RPC: 0 looking up UNIX cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163749] RPC: looking up UNIX cred
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163751] RPC: new task initialized, procpid 14964
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163753] RPC: allocated task f6534ec0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163755] RPC: 210 __rpc_execute flags=0x680
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163757] RPC: 210 call_start rpcbind4 proc UNSET (sync)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163759] RPC: 210 call_reserve (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163761] RPC: 210 reserved req f6590000 xid f132e0da
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163763] RPC: 210 call_reserveresult (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163765] RPC: 210 call_allocate (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163768] RPC: 210 allocated buffer of size 484 at f71c4800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163769] RPC: 210 call_bind (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163771] RPC: 210 call_connect xprt f5d22000 is connected
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163773] RPC: 210 call_transmit (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163775] RPC: 210 xprt_prepare_transmit
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163777] RPC: 210 rpc_xdr_encode (status 0)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163779] RPC: 210 marshaling UNIX cred f67efcc0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163781] RPC: 210 using AUTH_UNIX cred f67efcc0 to wrap rpc data
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163784] RPC: 210 encoding RPCB_UNSET call (1073741824, 4, '', '')
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163786] RPC: 210 xprt_transmit(104)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163798] RPC: xs_tcp_send_request(104) = 104
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163800] RPC: 210 xmit complete
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163802] RPC: 210 sleep_on(queue "xprt_pending" time 70347290)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163804] RPC: 210 added to queue f5d221f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163806] RPC: 210 setting alarm for 60000 ms
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163809] RPC: wake_up_next(f5d22184 "xprt_resend")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163811] RPC: wake_up_next(f5d22114 "xprt_sending")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163813] RPC: 210 sync task going to sleep
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163954] RPC: xs_tcp_data_ready...
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163956] RPC: xs_tcp_data_recv started
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163958] RPC: reading TCP record fragment of length 28
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163960] RPC: reading XID (4 bytes)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163962] RPC: reading reply for XID f132e0da
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163964] RPC: reading CALL/REPLY flag (4 bytes)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163966] RPC: reading reply for CALL/REPLY flag 01000000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163968] RPC: read reply XID f132e0da
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163970] RPC: XID f132e0da read 20 bytes
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163973] RPC: xprt = f5d22000, tcp_copied = 28, tcp_offset = 28, tcp_reclen = 28
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163975] RPC: 210 xid f132e0da complete (28 bytes received)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163977] RPC: 210 __rpc_wake_up_task (now 70347290)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163979] RPC: 210 disabling timer
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163981] RPC: 210 removed from queue f5d221f4 "xprt_pending"
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163985] RPC: __rpc_wake_up_task done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163986] RPC: xs_tcp_data_recv done
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163996] RPC: 210 sync task resuming
Apr 16 23:37:16 phsgrid-03 kernel: [281689.163998] RPC: 210 call_status (status 28)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164000] RPC: 210 call_decode (status 28)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164002] RPC: 210 validating UNIX cred f67efcc0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164005] RPC: 210 using AUTH_UNIX cred f67efcc0 to unwrap rpc data
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164007] RPC: 210 RPCB_UNSET call succeeded
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164009] RPC: 210 call_decode result 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164011] RPC: 210 return 0, status 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164012] RPC: 210 release task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164015] RPC: freeing buffer of size 484 at f71c4800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164017] RPC: 210 release request f6590000
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164019] RPC: wake_up_next(f5d22264 "xprt_backlog")
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164022] RPC: 210 releasing UNIX cred f67efcc0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164024] RPC: rpc_release_client(f6aa0780)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164026] RPC: 210 freeing task
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164029] svc: __svc_unregister(NFSv4 callbackv4), error 0
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164038] NFS: releasing client cookie (0xf68a9c00/0xf6a6c634)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164041] RPC: shutting down nfs client for computron
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164043] RPC: rpc_release_client(f6aa0180)
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164046] RPC: destroying GSS authenticator f68a5d84 flavor 390003
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164055] RPC: destroying nfs client for computron
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164064] RPC: destroying transport f5c95800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164067] RPC: xs_destroy xprt f5c95800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164069] RPC: xs_close xprt f5c95800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164077] RPC: disconnected transport f5c95800
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164080] <-- nfs_free_client()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164086] <-- nfs_free_server()
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164088] <-- nfs4_create_server() = error -13
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164092] <-- nfs4_try_mount() = -13 [error]
Apr 16 23:37:16 phsgrid-03 kernel: [281689.164094] <-- nfs4_get_sb() = -13 [error]
Apr 16 23:37:16 phsgrid-03 kernel: [281689.168260] RPC: gss_free_cred f6389f40
Apr 16 23:37:16 phsgrid-03 kernel: [281689.172007] RPC: gss_free_ctx
