ls stalls
Subsystems (2)
A message that is not in the archive (sent off-list or not yet received): [email protected]
Hi folks,
On our large memory (64GB) HPC nodes, we intermittently see what we call 'interactive stalls': pauses in receiving 'ls' output. Also, bash shell completion stalls, emacs stalls. We've hacked /bin/ls to time how long it takes to complete and then to log diagnostic information when that time exceeds 3 seconds. In some cases, the result isn't surprising -- a directory containing thousands or tens of thousands of files, hosted on slow storage, might well take seconds to display. But most of the time, these stalls occur on directories containing tens or occasionally hundreds of files; 'ls' on such a directory normally takes a millisecond or less to complete. Stalls vary in length: most of them under 10s, with a significant portion under 100s, and the occasional stall in the 100-300s range.
I've been correlating strace output ('strace -f -tt ls {directory}') with packet traces. And I see the following pattern:
(A) The stall occurs between a 'stat' on the directory and the 'open' on the directory ... and sometimes, though not always, between the 'open' and the following 'fcntl'. Here's an example of a 10s stall:
17:20:01.365375 stat("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", {st_mode=S_IFDIR|0770, st_size=327680, ...}) = 0
17:20:11.774368 open("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
And of a ~200s stall:
10:30:01.768459 stat("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", {st_mode=S_IFDIR|0770, st_size=327680, ...}) = 0
10:33:06.072659 open("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
10:33:28.884426 fcntl(3, F_GETFD) = 0x1 (flags FD_CLOEXEC)
10:33:28.884600 getdents64(3, /* 683 entries */, 32768) = 32736
(B) On the wire, during that stall, the HPC node says nothing to the NFS server (sometimes literally, sometimes it is reading or writing in support of some other task/user, but not emitting GETATTR or READDIR or READDIRPLUS calls). [No dropped frames, no TCP pathology.]
(C) Network IO is noticeable: the node is reading and/or writing, rapidly, with at least one of the handful of NFS servers which provide storage to the HPC environment.
The clients are all running OpenSuse 11.3 Teal (kernel 2.6.34.10-0.2-default). The NFS servers are a mix -- Solaris 10, several NetApps, Windows 2008 -- backed by several different storage systems.
Diagrams and related information visible at
https://vishnu.fhcrc.org/Rhino-RCA/
Insights? Suggestions?
--sk
Stuart Kendrick
Fred Hutchinson Cancer Research Center
Seattle, WA USA
Quoted 63 lines · Stuart Kendrick
Hi folks,
On our large memory (64GB) HPC nodes, we intermittently see what we call 'interactive stalls': pauses in receiving 'ls' output. Also, bash shell completion stalls, emacs stalls. We've hacked
/bin/lsto time how long it takes to complete and then to log diagnostic information when that time exceeds 3 seconds. In some cases, the result isn't surprising -- a directory containing thousands or tens of thousands of files, hosted on slow storage, might well take seconds to display. But most of the time, these stalls occur on directories containing tens or occasionally hundreds of files; 'ls' on such a directory normally takes a millisecond or less to complete. Stalls vary in length: most of them under 10s, with a significant portion under 100s, and the occasional stall in the 100-300s range.I've been correlating strace output ('strace -f -tt ls {directory}') with packet traces. And I see the following pattern:
(A) The stall occurs between a 'stat' on the directory and the 'open' on the directory ... and sometimes, though not always, between the 'open' and the following 'fcntl'. Here's an example of a 10s stall:
17:20:01.365375 stat("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", {st_mode=S_IFDIR|0770, st_size=327680, ...}) = 0
17:20:11.774368 open("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
And of a ~200s stall:
10:30:01.768459 stat("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", {st_mode=S_IFDIR|0770, st_size=327680, ...}) = 0
10:33:06.072659 open("/shared/silo_r/xxx/colongwas_archive/plco-sshfs/pancreatic-panscan-dbgap/panscan-work/610-gtc", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
10:33:28.884426
fcntl(3, F_GETFD)=0x1(flagsFD_CLOEXEC)10:33:28.884600
getdents64(3, /* 683 entries */, 32768)= 32736(B) On the wire, during that stall, the HPC node says nothing to the NFS server (sometimes literally, sometimes it is reading or writing in support of some other task/user, but not emitting GETATTR or READDIR or READDIRPLUS calls). [No dropped frames, no TCP pathology.]
(C) Network IO is noticeable: the node is reading and/or writing, rapidly, with at least one of the handful of NFS servers which provide storage to the HPC environment.
The clients are all running OpenSuse 11.3 Teal (kernel 2.6.34.10-0.2-default). The NFS servers are a mix -- Solaris 10, several NetApps, Windows 2008 -- backed by several different storage systems.
Quoted 4 lines
Diagrams and related information visible at
https://vishnu.fhcrc.org/Rhino-RCA/Insights? Suggestions?
My starting guess is that there is some task on that client that has dirtied the pages of one of the files in the directory you are trying to list. A GETATTR is required to flush outstanding writes to a file so the server can provide size and mtime attributes that reflect the last most recent write to that file.
Possible work-arounds: You can reduce the dirty_ratio setting on the client to force it to starting flushing outstanding writes sooner, you can change the writing applications to use synchronous writes (or flush manually), or you can alter your "ls" command so that it doesn't require a GETATTR for each file.
Signature · 2 lines
Chuck Lever chuck[dot]lever[at]oracle[dot]com
Quoted 4 lines
My starting guess is that there is some task on that client that has dirtied the pages of one of the files in the directory you are trying to list. A GETATTR is required to flush outstanding writes to a file so the server can provide size and mtime attributes that reflect the last most recent write to that file.
Possible work-arounds: You can reduce the
dirty_ratiosetting on the client to force it to starting flushing outstanding writes sooner, you can change the writing applications to use synchronous writes (or flush manually), or you can alter your "ls" command so that it doesn't require a GETATTR for each file.
How might I replicate this?
I'm trying a continuous write to a file ... but 'ls -l' remains snappy.
#!/bin/bash
while [ true ]
cp foo.1 foo.2 echo Do it again
done
--sk
Quoted 7 lines · Stuart Kendrick
Quoted 4 lines
My starting guess is that there is some task on that client that has dirtied the pages of one of the files in the directory you are trying to list. A GETATTR is required to flush outstanding writes to a file so the server can provide size and mtime attributes that reflect the last most recent write to that file.
Possible work-arounds: You can reduce the
dirty_ratiosetting on the client to force it to starting flushing outstanding writes sooner, you can change the writing applications to use synchronous writes (or flush manually), or you can alter your "ls" command so that it doesn't require a GETATTR for each file.How might I replicate this?
I'm trying a continuous write to a file ... but 'ls -l' remains snappy.
The file must reside in the directory you are listing, and it should be very large. Typically dd'ing zeroes into a large file is a good way to starve non-writers.
Quoted 5 lines
#!/bin/bash
while [ true ]cp foo.1 foo.2 echo Do it againdone
Signature · 2 lines
Chuck Lever chuck[dot]lever[at]oracle[dot]com
Quoted 2 lines
The file must reside in the directory you are listing, and it should be very large. Typically dd'ing zeroes into a large file is a good way to starve non-writers.
Thanx Chuck. I can replicate the problem, I've learned a lot about dirty_bytes/dirty_ratio and I'm on my way to resolving this.
--sk
Quoted 1 line
Quoted 1 line
My starting guess is that there is some task on that client that has dirtied the pages of one of the files in the directory you are trying to list.
A GETATTR is required to flush outstanding writes to a file so the server can provide size and mtime attributes that reflect the last most recent write to that file.
Quoted 3 lines
Quoted 3 lines
Possible work-arounds: You can reduce the
dirty_ratiosetting on the client to force it to starting flushing outstanding writes sooner, you can change the writing applications to use synchronous writes (or flush manually), or you can alter your "ls" command so that it doesn't require a GETATTR for each file.
OK, I think I understand that if I've dirtied the pages on a file and then issue a stat against it, that the NFS Client will stall my stat until it flushes cache.
And I'm focused on the work-around of: "You can reduce the dirty_ratio setting ..."
(a) Does the stat /trigger/ a cache flush? Or does the stat have to wait for the usual mechanisms to initiate a flush?
(b) How granular is this process? Will the NFS Client issue my stat (GETATTR) once all the dirty pages relevant to my particular file are flushed (but other pages are still being written)? Or does the NFS Client wait until pdflush has entirely emptied cache before proceeding with the stat?
(c) When cache hits dirty_ratio (or dirty_bytes), I believe the kernel blocks /all/ writers until it has /emptied/ cache (and flushing a big cache to slow storage can take a while) ... am I correct?
(d) If my load is dominated by large writes over NFS, does cache buy me anything? Seems to me that the dominant benefit of cache is elevatoring ... the block structure of storage accessible via NFS is opaque ... thus, there's nothing write cache can do to increase the performance of the write ... it may as well hand off the blocks in any old order to the NFS server and let the storage's cache worry about sequencing the blocks.
==> Seems to me that shrinking dirty_xxx to something really low ... like 100K ... would:
(1) maximize 'stat' performance during heavy writes
(2) leave NFS write performance unaffected
but I can tell that I'm missing something here (because when I try it, interactive performance, i.e. 'ls -l', tanks). What am I not understanding?
--sk
Quoted 12 lines · Stuart Kendrick
Quoted 1 line
Quoted 1 line
My starting guess is that there is some task on that client that has dirtied the pages of one of the files in the directory you are trying to list.
A GETATTR is required to flush outstanding writes to a file so the server can provide size and mtime attributes that reflect the last most recent write to that file.
Quoted 3 lines
Quoted 3 lines
Possible work-arounds: You can reduce the
dirty_ratiosetting on the client to force it to starting flushing outstanding writes sooner, you can change the writing applications to use synchronous writes (or flush manually), or you can alter your "ls" command so that it doesn't require a GETATTR for each file.OK, I think I understand that if I've dirtied the pages on a file and then issue a stat against it, that the NFS Client will stall my stat until it flushes cache.
Quoted 5 lines
And I'm focused on the work-around of: "You can reduce the
dirty_ratiosetting ..."(a) Does the stat /trigger/ a cache flush? Or does the stat have to wait for the usual mechanisms to initiate a flush?
stat(2) invokes the VFS ->getattr method, which is nfs_getattr() for NFS. nfs_getattr() initiates the flush before sending the GETATTR operation.
Quoted 5 lines
(b) How granular is this process? Will the NFS Client issue my stat (GETATTR) once all the dirty pages relevant to my particular file are flushed (but other pages are still being written)? Or does the NFS Client wait until pdflush has entirely emptied cache before proceeding with the stat?
The nfs_getattr() function flushes dirty pages for just that file.
nfs_getattr() should cause other writers to wait for the GETATTR to complete; otherwise the GETATTR can be starved. I'm not sure I see a mechanism like that in 3.4.
Quoted 3 lines
(c) When cache hits
dirty_ratio(ordirty_bytes), I believe the kernel blocks /all/ writers until it has /emptied/ cache (and flushing a big cache to slow storage can take a while) ... am I correct?
Not sure. You may want to try dirty_background_ratio instead, as that kicks off background flushing, but writers may continue.
Quoted 6 lines
(d) If my load is dominated by large writes over NFS, does cache buy me anything? Seems to me that the dominant benefit of cache is elevatoring ... the block structure of storage accessible via NFS is opaque ... thus, there's nothing write cache can do to increase the performance of the write ... it may as well hand off the blocks in any old order to the NFS server and let the storage's cache worry about sequencing the blocks.
Caching is mostly of benefit for readers.
However, delaying small writes has the benefit of allowing a client to coalesce small application write requests into fewer large on-the-wire requests. It can also be of benefit if an application is overwriting the same part of a file many times, or if it writes then truncates.
Honestly, I've always regarded the aggressive write caching behavior of the Linux NFS client as a performance bug. The problem is that write flushing is driven almost entirely by the VM in modern Linux kernels, and there isn't a way to adjust specific flushing behavior for a specific file system implementation (hence the use of system-wide tunables as a workaround).
Quoted 7 lines
==> Seems to me that shrinking
dirty_xxxto something really low ... like 100K ... would:
(1) maximize 'stat' performance during heavy writes
(2) leave NFS write performance unaffectedbut I can tell that I'm missing something here (because when I try it, interactive performance, i.e. 'ls -l', tanks). What am I not understanding?
That's a very broad question. Try diagnosing the specific problem in your environment, and do try out dirty_background_ratio.
Signature · 2 lines
Chuck Lever chuck[dot]lever[at]oracle[dot]com