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@xxxxxxxxxxxxx> 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@xxxxxxxxxx> wrote: > > > > On Mon, Feb 24, 2020 at 3:18 PM Michael Stapelberg > > <michael+lkml@xxxxxxxxxxxxx> 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
Attachment:
fuse-25s.log
Description: Binary data
#include <sys/types.h>
#include <sys/stat.h>
#include <sys/mman.h>
#include <fcntl.h>
#include <string.h>
#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
/*
* An implementation of copy ("cp") that uses memory maps. Various
* error checking has been removed to promote readability
*/
// Where we want the source file's memory map to live in virtual memory
// The destination file resides immediately after the source file
#define MAP_LOCATION 0x6100
int main (int argc, char *argv[]) {
int fdin, fdout;
char *src, *dst;
struct stat statbuf;
off_t fileSize = 0;
if (argc != 3) {
printf ("usage: a.out <fromfile> <tofile>\n");
exit(0);
}
/* open the input file */
if ((fdin = open (argv[1], O_RDONLY)) < 0) {
printf ("can't open %s for reading\n", argv[1]);
exit(0);
}
/* open/create the output file */
if ((fdout = open (argv[2], O_RDWR | O_CREAT | O_TRUNC, 0600)) < 0) {
printf ("can't create %s for writing\n", argv[2]);
exit(0);
}
/* find size of input file */
fstat (fdin,&statbuf) ;
fileSize = statbuf.st_size;
/* go to the location corresponding to the last byte */
if (lseek (fdout, fileSize - 1, SEEK_SET) == -1) {
printf ("lseek error\n");
exit(0);
}
/* write a dummy byte at the last location */
write (fdout, "", 1);
/*
* memory map the input file. Only the first two arguments are
* interesting: 1) the location and 2) the size of the memory map
* in virtual memory space. Note that the location is only a "hint";
* the OS can choose to return a different virtual memory address.
* This is illustrated by the printf command below.
*/
src = mmap ((void*) MAP_LOCATION, fileSize,
PROT_READ, MAP_SHARED | MAP_POPULATE, fdin, 0);
/* memory map the output file after the input file */
dst = mmap ((void*) MAP_LOCATION + fileSize , fileSize ,
PROT_READ | PROT_WRITE, MAP_SHARED, fdout, 0);
printf("Mapped src: 0x%x and dst: 0x%x\n",src,dst);
/* Copy the input file to the output file */
memcpy (dst, src, fileSize);
printf("memcpy done\n");
// we should probably unmap memory and close the files
} /* main */
Attachment:
25s-offsets-slow.png
Description: PNG image
Attachment:
25s-offsets-fast.png
Description: PNG image
Attachment:
25s-offsets.png
Description: PNG image
