Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
From:   Stephen Brennan <stephen.s.brennan@oracle.com>
To:     Sergey Senozhatsky <senozhatsky@chromium.org>,
        Petr Mladek <pmladek@suse.com>
Cc:     Steven Rostedt <rostedt@goodmis.org>, linux-kernel@vger.kernel.org,
        John Ogness <john.ogness@linutronix.de>,
        Stephen Brennan <stephen.s.brennan@oracle.com>
Subject: [PATCH v3 3/4] printk: Avoid livelock with heavy printk during panic
Date:   Tue,  1 Feb 2022 10:58:01 -0800
Message-Id: <20220201185802.98345-4-stephen.s.brennan@oracle.com>
In-Reply-To: <20220201185802.98345-1-stephen.s.brennan@oracle.com>
References: <20220201185802.98345-1-stephen.s.brennan@oracle.com>
Content-Transfer-Encoding: 8bit
Content-Type: text/plain
MIME-Version: 1.0
X-MS-Exchange-AntiSpam-MessageData-ChunkCount: 1
X-MS-Exchange-AntiSpam-MessageData-0: =?us-ascii?Q?MLyGtZyIiGlG6FP/Wl/dAMggQFOrvBk7h2EmxiDCylD68GFp/G6s5DIeFBFa?=
 =?us-ascii?Q?CNfuGW5WRdBoCpmfEtmaSUom7BSAJQp12q0dftN5b4CmVwOUM4/zm1byX26a?=
 =?us-ascii?Q?4BpfiY4EYnq7BRJ/sE8GkZMSAN5wiRg1RQ+YQB028Qi17JRpbAE4td2jf8dg?=
 =?us-ascii?Q?dElSXOX4KhFK06/jfKmix9qYI1BLDb8yexjNJACju6LcPyK9iN2S9E2WSyRt?=
 =?us-ascii?Q?MTsfTOUTU3ioX4pcvGcloBI7JeZbSO+V3Mu/mRnzV9OPJJEIBPet2KM+9Zhj?=
 =?us-ascii?Q?2hb+ZC61YThD3KtAHfrLKqo9olels95WtUdUmrmq8PSurnDyN/zEanToAMYU?=
 =?us-ascii?Q?wWfNFlpqJeJIaIaK3ZSjkR9LVwwe4Txm3xG5AdfT8grcqINr8u9ksC5dkqIv?=
 =?us-ascii?Q?pRbqU+Ijruqy7Cu+D0jcybLEucHQE7GLWkL91GZLlI0dneIPBVsWcOmCsyIf?=
 =?us-ascii?Q?/IihGEateEvOlNx7e8YJQTqIuyzhXj3S1vapWZjNQ/Cik1R5nxrW42+JagPP?=
 =?us-ascii?Q?FAnS8BtMPcDK1P4oGIcAL2VeT4Uahw08J6rGHsSkwG7UXo/J0e2wXGxPxFbO?=
 =?us-ascii?Q?qPxTF+ppGyrPZ/40utetarlWmmSQT2CwciCL5zAvKHqn1odNGw5+nRsubFnl?=
 =?us-ascii?Q?mIseS9eRC5UCyEV2Och7wptylzPPtwrPzB1q6Aos52wli8/z2irgnlVf0wST?=
 =?us-ascii?Q?kN9+8AOG5KpTVXGzno16jWX+dQUqgHwe3uNygyJweuDfGAf1tXoYghNHkQdO?=
 =?us-ascii?Q?xmS4R54usPaBMG51mIE39VksoKIYAStmBeS2v2Wdjni3a2jTCmOLbCwNYLsQ?=
 =?us-ascii?Q?kB/z45NjxToSjd/RpeOsuk3xURjgY7h+gzumIG0YKhYEJSOah5uyul67p0OJ?=
 =?us-ascii?Q?oDIr50TDtZ3jyyBSu5A6JZNSai5FWcY61VyTxHwMoi4Jb4ivKwTLil2MFpoi?=
 =?us-ascii?Q?q2LXvVgWuhz/kwCNOYnjXRKfxizA2BOJE2/0FSnOZjIcvt8xvpfsryxj5/Xc?=
 =?us-ascii?Q?kUOYQycosEbgdJi/jHNu+Vwj/QorkVbDZPB0IlMMX3OEIjuOIuvieq43/rFY?=
 =?us-ascii?Q?DqHjlyNZH0M367EbI+rkapx5FnwugScjXINlR1fONr6Hb/s6y/2eB0r5N8NP?=
 =?us-ascii?Q?Z2+tOE9NpKragjJf88rhzVxOn7YQYMlRw2lLdJ0uaf/Ad8aZMaKN/FGq5e95?=
 =?us-ascii?Q?S+wCALFP+igqQTMcWr77RwOAXzI4w1gZPrXRBZN2AaE1VtNP2z0qs+Si3Riz?=
 =?us-ascii?Q?yrOvooBrD8P2Ug4MUNB6gcSeStTbUmO/wFjMc8YRsuEXu8gvt+OKrsfW3CwF?=
 =?us-ascii?Q?SdJUkFwbc7CMrMA4WMqdhCHmFWs9tV7MBZssajuShQvH7/LqCEm6rnSHxo6h?=
 =?us-ascii?Q?GkOhQ4NN7CQ0uIvoLXX/nNluzqKHuAbrpF0f8CF/NoGas6XJTACu4oM7gfYq?=
 =?us-ascii?Q?gl4baf/oAutaiJcYzwYrc2mw8PyQ0DoqSQMcISKAoC3yNNf7EIDZ2cENv7TK?=
 =?us-ascii?Q?RmNkAD4gosDVxeOb96Avd8my+a4FtCiJ7ZN7jv85q9/ftdmKD751wds0zydv?=
 =?us-ascii?Q?rMtnd5jwGKD3MP2PpjuVq7byosB/pfU7JOpmm96yvgqriJZdSZoCHXLtcfXu?=
 =?us-ascii?Q?/BjxTobcF28Ttt2H0o3KZKWQQgce2xDbu03V4YySAuQC2Hfogt8qCGnby7X3?=
 =?us-ascii?Q?/8ISSA=3D=3D?=
