Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:18 as permitted sender) client-ip=2620:137:e000::1:18;
Message-ID: <6ba14287-336d-cdcd-0d39-680f288ca776@ddn.com>
Date:   Mon, 28 Mar 2022 15:21:28 +0200
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101
 Thunderbird/91.7.0
Content-Language: en-US
To:     Linux-FSDevel <linux-fsdevel@vger.kernel.org>,
        Linux Kernel <linux-kernel@vger.kernel.org>
Cc:     Dharmendra Singh <dsingh@ddn.com>,
        Miklos Szeredi <miklos@szeredi.hu>,
        Boaz Harrosh <boaz@plexistor.com>,
        Sagi Manole <sagim@netapp.com>
From:   Bernd Schubert <bschubert@ddn.com>
Subject: RFC fuse waitq latency
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 2
X-MS-Exchange-AntiSpam-MessageData-0: =?utf-8?B?dUx3M3crRzE4SXhMU0ZHVmVaVWpRVW40cHJyRHBuTTg2R0RSQjlyMTJscUdo?=
 =?utf-8?B?SFdQcXNQSE5vMlQycGhOY0xyN1ZtZHQySVFJTVVBM1libXFCS2oxZ2N5Rkxl?=
 =?utf-8?B?RkVrMW83UTFveWhGOEdIbkhhNTJIQWpxN0EzS3pNQWIwV2hIYS9CSGxiWTQv?=
 =?utf-8?B?dHpQakhVYlZJRjdITUdhOVdEd0JSd2RwVkpVbG1Ib1hZRFFLWnlNY2JJQnNx?=
 =?utf-8?B?S0NoSnBCYVBiTGUxS25UblM2Q2dXakVFT0YyNU5ZcUdYRCtVUCs4cEN3eFYw?=
 =?utf-8?B?WFlCV2hSNU14a1FySnRGaFdDcnhzNytJZ1R2YlgxRC9ML2haNkQ4TkNzWWlk?=
 =?utf-8?B?ejJSUG1lK0l0Q2Y0SjJObHNnQzlEU1JEYm9ua0tlcCtTRldsTC9XNTRXU2hL?=
 =?utf-8?B?SGJCcFhyb0V1Z1lmaXNwY29FT1Z5ekg4aXBGV1A3VE14TlZZZXQ1NCtjdFVh?=
 =?utf-8?B?VklTdjZiYVh4OHE5K25xN0ZuS08zUFcwMTlqTUJpZHI0akpCdWQwcmtyQk54?=
 =?utf-8?B?cU45c0RTaEdLV3ZKVlZXeVg2WDBRN0FBTDZmS2tyQWloTHRoRmltdk5nNXhX?=
 =?utf-8?B?YmRoWit1bjdRNU9vZnlXUzdHTjdDbFU1Q1I4VnNUODBOTVZFQXBVWWRjbThk?=
 =?utf-8?B?My93cXFnNmlma1g0MEVTS29Ld2phOTFyZEx4dGpKanFRL0RNaWZUTFJidnNW?=
 =?utf-8?B?KzJnNlRxR2NHWHRQaTlTQUlzOVIxMHVRVTBOR2lRSmdXNlpsa3FzZlNEK0h1?=
 =?utf-8?B?Q09sdkpNTy84b2FJNHFmR1ZHN01NVG12bEYrZnRQVG05Mndwazlhc2dBVHMv?=
 =?utf-8?B?VitibkZpT3oxYmhuUXlXS3NlOWVlamZkQ2FQbmdzbjdXbU9Ya1E4em1iU3VQ?=
 =?utf-8?B?TUZ5RzJycXVZcVVUOE85Y2ZBWXhLd0w3bk1WOEk5ZjlHSGtiNkd3eElEdzlZ?=
 =?utf-8?B?eDlKSzV1ZDF4Z0JpT0Y5T0dwYytJakZaeHk4RW9YaU5xVUJvMWdxaC9rYzVT?=
 =?utf-8?B?MjUzV0dweXhhNjNpWFhSWjhabGE3QWNuQ3lTZzRkckdrU0lEZ1pIb0tsS0NV?=
 =?utf-8?B?TlF4Ny9DaW1WNVBBa091Yy9Zb3VCZnBaYk9HKzZsMlJ6S3dKMDYweW9kZG9W?=
 =?utf-8?B?OS9LMmxoOFc2NUIzazNKOWxBTDdOemoxWFdXZktVNXRpVHRrZnB6ZUVGRmxB?=
 =?utf-8?B?Rkd5STZETnBER1o3TExITmpmY2sxcnY0MHkrYmw5TlR0ZHVja28yYThvLzA4?=
 =?utf-8?B?eldTV3N6eENYK2o0NGUxR09FUFZlWGI4UDF4RkdwS25PYzJqVlJSb1RCSWNk?=
 =?utf-8?B?cjJFNWFtcUMwcTIyKzVOQlBVbEd4V1Fwc3h6ZU8zcjRUMktiWTFIamdiNmVO?=
 =?utf-8?B?VVovOFpDNXI2b3NLekNHUHlaWUJVYlBmeGtOaUptMjVobDJFWk5aWmRpN25I?=
 =?utf-8?B?cHFrVVE2SzVGV3d5cncyT0MvUkUvei9RU0d3TzRpK1dpTFhkUEI5OUJNdS9I?=
 =?utf-8?B?Y1V6UDhYbFg1MzJnM3h2eEZWTkFQVWZvdmJMTi9CNXdUclNodEE3dnVmUE4r?=
 =?utf-8?B?bjF4WEU2czQva3NCclRFWkVoVE1Qd2ZsYnhmdUhsbzdFSjFFdWJBSHB5cWU4?=
 =?utf-8?B?enBPQzJrSmg2czExSjhsbFRUSXBxT1NYYWM3QnFsZmZ4Qm1QeVp3N0JndVZX?=
 =?utf-8?B?MkFieWhWMldDeTBseDA5QTNSV0hvWXZiQStYeUNzS09LSUxzUVRiNFpFTkN6?=
 =?utf-8?B?WkczR0lYbzVIL2ZPZ0lZME9acEQwakE1K3pmeGxjTUtoUVp1aGdRWGpzdi85?=
 =?utf-8?B?cWs4U2VRTXRiUjNiUUVGVnlZVUdsdTM3TFdDTVFkUGNZck5Mek9HazhVTDZB?=
 =?utf-8?B?SlpIcDNraDhmQUVIWGNreFV6YXRRZ2RwRVFTejJpNExHcEduWmZaL2FmWHIv?=
 =?utf-8?B?NXd3a1JoOUM4RkxGY0N4bTJvM3N2MGZpc3dPeTlnN1FwNTcxc2dNdmFIQjkw?=
 =?utf-8?B?WGlKK2pKK1NNOFI0dm1yMTljUzJvaHIzcjN6bllxMnVRa3A4U3FORitBSFZY?=
 =?utf-8?B?RVpiajJSOTJmWnd3enZET0R2aHpmSHRhNGRzdlprWjFIQnhmaG92ZTUrK0tQ?=
 =?utf-8?B?SGJNZWJHNjF0RXZsTTdoK2c0dlAxQWNVWm5yaEVIL0NrU1I0Rkh2Qk9IUTYy?=
 =?utf-8?B?U0F1cUE5WjN2Q1V0YnY4WHlGVUdBRnROczdTWlV2UFNTeE9wOVlXY1pGVWRN?=
 =?utf-8?B?UDg1akRCUHhXSXJxbmRkWkYxWlQ0dTFmWHdqeVkvUVFDZno4eXNsaC9nRDMz?=
 =?utf-8?B?bGcrN2tVRWhnVmwrbE5JdXh2b3VHUHRlSE5sbGlUVlZWUjZvQ1RITHRqV0R5?=
 =?utf-8?Q?Z9Nz7v63a8KmEyzVm6kd3YoTnPszOuEdUFFuVyZh2aydS?=
