Skip to content

Commit 3ce500a

Browse files
Benjamin-Blockhcahca
Benjamin-Block
authored and
hcahca
committed
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>
1 parent 3ee5333 commit 3ce500a

File tree

2 files changed

+32
-32
lines changed

2 files changed

+32
-32
lines changed

‎arch/s390/include/asm/debug.h‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,7 @@ typedef struct debug_info {
4545
struct debug_info *next;
4646
struct debug_info *prev;
4747
refcount_t ref_count;
48-
spinlock_t lock;
48+
raw_spinlock_t lock;
4949
int level;
5050
int nr_areas;
5151
int pages_per_area;
@@ -440,7 +440,7 @@ static int VNAME(var, active_entries)[EARLY_AREAS] __initdata
440440
.next = NULL, \
441441
.prev = NULL, \
442442
.ref_count = REFCOUNT_INIT(1), \
443-
.lock = __SPIN_LOCK_UNLOCKED(var.lock), \
443+
.lock = __RAW_SPIN_LOCK_UNLOCKED(var.lock), \
444444
.level = DEBUG_DEFAULT_LEVEL, \
445445
.nr_areas = EARLY_AREAS, \
446446
.pages_per_area = EARLY_PAGES, \

‎arch/s390/kernel/debug.c‎

Lines changed: 30 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -243,7 +243,7 @@ static debug_info_t *debug_info_alloc(const char *name, int pages_per_area,
243243
}
244244

245245
/* initialize members */
246-
spin_lock_init(&rc->lock);
246+
raw_spin_lock_init(&rc->lock);
247247
rc->pages_per_area = pages_per_area;
248248
rc->nr_areas = nr_areas;
249249
rc->active_area = 0;
@@ -333,15 +333,15 @@ static debug_info_t *debug_info_copy(debug_info_t *in, int mode)
333333
do {
334334
rc = debug_info_alloc(in->name, in->pages_per_area,
335335
in->nr_areas, in->buf_size, in->level, mode);
336-
spin_lock_irqsave(&in->lock, flags);
336+
raw_spin_lock_irqsave(&in->lock, flags);
337337
if (!rc)
338338
goto out;
339339
/* has something changed in the meantime ? */
340340
if ((rc->pages_per_area == in->pages_per_area) &&
341341
(rc->nr_areas == in->nr_areas)) {
342342
break;
343343
}
344-
spin_unlock_irqrestore(&in->lock, flags);
344+
raw_spin_unlock_irqrestore(&in->lock, flags);
345345
debug_info_free(rc);
346346
} while (1);
347347

@@ -356,7 +356,7 @@ static debug_info_t *debug_info_copy(debug_info_t *in, int mode)
356356
}
357357
rc->active_area = in->active_area;
358358
out:
359-
spin_unlock_irqrestore(&in->lock, flags);
359+
raw_spin_unlock_irqrestore(&in->lock, flags);
360360
return rc;
361361
}
362362

@@ -879,20 +879,20 @@ void debug_register_static(debug_info_t *id, int pages_per_area, int nr_areas)
879879
pr_err("Registering debug feature %s failed\n", id->name);
880880

881881
/* Clear pointers to prevent tracing into released initdata. */
882-
spin_lock_irqsave(&id->lock, flags);
882+
raw_spin_lock_irqsave(&id->lock, flags);
883883
id->areas = NULL;
884884
id->active_pages = NULL;
885885
id->active_entries = NULL;
886-
spin_unlock_irqrestore(&id->lock, flags);
886+
raw_spin_unlock_irqrestore(&id->lock, flags);
887887

888888
return;
889889
}
890890

891891
/* Replace static trace area with dynamic copy. */
892-
spin_lock_irqsave(&id->lock, flags);
892+
raw_spin_lock_irqsave(&id->lock, flags);
893893
debug_events_append(copy, id);
894894
debug_areas_swap(id, copy);
895-
spin_unlock_irqrestore(&id->lock, flags);
895+
raw_spin_unlock_irqrestore(&id->lock, flags);
896896

