thr3ads.net - Lustre discuss - [Lustre-discuss] IOR Single File -- lock callback timer expired [Dec 2008]

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

Roger Spellman

2008-Dec-10 18:21 UTC

[Lustre-discuss] IOR Single File -- lock callback timer expired

I have a customer running IOR on 128 clients, using IOR''s POSIX mode to
create a single file.  

The clients are running Lustre 1.6.6.  The servers are running Lustre
1.6.5.

 

The following is the IOR output:

 

    /usr/bin/lfs setstripe /scratch1/test/bm_runs 2097152 -1 18 

    IOR-2.10.1: MPI Coordinated Test of Parallel I/O

 

    Run began: Tue Dec  9 09:19:37 2008

    Command line used: /home/test/IOR/bin/IOR-2.10.1 -b 32g -t 1m -i 1
-a POSIX -E -g -C -w -r -v -d 2 -o
/scratch1/test/bm_runs/IOR.stripe.18.1

    Machine: Linux whitney160

    Start time skew across all tasks: 0.02 sec

    Path: /scratch1/test/bm_runs

    FS: 118.7 TiB   Used FS: 2.6%   Inodes: 300.5 Mi   Used Inodes: 0.0%

    Participating tasks: 128

    Using reorderTasks ''-C'' (expecting block, not cyclic, task
assignment)

 

    Summary:

        api                = POSIX

        test filename      = /scratch1/test/bm_runs/IOR.stripe.18.1

        access             = single-shared-file

        pattern            = segmented (1 segment)

        ordering           = sequential offsets

        clients            = 128 (1 per node)

        repetitions        = 1

        xfersize           = 1 MiB

        blocksize          = 32 GiB

        aggregate filesize = 4096 GiB

 

    delaying 2 seconds . . .

    Commencing write performance test.

    Tue Dec  9 09:19:39 2008

 

    ** error **

    ERROR in aiori-POSIX.c (line 247): transfer failed.

    ERROR: No locks available

    ** exiting **

    [whitney287:07469] MPI_ABORT invoked on rank 127 in communicator
MPI_COMM_WORLD with errorcode -1

    mpiexec noticed that job rank 0 with PID 7520 on node whitney160
exited on signal 42 (Real-time signal 8).

    110 additional processes aborted (not shown)

    16 processes killed (possibly by Open MPI)

    

Looking at the logs on the servers, I see a bunch of messages like the
following:

 

Dec  9 18:23:38 ts-sandia-02 kernel: LustreError:
0:0:(ldlm_lockd.c:234:waiting_locks_callback()) ### lock callback timer
expired after 116s: evicting client at 192.168.121.32 at o2ib  ns:
filter-scratch-OST0000_UUID lock: ffff810014239600/0x6316855aa9d9f014
lrc: 1/0,0 mode: PW/PW res: 5987/0 rrc: 373 type: EXT
[1409286144->1442840575] (req 1409286144->1410334719) flags: 2

0 remote: 0x77037709d529258a expref: 28 pi

 

What might be causing this?

 

Can I fix this problem by extending timers, such as
/proc/sys/lustre/timeout and /proc/sys/lustre/ldlm_timeout ?

 

Are there other timers I can try?

 

 

Thanks for your help.

 

Roger Spellman

Staff Engineer

Terascala, Inc.

508-588-1501

-------------- next part --------------
An HTML attachment was scrubbed...
URL:
http://lists.lustre.org/pipermail/lustre-discuss/attachments/20081210/fae6bb96/attachment.html

Andreas Dilger

2008-Dec-13 01:10 UTC

head link

[Lustre-discuss] IOR Single File -- lock callback timer expired

On Dec 10, 2008  13:21 -0500, Roger Spellman wrote:> I have a customer running IOR on 128 clients, using IOR''s POSIX
mode to
> create a single file.  
> 
> The clients are running Lustre 1.6.6.  The servers are running Lustre
> 1.6.5.
If the file is not striped over multiple OSTs it may be that the 1 (default)
OST that this file is striped over is being overloaded.
>     mpiexec noticed that job rank 0 with PID 7520 on node whitney160
> exited on signal 42 (Real-time signal 8).
> 
> Looking at the logs on the servers, I see a bunch of messages like the
> following:
> 
> Dec  9 18:23:38 ts-sandia-02 kernel: LustreError:
> 0:0:(ldlm_lockd.c:234:waiting_locks_callback()) ### lock callback timer
> expired after 116s: evicting client at 192.168.121.32 at o2ib  ns:
> filter-scratch-OST0000_UUID lock: ffff810014239600/0x6316855aa9d9f014
> lrc: 1/0,0 mode: PW/PW res: 5987/0 rrc: 373 type: EXT
> [1409286144->1442840575] (req 1409286144->1410334719) flags: 20
> remote: 0x77037709d529258a expref: 28 pi
>  
> 
> What might be causing this?
This indicates that the (from the OST''s POV) the client hasn''t
cancelled
the lock, nor done any writes under this lock in the past 2 minutes.