X-MS-Exchange-AntiSpam-MessageData-1: S2rWb44FREiGmw==
X-OriginatorOrg: ddn.com
X-MS-Exchange-CrossTenant-Network-Message-Id: e51e189d-eedf-41a9-51e3-08da10bde21d
X-MS-Exchange-CrossTenant-AuthSource: DM5PR1901MB2037.namprd19.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 28 Mar 2022 13:21:35.7438
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 753b6e26-6fd3-43e6-8248-3f1735d59bb4
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: Mnp8hRhQy12Z5U9YyibZjEnz7zqTMzTFAtNaSXMX4J7NubtJ8GnHRWrYWmPe8wCqqs5I9o5SGP8lwy7M7W+a+w==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DM6PR19MB3674
X-Spam-Status: No, score=-2.0 required=5.0 tests=BAYES_00,DKIM_SIGNED,
	DKIM_VALID,DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,
	MAILING_LIST_MULTI,RDNS_NONE,SPF_HELO_NONE,T_SCC_BODY_TEXT_LINE
	autolearn=no autolearn_force=no version=3.4.6
X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on
	lindbergh.monkeyblade.net
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

I would like to discuss the user thread wake up latency in
fuse_dev_do_read(). Profiling fuse shows there is room for improvement
regarding memory copies and splice. The basic profiling with flame graphs
didn't reveal, though, why fuse is so much
slower (with an overlay file system) than just accessing the underlying
file system directly and also didn't reveal why a single threaded fuse
uses less than 100% cpu, with the application on top of use also using
less than 100% cpu (simple bonnie++ runs with 1B files).
So I started to suspect the wait queues and indeed, keeping the thread
that reads the fuse device for work running for some time gives quite
some improvements.


