lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20200304002542.GY6548@shao2-debian>
Date:   Wed, 4 Mar 2020 08:25:42 +0800
From:   kernel test robot <rong.a.chen@...el.com>
To:     Anshuman Khandual <anshuman.khandual@....com>
Cc:     Stephen Rothwell <sfr@...b.auug.org.au>,
        Christophe Leroy <christophe.leroy@....fr>,
        Catalin Marinas <catalin.marinas@....com>,
        Ingo Molnar <mingo@...nel.org>,
        Mike Rapoport <rppt@...ux.ibm.com>,
        Vineet Gupta <vgupta@...opsys.com>,
        Will Deacon <will@...nel.org>,
        Benjamin Herrenschmidt <benh@...nel.crashing.org>,
        Paul Mackerras <paulus@...ba.org>,
        Michael Ellerman <mpe@...erman.id.au>,
        Heiko Carstens <heiko.carstens@...ibm.com>,
        Vasily Gorbik <gor@...ux.ibm.com>,
        Christian Borntraeger <borntraeger@...ibm.com>,
        Thomas Gleixner <tglx@...utronix.de>,
        Ingo Molnar <mingo@...hat.com>, Borislav Petkov <bp@...en8.de>,
        "H. Peter Anvin" <hpa@...or.com>,
        "Kirill A. Shutemov" <kirill@...temov.name>,
        Paul Walmsley <paul.walmsley@...ive.com>,
        Palmer Dabbelt <palmer@...belt.com>,
        Andrew Morton <akpm@...ux-foundation.org>,
        LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org
Subject: [mm/debug] 216e0b7a58: BUG:non-zero_pgtables_bytes_on_freeing_mm

FYI, we noticed the following commit (built with gcc-7):

commit: 216e0b7a586b92c286da611aad11ec36e8985755 ("mm/debug: add tests validating architecture page table helpers")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: trinity
with following parameters:

	runtime: 300s

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 8G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+-------------------------------------------------------------------------------+------------+------------+
|                                                                               | ddad3873db | 216e0b7a58 |
+-------------------------------------------------------------------------------+------------+------------+
| boot_successes                                                                | 7          | 0          |
| boot_failures                                                                 | 5          | 12         |
| WARNING:at_kernel/rcu/rcutorture.c:#rcutorture_oom_notify                     | 5          |            |
| EIP:rcutorture_oom_notify                                                     | 5          |            |
| WARNING:at_kernel/locking/lockdep.c:#mark_lock                                | 1          |            |
| EIP:mark_lock                                                                 | 1          |            |
| BUG:kernel_hang_in_test_stage                                                 | 2          |            |
| page_allocation_failure:order:#,mode:#(GFP_NOWAIT|__GFP_COMP),nodemask=(null) | 2          |            |
| Mem-Info                                                                      | 2          |            |
| INFO:trying_to_register_non-static_key                                        | 3          | 1          |
| BUG:unable_to_handle_page_fault_for_address                                   | 1          |            |
| Oops:#[##]                                                                    | 1          |            |
| EIP:rcu_torture_fwd_prog_cbfree                                               | 1          |            |
| Kernel_panic-not_syncing:Fatal_exception                                      | 1          |            |
| BUG:non-zero_pgtables_bytes_on_freeing_mm                                     | 0          | 12         |
| BUG:Bad_page_state_in_process                                                 | 0          | 12         |
+-------------------------------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <rong.a.chen@...el.com>


