[lustre-discuss] SSK key refresh issue
Hans Henrik Happe
happe at nbi.dk
Wed Jun 3 14:35:02 PDT 2020
We only have one MGS with two filesystems. It evolved into to two due to
some reconfiguration and the end game is to remove one. Anyway, one of
the modifications to the new one was to have daily key refresh. Either
that made the refresh issue more likely or having two filesystems is not
a good idea. It seemed to work with two so we went on and started to
rsync some data over. Then we hit the refresh issue. For now I'm just
asking if multiple filesystems could cause issues.
Anyway, I'm setting up a debug system to test if I can reproduce it with
a single fs. Then I'll get back with more info about the actual error.
I've attached some client output from the failing system. This was on a
nodemap with a 120s expire key, for fast testing. It seems that there
need to be I/O during the refresh to hit this.
A bit more info about the setup. All except mgs is configured for ski
messaging. mdt2ost is using the default nodemap.
Cheers,
Hans Henrik
On 03.06.2020 18.01, Sebastien Buisson wrote:
> Hi,
>
> Do you use one shared MGS for all your file systems, or does each file system have its own MGS? In the latter case, are the MGSes running on the same node?
>
> You are mentioning a key refresh issue, so I am wondering if you see this issue with multiple file systems only, or if it occurs when you have just one file system setup?
>
> Cheers,
> Sebastien.
>
>> Le 3 juin 2020 à 15:07, Hans Henrik Happe <happe at nbi.dk> a écrit :
>>
>> Hi,
>>
>> I'm trying to hunt down an issue where SSK is failing key refresh on
>> 2.12.4. Mounting the filesystem works, but active sessions dies at refresh.
>>
>> First I would like to get a few things cleared.
>>
>> Is multiple Lustre filesystems on the same servers supported with SSK?
>>
>> If so, is it supported to use the same nodemap on each filesystem?
>> Obviously, with different keys for each fs.
>>
>> A mount from an ssh to the root account will create this keyring on
>> CentOS 7:
>>
>> # keyctl show
>> Session Keyring
>> 669565440 --alswrv 0 0 keyring: _ses
>> 458158660 --alswrv 0 65534 \_ keyring: _uid.0
>> 129939379 --alswrv 0 0 \_ user: lustre:erda
>>
>> 65534 usually is nfsnobody but is does not exist on the system. Would
>> this be an issue? Even if nfsnobody existed?
>>
>> A mount through sudo will create this keyring on CentOS 7:
>>
>> # keyctl show
>> Session Keyring
>> 381836048 --alswrv 0 65534 keyring: _uid_ses.0
>> 423400032 --alswrv 0 65534 \_ keyring: _uid.0
>> 934942793 --alswrv 0 0 \_ user: lustre:erda
>>
>> Again is this a problem?
>>
>>
>> Cheers,
>> Hans Henrik
>> _______________________________________________
>> lustre-discuss mailing list
>> lustre-discuss at lists.lustre.org
>> http://lists.lustre.org/listinfo.cgi/lustre-discuss-lustre.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.lustre.org/pipermail/lustre-discuss-lustre.org/attachments/20200603/47e4cdb3/attachment-0001.html>
-------------- next part --------------
Jun 2 08:49:55 sci-mds01 kernel: Lustre: Lustre: Build Version: 2.12.4
Jun 2 08:49:55 sci-mds01 kernel: LNet: Added LNI 172.25.10.51 at tcp [8/256/0/180]
Jun 2 08:49:55 sci-mds01 kernel: LNet: Accept secure, port 988
Jun 2 08:49:56 sci-mds01 kernel: LNetError: 47936:0:(peer.c:3451:lnet_peer_ni_add_to_recoveryq_locked()) lpni 172.25.10.110 at tcp added to recovery queue. Health = 900
Jun 2 08:49:59 sci-mds01 kernel: Lustre: 48016:0:(gss_svc_upcall.c:1216:gss_init_svc_upcall()) Init channel is not opened by lsvcgssd, following request might be dropped until lsvcgssd is active
Jun 2 08:49:59 sci-mds01 kernel: Key type lgssc registered
Jun 2 08:49:59 sci-mds01 kernel: Lustre: 48022:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) client refreshed ctx ffff9db846289b00 idx 0xe4574184e6adcf6d (0->science-MDT0000_UUID), expiry 1591080709(+110s)
Jun 2 08:49:59 sci-mds01 kernel: Lustre: 48022:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) create reverse svc ctx ffff9de627265a40 to science-MDT0000_UUID: idx 0x9bf0d0270b0486e
Jun 2 08:50:00 sci-mds01 kernel: Lustre: Mounted science-client
Jun 2 08:50:00 sci-mds01 kernel: Lustre: 48029:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) client refreshed ctx ffff9db84628b600 idx 0x441bc9ec5b94197f (0->science-OST1101_UUID), expiry 1591080710(+110s)
Jun 2 08:50:00 sci-mds01 kernel: Lustre: 48029:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) create reverse svc ctx ffff9dc0f77f3440 to science-OST1101_UUID: idx 0x9bf0d0270b04870
Jun 2 08:50:00 sci-mds01 kernel: Lustre: 48029:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) Skipped 1 previous similar message
Jun 2 08:50:01 sci-mds01 systemd: Started Session 5540 of user root.
Jun 2 08:51:50 sci-mds01 kernel: Lustre: 48111:0:(sec_gss.c:315:cli_ctx_expire()) ctx ffff9db846288300(0->science-OST1103_UUID) get expired: 1591080710(+0s)
Jun 2 08:51:50 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:51:50 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9de6b17b0000: fail to get context
Jun 2 08:51:50 sci-mds01 kernel: LustreError: 48109:0:(sec.c:786:sptlrpc_req_refresh_ctx()) req ffff9de6b17b0000: failed to replace dead ctx ffff9db846288300: -111
Jun 2 08:51:50 sci-mds01 kernel: LustreError: 48111:0:(file.c:216:ll_close_inode_openhandle()) science-clilmv-ffff9dd1c9bee800: inode [0x200001b80:0x1:0x0] mdc close failed: rc = -111
Jun 2 08:51:50 sci-mds01 kernel: LustreError: 48111:0:(file.c:4341:ll_inode_revalidate_fini()) science: revalidate FID [0x200001b72:0x3:0x0] error: rc = -111
Jun 2 08:51:51 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:51:51 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) Skipped 12 previous similar messages
Jun 2 08:51:51 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9de6de9f6780: fail to get context
Jun 2 08:51:51 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) Skipped 8 previous similar messages
Jun 2 08:51:52 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:51:52 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) Skipped 395 previous similar messages
Jun 2 08:51:52 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9dc0c8e49f80: fail to get context
Jun 2 08:51:52 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) Skipped 197 previous similar messages
Jun 2 08:51:54 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:51:54 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) Skipped 801 previous similar messages
Jun 2 08:51:54 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9de162ec3a80: fail to get context
Jun 2 08:51:54 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) Skipped 400 previous similar messages
Jun 2 08:51:58 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:51:58 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) Skipped 1599 previous similar messages
Jun 2 08:51:58 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9de6de9f6780: fail to get context
Jun 2 08:51:58 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) Skipped 799 previous similar messages
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48196]:INFO:main(): key 434774280, desc 0 at 6, ugid 0:0, sring 182285978, coinfo 6:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1103-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48196]:DEBUG:parse_callout_info(): parse call out info: secid 6, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1103-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48196]:INFO:sk_create_cred(): Creating credentials for target: science-OST1103-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48196]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 48197:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) client refreshed ctx ffff9dcad7b6a300 idx 0x441bc9ec5b941983 (0->science-OST1103_UUID), expiry 1591080830(+110s)
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 48197:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) Skipped 3 previous similar messages
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 48197:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) create reverse svc ctx ffff9dcc65f75640 to science-OST1103_UUID: idx 0x9bf0d0270b05690
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 48197:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) Skipped 2 previous similar messages
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 151945:0:(sec_gss.c:1228:gss_cli_ctx_fini_common()) gss.keyring at ffff9de74ce0e800: destroy ctx ffff9db846288300(0->science-OST1103_UUID)
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:DEBUG:update_kernel_key(): key 19ea2108: updated
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48197]:INFO:lgssc_kr_negotiate_manual(): key 19ea2108 for user 0 is updated OK!
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 46471:0:(sec_gss.c:315:cli_ctx_expire()) ctx ffff9db84628b500(0->science-OST1102_UUID) get expired: 1591080710(-10s)
Jun 2 08:52:00 sci-mds01 kernel: Lustre: 46471:0:(sec_gss.c:315:cli_ctx_expire()) Skipped 1 previous similar message
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48199]:INFO:main(): key 530794287, desc 0 at 5, ugid 0:0, sring 182285978, coinfo 5:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1102-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48199]:DEBUG:parse_callout_info(): parse call out info: secid 5, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1102-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48199]:INFO:sk_create_cred(): Creating credentials for target: science-OST1102-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48199]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:DEBUG:update_kernel_key(): key 1fa3472f: updated
Jun 2 08:52:00 sci-mds01 lgss_keyring: [48200]:INFO:lgssc_kr_negotiate_manual(): key 1fa3472f for user 0 is updated OK!
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48206]:INFO:main(): key 863786640, desc 0 at 2, ugid 0:0, sring 182285978, coinfo 2:sk:0:0:r:i:1:0x20000ac190a32:science-MDT0000-mdc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48206]:DEBUG:parse_callout_info(): parse call out info: secid 2, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 1, nid 0x20000ac190a32, tgt science-MDT0000-mdc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48206]:INFO:sk_create_cred(): Creating credentials for target: science-MDT0000-mdc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48206]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x320a19ac => sci-mds00.science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:DEBUG:lgss_get_service_str(): constructed service string: lustre_mds at sci-mds00.science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48209]:INFO:main(): key 1073660089, desc 0 at 4, ugid 0:0, sring 182285978, coinfo 4:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1101-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48209]:DEBUG:parse_callout_info(): parse call out info: secid 4, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1101-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48209]:INFO:sk_create_cred(): Creating credentials for target: science-OST1101-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48209]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 47980:0:(sec_gss.c:315:cli_ctx_expire()) ctx ffff9db84628bf00(0->science-OST1100_UUID) get expired: 1591080710(-15s)
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 47980:0:(sec_gss.c:315:cli_ctx_expire()) Skipped 1 previous similar message
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48212]:INFO:main(): key 654412498, desc 0 at 3, ugid 0:0, sring 182285978, coinfo 3:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1100-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48212]:DEBUG:parse_callout_info(): parse call out info: secid 3, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1100-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48212]:INFO:sk_create_cred(): Creating credentials for target: science-OST1100-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48212]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:DEBUG:update_kernel_key(): key 3ffec0b9: updated
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48210]:INFO:lgssc_kr_negotiate_manual(): key 3ffec0b9 for user 0 is updated OK!
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:DEBUG:update_kernel_key(): key 27018ad2: updated
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48213]:INFO:lgssc_kr_negotiate_manual(): key 27018ad2 for user 0 is updated OK!
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 48207:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) client refreshed ctx ffff9de74baf6a00 idx 0xe4574184e6adcf6e (0->science-MDT0000_UUID), expiry 1591080835(+110s)
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 48210:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) create reverse svc ctx ffff9de4f99bdc40 to science-OST1101_UUID: idx 0x9bf0d0270b05693
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 48210:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) Skipped 1 previous similar message
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 47459:0:(sec_gss.c:1228:gss_cli_ctx_fini_common()) gss.keyring at ffff9de776b6a800: destroy ctx ffff9db84628b600(0->science-OST1101_UUID)
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 47459:0:(sec_gss.c:1228:gss_cli_ctx_fini_common()) Skipped 1 previous similar message
Jun 2 08:52:05 sci-mds01 kernel: Lustre: 48207:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) Skipped 3 previous similar messages
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:DEBUG:update_kernel_key(): key 337c5690: updated
Jun 2 08:52:05 sci-mds01 lgss_keyring: [48207]:INFO:lgssc_kr_negotiate_manual(): key 337c5690 for user 0 is updated OK!
Jun 2 08:53:50 sci-mds01 kernel: Lustre: 48109:0:(sec_gss.c:315:cli_ctx_expire()) ctx ffff9dcad7b6a300(0->science-OST1103_UUID) get expired: 1591080830(+0s)
Jun 2 08:53:50 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:53:50 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) Skipped 801 previous similar messages
Jun 2 08:53:50 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9ddb5df11b00: fail to get context
Jun 2 08:53:50 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) Skipped 400 previous similar messages
Jun 2 08:53:50 sci-mds01 kernel: LustreError: 48109:0:(sec.c:786:sptlrpc_req_refresh_ctx()) req ffff9ddb5df11b00: failed to replace dead ctx ffff9dcad7b6a300: -111
Jun 2 08:53:50 sci-mds01 kernel: LustreError: 48109:0:(sec.c:786:sptlrpc_req_refresh_ctx()) Skipped 2 previous similar messages
Jun 2 08:53:50 sci-mds01 kernel: Lustre: 48109:0:(sec_gss.c:1228:gss_cli_ctx_fini_common()) gss.keyring at ffff9de74ce0e800: destroy ctx ffff9dcad7b6a300(0->science-OST1103_UUID)
Jun 2 08:53:50 sci-mds01 kernel: Lustre: 48109:0:(sec_gss.c:1228:gss_cli_ctx_fini_common()) Skipped 1 previous similar message
Jun 2 08:54:06 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) failed request key: -128
Jun 2 08:54:06 sci-mds01 kernel: LustreError: 48109:0:(gss_keyring.c:835:gss_sec_lookup_ctx_kr()) Skipped 6025 previous similar messages
Jun 2 08:54:06 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) req ffff9de6cfb90000: fail to get context
Jun 2 08:54:06 sci-mds01 kernel: LustreError: 48109:0:(sec.c:450:sptlrpc_req_get_ctx()) Skipped 3013 previous similar messages
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48367]:INFO:main(): key 262101124, desc 0 at 6, ugid 0:0, sring 182285978, coinfo 6:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1103-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48365]:INFO:main(): key 226145045, desc 0 at 2, ugid 0:0, sring 182285978, coinfo 2:sk:0:0:r:i:1:0x20000ac190a32:science-MDT0000-mdc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48368]:INFO:main(): key 820176239, desc 0 at 4, ugid 0:0, sring 182285978, coinfo 4:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1101-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48366]:INFO:main(): key 679758548, desc 0 at 5, ugid 0:0, sring 182285978, coinfo 5:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1102-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48367]:DEBUG:parse_callout_info(): parse call out info: secid 6, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1103-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48365]:DEBUG:parse_callout_info(): parse call out info: secid 2, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 1, nid 0x20000ac190a32, tgt science-MDT0000-mdc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48366]:DEBUG:parse_callout_info(): parse call out info: secid 5, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1102-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48368]:DEBUG:parse_callout_info(): parse call out info: secid 4, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1101-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48367]:INFO:sk_create_cred(): Creating credentials for target: science-OST1103-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48367]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48365]:INFO:sk_create_cred(): Creating credentials for target: science-MDT0000-mdc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48368]:INFO:sk_create_cred(): Creating credentials for target: science-OST1101-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48366]:INFO:sk_create_cred(): Creating credentials for target: science-OST1102-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48365]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48368]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48366]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x320a19ac => sci-mds00.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:DEBUG:lgss_get_service_str(): constructed service string: lustre_mds at sci-mds00.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 kernel: Lustre: 47981:0:(sec_gss.c:315:cli_ctx_expire()) ctx ffff9de74d32b500(0->science-OST1100_UUID) get expired: 1591080835(-16s)
Jun 2 08:54:11 sci-mds01 kernel: Lustre: 47980:0:(sec_gss.c:1228:gss_cli_ctx_fini_common()) gss.keyring at ffff9de776b68800: destroy ctx ffff9de74baf6a00(0->science-MDT0000_UUID)
Jun 2 08:54:11 sci-mds01 kernel: Lustre: 47981:0:(sec_gss.c:315:cli_ctx_expire()) Skipped 3 previous similar messages
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48374]:INFO:main(): key 487950447, desc 0 at 3, ugid 0:0, sring 182285978, coinfo 3:sk:0:0:r:i:2:0x20000ac190a6f:science-OST1100-osc-ffff9dd1c9bee800:0x20000ac190a33:1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48374]:DEBUG:parse_callout_info(): parse call out info: secid 3, mech sk, ugid 0:0, is_root 1, is_mdt 0, is_ost 0, svc type i, svc 2, nid 0x20000ac190a6f, tgt science-OST1100-osc-ffff9dd1c9bee800, self nid 0x20000ac190a33, pid 1
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48374]:INFO:sk_create_cred(): Creating credentials for target: science-OST1100-osc-ffff9dd1c9bee800 with nodemap: (null)
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48374]:INFO:sk_create_cred(): Searching for key with description: lustre:science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:INFO:ipv4_nid2hostname(): SOCKLND: net 0x20000, addr 0x6f0a19ac => sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:DEBUG:lgss_get_service_str(): constructed service string: lustre_oss at sci-oss11.science
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:INFO:sk_encode_netstring(): Encoded netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:INFO:lgss_sk_using_cred(): Created netstring of 656 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:DEBUG:update_kernel_key(): key 28844ad4: updated
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48371]:INFO:lgssc_kr_negotiate_manual(): key 28844ad4 for user 0 is updated OK!
Jun 2 08:54:11 sci-mds01 kernel: Lustre: 48369:0:(sec_gss.c:377:gss_cli_ctx_uptodate()) client refreshed ctx ffff9de74baf6500 idx 0x441bc9ec5b941987 (0->science-OST1103_UUID), expiry 1591080961(+110s)
Jun 2 08:54:11 sci-mds01 kernel: Lustre: 48369:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) create reverse svc ctx ffff9dc22ffa4e40 to science-OST1103_UUID: idx 0x9bf0d0270b0761d
Jun 2 08:54:11 sci-mds01 kernel: Lustre: 48369:0:(gss_svc_upcall.c:882:gss_svc_upcall_install_rvs_ctx()) Skipped 3 previous similar messages
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:DEBUG:update_kernel_key(): key 0f9f5884: updated
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48369]:INFO:lgssc_kr_negotiate_manual(): key 0f9f5884 for user 0 is updated OK!
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:DEBUG:update_kernel_key(): key 30e2e56f: updated
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48372]:INFO:lgssc_kr_negotiate_manual(): key 30e2e56f for user 0 is updated OK!
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:DEBUG:update_kernel_key(): key 0d7ab315: updated
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48370]:INFO:lgssc_kr_negotiate_manual(): key 0d7ab315 for user 0 is updated OK!
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:DEBUG:do_nego_rpc(): do_nego_rpc: receive handle len 8, token len 311, res 0
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:INFO:sk_decode_netstring(): Decoded netstring of 311 bytes
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:INFO:sk_serialize_kctx(): Serialized buffer of 240 bytes for kernel
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:DEBUG:lgssc_negotiation_manual(): successfully negotiated a context
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:DEBUG:update_kernel_key(): key 1d15886f: updated
Jun 2 08:54:11 sci-mds01 lgss_keyring: [48375]:INFO:lgssc_kr_negotiate_manual(): key 1d15886f for user 0 is updated OK!
More information about the lustre-discuss
mailing list