Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S964976AbcK3NIN (ORCPT ); Wed, 30 Nov 2016 08:08:13 -0500 Received: from mail-wj0-f172.google.com ([209.85.210.172]:35292 "EHLO mail-wj0-f172.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753680AbcK3NIF (ORCPT ); Wed, 30 Nov 2016 08:08:05 -0500 From: Michal Nazarewicz To: Michal Hocko , "Robin H. Johnson" Cc: linux-kernel@vger.kernel.org, robbat2@gentoo.org, linux-mm@kvack.org Subject: Re: PROBLEM-PERSISTS: dmesg spam: alloc_contig_range: [XX, YY) PFNs busy In-Reply-To: <20161130092239.GD18437@dhcp22.suse.cz> Organization: http://mina86.com/ References: <20161130092239.GD18437@dhcp22.suse.cz> User-Agent: Notmuch/0.19+53~g2e63a09 (http://notmuchmail.org) Emacs/26.0.50.2 (x86_64-unknown-linux-gnu) Face: iVBORw0KGgoAAAANSUhEUgAAADAAAAAwBAMAAAClLOS0AAAAJFBMVEWbfGlUPDDHgE57V0jUupKjgIObY0PLrom9mH4dFRK4gmjPs41MxjOgAAACP0lEQVQ4T23Sv2vbQBQHcBk1xE6WyALX107VUEgmn6+ouUwpEQQ6uRjttkWP4CkBg2M0BQLBdPFZYPsyFYo7qEtKDQ7on+t7+nF2Ux8ahD587717OmNYrOvycHsZ+o2r051wHTHysAvGb8ygvgu4QWT0sCmkgZCIEnlV2X8BtyraazFGDuxhmKSQJMlwHQ7v5MHSNxmz78rfElwAa3ieVD9e+hBhjaPDDG6NgFo2f4wBMNIo5YmRtF0RyDgFjJjlMIWbnuM4x9MMfABGTlN4qgIQB4A1DEyA1BHWtfeWNUMwiVJKoqh97KrkOO+qzgluVYLvFCUKAX73nONeBr7BGMdM6Sg0kuep03VywLaIzRiVr+GAzKlpQIsAFnWAG2e6DT5WmWDiudZMIc6hYrMOmeMQK9WX0B+/RfjzL9DI7Y9/Iayn29Ci0r2i4f9gMimMSZLCDMalgQGU5hnUtqAN0OGvEmO1Wnl0C0wWSCEHnuHBqmygxdxA8oWXwbipoc1EoNR9DqOpBpOJrnr0criQab9ZT4LL+wI+K7GBQH30CrhUruilgP9DRTrhVWZCiAyILP+wiuLeCKGTD6r/nc8LOJcAwR6IBTUs+7CASw3QFZ0MdA2PI3zNziH4ZKVhXCRMBjeZ1DWMekKwDCASwExy+NQ86TaykaDAFHO4aP48y4fIcDM5yOG8GcTLbOyp8A8azjJI93JFd1EA6yN8sSxMQJWoABqniRZVykYgRXErzrdqExAoUrRb0xfRp8p2A/4XmfilTtkDZ4cAAAAASUVORK5CYII= X-Face: -TR8(rDTHy/(xl?SfWd1|3:TTgDIatE^t'vop%*gVg[kn$t{EpK(P"VQ=~T2#ysNmJKN$"yTRLB4YQs$4{[.]Fc1)*O]3+XO^oXM>Q#b^ix,O)Zbn)q[y06$`e3?C)`CwR9y5riE=fv^X@x$y?D:XO6L&x4f-}}I4=VRNwiA^t1-ZrVK^07.Pi/57c_du'& X-PGP: 50751FF4 X-PGP-FP: AC1F 5F5C D418 88F8 CC84 5858 2060 4012 5075 1FF4 X-Hashcash: 1:20:161130:linux-mm@kvack.org::9Wvp/ydURV4dQV81:00000000000000000000000000000000000000000001FFt X-Hashcash: 1:20:161130:robbat2@gentoo.org::KiPEnyjtoK1yTY7y:00000000000000000000000000000000000000000002rJc X-Hashcash: 1:20:161130:linux-kernel@vger.kernel.org::N6fgB/yYODUZ5dD5:0000000000000000000000000000000007LEf X-Hashcash: 1:20:161130:robbat2@orbis-terrarum.net::hDXKFDpwjY0YE8k2:0000000000000000000000000000000000016nq X-Hashcash: 1:20:161130:mhocko@kernel.org::80GOvMTSOTJ9xKMM:000000000000000000000000000000000000000000002KjE Date: Wed, 30 Nov 2016 14:08:00 +0100 Message-ID: MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Transfer-Encoding: 8bit X-MIME-Autoconverted: from quoted-printable to 8bit by mail.home.local id uAUD8I1j007623 Content-Length: 5327 Lines: 125 On Wed, Nov 30 2016, Michal Hocko wrote: > [Let's CC linux-mm and Michal] > > On Tue 29-11-16 22:43:08, Robin H. Johnson wrote: >> I didn't get any responses to this. >> >> git bisect shows that the problem did actually exist in 4.5.0-rc6, but >> has gotten worse by many orders of magnitude (< 1/week to ~20M/hour). >> >> Presently with 4.9-rc5, it's now writing ~2.5GB/hour to syslog. > > This is really not helpful. I think we should simply make it pr_debug or > need some ratelimitting. AFAIU the message is far from serious On the other hand, if this didn’t happen and now happens all the time, this indicates a regression in CMA’s capability to allocate pages so just rate limiting the output would hide the potential actual issue. > >> The list of addresses in that time is only ~80 unique ranges, each >> appearing ~320K times. They don't appear exactly in order, so the kernel >> does not squelch the log message for appearing too frequently. >> >> Could somebody at least make a suggestion on how to trace the printed >> range to somewhere in the kernel? >> >> On Sat, Nov 19, 2016 at 03:25:32AM +0000, Robin H. Johnson wrote: >> > (Replies CC to list and direct to me please) >> > >> > Summary: >> > -------- >> > dmesg spammed with alloc_contig_range: [XX, YY) PFNs busy >> > >> > Description: >> > ------------ >> > I recently upgrading 4.9-rc5, (previous kernel 4.5.0-rc6-00141-g6794402), >> > and since then my dmesg has been absolutely flooded with 'PFNs busy' >> > (>3GiB/day). My config did not change (all new options =n). >> > >> > It's not consistent addresses, so the squelch of identical printk lines >> > hasn't helped. >> > Eg output: >> > [187487.621916] alloc_contig_range: [83f0a9, 83f0aa) PFNs busy >> > [187487.621924] alloc_contig_range: [83f0ce, 83f0cf) PFNs busy >> > [187487.621976] alloc_contig_range: [83f125, 83f126) PFNs busy >> > [187487.622013] alloc_contig_range: [83f127, 83f128) PFNs busy >> > >> > Keywords: >> > --------- >> > mm, alloc_contig_range, CMA >> > >> > Most recent kernel version which did not have the bug: >> > ------------------------------------------------------ >> > Known 4.5.0-rc6-00141-g6794402 >> > >> > ver_linux: >> > ---------- >> > Linux bohr-int 4.9.0-rc5-00177-g81bcfe5 #12 SMP Wed Nov 16 13:16:32 PST >> > 2016 x86_64 Intel(R) Core(TM) i7-2600K CPU @ 3.40GHz GenuineIntel >> > GNU/Linux >> > >> > GNU C 5.3.0 >> > GNU Make 4.2.1 >> > Binutils 2.25.1 >> > Util-linux 2.29 >> > Mount 2.29 >> > Quota-tools 4.03 >> > Linux C Library 2.23 >> > Dynamic linker (ldd) 2.23 >> > readlink: missing operand >> > Try 'readlink --help' for more information. >> > Procps 3.3.12 >> > Net-tools 1.60 >> > Kbd 2.0.3 >> > Console-tools 2.0.3 >> > Sh-utils 8.25 >> > Udev 230 >> > Modules Loaded 3w_sas 3w_xxxx ablk_helper aesni_intel >> > aes_x86_64 af_packet ahci aic79xx amdgpu async_memcpy async_pq >> > async_raid6_recov async_tx async_xor ata_piix auth_rpcgss binfmt_misc >> > bluetooth bnep bnx2 bonding btbcm btintel btrfs btrtl btusb button cdrom >> > cn configs coretemp crc32c_intel crc32_pclmul crc_ccitt crc_itu_t >> > crct10dif_pclmul cryptd dca dm_bio_prison dm_bufio dm_cache dm_cache_smq >> > dm_crypt dm_delay dm_flakey dm_log dm_log_userspace dm_mirror dm_mod >> > dm_multipath dm_persistent_data dm_queue_length dm_raid dm_region_hash >> > dm_round_robin dm_service_time dm_snapshot dm_thin_pool dm_zero drm >> > drm_kms_helper dummy e1000 e1000e evdev ext2 fat fb_sys_fops >> > firewire_core firewire_ohci fjes fscache fuse ghash_clmulni_intel >> > glue_helper grace hangcheck_timer hid_a4tech hid_apple hid_belkin >> > hid_cherry hid_chicony hid_cypress hid_ezkey hid_generic hid_gyration >> > hid_logitech hid_logitech_dj hid_microsoft hid_monterey hid_petalynx >> > hid_pl hid_samsung hid_sony hid_sunplus hwmon_vid i2c_algo_bit i2c_i801 >> > i2c_smbus igb input_leds intel_rapl ip6_udp_tunnel ipv6 irqbypass >> > iscsi_tcp iTCO_vendor_support iTCO_wdt ixgb ixgbe jfs kvm kvm_intel >> > libahci libata libcrc32c libiscsi libiscsi_tcp linear lockd lpc_ich lpfc >> > lrw macvlan mdio md_mod megaraid_mbox megaraid_mm megaraid_sas mii >> > mptbase mptfc mptsas mptscsih mptspi multipath nfs nfs_acl nfsd >> > nls_cp437 nls_iso8859_1 nvram ohci_hcd pata_jmicron pata_marvell >> > pata_platform pcspkr psmouse qla1280 qla2xxx r8169 radeon raid0 raid10 >> > raid1 raid456 raid6_pq reiserfs rfkill sata_mv sata_sil24 >> > scsi_transport_fc scsi_transport_iscsi scsi_transport_sas >> > scsi_transport_spi sd_mod sg sky2 snd snd_hda_codec >> > snd_hda_codec_generic snd_hda_codec_hdmi snd_hda_codec_realtek >> > snd_hda_core snd_hda_intel snd_hwdep snd_pcm snd_timer soundcore sr_mod >> > sunrpc syscopyarea sysfillrect sysimgblt tg3 ttm uas udp_tunnel >> > usb_storage vfat virtio virtio_net virtio_ring vxlan w83627ehf >> > x86_pkg_temp_thermal xfs xhci_hcd xhci_pci xor zlib_deflate >> >> -- >> Robin Hugh Johnson >> E-Mail : robbat2@orbis-terrarum.net >> Home Page : http://www.orbis-terrarum.net/?l=people.robbat2 >> ICQ# : 30269588 or 41961639 >> GnuPG FP : 11ACBA4F 4778E3F6 E4EDF38E B27B944E 34884E85 > > > > -- > Michal Hocko > SUSE Labs -- Best regards ミハウ “????????????????86” ナザレヴイツ «If at first you don’t succeed, give up skydiving»