s390/debug: Convert debug area lock from a spinlock to a raw spinlock

With PREEMPT_RT as potential configuration option, spinlock_t is now
considered as a sleeping lock, and thus might cause issues when used in
an atomic context. But even with PREEMPT_RT as potential configuration
option, raw_spinlock_t remains as a true spinning lock/atomic context.
This creates potential issues with the s390 debug/tracing feature. The
functions to trace errors are called in various contexts, including
under lock of raw_spinlock_t, and thus the used spinlock_t in each debug
area is in violation of the locking semantics.

Here are two examples involving failing PCI Read accesses that are
traced while holding `pci_lock` in `drivers/pci/access.c`:

=============================
[ BUG: Invalid wait context ]
6.19.0-devel #18 Not tainted
-----------------------------
bash/3833 is trying to lock:
0000027790baee30 (&rc->lock){-.-.}-{3:3}, at: debug_event_common+0xfc/0x300
other info that might help us debug this:
context-{5:5}
5 locks held by bash/3833:
 #0: 0000027efbb29450 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0x7c/0xf0
 #1: 00000277f0504a90 (&of->mutex#2){+.+.}-{4:4}, at: kernfs_fop_write_iter+0x13e/0x260
 #2: 00000277beed8c18 (kn->active#339){.+.+}-{0:0}, at: kernfs_fop_write_iter+0x164/0x260
 #3: 00000277e9859190 (&dev->mutex){....}-{4:4}, at: pci_dev_lock+0x2e/0x40
 #4: 00000383068a7708 (pci_lock){....}-{2:2}, at: pci_bus_read_config_dword+0x4a/0xb0
stack backtrace:
CPU: 6 UID: 0 PID: 3833 Comm: bash Kdump: loaded Not tainted 6.19.0-devel #18 PREEMPTLAZY
Hardware name: IBM 9175 ME1 701 (LPAR)
Call Trace:
 [<00000383048afec2>] dump_stack_lvl+0xa2/0xe8
 [<00000383049ba166>] __lock_acquire+0x816/0x1660
 [<00000383049bb1fa>] lock_acquire+0x24a/0x370
 [<00000383059e3860>] _raw_spin_lock_irqsave+0x70/0xc0
 [<00000383048bbb6c>] debug_event_common+0xfc/0x300
 [<0000038304900b0a>] __zpci_load+0x17a/0x1f0
 [<00000383048fad88>] pci_read+0x88/0xd0
 [<00000383054cbce0>] pci_bus_read_config_dword+0x70/0xb0
 [<00000383054d55e4>] pci_dev_wait+0x174/0x290
 [<00000383054d5a3e>] __pci_reset_function_locked+0xfe/0x170
 [<00000383054d9b30>] pci_reset_function+0xd0/0x100
 [<00000383054ee21a>] reset_store+0x5a/0x80
 [<0000038304e98758>] kernfs_fop_write_iter+0x1e8/0x260
 [<0000038304d995da>] new_sync_write+0x13a/0x180
 [<0000038304d9c5d0>] vfs_write+0x200/0x330
 [<0000038304d9c88c>] ksys_write+0x7c/0xf0
 [<00000383059cfa80>] __do_syscall+0x210/0x500
 [<00000383059e4c06>] system_call+0x6e/0x90
INFO: lockdep is turned off.

=============================
[ BUG: Invalid wait context ]
6.19.0-devel #3 Not tainted
-----------------------------
bash/6861 is trying to lock:
0000009da05c7430 (&rc->lock){-.-.}-{3:3}, at: debug_event_common+0xfc/0x300
other info that might help us debug this:
context-{5:5}
5 locks held by bash/6861:
 #0: 000000acff404450 (sb_writers#3){.+.+}-{0:0}, at: ksys_write+0x7c/0xf0
 #1: 000000acff41c490 (&of->mutex#2){+.+.}-{4:4}, at: kernfs_fop_write_iter+0x13e/0x260
 #2: 0000009da36937d8 (kn->active#75){.+.+}-{0:0}, at: kernfs_fop_write_iter+0x164/0x260
 #3: 0000009dd15250d0 (&zdev->state_lock){+.+.}-{4:4}, at: enable_slot+0x2e/0xc0
 #4: 000001a19682f708 (pci_lock){....}-{2:2}, at: pci_bus_read_config_byte+0x42/0xa0
