Re: [PATCH v2] mm/page_isolation: fix a deadlock with printk()

[Peter Oberparleiter]

On 08.10.2019 18:08, Qian Cai wrote:
> On Tue, 2019-10-08 at 14:56 +0200, Christian Borntraeger wrote:
>> Adding Peter Oberparleiter.
>> Peter, can you have a look?
>>
>> On 08.10.19 10:27, Michal Hocko wrote:
>>> On Tue 08-10-19 09:43:57, Petr Mladek wrote:
>>>> On Mon 2019-10-07 16:49:37, Michal Hocko wrote:
>>>>> [Cc s390 maintainers - the lockdep is http://lkml.kernel.org/r/1570228005-24979-1-git-send-email-cai@xxxxxx
>>>>>  Petr has explained it is a false positive
>>>>>  http://lkml.kernel.org/r/20191007143002.l37bt2lzqtnqjqxu@xxxxxxxxxxxxxxx]
>>>>> On Mon 07-10-19 16:30:02, Petr Mladek wrote:
>>>>> [...]
>>>>>> I believe that it cannot really happen because:
>>>>>>
>>>>>> 	static int __init
>>>>>> 	sclp_console_init(void)
>>>>>> 	{
>>>>>> 	[...]
>>>>>> 		rc = sclp_rw_init();
>>>>>> 	[...]
>>>>>> 		register_console(&sclp_console);
>>>>>> 		return 0;
>>>>>> 	}
>>>>>>
>>>>>> sclp_rw_init() is called before register_console(). And
>>>>>> console_unlock() will never call sclp_console_write() before
>>>>>> the console is registered.
>>>>>>
>>>>>> AFAIK, lockdep only compares existing chain of locks. It does
>>>>>> not know about console registration that would make some
>>>>>> code paths mutually exclusive.
>>>>>>
>>>>>> I believe that it is a false positive. I do not know how to
>>>>>> avoid this lockdep report. I hope that it will disappear
>>>>>> by deferring all printk() calls rather soon.
>>>>>
>>>>> Thanks a lot for looking into this Petr. I have also checked the code
>>>>> and I really fail to see why the allocation has to be done under the
>>>>> lock in the first place. sclp_read_sccb and sclp_init_sccb are global
>>>>> variables but I strongly suspect that they need a synchronization during
>>>>> early init, callbacks are registered only later IIUC:
>>>>
>>>> Good idea. It would work when the init function is called only once.
>>>> But see below.
>>>>
>>>>> diff --git a/drivers/s390/char/sclp.c b/drivers/s390/char/sclp.c
>>>>> index d2ab3f07c008..4b1c033e3255 100644
>>>>> --- a/drivers/s390/char/sclp.c
>>>>> +++ b/drivers/s390/char/sclp.c
>>>>> @@ -1169,13 +1169,13 @@ sclp_init(void)
>>>>>  	unsigned long flags;
>>>>>  	int rc = 0;
>>>>>  
>>>>> +	sclp_read_sccb = (void *) __get_free_page(GFP_ATOMIC | GFP_DMA);
>>>>> +	sclp_init_sccb = (void *) __get_free_page(GFP_ATOMIC | GFP_DMA);
>>>>>  	spin_lock_irqsave(&sclp_lock, flags);
>>>>>  	/* Check for previous or running initialization */
>>>>>  	if (sclp_init_state != sclp_init_state_uninitialized)
>>>>>  		goto fail_unlock;
>>>>
>>>> It seems that sclp_init() could be called several times in parallel.
>>>> I see it called from sclp_register() and sclp_initcall().
>>>
>>> Interesting. Something for s390 people to answer I guess.
>>> Anyway, this should be quite trivial to workaround by a cmpxch or alike.
>>>
> 
> The above fix is simply insufficient,
> 
> 00: [ÂÂÂÂ3.654307] WARNING: possible circular locking dependency detectedÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654309] 5.4.0-rc1-next-20191004+ #4 Not taintedÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654311] ------------------------------------------------------ÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654313] swapper/0/1 is trying to acquire lock:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654314] 00000000553f3fb8 (sclp_lock){-.-.}, at: sclp_add_request+0x34
> 00: /0x308ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654320]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654322] but task is already holding lock:ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654323] 00000000550c9fc0 (console_owner){....}, at: console_unlock+0x
> 00: 328/0xa30ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654329]ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ
> 00: [ÂÂÂÂ3.654331] which lock already depends on the new lock.ÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂÂ 

I can confirm that both this lockdep warning as well as the original one
are both false positives: lockdep warns that code in sclp_init could
trigger a deadlock via the chain

   sclp_lock --> &(&zone->lock)->rlock --> console_owner

