xfs
[Top] [All Lists]

Re: Tons of empty transactions

To: linux-xfs@xxxxxxxxxxx
Subject: Re: Tons of empty transactions
From: KELEMEN Peter <fuji@xxxxxxx>
Date: Wed, 19 Jun 2002 13:22:22 +0200
In-reply-to: <1022524000.1147.7.camel@snafu>
Mail-followup-to: linux-xfs@xxxxxxxxxxx
Organization: ELTE Eotvos Lorand University of Sciences, Budapest, Hungary
References: <20020526225657.GA4965@chiara.elte.hu> <1022524000.1147.7.camel@snafu>
Reply-to: KELEMEN Peter <fuji@xxxxxxx>
Sender: owner-linux-xfs@xxxxxxxxxxx
User-agent: Mutt/1.3.28i
* Stephen Lord (lord@xxxxxxx) [20020527 13:26]:

Steve,

> There are some paths in xfs which allocate a transaction, and
> then discover they do not need it. [...]  I suspect the case I
> mentioned of truncating excess space on close is probably the
> main culprit.

Thanks for the explanation.

[ For those who haven't followed #xfs: after plotting the stats
  and finding correlation with xs_ig_attrchg counters, Steve came
  up with a theory of excessive utime() activity causing the high
  number of empty transactions. ]

Your theory was correct; after six days of monitoring, the culprit
application was found to be ncftp.  You can reproduce the effect
by simply downloading a big file, and it will boost your empty
transaction counter.  Snippet from the strace output:

select(8, [7], NULL, NULL, {1, 0})      = 1 (in [7], left {1, 0})
read(7, "\214Oc\255m\2672\253\241\262\305r\f\0071\2\356\324\232"..., 4096) = 
4096
write(6, "\214Oc\255m\2672\253\241\262\305r\f\0071\2\356\324\232"..., 4096) = 
4096
utime("PATH/TO/FILE/DOWNLOADED", [2002/06/19-11:33:01, 2002/06/14-11:54:13]) = 0
time([1024479198])                      = 1024479198
...
alarm(3600)                             = 3600
elect(8, [7], NULL, NULL, {1, 0})      = 1 (in [7], left {1, 0})
read(7, "\r\275\355r\335\325\20\0\0\0\1\v\32\246\210\\\214\356\353"..., 4096) = 
4096
write(6, "\r\275\355r\335\325\20\0\0\0\1\v\32\246\210\\\214\356\353"..., 4096) 
= 4096
utime("PATH/TO/FILE/DOWNLOADED", [2002/06/19-11:33:01, 2002/06/14-11:54:13]) = 0
time([1024479199])                      = 1024479199
alarm(3600)                             = 3600
...

...in repeating pattern.  On a slow machine/link I measured about
2-3000 calls per minute.

On #xfs, you suggested the following change to turn these empty
transactions to async ones:

--- xfs_vnodeops.c.orig      Wed May 22 14:08:19 2002
+++ xfs_vnodeops.c      Wed Jun 12 17:31:18 2002
@@ -820,6 +820,7 @@
                        timeflags &= ~XFS_ICHGTIME_MOD;
                        timeflags |= XFS_ICHGTIME_CHG;
                 }
+               xfs_trans_log_inode (tp, ip, XFS_ILOG_CORE);
         }

        /*

There was no definite opinion if we need these transactions at
all, and you mentioned that eliminating them would be a more
coplex change.  Awaiting your comment.

Peter
 
-- 
    .+'''+.         .+'''+.         .+'''+.         .+'''+.         .+''
 Kelemen Péter     /       \       /       \       /      fuji@xxxxxxx
.+'         `+...+'         `+...+'         `+...+'         `+...+'


<Prev in Thread] Current Thread [Next in Thread>