From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-1.9 required=3.0 tests=DKIM_ADSP_CUSTOM_MED, DKIM_INVALID,DKIM_SIGNED,FREEMAIL_FORGED_FROMDOMAIN,FREEMAIL_FROM, HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS, USER_AGENT_SANE_1 autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id D8777C3A5A6 for ; Mon, 23 Sep 2019 10:21:08 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id 7179B206C2 for ; Mon, 23 Sep 2019 10:21:08 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=fail reason="signature verification failed" (2048-bit key) header.d=gmail.com header.i=@gmail.com header.b="IDEfImop" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 7179B206C2 Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=gmail.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix) id 0C7276B0007; Mon, 23 Sep 2019 06:21:08 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id 078106B0008; Mon, 23 Sep 2019 06:21:08 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id EA9976B000A; Mon, 23 Sep 2019 06:21:07 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0131.hostedemail.com [216.40.44.131]) by kanga.kvack.org (Postfix) with ESMTP id C537C6B0007 for ; Mon, 23 Sep 2019 06:21:07 -0400 (EDT) Received: from smtpin05.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay03.hostedemail.com (Postfix) with SMTP id 715C48243765 for ; Mon, 23 Sep 2019 10:21:07 +0000 (UTC) X-FDA: 75965792574.05.lamp11_9b70de082e0d X-HE-Tag: lamp11_9b70de082e0d X-Filterd-Recvd-Size: 10532 Received: from mail-pf1-f195.google.com (mail-pf1-f195.google.com [209.85.210.195]) by imf42.hostedemail.com (Postfix) with ESMTP for ; Mon, 23 Sep 2019 10:21:06 +0000 (UTC) Received: by mail-pf1-f195.google.com with SMTP id x127so8859340pfb.7 for ; Mon, 23 Sep 2019 03:21:06 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=date:from:to:cc:subject:message-id:references:mime-version :content-disposition:content-transfer-encoding:in-reply-to :user-agent; bh=CXvbstD2m08lCzQh36duEA5ws0bxBPn6LqTdvVcfkS4=; b=IDEfImopZM+uhUkTwx6z6NBrJo2aMW0JluC4He2eeVrx3Enr+nqtwDcFdQ90gDWTN7 f5dKe1J5zyEesLT/TIMB4N9k8Aznfh1hRu0K2ice0sEUQzsNEF7ABYH54cBkC2nMXvCW sOEWLqL9bIDP0KhdmDg8oMuztPgg2t0TBvAvacpuoYYybqc7ifYt0XYAu6L+Zyd3z5kW AZtM2lEo9LHDl2+lBZtV8y9kTSYWg7XUzBemMsMa829ubhzUNkhxh6GFy4h8boT+hRpI Y9IKxnj2RBhQ1dlbaypEXmmru6Jm0bnYfcFZfEa/fq9AXS7EE/PczhtK5F/PBdR0hzAB 9rOA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:cc:subject:message-id:references :mime-version:content-disposition:content-transfer-encoding :in-reply-to:user-agent; bh=CXvbstD2m08lCzQh36duEA5ws0bxBPn6LqTdvVcfkS4=; b=H3PQV6ZSg7D89izLwZUqZ25hDvlwJeekcSi5qUmNFwo+Q7VEyAQSMhZvBtPul+Dt6c 4c+D1b07jkgLR3YZW5nOv1hE8XWmDsNZzhN7y7ZQ4ANAivC3G6wllUWUxnAII1p/hwxA Ch5Mu2DpxicauLnMNiR586Woj/ad4PymN3c5IVv6a1R2GrXOr3PuBRzWHNQ6G4PgB67v 8GJpD3JdmLIhwHne+I6lAMTpBbRNXNX2v6DDYs8Iy4Viyb6sad/e55trK676JA789a11 wg24SdIXTZrLWNlxPvtO6ObLN4JpOPWnFVOd5xSBcWJAM+yK1iVk6fx6jM2BjNUGS7TB HM9A== X-Gm-Message-State: APjAAAVxxCTgdDnTb+pLYLxdmxBmgcB8W7rEUUB2lP3odL2Ge/rr8M/A 869NLVdsMOIp+5P2eAx67xo= X-Google-Smtp-Source: APXvYqwgTjx/Ho05abUBRZtOqhFdPYqvJK1KmpHYQN3e+VYW1sen0LuZHG10cGI6bBC7ftaWS4s/8w== X-Received: by 2002:a62:8702:: with SMTP id i2mr32616605pfe.187.1569234065362; Mon, 23 Sep 2019 03:21:05 -0700 (PDT) Received: from localhost ([110.70.15.104]) by smtp.gmail.com with ESMTPSA id q71sm11380351pjb.26.2019.09.23.03.21.03 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Mon, 23 Sep 2019 03:21:04 -0700 (PDT) Date: Mon, 23 Sep 2019 19:21:00 +0900 From: Sergey Senozhatsky To: Qian Cai Cc: Sergey Senozhatsky , Steven Rostedt , Sergey Senozhatsky , Petr Mladek , Catalin Marinas , Will Deacon , Dan Williams , linux-mm@kvack.org, linux-kernel@vger.kernel.org, linux-arm-kernel@lists.infradead.org, Peter Zijlstra , Waiman Long , Thomas Gleixner , Theodore Ts'o , Arnd Bergmann , Greg Kroah-Hartman Subject: Re: printk() + memory offline deadlock (WAS Re: page_alloc.shuffle=1 + CONFIG_PROVE_LOCKING=y = arm64 hang) Message-ID: <20190923102100.GA1171@jagdpanzerIV> References: <1566509603.5576.10.camel@lca.pw> <1567717680.5576.104.camel@lca.pw> <1568128954.5576.129.camel@lca.pw> <20190911011008.GA4420@jagdpanzerIV> <1568289941.5576.140.camel@lca.pw> <20190916104239.124fc2e5@gandalf.local.home> <1568817579.5576.172.camel@lca.pw> <20190918155059.GA158834@tigerII.localdomain> <1568823006.5576.178.camel@lca.pw> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline In-Reply-To: <1568823006.5576.178.camel@lca.pw> User-Agent: Mutt/1.12.2 (2019-09-21) Content-Transfer-Encoding: quoted-printable X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: On (09/18/19 12:10), Qian Cai wrote: [..] > > So you have debug objects enabled. Right? This thing does not behave > > when it comes to printing. debug_objects are slightly problematic. >=20 > Yes, but there is an also a similar splat without the debug_objects. It= looks > like anything try to allocate memory in that path will trigger it anywa= y. Appears to be different, yet somehow very familiar. > [=A0=A0297.425908] WARNING: possible circular locking dependency detect= ed > [=A0=A0297.425908] 5.3.0-next-20190917 #8 Not tainted > [=A0=A0297.425909] ----------------------------------------------------= -- > [=A0=A0297.425910] test.sh/8653 is trying to acquire lock: > [=A0=A0297.425911] ffffffff865a4460 (console_owner){-.-.}, at: > console_unlock+0x207/0x750 >=20 > [=A0=A0297.425914] but task is already holding lock: > [=A0=A0297.425915] ffff88883fff3c58 (&(&zone->lock)->rlock){-.-.}, at: > __offline_isolated_pages+0x179/0x3e0 >=20 > [=A0=A0297.425919] which lock already depends on the new lock. >=20 >=20 > [=A0=A0297.425920] the existing dependency chain (in reverse order) is: >=20 > [=A0=A0297.425922] -> #3 (&(&zone->lock)->rlock){-.-.}: > [=A0=A0297.425925]=A0=A0=A0=A0=A0=A0=A0=A0__lock_acquire+0x5b3/0xb40 > [=A0=A0297.425925]=A0=A0=A0=A0=A0=A0=A0=A0lock_acquire+0x126/0x280 > [=A0=A0297.425926]=A0=A0=A0=A0=A0=A0=A0=A0_raw_spin_lock+0x2f/0x40 > [=A0=A0297.425927]=A0=A0=A0=A0=A0=A0=A0=A0rmqueue_bulk.constprop.21+0xb= 6/0x1160 > [=A0=A0297.425928]=A0=A0=A0=A0=A0=A0=A0=A0get_page_from_freelist+0x898/= 0x22c0 > [=A0=A0297.425928]=A0=A0=A0=A0=A0=A0=A0=A0__alloc_pages_nodemask+0x2f3/= 0x1cd0 > [=A0=A0297.425929]=A0=A0=A0=A0=A0=A0=A0=A0alloc_pages_current+0x9c/0x11= 0 > [=A0=A0297.425930]=A0=A0=A0=A0=A0=A0=A0=A0allocate_slab+0x4c6/0x19c0 > [=A0=A0297.425931]=A0=A0=A0=A0=A0=A0=A0=A0new_slab+0x46/0x70 > [=A0=A0297.425931]=A0=A0=A0=A0=A0=A0=A0=A0___slab_alloc+0x58b/0x960 > [=A0=A0297.425932]=A0=A0=A0=A0=A0=A0=A0=A0__slab_alloc+0x43/0x70 > [=A0=A0297.425933]=A0=A0=A0=A0=A0=A0=A0=A0__kmalloc+0x3ad/0x4b0 > [=A0=A0297.425933]=A0=A0=A0=A0=A0=A0=A0=A0__tty_buffer_request_room+0x1= 00/0x250 > [=A0=A0297.425934]=A0=A0=A0=A0=A0=A0=A0=A0tty_insert_flip_string_fixed_= flag+0x67/0x110 > [=A0=A0297.425935]=A0=A0=A0=A0=A0=A0=A0=A0pty_write+0xa2/0xf0 > [=A0=A0297.425936]=A0=A0=A0=A0=A0=A0=A0=A0n_tty_write+0x36b/0x7b0 > [=A0=A0297.425936]=A0=A0=A0=A0=A0=A0=A0=A0tty_write+0x284/0x4c0 > [=A0=A0297.425937]=A0=A0=A0=A0=A0=A0=A0=A0__vfs_write+0x50/0xa0 > [=A0=A0297.425938]=A0=A0=A0=A0=A0=A0=A0=A0vfs_write+0x105/0x290 > [=A0=A0297.425939]=A0=A0=A0=A0=A0=A0=A0=A0redirected_tty_write+0x6a/0xc= 0 > [=A0=A0297.425939]=A0=A0=A0=A0=A0=A0=A0=A0do_iter_write+0x248/0x2a0 > [=A0=A0297.425940]=A0=A0=A0=A0=A0=A0=A0=A0vfs_writev+0x106/0x1e0 > [=A0=A0297.425941]=A0=A0=A0=A0=A0=A0=A0=A0do_writev+0xd4/0x180 > [=A0=A0297.425941]=A0=A0=A0=A0=A0=A0=A0=A0__x64_sys_writev+0x45/0x50 > [=A0=A0297.425942]=A0=A0=A0=A0=A0=A0=A0=A0do_syscall_64+0xcc/0x76c > [=A0=A0297.425943]=A0=A0=A0=A0=A0=A0=A0=A0entry_SYSCALL_64_after_hwfram= e+0x49/0xbe >=20 > [=A0=A0297.425944] -> #2 (&(&port->lock)->rlock){-.-.}: > [=A0=A0297.425946]=A0=A0=A0=A0=A0=A0=A0=A0__lock_acquire+0x5b3/0xb40 > [=A0=A0297.425947]=A0=A0=A0=A0=A0=A0=A0=A0lock_acquire+0x126/0x280 > [=A0=A0297.425948]=A0=A0=A0=A0=A0=A0=A0=A0_raw_spin_lock_irqsave+0x3a/0= x50 > [=A0=A0297.425949]=A0=A0=A0=A0=A0=A0=A0=A0tty_port_tty_get+0x20/0x60 > [=A0=A0297.425949]=A0=A0=A0=A0=A0=A0=A0=A0tty_port_default_wakeup+0xf/0= x30 > [=A0=A0297.425950]=A0=A0=A0=A0=A0=A0=A0=A0tty_port_tty_wakeup+0x39/0x40 > [=A0=A0297.425951]=A0=A0=A0=A0=A0=A0=A0=A0uart_write_wakeup+0x2a/0x40 > [=A0=A0297.425952]=A0=A0=A0=A0=A0=A0=A0=A0serial8250_tx_chars+0x22e/0x4= 40 > [=A0=A0297.425952]=A0=A0=A0=A0=A0=A0=A0=A0serial8250_handle_irq.part.8+= 0x14a/0x170 > [=A0=A0297.425953]=A0=A0=A0=A0=A0=A0=A0=A0serial8250_default_handle_irq= +0x5c/0x90 > [=A0=A0297.425954]=A0=A0=A0=A0=A0=A0=A0=A0serial8250_interrupt+0xa6/0x1= 30 > [=A0=A0297.425955]=A0=A0=A0=A0=A0=A0=A0=A0__handle_irq_event_percpu+0x7= 8/0x4f0 > [=A0=A0297.425955]=A0=A0=A0=A0=A0=A0=A0=A0handle_irq_event_percpu+0x70/= 0x100 > [=A0=A0297.425956]=A0=A0=A0=A0=A0=A0=A0=A0handle_irq_event+0x5a/0x8b > [=A0=A0297.425957]=A0=A0=A0=A0=A0=A0=A0=A0handle_edge_irq+0x117/0x370 > [=A0=A0297.425958]=A0=A0=A0=A0=A0=A0=A0=A0do_IRQ+0x9e/0x1e0 > [=A0=A0297.425958]=A0=A0=A0=A0=A0=A0=A0=A0ret_from_intr+0x0/0x2a > [=A0=A0297.425959]=A0=A0=A0=A0=A0=A0=A0=A0cpuidle_enter_state+0x156/0x8= e0 > [=A0=A0297.425960]=A0=A0=A0=A0=A0=A0=A0=A0cpuidle_enter+0x41/0x70 > [=A0=A0297.425960]=A0=A0=A0=A0=A0=A0=A0=A0call_cpuidle+0x5e/0x90 > [=A0=A0297.425961]=A0=A0=A0=A0=A0=A0=A0=A0do_idle+0x333/0x370 > [=A0=A0297.425962]=A0=A0=A0=A0=A0=A0=A0=A0cpu_startup_entry+0x1d/0x1f > [=A0=A0297.425962]=A0=A0=A0=A0=A0=A0=A0=A0start_secondary+0x290/0x330 > [=A0=A0297.425963]=A0=A0=A0=A0=A0=A0=A0=A0secondary_startup_64+0xb6/0xc= 0 >=20 > [=A0=A0297.425964] -> #1 (&port_lock_key){-.-.}: > [=A0=A0297.425967]=A0=A0=A0=A0=A0=A0=A0=A0__lock_acquire+0x5b3/0xb40 > [=A0=A0297.425967]=A0=A0=A0=A0=A0=A0=A0=A0lock_acquire+0x126/0x280 > [=A0=A0297.425968]=A0=A0=A0=A0=A0=A0=A0=A0_raw_spin_lock_irqsave+0x3a/0= x50 > [=A0=A0297.425969]=A0=A0=A0=A0=A0=A0=A0=A0serial8250_console_write+0x3e= 4/0x450 > [=A0=A0297.425970]=A0=A0=A0=A0=A0=A0=A0=A0univ8250_console_write+0x4b/0= x60 > [=A0=A0297.425970]=A0=A0=A0=A0=A0=A0=A0=A0console_unlock+0x501/0x750 > [=A0=A0297.425971]=A0=A0=A0=A0=A0=A0=A0=A0vprintk_emit+0x10d/0x340 > [=A0=A0297.425972]=A0=A0=A0=A0=A0=A0=A0=A0vprintk_default+0x1f/0x30 > [=A0=A0297.425972]=A0=A0=A0=A0=A0=A0=A0=A0vprintk_func+0x44/0xd4 > [=A0=A0297.425973]=A0=A0=A0=A0=A0=A0=A0=A0printk+0x9f/0xc5 > [=A0=A0297.425974]=A0=A0=A0=A0=A0=A0=A0=A0register_console+0x39c/0x520 > [=A0=A0297.425975]=A0=A0=A0=A0=A0=A0=A0=A0univ8250_console_init+0x23/0x= 2d > [=A0=A0297.425975]=A0=A0=A0=A0=A0=A0=A0=A0console_init+0x338/0x4cd > [=A0=A0297.425976]=A0=A0=A0=A0=A0=A0=A0=A0start_kernel+0x534/0x724 > [=A0=A0297.425977]=A0=A0=A0=A0=A0=A0=A0=A0x86_64_start_reservations+0x2= 4/0x26 > [=A0=A0297.425977]=A0=A0=A0=A0=A0=A0=A0=A0x86_64_start_kernel+0xf4/0xfb > [=A0=A0297.425978]=A0=A0=A0=A0=A0=A0=A0=A0secondary_startup_64+0xb6/0xc= 0 >=20 > [=A0=A0297.425979] -> #0 (console_owner){-.-.}: > [=A0=A0297.425982]=A0=A0=A0=A0=A0=A0=A0=A0check_prev_add+0x107/0xea0 > [=A0=A0297.425982]=A0=A0=A0=A0=A0=A0=A0=A0validate_chain+0x8fc/0x1200 > [=A0=A0297.425983]=A0=A0=A0=A0=A0=A0=A0=A0__lock_acquire+0x5b3/0xb40 > [=A0=A0297.425984]=A0=A0=A0=A0=A0=A0=A0=A0lock_acquire+0x126/0x280 > [=A0=A0297.425984]=A0=A0=A0=A0=A0=A0=A0=A0console_unlock+0x269/0x750 > [=A0=A0297.425985]=A0=A0=A0=A0=A0=A0=A0=A0vprintk_emit+0x10d/0x340 > [=A0=A0297.425986]=A0=A0=A0=A0=A0=A0=A0=A0vprintk_default+0x1f/0x30 > [=A0=A0297.425987]=A0=A0=A0=A0=A0=A0=A0=A0vprintk_func+0x44/0xd4 > [=A0=A0297.425987]=A0=A0=A0=A0=A0=A0=A0=A0printk+0x9f/0xc5 > [=A0=A0297.425988]=A0=A0=A0=A0=A0=A0=A0=A0__offline_isolated_pages.cold= .52+0x2f/0x30a > [=A0=A0297.425989]=A0=A0=A0=A0=A0=A0=A0=A0offline_isolated_pages_cb+0x1= 7/0x30 > [=A0=A0297.425990]=A0=A0=A0=A0=A0=A0=A0=A0walk_system_ram_range+0xda/0x= 160 > [=A0=A0297.425990]=A0=A0=A0=A0=A0=A0=A0=A0__offline_pages+0x79c/0xa10 > [=A0=A0297.425991]=A0=A0=A0=A0=A0=A0=A0=A0offline_pages+0x11/0x20 > [=A0=A0297.425992]=A0=A0=A0=A0=A0=A0=A0=A0memory_subsys_offline+0x7e/0x= c0 > [=A0=A0297.425992]=A0=A0=A0=A0=A0=A0=A0=A0device_offline+0xd5/0x110 > [=A0=A0297.425993]=A0=A0=A0=A0=A0=A0=A0=A0state_store+0xc6/0xe0 > [=A0=A0297.425994]=A0=A0=A0=A0=A0=A0=A0=A0dev_attr_store+0x3f/0x60 > [=A0=A0297.425995]=A0=A0=A0=A0=A0=A0=A0=A0sysfs_kf_write+0x89/0xb0 > [=A0=A0297.425995]=A0=A0=A0=A0=A0=A0=A0=A0kernfs_fop_write+0x188/0x240 > [=A0=A0297.425996]=A0=A0=A0=A0=A0=A0=A0=A0__vfs_write+0x50/0xa0 > [=A0=A0297.425997]=A0=A0=A0=A0=A0=A0=A0=A0vfs_write+0x105/0x290 > [=A0=A0297.425997]=A0=A0=A0=A0=A0=A0=A0=A0ksys_write+0xc6/0x160 > [=A0=A0297.425998]=A0=A0=A0=A0=A0=A0=A0=A0__x64_sys_write+0x43/0x50 > [=A0=A0297.425999]=A0=A0=A0=A0=A0=A0=A0=A0do_syscall_64+0xcc/0x76c > [=A0=A0297.426000]=A0=A0=A0=A0=A0=A0=A0=A0entry_SYSCALL_64_after_hwfram= e+0x49/0xbe I suppose you run with CONFIG_DEBUG_VM... So we have port->lock -> MM -> zone->lock // from pty_write()->__tty_buffer_request_room()->kmalloc() vs zone->lock -> printk() -> port->lock // from __offline_pages()->__offline_isolated_pages()->printk() A number of debugging options make the kernel less stable. Sad but true. -ss