* Kernel NFS boot failure @ 2016-08-03 11:41 Grygorii Strashko 2016-08-03 12:06 ` Vladimir Murzin 0 siblings, 1 reply; 5+ messages in thread From: Grygorii Strashko @ 2016-08-03 11:41 UTC (permalink / raw) To: netdev; +Cc: linux-omap@vger.kernel.org, Sekhar Nori, linux-arm Hi All, We observe Kernel boot failure while running NFS boot stress test (1000 iterations): - Linux version 4.7.0 - am335x-evm (TI AM335x EVM) - failure rate 10-20 times per test. Originally this issue was reproduced using TI Kernel 4.4 ( git://git.ti.com/ti-linux-kernel/ti-linux-kernel.git, branch: ti-linux-4.4.y) on both am335x-evm and am57xx-beagle-x15(am57xx-evm) platforms. This issues has not been reproduced with TI Kernel 4.1 before. The SysRq shows that system stuck in nfs_fs_mount() [ 207.904632] [<c07ab34c>] (schedule) from [<c0783554>] (rpc_wait_bit_killable+0x2c/0xd8) [ 207.912996] [<c0783554>] (rpc_wait_bit_killable) from [<c07ab7f0>] (__wait_on_bit+0x84/0xc0) [ 207.921812] [<c07ab7f0>] (__wait_on_bit) from [<c07ab890>] (out_of_line_wait_on_bit+0x64/0x70) [ 207.930810] [<c07ab890>] (out_of_line_wait_on_bit) from [<c07843f4>] (__rpc_execute+0x18c/0x544) [ 207.939988] [<c07843f4>] (__rpc_execute) from [<c0779f24>] (rpc_run_task+0x13c/0x158) [ 207.948166] [<c0779f24>] (rpc_run_task) from [<c0779f84>] (rpc_call_sync+0x44/0xc4) [ 207.956163] [<c0779f84>] (rpc_call_sync) from [<c077a04c>] (rpc_ping+0x48/0x68) [ 207.963796] [<c077a04c>] (rpc_ping) from [<c077a158>] (rpc_create_xprt+0xec/0x164) [ 207.971702] [<c077a158>] (rpc_create_xprt) from [<c077a2c0>] (rpc_create+0xf0/0x1a0) [ 207.979794] [<c077a2c0>] (rpc_create) from [<c0393088>] (nfs_create_rpc_client+0xd4/0xec) [ 207.988338] [<c0393088>] (nfs_create_rpc_client) from [<c0394d10>] (nfs_init_client+0x20/0x78) [ 207.997332] [<c0394d10>] (nfs_init_client) from [<c03949d4>] (nfs_create_server+0xa0/0x3bc) [ 208.006057] [<c03949d4>] (nfs_create_server) from [<c03b197c>] (nfs3_create_server+0x8/0x20) [ 208.014879] [<c03b197c>] (nfs3_create_server) from [<c03a34c4>] (nfs_try_mount+0xc4/0x1f0) [ 208.023513] [<c03a34c4>] (nfs_try_mount) from [<c03a2c48>] (nfs_fs_mount+0x290/0x910) [ 208.031702] [<c03a2c48>] (nfs_fs_mount) from [<c0294d24>] (mount_fs+0x44/0x168) Has anyone else seen this issue? I'd be appreciated for any help or advice related to this issue? Thanks in advance. regards, -grygorii =================== kernel log ======================= Starting kernel ... [ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 4.7.0 (lcpdbld@dflsdit-build06.dal.design.ti.com) (gcc version 4.9.3 20150413 (prerelease) (Linaro GCC 4.9-2015.05) ) #1 SMP Fri Jul 29 17:41:27 CDT 2016 [ 0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache [ 0.000000] Machine model: TI AM335x EVM [ 0.000000] cma: Reserved 16 MiB at 0xbe800000 [ 0.000000] Memory policy: Data cache writeback [ 0.000000] CPU: All CPU(s) started in SVC mode. [ 0.000000] AM335X ES2.1 (sgx neon ) [ 0.000000] percpu: Embedded 15 pages/cpu @ef6b9000 s29440 r8192 d23808 u61440 [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 259904 [ 0.000000] Kernel command line: console=ttyO0,115200n8 earlyprintk=serial,ttyO0,115200n8 rootwait ip=:::::eth0:dhcp root=/dev/nfs rw nfsroot=192.168.0.1:/home/tigtfarm04/NFS_exports/linux/am335x-evm/autofs/bdb57ec4c06590e6172879867ab30d1e,nolock,v3,tcp,rsize=4096,wsize=4096 [ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes) [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Memory: 999648K/1046528K available (7354K kernel code, 768K rwdata, 2360K rodata, 1024K init, 8122K bss, 30496K reserved, 16384K cma-reserved, 243712K highmem) [ 0.000000] Virtual kernel memory layout: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB) [ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB) [ 0.000000] vmalloc : 0xf0800000 - 0xff800000 ( 240 MB) [ 0.000000] lowmem : 0xc0000000 - 0xf0000000 ( 768 MB) [ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB) [ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB) [ 0.000000] .text : 0xc0008000 - 0xc0a7c8e8 (10707 kB) [ 0.000000] .init : 0xc0b00000 - 0xc0c00000 (1024 kB) [ 0.000000] .data : 0xc0c00000 - 0xc0cc0304 ( 769 kB) [ 0.000000] .bss : 0xc0cc2000 - 0xc14b0a40 (8123 kB) [ 0.000000] Running RCU self tests [ 0.000000] Hierarchical RCU implementation. [ 0.000000] RCU lockdep checking is enabled. [ 0.000000] Build-time adjustment of leaf fanout to 32. [ 0.000000] RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1. [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=32, nr_cpu_ids=1 [ 0.000000] NR_IRQS:16 nr_irqs:16 16 [ 0.000000] IRQ: Found an INTC at 0xfa200000 (revision 5.0) with 128 interrupts [ 0.000000] OMAP clockevent source: timer2 at 24000000 Hz [ 0.000017] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 89478484971ns [ 0.000039] clocksource: timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 79635851949 ns [ 0.000090] OMAP clocksource: timer1 at 24000000 Hz [ 0.000600] clocksource_probe: no matching clocksources found [ 0.001543] Console: colour dummy device 80x30 [ 0.001605] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 0.001615] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 0.001622] ... MAX_LOCK_DEPTH: 48 [ 0.001630] ... MAX_LOCKDEP_KEYS: 8191 [ 0.001637] ... CLASSHASH_SIZE: 4096 [ 0.001645] ... MAX_LOCKDEP_ENTRIES: 32768 [ 0.001652] ... MAX_LOCKDEP_CHAINS: 65536 [ 0.001659] ... CHAINHASH_SIZE: 32768 [ 0.001667] memory used by lock dependency info: 5167 kB [ 0.001675] per task-struct memory footprint: 1536 bytes [ 0.001709] Calibrating delay loop... 996.14 BogoMIPS (lpj=4980736) [ 0.078684] pid_max: default: 32768 minimum: 301 [ 0.079156] Security Framework initialized [ 0.079302] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.079317] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.082842] CPU: Testing write buffer coherency: ok [ 0.084628] CPU0: thread -1, cpu 0, socket -1, mpidr 0 [ 0.084709] Setting up static identity map for 0x80100000 - 0x80100070 [ 0.089402] Brought up 1 CPUs [ 0.089425] SMP: Total of 1 processors activated (996.14 BogoMIPS). [ 0.089436] CPU: All CPU(s) started in SVC mode. [ 0.093423] devtmpfs: initialized [ 0.133262] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3 [ 0.134204] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.135944] pinctrl core: initialized pinctrl subsystem [ 0.141766] NET: Registered protocol family 16 [ 0.147074] DMA: preallocated 256 KiB pool for atomic coherent allocations [ 0.203979] omap_hwmod: debugss: _wait_target_disable failed [ 0.261060] cpuidle: using governor menu [ 0.274990] OMAP GPIO hardware version 0.1 [ 0.301030] omap-gpmc 50000000.gpmc: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/nandflash_pins_s0, deferring probe [ 0.307161] No ATAGs? [ 0.307186] hw-breakpoint: debug architecture 0x4 unsupported. [ 0.307435] omap4_sram_init:Unable to allocate sram needed to handle errata I688 [ 0.307451] omap4_sram_init:Unable to get sram pool needed to handle errata I688 [ 0.354305] edma 49000000.edma: TI EDMA DMA engine driver [ 0.361450] SCSI subsystem initialized [ 0.363558] omap_i2c 44e0b000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c0_pins, deferring probe [ 0.363669] omap_i2c 4802a000.i2c: could not find pctldev for node /ocp/l4_wkup@44c00000/scm@210000/pinmux@800/pinmux_i2c1_pins, deferring probe [ 0.363964] pps_core: LinuxPPS API ver. 1 registered [ 0.363975] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it> [ 0.364026] PTP clock support registered [ 0.368809] clocksource: Switched to clocksource timer1 [ 0.471686] VFS: Disk quotas dquot_6.6.0 [ 0.471879] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) [ 0.504828] NET: Registered protocol family 2 [ 0.507032] TCP established hash table entries: 8192 (order: 3, 32768 bytes) [ 0.507202] TCP bind hash table entries: 8192 (order: 6, 294912 bytes) [ 0.509721] TCP: Hash tables configured (established 8192 bind 8192) [ 0.510050] UDP hash table entries: 512 (order: 3, 40960 bytes) [ 0.510377] UDP-Lite hash table entries: 512 (order: 3, 40960 bytes) [ 0.511368] NET: Registered protocol family 1 [ 0.513282] RPC: Registered named UNIX socket transport module. [ 0.513309] RPC: Registered udp transport module. [ 0.513320] RPC: Registered tcp transport module. [ 0.513330] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.516207] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available [ 0.521290] futex hash table entries: 256 (order: 2, 16384 bytes) [ 0.521519] audit: initializing netlink subsys (disabled) [ 0.521801] audit: type=2000 audit(0.510:1): initialized [ 0.525994] workingset: timestamp_bits=12 max_order=18 bucket_order=6 [ 0.528964] NFS: Registering the id_resolver key type [ 0.529371] Key type id_resolver registered [ 0.529388] Key type id_legacy registered [ 0.529583] jffs2: version 2.2. (NAND) (SUMMARY) 2001-2006 Red Hat, Inc. [ 0.535376] bounce: pool size: 64 pages [ 0.535560] io scheduler noop registered [ 0.535575] io scheduler deadline registered [ 0.535632] io scheduler cfq registered (default) [ 0.538164] pinctrl-single 44e10800.pinmux: 142 pins at pa f9e10800 size 568 [ 0.543123] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 0.549627] omap_uart 44e09000.serial: no wakeirq for uart0 [ 0.550363] 44e09000.serial: ttyO0 at MMIO 0x44e09000 (irq = 158, base_baud = 3000000) is a OMAP UART0 [ 1.280532] console [ttyO0] enabled [ 1.286200] omap_uart 48022000.serial: no wakeirq for uart1 [ 1.292563] 48022000.serial: ttyO1 at MMIO 0x48022000 (irq = 159, base_baud = 3000000) is a OMAP UART1 [ 1.343677] brd: module loaded [ 1.372084] loop: module loaded [ 1.378098] mtdoops: mtd device (mtddev=name/number) must be supplied [ 1.448758] davinci_mdio 4a101000.mdio: davinci mdio revision 1.6 [ 1.455149] davinci_mdio 4a101000.mdio: detected phy mask fffffffe [ 1.466091] libphy: 4a101000.mdio: probed [ 1.470478] davinci_mdio 4a101000.mdio: phy[0]: device 4a101000.mdio:00, driver Atheros 8031 ethernet [ 1.481604] cpsw 4a100000.ethernet: Detected MACID = d0:ff:50:57:02:d9 [ 1.494503] mousedev: PS/2 mouse device common for all mice [ 1.500507] i2c /dev entries driver [ 1.506791] omap_hsmmc 48060000.mmc: Got CD GPIO [ 1.629181] ledtrig-cpu: registered to indicate activity on CPUs [ 1.637125] oprofile: using arm/armv7 [ 1.641883] Initializing XFRM netlink socket [ 1.646812] NET: Registered protocol family 10 [ 1.657446] sit: IPv6 over IPv4 tunneling driver [ 1.664949] NET: Registered protocol family 17 [ 1.669812] NET: Registered protocol family 15 [ 1.674901] Key type dns_resolver registered [ 1.679650] omap_voltage_late_init: Voltage driver support not added [ 1.686325] sr_dev_init: No voltage domain specified for smartreflex0. Cannot initialize [ 1.694833] sr_dev_init: No voltage domain specified for smartreflex1. Cannot initialize [ 1.704103] ThumbEE CPU extension supported. [ 1.708687] Registering SWP/SWPB emulation handler [ 1.713694] SmartReflex Class3 initialized [ 1.727416] omap-gpmc 50000000.gpmc: omap_device: omap_device_enable() called from invalid state 1 [ 1.736984] omap-gpmc 50000000.gpmc: use pm_runtime_put_sync_suspend() in driver? [ 1.744891] omap-gpmc 50000000.gpmc: GPMC revision 6.0 [ 1.750534] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000 [ 1.763255] nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xda [ 1.770059] nand: Micron MT29F2G08ABAEAWP [ 1.774253] nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64 [ 1.782278] nand: using OMAP_ECC_BCH8_CODE_HW ECC scheme [ 1.788157] 10 ofpart partitions found on MTD device 8000000.nand [ 1.794573] Creating 10 MTD partitions on "8000000.nand": [ 1.800255] 0x000000000000-0x000000020000 : "NAND.SPL" [ 1.813707] 0x000000020000-0x000000040000 : "NAND.SPL.backup1" [ 1.824552] 0x000000040000-0x000000060000 : "NAND.SPL.backup2" [ 1.835304] 0x000000060000-0x000000080000 : "NAND.SPL.backup3" [ 1.845935] 0x000000080000-0x0000000c0000 : "NAND.u-boot-spl-os" [ 1.856686] 0x0000000c0000-0x0000001c0000 : "NAND.u-boot" [ 1.867218] 0x0000001c0000-0x0000001e0000 : "NAND.u-boot-env" [ 1.877621] 0x0000001e0000-0x000000200000 : "NAND.u-boot-env.backup1" [ 1.888812] 0x000000200000-0x000000a00000 : "NAND.kernel" [ 1.901811] 0x000000a00000-0x000010000000 : "NAND.file-system" [ 2.029897] tps65910 0-002d: No interrupt support, no core IRQ [ 2.040322] vrtc: supplied by vbat [ 2.051821] vio: supplied by vbat [ 2.058770] vdd1: supplied by vbat [ 2.063500] vdd_mpu: Bringing 1325000uV into 1312500-1312500uV [ 2.072533] vdd2: supplied by vbat [ 2.082954] vdig1: supplied by vbat [ 2.089848] vdig2: supplied by vbat [ 2.096603] vpll: supplied by vbat [ 2.103298] vdac: supplied by vbat [ 2.110075] vaux1: supplied by vbat [ 2.116777] vaux2: supplied by vbat [ 2.123576] vaux33: supplied by vbat [ 2.130510] vmmc: supplied by vbat [ 2.137134] vbb: supplied by vbat [ 2.143675] omap_i2c 44e0b000.i2c: bus 0 rev0.11 at 400 kHz [ 2.154258] omap_i2c 4802a000.i2c: bus 1 rev0.11 at 100 kHz [ 2.161584] omap_hsmmc 48060000.mmc: Got CD GPIO [ 2.211668] hctosys: unable to open rtc device (rtc0) [ 2.216968] sr_init: No PMIC hook to init smartreflex [ 2.222637] sr_init: platform driver register failed for SR [ 2.247587] net eth0: initializing cpsw version 1.12 (0) [ 2.286454] mmc1: host does not support reading read-only switch, assuming write-enable [ 2.296952] mmc1: new high speed SDHC card at address 59b4 [ 2.306618] mmcblk1: mmc1:59b4 NCard 7.51 GiB [ 2.315976] mmcblk1: p1 p2 p3 [ 2.329789] Atheros 8031 ethernet 4a101000.mdio:00: attached PHY driver [Atheros 8031 ethernet] (mii_bus:phy_addr=4a101000.mdio:00, irq=-1) [ 2.343148] libphy: PHY 4a101000.mdio:01 not found [ 2.348160] net eth0: phy "4a101000.mdio:01" not found on slave 1, err -19 [ 2.363596] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 6.329622] cpsw 4a100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx [ 6.338420] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 6.349476] Sending DHCP requests ., OK [ 6.409166] IP-Config: Got DHCP answer from 192.168.0.1, my address is 192.168.0.175 [ 6.417934] IP-Config: Complete: [ 6.421439] device=eth0, hwaddr=d0:ff:50:57:02:d9, ipaddr=192.168.0.175, mask=255.255.255.0, gw=192.168.0.1 [ 6.432099] host=192.168.0.175, domain=ti.com, nis-domain=(none) [ 6.438849] bootserver=192.168.0.1, rootserver=192.168.0.1, rootpath= nameserver0=192.0.2.2, nameserver1=192.0.2.3 [ 6.450704] lis3_reg: disabling [ 6.453996] wlan-en-regulator: disabling [ 194.829109] random: nonblocking pool is initialized - 20:53:45 [INFO] Boot attempt 1/1 failed - 20:53:45 [INFO] Collecting kernel traces via sysrq... - 20:53:55 [INFO] [ 207.881249] sysrq: SysRq : Show State [ 207.885105] task PC stack pid father [ 207.890567] swapper/0 D c07aaa40 0 1 0 0x00000000 [ 207.897255] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 207.904632] [<c07ab34c>] (schedule) from [<c0783554>] (rpc_wait_bit_killable+0x2c/0xd8) [ 207.912996] [<c0783554>] (rpc_wait_bit_killable) from [<c07ab7f0>] (__wait_on_bit+0x84/0xc0) [ 207.921812] [<c07ab7f0>] (__wait_on_bit) from [<c07ab890>] (out_of_line_wait_on_bit+0x64/0x70) [ 207.930810] [<c07ab890>] (out_of_line_wait_on_bit) from [<c07843f4>] (__rpc_execute+0x18c/0x544) [ 207.939988] [<c07843f4>] (__rpc_execute) from [<c0779f24>] (rpc_run_task+0x13c/0x158) [ 207.948166] [<c0779f24>] (rpc_run_task) from [<c0779f84>] (rpc_call_sync+0x44/0xc4) [ 207.956163] [<c0779f84>] (rpc_call_sync) from [<c077a04c>] (rpc_ping+0x48/0x68) [ 207.963796] [<c077a04c>] (rpc_ping) from [<c077a158>] (rpc_create_xprt+0xec/0x164) [ 207.971702] [<c077a158>] (rpc_create_xprt) from [<c077a2c0>] (rpc_create+0xf0/0x1a0) [ 207.979794] [<c077a2c0>] (rpc_create) from [<c0393088>] (nfs_create_rpc_client+0xd4/0xec) [ 207.988338] [<c0393088>] (nfs_create_rpc_client) from [<c0394d10>] (nfs_init_client+0x20/0x78) [ 207.997332] [<c0394d10>] (nfs_init_client) from [<c03949d4>] (nfs_create_server+0xa0/0x3bc) [ 208.006057] [<c03949d4>] (nfs_create_server) from [<c03b197c>] (nfs3_create_server+0x8/0x20) [ 208.014879] [<c03b197c>] (nfs3_create_server) from [<c03a34c4>] (nfs_try_mount+0xc4/0x1f0) [ 208.023513] [<c03a34c4>] (nfs_try_mount) from [<c03a2c48>] (nfs_fs_mount+0x290/0x910) [ 208.031702] [<c03a2c48>] (nfs_fs_mount) from [<c0294d24>] (mount_fs+0x44/0x168) [ 208.039350] [<c0294d24>] (mount_fs) from [<c02b3420>] (vfs_kern_mount+0x54/0x134) [ 208.047171] [<c02b3420>] (vfs_kern_mount) from [<c02b6c40>] (do_mount+0x1d4/0xd30) [ 208.055078] [<c02b6c40>] (do_mount) from [<c02b7b08>] (SyS_mount+0x74/0x9c) [ 208.062363] [<c02b7b08>] (SyS_mount) from [<c0b014b4>] (mount_root+0x5c/0x124) [ 208.069910] [<c0b014b4>] (mount_root) from [<c0b016e0>] (prepare_namespace+0x164/0x1c8) [ 208.078272] [<c0b016e0>] (prepare_namespace) from [<c0b00f08>] (kernel_init_freeable+0x28c/0x2e0) [ 208.087541] [<c0b00f08>] (kernel_init_freeable) from [<c07a9418>] (kernel_init+0x8/0x118) [ 208.096092] [<c07a9418>] (kernel_init) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.103996] kthreadd S c07aaa40 0 2 0 0x00000000 [ 208.110653] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.118022] [<c07ab34c>] (schedule) from [<c015b258>] (kthreadd+0x220/0x248) [ 208.125386] [<c015b258>] (kthreadd) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.133017] ksoftirqd/0 S c07aaa40 0 3 2 0x00000000 [ 208.139672] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.147037] [<c07ab34c>] (schedule) from [<c015e158>] (smpboot_thread_fn+0xd0/0x194) [ 208.155126] [<c015e158>] (smpboot_thread_fn) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.163034] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.170573] kworker/0:0 S c07aaa40 0 4 2 0x00000000 [ 208.177243] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.184618] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 208.192344] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.199889] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.207428] kworker/0:0H S c07aaa40 0 5 2 0x00000000 [ 208.214088] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.221452] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 208.229177] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.236721] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.244260] kworker/u2:0 S c07aaa40 0 6 2 0x00000000 [ 208.250918] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.258282] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 208.266007] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.273551] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.281090] rcu_sched S c07aaa40 0 7 2 0x00000000 [ 208.287744] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.295120] [<c07ab34c>] (schedule) from [<c01ab8b8>] (rcu_gp_kthread+0x40/0x814) [ 208.302938] [<c01ab8b8>] (rcu_gp_kthread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.310573] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.318112] rcu_bh S c07aaa40 0 8 2 0x00000000 [ 208.324766] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.332130] [<c07ab34c>] (schedule) from [<c01ab8b8>] (rcu_gp_kthread+0x40/0x814) [ 208.339946] [<c01ab8b8>] (rcu_gp_kthread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.347581] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.355120] migration/0 S c07aaa40 0 9 2 0x00000000 [ 208.361774] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.369137] [<c07ab34c>] (schedule) from [<c015e158>] (smpboot_thread_fn+0xd0/0x194) [ 208.377224] [<c015e158>] (smpboot_thread_fn) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.385131] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.392670] lru-add-drain S c07aaa40 0 10 2 0x00000000 [ 208.399328] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.406692] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.414600] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.422234] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.429774] cpuhp/0 S c07aaa40 0 11 2 0x00000000 [ 208.436428] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.443791] [<c07ab34c>] (schedule) from [<c015e158>] (smpboot_thread_fn+0xd0/0x194) [ 208.451879] [<c015e158>] (smpboot_thread_fn) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.459785] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.467324] kdevtmpfs S c07aaa40 0 12 2 0x00000000 [ 208.473978] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.481353] [<c07ab34c>] (schedule) from [<c052a61c>] (devtmpfsd+0x2b8/0x2e4) [ 208.488809] [<c052a61c>] (devtmpfsd) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.495990] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.503529] netns S c07aaa40 0 13 2 0x00000000 [ 208.510188] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.517553] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.525460] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.533094] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.540633] kworker/0:1 S c07aaa40 0 14 2 0x00000000 [ 208.547291] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.554655] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 208.562380] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.569924] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.577463] oom_reaper S c07aaa40 0 15 2 0x00000000 [ 208.584116] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.591480] [<c07ab34c>] (schedule) from [<c0233250>] (oom_reaper+0x134/0x194) [ 208.599025] [<c0233250>] (oom_reaper) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.606297] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.613836] writeback S c07aaa40 0 16 2 0x00000000 [ 208.620494] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.627858] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.635765] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.643399] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.650939] kcompactd0 S c07aaa40 0 17 2 0x00000000 [ 208.657593] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.664962] [<c07ab34c>] (schedule) from [<c025e868>] (kcompactd+0x490/0x5b0) [ 208.672417] [<c025e868>] (kcompactd) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.679598] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.687137] crypto S c07aaa40 0 18 2 0x00000000 [ 208.693795] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.701160] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.709067] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.716701] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.724240] bioset S c07aaa40 0 19 2 0x00000000 [ 208.730900] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.738264] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.746171] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.753805] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.761344] kblockd S c07aaa40 0 20 2 0x00000000 [ 208.768003] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.775367] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.783274] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.790909] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.798448] ata_sff S c07aaa40 0 21 2 0x00000000 [ 208.805105] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.812470] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.820376] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.828011] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.835550] watchdogd S c07aaa40 0 22 2 0x00000000 [ 208.842208] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.849572] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.857478] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.865112] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.872652] rpciod S c07aaa40 0 23 2 0x00000000 [ 208.879311] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.886674] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.894581] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.902216] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.909755] kswapd0 S c07aaa40 0 24 2 0x00000000 [ 208.916409] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.923774] [<c07ab34c>] (schedule) from [<c024aca4>] (kswapd+0x9e4/0xb44) [ 208.930955] [<c024aca4>] (kswapd) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.937864] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.945403] vmstat S c07aaa40 0 25 2 0x00000000 [ 208.952062] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.959426] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 208.967333] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 208.974967] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 208.982506] nfsiod S c07aaa40 0 26 2 0x00000000 [ 208.989164] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 208.996528] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.004435] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.012070] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.019609] bioset S c07aaa40 0 37 2 0x00000000 [ 209.026267] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.033631] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.041537] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.049172] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.056711] bioset S c07aaa40 0 38 2 0x00000000 [ 209.063369] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.070733] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.078640] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.086274] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.093813] bioset S c07aaa40 0 39 2 0x00000000 [ 209.100472] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.107836] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.115743] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.123377] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.130916] bioset S c07aaa40 0 40 2 0x00000000 [ 209.137575] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.144939] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.152846] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.160480] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.168019] bioset S c07aaa40 0 41 2 0x00000000 [ 209.174677] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.182041] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.189948] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.197582] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.205122] bioset S c07aaa40 0 42 2 0x00000000 [ 209.211779] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.219144] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.227051] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.234685] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.242224] bioset S c07aaa40 0 43 2 0x00000000 [ 209.248883] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.256246] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.264153] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.271788] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.279327] bioset S c07aaa40 0 44 2 0x00000000 [ 209.285984] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.293348] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.301255] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.308889] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.316429] bioset S c07aaa40 0 45 2 0x00000000 [ 209.323087] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.330451] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.338358] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.345993] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.353532] bioset S c07aaa40 0 46 2 0x00000000 [ 209.360191] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.367555] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.375461] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.383096] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.390635] bioset S c07aaa40 0 47 2 0x00000000 [ 209.397293] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.404657] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.412564] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.420199] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.427738] bioset S c07aaa40 0 48 2 0x00000000 [ 209.434396] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.441760] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.449667] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.457301] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.464840] bioset S c07aaa40 0 49 2 0x00000000 [ 209.471498] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.478862] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.486768] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.494403] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.501942] bioset S c07aaa40 0 50 2 0x00000000 [ 209.508600] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.515964] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.523871] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.531505] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.539044] bioset S c07aaa40 0 51 2 0x00000000 [ 209.545702] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.553066] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.560974] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.568608] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.576147] bioset S c07aaa40 0 52 2 0x00000000 [ 209.582805] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.590169] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.598076] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.605711] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.613250] bioset S c07aaa40 0 53 2 0x00000000 [ 209.619908] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.627272] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.635179] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.642814] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.650353] bioset S c07aaa40 0 54 2 0x00000000 [ 209.657012] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.664375] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.672282] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.679917] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.687456] bioset S c07aaa40 0 55 2 0x00000000 [ 209.694115] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.701479] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.709386] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.717020] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.724559] bioset S c07aaa40 0 56 2 0x00000000 [ 209.731217] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.738581] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.746488] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.754122] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.761662] bioset S c07aaa40 0 57 2 0x00000000 [ 209.768320] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.775684] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.783590] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.791225] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.798764] bioset S c07aaa40 0 58 2 0x00000000 [ 209.805422] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.812786] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.820693] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.828327] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.835866] bioset S c07aaa40 0 59 2 0x00000000 [ 209.842524] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.849888] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.857795] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.865429] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.872969] bioset S c07aaa40 0 60 2 0x00000000 [ 209.879627] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.886991] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.894898] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.902532] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.910071] kworker/u2:1 S c07aaa40 0 61 2 0x00000000 [ 209.916730] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.924094] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 209.931819] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.939363] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.946902] ipv6_addrconf S c07aaa40 0 63 2 0x00000000 [ 209.953560] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.960924] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 209.968831] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 209.976465] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 209.984005] kworker/0:2 S c07aaa40 0 64 2 0x00000000 [ 209.990663] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 209.998027] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 210.005752] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.013296] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.020835] deferwq S c07aaa40 0 65 2 0x00000000 [ 210.027493] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.034857] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.042764] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.050398] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.057937] bioset S c07aaa40 0 66 2 0x00000000 [ 210.064595] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.071959] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.079866] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.087500] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.095039] bioset S c07aaa40 0 67 2 0x00000000 [ 210.101697] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.109061] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.116968] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.124602] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.132141] bioset S c07aaa40 0 68 2 0x00000000 [ 210.138799] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.146163] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.154070] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.161704] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.169243] bioset S c07aaa40 0 69 2 0x00000000 [ 210.175902] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.183266] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.191172] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.198807] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.206346] bioset S c07aaa40 0 70 2 0x00000000 [ 210.213004] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.220369] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.228275] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.235910] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.243449] bioset S c07aaa40 0 71 2 0x00000000 [ 210.250107] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.257471] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.265378] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.273012] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.280552] bioset S c07aaa40 0 72 2 0x00000000 [ 210.287210] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.294574] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.302481] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.310115] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.317654] bioset S c07aaa40 0 73 2 0x00000000 [ 210.324313] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.331677] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.339584] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.347218] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.354757] bioset S c07aaa40 0 74 2 0x00000000 [ 210.361416] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.368780] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.376687] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.384322] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.391861] bioset S c07aaa40 0 75 2 0x00000000 [ 210.398520] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.405884] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.413790] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.421425] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.428964] irq/160-44e0b00 S c07aaa40 0 76 2 0x00000000 [ 210.435617] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.442990] [<c07ab34c>] (schedule) from [<c019ffc4>] (irq_thread+0xb0/0x200) [ 210.450444] [<c019ffc4>] (irq_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.457716] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.465255] irq/161-4802a00 S c07aaa40 0 77 2 0x00000000 [ 210.471910] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.479273] [<c07ab34c>] (schedule) from [<c019ffc4>] (irq_thread+0xb0/0x200) [ 210.486726] [<c019ffc4>] (irq_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.493998] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.501537] irq/33-48060000 S c07aaa40 0 78 2 0x00000000 [ 210.508191] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.515554] [<c07ab34c>] (schedule) from [<c019ffc4>] (irq_thread+0xb0/0x200) [ 210.523007] [<c019ffc4>] (irq_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.530279] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.537818] bioset S c07aaa40 0 79 2 0x00000000 [ 210.544477] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.551841] [<c07ab34c>] (schedule) from [<c0154da0>] (rescuer_thread+0x28c/0x300) [ 210.559748] [<c0154da0>] (rescuer_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.567382] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.574922] mmcqd/1 S c07aaa40 0 80 2 0x00000000 [ 210.581575] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.588941] [<c07ab34c>] (schedule) from [<c0616eac>] (mmc_queue_thread+0x11c/0x174) [ 210.597030] [<c0616eac>] (mmc_queue_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.604846] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.612385] kworker/0:1H S c07aaa40 0 81 2 0x00000000 [ 210.619044] [<c07aaa40>] (__schedule) from [<c07ab34c>] (schedule+0x44/0x9c) [ 210.626407] [<c07ab34c>] (schedule) from [<c01546e8>] (worker_thread+0xa4/0x4d0) [ 210.634133] [<c01546e8>] (worker_thread) from [<c015a6b4>] (kthread+0xd4/0xf0) [ 210.641676] [<c015a6b4>] (kthread) from [<c01078d0>] (ret_from_fork+0x14/0x24) [ 210.649243] Sched Debug Version: v0.11, 4.7.0 #1 [ 210.654064] ktime : 210640.702525 [ 210.660606] sched_clk : 210649.237069 [ 210.667147] cpu_clk : 210649.237403 [ 210.673689] jiffies : 4294958083 [ 210.679956] [ 210.681507] sysctl_sched [ 210.684148] .sysctl_sched_latency : 6.000000 [ 210.690508] .sysctl_sched_min_granularity : 0.750000 [ 210.696868] .sysctl_sched_wakeup_granularity : 1.000000 [ 210.703227] .sysctl_sched_child_runs_first : 0 [ 210.708951] .sysctl_sched_features : 44859 [ 210.715038] .sysctl_sched_tunable_scaling : 1 (logaritmic) [ 210.721940] [ 210.723493] cpu#0 [ 210.725499] .nr_running : 0 [ 210.730316] .load : 0 [ 210.735133] .nr_switches : 2637 [ 210.740222] .nr_load_updates : 770 [ 210.745221] .nr_uninterruptible : 1 [ 210.750039] .next_balance : 4294.937296 [ 210.755763] .curr->pid : 0 [ 210.760581] .clock : 207629.102789 [ 210.766487] .clock_task : 207629.102789 [ 210.772392] .cpu_load[0] : 0 [ 210.777209] .cpu_load[1] : 0 [ 210.782026] .cpu_load[2] : 0 [ 210.786843] .cpu_load[3] : 0 [ 210.791659] .cpu_load[4] : 0 [ 210.796476] .avg_idle : 1000000 [ 210.801837] .max_idle_balance_cost : 500000 [ 210.807541] [ 210.807541] cfs_rq[0]:/ [ 210.811644] .exec_clock : 0.000000 [ 210.817129] .MIN_vruntime : 0.000001 [ 210.822586] .min_vruntime : 2219.665999 [ 210.828311] .max_vruntime : 0.000001 [ 210.833764] .spread : 0.000000 [ 210.839217] .spread0 : 0.000000 [ 210.844669] .nr_spread_over : 0 [ 210.849486] .nr_running : 0 [ 210.854302] .load : 0 [ 210.859119] .load_avg : 0 [ 210.863936] .runnable_load_avg : 0 [ 210.868753] .util_avg : 0 [ 210.873569] .removed_load_avg : 0 [ 210.878386] .removed_util_avg : 0 [ 210.883203] .tg_load_avg_contrib : 0 [ 210.888020] .tg_load_avg : 0 [ 210.892836] .throttled : 0 [ 210.897653] .throttle_count : 0 [ 210.902478] [ 210.902478] rt_rq[0]:/ [ 210.906482] .rt_nr_running : 0 [ 210.911298] .rt_throttled : 0 [ 210.916116] .rt_time : 0.000000 [ 210.921569] .rt_runtime : 950.000000 [ 210.927203] [ 210.927203] dl_rq[0]: [ 210.931115] .dl_nr_running : 0 [ 210.935932] .dl_bw->bw : 996147 [ 210.941203] .dl_bw->total_bw : 0 [ 210.946022] [ 210.946022] runnable tasks: [ 210.946022] task PID tree-key switches prio wait-time sum-exec sum-sleep [ 210.946022] ---------------------------------------------------------------------------------------------------------- [ 210.972885] swapper/0 1 2156.149123 430 120 0.000000 1585.136238 0.000000 / [ 210.984271] kthreadd 2 2038.321501 79 120 0.000000 14.037962 0.000000 / [ 210.995650] ksoftirqd/0 3 2215.763039 52 120 0.000000 2.544000 0.000000 / [ 211.007028] kworker/0:0 4 1904.921171 13 120 0.000000 1.389583 0.000000 / [ 211.018406] kworker/0:0H 5 2041.204781 7 100 0.000000 8.077250 0.000000 / [ 211.029784] kworker/u2:0 6 2217.179165 265 120 0.000000 381.272297 0.000000 / [ 211.041161] rcu_sched 7 2154.556373 55 120 0.000000 21.241542 0.000000 / [ 211.052539] rcu_bh 8 16.105444 2 120 0.000000 0.039626 0.000000 / [ 211.063916] migration/0 9 0.000000 4 0 0.000000 0.423750 0.000000 / [ 211.075293] lru-add-drain 10 21.168027 2 100 0.000000 0.085249 0.000000 / [ 211.086670] cpuhp/0 11 23.208855 3 120 0.000000 0.058416 0.000000 / [ 211.098047] kdevtmpfs 12 1928.760087 161 120 0.000000 26.371584 0.000000 / [ 211.109425] netns 13 61.744445 2 100 0.000000 1.661750 0.000000 / [ 211.120802] kworker/0:1 14 2219.665999 410 120 0.000000 247.404410 0.000000 / [ 211.132180] oom_reaper 15 251.102895 2 120 0.000000 0.323084 0.000000 / [ 211.143558] writeback 16 256.870256 2 100 0.000000 0.064208 0.000000 / [ 211.154935] kcompactd0 17 258.964766 2 120 0.000000 0.111833 0.000000 / [ 211.166312] crypto 18 260.919055 2 100 0.000000 0.062918 0.000000 / [ 211.177689] bioset 19 262.941979 2 100 0.000000 0.053625 0.000000 / [ 211.189066] kblockd 20 264.973202 2 100 0.000000 0.069207 0.000000 / [ 211.200443] ata_sff 21 288.694669 2 100 0.000000 0.130875 0.000000 / [ 211.211820] watchdogd 22 294.705832 2 100 0.000000 0.098167 0.000000 / [ 211.223197] rpciod 23 428.119413 2 100 0.000000 0.182249 0.000000 / [ 211.234574] kswapd0 24 547.316984 3 120 0.000000 0.383958 0.000000 / [ 211.245951] vmstat 25 445.549286 2 100 0.000000 0.070042 0.000000 / [ 211.257327] nfsiod 26 447.076801 2 100 0.000000 0.068708 0.000000 / [ 211.268704] bioset 37 1238.234375 2 100 0.000000 0.071458 0.000000 / [ 211.280081] bioset 38 1240.257845 2 100 0.000000 0.058250 0.000000 / [ 211.291458] bioset 39 1242.275639 2 100 0.000000 0.048500 0.000000 / [ 211.302835] bioset 40 1244.296648 2 100 0.000000 0.049625 0.000000 / [ 211.314212] bioset 41 1246.314693 2 100 0.000000 0.047916 0.000000 / [ 211.325589] bioset 42 1248.333430 2 100 0.000000 0.046458 0.000000 / [ 211.336966] bioset 43 1250.353030 2 100 0.000000 0.048793 0.000000 / [ 211.348342] bioset 44 1252.372277 2 100 0.000000 0.048999 0.000000 / [ 211.359719] bioset 45 1254.392090 2 100 0.000000 0.047709 0.000000 / [ 211.371096] bioset 46 1256.412263 2 100 0.000000 0.047791 0.000000 / [ 211.382473] bioset 47 1258.433322 2 100 0.000000 0.051001 0.000000 / [ 211.393850] bioset 48 1260.452184 2 100 0.000000 0.049375 0.000000 / [ 211.405227] bioset 49 1262.471106 2 100 0.000000 0.047375 0.000000 / [ 211.416603] bioset 50 1264.491916 2 100 0.000000 0.046917 0.000000 / [ 211.427980] bioset 51 1266.512992 2 100 0.000000 0.051041 0.000000 / [ 211.439356] bioset 52 1268.547806 2 100 0.000000 0.072042 0.000000 / [ 211.450734] bioset 53 1300.699923 2 100 0.000000 0.073208 0.000000 / [ 211.462111] bioset 54 1302.717044 2 100 0.000000 0.056417 0.000000 / [ 211.473487] bioset 55 1304.740238 2 100 0.000000 0.063041 0.000000 / [ 211.484864] bioset 56 1307.786364 2 100 0.000000 0.067750 0.000000 / [ 211.496241] bioset 57 1309.803349 2 100 0.000000 0.055708 0.000000 / [ 211.507618] bioset 58 1311.825130 2 100 0.000000 0.056334 0.000000 / [ 211.518995] bioset 59 1313.847701 2 100 0.000000 0.060875 0.000000 / [ 211.530371] bioset 60 1315.883544 2 100 0.000000 0.073334 0.000000 / [ 211.541749] kworker/u2:1 61 1764.180582 3 120 0.000000 0.166875 0.000000 / [ 211.553126] ipv6_addrconf 63 1437.655997 2 100 0.000000 0.164501 0.000000 / [ 211.564504] kworker/0:2 64 1981.529376 7 120 0.000000 8.763625 0.000000 / [ 211.575881] deferwq 65 1508.836081 2 100 0.000000 0.130291 0.000000 / [ 211.587258] bioset 66 1581.328288 2 100 0.000000 0.097625 0.000000 / [ 211.598636] bioset 67 1592.245439 2 100 0.000000 0.076042 0.000000 / [ 211.610012] bioset 68 1602.178951 2 100 0.000000 0.074792 0.000000 / [ 211.621389] bioset 69 1612.120004 2 100 0.000000 0.075666 0.000000 / [ 211.632766] bioset 70 1622.244925 2 100 0.000000 0.078291 0.000000 / [ 211.644142] bioset 71 1631.857791 2 100 0.000000 0.073042 0.000000 / [ 211.655519] bioset 72 1641.419973 2 100 0.000000 0.073667 0.000000 / [ 211.666896] bioset 73 1651.738637 2 100 0.000000 0.061791 0.000000 / [ 211.678273] bioset 74 1664.070092 2 100 0.000000 0.073001 0.000000 / [ 211.689651] bioset 75 1767.096034 2 100 0.000000 0.067125 0.000000 / [ 211.701027] irq/160-44e0b00 76 0.000000 274 49 0.000000 13.390751 0.000000 / [ 211.712404] irq/161-4802a00 77 0.000000 2 49 0.000000 0.099084 0.000000 / [ 211.723780] irq/33-48060000 78 0.000000 2 49 0.000000 0.243458 0.000000 / [ 211.735156] bioset 79 1910.880292 2 100 0.000000 0.076584 0.000000 / [ 211.746533] mmcqd/1 80 1924.364590 4 120 0.000000 1.093001 0.000000 / [ 211.757910] kworker/0:1H 81 2156.095694 9 100 0.000000 4.953916 0.000000 / [ 211.769289] [ 211.770844] [ 211.770844] Showing all locks held in the system: [ 211.777327] [ 211.778879] ============================================= [ 211.778879] [ 211.786060] Showing busy workqueues and worker pools: - 20:54:05 [INFO] [ 218.145014] sysrq: SysRq : Show backtrace of all active CPUs [ 218.150957] Sending NMI to all CPUs: [ 218.154693] NMI backtrace for cpu 0 [ 218.158341] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.7.0 #1 [ 218.164430] Hardware name: Generic AM33XX (Flattened Device Tree) [ 218.170823] [<c011005c>] (unwind_backtrace) from [<c010c250>] (show_stack+0x10/0x14) [ 218.178926] [<c010c250>] (show_stack) from [<c047f49c>] (dump_stack+0xb0/0xe4) [ 218.186478] [<c047f49c>] (dump_stack) from [<c0482eb8>] (nmi_cpu_backtrace+0x7c/0x88) [ 218.194658] [<c0482eb8>] (nmi_cpu_backtrace) from [<c010dbf8>] (raise_nmi+0x60/0x70) [ 218.202746] [<c010dbf8>] (raise_nmi) from [<c0482f84>] (nmi_trigger_all_cpu_backtrace+0xc0/0xf4) [ 218.211933] [<c0482f84>] (nmi_trigger_all_cpu_backtrace) from [<c04f9424>] (__handle_sysrq+0xd4/0x248) [ 218.221662] [<c04f9424>] (__handle_sysrq) from [<c05147c8>] (serial_omap_irq+0x374/0x3bc) [ 218.230213] [<c05147c8>] (serial_omap_irq) from [<c019ea30>] (handle_irq_event_percpu+0x44/0x3fc) [ 218.239482] [<c019ea30>] (handle_irq_event_percpu) from [<c019ee20>] (handle_irq_event+0x38/0x5c) [ 218.248754] [<c019ee20>] (handle_irq_event) from [<c01a1f14>] (handle_level_irq+0xb8/0x14c) [ 218.257478] [<c01a1f14>] (handle_level_irq) from [<c019e05c>] (generic_handle_irq+0x20/0x34) [ 218.266293] [<c019e05c>] (generic_handle_irq) from [<c019e350>] (__handle_domain_irq+0x64/0xe0) [ 218.275382] [<c019e350>] (__handle_domain_irq) from [<c07b06b8>] (__irq_svc+0x58/0x78) [ 218.283661] [<c07b06b8>] (__irq_svc) from [<c010831c>] (arch_cpu_idle+0x20/0x3c) [ 218.291389] [<c010831c>] (arch_cpu_idle) from [<c01844d8>] (cpu_startup_entry+0x30c/0x3f0) [ 218.300034] [<c01844d8>] (cpu_startup_entry) from [<c0b00c08>] (start_kernel+0x340/0x3b4) [ 218.308579] [<c0b00c08>] (start_kernel) from [<8000807c>] (0x8000807c) [ 218.315407] Unable to handle kernel NULL pointer dereference at virtual address 00000000 [ 218.323853] pgd = c0004000 [ 218.326675] [00000000] *pgd=00000000 [ 218.330423] Internal error: Oops: 80000005 [#1] SMP ARM [ 218.335880] Modules linked in: [ 218.339074] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.7.0 #1 [ 218.345162] Hardware name: Generic AM33XX (Flattened Device Tree) [ 218.351523] task: c0c065c0 ti: c0c00000 task.ti: c0c00000 [ 218.357157] PC is at 0x0 [ 218.359802] LR is at nmi_trigger_all_cpu_backtrace+0xc0/0xf4 [ 218.365709] pc : [<00000000>] lr : [<c0482f84>] psr: 60000193 [ 218.365709] sp : c0c01e68 ip : 00000000 fp : c0c029cc [ 218.377694] r10: 00000061 r9 : 00000000 r8 : 00000007 [ 218.383146] r7 : 00000000 r6 : c010db98 r5 : c0c037f8 r4 : 00000001 [ 218.389960] r3 : 00000000 r2 : 00000000 r1 : 00000007 r0 : c0c037f8 [ 218.396776] Flags: nZCv IRQs off FIQs on Mode SVC_32 ISA ARM Segment none [ 218.404315] Control: 10c5387d Table: 80004019 DAC: 00000051 [ 218.410312] Process swapper/0 (pid: 0, stack limit = 0xc0c00218) [ 218.416582] Stack: (0xc0c01e68 to 0xc0c02000) [ 218.421134] 1e60: c0c87680 c0c4456c 0000006c 00000001 00000007 c04f9424 [ 218.429675] 1e80: 00000000 00000000 c04f9350 c052eb88 eebae810 00000101 00000000 00000002 [ 218.438217] 1ea0: 00000005 c05147c8 00000000 60000193 ee95c510 eee72b40 ee95c560 ee95c510 [ 218.446757] 1ec0: 00000000 0000009e 00000000 00000000 c0c029cc c019ea30 60000193 00000000 [ 218.455298] 1ee0: 60000193 ee95c500 ee95c560 ee95c500 ee95c560 ee95c510 00000000 00000001 [ 218.463839] 1f00: ee814000 c0b759f8 c0cbcc26 c019ee20 ee95c500 ee95c560 ee95c510 c01a1f14 [ 218.472381] 1f20: c0b74944 0000009e c0c035fc c019e05c c0b74944 c019e350 c010831c 20000013 [ 218.480921] 1f40: ffffffff c0c01f8c c0c029cc c0cbde98 c0b759f8 c07b06b8 00000001 00000001 [ 218.489462] 1f60: 00000000 c0c065c0 c0c02a38 00000000 00000000 c0cbde98 c0c029cc c0cbde98 [ 218.498004] 1f80: c0b759f8 c0cbcc26 00000000 c0c01fa8 c018ff64 c010831c 20000013 ffffffff [ 218.506545] 1fa0: 00000051 c0108318 c0c02a38 c01844d8 c0cc2050 c0c02900 00000000 c0b00c08 [ 218.515086] 1fc0: ffffffff ffffffff 00000000 c0b00684 00000000 c0b52a48 c0cc2214 c0c029ac [ 218.523627] 1fe0: c0b52a44 c0c08228 80004059 413fc082 00000000 8000807c 00000000 00000000 [ 218.532170] [<c0482f84>] (nmi_trigger_all_cpu_backtrace) from [<c04f9424>] (__handle_sysrq+0xd4/0x248) [ 218.541892] [<c04f9424>] (__handle_sysrq) from [<c05147c8>] (serial_omap_irq+0x374/0x3bc) [ 218.550436] [<c05147c8>] (serial_omap_irq) from [<c019ea30>] (handle_irq_event_percpu+0x44/0x3fc) [ 218.559703] [<c019ea30>] (handle_irq_event_percpu) from [<c019ee20>] (handle_irq_event+0x38/0x5c) [ 218.568971] [<c019ee20>] (handle_irq_event) from [<c01a1f14>] (handle_level_irq+0xb8/0x14c) [ 218.577694] [<c01a1f14>] (handle_level_irq) from [<c019e05c>] (generic_handle_irq+0x20/0x34) [ 218.586508] [<c019e05c>] (generic_handle_irq) from [<c019e350>] (__handle_domain_irq+0x64/0xe0) [ 218.595594] [<c019e350>] (__handle_domain_irq) from [<c07b06b8>] (__irq_svc+0x58/0x78) [ 218.603865] [<c07b06b8>] (__irq_svc) from [<c010831c>] (arch_cpu_idle+0x20/0x3c) [ 218.611590] [<c010831c>] (arch_cpu_idle) from [<c01844d8>] (cpu_startup_entry+0x30c/0x3f0) [ 218.620224] [<c01844d8>] (cpu_startup_entry) from [<c0b00c08>] (start_kernel+0x340/0x3b4) [ 218.628765] [<c0b00c08>] (start_kernel) from [<8000807c>] (0x8000807c) [ 218.635581] Code: bad PC value [ 218.638788] ---[ end trace 99ddf7059abf1fd2 ]--- [ 218.643609] Kernel panic - not syncing: Fatal exception in interrupt [ 218.650256] ---[ end Kernel panic - not syncing: Fatal exception in interrupt - 20:54:16 [INFO] - 20:54:16 [INFO] Disconnected serial from am335x-evm - 20:54:16 [INFO] Failed to boot on Iteration 61 - 20:54:16 [INFO] Disconnected all from am335x-evm - 20:54:17 [INFO] Connected to am335x-evm via serial - 20:54:17 [INFO] Host: #check prompt - 20:54:20 [ERROR] On command: #check prompt waiting for #check prompt.+?(?-mix:((?-mix:login:)|[Pp]assword)) >>> error: execution expired - 20:54:20 [INFO] Target: - 20:54:20 [INFO] Host: #check prompt - 20:54:22 [ERROR] On command: #check prompt waiting for #check prompt.+?(?-mix:[\w\d]+@.+[@:#]+) >>> error: execution expired - 20:54:22 [INFO] Target: - 20:54:22 [INFO] Host: #check prompt - 20:54:24 [ERROR] On command: #check prompt waiting for #check prompt.+?(?-mix:[\w\d]+@.+[@:#]+) >>> error: execution expired - 20:54:24 [INFO] Target: - 20:54:24 [INFO] Host: #check prompt - 20:54:26 [ERROR] On command: #check prompt waiting for #check prompt.+?(?-mix:[\w\d]+@.+[@:#]+) >>> error: execution expired - 20:54:26 [INFO] Target: - 20:54:26 [INFO] Disconnected serial from am335x-evm - 20:54:27 [INFO] Connected to am335x-evm via serial - 20:54:27 [INFO] Host: - 20:54:28 [INFO] Target: -- ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Kernel NFS boot failure 2016-08-03 11:41 Kernel NFS boot failure Grygorii Strashko @ 2016-08-03 12:06 ` Vladimir Murzin 2016-08-03 15:04 ` Grygorii Strashko 0 siblings, 1 reply; 5+ messages in thread From: Vladimir Murzin @ 2016-08-03 12:06 UTC (permalink / raw) To: Grygorii Strashko, netdev Cc: linux-omap@vger.kernel.org, Sekhar Nori, linux-arm Hi, On 03/08/16 12:41, Grygorii Strashko wrote: > Hi All, > > We observe Kernel boot failure while running NFS boot stress test (1000 iterations): > - Linux version 4.7.0 > - am335x-evm (TI AM335x EVM) > - failure rate 10-20 times per test. > Originally this issue was reproduced using TI Kernel 4.4 > ( git://git.ti.com/ti-linux-kernel/ti-linux-kernel.git, branch: ti-linux-4.4.y) > on both am335x-evm and am57xx-beagle-x15(am57xx-evm) platforms. > This issues has not been reproduced with TI Kernel 4.1 before. > > The SysRq shows that system stuck in nfs_fs_mount() > > [ 207.904632] [<c07ab34c>] (schedule) from [<c0783554>] (rpc_wait_bit_killable+0x2c/0xd8) > [ 207.912996] [<c0783554>] (rpc_wait_bit_killable) from [<c07ab7f0>] (__wait_on_bit+0x84/0xc0) > [ 207.921812] [<c07ab7f0>] (__wait_on_bit) from [<c07ab890>] (out_of_line_wait_on_bit+0x64/0x70) > [ 207.930810] [<c07ab890>] (out_of_line_wait_on_bit) from [<c07843f4>] (__rpc_execute+0x18c/0x544) > [ 207.939988] [<c07843f4>] (__rpc_execute) from [<c0779f24>] (rpc_run_task+0x13c/0x158) > [ 207.948166] [<c0779f24>] (rpc_run_task) from [<c0779f84>] (rpc_call_sync+0x44/0xc4) > [ 207.956163] [<c0779f84>] (rpc_call_sync) from [<c077a04c>] (rpc_ping+0x48/0x68) > [ 207.963796] [<c077a04c>] (rpc_ping) from [<c077a158>] (rpc_create_xprt+0xec/0x164) > [ 207.971702] [<c077a158>] (rpc_create_xprt) from [<c077a2c0>] (rpc_create+0xf0/0x1a0) > [ 207.979794] [<c077a2c0>] (rpc_create) from [<c0393088>] (nfs_create_rpc_client+0xd4/0xec) > [ 207.988338] [<c0393088>] (nfs_create_rpc_client) from [<c0394d10>] (nfs_init_client+0x20/0x78) > [ 207.997332] [<c0394d10>] (nfs_init_client) from [<c03949d4>] (nfs_create_server+0xa0/0x3bc) > [ 208.006057] [<c03949d4>] (nfs_create_server) from [<c03b197c>] (nfs3_create_server+0x8/0x20) > [ 208.014879] [<c03b197c>] (nfs3_create_server) from [<c03a34c4>] (nfs_try_mount+0xc4/0x1f0) > [ 208.023513] [<c03a34c4>] (nfs_try_mount) from [<c03a2c48>] (nfs_fs_mount+0x290/0x910) > [ 208.031702] [<c03a2c48>] (nfs_fs_mount) from [<c0294d24>] (mount_fs+0x44/0x168) > > Has anyone else seen this issue? > > I'd be appreciated for any help or advice related to this issue? I did not look at details, but because it is 4.4 and __wait_on_bit showed up you might want to look at [1] [1] https://lkml.org/lkml/2015/11/20/472 Just my 2p. Vladimir > > Thanks in advance. > > regards, > -grygorii ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Kernel NFS boot failure 2016-08-03 12:06 ` Vladimir Murzin @ 2016-08-03 15:04 ` Grygorii Strashko 2016-08-11 16:25 ` Grygorii Strashko 0 siblings, 1 reply; 5+ messages in thread From: Grygorii Strashko @ 2016-08-03 15:04 UTC (permalink / raw) To: Vladimir Murzin, netdev Cc: linux-omap@vger.kernel.org, Sekhar Nori, open list, linux-arm Hi Vladimir, On 08/03/2016 03:06 PM, Vladimir Murzin wrote: > On 03/08/16 12:41, Grygorii Strashko wrote: >> We observe Kernel boot failure while running NFS boot stress test (1000 iterations): >> - Linux version 4.7.0 I'd like to pay your attention that this issue also reproducible with Kernel 4.7.0! The same can be seen from the log I've provided in first e-mail: [ 0.000000] Linux version 4.7.0 (lcpdbld@dflsdit-build06.dal.design.ti.com) (gcc version 4.9.3 20150413 (prerelease) (Linaro GCC 4.9-2015.05) ) #1 SMP Fri Jul 29 17:41:27 CDT 2016 I've not run the test with current master at it's not been tagged yet. >> - am335x-evm (TI AM335x EVM) >> - failure rate 10-20 times per test. >> Originally this issue was reproduced using TI Kernel 4.4 >> ( git://git.ti.com/ti-linux-kernel/ti-linux-kernel.git, branch: ti-linux-4.4.y) >> on both am335x-evm and am57xx-beagle-x15(am57xx-evm) platforms. >> This issues has not been reproduced with TI Kernel 4.1 before. >> >> The SysRq shows that system stuck in nfs_fs_mount() >> >> [ 207.904632] [<c07ab34c>] (schedule) from [<c0783554>] (rpc_wait_bit_killable+0x2c/0xd8) >> [ 207.912996] [<c0783554>] (rpc_wait_bit_killable) from [<c07ab7f0>] (__wait_on_bit+0x84/0xc0) >> [ 207.921812] [<c07ab7f0>] (__wait_on_bit) from [<c07ab890>] (out_of_line_wait_on_bit+0x64/0x70) >> [ 207.930810] [<c07ab890>] (out_of_line_wait_on_bit) from [<c07843f4>] (__rpc_execute+0x18c/0x544) >> [ 207.939988] [<c07843f4>] (__rpc_execute) from [<c0779f24>] (rpc_run_task+0x13c/0x158) >> [ 207.948166] [<c0779f24>] (rpc_run_task) from [<c0779f84>] (rpc_call_sync+0x44/0xc4) >> [ 207.956163] [<c0779f84>] (rpc_call_sync) from [<c077a04c>] (rpc_ping+0x48/0x68) >> [ 207.963796] [<c077a04c>] (rpc_ping) from [<c077a158>] (rpc_create_xprt+0xec/0x164) >> [ 207.971702] [<c077a158>] (rpc_create_xprt) from [<c077a2c0>] (rpc_create+0xf0/0x1a0) >> [ 207.979794] [<c077a2c0>] (rpc_create) from [<c0393088>] (nfs_create_rpc_client+0xd4/0xec) >> [ 207.988338] [<c0393088>] (nfs_create_rpc_client) from [<c0394d10>] (nfs_init_client+0x20/0x78) >> [ 207.997332] [<c0394d10>] (nfs_init_client) from [<c03949d4>] (nfs_create_server+0xa0/0x3bc) >> [ 208.006057] [<c03949d4>] (nfs_create_server) from [<c03b197c>] (nfs3_create_server+0x8/0x20) >> [ 208.014879] [<c03b197c>] (nfs3_create_server) from [<c03a34c4>] (nfs_try_mount+0xc4/0x1f0) >> [ 208.023513] [<c03a34c4>] (nfs_try_mount) from [<c03a2c48>] (nfs_fs_mount+0x290/0x910) >> [ 208.031702] [<c03a2c48>] (nfs_fs_mount) from [<c0294d24>] (mount_fs+0x44/0x168) >> >> Has anyone else seen this issue? >> >> I'd be appreciated for any help or advice related to this issue? > > I did not look at details, but because it is 4.4 and __wait_on_bit > showed up you might want to look at [1] > > [1] https://lkml.org/lkml/2015/11/20/472 Thanks. I'll take a look. -- regards, -grygorii ^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Kernel NFS boot failure 2016-08-03 15:04 ` Grygorii Strashko @ 2016-08-11 16:25 ` Grygorii Strashko 2016-08-19 11:14 ` Grygorii Strashko 0 siblings, 1 reply; 5+ messages in thread From: Grygorii Strashko @ 2016-08-11 16:25 UTC (permalink / raw) To: netdev, Trond Myklebust, linux-nfs, Anna Schumaker Cc: Vladimir Murzin, linux-omap@vger.kernel.org, Sekhar Nori, open list, linux-arm, Neil Brown On 08/03/2016 06:04 PM, Grygorii Strashko wrote: > Hi Vladimir, > > On 08/03/2016 03:06 PM, Vladimir Murzin wrote: >> On 03/08/16 12:41, Grygorii Strashko wrote: >>> We observe Kernel boot failure while running NFS boot stress test (1000 iterations): >>> - Linux version 4.7.0 > > I'd like to pay your attention that this issue also reproducible with > Kernel 4.7.0! > The same can be seen from the log I've provided in first e-mail: > [ 0.000000] Linux version 4.7.0 (lcpdbld@dflsdit-build06.dal.design.ti.com) (gcc version 4.9.3 20150413 (prerelease) (Linaro GCC 4.9-2015.05) ) #1 SMP Fri Jul 29 17:41:27 CDT 2016 > > > I've not run the test with current master at it's not been tagged yet. Still in progress. rc1 unstable on my platforms due to other issues :( > >>> - am335x-evm (TI AM335x EVM) >>> - failure rate 10-20 times per test. >>> Originally this issue was reproduced using TI Kernel 4.4 >>> ( git://git.ti.com/ti-linux-kernel/ti-linux-kernel.git, branch: ti-linux-4.4.y) >>> on both am335x-evm and am57xx-beagle-x15(am57xx-evm) platforms. >>> This issues has not been reproduced with TI Kernel 4.1 before. >>> >>> The SysRq shows that system stuck in nfs_fs_mount() >>> >>> [ 207.904632] [<c07ab34c>] (schedule) from [<c0783554>] (rpc_wait_bit_killable+0x2c/0xd8) >>> [ 207.912996] [<c0783554>] (rpc_wait_bit_killable) from [<c07ab7f0>] (__wait_on_bit+0x84/0xc0) >>> [ 207.921812] [<c07ab7f0>] (__wait_on_bit) from [<c07ab890>] (out_of_line_wait_on_bit+0x64/0x70) >>> [ 207.930810] [<c07ab890>] (out_of_line_wait_on_bit) from [<c07843f4>] (__rpc_execute+0x18c/0x544) >>> [ 207.939988] [<c07843f4>] (__rpc_execute) from [<c0779f24>] (rpc_run_task+0x13c/0x158) >>> [ 207.948166] [<c0779f24>] (rpc_run_task) from [<c0779f84>] (rpc_call_sync+0x44/0xc4) >>> [ 207.956163] [<c0779f84>] (rpc_call_sync) from [<c077a04c>] (rpc_ping+0x48/0x68) >>> [ 207.963796] [<c077a04c>] (rpc_ping) from [<c077a158>] (rpc_create_xprt+0xec/0x164) >>> [ 207.971702] [<c077a158>] (rpc_create_xprt) from [<c077a2c0>] (rpc_create+0xf0/0x1a0) >>> [ 207.979794] [<c077a2c0>] (rpc_create) from [<c0393088>] (nfs_create_rpc_client+0xd4/0xec) >>> [ 207.988338] [<c0393088>] (nfs_create_rpc_client) from [<c0394d10>] (nfs_init_client+0x20/0x78) >>> [ 207.997332] [<c0394d10>] (nfs_init_client) from [<c03949d4>] (nfs_create_server+0xa0/0x3bc) >>> [ 208.006057] [<c03949d4>] (nfs_create_server) from [<c03b197c>] (nfs3_create_server+0x8/0x20) >>> [ 208.014879] [<c03b197c>] (nfs3_create_server) from [<c03a34c4>] (nfs_try_mount+0xc4/0x1f0) >>> [ 208.023513] [<c03a34c4>] (nfs_try_mount) from [<c03a2c48>] (nfs_fs_mount+0x290/0x910) >>> [ 208.031702] [<c03a2c48>] (nfs_fs_mount) from [<c0294d24>] (mount_fs+0x44/0x168) >>> >>> Has anyone else seen this issue? >>> >>> I'd be appreciated for any help or advice related to this issue? >> >> I did not look at details, but because it is 4.4 and __wait_on_bit >> showed up you might want to look at [1] >> >> [1] https://lkml.org/lkml/2015/11/20/472 > > Thanks. I'll take a look. > I've checked this thread and all three commits mentioned there are present in K4.4 >=3.17 commit 743162013d40 sched: Remove proliferation of wait_on_bit() action functions >=4.4 commit 68985633bccb sched/wait: Fix signal handling in bit wait helpers >=4.4 commit dfd01f026058 sched/wait: Fix the signal handling fix Also, It seems first patch, probably, has copy-past error. I'm not sure and it may be that patch is correct :) Any way, It doesn't help with this issue if I use wait_on_bit_lock_io in nfs_page_group_lock(). 743162013d40 ("sched: Remove proliferation of wait_on_bit() action functions") -- does: diff --git a/fs/nfs/pagelist.c b/fs/nfs/pagelist.c index b6ee3a6..6104d35 100644 --- a/fs/nfs/pagelist.c +++ b/fs/nfs/pagelist.c @@ -138,12 +138,6 @@ nfs_iocounter_wait(struct nfs_io_counter *c) return __nfs_iocounter_wait(c); } -static int nfs_wait_bit_uninterruptible(void *word) -{ - io_schedule(); - return 0; -} - /* * nfs_page_group_lock - lock the head of the page group * @req - request in group that is to be locked @@ -158,7 +152,6 @@ nfs_page_group_lock(struct nfs_page *req) WARN_ON_ONCE(head != head->wb_head); wait_on_bit_lock(&head->wb_flags, PG_HEADLOCK, - nfs_wait_bit_uninterruptible, [GS] But it seems should be wait_on_bit_lock_io() <---- TASK_UNINTERRUPTIBLE); } @@ -425,9 +418,8 @@ void nfs_release_request(struct nfs_page *req) int nfs_wait_on_request(struct nfs_page *req) { - return wait_on_bit(&req->wb_flags, PG_BUSY, - nfs_wait_bit_uninterruptible, - TASK_UNINTERRUPTIBLE); + return wait_on_bit_io(&req->wb_flags, PG_BUSY, + TASK_UNINTERRUPTIBLE); } -- regards, -grygorii ^ permalink raw reply related [flat|nested] 5+ messages in thread
* Re: Kernel NFS boot failure 2016-08-11 16:25 ` Grygorii Strashko @ 2016-08-19 11:14 ` Grygorii Strashko 0 siblings, 0 replies; 5+ messages in thread From: Grygorii Strashko @ 2016-08-19 11:14 UTC (permalink / raw) To: netdev, Trond Myklebust, linux-nfs, Anna Schumaker Cc: Vladimir Murzin, Neil Brown, Sekhar Nori, open list, linux-omap@vger.kernel.org, linux-arm Hi All, On 08/11/2016 07:25 PM, Grygorii Strashko wrote: > On 08/03/2016 06:04 PM, Grygorii Strashko wrote: >> Hi Vladimir, >> >> On 08/03/2016 03:06 PM, Vladimir Murzin wrote: >>> On 03/08/16 12:41, Grygorii Strashko wrote: >>>> We observe Kernel boot failure while running NFS boot stress test (1000 iterations): >>>> - Linux version 4.7.0 >> >> I'd like to pay your attention that this issue also reproducible with >> Kernel 4.7.0! >> The same can be seen from the log I've provided in first e-mail: >> [ 0.000000] Linux version 4.7.0 (lcpdbld@dflsdit-build06.dal.design.ti.com) (gcc version 4.9.3 20150413 (prerelease) (Linaro GCC 4.9-2015.05) ) #1 SMP Fri Jul 29 17:41:27 CDT 2016 >> >> >> I've not run the test with current master at it's not been tagged yet. > > Still in progress. rc1 unstable on my platforms due to other issues :( > >> >>>> - am335x-evm (TI AM335x EVM) >>>> - failure rate 10-20 times per test. >>>> Originally this issue was reproduced using TI Kernel 4.4 >>>> ( git://git.ti.com/ti-linux-kernel/ti-linux-kernel.git, branch: ti-linux-4.4.y) >>>> on both am335x-evm and am57xx-beagle-x15(am57xx-evm) platforms. >>>> This issues has not been reproduced with TI Kernel 4.1 before. >>>> >>>> The SysRq shows that system stuck in nfs_fs_mount() >>>> >>>> [ 207.904632] [<c07ab34c>] (schedule) from [<c0783554>] (rpc_wait_bit_killable+0x2c/0xd8) >>>> [ 207.912996] [<c0783554>] (rpc_wait_bit_killable) from [<c07ab7f0>] (__wait_on_bit+0x84/0xc0) >>>> [ 207.921812] [<c07ab7f0>] (__wait_on_bit) from [<c07ab890>] (out_of_line_wait_on_bit+0x64/0x70) >>>> [ 207.930810] [<c07ab890>] (out_of_line_wait_on_bit) from [<c07843f4>] (__rpc_execute+0x18c/0x544) >>>> [ 207.939988] [<c07843f4>] (__rpc_execute) from [<c0779f24>] (rpc_run_task+0x13c/0x158) >>>> [ 207.948166] [<c0779f24>] (rpc_run_task) from [<c0779f84>] (rpc_call_sync+0x44/0xc4) >>>> [ 207.956163] [<c0779f84>] (rpc_call_sync) from [<c077a04c>] (rpc_ping+0x48/0x68) >>>> [ 207.963796] [<c077a04c>] (rpc_ping) from [<c077a158>] (rpc_create_xprt+0xec/0x164) >>>> [ 207.971702] [<c077a158>] (rpc_create_xprt) from [<c077a2c0>] (rpc_create+0xf0/0x1a0) >>>> [ 207.979794] [<c077a2c0>] (rpc_create) from [<c0393088>] (nfs_create_rpc_client+0xd4/0xec) >>>> [ 207.988338] [<c0393088>] (nfs_create_rpc_client) from [<c0394d10>] (nfs_init_client+0x20/0x78) >>>> [ 207.997332] [<c0394d10>] (nfs_init_client) from [<c03949d4>] (nfs_create_server+0xa0/0x3bc) >>>> [ 208.006057] [<c03949d4>] (nfs_create_server) from [<c03b197c>] (nfs3_create_server+0x8/0x20) >>>> [ 208.014879] [<c03b197c>] (nfs3_create_server) from [<c03a34c4>] (nfs_try_mount+0xc4/0x1f0) >>>> [ 208.023513] [<c03a34c4>] (nfs_try_mount) from [<c03a2c48>] (nfs_fs_mount+0x290/0x910) >>>> [ 208.031702] [<c03a2c48>] (nfs_fs_mount) from [<c0294d24>] (mount_fs+0x44/0x168) >>>> I was able to reproduce this issue with NFS/SUNRPC debug logs enabled using TI kernel 4.4. I'd be appreciated for any help :( and be happy to run any kind of tests or check debug patches if needed. >From the logs I found that problem happens when rpc_task 2 is freeing too late as in the below log. (marked as [GS]) Starting kernel ... [ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Initializing cgroup subsys cpuset [ 0.000000] Initializing cgroup subsys cpu [ 0.000000] Initializing cgroup subsys cpuacct [ 0.000000] Linux version 4.4.18-32575-g5db1dce (lcpdbld@dflsdit-build06.dal.design.ti.com) (gcc version 4.9.3 20150413 (prerelease) (Linaro GCC 4.9-2015.05) ) #2 SMP PREEMPT Wed Aug 17 10:49:14 CDT 2016 [ 0.000000] CPU: ARMv7 Processor [412fc0f2] revision 2 (ARMv7), cr=30c5387d [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache [ 0.000000] Machine model: TI AM5728 EVM [ 0.000000] Reserved memory: created CMA memory pool at 0x0000000095800000, size 56 MiB [ 0.000000] Reserved memory: initialized node ipu2_cma@95800000, compatible id shared-dma-pool [ 0.000000] Reserved memory: created CMA memory pool at 0x0000000099000000, size 64 MiB [ 0.000000] Reserved memory: initialized node dsp1_cma@99000000, compatible id shared-dma-pool [ 0.000000] Reserved memory: created CMA memory pool at 0x000000009d000000, size 32 MiB [ 0.000000] Reserved memory: initialized node ipu1_cma@9d000000, compatible id shared-dma-pool [ 0.000000] Reserved memory: created CMA memory pool at 0x000000009f000000, size 8 MiB [ 0.000000] Reserved memory: initialized node dsp2_cma@9f000000, compatible id shared-dma-pool [ 0.000000] cma: Reserved 24 MiB at 0x00000000fe400000 [ 0.000000] Forcing write-allocate cache policy for SMP [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] OMAP4: Map 0x00000000ffd00000 to fe600000 for dram barrier [ 0.000000] DRA752 ES1.1 [ 0.000000] PERCPU: Embedded 11 pages/cpu @eed31000 s14848 r8192 d22016 u45056 [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 521792 [ 0.000000] Kernel command line: console=ttyO2,115200n8 earlyprintk=serial,ttyO2,115200n8 rootwait ip=:::::eth0:dhcp root=/dev/nfs rw nfsroot=192.168.0.1:/home/tigtfarm10/NFS_exports/linux/am57xx-evm/autofs/f1a395609921e4cdad1b0bb2ec56f877,nolock,v3,tcp,rsize=4096,wsize=4096 [ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes) [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Memory: 1875576K/2094080K available (6523K kernel code, 358K rwdata, 2408K rodata, 336K init, 289K bss, 30088K reserved, 188416K cma-reserved, 1283072K highmem) [ 0.000000] Virtual kernel memory layout: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB) [ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB) [ 0.000000] vmalloc : 0xf0800000 - 0xff800000 ( 240 MB) [ 0.000000] lowmem : 0xc0000000 - 0xf0000000 ( 768 MB) [ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB) [ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB) [ 0.000000] .text : 0xc0008000 - 0xc08c106c (8933 kB) [ 0.000000] .init : 0xc08c2000 - 0xc0916000 ( 336 kB) [ 0.000000] .data : 0xc0916000 - 0xc096f9a0 ( 359 kB) [ 0.000000] .bss : 0xc0972000 - 0xc09ba6b0 ( 290 kB) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1 [ 0.000000] Preemptible hierarchical RCU implementation. [ 0.000000] Build-time adjustment of leaf fanout to 32. [ 0.000000] NR_IRQS:16 nr_irqs:16 16 [ 0.000000] OMAP clockevent source: timer1 at 32786 Hz [ 0.000000] Architected cp15 timer(s) running at 6.14MHz (virt). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x16af5adb9, max_idle_ns: 440795202250 ns [ 0.000004] sched_clock: 56 bits at 6MHz, resolution 162ns, wraps every 4398046511023ns [ 0.000015] Switching to timer-based delay loop, resolution 162ns [ 0.000328] clocksource: 32k_counter: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 58327039986419 ns [ 0.000337] OMAP clocksource: 32k_counter at 32768 Hz [ 0.000760] Console: colour dummy device 80x30 [ 0.000776] WARNING: Your 'console=ttyO2' has been replaced by 'ttyS2' [ 0.000782] This ensures that you still see kernel messages. Please [ 0.000788] update your kernel commandline. [ 0.000801] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.29 BogoMIPS (lpj=61475) [ 0.000814] pid_max: default: 32768 minimum: 301 [ 0.000906] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.000916] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.001461] Initializing cgroup subsys io [ 0.001478] Initializing cgroup subsys memory [ 0.001502] Initializing cgroup subsys devices [ 0.001514] Initializing cgroup subsys freezer [ 0.001525] Initializing cgroup subsys perf_event [ 0.001536] Initializing cgroup subsys pids [ 0.001562] CPU: Testing write buffer coherency: ok [ 0.001764] /cpus/cpu@0 missing clock-frequency property [ 0.001781] /cpus/cpu@1 missing clock-frequency property [ 0.001791] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.001827] Setting up static identity map for 0x800082c0 - 0x80008318 [ 0.080183] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.080250] Brought up 2 CPUs [ 0.080262] SMP: Total of 2 processors activated (24.59 BogoMIPS). [ 0.080269] CPU: All CPU(s) started in SVC mode. [ 0.080643] devtmpfs: initialized [ 0.106472] VFP support v0.3: implementor 41 architecture 4 part 30 variant f rev 0 [ 0.107342] omap_hwmod: l3_main_2 using broken dt data from ocp [ 0.304568] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.308002] pinctrl core: initialized pinctrl subsystem [ 0.308848] NET: Registered protocol family 16 [ 0.309801] DMA: preallocated 256 KiB pool for atomic coherent allocations [ 0.340242] cpuidle: using governor ladder [ 0.370275] cpuidle: using governor menu [ 0.378776] OMAP GPIO hardware version 0.1 [ 0.385225] irq: no irq domain found for /ocp/l4@4a000000/scm@2000/pinmux@1400 ! [ 0.409647] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. [ 0.409657] hw-breakpoint: maximum watchpoint size is 8 bytes. [ 0.410122] omap4_sram_init:Unable to allocate sram needed to handle errata I688 [ 0.410131] omap4_sram_init:Unable to get sram pool needed to handle errata I688 [ 0.410723] OMAP DMA hardware revision 0.0 [ 0.444520] omap-dma-engine 4a056000.dma-controller: OMAP DMA engine driver [ 0.445630] edma 43300000.edma: memcpy is disabled [ 0.450477] edma 43300000.edma: TI EDMA DMA engine driver [ 0.454327] omap-iommu 40d01000.mmu: 40d01000.mmu registered [ 0.454507] omap-iommu 40d02000.mmu: 40d02000.mmu registered [ 0.454658] omap-iommu 58882000.mmu: 58882000.mmu registered [ 0.454806] omap-iommu 55082000.mmu: 55082000.mmu registered [ 0.455061] omap-iommu 41501000.mmu: 41501000.mmu registered [ 0.455249] omap-iommu 41502000.mmu: 41502000.mmu registered [ 0.458152] palmas 0-0058: Irq flag is 0x00000008 [ 0.472649] palmas 0-0058: Muxing GPIO 2f, PWM 0, LED 0 [ 0.554028] omap_i2c 48070000.i2c: bus 0 rev0.12 at 400 kHz [ 0.554526] omap_i2c 48060000.i2c: bus 2 rev0.12 at 400 kHz [ 0.555103] omap_i2c 4807c000.i2c: bus 4 rev0.12 at 400 kHz [ 0.555313] media: Linux media interface: v0.10 [ 0.555368] Linux video capture interface: v2.00 [ 0.555410] pps_core: LinuxPPS API ver. 1 registered [ 0.555417] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it> [ 0.555443] PTP clock support registered [ 0.555490] EDAC MC: Ver: 3.0.0 [ 0.556248] omap-mailbox 4883c000.mailbox: omap mailbox rev 0x400 [ 0.556543] omap-mailbox 4883e000.mailbox: omap mailbox rev 0x400 [ 0.556831] omap-mailbox 48840000.mailbox: omap mailbox rev 0x400 [ 0.557123] omap-mailbox 48842000.mailbox: omap mailbox rev 0x400 [ 0.557444] Advanced Linux Sound Architecture Driver Initialized. [ 0.558290] clocksource: Switched to clocksource arch_sys_counter [ 0.569416] NET: Registered protocol family 2 [ 0.569913] TCP established hash table entries: 8192 (order: 3, 32768 bytes) [ 0.569977] TCP bind hash table entries: 8192 (order: 4, 65536 bytes) [ 0.570101] TCP: Hash tables configured (established 8192 bind 8192) [ 0.570149] UDP hash table entries: 512 (order: 2, 16384 bytes) [ 0.570180] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) [ 0.570325] NET: Registered protocol family 1 [ 0.570361] RPC: creating workqueue rpciod [ 0.570524] RPC: registering /proc/net/rpc [ 0.570662] svc: Adding svc transport class 'tcp' [ 0.570670] svc: Adding svc transport class 'udp' [ 0.570687] RPC: Registered named UNIX socket transport module. [ 0.570694] RPC: Registered udp transport module. [ 0.570699] RPC: Registered tcp transport module. [ 0.570705] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.571727] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available [ 0.574145] futex hash table entries: 512 (order: 3, 32768 bytes) [ 0.582005] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 0.582247] RPC: creating workqueue nfsiod [ 0.582620] RPC: registering /proc/net/rpc/nfs [ 0.582669] NFS: Registering the id_resolver key type [ 0.582700] Key type id_resolver registered [ 0.582707] Key type id_legacy registered [ 0.582770] ntfs: driver 2.1.32 [Flags: R/O]. [ 0.584763] bounce: pool size: 64 pages [ 0.584920] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248) [ 0.584936] io scheduler noop registered [ 0.584949] io scheduler deadline registered [ 0.584984] io scheduler cfq registered (default) [ 0.589950] pinctrl-single 4a003400.pinmux: 282 pins at pa fc003400 size 1128 [ 0.593494] PCI host bridge /ocp/axi@0/pcie@51000000 ranges: [ 0.593505] No bus range found for /ocp/axi@0/pcie@51000000, using [bus 00-ff] [ 0.593536] IO 0x20003000..0x20012fff -> 0x00000000 [ 0.593556] MEM 0x20013000..0x2fffffff -> 0x20013000 [ 0.623979] dra7-pcie 51000000.pcie: link is not up [ 0.624163] dra7-pcie 51000000.pcie: PCI host bridge to bus 0000:00 [ 0.624175] pci_bus 0000:00: root bus resource [bus 00-ff] [ 0.624185] pci_bus 0000:00: root bus resource [io 0x0000-0xffff] [ 0.624195] pci_bus 0000:00: root bus resource [mem 0x20013000-0x2fffffff] [ 0.624598] PCI: bus0: Fast back to back transfers disabled [ 0.638362] PCI: bus1: Fast back to back transfers disabled [ 0.638409] irq: no irq domain found for /ocp/axi@0/pcie@51000000/interrupt-controller ! [ 0.638449] irq: no irq domain found for /ocp/axi@0/pcie@51000000/interrupt-controller ! [ 0.638487] pci 0000:00:00.0: BAR 0: assigned [mem 0x20100000-0x201fffff] [ 0.638502] pci 0000:00:00.0: BAR 8: assigned [mem 0x20200000-0x202fffff] [ 0.638514] pci 0000:00:00.0: BAR 9: assigned [mem 0x20300000-0x203fffff pref] [ 0.638525] pci 0000:00:00.0: BAR 1: assigned [mem 0x20020000-0x2002ffff] [ 0.638538] pci 0000:00:00.0: BAR 7: assigned [io 0x1000-0x1fff] [ 0.638553] pci 0000:01:00.0: BAR 6: assigned [mem 0x20300000-0x2030ffff pref] [ 0.638564] pci 0000:01:00.0: BAR 5: assigned [mem 0x20200000-0x202001ff] [ 0.638584] pci 0000:01:00.0: BAR 4: assigned [io 0x1000-0x101f] [ 0.638603] pci 0000:01:00.0: BAR 0: assigned [io 0x1020-0x1027] [ 0.638621] pci 0000:01:00.0: BAR 2: assigned [io 0x1028-0x102f] [ 0.638639] pci 0000:01:00.0: BAR 1: assigned [io 0x1030-0x1033] [ 0.638658] pci 0000:01:00.0: BAR 3: assigned [io 0x1034-0x1037] [ 0.638676] pci 0000:00:00.0: PCI bridge to [bus 01] [ 0.638686] pci 0000:00:00.0: bridge window [io 0x1000-0x1fff] [ 0.638698] pci 0000:00:00.0: bridge window [mem 0x20200000-0x202fffff] [ 0.638708] pci 0000:00:00.0: bridge window [mem 0x20300000-0x203fffff pref] [ 0.638936] pcieport 0000:00:00.0: Signaling PME through PCIe PME interrupt [ 0.638947] pci 0000:01:00.0: Signaling PME through PCIe PME interrupt [ 0.640117] backlight supply power not found, using dummy regulator [ 0.701389] Serial: 8250/16550 driver, 10 ports, IRQ sharing disabled [ 0.704755] 48020000.serial: ttyS2 at MMIO 0x48020000 (irq = 301, base_baud = 3000000) is a 8250 [ 1.803275] console [ttyS2] enabled [ 1.807606] 48422000.serial: ttyS7 at MMIO 0x48422000 (irq = 302, base_baud = 3000000) is a 8250 [ 1.817676] [drm] Initialized drm 1.1.0 20060810 [ 1.824304] OMAP DSS rev 6.1 [ 1.828074] omapdss_dss 58000000.dss: bound 58001000.dispc (ops dispc_component_ops) [ 1.836561] omapdss_dss 58000000.dss: bound 58040000.encoder (ops hdmi5_component_ops) [ 1.852730] loop: module loaded [ 1.858711] libphy: Fixed MDIO Bus: probed [ 1.908322] davinci_mdio 48485000.mdio: davinci mdio revision 1.6 [ 1.914447] davinci_mdio 48485000.mdio: detected phy mask fffffff9 [ 1.924982] libphy: 48485000.mdio: probed [ 1.929054] davinci_mdio 48485000.mdio: phy[1]: device 48485000.mdio:01, driver Micrel KSZ9031 Gigabit PHY [ 1.938788] davinci_mdio 48485000.mdio: phy[2]: device 48485000.mdio:02, driver Micrel KSZ9031 Gigabit PHY [ 1.949155] cpsw 48484000.ethernet: Detected MACID = 74:da:ea:47:8b:26 [ 1.956425] cpsw 48484000.ethernet: cpsw: Detected MACID = 74:da:ea:47:8b:27 [ 1.964968] mousedev: PS/2 mouse device common for all mice [ 1.971072] i2c /dev entries driver [ 1.977349] gpio-fan gpio_fan: GPIO fan initialized [ 1.983301] tmp102 0-0048: initialized [ 1.989999] omap_hsmmc 4809c000.mmc: Got CD GPIO [ 2.038843] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr25 mode [ 2.045225] omap_hsmmc 480b4000.mmc: no pinctrl state for sdr12 mode [ 2.068430] vdd_3v3: supplied by regen1 [ 2.149616] ledtrig-cpu: registered to indicate activity on CPUs [ 2.159632] davinci-mcasp 48468000.mcasp: ERRATA i868 workaround is enabled [ 2.167775] NET: Registered protocol family 10 [ 2.183098] sit: IPv6 over IPv4 tunneling driver [ 2.188303] NET: Registered protocol family 17 [ 2.192973] Key type dns_resolver registered [ 2.197370] omap_voltage_late_init: Voltage driver support not added [ 2.204273] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm [ 2.210499] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm [ 2.217194] Adding alias for supply vdd,cpu0 -> vdd,4a003b20.oppdm [ 2.223424] Adding alias for supply vbb,cpu0 -> vbb,4a003b20.oppdm [ 2.231589] Power Management for TI OMAP4+ devices. [ 2.236687] Registering SWP/SWPB emulation handler [ 2.243623] dmm 4e000000.dmm: initialized all PAT entries [ 2.271099] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013). [ 2.277741] [drm] No driver support for vblank timestamp query. [ 2.337700] mmc0: host does not support reading read-only switch, assuming write-enable [ 2.349180] mmc0: new high speed SDHC card at address aaaa [ 2.355029] mmcblk0: mmc0:aaaa SL08G 7.40 GiB [ 2.360674] mmcblk0: p1 p2 p3 [ 2.422915] mmc1: MAN_BKOPS_EN bit is not set [ 2.435914] mmc1: new DDR MMC card at address 0001 [ 2.451053] mmcblk1: mmc1:0001 S10004 3.56 GiB [ 2.465778] mmcblk1boot0: mmc1:0001 S10004 partition 1 4.00 MiB [ 2.471891] mmcblk1boot1: mmc1:0001 S10004 partition 2 4.00 MiB [ 2.478728] mmcblk1: p1 p2 p3 [ 2.562262] [drm] Enabling DMM ywrap scrolling [ 2.600301] Console: switching to colour frame buffer device 100x30 [ 2.608627] omapdrm omapdrm.0: fb0: omapdrm frame buffer device [ 2.638571] [drm] Initialized omapdrm 1.0.0 20110917 on minor 0 [ 2.645862] input: gpio_keys as /devices/platform/gpio_keys/input/input0 [ 2.652827] hctosys: unable to open rtc device (rtc0) [ 2.668349] net eth0: initializing cpsw version 1.15 (0) [ 2.673702] net eth0: initialized cpsw ale version 1.4 [ 2.678878] net eth0: ALE Table size 1024 [ 2.770336] net eth0: phy found : id is : 0x221622 [ 2.781714] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 6.776920] cpsw 48484000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx [ 6.784829] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 6.798309] Sending DHCP requests ., OK [ 6.848304] IP-Config: Got DHCP answer from 192.168.0.1, my address is 192.168.0.97 [ 6.856129] IP-Config: Complete: [ 6.859400] device=eth0, hwaddr=74:da:ea:47:8b:26, ipaddr=192.168.0.97, mask=255.255.255.0, gw=192.168.0.1 [ 6.870013] host=192.168.0.97, domain=ti.com, nis-domain=(none) [ 6.876395] bootserver=0.0.0.0, rootserver=192.168.0.1, rootpath= [ 6.882795] nameserver0=192.0.2.2, nameserver1=192.0.2.3 [ 6.888933] aic_dvdd_fixed: disabling [ 6.892611] vmmcwl_fixed: disabling [ 6.896293] ldousb: disabling [ 6.899787] ALSA device list: [ 6.902765] No soundcards found. [ 6.907052] Root-NFS: nfsroot=/home/tigtfarm10/NFS_exports/linux/am57xx-evm/autofs/f1a395609921e4cdad1b0bb2ec56f877,nolock,v3,tcp,rsize=4096,wsize=4096 [ 6.920854] NFS: nfs mount opts='vers=2,udp,rsize=4096,wsize=4096,nolock,v3,tcp,rsize=4096,wsize=4096,nolock,addr=192.168.0.1' [ 6.932330] NFS: parsing nfs mount option 'vers=2' [ 6.937399] NFS: parsing nfs mount option 'udp' [ 6.942194] NFS: parsing nfs mount option 'rsize=4096' [ 6.947561] NFS: parsing nfs mount option 'wsize=4096' [ 6.952967] NFS: parsing nfs mount option 'nolock' [ 6.957980] NFS: parsing nfs mount option 'v3' [ 6.962725] NFS: parsing nfs mount option 'tcp' [ 6.967607] NFS: parsing nfs mount option 'rsize=4096' [ 6.972959] NFS: parsing nfs mount option 'wsize=4096' [ 6.978359] NFS: parsing nfs mount option 'nolock' [ 6.983345] NFS: parsing nfs mount option 'addr=192.168.0.1' [ 6.989222] NFS: MNTPATH: '/home/tigtfarm10/NFS_exports/linux/am57xx-evm/autofs/f1a395609921e4cdad1b0bb2ec56f877' [ 6.999540] NFS: sending MNT request for 192.168.0.1:/home/tigtfarm10/NFS_exports/linux/am57xx-evm/autofs/f1a395609921e4cdad1b0bb2ec56f877 [ 7.012046] RPC: set up xprt to 192.168.0.1 (autobind) via tcp [ 7.018454] RPC: created transport eddc9000 with 65536 slots [ 7.024659] RPC: creating mount client for 192.168.0.1 (xprt eddc9000) [ 7.031785] RPC: creating UNIX authenticator for client ee8ead00 [ 7.038376] RPC: new task initialized, procpid 1 [ 7.043532] RPC: allocated task edd8cc00 [ 7.047993] RPC: 1 __rpc_execute flags=0x680 [ 7.052636] RPC: 1 call_start mount3 proc NULL (sync) [ 7.058055] RPC: 1 call_reserve (status 0) [ 7.062524] RPC: 1 reserved req ee8eac00 xid 57c6e885 [ 7.067944] RPC: wake_up_first(eddc9100 "xprt_sending") [ 7.073725] RPC: 1 call_reserveresult (status 0) [ 7.078720] RPC: 1 call_refresh (status 0) [ 7.083180] RPC: 1 holding NULL cred c096c2f0 [ 7.087901] RPC: 1 refreshing NULL cred c096c2f0 [ 7.092894] RPC: 1 call_refreshresult (status 0) [ 7.097877] RPC: 1 call_allocate (status 0) [ 7.102432] RPC: 1 allocated buffer of size 92 at eddc9800 [ 7.108302] RPC: 1 call_bind (status 0) [ 7.112502] RPC: 1 rpcb_getport_async(192.168.0.1, 100005, 3, 6) [ 7.118913] RPC: 1 sleep_on(queue "xprt_binding" time 4294938008) [ 7.125380] RPC: 1 added to queue eddc90a4 "xprt_binding" [ 7.131159] RPC: 1 setting alarm for 60000 ms [ 7.135884] RPC: 1 rpcb_getport_async: trying rpcbind version 2 [ 7.142197] RPC: set up xprt to 192.168.0.1 (port 111) via tcp [ 7.148601] RPC: created transport eddca800 with 65536 slots [ 7.154805] RPC: creating rpcbind client for 192.168.0.1 (xprt eddca800) [ 7.162115] RPC: creating UNIX authenticator for client edd8f200 [ 7.168679] RPC: new task initialized, procpid 1 [ 7.173835] RPC: allocated task edd8cd00 [ 7.178367] RPC: rpc_release_client(edd8f200) [ 7.183285] RPC: 2 __rpc_execute flags=0x681 [ 7.187919] RPC: 2 call_start rpcbind2 proc GETPORT (async) [ 7.193875] RPC: 2 call_reserve (status 0) [ 7.193893] RPC: 1 sync task going to sleep [ 7.202894] RPC: 2 reserved req edd8f100 xid 926299b2 [ 7.208328] RPC: wake_up_first(eddca900 "xprt_sending") [ 7.214096] RPC: 2 call_reserveresult (status 0) [ 7.219089] RPC: 2 call_refresh (status 0) [ 7.223549] RPC: 2 looking up UNIX cred [ 7.227745] RPC: looking up UNIX cred [ 7.231958] RPC: allocating UNIX cred for uid 0 gid 0 [ 7.237553] RPC: 2 refreshing UNIX cred edd8cf00 [ 7.242799] RPC: 2 call_refreshresult (status 0) [ 7.247782] RPC: 2 call_allocate (status 0) [ 7.252340] RPC: 2 allocated buffer of size 508 at eddcb000 [ 7.258296] RPC: 2 call_bind (status 0) [ 7.262494] RPC: 2 call_connect xprt eddca800 is not connected [ 7.268713] RPC: 2 xprt_connect xprt eddca800 is not connected [ 7.274917] RPC: 2 sleep_on(queue "xprt_pending" time 4294938023) [ 7.281392] RPC: 2 added to queue eddca95c "xprt_pending" [ 7.287159] RPC: 2 setting alarm for 60000 ms [ 7.291939] RPC: xs_connect scheduled xprt eddca800 [ 7.297405] RPC: worker connecting xprt eddca800 via tcp to 192.168.0.1 (port 111) [ 7.305897] RPC: eddca800 connect status 115 connected 0 sock state 2 [ 7.306109] RPC: xs_tcp_state_change client eddca800... [ 7.306114] RPC: state 1 conn 0 dead 0 zapped 1 sk_shutdown 0 [ 7.306118] RPC: 2 __rpc_wake_up_task (now 4294938026) [ 7.306120] RPC: 2 disabling timer [ 7.306124] RPC: 2 removed from queue eddca95c "xprt_pending" [ 7.306134] RPC: __rpc_wake_up_task done [ 7.316303] RPC: 2 __rpc_execute flags=0x681 [ 7.316306] RPC: 2 xprt_connect_status: retrying [ 7.316310] RPC: 2 call_connect_status (status -11) [ 7.316313] RPC: 2 call_timeout (minor) [ 7.316315] RPC: 2 call_bind (status 0) [ 7.316319] RPC: 2 call_connect xprt eddca800 is connected [ 7.316322] RPC: 2 call_transmit (status 0) [ 7.316324] RPC: 2 xprt_prepare_transmit [ 7.316328] RPC: 2 failed to lock transport eddca800 [ 7.316331] RPC: 2 sleep_on(queue "xprt_sending" time 4294938027) [ 7.316334] RPC: 2 added to queue eddca900 "xprt_sending" [ 7.400396] RPC: wake_up_first(eddca900 "xprt_sending") [ 7.406168] RPC: 2 __rpc_wake_up_task (now 4294938036) [ 7.411684] RPC: 2 removed from queue eddca900 "xprt_sending" [ 7.417800] RPC: __rpc_wake_up_task done [ 7.422290] RPC: 2 __rpc_execute flags=0x681 [ 7.426965] RPC: 2 call_status (status -11) [ 7.431657] RPC: 2 call_transmit (status 0) [ 7.436202] RPC: 2 xprt_prepare_transmit [ 7.440498] RPC: 2 rpc_xdr_encode (status 0) [ 7.445129] RPC: 2 marshaling UNIX cred edd8cf00 [ 7.450122] RPC: 2 using AUTH_UNIX cred edd8cf00 to wrap rpc data [ 7.456587] RPC: 2 encoding PMAP_GETPORT call (100005, 3, 6, 0) [ 7.462885] RPC: 2 xprt_transmit(92) [ 7.466841] RPC: xs_tcp_send_request(92) = 0 [ 7.467095] RPC: xs_tcp_data_ready... [ 7.467130] RPC: xs_tcp_data_recv started [ 7.467134] RPC: reading TCP record fragment of length 28 [ 7.467136] RPC: reading XID (4 bytes) [ 7.467138] RPC: reading request with XID 926299b2 [ 7.467140] RPC: reading CALL/REPLY flag (4 bytes) [ 7.467142] RPC: read reply XID 926299b2 [ 7.467145] RPC: XID 926299b2 read 20 bytes [ 7.467148] RPC: xprt = eddca800, tcp_copied = 28, tcp_offset = 28, tcp_reclen = 28 [ 7.467151] RPC: 2 xid 926299b2 complete (28 bytes received) [ 7.467154] RPC: xs_tcp_data_recv done [ 7.528985] RPC: 2 xmit complete [ 7.532571] RPC: wake_up_first(eddca900 "xprt_sending") [ 7.538348] RPC: 2 call_status (status 28) [ 7.542806] RPC: 2 call_decode (status 28) [ 7.547263] RPC: 2 validating UNIX cred edd8cf00 [ 7.552255] RPC: 2 using AUTH_UNIX cred edd8cf00 to unwrap rpc data [ 7.558920] RPC: 2 PMAP_GETPORT result: 41203 [ 7.563638] RPC: 2 call_decode result 0 [ 7.567834] RPC: setting port for xprt eddc9000 to 41203 [ 7.573698] RPC: 2 rpcb_getport_done(status 0, port 41203) [ 7.579561] RPC: 2 return 0, status 0 [ 7.583582] RPC: 2 release task [ 7.587081] RPC: freeing buffer of size 508 at eddcb000 [ 7.592856] RPC: 2 release request edd8f100 [ 7.597401] RPC: wake_up_first(eddca9b8 "xprt_backlog") [ 7.603177] RPC: rpc_release_client(edd8f200) [ 7.608072] RPC: destroying rpcbind client for 192.168.0.1 [ 7.614135] RPC: destroying transport eddca800 [ 7.619150] RPC: xs_destroy xprt eddca800 [ 7.623695] RPC: xs_close xprt eddca800 [ 7.628078] RPC: xs_tcp_state_change client eddca800... [ 7.633856] RPC: state 4 conn 1 dead 0 zapped 1 sk_shutdown 3 [ 7.640180] RPC: xs_tcp_state_change client eddca800... [ 7.645947] RPC: state 5 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 7.652265] RPC: xs_tcp_state_change client eddca800... [ 7.658031] RPC: state 7 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 7.664329] RPC: disconnected transport eddca800 [ 7.669493] RPC: xs_tcp_state_change client eddca800... [ 7.675259] RPC: state 7 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 7.681556] RPC: disconnected transport eddca800 [ 7.686711] RPC: xs_tcp_data_ready... [ 7.690938] RPC: disconnected transport eddca800 [ 7.696099] RPC: 1 __rpc_wake_up_task (now 4294938065) [ 7.701613] RPC: 1 disabling timer [ 7.705374] RPC: 1 removed from queue eddc90a4 "xprt_binding" [ 7.711499] RPC: __rpc_wake_up_task done [GS] In good case "RPC: 2 freeing task" can be seen here [ 7.711506] RPC: 1 sync task resuming [ 7.711510] RPC: 1 call_bind_status (status 0) [ 7.711512] RPC: 1 call_connect xprt eddc9000 is not connected [ 7.711515] RPC: 1 xprt_connect xprt eddc9000 is not connected [ 7.711519] RPC: 1 sleep_on(queue "xprt_pending" time 4294938067) [ 7.711521] RPC: 1 added to queue eddc915c "xprt_pending" [ 7.711523] RPC: 1 setting alarm for 60000 ms [ 7.711527] RPC: xs_connect scheduled xprt eddc9000 [ 7.711534] RPC: 1 sync task going to sleep [ 7.711557] RPC: xs_bind 0.0.0.0:872: ok (0) [ 7.711560] RPC: worker connecting xprt eddc9000 via tcp to 192.168.0.1 (port 41203) [ 7.711604] RPC: eddc9000 connect status 115 connected 0 sock state 2 [ 7.711607] RPC: wake_up_first(eddc9100 "xprt_sending") [ 7.711733] RPC: xs_tcp_state_change client eddc9000... [ 7.711737] RPC: state 1 conn 0 dead 0 zapped 1 sk_shutdown 0 [ 7.711740] RPC: 1 __rpc_wake_up_task (now 4294938067) [ 7.711741] RPC: 1 disabling timer [ 7.711744] RPC: 1 removed from queue eddc915c "xprt_pending" [ 7.711750] RPC: __rpc_wake_up_task done [ 7.711790] RPC: 1 sync task resuming [ 7.711793] RPC: 1 xprt_connect_status: retrying [ 7.711796] RPC: 1 call_connect_status (status -11) [ 7.711797] RPC: 1 call_timeout (minor) [ 7.711799] RPC: 1 call_bind (status 0) [ 7.711802] RPC: 1 call_connect xprt eddc9000 is connected [ 7.711803] RPC: 1 call_transmit (status 0) [ 7.711805] RPC: 1 xprt_prepare_transmit [ 7.711808] RPC: 1 rpc_xdr_encode (status 0) [GS] =OR= In good case "RPC: 2 freeing task" can be seen here [ 7.711809] RPC: 1 marshaling NULL cred c096c2f0 [ 7.711812] RPC: 1 using AUTH_NULL cred c096c2f0 to wrap rpc data [ 7.711814] RPC: 1 xprt_transmit(44) [ 7.711839] RPC: xs_tcp_send_request(44) = 0 [ 7.711841] RPC: 1 xmit complete [ 7.711844] RPC: 1 sleep_on(queue "xprt_pending" time 4294938067) [ 7.711846] RPC: 1 added to queue eddc915c "xprt_pending" [ 7.711848] RPC: 1 setting alarm for 60000 ms [ 7.711852] RPC: wake_up_first(eddc9100 "xprt_sending") [ 7.711855] RPC: 1 sync task going to sleep [ 7.712063] RPC: xs_tcp_data_ready... [ 7.712091] RPC: xs_tcp_data_recv started [ 7.712094] RPC: reading TCP record fragment of length 24 [ 7.712096] RPC: reading XID (4 bytes) [ 7.712098] RPC: reading request with XID 57c6e885 [ 7.712101] RPC: reading CALL/REPLY flag (4 bytes) [ 7.712102] RPC: read reply XID 57c6e885 [ 7.712105] RPC: XID 57c6e885 read 16 bytes [ 7.712107] RPC: xprt = eddc9000, tcp_copied = 24, tcp_offset = 24, tcp_reclen = 24 [ 7.712110] RPC: 1 xid 57c6e885 complete (24 bytes received) [ 7.712113] RPC: 1 __rpc_wake_up_task (now 4294938067) [ 7.712114] RPC: 1 disabling timer [ 7.712117] RPC: 1 removed from queue eddc915c "xprt_pending" [ 7.712123] RPC: __rpc_wake_up_task done [ 7.712129] RPC: 1 sync task resuming [ 7.712131] RPC: 1 call_status (status 24) [ 7.712134] RPC: 1 call_decode (status 24) [ 7.712136] RPC: 1 validating NULL cred c096c2f0 [ 7.712140] RPC: 1 using AUTH_NULL cred c096c2f0 to unwrap rpc data [ 7.712141] RPC: 1 call_decode result 0 [ 7.712144] RPC: 1 return 0, status 0 [ 7.712145] RPC: 1 release task [ 7.712150] RPC: freeing buffer of size 92 at eddc9800 [ 7.712153] RPC: 1 release request ee8eac00 [ 7.712154] RPC: wake_up_first(eddc91b8 "xprt_backlog") [ 7.712157] RPC: rpc_release_client(ee8ead00) [ 7.712160] RPC: 1 freeing task [ 7.712164] RPC: new task initialized, procpid 1 [ 7.712166] RPC: allocated task ee257300 [ 7.712169] RPC: 3 __rpc_execute flags=0x1280 [ 7.712171] RPC: 3 call_start mount3 proc MOUNT (sync) [ 7.712173] RPC: 3 call_reserve (status 0) [ 7.712176] RPC: 3 reserved req ee8eac00 xid 58c6e885 [ 7.712179] RPC: wake_up_first(eddc9100 "xprt_sending") [ 7.712182] RPC: 3 call_reserveresult (status 0) [ 7.712184] RPC: 3 call_refresh (status 0) [ 7.712186] RPC: 3 looking up UNIX cred [ 7.712188] RPC: looking up UNIX cred [ 7.712191] RPC: 3 refreshing UNIX cred edd8cf00 [ 7.712193] RPC: 3 call_refreshresult (status 0) [ 7.712195] RPC: 3 call_allocate (status 0) [ 7.712198] RPC: 3 allocated buffer of size 1604 at eeb5f000 [ 7.712200] RPC: 3 call_bind (status 0) [ 7.712202] RPC: 3 call_connect xprt eddc9000 is connected [ 7.712204] RPC: 3 call_transmit (status 0) [ 7.712205] RPC: 3 xprt_prepare_transmit [ 7.712208] RPC: 3 rpc_xdr_encode (status 0) [ 7.712209] RPC: 3 marshaling UNIX cred edd8cf00 [ 7.712212] RPC: 3 using AUTH_UNIX cred edd8cf00 to wrap rpc data [ 7.712215] RPC: 3 xprt_transmit(168) [ 7.712222] RPC: xs_tcp_data_recv done [ 7.712257] RPC: xs_tcp_send_request(168) = 0 [ 7.712259] RPC: 3 xmit complete [ 7.712262] RPC: 3 sleep_on(queue "xprt_pending" time 4294938067) [ 7.712264] RPC: 3 added to queue eddc915c "xprt_pending" [ 7.712266] RPC: 3 setting alarm for 60000 ms [ 7.712269] RPC: wake_up_first(eddc9100 "xprt_sending") [ 7.712273] RPC: 3 sync task going to sleep [ 7.721103] RPC: xs_tcp_data_ready... [ 7.721123] RPC: xs_tcp_data_recv started [ 7.721126] RPC: reading TCP record fragment of length 76 [ 7.721127] RPC: reading XID (4 bytes) [ 7.721129] RPC: reading reply for XID 58c6e885 [ 7.721131] RPC: reading CALL/REPLY flag (4 bytes) [ 7.721133] RPC: read reply XID 58c6e885 [ 7.721136] RPC: XID 58c6e885 read 68 bytes [ 7.721139] RPC: xprt = eddc9000, tcp_copied = 76, tcp_offset = 76, tcp_reclen = 76 [ 7.721141] RPC: 3 xid 58c6e885 complete (76 bytes received) [ 7.721144] RPC: 3 __rpc_wake_up_task (now 4294938068) [ 7.721145] RPC: 3 disabling timer [ 7.721147] RPC: 3 removed from queue eddc915c "xprt_pending" [ 7.721154] RPC: __rpc_wake_up_task done [ 7.721159] RPC: 3 sync task resuming [ 7.721162] RPC: 3 call_status (status 76) [ 7.721164] RPC: 3 call_decode (status 76) [ 7.721166] RPC: 3 validating UNIX cred edd8cf00 [ 7.721169] RPC: 3 using AUTH_UNIX cred edd8cf00 to unwrap rpc data [ 7.721171] NFS: received 1 auth flavors [ 7.721173] NFS: auth flavor[0]: 1 [ 7.721175] RPC: 3 call_decode result 0 [ 7.721177] RPC: 3 return 0, status 0 [ 7.721178] RPC: 3 release task [ 7.721182] RPC: freeing buffer of size 1604 at eeb5f000 [ 7.721186] RPC: 3 release request ee8eac00 [ 7.721188] RPC: wake_up_first(eddc91b8 "xprt_backlog") [ 7.721191] RPC: rpc_release_client(ee8ead00) [ 7.721194] RPC: 3 freeing task [ 7.721197] RPC: shutting down mount client for 192.168.0.1 [ 7.721198] RPC: rpc_release_client(ee8ead00) [ 7.721200] RPC: destroying UNIX authenticator c096c324 [ 7.721205] RPC: destroying mount client for 192.168.0.1 [ 7.721238] NFS: MNT request succeeded [ 7.721241] NFS: attempting to use auth flavor 1 [ 7.721257] --> nfs_init_server() [ 7.721260] --> nfs_get_client(192.168.0.1,v3) [ 7.721264] RPC: looking up machine cred for service * [ 7.721269] RPC: allocated machine cred ee257300 for uid 0 gid 0 [ 7.721279] RPC: set up xprt to 192.168.0.1 (autobind) via tcp [ 7.721296] RPC: created transport eeb5f800 with 65536 slots [ 7.721299] RPC: creating nfs client for 192.168.0.1 (xprt eeb5f800) [ 7.721333] RPC: creating UNIX authenticator for client ee24f600 [ 7.721336] RPC: new task initialized, procpid 1 [ 7.721338] RPC: allocated task ee257380 [ 7.721341] RPC: 4 __rpc_execute flags=0x680 [ 7.721344] RPC: 4 call_start nfs3 proc NULL (sync) [ 7.721347] RPC: 4 call_reserve (status 0) [ 7.721350] RPC: 4 reserved req ee24f500 xid 799833c3 [ 7.721353] RPC: wake_up_first(eeb5f900 "xprt_sending") [ 7.721356] RPC: 4 call_reserveresult (status 0) [ 7.721357] RPC: 4 call_refresh (status 0) [ 7.721360] RPC: 4 holding NULL cred c096c2f0 [ 7.721362] RPC: 4 refreshing NULL cred c096c2f0 [ 7.721364] RPC: 4 call_refreshresult (status 0) [ 7.721367] RPC: 4 call_allocate (status 0) [ 7.721369] RPC: 4 allocated buffer of size 92 at ee2ac800 [ 7.721371] RPC: 4 call_bind (status 0) [ 7.721374] RPC: 4 rpcb_getport_async(192.168.0.1, 100003, 3, 6) [ 7.721376] RPC: 4 sleep_on(queue "xprt_binding" time 4294938068) [ 7.721378] RPC: 4 added to queue eeb5f8a4 "xprt_binding" [ 7.721380] RPC: 4 setting alarm for 60000 ms [ 7.721385] RPC: 4 rpcb_getport_async: trying rpcbind version 2 [ 7.721393] RPC: set up xprt to 192.168.0.1 (port 111) via tcp [ 7.721407] RPC: created transport ee2ac000 with 65536 slots [ 7.721409] RPC: creating rpcbind client for 192.168.0.1 (xprt ee2ac000) [ 7.721432] RPC: creating UNIX authenticator for client ee24f900 [ 7.721435] RPC: new task initialized, procpid 1 [ 7.721437] RPC: allocated task ee257480 [ 7.721440] RPC: rpc_release_client(ee24f900) [ 7.721442] RPC: 4 sync task going to sleep [ 7.721450] RPC: xs_tcp_data_recv done [ 7.721458] RPC: 5 __rpc_execute flags=0x681 [ 7.721460] RPC: 5 call_start rpcbind2 proc GETPORT (async) [ 7.721462] RPC: 5 call_reserve (status 0) [ 7.721465] RPC: 5 reserved req ee24f800 xid 9916d160 [ 7.721468] RPC: wake_up_first(ee2ac100 "xprt_sending") [ 7.721471] RPC: 5 call_reserveresult (status 0) [ 7.721473] RPC: 5 call_refresh (status 0) [ 7.721474] RPC: 5 looking up UNIX cred [ 7.721476] RPC: looking up UNIX cred [ 7.721478] RPC: allocating UNIX cred for uid 0 gid 0 [ 7.721480] RPC: 5 refreshing UNIX cred ee257500 [ 7.721482] RPC: 5 call_refreshresult (status 0) [ 7.721485] RPC: 5 call_allocate (status 0) [ 7.721487] RPC: 5 allocated buffer of size 508 at ee2ad800 [ 7.721489] RPC: 5 call_bind (status 0) [ 7.721491] RPC: 5 call_connect xprt ee2ac000 is not connected [ 7.721493] RPC: 5 xprt_connect xprt ee2ac000 is not connected [ 7.721497] RPC: 5 sleep_on(queue "xprt_pending" time 4294938068) [ 7.721498] RPC: 5 added to queue ee2ac15c "xprt_pending" [ 7.721500] RPC: 5 setting alarm for 60000 ms [ 7.721504] RPC: xs_connect scheduled xprt ee2ac000 [ 7.721514] RPC: worker connecting xprt ee2ac000 via tcp to 192.168.0.1 (port 111) [ 7.721555] RPC: ee2ac000 connect status 115 connected 0 sock state 2 [ 7.721558] RPC: wake_up_first(ee2ac100 "xprt_sending") [ 7.721687] RPC: xs_tcp_state_change client ee2ac000... [ 7.721690] RPC: state 1 conn 0 dead 0 zapped 1 sk_shutdown 0 [ 7.721693] RPC: 5 __rpc_wake_up_task (now 4294938068) [ 7.721695] RPC: 5 disabling timer [ 7.721697] RPC: 5 removed from queue ee2ac15c "xprt_pending" [ 7.721703] RPC: __rpc_wake_up_task done [ 7.721744] RPC: 5 __rpc_execute flags=0x681 [ 7.721746] RPC: 5 xprt_connect_status: retrying [ 7.721748] RPC: 5 call_connect_status (status -11) [ 7.721750] RPC: 5 call_timeout (minor) [ 7.721752] RPC: 5 call_bind (status 0) [ 7.721755] RPC: 5 call_connect xprt ee2ac000 is connected [ 7.721756] RPC: 5 call_transmit (status 0) [ 7.721758] RPC: 5 xprt_prepare_transmit [ 7.721760] RPC: 5 rpc_xdr_encode (status 0) [ 7.721762] RPC: 5 marshaling UNIX cred ee257500 [ 7.721765] RPC: 5 using AUTH_UNIX cred ee257500 to wrap rpc data [ 7.721768] RPC: 5 encoding PMAP_GETPORT call (100003, 3, 6, 0) [ 7.721769] RPC: 5 xprt_transmit(92) [ 7.721796] RPC: xs_tcp_send_request(92) = 0 [ 7.721798] RPC: 5 xmit complete [ 7.721800] RPC: 5 sleep_on(queue "xprt_pending" time 4294938068) [ 7.721803] RPC: 5 added to queue ee2ac15c "xprt_pending" [ 7.721805] RPC: 5 setting alarm for 60000 ms [ 7.721808] RPC: wake_up_first(ee2ac100 "xprt_sending") [ 7.722037] RPC: xs_tcp_data_ready... [ 7.722066] RPC: xs_tcp_data_recv started [ 7.722069] RPC: reading TCP record fragment of length 28 [ 7.722071] RPC: reading XID (4 bytes) [ 7.722073] RPC: reading request with XID 9916d160 [ 7.722075] RPC: reading CALL/REPLY flag (4 bytes) [ 7.722076] RPC: read reply XID 9916d160 [ 7.722079] RPC: XID 9916d160 read 20 bytes [ 7.722082] RPC: xprt = ee2ac000, tcp_copied = 28, tcp_offset = 28, tcp_reclen = 28 [ 7.722084] RPC: 5 xid 9916d160 complete (28 bytes received) [ 7.722087] RPC: 5 __rpc_wake_up_task (now 4294938068) [ 7.722088] RPC: 5 disabling timer [ 7.722091] RPC: 5 removed from queue ee2ac15c "xprt_pending" [ 7.722093] RPC: __rpc_wake_up_task done [ 7.722095] RPC: xs_tcp_data_recv done [ 7.722101] RPC: 5 __rpc_execute flags=0xe81 [ 7.722103] RPC: 5 call_status (status 28) [ 7.722105] RPC: 5 call_decode (status 28) [ 7.722108] RPC: 5 validating UNIX cred ee257500 [ 7.722110] RPC: 5 using AUTH_UNIX cred ee257500 to unwrap rpc data [ 7.722112] RPC: 5 PMAP_GETPORT result: 2049 [ 7.722114] RPC: 5 call_decode result 0 [ 7.722116] RPC: setting port for xprt eeb5f800 to 2049 [ 7.722120] RPC: 5 rpcb_getport_done(status 0, port 2049) [ 7.722122] RPC: 5 return 0, status 0 [ 7.722123] RPC: 5 release task [ 7.722128] RPC: freeing buffer of size 508 at ee2ad800 [ 7.722131] RPC: 5 release request ee24f800 [ 7.722132] RPC: wake_up_first(ee2ac1b8 "xprt_backlog") [ 7.722135] RPC: rpc_release_client(ee24f900) [ 7.722138] RPC: destroying rpcbind client for 192.168.0.1 [ 7.722165] RPC: destroying transport ee2ac000 [ 7.722185] RPC: xs_destroy xprt ee2ac000 [ 7.722188] RPC: xs_close xprt ee2ac000 [ 7.722212] RPC: xs_tcp_state_change client ee2ac000... [ 7.722215] RPC: state 4 conn 1 dead 0 zapped 1 sk_shutdown 3 [ 7.722225] RPC: disconnected transport ee2ac000 [ 7.722232] RPC: 4 __rpc_wake_up_task (now 4294938068) [ 7.722234] RPC: 4 disabling timer [ 7.722236] RPC: 4 removed from queue eeb5f8a4 "xprt_binding" [ 7.722243] RPC: __rpc_wake_up_task done [ 7.722249] RPC: 4 sync task resuming [ 7.722251] RPC: 4 call_bind_status (status 0) [ 7.722253] RPC: 4 call_connect xprt eeb5f800 is not connected [ 7.722255] RPC: 4 xprt_connect xprt eeb5f800 is not connected [ 7.722258] RPC: 4 sleep_on(queue "xprt_pending" time 4294938068) [ 7.722261] RPC: 4 added to queue eeb5f95c "xprt_pending" [ 7.722263] RPC: 4 setting alarm for 60000 ms [ 7.722266] RPC: xs_connect scheduled xprt eeb5f800 [ 7.722270] RPC: 4 sync task going to sleep [ 7.722276] RPC: 5 freeing task [ 7.722289] RPC: xs_bind 0.0.0.0:936: ok (0) [ 7.722292] RPC: worker connecting xprt eeb5f800 via tcp to 192.168.0.1 (port 2049) [ 7.722371] RPC: eeb5f800 connect status 115 connected 0 sock state 2 [ 7.722379] RPC: wake_up_first(eeb5f900 "xprt_sending") [ 8.988298] omap_i2c 48070000.i2c: controller timed out [ 9.128222] RPC: destroying transport eddc9000 [ 9.133237] RPC: xs_destroy xprt eddc9000 [ 9.137782] RPC: xs_close xprt eddc9000 [ 9.142179] RPC: xs_tcp_state_change client eddc9000... [ 9.147945] RPC: state 4 conn 1 dead 0 zapped 1 sk_shutdown 3 [ 9.148286] RPC: unx_free_cred edd8cf00 [ 9.158642] RPC: xs_tcp_state_change client eddc9000... [ 9.164411] RPC: state 5 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 9.170724] RPC: xs_tcp_state_change client eddc9000... [ 9.176489] RPC: state 7 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 9.182789] RPC: disconnected transport eddc9000 [ 9.187944] RPC: xs_tcp_state_change client eddc9000... [ 9.193719] RPC: state 7 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 9.200016] RPC: disconnected transport eddc9000 [ 9.205170] RPC: xs_tcp_data_ready... [ 9.209402] RPC: disconnected transport eddc9000 [ 9.214586] RPC: 2 freeing task [GS] This is failed sequence ^^^^^ [ 62.749957] random: nonblocking pool is initialized [ 67.838287] RPC: 4 timeout [ 67.841361] RPC: 4 __rpc_wake_up_task (now 4294944080) [ 67.846868] RPC: 4 disabling timer [ 67.850647] RPC: 4 removed from queue eeb5f95c "xprt_pending" [ 67.856775] RPC: __rpc_wake_up_task done [ 67.861262] RPC: 4 sync task resuming [ 67.865286] RPC: 4 xprt_connect_status: connect attempt timed out [ 67.871787] RPC: 4 call_connect_status (status -110) [ 67.877124] RPC: 4 call_timeout (minor) [ 67.881339] RPC: 4 call_bind (status 0) [ 67.885543] RPC: 4 call_connect xprt eeb5f800 is not connected [ 67.891766] RPC: 4 xprt_connect xprt eeb5f800 is not connected [ 67.897973] RPC: 4 sleep_on(queue "xprt_pending" time 4294944085) [ 67.904456] RPC: 4 added to queue eeb5f95c "xprt_pending" [ 67.910241] RPC: 4 setting alarm for 120000 ms [ 67.915055] RPC: 4 sync task going to sleep [ 135.038293] RPC: xs_error_report client eeb5f800, error=110... [ 135.044676] RPC: 4 __rpc_wake_up_task (now 4294950800) [ 135.050188] RPC: 4 disabling timer [ 135.053957] RPC: 4 removed from queue eeb5f95c "xprt_pending" [ 135.060079] RPC: __rpc_wake_up_task done [ 135.064542] RPC: xs_tcp_state_change client eeb5f800... [ 135.070317] RPC: state 7 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 135.076609] RPC: disconnected transport eeb5f800 [ 135.081790] RPC: 4 sync task resuming [ 135.085819] RPC: 4 xprt_connect_status: connect attempt timed out [ 135.092334] RPC: 4 call_connect_status (status -110) [ 135.097667] RPC: 4 call_timeout (minor) [ 135.101888] RPC: 4 call_bind (status 0) [ 135.106087] RPC: 4 call_connect xprt eeb5f800 is not connected [ 135.112305] RPC: 4 xprt_connect xprt eeb5f800 is not connected [ 135.118531] RPC: 4 sleep_on(queue "xprt_pending" time 4294950808) [ 135.125002] RPC: 4 added to queue eeb5f95c "xprt_pending" [ 135.130786] RPC: 4 setting alarm for 180000 ms [ 135.135604] RPC: xs_connect delayed xprt eeb5f800 for 3 seconds [ 135.142083] RPC: xs_tcp_state_change client eeb5f800... [ 135.147852] RPC: state 7 conn 0 dead 0 zapped 1 sk_shutdown 3 [ 135.154159] RPC: disconnected transport eeb5f800 [ 135.159328] RPC: 4 __rpc_wake_up_task (now 4294950812) [ 135.164833] RPC: 4 disabling timer [ 135.168614] RPC: 4 removed from queue eeb5f95c "xprt_pending" [ 135.174730] RPC: __rpc_wake_up_task done [ 135.179231] RPC: 4 xprt_connect_status: retrying [ 135.184221] RPC: 4 call_connect_status (status -11) [ 135.189510] RPC: 4 call_timeout (minor) [ 135.193709] RPC: 4 call_bind (status 0) [ 135.197908] RPC: 4 call_connect xprt eeb5f800 is not connected [ 135.204158] RPC: 4 xprt_connect xprt eeb5f800 is not connected [ 135.210443] RPC: 4 failed to lock transport eeb5f800 [ 135.215785] RPC: 4 sleep_on(queue "xprt_sending" time 4294950817) [ 135.222280] RPC: 4 added to queue eeb5f900 "xprt_sending" [ 135.228065] RPC: 4 sync task going to sleep [ 138.188320] RPC: xs_bind 0.0.0.0:936: ok (0) [ 138.193139] RPC: worker connecting xprt eeb5f800 via tcp to 192.168.0.1 (port 2049) [ 138.201418] RPC: eeb5f800 connect status 115 connected 0 sock state 2 [ 138.208433] RPC: wake_up_first(eeb5f900 "xprt_sending") [ 138.214202] RPC: 4 __rpc_wake_up_task (now 4294951117) [ 138.219723] RPC: 4 removed from queue eeb5f900 "xprt_sending" [ 138.225851] RPC: __rpc_wake_up_task done [ 138.230344] RPC: 4 sync task resuming [ 138.234369] RPC: 4 call_connect_status (status -11) [ 138.239664] RPC: 4 call_timeout (minor) [ 138.243870] RPC: 4 call_bind (status 0) [ 138.248070] RPC: 4 call_connect xprt eeb5f800 is not connected [ 138.254295] RPC: 4 xprt_connect xprt eeb5f800 is not connected [ 138.260520] RPC: 4 sleep_on(queue "xprt_pending" time 4294951122) [ 138.266987] RPC: 4 added to queue eeb5f95c "xprt_pending" [ 138.272772] RPC: 4 setting alarm for 180000 ms [ 138.277588] RPC: 4 sync task going to sleep - 12:26:16 [INFO] Boot attempt 1/1 failed - 12:26:16 [INFO] Collecting kernel traces via sysrq... - 12:26:27 [INFO] [ 208.203437] sysrq: SysRq : Show State [ 208.207123] task PC stack pid father [ 208.212370] swapper/0 D c0660fe0 0 1 0 0x00000000 [ 208.218765] Backtrace: [ 208.221239] [<c0660cfc>] (__schedule) from [<c06613c0>] (schedule+0x54/0xc4) [ 208.228316] r10:ee318e00 r9:fffffe00 r8:c063b54c r7:eeda1db4 r6:ee88da34 r5:00000082 [ 208.236216] r4:ee88c000 [ 208.238772] [<c066136c>] (schedule) from [<c063b57c>] (rpc_wait_bit_killable+0x30/0xe4) [ 208.246808] r5:00000082 r4:00000082 [ 208.250416] [<c063b54c>] (rpc_wait_bit_killable) from [<c066195c>] (__wait_on_bit+0x8c/0xcc) [ 208.258886] r5:00000082 r4:ee88da28 [ 208.262492] [<c06618d0>] (__wait_on_bit) from [<c0661a10>] (out_of_line_wait_on_bit+0x74/0x7c) [ 208.271137] r9:fffffe00 r8:00000000 r7:ee2573b8 r6:00000001 r5:ee890000 r4:00000000 [ 208.278952] [<c066199c>] (out_of_line_wait_on_bit) from [<c063c4a0>] (__rpc_execute+0x20c/0x394) [ 208.287772] r7:ee2573b8 r6:c096c8f4 r5:eeb5f95c r4:ee257380 [ 208.293487] [<c063c294>] (__rpc_execute) from [<c063c950>] (rpc_execute+0x6c/0x70) [ 208.301085] r9:c067b694 r8:ee2a0910 r7:c0965a40 r6:c0965a40 r5:00000000 r4:ee257380 [ 208.308902] [<c063c8e4>] (rpc_execute) from [<c0634bb0>] (rpc_run_task+0xac/0xb4) [ 208.316413] r5:ee88dad4 r4:ee257380 [ 208.320017] [<c0634b04>] (rpc_run_task) from [<c0634c00>] (rpc_call_sync+0x48/0xc4) [ 208.327702] r5:ee88dbc4 r4:ee24f600 [ 208.331307] [<c0634bb8>] (rpc_call_sync) from [<c0634cd8>] (rpc_ping+0x5c/0x78) [ 208.338644] r4:ee24f600 [ 208.341194] [<c0634c7c>] (rpc_ping) from [<c0634dac>] (rpc_create_xprt+0xb8/0xd0) [ 208.348705] r4:ee24f600 [ 208.351254] [<c0634cf4>] (rpc_create_xprt) from [<c0634e78>] (rpc_create+0xb4/0x1c4) [ 208.359028] r7:c0965a40 r6:c0965a40 r5:00000000 r4:ee88dbc4 [ 208.364743] [<c0634dc4>] (rpc_create) from [<c01e1abc>] (nfs_create_rpc_client+0xdc/0x12c) [ 208.373039] r6:ee88dc94 r5:00000001 r4:ee318e00 [ 208.377698] [<c01e19e0>] (nfs_create_rpc_client) from [<c01e2778>] (nfs_init_client+0x3c/0xd8) [ 208.386343] r6:eeafefec r5:ee88dca8 r4:ee318e00 [ 208.391002] [<c01e273c>] (nfs_init_client) from [<c01e1840>] (nfs_get_client+0x254/0x3c4) [ 208.399209] r5:ee88dca8 r4:eeafef18 [ 208.402813] [<c01e15ec>] (nfs_get_client) from [<c01e2994>] (nfs_create_server+0xbc/0x4cc) [ 208.411109] r10:c09313d4 r9:ee88ddc4 r8:ee24dcc0 r7:ee88dca8 r6:c096c8f0 r5:eeb5f000 [ 208.419006] r4:ee2a0800 [ 208.421559] [<c01e28d8>] (nfs_create_server) from [<c01fa574>] (nfs3_create_server+0x10/0x28) [ 208.430117] r10:00000001 r9:edd8ca80 r8:c09313d4 r7:c096c8f0 r6:ee88ddc4 r5:00000000 [ 208.438016] r4:ee2a0800 [ 208.440568] [<c01fa564>] (nfs3_create_server) from [<c01ee8a8>] (nfs_try_mount+0xe4/0x340) [ 208.448865] r5:00000000 r4:ee2a0800 [ 208.452474] [<c01ee7c4>] (nfs_try_mount) from [<c01ee14c>] (nfs_fs_mount+0x624/0xb78) [ 208.460333] r10:00000400 r9:00008000 r8:edd8ca8c r7:edd8ca80 r6:c096c8f0 r5:c01ee7c4 [ 208.468232] r4:c09313d4 [ 208.470787] [<c01edb28>] (nfs_fs_mount) from [<c0120a90>] (mount_fs+0x1c/0xac) [ 208.478037] r10:c0930e40 r9:c0928c94 r8:c0930e40 r7:c0930e40 r6:00008000 r5:edd8ca80 [ 208.485936] r4:c01edb28 [ 208.488490] [<c0120a74>] (mount_fs) from [<c0139acc>] (vfs_kern_mount+0x50/0xf8) [ 208.495914] r8:edd8e000 r7:c0930e40 r6:00008000 r5:edd8ca80 r4:edd71900 [ 208.502681] [<c0139a7c>] (vfs_kern_mount) from [<c013cbb4>] (do_mount+0x1a8/0xc20) [ 208.510278] r9:c0928c94 r8:edd68c40 r7:edd8ca80 r6:00008000 r5:00000020 r4:edd8e000 [ 208.518094] [<c013ca0c>] (do_mount) from [<c013d9a0>] (SyS_mount+0x7c/0xa8) [ 208.525081] r10:c090283c r9:c08c25ec r8:00008000 r7:c07eff78 r6:00000000 r5:edd8ca80 [ 208.532979] r4:edd68c40 [ 208.535532] [<c013d924>] (SyS_mount) from [<c08c3494>] (mount_root+0x70/0x12c) [ 208.542781] r8:c091071c r7:00000006 r6:00000005 r5:c091b888 r4:c0972024 [ 208.549549] [<c08c3424>] (mount_root) from [<c08c36b0>] (prepare_namespace+0x160/0x1a4) [ 208.557584] r7:c0972000 r6:c0972000 r5:c0902871 r4:c0972024 [ 208.563297] [<c08c3550>] (prepare_namespace) from [<c08c2fdc>] (kernel_init_freeable+0x274/0x284) [ 208.572203] r5:c0902838 r4:00000008 [ 208.575811] [<c08c2d68>] (kernel_init_freeable) from [<c0660444>] (kernel_init+0x18/0xf0) [ 208.584019] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c066042c [ 208.591918] r4:c0972000 [ 208.594472] [<c066042c>] (kernel_init) from [<c000fa88>] (ret_from_fork+0x14/0x2c) [ 208.602070] r5:c066042c r4:00000000 -- regards, -grygorii ^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2016-08-19 11:14 UTC | newest] Thread overview: 5+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2016-08-03 11:41 Kernel NFS boot failure Grygorii Strashko 2016-08-03 12:06 ` Vladimir Murzin 2016-08-03 15:04 ` Grygorii Strashko 2016-08-11 16:25 ` Grygorii Strashko 2016-08-19 11:14 ` Grygorii Strashko
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).