It would be worthwhile for you to check the RPC IO stats to see how long
writes are taking on this OST:

	llstat -i 1 /proc/fs/lustre/ost/OSS/ost_io/stats
> Can I fix this problem by extending timers, such as
> /proc/sys/lustre/timeout and /proc/sys/lustre/ldlm_timeout ?
Increasing /proc/sys/lustre/timeout would likely help.

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

Roger Spellman

2008-Dec-15 17:47 UTC

head link

[Lustre-discuss] IOR Single File -- lock callback timer expired

Andreas,

Thanks.  
> If the file is not striped over multiple OSTs it may be that the 1
> (default)
> OST that this file is striped over is being overloaded.
The file is striped over many OSTs.  The customer has tested between 8
and 18 stripes, to my knowledge.  

As far as I can tell, I can control how many RPCs are outstanding from
each client to each OST.  However, I cannot control the total number of
outstanding RPCs from a single client.  So, it is possible that many (or
even all) of the 128 clients have outstanding I/Os to the same OST, even
if the file is striped.  Do you agree?  

Is there a proc file like max_rpcs_in_flight that is per-client, not
per-client/per-OST pair?
> 	llstat -i 1 /proc/fs/lustre/ost/OSS/ost_io/stats
Do you want this command to be run WHILE the test is going on?

Thanks again.

-Roger
> -----Original Message-----
> From: Andreas.Dilger at sun.com [mailto:Andreas.Dilger at sun.com] On
Behalf
Of> Andreas Dilger
> Sent: Friday, December 12, 2008 8:11 PM
> To: Roger Spellman
> Cc: lustre-discuss at lists.lustre.org
> Subject: Re: [Lustre-discuss] IOR Single File -- lock callback timer
> expired
> 
> On Dec 10, 2008  13:21 -0500, Roger Spellman wrote:
> > I have a customer running IOR on 128 clients, using IOR''s
POSIX mode
to> > create a single file.
> >
> > The clients are running Lustre 1.6.6.  The servers are running
Lustre> > 1.6.5.
> 
> If the file is not striped over multiple OSTs it may be that the 1
> (default)
> OST that this file is striped over is being overloaded.
> 
> >     mpiexec noticed that job rank 0 with PID 7520 on node whitney160
> > exited on signal 42 (Real-time signal 8).
> >
> > Looking at the logs on the servers, I see a bunch of messages like
the> > following:
> >
> > Dec  9 18:23:38 ts-sandia-02 kernel: LustreError:
> > 0:0:(ldlm_lockd.c:234:waiting_locks_callback()) ### lock callback
timer> > expired after 116s: evicting client at 192.168.121.32 at o2ib  ns:
> > filter-scratch-OST0000_UUID lock:
ffff810014239600/0x6316855aa9d9f014> > lrc: 1/0,0 mode: PW/PW res: 5987/0 rrc: 373 type: EXT
> > [1409286144->1442840575] (req 1409286144->1410334719) flags: 20
> > remote: 0x77037709d529258a expref: 28 pi
> >
> >
> > What might be causing this?
> 
> This indicates that the (from the OST''s POV) the client
hasn''t
cancelled> the lock, nor done any writes under this lock in the past 2 minutes.
> 
> It would be worthwhile for you to check the RPC IO stats to see how
long> writes are taking on this OST:
> 
> 	llstat -i 1 /proc/fs/lustre/ost/OSS/ost_io/stats
> 
> > Can I fix this problem by extending timers, such as
> > /proc/sys/lustre/timeout and /proc/sys/lustre/ldlm_timeout ?
> 
> Increasing /proc/sys/lustre/timeout would likely help.
> 
> Cheers, Andreas
> --
> Andreas Dilger
> Sr. Staff Engineer, Lustre Group
> Sun Microsystems of Canada, Inc.

Jeffrey Alan Bennett

2008-Dec-15 18:37 UTC

head link

[Lustre-discuss] IOR Single File -- lock callback timer expired

I am also having this same issue when using IOR with POSIX. I also have other
issues with IOR. For example, when I run IOR with MPI-IO, sometimes IOR is hung
forever in the middle of the test. I am only using 4 Lustre clients and files
are striped over 28 OSTs.

Jeff
 
