Re: [fuse-devel] Writing to FUSE via mmap extremely slow (sometimes) on some machines?

[Michael Stapelberg <michael+lkml@stapelberg.ch>]

Tejun, friendly ping? Any thoughts on this? Thanks!

On Wed, Feb 26, 2020 at 9:00 PM Miklos Szeredi <miklos@szeredi.hu> wrote:
>
> Adding more CC and re-attaching the reproducer and the 25s log.
>
> On Wed, Feb 26, 2020 at 11:03 AM Michael Stapelberg
> <michael+lkml@stapelberg.ch> wrote:
> >
> > Find attached two logs:
> >
> > fuse-1s.log shows the expected case
> >
> > fuse-25s.log shows the issue. Note that the log spans 2 days. I
> > started the cp at 10:54:53.251395. Note how the first WRITE opcode is
> > only received at 10:55:18.094578!
>
> Observations:
>
> - apparently memcpy is copying downwards (from largest address to
> smallest address).  Not sure why, when I run the reproducer, it copies
> upwards.
> - there's a slow batch of reads of the first ~4MB of data, then a
> quick writeback
> - there's a quick read of the rest (~95MB) of data, then a quick
> writeback of the same
>
> Plots of the whole and closeups of slow and quick segments attached.
> X axis is time, Y axis is offset.
>
> Tejun, could this behavior be attributed to dirty throttling?  What
> would be the best way to trace this?
>
> Thanks,
> Miklos
>
>
> >
> > Is there some sort of readahead going on that’s then being throttled somewhere?
> >
> > Thanks,
> >
> > On Mon, Feb 24, 2020 at 3:23 PM Miklos Szeredi <miklos@szeredi.hu> wrote:
> > >
> > > On Mon, Feb 24, 2020 at 3:18 PM Michael Stapelberg
> > > <michael+lkml@stapelberg.ch> wrote:
> > > >
> > > > Sorry, to clarify: the hang is always in the memcpy call. I.e., the
> > > > “Mapped” message is always printed, and it takes a long time until
> > > > “memcpy done” is printed.
> > >
> > > Have you tried running the fuse daemon with debugging enabled?  Is
> > > there any observable difference between the fast and the slow runs?
> > >
> > > Thanks,
> > > Miklos