[LU-890] MDS Failover Issue - Clients not reconnecting after MGT/MDT fail over to other MDS.

• Type: Bug
• Resolution: Fixed
• Priority: Major
• Fix Version/s: Lustre 1.8.6, Lustre 1.8.x (1.8.0 - 1.8.5)

Environment

This is a rather complex configuration. It consists of two large Lustre filesystems. scratch1 is comprised of 2, MDS, 16 OSS, 4 DDN SFA 10K storage arrays. scratch2 is comprised of 2 MDS, 20 OSS, 5 DDN SFA 10K storage arrays. The Lustre servers all have 4 IB ports for client access to the filesystems. The compute nodes access scratch1 via their ib0 port (ib0 on the lustre servers). They access scratch2 vi ib1 (also ib1 on the servers). The various login nodes of the cluster access both scratch1 and scratch2 through their ib2 port (also ib2 on the servers). Finally, ib3 is for access to the production filesystems from clients in a test cluster.

The servers are running CentOS 5.5 (2.6.18-238.12.1.el5)
Lustre 1.8.6 with the LU-530 patch installed
The clients are currently running RHEL 6.0.

• Severity: 3
• Assignee: Hongchao Zhang
• Reporter: Dennis Nelson

Description

The production compute nodes and login nodes can access both filesystems when the MGT/MDT is running on the primary MDS of scratch1. When the MGT and MDT are failed over to the backup MDS, the clients fail to reconnect.

The basic configuration information is as follows:

The primary MDS for scratch1 is named lfs-mds-1-1 and the secondary MDS is named lfs-mds-1-2.
/etc/modprobe.d/lustre.conf:
options lnet networks="o2ib0(ib0), o2ib1(ib2), o2ib2(ib3)"

lfs-mds-1-1:
ib0 inet addr:10.174.31.241 Bcast:10.174.31.255 Mask:255.255.224.0
ib1 inet addr:10.175.31.241 Bcast:10.175.31.255 Mask:255.255.224.0
ib2 inet addr:10.174.79.241 Bcast:10.174.79.255 Mask:255.255.240.0
ib3 inet addr:10.174.80.40 Bcast:10.174.111.255 Mask:255.255.240.0

[root@lfs-mds-1-1 config]# lctl list_nids
10.174.31.241@o2ib
10.174.79.241@o2ib1
10.174.80.40@o2ib2

lfs-mds-1-2:
ib0 inet addr:10.174.31.251 Bcast:10.174.31.255 Mask:255.255.224.0
ib1 inet addr:10.175.31.251 Bcast:10.175.31.255 Mask:255.255.224.0
ib2 inet addr:10.174.79.251 Bcast:10.174.79.255 Mask:255.255.240.0
ib3 inet addr:10.174.80.41 Bcast:10.174.111.255 Mask:255.255.240.0

[root@lfs-mds-1-2 ~]# lctl list_nids
10.174.31.251@o2ib
10.174.79.251@o2ib1
10.174.80.41@o2ib2

r1i0n0 config (compute node):
ib0 inet addr:10.174.0.55 Bcast:10.174.31.255 Mask:255.255.224.0
ib1 inet addr:10.175.0.55 Bcast:10.175.31.255 Mask:255.255.224.0

/etc/modprobe.d/lustre.conf
options lnet networks="o2ib0(ib0), o2ib1(ib1)"

[root@r1i0n0 ~]# lctl list_nids
10.174.0.55@o2ib
10.175.0.55@o2ib1

[root@r1i0n0 ~]# lctl ping 10.174.31.241@o2ib
12345-0@lo
12345-10.174.31.241@o2ib
12345-10.174.79.241@o2ib1
12345-10.174.80.40@o2ib2
[root@r1i0n0 ~]# lctl ping 10.174.31.251@o2ib
12345-0@lo
12345-10.174.31.251@o2ib
12345-10.174.79.251@o2ib1
12345-10.174.80.41@o2ib2

