thr3ads.net - Lustre discuss - [Lustre-discuss] Lustre client lockups [Nov 2008]

If this information is useful, please help other people find it:
Share via:

Kurt Dillen

2008-Nov-04 17:06 UTC

[Lustre-discuss] Lustre client lockups

Hello all,

We have a serious problem with lustre.  Since a few days we have
lockups on the client side.  Not all clients are having this
problem.

We are running this kernel  2.6.16-54-0.2.5_lustre.1.6.4.3smp.

The statahead disable is done on the systems.

Some more information about the environment:

- Lustre clients are all vmware virtual systems
- Lustre Farm are all vmware virtual systems

the errors I see are the following:

LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e5dca000
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e519e000
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e4e0a000
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e86b1bc0
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e79fe5c0
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e70a88c0
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e7081280
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100e6d6d5c0
LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225816920, 100s ago)  req at ffff8100e7e2ba00 x17940/t0
o4->lustre-OST0005_UUID at 172.16.0.29@tcp:28 lens 384/352 ref 2 fl Rpc:/
0/0 rc 0/-22
Lustre: lustre-OST0005-osc-ffff8100e8551800: Connection to service
lustre-OST0005 via nid 172.16.0.29 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-OST0005-osc-ffff8100e8551800: Connection restored to
service lustre-OST0005 using nid 172.16.0.29 at tcp.
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225816924, 100s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/0/0 rc 0/-22
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) Skipped
2 previous similar messages
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225816953, 100s ago)  req at ffff8100e7e2d800 x20560/t0
o4->lustre-OST0006_UUID at 172.16.0.30@tcp:28 lens 384/352 ref 2 fl Rpc:/
0/0 rc 0/-22
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection to service
lustre-OST0006 via nid 172.16.0.30 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection restored to
service lustre-OST0006 using nid 172.16.0.30 at tcp.
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817024, 100s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/2/0 rc -11/-22
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817053, 100s ago)  req at ffff8100e7e2d800 x20724/t0
o4->lustre-OST0006_UUID at 172.16.0.30@tcp:28 lens 384/352 ref 2 fl Rpc:/
2/0 rc -11/-22
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection to service
lustre-OST0006 via nid 172.16.0.30 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection restored to
service lustre-OST0006 using nid 172.16.0.30 at tcp.
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817124, 100s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/2/0 rc -11/-22
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817153, 100s ago)  req at ffff8100e7e2d800 x20767/t0
o4->lustre-OST0006_UUID at 172.16.0.30@tcp:28 lens 384/352 ref 2 fl Rpc:/
2/0 rc -11/-22
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection to service
lustre-OST0006 via nid 172.16.0.30 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection restored to
service lustre-OST0006 using nid 172.16.0.30 at tcp.
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817224, 100s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/2/0 rc -11/-22
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817324, 100s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/2/0 rc -11/-22
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) Skipped
1 previous similar message
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: Skipped 1 previous similar message
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
Lustre: Skipped 1 previous similar message
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817424, 100s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/2/0 rc -11/-22
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) Skipped
1 previous similar message
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: Skipped 1 previous similar message
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
Lustre: Skipped 1 previous similar message
LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817553, 100s ago)  req at ffff8100e7e2d800 x20952/t0
o4->lustre-OST0006_UUID at 172.16.0.30@tcp:28 lens 384/352 ref 2 fl Rpc:/
2/0 rc -11/-22
LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) Skipped
2 previous similar messages
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection to service
lustre-OST0006 via nid 172.16.0.30 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: Skipped 2 previous similar messages
Lustre: lustre-OST0006-osc-ffff8100e8551800: Connection restored to
service lustre-OST0006 using nid 172.16.0.30 at tcp.
Lustre: Skipped 2 previous similar messages
LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
0, status -5, desc ffff8100efba6800
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) @@@
timeout (sent at 1225817824, 99s ago)  req at ffff8100e64b3a00 x19702/t0
o36->lustre-MDT0000_UUID at 172.16.0.22@tcp:12 lens 1544/296 ref 1 fl
Rpc:/2/0 rc -11/-22
LustreError: 3602:0:(client.c:975:ptlrpc_expire_one_request()) Skipped
4 previous similar messages
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection to service
lustre-MDT0000 via nid 172.16.0.22 at tcp was lost; in progress
operations using this service will wait for recovery to complete.
Lustre: Skipped 4 previous similar messages
Lustre: lustre-MDT0000-mdc-ffff8100e8551800: Connection restored to
service lustre-MDT0000 using nid 172.16.0.22 at tcp.
Lustre: Skipped 4 previous similar messages