897897
/* Clear pointers to initdata and discard copy. */
898898
copy->areas = NULL;
@@ -966,11 +966,11 @@ static int debug_set_size(debug_info_t *id, int nr_areas, int pages_per_area)
966966
return -ENOMEM;
967967
}
968968

969-
spin_lock_irqsave(&id->lock, flags);
969+
raw_spin_lock_irqsave(&id->lock, flags);
970970
debug_events_append(new_id, id);
971971
debug_areas_swap(new_id, id);
972+
raw_spin_unlock_irqrestore(&id->lock, flags);
972973
debug_info_free(new_id);
973-
spin_unlock_irqrestore(&id->lock, flags);
974974
pr_info("%s: set new size (%i pages)\n", id->name, pages_per_area);
975975

976976
return 0;
@@ -1000,9 +1000,9 @@ void debug_set_level(debug_info_t *id, int new_level)
10001000
return;
10011001
}
10021002

1003-
spin_lock_irqsave(&id->lock, flags);
1003+
raw_spin_lock_irqsave(&id->lock, flags);
10041004
id->level = new_level;
1005-
spin_unlock_irqrestore(&id->lock, flags);
1005+
raw_spin_unlock_irqrestore(&id->lock, flags);
10061006
}
10071007
EXPORT_SYMBOL(debug_set_level);
10081008