> -----Original Message-----
> From: lustre-discuss-bounces at lists.lustre.org 
> [mailto:lustre-discuss-bounces at lists.lustre.org] On Behalf Of 
> Roger Spellman
> Sent: Monday, December 15, 2008 9:48 AM
> To: Andreas Dilger
> Cc: lustre-discuss at lists.lustre.org
> Subject: Re: [Lustre-discuss] IOR Single File -- lock 
> callback timer expired
> 
> Andreas,
> 
> Thanks.  
> 
> > If the file is not striped over multiple OSTs it may be that the 1
> > (default)
> > OST that this file is striped over is being overloaded.
> 
> The file is striped over many OSTs.  The customer has tested 
> between 8 and 18 stripes, to my knowledge.  
> 
> As far as I can tell, I can control how many RPCs are 
> outstanding from each client to each OST.  However, I cannot 
> control the total number of outstanding RPCs from a single 
> client.  So, it is possible that many (or even all) of the 
> 128 clients have outstanding I/Os to the same OST, even if 
> the file is striped.  Do you agree?  
> 
> Is there a proc file like max_rpcs_in_flight that is 
> per-client, not per-client/per-OST pair?
> 
> > 	llstat -i 1 /proc/fs/lustre/ost/OSS/ost_io/stats
> 
> Do you want this command to be run WHILE the test is going on?
> 
> Thanks again.
> 
> -Roger
> 
> > -----Original Message-----
> > From: Andreas.Dilger at sun.com 
> [mailto:Andreas.Dilger at sun.com] On Behalf
> Of
> > Andreas Dilger
> > Sent: Friday, December 12, 2008 8:11 PM
> > To: Roger Spellman
> > Cc: lustre-discuss at lists.lustre.org
> > Subject: Re: [Lustre-discuss] IOR Single File -- lock 
> callback timer 
> > expired
> > 
> > On Dec 10, 2008  13:21 -0500, Roger Spellman wrote:
> > > I have a customer running IOR on 128 clients, using
IOR''s
> POSIX mode
> to
> > > create a single file.
> > >
> > > The clients are running Lustre 1.6.6.  The servers are running
> Lustre
> > > 1.6.5.
> > 
> > If the file is not striped over multiple OSTs it may be that the 1
> > (default)
> > OST that this file is striped over is being overloaded.
> > 
> > >     mpiexec noticed that job rank 0 with PID 7520 on node 
> whitney160 
> > > exited on signal 42 (Real-time signal 8).
> > >
> > > Looking at the logs on the servers, I see a bunch of messages
like
> the
> > > following:
> > >
> > > Dec  9 18:23:38 ts-sandia-02 kernel: LustreError:
> > > 0:0:(ldlm_lockd.c:234:waiting_locks_callback()) ### lock callback
> timer
> > > expired after 116s: evicting client at 192.168.121.32 at o2ib 
ns:
> > > filter-scratch-OST0000_UUID lock:
> ffff810014239600/0x6316855aa9d9f014
> > > lrc: 1/0,0 mode: PW/PW res: 5987/0 rrc: 373 type: EXT 
> > > [1409286144->1442840575] (req 1409286144->1410334719)
flags: 20
> > > remote: 0x77037709d529258a expref: 28 pi
> > >
> > >
> > > What might be causing this?
> > 
> > This indicates that the (from the OST''s POV) the client
hasn''t
> cancelled
> > the lock, nor done any writes under this lock in the past 2 minutes.
> > 
> > It would be worthwhile for you to check the RPC IO stats to see how
> long
> > writes are taking on this OST:
> > 
> > 	llstat -i 1 /proc/fs/lustre/ost/OSS/ost_io/stats
> > 
> > > Can I fix this problem by extending timers, such as 
> > > /proc/sys/lustre/timeout and /proc/sys/lustre/ldlm_timeout ?
> > 
> > Increasing /proc/sys/lustre/timeout would likely help.
> > 
> > Cheers, Andreas
> > --
> > Andreas Dilger
> > Sr. Staff Engineer, Lustre Group
> > Sun Microsystems of Canada, Inc.
> 
> _______________________________________________
> Lustre-discuss mailing list
> Lustre-discuss at lists.lustre.org
> http://lists.lustre.org/mailman/listinfo/lustre-discuss
>

Lustre discuss - Dec 2008 - IOR Single File -- lock callback timer expired

[Lustre-discuss] IOR Single File -- lock callback timer expired

[Lustre-discuss] IOR Single File -- lock callback timer expired

[Lustre-discuss] IOR Single File -- lock callback timer expired

[Lustre-discuss] IOR Single File -- lock callback timer expired