diff --git a/fs/fuse/dev.c b/fs/fuse/dev.c
index 592730fd6e42..20b7cf296fb0 100644
--- a/fs/fuse/dev.c
+++ b/fs/fuse/dev.c
@@ -1034,7 +1034,7 @@ static int fuse_copy_args(struct fuse_copy_state *cs, unsigned numargs,
  
  static int forget_pending(struct fuse_iqueue *fiq)
  {
-       return fiq->forget_list_head.next != NULL;
+       return READ_ONCE(fiq->forget_list_head.next) != NULL;
  }
  
  static int request_pending(struct fuse_iqueue *fiq)
@@ -1237,18 +1237,25 @@ static ssize_t fuse_dev_do_read(struct fuse_dev *fud, struct file *file,
                 return -EINVAL;
  
   restart:
+       expires = jiffies + 10;
         for (;;) {
-               spin_lock(&fiq->lock);
-               if (!fiq->connected || request_pending(fiq))
-                       break;
-               spin_unlock(&fiq->lock);
  
+               if (!READ_ONCE(fiq->connected) || request_pending(fiq)) {
+                       spin_lock(&fiq->lock);
+                       if (!fiq->connected || request_pending(fiq))
+                               break;
+                       spin_unlock(&fiq->lock);
+               }
                 if (file->f_flags & O_NONBLOCK)
                         return -EAGAIN;
-               err = wait_event_interruptible_exclusive(fiq->waitq,
-                               !fiq->connected || request_pending(fiq));
+
+               if (time_after_eq(jiffies, expires))
+                       err = wait_event_interruptible_exclusive(fiq->waitq,
+                                       !fiq->connected || request_pending(fiq));
                 if (err)
                         return err;
+
+               cond_resched();
         }
  
         if (!fiq->connected) {


Without patch above

>                     ------Sequential Create------ --------Random Create--------
>                     -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
>       files:max:min  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
> imesrv1   30:1:1:10  5568  28  7784  40  9737  23  5756  29  5709  39  7573  25
> Latency             26813us     654us     965us     261us     550us     336ms


Patch above applied

                     ------Sequential Create------ --------Random Create--------
                     -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
       files:max:min  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
imesrv1   30:1:1:10  8043  30 12100  44 14024  22  7791  28  9238  43  9871  25
Latency               235us    3982us    3201us     240us     277us     355ms


So there is quite some improvement by 'just' preventing the thread going to
sleep, with the disadvantage that the thread now spins. This also does not
work that well when libfuse creates multiple threads (still with a single
threaded bonnie++), as wakeup then wakes up different threads, multiple
of them start to spin and without having profiled it, I guess
fiq->lock then might become a problem.

I had also tried to use swaitq instead of waitq, there is a little improvement
with it, but it does not solve the major issue.


Now if the wakeup is an issue, how did zufs avoid it? Looking at its code,
zufs also has a thread wakeup. Same for Miklos' fuse2. On our side
Dharmendra was just read to start to port Miklos' fuse2 to more recent
kernels and to add support into libfuse for it. Now with the waitq
latency we are not sure if this is actually the right approach.


Results above are done with bonnie++
bonnie++ -x 4 -q -s0  -d /scratch/dest/ -n 30:1:1:10 -r 0

using passthrough_hp. This is with additional patches (kernel side
has Dharmendras atomic-open optimizations, libfuse has additional
patches for atomic-open, a libfuse thread creation fix and more
fixes and options for passthrough_hp.cc).

passthrough_hp --foreground --nosplice --nocache --num_threads=1\
     /scratch/source /scratch/dest


Thanks,
Bernd