X-OriginatorOrg: oracle.com
X-MS-Exchange-CrossTenant-Network-Message-Id: 4587baa9-634d-4323-03a7-08d9e5b4cd46
X-MS-Exchange-CrossTenant-AuthSource: CH2PR10MB4166.namprd10.prod.outlook.com
X-MS-Exchange-CrossTenant-AuthAs: Internal
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 01 Feb 2022 18:58:15.1990
 (UTC)
X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted
X-MS-Exchange-CrossTenant-Id: 4e2c6054-71cb-48f1-bd6c-3a9705aca71b
X-MS-Exchange-CrossTenant-MailboxType: HOSTED
X-MS-Exchange-CrossTenant-UserPrincipalName: cxfqlBx9RAppKPAh72wyT/2dIhSH8K2R0Qkg3tUMsPq8k1iCZLsrQRSx7HMRco57mmCqYOEYklbotoo/8JJ9Box4W+TBsfYRPb5MJTwW5jc=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: BLAPR10MB5156
X-Proofpoint-Virus-Version: vendor=nai engine=6300 definitions=10245 signatures=673430
X-Proofpoint-Spam-Details: rule=notspam policy=default score=0 mlxlogscore=999 adultscore=0
 suspectscore=0 malwarescore=0 bulkscore=0 mlxscore=0 spamscore=0
 phishscore=0 classifier=spam adjust=0 reason=mlx scancount=1
 engine=8.12.0-2201110000 definitions=main-2202010106
X-Proofpoint-GUID: m1jZKStXI1DAtEQ0PsfFS_fLf5dstIdV
X-Proofpoint-ORIG-GUID: m1jZKStXI1DAtEQ0PsfFS_fLf5dstIdV
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org

During panic(), if another CPU is writing heavily the kernel log (e.g.
via /dev/kmsg), then the panic CPU may livelock writing out its messages
to the console. Note when too many messages are dropped during panic and
suppress further printk, except from the panic CPU. This could result in
some important messages being dropped. However, messages are already
being dropped, so this approach at least prevents a livelock.

Reviewed-by: Petr Mladek <pmladek@suse.com>
Signed-off-by: Stephen Brennan <stephen.s.brennan@oracle.com>
---

Notes:
    v3: Use pr_warn_once, and don't break the message line
    v2: Add pr_warn when we suppress printk on non-panic CPU

 kernel/printk/printk.c | 15 +++++++++++++++
 1 file changed, 15 insertions(+)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1b96166eea35..cc7bb86f7bfe 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -93,6 +93,12 @@ EXPORT_SYMBOL_GPL(console_drivers);
  */
 int __read_mostly suppress_printk;
 
+/*
+ * During panic, heavy printk by other CPUs can delay the
+ * panic and risk deadlock on console resources.
+ */
+int __read_mostly suppress_panic_printk;
+
 #ifdef CONFIG_LOCKDEP
 static struct lockdep_map console_lock_dep_map = {
 	.name = "console_lock"
@@ -2233,6 +2239,10 @@ asmlinkage int vprintk_emit(int facility, int level,
 	if (unlikely(suppress_printk))
 		return 0;
 
+	if (unlikely(suppress_panic_printk) &&
+	    atomic_read(&panic_cpu) != raw_smp_processor_id())
+		return 0;
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;
@@ -2618,6 +2628,7 @@ void console_unlock(void)
 {
 	static char ext_text[CONSOLE_EXT_LOG_MAX];
 	static char text[CONSOLE_LOG_MAX];
+	static int panic_console_dropped;
 	unsigned long flags;
 	bool do_cond_resched, retry;
 	struct printk_info info;
@@ -2672,6 +2683,10 @@ void console_unlock(void)
 		if (console_seq != r.info->seq) {
 			console_dropped += r.info->seq - console_seq;
 			console_seq = r.info->seq;
+			if (panic_in_progress() && panic_console_dropped++ > 10) {
+				suppress_panic_printk = 1;
+				pr_warn_once("Too many dropped messages. Supress messages on non-panic CPUs to prevent livelock.\n");
+			}
 		}
 
 		if (suppress_message_printing(r.info->level)) {
-- 
2.30.2