|
John,
Could you please have a look and comment on this one?
Thank you!
|
|
Hi Cliff, could you please include the exact version you were testing along with a description of your failover testing?
|
|
We are running 2.6.94 lustre-master build 2856.
Failover testing consists of
- power an OSS node off.
- mount the devices from the dead OSS on the failover node.
- sleep for awhile
- power up the dead OSS
- failback the devices.
This is done 'manually' via a script, as we do not have HA software installed.
|
|
What were the clients running?
|
|
They were running the client bits from the same build
|
|
What application(s) were they running?
|
|
They were running the SWL workload which is a mix of standard tests, including IOR, mutest, simul and others.
|
|
Does the workload include Direct IO and how often can it be reproduced?
|
|
I took a look at the log. From the log, it looks like the write back was not triggered at all. The client was discarding the pages starting from index 4608, and the assertion was hit when it tried to discard page 5120. The log is too short and some key information is missing because I want to know the lock range, type, and what pages were actually written back.
Cliff, can you rerun the test case, with a little bit more debug buffer size, say 100M, and enable cache on the client and then reproduce this issue? As follows:
|
|
BTW, do the test programs use group lock?
|
|
Our normal default is
lctl set_param panic_on_lbug=0;lctl set_param debug_mb=512M
So, no idea why the info you want is not in that log. I am past that build in the test cycle, I will repeat the test when I get the next build test cycle.
|
|
We encountered the same problem at NCI, when the OSTs evicted the clients, many clients LBUGed with the same context above. Now we can reproduce this with a simple setup:
on the client, have a script monitor and keep the number of write processes, e.g. IOR. on the OSTs, have another script does the eviction constantly with an interval, e.g. 10 seconds.
The client always LBUG with the ldlm_resource_dump message. If message appears then it's close. sometimes it takes resource dump messages for a LBUG.
|
|
Li Dongyang (dongyang.li@anu.edu.au) uploaded a new patch: http://review.whamcloud.com/14915
Subject: LU-6271 ldlm: cleanup locks before activating import
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: aeff14823489ef3c53982d440a1df2c583c802d6
|
|
The lock being canceled belongs to the previous instance of import. The dirty pages are actually protected by a new lock. They shouldn't be written back at this time at all. I'm working on a patch
|
|
Hi Jinshan,
IMHO the client should clean up everything in cleanup_resource() before reconnecting. Doing this can also avoid the annoying ldlm_resource_complain messages. On our login nodes where users are doing many IOs to their files, once it got evicted from the OST, the cpu will spin for a long time dumping the locks and the box is not responsive at all.
|
|
Jinshan Xiong (jinshan.xiong@intel.com) uploaded a new patch: http://review.whamcloud.com/14989
Subject: LU-6271 osc: handle osc eviction correctly
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 8c01bf6f3c689f40f5863b30478c1f61947e316f
|
|
Hi Dongyang,
Will you try the patch 14989 and see how it goes?
Jinshan
|
|
Hi Jinshan,
Could you have a look at patch 14915 please? We have been testing it for a long time before submitting it.
|
|
HI,
At Cea with lustre 2.7, we meet the same LBUG
(osc_cache.c:3150:discard_cb()) ASSERTION( (!(page->cp_type == CPT_CACHEABLE) || (!PageDirty(cl_page_vmpage(page)))) ) failed:
In my case the ldlm thread has the same stack and I have another user thread who are currently writing on the
concerning file and the stack was :
This thread do a write in 1024 (0x400) pages, and the page concerning by the LBug is a page
who are in this write()
The writing thread waiting the sync of the last page 1024 (0x400)
If I understand well patch 14915 need some additional work, could you confirm ?
Antoine
|
|
Hi Antoine,
Did you notice that this OSC had ever been evicted from your occurrence?
|
|
Hello Jinshan,
Talking about this problem with Antoine today, I think that the answer is yes, but it need to be double-checked by Antoine on-site.
|
|
Hi,
Yes, for this client, the 3 osts concerning by the current I/Os has evicted and reconnected just before the assert. And for me that is a "short eviction" due to huge I/O between these OSTs and this client.
Antoine
|
|
Here is a demo code to show how to reproduce the problem with grouplock:
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <sys/ioctl.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <stdio.h>
#include <lustre/lustre_user.h>
int main(int argc, char *argv[])
{
int fd;
int rc;
int gid;
char *buf;
int i;
fd = open(<file>, O_RDWR|O_CREAT|O_TRUNC);
gid = atoi(argv[1]);
rc = ioctl(fd, LL_IOC_GROUP_LOCK, gid);
printf("ioctl %d\n", rc);
if (rc)
return rc;
buf = malloc(1<<20);
memset(buf, 1, 1<<20);
while (1)
write(fd, buf, 1<<20);
return 0;
}
Run this with a parameter as gid, then evict the client from the OST.
|
|
I just update http://review.whamcloud.com/14989 it should be good for general IO but group lock is not yet supported. Please verify if this is the case on your side.
|
|
We have hit this on lola, with 2.7.0
fff8807e5361e40) refcount = 3
LustreError: 118965:0:(ldlm_resource.c:1377:ldlm_resource_dump()) Granted locks (in reverse order):
Lustre: soaked-OST000f-osc-ffff88082297e800: Connection restored to soaked-OST000f (at 192.168.1.105@o2ib10)
LustreError: 73177:0:(osc_cache.c:3150:discard_cb()) ASSERTION( (!(page->cp_type == CPT_CACHEABLE) || (!PageDirty(cl_page_vmpage(page)))) ) failed:
LustreError: 73177:0:(osc_cache.c:3150:discard_cb()) LBUG
Pid: 73177, comm: ldlm_bl_100
Call Trace:
[<ffffffffa046c895>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
[<ffffffffa046ce97>] lbug_with_loc+0x47/0xb0 [libcfs]
[<ffffffffa0ba8046>] discard_cb+0x156/0x190 [osc]
[<ffffffffa0ba83bc>] osc_page_gang_lookup+0x1ac/0x330 [osc]
[<ffffffffa0ba7ef0>] ? discard_cb+0x0/0x190 [osc]
[<ffffffffa0ba8684>] osc_lock_discard_pages+0x144/0x240 [osc]
[<ffffffffa0ba7ef0>] ? discard_cb+0x0/0x190 [osc]
[<ffffffffa0b9ef7b>] osc_lock_flush+0x8b/0x260 [osc]
[<ffffffffa0b9f3f8>] osc_ldlm_blocking_ast+0x2a8/0x3c0 [osc]
[<ffffffffa0764a6c>] ldlm_cancel_callback+0x6c/0x170 [ptlrpc]
[<ffffffffa077732a>] ldlm_cli_cancel_local+0x8a/0x470 [ptlrpc]
[<ffffffffa077bf40>] ldlm_cli_cancel+0x60/0x360 [ptlrpc]
[<ffffffffa0b9f22b>] osc_ldlm_blocking_ast+0xdb/0x3c0 [osc]
[<ffffffffa077f980>] ldlm_handle_bl_callback+0x130/0x400 [ptlrpc]
[<ffffffffa077fee1>] ldlm_bl_thread_main+0x291/0x3f0 [ptlrpc]
[<ffffffff81064be0>] ? default_wake_function+0x0/0x20
[<ffffffffa077fc50>] ? ldlm_bl_thread_main+0x0/0x3f0 [ptlrpc]
[<ffffffff8109e78e>] kthread+0x9e/0xc0
[<ffffffff8100c28a>] child_rip+0xa/0x20
[<ffffffff8109e6f0>] ? kthread+0x0/0xc0
[<ffffffff8100c280>] ? child_rip+0x0/0x20
|
|
Lustre Log from LBUG
|
|
Hi Jinshan,
The client is stuck after eviction with 14989 patched:
PID: 15242 TASK: ffff880037cd3520 CPU: 0 COMMAND: "ll_imp_inval"
#0 [ffff88003de53b60] schedule at ffffffff81529ab0
#1 [ffff88003de53c38] osc_object_invalidate at ffffffffa103a695 [osc]
#2 [ffff88003de53cb8] osc_ldlm_resource_invalidate at ffffffffa102b769 [osc]
#3 [ffff88003de53cf8] cfs_hash_for_each_relax at ffffffffa09726ab [libcfs]
#4 [ffff88003de53d88] cfs_hash_for_each_nolock at ffffffffa09745ac [libcfs]
#5 [ffff88003de53db8] osc_import_event at ffffffffa1036556 [osc]
#6 [ffff88003de53e08] ptlrpc_invalidate_import at ffffffffa0c9d7a1 [ptlrpc]
#7 [ffff88003de53ec8] ptlrpc_invalidate_import_thread at ffffffffa0ca0608 [ptlrpc]
#8 [ffff88003de53ee8] kthread at ffffffff8109e78e
#9 [ffff88003de53f48] kernel_thread at ffffffff8100c28a
I've updated http://review.whamcloud.com/#/c/14915/ now we skip the grouplocks during cleanup so we can reconnect to the servers, purge the extents of the grouplock,
and if we see any IO from the grouplock fd, just return -ENOLCK.
The grouplock still needs to be released manually by the user. It's not ideal but at least the client is not crashing any more.
|
|
In that case, let's land the patch 14915 at least it's working.
|
|
Hi Dongyang,
Do you have a program to reproduce the problem?
Jinshan
|
|
We also found this problem on hyperion test. Here is the debug log.
|
|
Are the two patches here complimentary (i.e. both should land) or is only one of the two patches needed?
|
|
Hi Andreas, the two patches are exclusive. I would rather land http://review.whamcloud.com/14989, but it's fine for me to land http://review.whamcloud.com/#/c/14915 if you think it is a better solution.
|
|
Hi Jinshan,
was sick in the past week, sorry for the late reply.
The reproducer is pretty simple:
On the client, have some threads doing write to a file, ior would do, and start e.g. 20 of them.
On the OSS evict the client over and over again, say 10 sec.
Upon eviction on the client the processes will die as a result, just bump the number up back to 20.
Keep it running for a while, and it will hit the problem pretty quick.
BTW with patch set 4 from http://review.whamcloud.com/14989 the client still stuck at one point:
crash> bt 11413
PID: 11413 TASK: ffff88003b1e0ab0 CPU: 0 COMMAND: "ll_imp_inval"
#0 [ffff88003bd59b60] schedule at ffffffff81529ab0
#1 [ffff88003bd59c38] osc_object_invalidate at ffffffffa090468c [osc]
#2 [ffff88003bd59cb8] osc_ldlm_resource_invalidate at ffffffffa08f5769 [osc]
#3 [ffff88003bd59cf8] cfs_hash_for_each_relax at ffffffffa022865b [libcfs]
#4 [ffff88003bd59d88] cfs_hash_for_each_nolock at ffffffffa022a53c [libcfs]
#5 [ffff88003bd59db8] osc_import_event at ffffffffa0900546 [osc]
#6 [ffff88003bd59e08] ptlrpc_invalidate_import at ffffffffa055fcb1 [ptlrpc]
#7 [ffff88003bd59ec8] ptlrpc_invalidate_import_thread at ffffffffa0562b18 [ptlrpc]
#8 [ffff88003bd59ee8] kthread at ffffffff8109e78e
#9 [ffff88003bd59f48] kernel_thread at ffffffff8100c28a
Seems it won't reconnect to the OSS.
Thanks
|
|
Hi Dongyang,
I have been running this test program for over 10 hours on my testing node but I didn't reproduce this problem. I did this test on my VM nodes so this may be one of reasons why I couldn't reproduce it. Will you please reproduce it again and collect lustre logs and output of dmesg when you see the problem? Also it will be helpful to take a crashdump and then upload it, along with lustre modules, to our ftp site at: ftp.whamcloud.com so that I can take a look.
Thanks in advance,
Jinshan
|
|
Hi Jinshan,
I finally got some time to generate the dump for you. I'm using patchset 5 of http://review.whamcloud.com/#/c/14989/ on top of master.
While I was trying to reproduce the problem, I got a client crash. I don't know if it's related but I got the dump as well.
I tried to upload them to ftp.whamcloud.com/uploads. the LU-6271_pkgs.tar.gz was uploaded fine, which has all the lustre modules and debuginfo I used to reproduce the problem.
But when I tried to upload other 2 tarballs(crashdump of the crash and stuck), the transfer stalled despite multiple retries.
Is there another way to upload those files to you?
Thanks
Dongyang
|
|
Another way would be to upload it to dropbox or google drive and share it to me. Please encrypt it if the crash dump has sensitive data and email me the password.
|
|
We just ran into this during our are large scale testing on titan today.
|
|
Oleg Drokin (oleg.drokin@intel.com) merged in patch http://review.whamcloud.com/14989/
Subject: LU-6271 osc: handle osc eviction correctly
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 8f01f8b51d114b0d2d54a5ab7db3161782e52447
|
|
I reckon it is too soon to land http://review.whamcloud.com/14989/
With the patch the client still crashes when I run the reproducer, for example:
<3>LustreError: 15348:0:(ldlm_resource.c:835:ldlm_resource_complain()) testfs-OST0000-osc-ffff880037fea000: namespace resource [0x302:0x0:0x0].0 (ffff88003deae500) refcount no
nzero (1) after lock cleanup; forcing cleanup.
<3>LustreError: 15348:0:(ldlm_resource.c:1450:ldlm_resource_dump()) — Resource: [0x302:0x0:0x0].0 (ffff88003deae500) refcount = 2
<3>LustreError: 15348:0:(ldlm_resource.c:1453:ldlm_resource_dump()) Granted locks (in reverse order):
<3>LustreError: 15348:0:(ldlm_resource.c:1456:ldlm_resource_dump()) ### ### ns: testfs-OST0000-osc-ffff880037fea000 lock: ffff880037e29940/0xaa5a0b4e389da92d lrc: 4/0,1 mode:
PW/PW res: [0x302:0x0:0x0].0 rrc: 2 type: EXT [0->18446744073709551615] (req 0->1048575) flags: 0x126400000000 nid: local remote: 0x59a587f3f1d1130e expref: -99 pid: 15181 tim
eout: 0 lvb_type: 1
<3>LustreError: 15348:0:(ldlm_resource.c:1450:ldlm_resource_dump()) — Resource: [0x302:0x0:0x0].0 (ffff88003deae500) refcount = 2
<3>LustreError: 15348:0:(ldlm_resource.c:1453:ldlm_resource_dump()) Granted locks (in reverse order):
<3>LustreError: 12670:0:(osc_cache.c:3141:discard_cb()) page@ffff880038c3fa00[3 ffff88003ac29b38 1 0 1 ffff88003a78ebb8 (null)]
<3>
<3>LustreError: 12670:0:(osc_cache.c:3141:discard_cb()) vvp-page@ffff880038c3fa68(0:0) vm@ffffea000071dfb8 2000000000087f 2:0 ffff880038c3fa00 21504 lru
<3>
<3>LustreError: 12670:0:(osc_cache.c:3141:discard_cb()) lov-page@ffff880038c3faa8, raid0
<3>
<3>LustreError: 12670:0:(osc_cache.c:3141:discard_cb()) osc-page@ffff880038c3fb10 21504: 1< 0x845fed 258 0 + - > 2< 88080384 0 4096 0x0 0x520 | (null) ffff88003ac58500 ffff880
03cfdbe60 > 3< 1 0 0 > 4< 0 10 8 18446744073619427328 + | + - + - > 5< + - + - | 0 - | 6663 - ->
<3>
<3>LustreError: 12670:0:(osc_cache.c:3141:discard_cb()) end page@ffff880038c3fa00
<3>
<3>LustreError: 12670:0:(osc_cache.c:3141:discard_cb()) discard dirty page?
<3>LustreError: 12670:0:(osc_cache.c:2454:osc_teardown_async_page()) extent ffff88003da0eb10@
{[21504 -> 21759/21759], [2|0|-|cache|wi|ffff88003cfdbe60], [1048576|256|+|-|ffff8
8003c75d680|256|(null)]}
trunc at 21504.
<3>LustreError: 12670:0:(osc_cache.c:2454:osc_teardown_async_page()) ### extent: ffff88003da0eb10
<3> ns: testfs-OST0000-osc-ffff880037fea000 lock: ffff88003c75d680/0xaa5a0b4e389daa3e lrc: 68/0,6 mode: PW/PW res: [0x302:0x0:0x0].0 rrc: 2 type: EXT [0->18446744073709551615]
(req 70254592->71303167) flags: 0x20000000000 nid: local remote: 0x59a587f3f1d11323 expref: -99 pid: 15246 timeout: 0 lvb_type: 1
<3>LustreError: 12670:0:(osc_page.c:307:osc_page_delete()) page@ffff880038c3fa00[3 ffff88003ac29b38 4 0 1 (null) (null)]
<3>
<3>LustreError: 12670:0:(osc_page.c:307:osc_page_delete()) vvp-page@ffff880038c3fa68(0:0) vm@ffffea000071dfb8 2000000000087f 2:0 ffff880038c3fa00 21504 lru
<3>
<3>LustreError: 12670:0:(osc_page.c:307:osc_page_delete()) lov-page@ffff880038c3faa8, raid0
<3>
<3>LustreError: 12670:0:(osc_page.c:307:osc_page_delete()) osc-page@ffff880038c3fb10 21504: 1< 0x845fed 258 0 + - > 2< 88080384 0 4096 0x0 0x520 | (null) ffff88003ac58500 ffff
88003cfdbe60 > 3< 0 0 0 > 4< 0 9 8 18446744073619361792 + | + - + - > 5< + - + - | 0 - | 6679 - ->
<3>
<3>LustreError: 12670:0:(osc_page.c:307:osc_page_delete()) end page@ffff880038c3fa00
<3>
<3>LustreError: 12670:0:(osc_page.c:307:osc_page_delete()) Trying to teardown failed: -16
<0>LustreError: 12670:0:(osc_page.c:308:osc_page_delete()) ASSERTION( 0 ) failed:
<0>LustreError: 12670:0:(osc_page.c:308:osc_page_delete()) LBUG
<4>Pid: 12670, comm: ldlm_bl_00
<4>
<4>Call Trace:
<4> [<ffffffffa021d875>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
<4> [<ffffffffa021de77>] lbug_with_loc+0x47/0xb0 [libcfs]
<4> [<ffffffffa090dbfe>] osc_page_delete+0x46e/0x4e0 [osc]
<4> [<ffffffffa037e9dd>] cl_page_delete0+0x7d/0x210 [obdclass]
<4> [<ffffffffa037ebad>] cl_page_delete+0x3d/0x110 [obdclass]
<4> [<ffffffffa0837d0d>] ll_invalidatepage+0x8d/0x160 [lustre]
<4> [<ffffffffa0846da5>] vvp_page_discard+0xc5/0x160 [lustre]
<4> [<ffffffffa037cfd8>] cl_page_invoid+0x68/0x160 [obdclass]
<4> [<ffffffffa037d0e3>] cl_page_discard+0x13/0x20 [obdclass]
<4> [<ffffffffa0919678>] discard_cb+0x88/0x1e0 [osc]
<4> [<ffffffffa091946e>] osc_page_gang_lookup+0x1ae/0x330 [osc]
<4> [<ffffffffa09195f0>] ? discard_cb+0x0/0x1e0 [osc]
<4> [<ffffffffa0919914>] osc_lock_discard_pages+0x144/0x240 [osc]
<4> [<ffffffffa09195f0>] ? discard_cb+0x0/0x1e0 [osc]
<4> [<ffffffffa090ff7b>] osc_lock_flush+0x8b/0x260 [osc]
<4> [<ffffffffa09103f8>] osc_ldlm_blocking_ast+0x2a8/0x3c0 [osc]
<4> [<ffffffffa050e9dc>] ldlm_cancel_callback+0x6c/0x170 [ptlrpc]
<4> [<ffffffffa052190a>] ldlm_cli_cancel_local+0x8a/0x470 [ptlrpc]
<4> [<ffffffffa0526540>] ldlm_cli_cancel+0x60/0x360 [ptlrpc]
<4> [<ffffffffa091022b>] osc_ldlm_blocking_ast+0xdb/0x3c0 [osc]
<4> [<ffffffffa052a440>] ldlm_handle_bl_callback+0x130/0x400 [ptlrpc]
<4> [<ffffffffa052af24>] ldlm_bl_thread_main+0x484/0x700 [ptlrpc]
<4> [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
<4> [<ffffffffa052aaa0>] ? ldlm_bl_thread_main+0x0/0x700 [ptlrpc]
<4> [<ffffffff810a101e>] kthread+0x9e/0xc0
<4> [<ffffffff8100c28a>] child_rip+0xa/0x20
<4> [<ffffffff810a0f80>] ? kthread+0x0/0xc0
<4> [<ffffffff8100c280>] ? child_rip+0x0/0x20
<4>
<0>Kernel panic - not syncing: LBUG
<4>Pid: 12670, comm: ldlm_bl_00 Not tainted 2.6.32-573.3.1.el6.x86_64 #1
<4>Call Trace:
<4> [<ffffffff81537c54>] ? panic+0xa7/0x16f
<4> [<ffffffffa021decb>] ? lbug_with_loc+0x9b/0xb0 [libcfs]
<4> [<ffffffffa090dbfe>] ? osc_page_delete+0x46e/0x4e0 [osc]
<4> [<ffffffffa037e9dd>] ? cl_page_delete0+0x7d/0x210 [obdclass]
<4> [<ffffffffa037ebad>] ? cl_page_delete+0x3d/0x110 [obdclass]
<4> [<ffffffffa0837d0d>] ? ll_invalidatepage+0x8d/0x160 [lustre]
<4> [<ffffffffa0846da5>] ? vvp_page_discard+0xc5/0x160 [lustre]
<4> [<ffffffffa037cfd8>] ? cl_page_invoid+0x68/0x160 [obdclass]
<4> [<ffffffffa037d0e3>] ? cl_page_discard+0x13/0x20 [obdclass]
<4> [<ffffffffa0919678>] ? discard_cb+0x88/0x1e0 [osc]
<4> [<ffffffffa091946e>] ? osc_page_gang_lookup+0x1ae/0x330 [osc]
<4> [<ffffffffa09195f0>] ? discard_cb+0x0/0x1e0 [osc]
<4> [<ffffffffa0919914>] ? osc_lock_discard_pages+0x144/0x240 [osc]
<4> [<ffffffffa09195f0>] ? discard_cb+0x0/0x1e0 [osc]
<4> [<ffffffffa090ff7b>] ? osc_lock_flush+0x8b/0x260 [osc]
<4> [<ffffffffa09103f8>] ? osc_ldlm_blocking_ast+0x2a8/0x3c0 [osc]
<4> [<ffffffffa050e9dc>] ? ldlm_cancel_callback+0x6c/0x170 [ptlrpc]
<4> [<ffffffffa052190a>] ? ldlm_cli_cancel_local+0x8a/0x470 [ptlrpc]
<4> [<ffffffffa0526540>] ? ldlm_cli_cancel+0x60/0x360 [ptlrpc]
<4> [<ffffffffa091022b>] ? osc_ldlm_blocking_ast+0xdb/0x3c0 [osc]
<4> [<ffffffffa052a440>] ? ldlm_handle_bl_callback+0x130/0x400 [ptlrpc]
<4> [<ffffffffa052af24>] ? ldlm_bl_thread_main+0x484/0x700 [ptlrpc]
<4> [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
<4> [<ffffffffa052aaa0>] ? ldlm_bl_thread_main+0x0/0x700 [ptlrpc]
<4> [<ffffffff810a101e>] ? kthread+0x9e/0xc0
<4> [<ffffffff8100c28a>] ? child_rip+0xa/0x20
<4> [<ffffffff810a0f80>] ? kthread+0x0/0xc0
<4> [<ffffffff8100c280>] ? child_rip+0x0/0x20
and another one, however don't know if it's related.
<3>LustreError: 4278:0:(ldlm_resource.c:835:ldlm_resource_complain()) testfs-OST0001-osc-ffff88003c715c00: namespace resource [0x302:0x0:0x0].0 (ffff880037015800) refcount non
zero (1) after lock cleanup; forcing cleanup.
<3>LustreError: 4278:0:(ldlm_resource.c:1450:ldlm_resource_dump()) — Resource: [0x302:0x0:0x0].0 (ffff880037015800) refcount = 2
<3>LustreError: 4278:0:(ldlm_resource.c:1453:ldlm_resource_dump()) Granted locks (in reverse order):
<3>LustreError: 4278:0:(ldlm_resource.c:1456:ldlm_resource_dump()) ### ### ns: testfs-OST0001-osc-ffff88003c715c00 lock: ffff880037269380/0x532f2161a177e283 lrc: 19/0,1 mode:
PW/PW res: [0x302:0x0:0x0].0 rrc: 2 type: EXT [0->18446744073709551615] (req 0->1048575) flags: 0x126400000000 nid: local remote: 0x59a587f3f1d100b5 expref: -99 pid: 4040 time
out: 0 lvb_type: 1
<3>LustreError: 790:0:(osc_io.c:1010:osc_req_attr_set()) page@ffff880022f02600[2 ffff88003be7db38 2 0 1 (null) ffff88003df849c0]
<3>
<3>LustreError: 789:0:(osc_io.c:1010:osc_req_attr_set()) page@ffff88003dfc8000[2 ffff88003be7db38 2 0 1 (null) ffff88003b3982c0]
<3>
<3>LustreError: 789:0:(osc_io.c:1010:osc_req_attr_set()) vvp-page@ffff88003dfc8068(0:0) vm@ffffea0000785428 2000000000282c 2:0 ffff88003dfc8000 19200 lru
<3>
<3>LustreError: 789:0:(osc_io.c:1010:osc_req_attr_set()) lov-page@ffff88003dfc80a8, raid0
<3>
<3>LustreError: 789:0:(osc_io.c:1010:osc_req_attr_set()) osc-page@ffff88003dfc8110 19200: 1< 0x845fed 258 0 + + > 2< 78643200 0 4096 0x5 0x520 | (null) ffff88003d970540 ffff88
003bc81e20 > 3< 1 12 0 > 4< 0 7 8 18446744073678077952 - | - - - - > 5< - - - - | 0 - | 0 - ->
<3>
<3>LustreError: 789:0:(osc_io.c:1010:osc_req_attr_set()) end page@ffff88003dfc8000
<3>
<3>LustreError: 789:0:(osc_io.c:1010:osc_req_attr_set()) uncovered page!
<3>LustreError: 789:0:(ldlm_resource.c:1450:ldlm_resource_dump()) — Resource: [0x302:0x0:0x0].0 (ffff880037015800) refcount = 3
<4>Pid: 789, comm: ptlrpcd_00_00
<4>
<4>Call Trace:
<4> [<ffffffffa021d875>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
<4> [<ffffffffa09133fa>] osc_req_attr_set+0x55a/0x720 [osc]
<4> [<ffffffffa0383829>] cl_req_attr_set+0xc9/0x220 [obdclass]
<4> [<ffffffffa0904082>] osc_build_rpc+0x882/0x12d0 [osc]
<4> [<ffffffffa091f623>] osc_io_unplug0+0x1133/0x1af0 [osc]
<4> [<ffffffffa0918428>] ? osc_ap_completion+0x1a8/0x550 [osc]
<4> [<ffffffffa0917a3e>] ? osc_extent_put+0xbe/0x260 [osc]
<4> [<ffffffffa0374f75>] ? lu_object_put+0x135/0x3b0 [obdclass]
<4> [<ffffffffa09224b0>] osc_io_unplug+0x10/0x20 [osc]
<4> [<ffffffffa0905593>] brw_interpret+0xac3/0x2320 [osc]
<4> [<ffffffffa0546ee2>] ? ptlrpc_unregister_bulk+0xa2/0xac0 [ptlrpc]
<4> [<ffffffffa053f4bc>] ? ptlrpc_unregister_reply+0x6c/0x810 [ptlrpc]
<4> [<ffffffffa053e2a4>] ? ptlrpc_send_new_req+0x154/0x980 [ptlrpc]
<4> [<ffffffffa0540551>] ptlrpc_check_set+0x331/0x1be0 [ptlrpc]
<4> [<ffffffffa056e443>] ptlrpcd_check+0x3d3/0x610 [ptlrpc]
<4> [<ffffffffa056e8fa>] ptlrpcd+0x27a/0x500 [ptlrpc]
<4> [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
<4> [<ffffffffa056e680>] ? ptlrpcd+0x0/0x500 [ptlrpc]
<4> [<ffffffff810a101e>] kthread+0x9e/0xc0
<4> [<ffffffff8100c28a>] child_rip+0xa/0x20
<4> [<ffffffff810a0f80>] ? kthread+0x0/0xc0
<4> [<ffffffff8100c280>] ? child_rip+0x0/0x20
<4>
<0>LustreError: 789:0:(osc_io.c:1020:osc_req_attr_set()) LBUG
<4>Pid: 789, comm: ptlrpcd_00_00
<4>
<4>Call Trace:
<4> [<ffffffffa021d875>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
<4> [<ffffffffa021de77>] lbug_with_loc+0x47/0xb0 [libcfs]
<4> [<ffffffffa0913410>] osc_req_attr_set+0x570/0x720 [osc]
<4> [<ffffffffa0383829>] cl_req_attr_set+0xc9/0x220 [obdclass]
<4> [<ffffffffa0904082>] osc_build_rpc+0x882/0x12d0 [osc]
<4> [<ffffffffa091f623>] osc_io_unplug0+0x1133/0x1af0 [osc]
<4> [<ffffffffa0918428>] ? osc_ap_completion+0x1a8/0x550 [osc]
<4> [<ffffffffa0917a3e>] ? osc_extent_put+0xbe/0x260 [osc]
<4> [<ffffffffa0374f75>] ? lu_object_put+0x135/0x3b0 [obdclass]
<4> [<ffffffffa09224b0>] osc_io_unplug+0x10/0x20 [osc]
<4> [<ffffffffa0905593>] brw_interpret+0xac3/0x2320 [osc]
<4> [<ffffffffa0546ee2>] ? ptlrpc_unregister_bulk+0xa2/0xac0 [ptlrpc]
<4> [<ffffffffa053f4bc>] ? ptlrpc_unregister_reply+0x6c/0x810 [ptlrpc]
<4> [<ffffffffa053e2a4>] ? ptlrpc_send_new_req+0x154/0x980 [ptlrpc]
<4> [<ffffffffa0540551>] ptlrpc_check_set+0x331/0x1be0 [ptlrpc]
<4> [<ffffffffa056e443>] ptlrpcd_check+0x3d3/0x610 [ptlrpc]
<4> [<ffffffffa056e8fa>] ptlrpcd+0x27a/0x500 [ptlrpc]
<4> [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
<4> [<ffffffffa056e680>] ? ptlrpcd+0x0/0x500 [ptlrpc]
<4> [<ffffffff810a101e>] kthread+0x9e/0xc0
<4> [<ffffffff8100c28a>] child_rip+0xa/0x20
<4> [<ffffffff810a0f80>] ? kthread+0x0/0xc0
<4> [<ffffffff8100c280>] ? child_rip+0x0/0x20
|
|
Jinshan Xiong (jinshan.xiong@intel.com) uploaded a new patch: http://review.whamcloud.com/16456
Subject: LU-6271 osc: further OSC cleanup after eviction
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 9dd22234a098bb2bea26c4694d91edc928e027ac
|
|
Hi Dongyang,
Please try patch 16456 and see if it can fix the problem.
Jinshan
|
|
Hi Jinshan,
I'm using master which has 14989 landed already, plus patch set 3 of 16456:
The client crashed 5mins after I started the reproducer:
Sep 18 13:29:00 client kernel: LustreError: 16824:0:(ldlm_resource.c:887:ldlm_resource_complain()) testfs-OST0000-osc-ffff8800375c4000: namespace resource [0x303:0x0:0x0].0 (ffff88003d2abcc0) refcount nonzero (1) after lock cleanup; forcing cleanup.
Sep 18 13:29:00 client kernel: LustreError: 16824:0:(ldlm_resource.c:1502:ldlm_resource_dump()) — Resource: [0x303:0x0:0x0].0 (ffff88003d2abcc0) refcount = 3
Sep 18 13:29:00 client kernel: LustreError: 16824:0:(ldlm_resource.c:1505:ldlm_resource_dump()) Granted locks (in reverse order):
Sep 18 13:29:00 client kernel: LustreError: 16824:0:(ldlm_resource.c:1508:ldlm_resource_dump()) ### ### ns: testfs-OST0000-osc-ffff8800375c4000 lock: ffff88000b69d380/0x2104da78ff029aa9 lrc: 8/0,1 mode: PW/PW res: [0x303:0x0:0x0].0 rrc: 3 type: EXT [0->18446744073709551615] (req 0->1048575) flags: 0x126400000000 nid: local remote: 0x59a587f3f1d1d697 expref: -99 pid: 16588 timeout: 0 lvb_type: 1
Sep 18 13:29:00 client kernel: LustreError: 16824:0:(ldlm_resource.c:1502:ldlm_resource_dump()) — Resource: [0x303:0x0:0x0].0 (ffff88003d2abcc0) refcount = 2
Sep 18 13:29:00 client kernel: LustreError: 16824:0:(ldlm_resource.c:1505:ldlm_resource_dump()) Granted locks (in reverse order):
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:3134:discard_cb()) page@ffff88003d5a7600[3 ffff88003a513b38 1 0 1 ffff88003a5d6b78]
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:3134:discard_cb()) vvp-page@ffff88003d5a7650(0:0) vm@ffffea00004439e0 2000000000087d 3:0 ffff88003d5a7600 25088 lru
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:3134:discard_cb()) lov-page@ffff88003d5a7690, raid0
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:3134:discard_cb()) osc-page@ffff88003d5a76f8 25088: 1< 0x845fed 258 0 + - > 2< 102760448 0 4096 0x0 0x520 | (null) ffff88003c479500 ffff88003a517e20 > 3< 1 0 0 > 4< 0 9 8 18446744073642434560 + | + - + - > 5< + - + - | 0 - | 5635 - ->
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:3134:discard_cb()) end page@ffff88003d5a7600
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:3134:discard_cb()) discard dirty page?
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:2447:osc_teardown_async_page()) extent ffff880039a18720@
{[25088 -> 25341/25343], [2|0|+|locking|wi|ffff88003a517e20], [1040384|254|+|-|ffff88000b69d580|256|ffff8800372b3520]}
trunc at 25088.
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_cache.c:2447:osc_teardown_async_page()) ### extent: ffff880039a18720
Sep 18 13:29:01 client kernel: ns: testfs-OST0000-osc-ffff8800375c4000 lock: ffff88000b69d580/0x2104da78ff029c0e lrc: 41/0,3 mode: PW/PW res: [0x303:0x0:0x0].0 rrc: 2 type: EXT [0->18446744073709551615] (req 102760448->103809023) flags: 0x20000000000 nid: local remote: 0x59a587f3f1d1d6ac expref: -99 pid: 16683 timeout: 0 lvb_type: 1
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:307:osc_page_delete()) page@ffff88003d5a7600[3 ffff88003a513b38 4 0 1 (null)]
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:307:osc_page_delete()) vvp-page@ffff88003d5a7650(0:0) vm@ffffea00004439e0 2000000000087d 3:0 ffff88003d5a7600 25088 lru
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:307:osc_page_delete()) lov-page@ffff88003d5a7690, raid0
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:307:osc_page_delete()) osc-page@ffff88003d5a76f8 25088: 1< 0x845fed 258 0 + - > 2< 102760448 0 4096 0x0 0x520 | (null) ffff88003c479500 ffff88003a517e20 > 3< 0 0 0 > 4< 0 9 8 18446744073642434560 + | + - + - > 5< + - + - | 0 - | 5635 - ->
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:307:osc_page_delete()) end page@ffff88003d5a7600
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:307:osc_page_delete()) Trying to teardown failed: -16
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:308:osc_page_delete()) ASSERTION( 0 ) failed:
Message from syslogd@client at Sep 18 13:29:01 ...
kernel:LustreError: 13392:0:(osc_page.c:308:osc_page_delete()) ASSERTION( 0 ) failed:
Sep 18 13:29:01 client kernel: LustreError: 13392:0:(osc_page.c:308:osc_page_delete()) LBUG
Sep 18 13:29:01 client kernel: Pid: 13392, comm: ldlm_bl_00
Sep 18 13:29:01 client kernel:
Sep 18 13:29:01 client kernel: Call Trace:
Sep 18 13:29:01 client kernel: [<ffffffffa10ad875>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
Sep 18 13:29:01 client kernel: [<ffffffffa10ade77>] lbug_with_loc+0x47/0xb0 [libcfs]
Sep 18 13:29:01 client kernel: [<ffffffffa178bf9e>] osc_page_delete+0x46e/0x4e0 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa12019cd>] cl_page_delete0+0x7d/0x210 [obdclass]
Sep 18 13:29:01 client kernel: [<ffffffffa1201b9d>] cl_page_delete+0x3d/0x110 [obdclass]
Sep 18 13:29:01 client kernel: [<ffffffffa16b6d2d>] ll_invalidatepage+0x8d/0x160 [lustre]
Sep 18 13:29:01 client kernel: [<ffffffffa16c5d85>] vvp_page_discard+0xc5/0x160 [lustre]
Sep 18 13:29:01 client kernel: [<ffffffffa11fffc8>] cl_page_invoid+0x68/0x160 [obdclass]
Sep 18 13:29:01 client kernel: [<ffffffffa12000d3>] cl_page_discard+0x13/0x20 [obdclass]
Sep 18 13:29:01 client kernel: [<ffffffffa1797158>] discard_cb+0x88/0x1e0 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa1796f4e>] osc_page_gang_lookup+0x1ae/0x330 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa17970d0>] ? discard_cb+0x0/0x1e0 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa17973f4>] osc_lock_discard_pages+0x144/0x240 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa17970d0>] ? discard_cb+0x0/0x1e0 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa178e45b>] osc_lock_flush+0x8b/0x260 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa178e8d8>] osc_ldlm_blocking_ast+0x2a8/0x3c0 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa138ea57>] ldlm_cancel_callback+0x87/0x280 [ptlrpc]
Sep 18 13:29:01 client kernel: [<ffffffff81060530>] ? __dequeue_entity+0x30/0x50
Sep 18 13:29:01 client kernel: [<ffffffff8100969d>] ? __switch_to+0x7d/0x340
Sep 18 13:29:01 client kernel: [<ffffffffa13a184a>] ldlm_cli_cancel_local+0x8a/0x470 [ptlrpc]
Sep 18 13:29:01 client kernel: [<ffffffffa13a6480>] ldlm_cli_cancel+0x60/0x360 [ptlrpc]
Sep 18 13:29:01 client kernel: [<ffffffffa178e70b>] osc_ldlm_blocking_ast+0xdb/0x3c0 [osc]
Sep 18 13:29:01 client kernel: [<ffffffffa13aa380>] ldlm_handle_bl_callback+0x130/0x400 [ptlrpc]
Sep 18 13:29:01 client kernel: [<ffffffffa13aae64>] ldlm_bl_thread_main+0x484/0x700 [ptlrpc]
Sep 18 13:29:01 client kernel: [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
Sep 18 13:29:01 client kernel: [<ffffffffa13aa9e0>] ? ldlm_bl_thread_main+0x0/0x700 [ptlrpc]
Sep 18 13:29:01 client kernel: [<ffffffff810a101e>] kthread+0x9e/0xc0
Sep 18 13:29:01 client kernel: [<ffffffff8100c28a>] child_rip+0xa/0x20
|
|
Hi Dongyang,
it certainly lasted longer on my VM node 
Please upload your reproducer and I will restart working on this issue once I get access to a real hardware.
Thanks,
|
|
Hi Jinshan,
Hardware shouldn't matter as I'm reproducing it on my VMs.
Here are the scripts I used.
On client, I'm using IOR and when IOR dies because of eviction, just bring up new ones:
#!/bin/sh
while true
do
num=$(ps aux | grep IOR | wc -l)
while [ $num -lt 20 ]
do
/root/IOR/src/C/IOR -b 8g -w -e -E -t 1m -v -k -o /mnt/testfile &
num=$(ps aux | grep IOR | wc -l)
done
sleep 1
done
Here I got 20 of them running at the same time.
On the OSS:
#!/bin/sh
while true
do
for ost in /proc/fs/lustre/obdfilter/*
do
if [ -n $(cat $ost/exports/<your client nid>/uuid) ]
then
echo $(cat $ost/exports/<your client nid>/uuid) > $ost/evict_client
fi
done
sleep 10
done
As you can see I'm evicting the client over and over, and I'm using 10secs as the interval. Again you can change this.
Thanks
Dongyang
|
|
I did very similar thing with iozone but they wrote to different files, let me try your reproducer.
|
|
Please check the new patch and see if it can fix the problem.
|
|
OK I've been running the scripts with patchset 5 of 16456 for some time, seems the general IO is fine.
But when I tried the group lock, the client crashed immediately after eviction:
<0>LustreError: 1697:0:(osc_cache.c:2907:osc_cache_writeback_range()) ASSERTION( !ext->oe_hp ) failed:
<0>LustreError: 1697:0:(osc_cache.c:2907:osc_cache_writeback_range()) LBUG
<4>Pid: 1697, comm: ldlm_bl_11
<4>
<4>Call Trace:
<4> [<ffffffffa021d875>] libcfs_debug_dumpstack+0x55/0x80 [libcfs]
<4> [<ffffffffa021de77>] lbug_with_loc+0x47/0xb0 [libcfs]
<4> [<ffffffffa0922085>] osc_cache_writeback_range+0x1275/0x1280 [osc]
<4> [<ffffffffa090b545>] osc_lock_flush+0x175/0x260 [osc]
<4> [<ffffffffa090b8d8>] osc_ldlm_blocking_ast+0x2a8/0x3c0 [osc]
<4> [<ffffffffa050ba57>] ldlm_cancel_callback+0x87/0x280 [ptlrpc]
<4> [<ffffffff81060530>] ? __dequeue_entity+0x30/0x50
<4> [<ffffffff8100969d>] ? __switch_to+0x7d/0x340
<4> [<ffffffffa051e84a>] ldlm_cli_cancel_local+0x8a/0x470 [ptlrpc]
<4> [<ffffffffa05234bc>] ldlm_cli_cancel+0x9c/0x3e0 [ptlrpc]
<4> [<ffffffffa090b70b>] osc_ldlm_blocking_ast+0xdb/0x3c0 [osc]
<4> [<ffffffff810672c2>] ? default_wake_function+0x12/0x20
<4> [<ffffffffa0527400>] ldlm_handle_bl_callback+0x130/0x400 [ptlrpc]
<4> [<ffffffffa0527ee4>] ldlm_bl_thread_main+0x484/0x700 [ptlrpc]
<4> [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
<4> [<ffffffffa0527a60>] ? ldlm_bl_thread_main+0x0/0x700 [ptlrpc]
<4> [<ffffffff810a101e>] kthread+0x9e/0xc0
<4> [<ffffffff8100c28a>] child_rip+0xa/0x20
<4> [<ffffffff810a0f80>] ? kthread+0x0/0xc0
<4> [<ffffffff8100c280>] ? child_rip+0x0/0x20
<4>
<0>Kernel panic - not syncing: LBUG
<4>Pid: 1697, comm: ldlm_bl_11 Not tainted 2.6.32-573.3.1.el6.x86_64 #1
<4>Call Trace:
<4> [<ffffffff81537c54>] ? panic+0xa7/0x16f
<4> [<ffffffffa021decb>] ? lbug_with_loc+0x9b/0xb0 [libcfs]
<4> [<ffffffffa0922085>] ? osc_cache_writeback_range+0x1275/0x1280 [osc]
<4> [<ffffffffa090b545>] ? osc_lock_flush+0x175/0x260 [osc]
<4> [<ffffffffa090b8d8>] ? osc_ldlm_blocking_ast+0x2a8/0x3c0 [osc]
<4> [<ffffffffa050ba57>] ? ldlm_cancel_callback+0x87/0x280 [ptlrpc]
<4> [<ffffffff81060530>] ? __dequeue_entity+0x30/0x50
<4> [<ffffffff8100969d>] ? __switch_to+0x7d/0x340
<4> [<ffffffffa051e84a>] ? ldlm_cli_cancel_local+0x8a/0x470 [ptlrpc]
<4> [<ffffffffa05234bc>] ? ldlm_cli_cancel+0x9c/0x3e0 [ptlrpc]
<4> [<ffffffffa090b70b>] ? osc_ldlm_blocking_ast+0xdb/0x3c0 [osc]
<4> [<ffffffff810672c2>] ? default_wake_function+0x12/0x20
<4> [<ffffffffa0527400>] ? ldlm_handle_bl_callback+0x130/0x400 [ptlrpc]
<4> [<ffffffffa0527ee4>] ? ldlm_bl_thread_main+0x484/0x700 [ptlrpc]
<4> [<ffffffff810672b0>] ? default_wake_function+0x0/0x20
<4> [<ffffffffa0527a60>] ? ldlm_bl_thread_main+0x0/0x700 [ptlrpc]
<4> [<ffffffff810a101e>] ? kthread+0x9e/0xc0
<4> [<ffffffff8100c28a>] ? child_rip+0xa/0x20
<4> [<ffffffff810a0f80>] ? kthread+0x0/0xc0
<4> [<ffffffff8100c280>] ? child_rip+0x0/0x20
|
|
Hi Dongyang, please upload your test cases.
|
|
Hi Jinshan,
See my comment earlier on 28/Jul/15 8:39 PM.
|
|
Thanks. Please check if the latest patch can fix the problem
|
|
With patch set 6 pf 16456, the client won't crash with the gplck reproducer and single eviction.
However, the client crashes if:
1. run the gplck reproducer, evict the client once.
2. after client reconnects, don't kill the gplck, run another instance of gplck with a different gid.
3. evict the client again, the client crashes with the same stack trace ASSERTION( !ext->oe_hp ) failed
This makes me think that the problem should be fixed in the ldlm layer like http://review.whamcloud.com/#/c/14915/
not in the osc layer.
Thanks
Dongyang
|
|
Hi Dongyang, the problem may be fixed in patch set 7 but feel free to use patch 14915 on your own site.
|
|
this problem can only happen at eviction so even patch 14989 is good enough for daily use.
|
|
Hi Dongyang, I took a look at your latest patch 14915 and I suggest you shouldn't apply this patch to your own site because it's not production ready yet.
|
|
Oleg Drokin (oleg.drokin@intel.com) merged in patch http://review.whamcloud.com/16456/
Subject: LU-6271 osc: further OSC cleanup after eviction
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: e8b421531c166b91ab5c1f417570c544bcdd050c
|
|
Jinshan Xiong (jinshan.xiong@intel.com) uploaded a new patch: http://review.whamcloud.com/16727
Subject: LU-6271 osc: check oo_npages inside spin lock
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: e220fbbfa93069a783430d15a26dc3518006bc1c
|
|
Oleg Drokin (oleg.drokin@intel.com) merged in patch http://review.whamcloud.com/16727/
Subject: LU-6271 osc: faulty assertion in osc_object_prune()
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: c5e84d53198142919b526fd304c6782005e38bdb
|
|
Landed for 2.8
|
|
This bug is not resolved. At a customer site today, one of the issues reported with the patch series was reproduced:
Here is the gathered information from one of the engineers:
Nov 13 21:22:32 r2i1n4 kernel: [41261.553520] LustreError: 11-0: work-OST0018-osc-ffff880f4a556c00: Communicating with 10.148.254.146@o2ib, operation obd_ping failed with -107.
Nov 13 21:22:32 r2i1n4 kernel: [41261.553537] Lustre: work-OST0018-osc-ffff880f4a556c00: Connection to work-OST0018 (at 10.148.254.146@o2ib) was lost; in progress operations using this service will wait for recovery to complete
Nov 13 21:22:32 r2i1n4 kernel: [41261.553744] LustreError: 167-0: work-OST0018-osc-ffff880f4a556c00: This client was evicted by work-OST0018; in progress operations using this service will fail.
Nov 13 21:22:19 oss3 kernel: LustreError: 0:0:(ldlm_lockd.c:344:waiting_locks_callback()) ### lock callback timer expired after 100s: evicting client at 10.148.4.3@o2ib ns: filter-work-OST0018_UUID lock: ffff881bf46fa1c0/0x1b850f2869999e97 lrc: 3/0,0 mode: PW/PW res: [0xcc6a24:0x0:0x0].0 rrc: 31 type: EXT [0->18446744073709551615] (req 0->18446744073709551615) flags: 0x60000080010020 nid: 10.148.4.3@o2ib remote: 0x7a3c9c39e0502fcc expref: 5 pid: 20187 timeout: 4335795111 lvb_type: 0
r2i1n4:~ # lctl dl
0 UP mgc MGC10.148.254.141@o2ib 2dc4c54f-dab6-1190-fca7-d7747093f936 5
…
35 UP osc work-OST0017-osc-ffff880f4a556c00 9d007967-5de8-eb2e-eaf9-99d4b17d74e6 5
36 IN osc work-OST0018-osc-ffff880f4a556c00 9d007967-5de8-eb2e-eaf9-99d4b17d74e6 5
37 UP osc work-OST0019-osc-ffff880f4a556c00 9d007967-5de8-eb2e-eaf9-99d4b17d74e6 5
r2i1n4:~ # lctl --device 36 activate
error: activate: failed: Invalid argument
r2i1n4:~ # cat /proc/fs/lustre/osc/work-OST0018-osc-ffff880f4a556c00/import
import:
name: work-OST0018-osc-ffff880f4a556c00
target: work-OST0018_UUID
state: EVICTED
instance: 21
connect_flags: [ write_grant, server_lock, version, request_portal, truncate_lock, max_byte_per_rpc, early_lock_cancel, adaptive_timeouts, alt_checksum_algorithm, fid_is_enabled, version_recovery, full20, layout_lock, 64bithash, object_max_bytes, jobstats, einprogress, lvb_type]
import_flags: [ invalid, replayable, pingable, connect_tried ]
connection:
failover_nids: [ 10.148.254.146@o2ib, 10.148.254.147@o2ib ]
current_connection: 10.148.254.146@o2ib
connection_attempts: 2
generation: 2
in-progress_invalidations: 1
rpcs:
inflight: 0
unregistering: 0
timeouts: 0
avg_waittime: 803 usec
service_estimates:
services: 1 sec
network: 1 sec
transactions:
last_replay: 0
peer_committed: 90194391109
last_checked: 90194391109
read_data_averages:
bytes_per_rpc: 19550
usec_per_rpc: 938
MB_per_sec: 20.84
write_data_averages:
bytes_per_rpc: 508
usec_per_rpc: 5386
MB_per_sec: 0.09
r2i1n4:~ # ps -ef | grep ll_imp_inval
root 832 2 0 Nov13 ? 00:00:00 [ll_imp_inval]
root 25849 25765 0 14:18 pts/0 00:00:00 grep ll_imp_inval
Nov 16 14:22:19 r2i1n4 kernel: [274907.717827] ll_imp_inval S ffff881ffc253b00 0 832 2 0x00000000
Nov 16 14:22:19 r2i1n4 kernel: [274907.717832] ffff881ffc34dc50 0000000000000046 ffff881ffc34c010 0000000000010900
Nov 16 14:22:19 r2i1n4 kernel: [274907.717838] 0000000000010900 0000000000010900 0000000000010900 ffff881ffc34dfd8
Nov 16 14:22:19 r2i1n4 kernel: [274907.717845] ffff881ffc34dfd8 0000000000010900 ffff881fd7ffa580 ffff881020f2c300
Nov 16 14:22:19 r2i1n4 kernel: [274907.717852] Call Trace:
Nov 16 14:22:19 r2i1n4 kernel: [274907.717879] [<ffffffffa0bcf361>] osc_object_invalidate+0x1c1/0x280 [osc]
Nov 16 14:22:19 r2i1n4 kernel: [274907.717907] [<ffffffffa0bb5bae>] osc_ldlm_resource_invalidate+0xae/0x170 [osc]
Nov 16 14:22:19 r2i1n4 kernel: [274907.717930] [<ffffffffa0716d68>] cfs_hash_for_each_relax+0x178/0x340 [libcfs]
Nov 16 14:22:19 r2i1n4 kernel: [274907.717971] [<ffffffffa0718fc0>] cfs_hash_for_each_nolock+0x70/0x1c0 [libcfs]
Nov 16 14:22:19 r2i1n4 kernel: [274907.718008] [<ffffffffa0bc989c>] osc_import_event+0xfac/0x1420 [osc]
Nov 16 14:22:19 r2i1n4 kernel: [274907.718064] [<ffffffffa0a88592>] ptlrpc_invalidate_import+0x292/0x890 [ptlrpc]
Nov 16 14:22:19 r2i1n4 kernel: [274907.718151] [<ffffffffa0a8a702>] ptlrpc_invalidate_import_thread+0x42/0x2e0 [ptlrpc]
Nov 16 14:22:19 r2i1n4 kernel: [274907.718197] [<ffffffff810843f6>] kthread+0x96/0xa0
Nov 16 14:22:19 r2i1n4 kernel: [274907.718205] [<ffffffff8146f364>] kernel_thread_helper+0x4/0x10
|
|
client messages
|
|
server message
|
|
uploaded 2 logs file detailing the problem, customer is running the ddn-ieel branch 2.5.39-ddn7.
|
|
In short, clients were evicted suddenly and the OSTs stayed INACTIVE for those clients until the clients were restarted forcibly.
|
|
NOTE: the 2.5.39-ddn7 has the patches:
20401c7 LU-6271 osc: faulty assertion in osc_object_prune()
b08341e LU-6271 osc: further OSC cleanup after eviction
42e9257 LU-6271 osc: handle osc eviction correctly
I think we should seriously consider using patch (written by Dongyang Li):
http://review.whamcloud.com/#/c/14915/
I am going to test the above patch at NCI, where we are able to reproduce the crash and inactive OST (due to client eviction)...
|
|
From the log, obviously the root cause was a deadlock problem. It has nothing to do with these patches.
You could try patch 14915 but most likely you're going to end up with the same problem.
|
|
From the backtrace, the truncate process was waiting for i_alloc_sem while holding inode mutex but nobody should have held i_alloc_sem from the stack. Unfortunately I don't have a sle11-sp3 kernel source code on hand otherwise I could take a look.
One alternative way is to get a kernel dump when you see this problem and search the variable address of alloc_sem probably you can find it on some proc's stack.
|
|
To nip this in the bud - it seems like any ongoing work should move to a new ticket...
|
To nip this in the bud - it seems like any ongoing work should move to a new ticket...
To be clear, the customer was using a build with their own patches, there is no evidence that this issue can be seen on master.
|
Generated at Sat Feb 10 01:58:46 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.
iwc189.lbug.log.txt.gz
iwc260.log.gz