From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([140.186.70.92]:54315) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Rli5m-0002YK-24 for qemu-devel@nongnu.org; Fri, 13 Jan 2012 09:26:55 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1Rli5f-0002zn-5c for qemu-devel@nongnu.org; Fri, 13 Jan 2012 09:26:54 -0500 Received: from lo.gmane.org ([80.91.229.12]:44825) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Rli5e-0002zc-Rz for qemu-devel@nongnu.org; Fri, 13 Jan 2012 09:26:47 -0500 Received: from list by lo.gmane.org with local (Exim 4.69) (envelope-from ) id 1Rli5d-0002ze-Ej for qemu-devel@nongnu.org; Fri, 13 Jan 2012 15:26:45 +0100 Received: from barriere.frankfurter-softwarefabrik.de ([217.11.197.1]) by main.gmane.org with esmtp (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Fri, 13 Jan 2012 15:26:45 +0100 Received: from lvml by barriere.frankfurter-softwarefabrik.de with local (Gmexim 0.1 (Debian)) id 1AlnuQ-0007hv-00 for ; Fri, 13 Jan 2012 15:26:45 +0100 From: Lutz Vieweg Date: Fri, 13 Jan 2012 15:26:29 +0100 Message-ID: References: Mime-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit In-Reply-To: Subject: Re: [Qemu-devel] Serious regression of 9p read performance, huge amount of openat syscalls on plain file descriptors List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: qemu-devel@nongnu.org The regression does not exist in the way that I suspected - it's just that the default for 9p mount option "msize=4096" causes the bad performance when reading large files on the guest. I was mislead because... a) mount -o remount,msize=...,... seems to work (with mount reporting the changed value afterwards), but it doesn't - only the msize chosen at first mount time is relevant/used. b) gdb lied to me: > catch syscall openat Catchpoint 1 (syscall 'openat' [295]) I learned the hard way that the system supplied gdb made wrong assumptions on which syscall number is associated with what function. In fact, the so often used syscall was "preadv", not "openat". Thus my only suggestion is to change the default for "msize=" to 131072 (128k), this results in a speed up from ~ 30MB/s to ~ 290MB/s in the large-file reading use case. Regards, Lutz Vieweg On 01/12/2012 07:42 PM, Lutz Vieweg wrote: > Hi all, > > I have been using 9p mounts on guests for quite some time, and enjoyed > their nice performance. > > But not anymore: I noticed that just "dd"-ing large plain files to /dev/zero > on the guest system became very slow, even if the data is completely > in the cache of the host. The rate maxes at ~ 30MB/s while the qemu process > on the host eats lots of CPU). > Both qemu (from source repository) and host kernel (3.1.6) > were upgraded since the last good benchmark, so this could be the > result of some recent change... > > Looking for the cause I noticed that the qemu process, according to strace, > does an insane amount of "openat" syscalls - about 820 per second! - while > the guest system is reading the file (in 64kB chunks, if that matters). > I guess it's no wonder that this huge amount of "open" operations per > second will slow down whatever I/O qemu is trying to do. > > Especially strange is that the fds passed into the openat syscall as the > first parameter refers to the file being read (not the directory it is in, > which has a different fd), according to "lsof". > And the openat syscall always returns 0x1000 as a result (if strace is not > lying), which is neither a credible fd, nor an errno I'd know of: > >> [pid 29236] syscall_295(0x1b, 0x7fe46044a670, 0x1, 0x109e000, 0, 0, 0x7fe46034ae00, >> 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, >> 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, >> 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, >> 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, 0x7fe46034ae00, >> 0x7fe46034ae00 >> [pid 29236] <... syscall_295 resumed> ) = 0x1000 >> [pid 29235] syscall_295(0x1c, 0x7fe4659d8070, 0x1, 0x16df000, 0, 0, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800 >> [pid 29235] <... syscall_295 resumed> ) = 0x1000 >> [pid 29234] syscall_295(0x1b, 0x7fe4659d8070, 0x1, 0x109f000, 0, 0, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, 0x7fe4658d8800, >> 0x7fe4658d8800 >> [pid 29234] <... syscall_295 resumed> ) = 0x1000 > > Alas, I could not get gdb to tell me exactly where those openat calls are > made from (in the qemu-kvm source) - the functions that contain those calls > are static and seem to become inlined. > > Does anyone have an idea what may have caused this? Do you still see > good read performance when reading big plain files from a 9p mount. > > Regards, > > Lutz Vieweg > > > >