[   15.579147] BUG: non-zero pgtables_bytes on freeing mm: -4096
[   15.579586] debug: unmapping init [mem 0xc885e000-0xc8a2cfff]
[   15.580585] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[   15.581619] cfg80211: failed to load regulatory.db
[   15.600801] random: fast init done
[   15.611059] Write protecting kernel text and read-only data: 13616k
[   15.611834] NX-protecting the kernel data: 8620k
[   15.625996] x86/mm: Checked W+X mappings: passed, no W+X pages found.
[   15.626813] rodata_test: all tests were successful
[   15.627380] Run /init as init process
[   15.627809]   with arguments:
[   15.628165]     /init
[   15.628442]   with environment:
[   15.628817]     HOME=/
[   15.629103]     TERM=linux
[   15.629431]     user=lkp
[   15.629736]     job=/lkp/jobs/scheduled/vm-snb-i386-14/trinity-300s-yocto-i386-minimal-20190520.cgz-216e0b7a586b92c286da611aad11ec36e8985755-20200304-4330-u6qq9b-10.yaml
[   15.631436]     ARCH=i386
[   15.631718]     kconfig=i386-randconfig-e002-20200228
[   15.632234]     branch=linux-review/Qiujun-Huang/kcsan-Fix-a-typo-in-a-comment/20200228-201130
[   15.633132]     commit=216e0b7a586b92c286da611aad11ec36e8985755
[   15.633780]     BOOT_IMAGE=/pkg/linux/i386-randconfig-e002-20200228/gcc-7/216e0b7a586b92c286da611aad11ec36e8985755/vmlinuz-5.6.0-rc3-00029-g216e0b7a586b9
[   15.635178]     max_uptime=1500
[   15.635566]     RESULT_ROOT=/result/trinity/300s/vm-snb-i386/yocto-i386-minimal-20190520.cgz/i386-randconfig-e002-20200228/gcc-7/216e0b7a586b92c286da611aad11ec36e8985755/8
[   15.637029]     LKP_SERVER=inn
[   15.637260]     selinux=0
[   15.637458]     nmi_watchdog=panic
[   15.637711]     prompt_ramdisk=0
[   15.637952]     earlyprintk=ttyS0,115200
[   15.638243]     vga=normal
[   15.638616] BUG: Bad page state in process swapper/0  pfn:1dc26
[   15.639103] page:ef9af558 refcount:-1 mapcount:0 mapping:00000000 index:0x0
[   15.639610] flags: 0x0()
[   15.639805] raw: 00000000 00000100 00000122 00000000 00000000 c01153c0 ffffffff ffffffff
[   15.640392] raw: 00000000
[   15.640591] page dumped because: nonzero _refcount
[   15.640942] Modules linked in:
[   15.641174] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.6.0-rc3-00029-g216e0b7a586b9 #1
[   15.641751] Call Trace:
[   15.642003]  dump_stack+0x9a/0xd4
[   15.642302]  bad_page+0xc6/0x130
[   15.642549]  check_new_page_bad+0x51/0x70
[   15.642848]  get_page_from_freelist+0x1063/0x1660
[   15.643237]  ? sched_clock_cpu+0x19/0x140
[   15.643641]  __alloc_pages_nodemask+0xee/0xdc0
[   15.644205]  ? __lock_acquire+0x1a7e/0x1f10
[   15.644597]  ? cache_grow_begin+0x565/0xaa0
[   15.644994]  ? lockdep_hardirqs_on+0x124/0x1b0
[   15.645321]  ? cache_grow_begin+0x565/0xaa0
[   15.645709]  ? kmem_cache_alloc+0x310/0x700
[   15.646035]  ? trace_hardirqs_on+0x35/0xf0
[   15.646341]  cache_grow_begin+0x58c/0xaa0
[   15.646717]  ? kmem_cache_alloc+0x93/0x700
[   15.647030]  kmem_cache_alloc+0x310/0x700
[   15.647369]  vm_area_alloc+0x16/0x40
[   15.647645]  __do_execve_file+0x2d5/0x920
[   15.647953]  do_execve+0x1f/0x30
[   15.648215]  run_init_process+0x58/0xa0
[   15.648508]  ? rest_init+0x220/0x220
[   15.648806]  kernel_init+0x50/0xf0
[   15.649070]  ret_from_fork+0x33/0x40
[   15.649344] Disabling lock debugging due to kernel taint
[   15.655890] mount (200) used greatest stack depth: 4 bytes left
Starting udev
[   15.696213] udevd[226]: starting version 3.2.7
[   15.697231] random: udevd: uninitialized urandom read (16 bytes read)
[   15.703596] random: udevd: uninitialized urandom read (16 bytes read)
[   15.704416] random: udevd: uninitialized urandom read (16 bytes read)
[   15.706631] udevd[226]: specified group 'kvm' unknown
[   15.709584] udevd[227]: starting eudev-3.2.7
[   15.740547] udevd[227]: specified group 'kvm' unknown
[   15.756776] Linux agpgart interface v0.103
[   15.783499] rtc_cmos 00:00: RTC can wake from S4
[   15.784329] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0
[   15.788266] piix4_smbus 0000:00:01.3: SMBus region 0x700 already in use!
[   15.788768] piix4_smbus: probe of 0000:00:01.3 failed with error -16
[   15.803389] rtc_cmos 00:00: registered as rtc0
[   15.804107] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram, hpet irqs
[   15.805588] rtc_cmos 00:00: RTC can wake from S4
[   15.820863] rtc_cmos 00:00: registered as rtc1
[   15.821565] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram, hpet irqs
LKP: HOSTNAME vm-snb-i386-14, MAC 6a:43:f3:2d:8e:16, kernel 5.6.0-rc3-00029-g216e0b7a586b9 1, serial console /dev/ttyS0
Poky (Yocto Project Reference Distro) 2.7+snapshot vm-snb-i386-14 /dev/ttyS0
[   28.765565] can: request_module (can-proto-1) failed.
[   28.766367] can: request_module (can-proto-2) failed.
[   28.785933] VFS: Warning: trinity-c2 using old stat() call. Recompile your binary.
[   28.822322] warning: process `trinity-c4' used the deprecated sysctl system call with 
[   28.831669] VFS: Warning: trinity-c1 using old stat() call. Recompile your binary.
[   28.833558] VFS: Warning: trinity-c3 using old stat() call. Recompile your binary.
[   28.835219] vm86_32: Denied a call to vm86(old) from trinity-c3[764] (uid: 65534).  Set the vm.mmap_min_addr sysctl to 0 and/or adjust LSM mmap_min_addr policy to enable vm86 if you are using a vm86-based DOS emulator.
[   28.840307] audit: type=1326 audit(1583252334.460:2): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=764 comm="trinity-c3" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   28.842728] VFS: Warning: trinity-c5 using old stat() call. Recompile your binary.
[   28.845737] VFS: Warning: trinity-c5 using old stat() call. Recompile your binary.
[   28.864103] audit: type=1326 audit(1583252334.490:3): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=761 comm="trinity-c0" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   29.881821] raw_sendmsg: trinity-c7 forgot to set AF_INET. Fix it!
[   31.140533] random: crng init done
[   31.149362] random: 5 urandom warning(s) missed due to ratelimiting
[   31.152945] audit: type=1326 audit(1583252336.780:4): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=779 comm="trinity-c3" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   31.264643] audit: type=1326 audit(1583252336.890:5): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=767 comm="trinity-c6" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   31.290796] audit: type=1326 audit(1583252336.920:6): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=806 comm="trinity-c6" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   31.425043] audit: type=1326 audit(1583252337.050:7): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=808 comm="trinity-c6" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   31.878089] audit: type=1326 audit(1583252337.500:8): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=762 comm="trinity-c1" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   32.165271] futex_wake_op: trinity-c2 tries to shift op by -16; fix this program
[   32.444872] audit: type=1326 audit(1583252338.070:9): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=810 comm="trinity-c6" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   32.577475] audit: type=1326 audit(1583252338.200:10): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=780 comm="trinity-c0" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   39.265054] kauditd_printk_skb: 2 callbacks suppressed
[   39.265057] audit: type=1326 audit(1583252344.890:13): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=799 comm="trinity-c3" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0
[   42.573997] audit: type=1326 audit(1583252348.200:14): auid=4294967295 uid=65534 gid=65534 ses=4294967295 pid=833 comm="trinity-c0" exe="/bin/trinity" sig=9 arch=40000003 syscall=19 compat=0 ip=0xb7f2eb39 code=0x0

Elapsed time: 60

qemu-img create -f qcow2 disk-vm-snb-i386-14-0 256G
qemu-img create -f qcow2 disk-vm-snb-i386-14-1 256G
qemu-img create -f qcow2 disk-vm-snb-i386-14-2 256G
qemu-img create -f qcow2 disk-vm-snb-i386-14-3 256G
qemu-img create -f qcow2 disk-vm-snb-i386-14-4 256G
qemu-img create -f qcow2 disk-vm-snb-i386-14-5 256G
qemu-img create -f qcow2 disk-vm-snb-i386-14-6 256G

kvm=(
	qemu-system-i386
	-enable-kvm
	-cpu SandyBridge
	-kernel $kernel
	-initrd initrd-vm-snb-i386-14.cgz
	-m 8192
	-smp 2
	-device e1000,netdev=net0
	-netdev user,id=net0,hostfwd=tcp::32032-:22
	-boot order=nc
	-no-reboot


To reproduce:

        # build kernel
	cd linux
	cp config-5.6.0-rc3-00029-g216e0b7a586b9 .config
	make HOSTCC=gcc-7 CC=gcc-7 ARCH=i386 olddefconfig prepare modules_prepare bzImage

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
Rong Chen


View attachment "config-5.6.0-rc3-00029-g216e0b7a586b9" of type "text/plain" (134176 bytes)

View attachment "job-script" of type "text/plain" (4495 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (13780 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