cannot mount nfsv4/krb5 with krb51.7, 1.8 and 1.8.1

Di Pe dipeit at gmail.com
Sat Apr 17 03:51:09 EDT 2010


Hi,

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 at MYDOMAIN.ORG'
Success getting keytab entry for 'nfs/phsgrid-03.mydomain.org at MYDOMAIN.ORG'
Successfully obtained machine credentials for principal
'nfs/phsgrid-03.mydomain.org at MYDOMAIN.ORG' 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 at COMPUTRON.MYDOMAIN.ORG
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 at MYDOMAIN.ORG'
Success getting keytab entry for 'nfs/panther5.mydomain.org at MYDOMAIN.ORG'
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 at computron.mydomain.org
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 at MYDOMAIN.ORG (DES
cbc mode with CRC-32)


Thanks for your help
-------------- next part --------------
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


More information about the Kerberos mailing list