Could somebody help me out ?

Thanks in advance.

Kurt

Brian J. Murrell

2008-Nov-05 20:22 UTC

head link

[Lustre-discuss] Lustre client lockups

On Tue, 2008-11-04 at 09:06 -0800, Kurt Dillen wrote:> 
> Some more information about the environment:
> 
> - Lustre clients are all vmware virtual systems
> - Lustre Farm are all vmware virtual systems
Hrm.  That is a bit of a red flag right there.
> the errors I see are the following:
> 
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e5dca000
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e519e000
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e4e0a000
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e86b1bc0
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e79fe5c0
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e70a88c0
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e7081280
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e6d6d5c0
> LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
> timeout (sent at 1225816920, 100s ago)  req at ffff8100e7e2ba00 x17940/t0
> o4->lustre-OST0005_UUID at 172.16.0.29@tcp:28 lens 384/352 ref 2 fl
Rpc:/
> 0/0 rc 0/-22
> Lustre: lustre-OST0005-osc-ffff8100e8551800: Connection to service
> lustre-OST0005 via nid 172.16.0.29 at tcp was lost; in progress
> operations using this service will wait for recovery to complete.
> Lustre: lustre-OST0005-osc-ffff8100e8551800: Connection restored to
> service lustre-OST0005 using nid 172.16.0.29 at tcp.
These are just regular timeouts with nothing really to explain them.  A
detailed log analysis of all of your server logs (not something we can
do here on lustre-discuss) might yield more but I have suspicions about
your vmware-farm set up.  Running VMs, all competing for the same host
resources makes the environment unpredictable.

I''m not sure if you are using host-only or bridged networking but my
(now quite historic) experience with running lots of vmware machines on
a single piece of hardware is that the host-only network is less than
robust and the memory rquirements of running many VMs on a single
machine are demanding.  Additionally, if you have many OSTs all sharing
the same physical disk, you will have further contention there.
Timeouts are not surprising.

I would also encourage you to try 1.6.6 now that it is out.  I would
also encourage you to get some baseline performance metrics of all of
this virtual hardware with our iokit.

b.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 197 bytes
Desc: This is a digitally signed message part
Url :
http://lists.lustre.org/pipermail/lustre-discuss/attachments/20081105/b6a8f419/attachment.bin

Andreas Dilger

2008-Nov-06 17:23 UTC

head link

[Lustre-discuss] Lustre client lockups

On Nov 04, 2008  09:06 -0800, Kurt Dillen wrote:> We have a serious problem with lustre.  Since a few days we have
> lockups on the client side.  Not all clients are having this
> problem.
> 
> We are running this kernel  2.6.16-54-0.2.5_lustre.1.6.4.3smp.
> 
> The statahead disable is done on the systems.
> 
> Some more information about the environment:
> 
> - Lustre clients are all vmware virtual systems
> - Lustre Farm are all vmware virtual systems
> 
> the errors I see are the following:
> 
> LustreError: 3420:0:(events.c:134:client_bulk_callback()) event type
> 0, status -5, desc ffff8100e5dca000
> LustreError: 3428:0:(client.c:975:ptlrpc_expire_one_request()) @@@
> timeout (sent at 1225816920, 100s ago)  req at ffff8100e7e2ba00 x17940/t0
> o4->lustre-OST0005_UUID at 172.16.0.29@tcp:28 lens 384/352 ref 2 fl
Rpc:/
> 0/0 rc 0/-22
> Lustre: lustre-OST0005-osc-ffff8100e8551800: Connection to service
> lustre-OST0005 via nid 172.16.0.29 at tcp was lost; in progress
> operations using this service will wait for recovery to complete.
These all look like network problems.  Running production Lustre servers
inside a vmware doesn''t make much sense.  We don''t test
clients inside
vmware, but I don''t think that is nearly as bad as running the servers
in a virtual environment.

Cheers, Andreas
--
Andreas Dilger
Sr. Staff Engineer, Lustre Group
Sun Microsystems of Canada, Inc.

Lustre discuss - Nov 2008 - Lustre client lockups

[Lustre-discuss] Lustre client lockups

[Lustre-discuss] Lustre client lockups

[Lustre-discuss] Lustre client lockups