fe1 (login node):
inet addr:10.174.0.37 Bcast:10.255.255.255 Mask:255.255.224.0
inet addr:10.175.0.37 Bcast:10.255.255.255 Mask:255.255.224.0
inet addr:10.174.81.1 Bcast:10.174.95.255 Mask:255.255.240.0

/etc/modprobe.d/lustre.conf
options lnet networks="o2ib0(ib0), o2ib1(ib1), o2ib2(ib2)"

[root@fe1 ~]# lctl list_nids
10.174.0.37@o2ib
10.175.0.37@o2ib1
10.174.81.10@o2ib2

[root@fe1 ~]# lctl ping 10.174.80.40@o2ib2
12345-0@lo
12345-10.174.31.241@o2ib
12345-10.174.79.241@o2ib1
12345-10.174.80.40@o2ib2
[root@fe1 ~]# lctl ping 10.174.80.41@o2ib2
12345-0@lo
12345-10.174.31.251@o2ib
12345-10.174.79.251@o2ib1
12345-10.174.80.41@o2ib2

[root@lfs-mds-1-1 ~]# tunefs.lustre --dryrun /dev/vg_scratch1/mdt
checking for existing Lustre data: found CONFIGS/mountdata
Reading CONFIGS/mountdata

Read previous values:
Target: scratch1-MDT0000
Index: 0
Lustre FS: scratch1
Mount type: ldiskfs
Flags: 0x1401
(MDT no_primnode )
Persistent mount opts: iopen_nopriv,user_xattr,errors=remount-ro
Parameters: mgsnode=10.174.31.241@o2ib,10.174.79.241@o2ib1,10.174.80.40@o2ib2 mgsnode=10.174.31.251@o2ib,10.174.79.251@o2ib1,10.174.80.41@o2ib2 failover.node=10.174.31.241@o2ib,10.174.79.241@o2ib1,10.174.80.40@o2ib2 failover.node=10.174.31.251@o2ib,10.174.79.251@o2ib1,10.174.80.41@o2ib2 mdt.quota_type=ug

Permanent disk data:
Target: scratch1-MDT0000
Index: 0
Lustre FS: scratch1
Mount type: ldiskfs
Flags: 0x1401
(MDT no_primnode )
Persistent mount opts: iopen_nopriv,user_xattr,errors=remount-ro
Parameters: mgsnode=10.174.31.241@o2ib,10.174.79.241@o2ib1,10.174.80.40@o2ib2 mgsnode=10.174.31.251@o2ib,10.174.79.251@o2ib1,10.174.80.41@o2ib2 failover.node=10.174.31.241@o2ib,10.174.79.241@o2ib1,10.174.80.40@o2ib2 failover.node=10.174.31.251@o2ib,10.174.79.251@o2ib1,10.174.80.41@o2ib2 mdt.quota_type=ug

exiting before disk write.

After failing over the MGT and MDT to the backup MDS (lfs-mds-1-2) it appears to have never started recovery:

[root@lfs-mds-1-2 lustre]# cat
/proc/fs/lustre/mds/scratch1-MDT0000/recovery_status
status: RECOVERING
recovery_start: 0
time_remaining: 0
connected_clients: 0/2275
delayed_clients: 0/2275
completed_clients: 0/2275
replayed_requests: 0/??
queued_requests: 0
next_transno: 55834575147

Once I moved the MGT and MDT back to the original system, the client reconnected again in less than a minute:

[root@lfs-mds-1-1 ~]# cat
/proc/fs/lustre/mds/scratch1-MDT0000/recovery_status
status: RECOVERING
recovery_start: 1322752821
time_remaining: 267
connected_clients: 1896/2275
delayed_clients: 0/2275
completed_clients: 1896/2275
replayed_requests: 0/??
queued_requests: 0
next_transno: 55834575147
[root@lfs-mds-1-1 ~]# cat
/proc/fs/lustre/mds/scratch1-MDT0000/recovery_status
status: COMPLETE
recovery_start: 1322752821
recovery_duration: 56
delayed_clients: 0/2275
completed_clients: 2275/2275
replayed_requests: 0
last_transno: 55834575146