but

  a) before sclp_init successfully completes, register_console is not
     called, so there is no connection between console_owner -> sclp_lock
  b) after sclp_init completed, it won't be called again, so any
     dependency that requires a call-chain including sclp_init is
     impossible to achieve

Apparently lockdep cannot determine that sclp_init won't be called again.
I'm attaching a patch that moves sclp_init to __init so that lockdep has
a chance of knowing that the function will be gone after init.

This patch is intended for testing only though, to see if there are other
paths to similar possible deadlocks. I still need to decide if its worth
changing the code to remove false positives in lockdep.

A generic solution would be preferable from my point of view though,
because otherwise each console driver owner would need to ensure that any
lock taken in their console.write implementation is never held while
memory is allocated/released.

diff --git a/drivers/s390/char/sclp.c b/drivers/s390/char/sclp.c
index d2ab3f07c008..13219e43d488 100644
--- a/drivers/s390/char/sclp.c
+++ b/drivers/s390/char/sclp.c
@@ -140,7 +140,6 @@ static void sclp_request_timeout(bool force_restart);
 static void sclp_process_queue(void);
 static void __sclp_make_read_req(void);
 static int sclp_init_mask(int calculate);
-static int sclp_init(void);

 static void
 __sclp_queue_read_req(void)
@@ -670,7 +669,8 @@ __sclp_get_mask(sccb_mask_t *receive_mask, sccb_mask_t *send_mask)
 	}
 }

-/* Register event listener. Return 0 on success, non-zero otherwise. */
+/* Register event listener. Return 0 on success, non-zero otherwise. Early
+ * callers (<= arch_initcall) must call sclp_init() first. */
 int
 sclp_register(struct sclp_register *reg)
 {
@@ -679,9 +679,8 @@ sclp_register(struct sclp_register *reg)
 	sccb_mask_t send_mask;
 	int rc;

-	rc = sclp_init();
-	if (rc)
-		return rc;
+	if (sclp_init_state != sclp_init_state_initialized)
+		return -EINVAL;
 	spin_lock_irqsave(&sclp_lock, flags);
 	/* Check event mask for collisions */
 	__sclp_get_mask(&receive_mask, &send_mask);
@@ -1163,8 +1162,7 @@ static struct platform_device *sclp_pdev;

 /* Initialize SCLP driver. Return zero if driver is operational, non-zero
  * otherwise. */
-static int
-sclp_init(void)
+int __init sclp_init(void)
 {
 	unsigned long flags;
 	int rc = 0;
diff --git a/drivers/s390/char/sclp.h b/drivers/s390/char/sclp.h
index 196333013e54..463660261379 100644
--- a/drivers/s390/char/sclp.h
+++ b/drivers/s390/char/sclp.h
@@ -296,6 +296,7 @@ struct sclp_register {
 };

 /* externals from sclp.c */
+int __init sclp_init(void);
 int sclp_add_request(struct sclp_req *req);
 void sclp_sync_wait(void);
 int sclp_register(struct sclp_register *reg);
diff --git a/drivers/s390/char/sclp_con.c b/drivers/s390/char/sclp_con.c
index 8966a1c1b548..a08ef2c8379e 100644
--- a/drivers/s390/char/sclp_con.c
+++ b/drivers/s390/char/sclp_con.c
@@ -319,6 +319,9 @@ sclp_console_init(void)
 	/* SCLP consoles are handled together */
 	if (!(CONSOLE_IS_SCLP || CONSOLE_IS_VT220))
 		return 0;
+	rc = sclp_init();
+	if (rc)
+		return rc;
 	rc = sclp_rw_init();
 	if (rc)
 		return rc;
diff --git a/drivers/s390/char/sclp_vt220.c b/drivers/s390/char/sclp_vt220.c
index 3f9a6ef650fa..28b23e22248b 100644
--- a/drivers/s390/char/sclp_vt220.c
+++ b/drivers/s390/char/sclp_vt220.c
@@ -694,6 +694,11 @@ static int __init __sclp_vt220_init(int num_pages)
 	sclp_vt220_init_count++;
 	if (sclp_vt220_init_count != 1)
 		return 0;
+	rc = sclp_init();
+	if (rc) {
+		sclp_vt220_init_count--;
+		return rc;
+	}
 	spin_lock_init(&sclp_vt220_lock);
 	INIT_LIST_HEAD(&sclp_vt220_empty);
 	INIT_LIST_HEAD(&sclp_vt220_outqueue);
-- 
Peter Oberparleiter
Linux on Z Development - IBM Germany