Details
-
Bug
-
Resolution: Fixed
-
Critical
-
Lustre 2.12.2
-
None
-
L2.12.2 server & L2.10.8 Server
L2.12.2 client & L2.11 Client
-
2
-
9223372036854775807
Description
We are seeing
Oct 14 07:51:06 nbp7-oss7 kernel: [1110415.124675] LNet: 72766:0:(o2iblnd_cb.c:413:kiblnd_handle_rx()) PUT_NACK from 10.151.54.10@o2ib Oct 14 07:53:28 nbp7-oss7 kernel: [1110557.738283] LustreError: 48242:0:(ldlm_lib.c:3268:target_bulk_io()) @@@ truncated bulk READ 0(270336) req@ffff8bd7711d9850 x1647322708401808/t0(0) o3->c1bb3af1-465f-4e4e-3b45-831f7f0aa442@10.151.53.134@o2ib:520/0 lens 488/440 e 0 to 0 dl 1571064920 ref 1 fl Interpret:/2/0 rc 0/0 Oct 14 07:53:28 nbp7-oss7 kernel: [1110557.820414] Lustre: nbp7-OST0009: Bulk IO read error with c1bb3af1-465f-4e4e-3b45-831f7f0aa442 (at 10.151.53.134@o2ib), client will retry: rc -110 Oct 14 07:58:40 nbp7-oss7 kernel: [1110869.753867] LNet: 72764:0:(o2iblnd_cb.c:413:kiblnd_handle_rx()) PUT_NACK from 10.151.54.10@o2ib Oct 14 08:00:58 nbp7-oss7 kernel: [1111007.747557] LustreError: 7338:0:(ldlm_lib.c:3268:target_bulk_io()) @@@ truncated bulk READ 0(270336) req@ffff8bd4ef6c3050 x1647322708401808/t0(0) o3->c1bb3af1-465f-4e4e-3b45-831f7f0aa442@10.151.53.134@o2ib:220/0 lens 488/440 e 0 to 0 dl 1571065375 ref 1 fl Interpret:/2/0 rc 0/0 Oct 14 08:00:58 nbp7-oss7 kernel: [1111007.829410] Lustre: nbp7-OST0009: Bulk IO read error with c1bb3af1-465f-4e4e-3b45-831f7f0aa442 (at 10.151.53.134@o2ib), client will retry: rc -110 Oct 14 08:02:39 nbp7-oss7 kernel: [1111108.765855] Lustre: nbp7-OST0003: Client c1bb3af1-465f-4e4e-3b45-831f7f0aa442 (at 10.151.53.134@o2ib) reconnecting Oct 14 08:02:39 nbp7-oss7 kernel: [1111108.800504] Lustre: Skipped 5 previous similar messages Oct 14 08:02:39 nbp7-oss7 kernel: [1111108.818286] Lustre: nbp7-OST0003: Connection restored to 2ee3c4e1-9fd7-3338-5bf8-d1f02bcd8a20 (at 10.151.53.134@o2ib) Oct 14 08:02:39 nbp7-oss7 kernel: [1111108.818288] Lustre: Skipped 5 previous similar messages Oct 14 08:09:47 nbp7-oss7 kernel: [1111536.849491] LNet: 72766:0:(o2iblnd_cb.c:413:kiblnd_handle_rx()) PUT_NACK from 10.151.54.10@o2ib Oct 14 08:11:48 nbp7-oss7 kernel: [1111657.759009] LustreError: 82937:0:(ldlm_lib.c:3268:target_bulk_io()) @@@ truncated bulk READ 0(270336) req@ffff8bd724b11850 x1647322708401808/t0(0) o3->c1bb3af1-465f-4e4e-3b45-831f7f0aa442@10.151.53.134@o2ib:132/0 lens 488/440 e 0 to 0 dl 1571066042 ref 1 fl Interpret:/2/0 rc 0/0 Oct 14 08:11:48 nbp7-oss7 kernel: [1111657.841189] Lustre: nbp7-OST0009: Bulk IO read error with c1bb3af1-465f-4e4e-3b45-831f7f0aa442 (at 10.151.53.134@o2ib), client will retry: rc -110 Oct 14 08:12:57 nbp7-oss7 kernel: [1111726.231189] Lustre: nbp7-OST000f: Client c1bb3af1-465f-4e4e-3b45-831f7f0aa442 (at 10.151.53.134@o2ib) reconnecting Oct 14 08:12:57 nbp7-oss7 kernel: [1111726.265819] Lustre: Skipped 5 previous similar messages
We have the 3 patch reported in LU-12385 and LU-12772 applied to both client and server.
Client Configs
r593i6n16 ~ # lnetctl global show
global:
numa_range: 0
max_intf: 200
discovery: 1
drop_asym_route: 0
retry_count: 0
transaction_timeout: 100
health_sensitivity: 0
recovery_interval: 1
----
options ko2iblnd require_privileged_port=0 use_privileged_port=0
options ko2iblnd timeout=100 retry_count=7 peer_timeout=0 map_on_demand=32 peer_credits=32 concurrent_sends=32
options lnet networks=o2ib(ib1)
options lnet avoid_asym_router_failure=1 check_routers_before_use=1 small_router_buffers=65536 large_router_buffers=8192
options lnet lnet_transaction_timeout=100
options ptlrpc at_max=600 at_min=200
Server Configs
nbp7-oss7 ~ # lnetctl global show
global:
numa_range: 0
max_intf: 200
discovery: 1
drop_asym_route: 0
retry_count: 0
transaction_timeout: 100
health_sensitivity: 0
recovery_interval: 1
----
options ko2iblnd require_privileged_port=0 use_privileged_port=0
options ko2iblnd ntx=251072 credits=125536 fmr_pool_size=62769
options ko2iblnd timeout=100 retry_count=7 peer_timeout=0 map_on_demand=32 peer_credits=32 concurrent_sends=32
#lnet
options lnet networks=o2ib(ib1)
options lnet routes="o2ib233 10.151.26.[80-94]@o2ib; o2ib313 10.151.25.[195-197,202-205,222]@o2ib 10.151.26.[60,127,140-144,150-154]@o2ib; o2ib417 10.151.26.[148,149]@o2ib 10.151.25.[167-170]@o2ib"
options lnet dead_router_check_interval=60 live_router_check_interval=30
options lnet avoid_asym_router_failure=1 check_routers_before_use=1 small_router_buffers=65536 large_router_buffers=8192options lnet lnet_transaction_timeout=100
options ptlrpc at_max=600 at_min=200
These bulk errors are a major issue. We though matching client and server to 2.12.2 would solve it but doesn't look like it.
Attachments
Issue Links
Activity
Hi Mahmoud,
Attached is a short patch to collect some more info around the problem message. I'll probably be adding more debug patches to try and track down the problem. We're also trying to reproduce it locally.
Looks like there was an issue with our last 2.10.53 build. Rebuild an testing show it does NOT have the issue. So we have lookup further up. 
The discovery feature went between 2.10.52 and 2.10.53. Since we're going down the path of bisecting, can we try:
1c45d9051764e0637ba90b3db06ba8fa37722916 LU-9913 lnet: balance references in lnet_discover_peer_locked()
That's after the landing of the discovery feature.
I'm looking at the rest of the patches.
We did a test of tag 2.10.52 and it was ok. But tag 2.10.53 failed. So the issue was introduce after tag 2.10.52
We can't figure how 2.10.8 fits into master and how it is related 2.11
Turning of discovery didn't help. I was able to reproduce with 2.12.2 client and 2.10.6 server.
Can we try something, just to eliminate one of the variables.
in 2.12.2 client can you disable discovery:
options lnet lnet_peer_discovery_disabled=1
or vial lnetct
lnetctl set discovery 0
and try and reproduce with the 2.12.2 clients/2.10.x servers.
One of the features which made it in 2.11 and up is lnet discovery and I want to ensure that it's not introducing an issue.
2.10.8 client (sles12sp3) / 2.10.6 server (cent7) - no problem 2.10.8 client (sles12sp3) / 2.10.8 server (cent7) - no problem 2.10.8 client (sles12sp3) / 2.12.2 server (cent7) - no problem 2.11 client (sles12sp3) / 2.10.6 server (cent7) - problem 2.12.2 client (sles12sp4) / 2.10.6 server (cent7) - problem 2.12.2 client (sles12sp4) / 2.10.8 server (cent7) - problem 2.12.2 client (sles12sp4) / 2.12.2 server (cent7) - probem
Correct past 2.10.8 client is the issue.
I need to clarify the test matrix
2.10.8 client (sles12sp3) / 2.10.6 server (cent7) - no problem 2.10.8 client (sles12sp3) / 2.10.8 server (cent7) - no problem 2.10.8 client (sles12sp3) / 2.12.2 server (cent7) - no problem 2.11 client (sles12sp3) / 2.10.6 server (cent7) - problem 2.12.2 client (sles12sp4) / 2.10.6 server (cent7) - problem 2.12.2 client (sles12sp4) / 2.10.8 server (cent7) - problem 2.12.2 client (sles12sp4) / 2.12.2 server (cent7) - probem
Basically, once we move the clients past 2.10.8 we see the problem?
Is that correct? Will narrow down the list of changes to check.
thanks
amir
I tried a couple of time to reproduce using a 2.10.8 client and it wouldn't.
So looks like the bug was introduce after 2.10.8
Ran a bunch of more tests. Tag2.10.54 is good. and tag2.10.55 is very bad. Writes will even fail with out rebooting the server. I will try the debug patch next.
I tryied to do bisect but I had compilation errors.
In file included from /GITCHECKOUT/lustre-nas/libcfs/include/libcfs/libcfs.h:39:0, from /GITCHECKOUT/lustre-nas/lustre/include/obd_support.h:45, from /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:40: /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c: In function â: /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:1794:11: error: â undeclared (first use in this function) CLASSERT(LMV_HASH_FLAG_DEAD == 0x40000000); ^ /GITCHECKOUT/lustre-nas/libcfs/include/libcfs/libcfs_private.h:360:46: note: in definition of macro â #define CLASSERT(cond) do {switch (1) {case (cond): case 0: break; } } while (0) ^ /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:1794:11: note: each undeclared identifier is reported only once for each function it appears in CLASSERT(LMV_HASH_FLAG_DEAD == 0x40000000); ^ /GITCHECKOUT/lustre-nas/libcfs/include/libcfs/libcfs_private.h:360:46: note: in definition of macro â #define CLASSERT(cond) do {switch (1) {case (cond): case 0: break; } } while (0) ^ In file included from /usr/src/linux-4.4.143-94.47.1.20180815nasa/include/linux/linkage.h:4:0, from /usr/src/linux-4.4.143-94.47.1.20180815nasa/include/linux/fs.h:4, from /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:36: /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:3550:23: error: invalid application of â to incomplete type â LASSERTF((int)sizeof(struct mgs_send_param) == 1024, "found %lld\n", ^ /usr/src/linux-4.4.143-94.47.1.20180815nasa/include/linux/compiler.h:166:42: note: in definition of macro â # define unlikely(x) __builtin_expect(!!(x), 0) ^ /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:3550:2: note: in expansion of macro â LASSERTF((int)sizeof(struct mgs_send_param) == 1024, "found %lld\n", ^ In file included from /GITCHECKOUT/lustre-nas/libcfs/include/libcfs/libcfs.h:39:0, from /GITCHECKOUT/lustre-nas/lustre/include/obd_support.h:45, from /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:40: /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:3551:27: error: invalid application of â to incomplete type â (long long)(int)sizeof(struct mgs_send_param)); ^ /GITCHECKOUT/lustre-nas/libcfs/include/libcfs/libcfs_private.h:88:9: note: in definition of macro â ## __VA_ARGS__); \ ^ /GITCHECKOUT/lustre-nas/lustre/ptlrpc/wiretest.c:3552:11: error: â undeclared (first use in this function) g