stack backtrace:
CPU: 16 UID: 0 PID: 6861 Comm: bash Kdump: loaded Not tainted 6.19.0-devel #3 PREEMPTLAZY
Hardware name: IBM 9175 ME1 701 (LPAR)
Call Trace:
 [<000001a194837ec2>] dump_stack_lvl+0xa2/0xe8
 [<000001a194942166>] __lock_acquire+0x816/0x1660
 [<000001a1949431fa>] lock_acquire+0x24a/0x370
 [<000001a19596b810>] _raw_spin_lock_irqsave+0x70/0xc0
 [<000001a194843b6c>] debug_event_common+0xfc/0x300
 [<000001a194888b0a>] __zpci_load+0x17a/0x1f0
 [<000001a194882d88>] pci_read+0x88/0xd0
 [<000001a195453b88>] pci_bus_read_config_byte+0x68/0xa0
 [<000001a195457bc2>] pci_setup_device+0x62/0xad0
 [<000001a195458e70>] pci_scan_single_device+0x90/0xe0
 [<000001a19488a0f6>] zpci_bus_scan_device+0x46/0x80
 [<000001a19547f958>] enable_slot+0x98/0xc0
 [<000001a19547f134>] power_write_file+0xc4/0x110
 [<000001a194e20758>] kernfs_fop_write_iter+0x1e8/0x260
 [<000001a194d215da>] new_sync_write+0x13a/0x180
 [<000001a194d245d0>] vfs_write+0x200/0x330
 [<000001a194d2488c>] ksys_write+0x7c/0xf0
 [<000001a195957a30>] __do_syscall+0x210/0x500
 [<000001a19596cbb6>] system_call+0x6e/0x90
INFO: lockdep is turned off.

Since it is desired to keep it possible to create trace records in most
situations, including this particular case (failing PCI config space
accesses are relevant), convert the used spinlock_t in `struct
debug_info` to raw_spinlock_t.

The impact is small, as the debug area lock only protects bounded memory
access without external dependencies, apart from one function
debug_set_size() where kfree() is implicitly called with the lock held.
Move debug_info_free() out of this lock, to keep remove this external
dependency.

Acked-by: Heiko Carstens <hca@linux.ibm.com>
Signed-off-by: Benjamin Block <bblock@linux.ibm.com>
Signed-off-by: Heiko Carstens <hca@linux.ibm.com>

diff --git a/arch/s390/include/asm/debug.h b/arch/s390/include/asm/debug.h
index 6375276..c5440b3 100644 (file)
--- a/arch/s390/include/asm/debug.h
+++ b/arch/s390/include/asm/debug.h
@@ -45,7 +45,7 @@ typedef struct debug_info {
        struct debug_info *next;
        struct debug_info *prev;
        refcount_t ref_count;
-       spinlock_t lock;
+       raw_spinlock_t lock;
        int level;
        int nr_areas;
        int pages_per_area;
@@ -440,7 +440,7 @@ static int VNAME(var, active_entries)[EARLY_AREAS] __initdata
        .next = NULL,                                                   \
        .prev = NULL,                                                   \
        .ref_count = REFCOUNT_INIT(1),                                  \
-       .lock = __SPIN_LOCK_UNLOCKED(var.lock),                         \
+       .lock = __RAW_SPIN_LOCK_UNLOCKED(var.lock),                     \
        .level = DEBUG_DEFAULT_LEVEL,                                   \
        .nr_areas = EARLY_AREAS,                                        \
        .pages_per_area = EARLY_PAGES,                                  \

diff --git a/arch/s390/kernel/debug.c b/arch/s390/kernel/debug.c
index 71cdb68..e722243 100644 (file)
--- a/arch/s390/kernel/debug.c
+++ b/arch/s390/kernel/debug.c
@@ -243,7 +243,7 @@ static debug_info_t *debug_info_alloc(const char *name, int pages_per_area,
        }
 
        /* initialize members */
-       spin_lock_init(&rc->lock);
+       raw_spin_lock_init(&rc->lock);
        rc->pages_per_area = pages_per_area;
        rc->nr_areas       = nr_areas;
        rc->active_area    = 0;
@@ -333,7 +333,7 @@ static debug_info_t *debug_info_copy(debug_info_t *in, int mode)
        do {
                rc = debug_info_alloc(in->name, in->pages_per_area,
                        in->nr_areas, in->buf_size, in->level, mode);
-               spin_lock_irqsave(&in->lock, flags);
+               raw_spin_lock_irqsave(&in->lock, flags);
                if (!rc)
                        goto out;
                /* has something changed in the meantime ? */
@@ -341,7 +341,7 @@ static debug_info_t *debug_info_copy(debug_info_t *in, int mode)
                    (rc->nr_areas == in->nr_areas)) {
                        break;
                }
-               spin_unlock_irqrestore(&in->lock, flags);
+               raw_spin_unlock_irqrestore(&in->lock, flags);
                debug_info_free(rc);
        } while (1);
 