@@ -1184,10 +1184,10 @@ debug_entry_t *debug_event_common(debug_info_t *id, int level, const void *buf,
11841184
if (!debug_active || !id->areas)
11851185
return NULL;
11861186
if (debug_critical) {
1187-
if (!spin_trylock_irqsave(&id->lock, flags))
1187+
if (!raw_spin_trylock_irqsave(&id->lock, flags))
11881188
return NULL;
11891189
} else {
1190-
spin_lock_irqsave(&id->lock, flags);
1190+
raw_spin_lock_irqsave(&id->lock, flags);
11911191
}
11921192
do {
11931193
active = get_active_entry(id);
@@ -1199,7 +1199,7 @@ debug_entry_t *debug_event_common(debug_info_t *id, int level, const void *buf,
11991199
buf += id->buf_size;
12001200
} while (len > 0);
12011201

1202-
spin_unlock_irqrestore(&id->lock, flags);
1202+
raw_spin_unlock_irqrestore(&id->lock, flags);
12031203
return active;
12041204
}
12051205
EXPORT_SYMBOL(debug_event_common);
@@ -1217,10 +1217,10 @@ debug_entry_t *debug_exception_common(debug_info_t *id, int level,
12171217
if (!debug_active || !id->areas)
12181218
return NULL;
12191219
if (debug_critical) {
1220-
if (!spin_trylock_irqsave(&id->lock, flags))
1220+
if (!raw_spin_trylock_irqsave(&id->lock, flags))
12211221
return NULL;
12221222
} else {
1223-
spin_lock_irqsave(&id->lock, flags);
1223+
raw_spin_lock_irqsave(&id->lock, flags);
12241224
}
12251225
do {
12261226
active = get_active_entry(id);
@@ -1232,7 +1232,7 @@ debug_entry_t *debug_exception_common(debug_info_t *id, int level,
12321232
buf += id->buf_size;
12331233
} while (len > 0);
12341234

1235-
spin_unlock_irqrestore(&id->lock, flags);
1235+
raw_spin_unlock_irqrestore(&id->lock, flags);
12361236
return active;
12371237
}
12381238
EXPORT_SYMBOL(debug_exception_common);
@@ -1267,10 +1267,10 @@ debug_entry_t *__debug_sprintf_event(debug_info_t *id, int level, char *string,
12671267
numargs = debug_count_numargs(string);
12681268

12691269
if (debug_critical) {
1270-
if (!spin_trylock_irqsave(&id->lock, flags))
1270+
if (!raw_spin_trylock_irqsave(&id->lock, flags))
12711271
return NULL;
12721272
} else {
1273-
spin_lock_irqsave(&id->lock, flags);
1273+
raw_spin_lock_irqsave(&id->lock, flags);
12741274
}
12751275
active = get_active_entry(id);
12761276
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,
12801280
curr_event->args[idx] = va_arg(ap, long);
12811281
va_end(ap);
12821282
debug_finish_entry(id, active, level, 0);
1283-
spin_unlock_irqrestore(&id->lock, flags);
1283+
raw_spin_unlock_irqrestore(&id->lock, flags);
12841284

12851285
return active;
12861286
}
@@ -1303,10 +1303,10 @@ debug_entry_t *__debug_sprintf_exception(debug_info_t *id, int level, char *stri
13031303
numargs = debug_count_numargs(string);
13041304

13051305
if (debug_critical) {
1306-
if (!spin_trylock_irqsave(&id->lock, flags))
1306+
if (!raw_spin_trylock_irqsave(&id->lock, flags))
13071307
return NULL;
13081308
} else {
1309-
spin_lock_irqsave(&id->lock, flags);
1309+
raw_spin_lock_irqsave(&id->lock, flags);
13101310
}
13111311
active = get_active_entry(id);
13121312
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
13161316
curr_event->args[idx] = va_arg(ap, long);
13171317
va_end(ap);
13181318
debug_finish_entry(id, active, level, 1);
1319-
spin_unlock_irqrestore(&id->lock, flags);
1319+
raw_spin_unlock_irqrestore(&id->lock, flags);
13201320

13211321
return active;
13221322
}
@@ -1350,7 +1350,7 @@ int debug_register_view(debug_info_t *id, struct debug_view *view)
13501350
mode &= ~(S_IWUSR | S_IWGRP | S_IWOTH);
13511351
pde = debugfs_create_file(view->name, mode, id->debugfs_root_entry,
13521352
id, &debug_file_ops);
1353-
spin_lock_irqsave(&id->lock, flags);
1353+
raw_spin_lock_irqsave(&id->lock, flags);
13541354
for (i = 0; i < DEBUG_MAX_VIEWS; i++) {
13551355
if (!id->views[i])
13561356
break;
@@ -1361,7 +1361,7 @@ int debug_register_view(debug_info_t *id, struct debug_view *view)
13611361
id->views[i] = view;
13621362
id->debugfs_entries[i] = pde;
13631363
}
1364-
spin_unlock_irqrestore(&id->lock, flags);
1364+
raw_spin_unlock_irqrestore(&id->lock, flags);
13651365
if (rc) {
13661366
pr_err("Registering view %s/%s would exceed the maximum "
13671367
"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)
13911391

13921392
if (!id)
13931393
goto out;
1394-
spin_lock_irqsave(&id->lock, flags);
1394+
raw_spin_lock_irqsave(&id->lock, flags);
13951395
for (i = 0; i < DEBUG_MAX_VIEWS; i++) {
13961396
if (id->views[i] == view)
13971397
break;
@@ -1403,7 +1403,7 @@ int debug_unregister_view(debug_info_t *id, struct debug_view *view)
14031403
id->views[i] = NULL;
14041404
id->debugfs_entries[i] = NULL;
14051405
}
1406-
spin_unlock_irqrestore(&id->lock, flags);
1406+
raw_spin_unlock_irqrestore(&id->lock, flags);
14071407
debugfs_remove(dentry);
14081408
out:
14091409
return rc;
@@ -1557,7 +1557,7 @@ static void debug_flush(debug_info_t *id, int area)
15571557

15581558
if (!id || !id->areas)
15591559
return;
1560-
spin_lock_irqsave(&id->lock, flags);
1560+
raw_spin_lock_irqsave(&id->lock, flags);
15611561
if (area == DEBUG_FLUSH_ALL) {
15621562
id->active_area = 0;
15631563
memset(id->active_entries, 0, id->nr_areas * sizeof(int));
@@ -1572,7 +1572,7 @@ static void debug_flush(debug_info_t *id, int area)
15721572
for (i = 0; i < id->pages_per_area; i++)
15731573
memset(id->areas[area][i], 0, PAGE_SIZE);
15741574
}
1575-
spin_unlock_irqrestore(&id->lock, flags);
1575+
raw_spin_unlock_irqrestore(&id->lock, flags);
15761576
}
15771577

15781578
/*

0 commit comments

Comments
 (0)