The log file on fe1 showed this:
Dec 1 15:08:21 fe1 kernel: Lustre: 7508:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264150314 sent from scratch1-MDT0000-mdc-ffff880be72aec00 to NID 10.174.31.241@o2ib 7s ago has timed out (7s prior to deadline).
Dec 1 15:08:21 fe1 kernel: req@ffff880bee44fc00 x1386944264150314/t0 o35->scratch1-MDT0000_UUID@10.174.31.241@o2ib:23/10 lens 408/9864 e 0 to 1 dl 1322752101 ref 1 fl Rpc:/0/0 rc 0/0
Dec 1 15:08:21 fe1 kernel: Lustre: 7508:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 19 previous similar messages
Dec 1 15:08:21 fe1 kernel: Lustre: scratch1-MDT0000-mdc-ffff880be72aec00: Connection to service scratch1-MDT0000 via nid 10.174.31.241@o2ib was lost; in progress operations using this service will wait for recovery to complete.
Dec 1 15:08:36 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 2s
Dec 1 15:08:38 fe1 kernel: Lustre: 5585:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264150337 sent from MGC10.174.80.40@o2ib2 to NID 10.174.80.40@o2ib2 17s ago has timed out (17s prior to deadline).
Dec 1 15:08:38 fe1 kernel: req@ffff880becc30000 x1386944264150337/t0 o400->MGS@MGC10.174.80.40@o2ib2_0:26/25 lens 192/384 e 0 to 1 dl 1322752117 ref 1 fl Rpc:N/0/0 rc 0/0
Dec 1 15:08:38 fe1 kernel: Lustre: 5585:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 2 previous similar messages
Dec 1 15:08:38 fe1 kernel: LustreError: 166-1: MGC10.174.80.40@o2ib2: Connection to service MGS via nid 10.174.80.40@o2ib2 was lost; in progress operations using this service will fail.
Dec 1 15:08:52 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 3s
Dec 1 15:08:59 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264151143 sent from MGC10.174.80.40@o2ib2 to NID 10.174.80.40@o2ib2 6s ago has timed out (6s prior to deadline).
Dec 1 15:08:59 fe1 kernel: req@ffff880bed70c400 x1386944264151143/t0 o250->MGS@MGC10.174.80.40@o2ib2_0:26/25 lens 368/584 e 0 to 1 dl 1322752139 ref 1 fl Rpc:N/0/0 rc 0/0
Dec 1 15:08:59 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 5 previous similar messages
Dec 1 15:09:00 fe1 kernel: Lustre: 5586:0:(import.c:855:ptlrpc_connect_interpret()) MGS@MGC10.174.80.40@o2ib2_1 changed server handle from 0x242210f6584197b7 to 0xa6cae1b09294c1a2
Dec 1 15:09:00 fe1 kernel: Lustre: MGC10.174.80.40@o2ib2: Reactivating import
Dec 1 15:09:00 fe1 kernel: Lustre: MGC10.174.80.40@o2ib2: Connection restored to service MGS using nid 10.174.80.41@o2ib2.
Dec 1 15:09:11 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 4s
Dec 1 15:09:31 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 5s
Dec 1 15:09:41 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264151550 sent from scratch1-MDT0000-mdc-ffff880be72aec00 to NID 10.174.31.241@o2ib 10s ago has timed out (10s prior to deadline).
Dec 1 15:09:41 fe1 kernel: req@ffff8817eea7d000 x1386944264151550/t0 o38->scratch1-MDT0000_UUID@10.174.31.241@o2ib:12/10 lens 368/584 e 0 to 1 dl 1322752181 ref 1 fl Rpc:N/0/0 rc 0/0
Dec 1 15:09:41 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 4 previous similar messages
Dec 1 15:10:17 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 7s
Dec 1 15:10:17 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) Skipped 1 previous similar message
Dec 1 15:10:56 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264152753 sent from scratch1-MDT0000-mdc-ffff880be72aec00 to NID 10.174.31.241@o2ib 13s ago has timed out (13s prior to deadline).
Dec 1 15:10:56 fe1 kernel: req@ffff881808992800 x1386944264152753/t0 o38->scratch1-MDT0000_UUID@10.174.31.241@o2ib:12/10 lens 368/584 e 0 to 1 dl 1322752256 ref 1 fl Rpc:N/0/0 rc 0/0
Dec 1 15:10:56 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 5 previous similar messages
Dec 1 15:11:41 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 10s
Dec 1 15:11:41 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) Skipped 2 previous similar messages
Dec 1 15:13:41 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264155556 sent from scratch1-MDT0000-mdc-ffff880be72aec00 to NID 10.174.31.241@o2ib 18s ago has timed out (18s prior to deadline).
Dec 1 15:13:41 fe1 kernel: req@ffff880be9f5e000 x1386944264155556/t0 o38->scratch1-MDT0000_UUID@10.174.31.241@o2ib:12/10 lens 368/584 e 0 to 1 dl 1322752421 ref 1 fl Rpc:N/0/0 rc 0/0
Dec 1 15:13:41 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 9 previous similar messages
Dec 1 15:14:41 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 15s
Dec 1 15:14:41 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) Skipped 4 previous similar messages
Dec 1 15:18:56 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) @@@ Request x1386944264160358 sent from scratch1-MDT0000-mdc-ffff880be72aec00 to NID 10.174.31.241@o2ib 25s ago has timed out (25s prior to deadline).
Dec 1 15:18:56 fe1 kernel: req@ffff880beb4a4000 x1386944264160358/t0 o38->scratch1-MDT0000_UUID@10.174.31.241@o2ib:12/10 lens 368/584 e 0 to 1 dl 1322752736 ref 1 fl Rpc:N/0/0 rc 0/0
Dec 1 15:18:56 fe1 kernel: Lustre: 5586:0:(client.c:1487:ptlrpc_expire_one_request()) Skipped 13 previous similar messages
Dec 1 15:20:17 fe1 kernel: LustreError: 166-1: MGC10.174.80.40@o2ib2: Connection to service MGS via nid 10.174.80.41@o2ib2 was lost; in progress operations using this service will fail.
Dec 1 15:20:18 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) scratch1-MDT0000-mdc-ffff880be72aec00: tried all connections, increasing latency to 22s
Dec 1 15:20:18 fe1 kernel: Lustre: 5587:0:(import.c:517:import_select_connection()) Skipped 6 previous similar messages
Dec 1 15:20:24 fe1 kernel: Lustre: 5586:0:(import.c:855:ptlrpc_connect_interpret()) MGS@MGC10.174.80.40@o2ib2_0 changed server handle from 0xa6cae1b09294c1a2 to 0x242210f65845423c
Dec 1 15:20:24 fe1 kernel: Lustre: MGC10.174.80.40@o2ib2: Reactivating import
Dec 1 15:20:24 fe1 kernel: Lustre: MGC10.174.80.40@o2ib2: Connection restored to service MGS using nid 10.174.80.40@o2ib2.
Dec 1 15:21:14 fe1 kernel: LustreError: 5586:0:(client.c:2347:ptlrpc_replay_interpret()) @@@ status 301, old was 0 req@ffff880be96a8000 x1386944264100092/t55834575126 o101->scratch1-MDT0000_UUID@10.174.31.241@o2ib:12/10 lens 512/4880 e 0 to 1 dl 1322752939 ref 2 fl Interpret:RP/4/0 rc 301/301
Dec 1 15:21:17 fe1 kernel: Lustre: scratch1-MDT0000-mdc-ffff880be72aec00: Connection restored to service scratch1-MDT0000 using nid 10.174.31.241@o2ib.
Dec 1 15:21:17 fe1 kernel: LustreError: 11-0: an error occurred while communicating with 10.174.31.241@o2ib. The mds_close operation failed with -116
Dec 1 15:21:17 fe1 kernel: LustreError: Skipped 7 previous similar messages
Dec 1 15:21:17 fe1 kernel: LustreError: 7508:0:(file.c:116:ll_close_inode_openhandle()) inode 1905262791 mdc close failed: rc = -116

The log files on lfs-mds-1-1 and lfs-mds-1-2 are void of any useful data.