@@ -356,7 +356,7 @@ static debug_info_t *debug_info_copy(debug_info_t *in, int mode)
        }
        rc->active_area = in->active_area;
 out:
-       spin_unlock_irqrestore(&in->lock, flags);
+       raw_spin_unlock_irqrestore(&in->lock, flags);
        return rc;
 }
 
@@ -879,20 +879,20 @@ void debug_register_static(debug_info_t *id, int pages_per_area, int nr_areas)
                pr_err("Registering debug feature %s failed\n", id->name);
 
                /* Clear pointers to prevent tracing into released initdata. */
-               spin_lock_irqsave(&id->lock, flags);
+               raw_spin_lock_irqsave(&id->lock, flags);
                id->areas = NULL;
                id->active_pages = NULL;
                id->active_entries = NULL;
-               spin_unlock_irqrestore(&id->lock, flags);
+               raw_spin_unlock_irqrestore(&id->lock, flags);
 
                return;
        }
 
        /* Replace static trace area with dynamic copy. */
-       spin_lock_irqsave(&id->lock, flags);
+       raw_spin_lock_irqsave(&id->lock, flags);
        debug_events_append(copy, id);
        debug_areas_swap(id, copy);
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
 
        /* Clear pointers to initdata and discard copy. */
        copy->areas = NULL;
@@ -966,11 +966,11 @@ static int debug_set_size(debug_info_t *id, int nr_areas, int pages_per_area)
                return -ENOMEM;
        }
 
-       spin_lock_irqsave(&id->lock, flags);
+       raw_spin_lock_irqsave(&id->lock, flags);
        debug_events_append(new_id, id);
        debug_areas_swap(new_id, id);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
        debug_info_free(new_id);
-       spin_unlock_irqrestore(&id->lock, flags);
        pr_info("%s: set new size (%i pages)\n", id->name, pages_per_area);
 
        return 0;
@@ -1000,9 +1000,9 @@ void debug_set_level(debug_info_t *id, int new_level)
                return;
        }
 
-       spin_lock_irqsave(&id->lock, flags);
+       raw_spin_lock_irqsave(&id->lock, flags);
        id->level = new_level;
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
 }
 EXPORT_SYMBOL(debug_set_level);
 
