Re: [PATCH] locking/rtmutex: Provide proper spin_is_contended

From: Zhipeng Shi
Date: Wed Jun 08 2022 - 10:25:13 EST


On Tue, Jun 07, 2022 at 11:24:56AM +0200, Sebastian Andrzej Siewior wrote:
> On 2022-06-07 17:15:14 [+0800], Zhipeng Shi wrote:
> > Commit d89c70356acf ("locking/core: Remove break_lock field when
> > CONFIG_GENERIC_LOCKBREAK=y") removed GENERIC_LOCKBREAK, which caused
> > spin_is_contended depend on the implementation of arch_spin_is_contended.
> > But now in rt-spinlock, spin_is_contended returns 0 directly.
> >
> > This causes cond_resched_lock to fail to correctly detect lock contention
> > in RT-linux. In some scenarios (such as __purge_vmap_area_lazy in vmalloc),
> > this will cause a large latency.
> >
> > This patch provides the implementation of spin_is_contended for
> > rt-spinlock.
>
> Do you have a test-case or an example?

Sorry for late reply, here is my test-case.

After apply this patch, max-latency of vmalloc reduce from 10+ msec to
200+ usec, this because spin_lock is released halfway through
__purge_vmap_area_lazy.

But today I find if I 'chrt -f 10' to my test script, There will still be
a large latency in the vmalloc process. After trace, it seems update_curr_rt
leads to resched_curr. I haven't figured out the reason behind it, and I'm
still trying to figure out why. I would really appreciate your thoughts
on this issue.

Below is the test module
---------------------------------
#include <linux/module.h>
#include <linux/interrupt.h>
#include <linux/io.h>
#include <linux/poll.h>
#include <linux/proc_fs.h>
#include <linux/seq_file.h>
#include <trace/events/kmem.h>

#define TEST_MALLOC_SIZE 64
#define MAX_OFF 20000

void* buf[MAX_OFF];
void* fub[MAX_OFF];
int off = 0;
int ffo = 0;

u64 total_time1 = 0;
u64 total_time2 = 0;

u64 total_cnt1 = 0;
u64 total_cnt2 = 0;
u64 alloc_time1[16];
u64 alloc_time2[16];
#define DECIMAL_BASE 10


#define MODULE_NAME "vmalloc_test"

unsigned long long duration_max = 0;

ssize_t vmalloc_test_proc_write(struct file *file,
const char __user *buffer, size_t count, loff_t *pos)
{
char set_str[4] = {0};
uint32_t set_bits = 0;
ssize_t err = 0;
ktime_t time1, time2, delta;
unsigned long long duration;
int i = 0;

err = simple_write_to_buffer((void*)set_str, sizeof(set_str) - 1u,
pos, (const void*)buffer, count);
if (err == 0)
return err;
if (kstrtouint(set_str, DECIMAL_BASE, &set_bits) != 0)
return -EINVAL;

switch (set_bits) {
case 0:
if (off >= MAX_OFF) {
printk("buf number exceed\n");
return -1;
}

time1 = ktime_get();

buf[off] = vmalloc(TEST_MALLOC_SIZE);
if (NULL == buf[off]) {
printk("vmalloc buf failed\n");
return -1;
}
memset(buf[off], 1, TEST_MALLOC_SIZE);
off++;

time2 = ktime_get();
delta = ktime_sub(time2, time1);
duration = (unsigned long long) ktime_to_ns(delta) >> 10;
if (duration > 8000) {
printk("%s:%d, elapse %llu usec\n",
__func__, __LINE__, duration);
return -1;
}
total_cnt1++;
total_time1 += duration;
alloc_time1[fls(duration) - 1]++;
if (duration > duration_max)
duration_max = duration;
break;
case 1:
for (i = 0; i < MAX_OFF; i++) {
if (buf[i] == NULL)
break;

vfree(buf[i]);
buf[i] = NULL;
}
off = 0;
break;
case 2:
if (ffo >= MAX_OFF) {
printk("buf number exceed\n");
return -1;
}

time1 = ktime_get();

fub[ffo] = vmalloc(TEST_MALLOC_SIZE);
if (NULL == fub[ffo]) {
printk("vmalloc buf failed\n");
return -1;
}
memset(fub[ffo], 1, TEST_MALLOC_SIZE);
ffo++;

time2 = ktime_get();
delta = ktime_sub(time2, time1);
duration = (unsigned long long) ktime_to_ns(delta) >> 10;
if (duration > 8000) {
printk("%s:%d, elapse %llu usec\n",
__func__, __LINE__, duration);
//return -1;
}
total_cnt2++;
total_time2 += duration;
alloc_time1[fls(duration)- 1]++;
if (duration > duration_max)
duration_max = duration;
break;
case 3:
for (i = 0; i < MAX_OFF; i++) {
if (fub[i] == NULL)
break;

vfree(fub[i]);
fub[i] = NULL;
}
ffo = 0;
break;

default:
printk("input error\n");
return -EINVAL;
}

return (ssize_t)count;
}

static int32_t vmalloc_test_proc_show(struct seq_file *m, void *v)
{
int i = 0;
seq_printf(m, "max: %llu us\n", duration_max);
seq_printf(m, "avg1: %llu us\n", total_time1/total_cnt1);
seq_printf(m, "avg2: %llu us\n", total_time2/total_cnt2);
for (i = 0; i < 16; i++) {
seq_printf(m, "[%u ~ %u): %llu\n",
1 << i, 1 << (i + 1), alloc_time1[i]);
}
return 0;
}

static int32_t vmalloc_test_fault_injection_proc_open(struct inode *inode,
struct file *file)
{
return single_open(file, vmalloc_test_proc_show, PDE_DATA(inode));
}


static const struct proc_ops vmalloc_test_fault_inject_proc_fops = {
.proc_open = vmalloc_test_fault_injection_proc_open,
.proc_read = seq_read,
.proc_lseek = seq_lseek,
.proc_release = single_release,
.proc_write = vmalloc_test_proc_write,
};

static struct proc_dir_entry *root_irq_dir = NULL;
static struct proc_dir_entry *entry;

#define vmalloc_test_FAULT_INJECTION_MODE 444
static int32_t vmalloc_test_register_procfs(void)
{
if (NULL == root_irq_dir) {
root_irq_dir = proc_mkdir("driver/vmalloc_test", NULL);
if (NULL == root_irq_dir) {
return -EINVAL;
}
}

entry = proc_create_data("test",
vmalloc_test_FAULT_INJECTION_MODE,
root_irq_dir,
&vmalloc_test_fault_inject_proc_fops, NULL);
if (entry == NULL) {
return -ENOMEM;
}
return 0;
}
static int32_t vmalloc_test_unregister_procfs(void)
{

proc_remove(root_irq_dir);
return 0;
}


static s32 __init vmalloc_test_init(void)
{
int ret;

ret = vmalloc_test_register_procfs();
if (ret) {
printk("register proc failed\n");
return -1;
}

return 0;
}

module_init(vmalloc_test_init);/*PRQA S 0605*/

static void __exit vmalloc_test_exit(void)
{
vmalloc_test_unregister_procfs();
return;
}

module_exit(vmalloc_test_exit);/*PRQA S 0605*/

MODULE_AUTHOR("Sun Kaikai<kaikai.sun@xxxxxxxxxxx>");
MODULE_DESCRIPTION("Hobot GDC driver");
MODULE_LICENSE("GPL v2");
-------------------------------

Below is the test script no.1
-------------------------------------
#!/bin/bash

x=0
while true
do
for i in {1..10000}
do
echo 0 > /proc/driver/vmalloc_test/test
if [ $? != 0 ];then
echo 0 > /sys/kernel/debug/tracing/tracing_on
echo 1 > /proc/driver/vmalloc_test/test
exit
fi
done
echo 1 > /proc/driver/vmalloc_test/test
echo "loop $x done"
x=$((x+1))
done
---------------------------------

Below is the test script no.2
------------------------------
#!/bin/bash

x=0
while true
do
for i in {1..10000}
do
echo 2 > /proc/driver/vmalloc_test/test
if [ $? != 0 ];then
echo 0 > /sys/kernel/debug/tracing/tracing_on
echo 3 > /proc/driver/vmalloc_test/test
exit
fi
done
echo 3 > /proc/driver/vmalloc_test/test
echo "loop1 $x done"
x=$((x+1))
done
------------------------------


>
> The thing if _this_ task has higher priority than other tasks waiting on
> this lock then a simple unlock+lock won't do a thing. That is why I
> ripped it all out while it was half way done.
>
> > Signed-off-by: Zhipeng Shi <zhipeng.shi0@xxxxxxxxx>
>
> Sebastian

Zhipeng