@@ -1184,10 +1184,10 @@ debug_entry_t *debug_event_common(debug_info_t *id, int level, const void *buf,
        if (!debug_active || !id->areas)
                return NULL;
        if (debug_critical) {
-               if (!spin_trylock_irqsave(&id->lock, flags))
+               if (!raw_spin_trylock_irqsave(&id->lock, flags))
                        return NULL;
        } else {
-               spin_lock_irqsave(&id->lock, flags);
+               raw_spin_lock_irqsave(&id->lock, flags);
        }
        do {
                active = get_active_entry(id);
@@ -1199,7 +1199,7 @@ debug_entry_t *debug_event_common(debug_info_t *id, int level, const void *buf,
                buf += id->buf_size;
        } while (len > 0);
 
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
        return active;
 }
 EXPORT_SYMBOL(debug_event_common);
@@ -1217,10 +1217,10 @@ debug_entry_t *debug_exception_common(debug_info_t *id, int level,
        if (!debug_active || !id->areas)
                return NULL;
        if (debug_critical) {
-               if (!spin_trylock_irqsave(&id->lock, flags))
+               if (!raw_spin_trylock_irqsave(&id->lock, flags))
                        return NULL;
        } else {
-               spin_lock_irqsave(&id->lock, flags);
+               raw_spin_lock_irqsave(&id->lock, flags);
        }
        do {
                active = get_active_entry(id);
@@ -1232,7 +1232,7 @@ debug_entry_t *debug_exception_common(debug_info_t *id, int level,
                buf += id->buf_size;
        } while (len > 0);
 
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
        return active;
 }
 EXPORT_SYMBOL(debug_exception_common);
@@ -1267,10 +1267,10 @@ debug_entry_t *__debug_sprintf_event(debug_info_t *id, int level, char *string,
        numargs = debug_count_numargs(string);
 
        if (debug_critical) {
-               if (!spin_trylock_irqsave(&id->lock, flags))
+               if (!raw_spin_trylock_irqsave(&id->lock, flags))
                        return NULL;
        } else {
-               spin_lock_irqsave(&id->lock, flags);
+               raw_spin_lock_irqsave(&id->lock, flags);
        }
        active = get_active_entry(id);
        curr_event = (debug_sprintf_entry_t *) DEBUG_DATA(active);
@@ -1280,7 +1280,7 @@ debug_entry_t *__debug_sprintf_event(debug_info_t *id, int level, char *string,
                curr_event->args[idx] = va_arg(ap, long);
        va_end(ap);
        debug_finish_entry(id, active, level, 0);
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
 
        return active;
 }
@@ -1303,10 +1303,10 @@ debug_entry_t *__debug_sprintf_exception(debug_info_t *id, int level, char *stri
        numargs = debug_count_numargs(string);
 
        if (debug_critical) {
-               if (!spin_trylock_irqsave(&id->lock, flags))
+               if (!raw_spin_trylock_irqsave(&id->lock, flags))
                        return NULL;
        } else {
-               spin_lock_irqsave(&id->lock, flags);
+               raw_spin_lock_irqsave(&id->lock, flags);
        }
        active = get_active_entry(id);
        curr_event = (debug_sprintf_entry_t *)DEBUG_DATA(active);
@@ -1316,7 +1316,7 @@ debug_entry_t *__debug_sprintf_exception(debug_info_t *id, int level, char *stri
                curr_event->args[idx] = va_arg(ap, long);
        va_end(ap);
        debug_finish_entry(id, active, level, 1);
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
 
        return active;
 }
@@ -1350,7 +1350,7 @@ int debug_register_view(debug_info_t *id, struct debug_view *view)
                mode &= ~(S_IWUSR | S_IWGRP | S_IWOTH);
        pde = debugfs_create_file(view->name, mode, id->debugfs_root_entry,
                                  id, &debug_file_ops);
-       spin_lock_irqsave(&id->lock, flags);
+       raw_spin_lock_irqsave(&id->lock, flags);
        for (i = 0; i < DEBUG_MAX_VIEWS; i++) {
                if (!id->views[i])
                        break;
@@ -1361,7 +1361,7 @@ int debug_register_view(debug_info_t *id, struct debug_view *view)
                id->views[i] = view;
                id->debugfs_entries[i] = pde;
        }
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
        if (rc) {
                pr_err("Registering view %s/%s would exceed the maximum "
                       "number of views %i\n", id->name, view->name, i);
@@ -1391,7 +1391,7 @@ int debug_unregister_view(debug_info_t *id, struct debug_view *view)
 
        if (!id)
                goto out;
-       spin_lock_irqsave(&id->lock, flags);
+       raw_spin_lock_irqsave(&id->lock, flags);
        for (i = 0; i < DEBUG_MAX_VIEWS; i++) {
                if (id->views[i] == view)
                        break;
@@ -1403,7 +1403,7 @@ int debug_unregister_view(debug_info_t *id, struct debug_view *view)
                id->views[i] = NULL;
                id->debugfs_entries[i] = NULL;
        }
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
        debugfs_remove(dentry);
 out:
        return rc;
@@ -1557,7 +1557,7 @@ static void debug_flush(debug_info_t *id, int area)
 
        if (!id || !id->areas)
                return;
-       spin_lock_irqsave(&id->lock, flags);
+       raw_spin_lock_irqsave(&id->lock, flags);
        if (area == DEBUG_FLUSH_ALL) {
                id->active_area = 0;
                memset(id->active_entries, 0, id->nr_areas * sizeof(int));
@@ -1572,7 +1572,7 @@ static void debug_flush(debug_info_t *id, int area)
                for (i = 0; i < id->pages_per_area; i++)
                        memset(id->areas[area][i], 0, PAGE_SIZE);
        }
-       spin_unlock_irqrestore(&id->lock, flags);
+       raw_spin_unlock_irqrestore(&id->lock, flags);
 }
 
 /*