Messages in this thread | | | Date | Sat, 31 Jan 2009 12:37:39 -0500 (EST) | From | Justin Piszcz <> | Subject | Re: 2.6.28: All I/O, D-state: 3ware 9650SE-16ML/Intel/965/MTRR/PAT? |
| |
I think it was a coincidence when I tried to login before, I tried it again (after trying to re-produce the problem, which I had been able to do) and this time the mouse worked but the keyboard did not..even running echo b > sysrq-trigger did not reboot the server.. Had to resort to manual method.
I am now on kernel 2.6.28.2 and will see if I can make it happen again.
Here are the relevant traces: http://home.comcast.net/~jpiszcz/20090131/stacktrace-cpus.txt http://home.comcast.net/~jpiszcz/20090131/sysrq-trigger-m.txt http://home.comcast.net/~jpiszcz/20090131/sysrq-trigger-t.txt http://home.comcast.net/~jpiszcz/20090131/sysrq-trigger-w.txt http://home.comcast.net/~jpiszcz/20090131/sysrq-t.txt http://home.comcast.net/~jpiszcz/20090131/xfs.txt
The stacktace for each CPU is interesting, see below, XFS related(?)
Can anyone offer any suggestions on what to look for or how to debug this further?
$ df -i /dev/sda1 2539035008 1571332 2537463676 1% /r1
Should I be mounting with -o inode64?
/dev/sda1 on /r1 type xfs (rw,noatime,nobarrier,logbufs=8,logbsize=262144)
[2604823.699927] SysRq : Show backtrace of all active CPUs [2604823.699993] CPU0: [2604823.699996] ffffffff807d8f38 0000000000000046 ffff880228b516e8 0000000000000000 [2604823.700000] ffff8801f4f93588 000000000000000e ffff8801a8843e98 ffffffff8046ff72 [2604823.700000] ffff880228b516c0 ffffffff80272a8c ffff8801f4f935a8 ffff8801f4f93450 [2604823.700000] Call Trace: [2604823.700000] <IRQ> [<ffffffff8046ff72>] showacpu+0x42/0x60 [2604823.700000] [<ffffffff80272a8c>] generic_smp_call_function_interrupt+0x4c/0xf0 [2604823.700000] [<ffffffff8023855f>] smp_call_function_interrupt+0x1f/0x40 [2604823.700000] [<ffffffff8022a3bb>] call_function_interrupt+0x6b/0x70 [2604823.700000] <EOI> [<ffffffff802790d6>] find_get_pages+0x56/0xf0 [2604823.700000] [<ffffffff802790b4>] find_get_pages+0x34/0xf0 [2604823.700000] [<ffffffff80281cd7>] pagevec_lookup+0x17/0x20 [2604823.700000] [<ffffffff803e8459>] xfs_cluster_write+0x99/0x170 [2604823.700000] [<ffffffff803e8bdb>] xfs_page_state_convert+0x52b/0x6d0 [2604823.700000] [<ffffffff803e9071>] xfs_vm_writepage+0x71/0x130 [2604823.700000] [<ffffffff802849c0>] shrink_page_list+0x600/0x760 [2604823.700000] [<ffffffff80284d9f>] shrink_list+0x27f/0x640 [2604823.700000] [<ffffffff8040c9e1>] __up_write+0x21/0x150 [2604823.700000] [<ffffffff8028095d>] determine_dirtyable_memory+0xd/0x20 [2604823.700000] [<ffffffff802809cd>] get_dirty_limits+0x1d/0x290 [2604823.700000] [<ffffffff803cd468>] xfs_iomap+0x188/0x310 [2604823.700000] [<ffffffff802853a6>] shrink_zone+0x246/0x340 [2604823.700000] [<ffffffff802861de>] try_to_free_pages+0x22e/0x390 [2604823.700000] [<ffffffff80283330>] isolate_pages_global+0x0/0x270 [2604823.700000] [<ffffffff8027f472>] __alloc_pages_internal+0x212/0x4e0 [2604823.700000] [<ffffffff80281644>] __do_page_cache_readahead+0xf4/0x240 [2604823.700000] [<ffffffff80281ae2>] ondemand_readahead+0x172/0x1f0 [2604823.700000] [<ffffffff8027af39>] generic_file_aio_read+0x329/0x620 [2604823.700000] [<ffffffff803f08da>] xfs_read+0x12a/0x280 [2604823.700000] [<ffffffff802a3ed3>] do_sync_read+0xe3/0x130 [2604823.700000] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 [2604823.700000] [<ffffffff80608577>] thread_return+0x3d/0x5c6 [2604823.700000] [<ffffffff802a4aa8>] vfs_read+0xc8/0x170 [2604823.700000] [<ffffffff802a4c53>] sys_read+0x53/0xa0 [2604823.700000] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b [2604823.700089] CPU2: [2604823.700091] ffff88022b8d3f38 0000000000000046 ffff880228b516e8 0000000000000002 [2604823.700094] 00007fff4e576050 00007fff4e576048 00007fff4e57605c ffffffff8046ff72 [2604823.700097] ffff880228b516c0 ffffffff80272a8c 0000000000000000 ffff880100003eb0 [2604823.700099] Call Trace: [2604823.700101] <IRQ> [<ffffffff8046ff72>] showacpu+0x42/0x60 [2604823.700105] [<ffffffff80272a8c>] generic_smp_call_function_interrupt+0x4c/0xf0 [2604823.700108] [<ffffffff8023855f>] smp_call_function_interrupt+0x1f/0x40 [2604823.700110] [<ffffffff8022a3bb>] call_function_interrupt+0x6b/0x70 [2604823.700111] <EOI> [<ffffffff8040f426>] copy_user_generic_string+0x36/0x40 [2604823.700116] [<ffffffff8025a7e2>] sys_rt_sigprocmask+0x62/0x120 [2604823.700119] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b p34:~#
On Sat, 31 Jan 2009, Justin Piszcz wrote:
> I have opened a case with 3ware about this, but I do not believe the 3ware > card is at fault, it appears something to do with X or the memory subsystem. > This is not easily reproducible and does not occur often. Maybe once or twice > per month, if that, hopefully someone can make out what is happening in the > trace below? > > KERNEL: > # uname -a > Linux p34.internal.lan 2.6.28 #9 SMP Thu Jan 1 08:07:31 EST 2009 x86_64 > GNU/Linux > > PROBLEM: > During I/O to the 3ware RAID (at least in the past 3-4 previous cases when it > occured), the system stops all I/O to all processes that are have I/O to > perform on the 3ware card. I did a lot of analysis which is shown at the > bottom of this e-mail. > > ODDITY: > After all of the diagnostics I did below(!), what ended up "bringing" the > system back to life? I moved the mouse cursor on the local machine (I run X) > and it uses the Intel graphics (Intel DG965WH motherboard), once I logged in, > the ENTIRE system became responsive again, what the heck!? All of the > processes in D-state were now freed! I have taken an echo t > > /proc/sysrq-trigger, hopefully someone can shed some light on this? It > almost seems like the memory/MTRR(?) is stomping the other memory that is > used by the system? > > QUESTION: Why?? > At the bottom of this e-mail (and also the 3ware ticket): > Request:- 31st January 2009 at 2:24 > Just as I was about to give up, I went to the machine, woke up the > screensaver (moved mouse) and logged in and then EVERYTHING started working > again?? > > NOTE: > After all of this, I re-ran the unrar, it worked fine. My guess is X is > doing > something very strange with the memory? I can try running no X for awhile > and see if that gets rid of the problem? Is that the recommended course of > action, are there other things I can try to debug this problem further? Has > anyone ever seen anything like this? > > CONFIG: > http://home.comcast.net/~jpiszcz/20090131/config-2.6.28.txt > > LOGS: (from Xorg.log) > (II) intel(0): EDID vendor "DEL", prod id 40984 > (II) intel(0): Output VGA connected > (II) intel(0): Output VGA using initial mode 1680x1050 > (II) intel(0): detected 512 kB GTT. > (II) intel(0): detected 7676 kB stolen memory. <- Is this of interest? > (==) intel(0): video overlay key set to 0x101fe > (==) intel(0): Will not try to enable page flipping > (==) intel(0): Triple buffering disabled > (==) intel(0): Intel XvMC decoder disabled > (==) intel(0): Using gamma correction (1.0, 1.0, 1.0) > (**) intel(0): Display dimensions: (430, 270) mm > (**) intel(0): DPI set to (99, 158) > > KERNEL OPTIONS: (of interest?): > | | [*] MTRR (Memory Type Range Register) support | | > | | [*] MTRR cleanup support | | > | | (0) MTRR cleanup enable value (0-1) | | > | | (1) MTRR cleanup spare reg num (0-7) | | > | | [*] x86 PAT support | | > > Should I consider disabling MTRR, x86 PAT support or both? To see if the > problem recurs? Are there any other kernel options I have enabled that could > lead to this problem? > > LSPCI: > 00:00.0 Host bridge: Intel Corporation 82P965/G965 Memory Controller Hub (rev > 02) > 00:01.0 PCI bridge: Intel Corporation 82P965/G965 PCI Express Root Port (rev > 02) > 00:02.0 VGA compatible controller: Intel Corporation 82G965 Integrated > Graphics Controller (rev 02) > 00:03.0 Communication controller: Intel Corporation 82P965/G965 HECI > Controller (rev 02) > 00:19.0 Ethernet controller: Intel Corporation 82566DC Gigabit Network > Connection (rev 02) > 00:1a.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI > Controller #4 (rev 02) > 00:1a.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI > Controller #5 (rev 02) > 00:1a.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI > Controller #2 (rev 02) > 00:1b.0 Audio device: Intel Corporation 82801H (ICH8 Family) HD Audio > Controller (rev 02) > 00:1c.0 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 1 > (rev 02) > 00:1c.1 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 2 > (rev 02) > 00:1c.2 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 3 > (rev 02) > 00:1c.3 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 4 > (rev 02) > 00:1c.4 PCI bridge: Intel Corporation 82801H (ICH8 Family) PCI Express Port 5 > (rev 02) > 00:1d.0 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI > Controller #1 (rev 02) > 00:1d.1 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI > Controller #2 (rev 02) > 00:1d.2 USB Controller: Intel Corporation 82801H (ICH8 Family) USB UHCI > Controller #3 (rev 02) > 00:1d.7 USB Controller: Intel Corporation 82801H (ICH8 Family) USB2 EHCI > Controller #1 (rev 02) > 00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev f2) > 00:1f.0 ISA bridge: Intel Corporation 82801HH (ICH8DH) LPC Interface > Controller (rev 02) > 00:1f.2 SATA controller: Intel Corporation 82801HR/HO/HH (ICH8R/DO/DH) 6 port > SATA AHCI Controller (rev 02) > 00:1f.3 SMBus: Intel Corporation 82801H (ICH8 Family) SMBus Controller (rev > 02) > 01:00.0 RAID bus controller: 3ware Inc 9650SE SATA-II RAID (rev 01) > 03:00.0 IDE interface: Marvell Technology Group Ltd. 88SE6101 single-port > PATA133 interface (rev b1) > 07:00.0 Ethernet controller: Intel Corporation 82540EM Gigabit Ethernet > Controller (rev 02) > 07:01.0 Ethernet controller: Intel Corporation 82541GI Gigabit Ethernet > Controller > > INTERRUPTS: > # cat /proc/interrupts > CPU0 CPU1 CPU2 CPU3 > 0: 8722 0 0 0 IO-APIC-edge timer > 1: 2 0 0 0 IO-APIC-edge i8042 > 9: 0 0 0 0 IO-APIC-fasteoi acpi > 12: 3 0 0 0 IO-APIC-edge i8042 > 16: 10253239 34561425 28715428 20097192 IO-APIC-fasteoi 3w-9xxx, > uhci_hcd:usb3 > 18: 1532 38 0 0 IO-APIC-fasteoi > ehci_hcd:usb1, uhci_hcd:usb7 > 19: 43319 66498 0 0 IO-APIC-fasteoi > uhci_hcd:usb6 > 21: 1503630 282221348 34906481 251529888 IO-APIC-fasteoi > uhci_hcd:usb4, eth1 > 22: 3041085 50898734 44446192 106189021 IO-APIC-fasteoi HDA > Intel, eth2 > 23: 13630119 27422086 1544853 13244 IO-APIC-fasteoi > ehci_hcd:usb2, uhci_hcd:usb5 > 375: 3059314 15607219 8335846 3335608 PCI-MSI-edge ahci > 376: 2259672 275715231 18496746 107799784 PCI-MSI-edge eth0 > 377: 2653268 4958739 0 0 PCI-MSI-edge > i915@pci:0000:00:02.0 > NMI: 0 0 0 0 Non-maskable interrupts > LOC: 2603771749 2610047685 2594237486 2589369293 Local timer interrupts > RES: 5511462 1894029 4550761 1766978 Rescheduling interrupts > CAL: 15747 15686 15135 6535 Function call interrupts > TLB: 749115 747241 962808 893832 TLB shootdowns > TRM: 0 0 0 0 Thermal event interrupts > THR: 0 0 0 0 Threshold APIC interrupts > SPU: 0 0 0 0 Spurious interrupts > ERR: 0 > MIS: 0 > > DETAILS (warning! very long): > > Request:- 31st January 2009 at 1:45 > This problem has happened 3 or 4 times now, it is very strange, it > occurs across several kernels, the one I am running now is (2.6.28). It > occurs across two schedulers (so it is unlikely the kernel); noop and > deadline. > > Essentially what happens is all I/O is blocked during decompression of a file > and it stays that way: > > Extracting from backup.r81 > > ... backup-20090101.img > 87% > > Extracting from backup.r82 > > ... backup-20090101.img > 88% > > Extracting from backup.r83 > > ... backup-20090101.img > 89% > > Extracting from backup.r84 > > ... backup-20090101.img > 90% > > Here, it is *stuck* at 90%: > > PID USER PR NI VIRT SWAP RES SHR S %CPU %MEM TIME P COMMAND > 348 user 20 0 18616 16m 1572 1108 R 100 0.0 21:59 0 unrar > > It sits at 100%, this has happened during VERIFYs and also when the system is > just plain idle. It seems to be a very nasty bug because the process _never_ > seems to complete. > > When this bug occurs, it appears all I/O to the array is blocked: > $ dd if=/dev/zero of=create_file bs=1M count=1024 > > It just sits there, when I try to strace the process, I get nothing: > $ strace -p 770 > Process 770 attached - interrupt to quit > > I tried some things: > > # /opt/3ware/9500/tw_cli /c0 set verify=5 > Setting Verify Rate on /c0 to 5 (Fastest I/O)...Done. > > # /opt/3ware/9500/tw_cli /c0 set verify=1 > Setting Verify Rate on /c0 to 1 (Fastest Verify)...Done. > > # /opt/3ware/9500/tw_cli /c0 set verify=3 > Setting Verify Rate on /c0 to 3 (Balanced Verify and I/O )...Done. > > No difference. > > In its current failure mode: > //p34> info c0 > > Unit UnitType Status %RCmpl %V/I/M Stripe Size(GB) Cache AVrfy > ------------------------------------------------------------------------------ > u0 RAID-6 VERIFYING - 91%(A) 64K 12107.1 ON ON u1 > SPARE OK - - - 931.505 - ON > > > It is verifying, maybe it will 'unblock' the I/O when its done verifying? > > As you can see, the box is stagnant during this problem: > $ vmstat 1 > procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu---- > r b swpd free buff cache si so bi bo in cs us sy id wa > 5 0 83104 47396 136 6586588 0 0 580 442 3 0 1 1 98 > 0 > 5 0 83104 47380 136 6586612 0 0 0 0 4143 129 0 25 75 > 0 > 5 0 83104 47380 136 6586612 0 0 0 0 4063 147 0 25 75 > 0 > 5 0 83104 47380 136 6586612 0 0 0 0 4052 139 0 25 75 > 0 > 5 0 83104 47256 136 6586612 0 0 0 0 4137 199 0 25 75 > 0 > 5 0 83104 47256 136 6586612 0 0 0 0 4916 160 0 25 75 > 0 > > Here is an iostat on the device (/dev/sda): > > avg-cpu: %user %nice %system %iowait %steal %idle > 0.00 0.00 25.00 0.00 0.00 75.00 > > Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz > avgqu-sz await svctm %util > sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 0.00 0.00 0.00 > > avg-cpu: %user %nice %system %iowait %steal %idle > 0.00 0.00 25.06 0.00 0.00 74.94 > > Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz > avgqu-sz await svctm %util > sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 0.00 0.00 0.00 > > avg-cpu: %user %nice %system %iowait %steal %idle > 0.00 0.00 25.00 0.00 0.00 75.00 > > Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz > avgqu-sz await svctm %util > sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 0.00 0.00 0.00 > > avg-cpu: %user %nice %system %iowait %steal %idle > 0.00 0.00 25.06 0.00 0.00 74.94 > > Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz > avgqu-sz await svctm %util > sda1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 0.00 0.00 0.00 > > I will let it sit for now and see if it "comes to" after the VERIFY is > complete. In the interim I have attached the tw_cli /c0 show diag output, > but that looks normal as well, at least the most recent output, this looks > like it could be a deeper bug than just something on the surface. > > The 25% is probably 1 of the CPUs (quad core) pegged at 100% trying to get > I/O and the controller is not allowing it! > > This problem was *NEVER* experienced when I was not using the 3ware card, it > only happened after I began using this card in my machine. > > # /opt/3ware/9500/tw_cli /c0 show all > /c0 Driver Version = 2.26.02.011 > /c0 Model = 9650SE-16ML > /c0 Available Memory = 224MB > /c0 Firmware Version = FE9X 4.06.00.004 > /c0 Bios Version = BE9X 4.05.00.015 > /c0 Boot Loader Version = BL9X 3.08.00.001 > /c0 Serial Number = [[ snip ]] > /c0 PCB Version = Rev 032 > /c0 PCHIP Version = 2.00 > /c0 ACHIP Version = 1.90 > /c0 Number of Ports = 16 > /c0 Number of Drives = 16 > /c0 Number of Units = 2 > /c0 Total Optimal Units = 2 > /c0 Not Optimal Units = 0 /c0 JBOD Export Policy = off > /c0 Disk Spinup Policy = 1 > /c0 Spinup Stagger Time Policy (sec) = 1 > /c0 Auto-Carving Policy = off > /c0 Auto-Carving Size = 2048 GB > /c0 Auto-Rebuild Policy = on > /c0 Controller Bus Type = PCIe > /c0 Controller Bus Width = 8 lanes > /c0 Controller Bus Speed = 2.5 Gbps/lane > > Unit UnitType Status %RCmpl %V/I/M Stripe Size(GB) Cache AVrfy > ------------------------------------------------------------------------------ > u0 RAID-6 VERIFYING - 92%(A) 64K 12107.1 ON ON u1 > SPARE OK - - - 931.505 - ON > > Port Status Unit Size Blocks Serial > --------------------------------------------------------------- > p0 OK u0 931.51 GB 1953525168 WD-... > p1 OK u0 931.51 GB 1953525168 WD-... > p2 OK u0 931.51 GB 1953525168 WD-... > p3 OK u0 931.51 GB 1953525168 WD-... > p4 OK u0 931.51 GB 1953525168 WD-... > p5 OK u0 931.51 GB 1953525168 WD-... > p6 OK u0 931.51 GB 1953525168 WD-... > p7 OK u0 931.51 GB 1953525168 WD-... > p8 OK u0 931.51 GB 1953525168 WD-... > p9 OK u0 931.51 GB 1953525168 WD-... > p10 OK u0 931.51 GB 1953525168 WD-... > p11 OK u0 931.51 GB 1953525168 WD-... > p12 OK u0 931.51 GB 1953525168 WD-... > p13 OK u0 931.51 GB 1953525168 WD-... > p14 OK u0 931.51 GB 1953525168 WD-... > p15 OK u1 931.51 GB 1953525168 WD-... > > Name OnlineState BBUReady Status Volt Temp Hours LastCapTest > --------------------------------------------------------------------------- > bbu On Yes OK OK OK 255 28-Dec-2008 > > Once this is "over" then I can attach the tw_cli diag output right now its > locking/blocking any I/O, I cannot even ssh to the host, even though the root > partition/drives are not on the 3ware controller!! > > root 8694 0.0 0.0 0 0 ? D Jan29 2:21 [pdflush] > root 2226 0.0 0.0 10100 404 ? Ds Jan01 0:14 > /sbin/syslogd -r > > Lots of processes in D-state. > > > Request:- 31st January 2009 at 2:8 > Nope, its still LOCKED/blocked/etc: > > # /opt/3ware/9500/tw_cli info c0 > > Unit UnitType Status %RCmpl %V/I/M Stripe Size(GB) Cache AVrfy > ------------------------------------------------------------------------------ > u0 RAID-6 OK - - 64K 12107.1 ON ON u1 > SPARE OK - - - 931.505 - ON > > Port Status Unit Size Blocks Serial > --------------------------------------------------------------- > p0 OK u0 931.51 GB 1953525168 WD- > p1 OK u0 931.51 GB 1953525168 WD- > p2 OK u0 931.51 GB 1953525168 WD- > p3 OK u0 931.51 GB 1953525168 WD- > p4 OK u0 931.51 GB 1953525168 WD- > p5 OK u0 931.51 GB 1953525168 WD- > p6 OK u0 931.51 GB 1953525168 WD- > p7 OK u0 931.51 GB 1953525168 WD- > p8 OK u0 931.51 GB 1953525168 WD- > p9 OK u0 931.51 GB 1953525168 WD- > p10 OK u0 931.51 GB 1953525168 WD- > p11 OK u0 931.51 GB 1953525168 WD- > p12 OK u0 931.51 GB 1953525168 WD- > p13 OK u0 931.51 GB 1953525168 WD- > p14 OK u0 931.51 GB 1953525168 WD- > p15 OK u1 931.51 GB 1953525168 WD- > > Name OnlineState BBUReady Status Volt Temp Hours LastCapTest > --------------------------------------------------------------------------- > bbu On Yes OK OK OK 255 28-Dec-2008 > > Completely blocking all I/O.. > > p34:~# ps auxww | grep -i unrar > user 348 99.6 0.0 18616 1572 pts/19 R+ 04:05 60:59 unrar x > backup01.rar > root 865 0.0 0.0 4220 724 pts/29 S+ 05:06 0:00 grep -i > unrar > p34:~# kill -9 348 > p34:~# p34:~# killall -9 dd > p34:~# > > Still...... BLOCKED... > > > > Request:- 31st January 2009 at 2:13 > I was able to get a call trace, when I tried to write it to a file > though, it was BLOCKED, so this is from a free ssh session I had open: > > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff80264979>] autoremove_wake_function+0x9/0x30 > [2578818.429166] [<ffffffff8024597a>] __wake_up_common+0x5a/0x90 > [2578818.429166] [<ffffffff80608ced>] schedule_timeout+0xad/0xf0 > [2578818.429166] [<ffffffff80264a83>] prepare_to_wait_exclusive+0x23/0x80 > [2578818.429166] [<ffffffff805dcad6>] unix_wait_for_peer+0x86/0xd0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff80575cd7>] memcpy_fromiovec+0x57/0x80 > [2578818.429166] [<ffffffff805dd170>] unix_dgram_sendmsg+0x450/0x5a0 > [2578818.429166] [<ffffffff8056d77b>] sock_sendmsg+0xcb/0x100 > [2578818.429166] [<ffffffff802af076>] do_path_lookup+0xd6/0x1a0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802af15d>] kern_path+0x1d/0x40 > [2578818.429166] [<ffffffff8025408e>] current_fs_time+0x1e/0x30 > [2578818.429166] [<ffffffff802baa9d>] mnt_want_write+0x2d/0xa0 > [2578818.429166] [<ffffffff802bb637>] mntput_no_expire+0x27/0x140 > [2578818.429166] [<ffffffff805dccc2>] unix_find_other+0x1a2/0x200 > [2578818.429166] [<ffffffff8056cd62>] sockfd_lookup_light+0x22/0x90 > [2578818.429166] [<ffffffff8056db89>] sys_sendto+0x119/0x180 > [2578818.429166] [<ffffffff805dd5ba>] unix_dgram_connect+0xaa/0x250 > [2578818.429166] [<ffffffff8056d046>] sys_connect+0x86/0xe0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] cron S ffff88022aae7bc8 0 861 3044 > [2578818.429166] ffff8801005b9b88 0000000000000086 00007f68d6c77000 > ffffe2000453ab70 > [2578818.429166] ffffffff807cd000 ffff8801005b5260 ffff880211f8f160 > ffff8801005b5490 > [2578818.429166] 000000032abe1b60 ffff8801005b9d18 ffff8801005b5490 > ffffffff8028b45b > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff8028b45b>] handle_mm_fault+0x2bb/0x7a0 > [2578818.429166] [<ffffffff80608ced>] schedule_timeout+0xad/0xf0 > [2578818.429166] [<ffffffff80264a83>] prepare_to_wait_exclusive+0x23/0x80 > [2578818.429166] [<ffffffff805dcad6>] unix_wait_for_peer+0x86/0xd0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff80575cd7>] memcpy_fromiovec+0x57/0x80 > [2578818.429166] [<ffffffff805dd170>] unix_dgram_sendmsg+0x450/0x5a0 > [2578818.429166] [<ffffffff8056d77b>] sock_sendmsg+0xcb/0x100 > [2578818.429166] [<ffffffff802af076>] do_path_lookup+0xd6/0x1a0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802af15d>] kern_path+0x1d/0x40 > [2578818.429166] [<ffffffff8025408e>] current_fs_time+0x1e/0x30 > [2578818.429166] [<ffffffff802baa9d>] mnt_want_write+0x2d/0xa0 > [2578818.429166] [<ffffffff802bb637>] mntput_no_expire+0x27/0x140 > [2578818.429166] [<ffffffff805dccc2>] unix_find_other+0x1a2/0x200 > [2578818.429166] [<ffffffff8056cd62>] sockfd_lookup_light+0x22/0x90 > [2578818.429166] [<ffffffff8056db89>] sys_sendto+0x119/0x180 > [2578818.429166] [<ffffffff805dd5ba>] unix_dgram_connect+0xaa/0x250 > [2578818.429166] [<ffffffff8056d046>] sys_connect+0x86/0xe0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] cron S 00000000ffffffff 0 862 3044 > [2578818.429166] ffff8801005bbb88 0000000000000086 00007f68d6c77000 > ffffe2000453ab70 > [2578818.429166] ffffffff807cd000 ffff8801005b4cf0 ffff88022b8950e0 > ffff8801005b4f20 > [2578818.429166] 0000000129928420 0000000199ae5567 ffff8801005b4f20 > ffffffff8028b45b > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff8028b45b>] handle_mm_fault+0x2bb/0x7a0 > [2578818.429166] [<ffffffff80608ced>] schedule_timeout+0xad/0xf0 > [2578818.429166] [<ffffffff80264a83>] prepare_to_wait_exclusive+0x23/0x80 > [2578818.429166] [<ffffffff805dcad6>] unix_wait_for_peer+0x86/0xd0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff80575cd7>] memcpy_fromiovec+0x57/0x80 > [2578818.429166] [<ffffffff805dd170>] unix_dgram_sendmsg+0x450/0x5a0 > [2578818.429166] [<ffffffff8056d77b>] sock_sendmsg+0xcb/0x100 > [2578818.429166] [<ffffffff802af076>] do_path_lookup+0xd6/0x1a0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802af15d>] kern_path+0x1d/0x40 > [2578818.429166] [<ffffffff8025408e>] current_fs_time+0x1e/0x30 > [2578818.429166] [<ffffffff802baa9d>] mnt_want_write+0x2d/0xa0 > [2578818.429166] [<ffffffff802bb637>] mntput_no_expire+0x27/0x140 > [2578818.429166] [<ffffffff805dccc2>] unix_find_other+0x1a2/0x200 > [2578818.429166] [<ffffffff8056cd62>] sockfd_lookup_light+0x22/0x90 > [2578818.429166] [<ffffffff8056db89>] sys_sendto+0x119/0x180 > [2578818.429166] [<ffffffff805dd5ba>] unix_dgram_connect+0xaa/0x250 > [2578818.429166] [<ffffffff8056d046>] sys_connect+0x86/0xe0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > > > Request:- 31st January 2009 at 2:16 > These are the 'optimizations' I use on this array: > > echo 128 > /sys/block/$i/queue/max_sectors_kb # 128 is default > echo 512 > /sys/block/$i/queue/nr_requests # 128 is default > # echo 254 > /sys/block/$i/device/queue_depth # 254 is default > echo deadline > /sys/block/$i/queue/scheduler # distribution dependent > blockdev --setra 16384 /dev/$i # set readahead > > In the past I had been able to kill the process(es) involved or they died > eventually, however, this does not seem to be the case this time, I still > cannot get my system back! > > Request:- 31st January 2009 at 2:20 > Here is more of the echo t > sysrq-trigger: > > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff805de205>] unix_stream_sendmsg+0x3b5/0x3d0 > [2578818.429166] [<ffffffff80608ced>] schedule_timeout+0xad/0xf0 > [2578818.429166] [<ffffffff80264b03>] prepare_to_wait+0x23/0x80 > [2578818.429166] [<ffffffff805ddc92>] unix_stream_recvmsg+0x432/0x5f0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802aeb6c>] __link_path_walk+0xdbc/0xf20 > [2578818.429166] [<ffffffff8056c60f>] sock_aio_read+0x14f/0x160 > [2578818.429166] [<ffffffff802a3ed3>] do_sync_read+0xe3/0x130 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802a4b3e>] vfs_read+0x15e/0x170 > [2578818.429166] [<ffffffff802a4c53>] sys_read+0x53/0xa0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] sshd S 00000000ffffffff 0 32669 32667 > [2578818.429166] ffff8801c4b15998 0000000000000086 ffffffff80755008 > ffffffff8040c2c0 > [2578818.429166] ffffffff807cd000 ffff88022b968700 ffff88022b8f2bb0 > ffff88022b968930 > [2578818.429166] 0000000328057c18 0000000199b05a5c ffff88022b968930 > ffff8801c4b159a8 > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff8040c2c0>] rb_insert_color+0x100/0x130 > [2578818.429166] [<ffffffff8026800f>] hrtimer_start_range_ns+0xdf/0x1b0 > [2578818.429166] [<ffffffff80267eb9>] hrtimer_try_to_cancel+0x39/0x80 > [2578818.429166] [<ffffffff80609415>] schedule_hrtimeout_range+0xb5/0x150 > [2578818.429166] [<ffffffff802678e0>] hrtimer_wakeup+0x0/0x30 > [2578818.429166] [<ffffffff802b35d9>] do_select+0x539/0x630 > [2578818.429166] [<ffffffff802b3d30>] __pollwait+0x0/0x130 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80575f57>] memcpy_toiovec+0x57/0x80 > [2578818.429166] [<ffffffff8060a529>] _spin_lock_bh+0x9/0x20 > [2578818.429166] [<ffffffff8056fcc3>] release_sock+0x13/0xa0 > [2578818.429166] [<ffffffff805ab7dc>] tcp_recvmsg+0x32c/0x940 > [2578818.429166] [<ffffffff8056f110>] sock_common_recvmsg+0x30/0x50 > [2578818.429166] [<ffffffff8056c60f>] sock_aio_read+0x14f/0x160 > [2578818.429166] [<ffffffff802b38cf>] core_sys_select+0x1ff/0x310 > [2578818.429166] [<ffffffff80240bb0>] do_page_fault+0x2f0/0x980 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff8026aa98>] getnstimeofday+0x48/0xc0 > [2578818.429166] [<ffffffff802308b9>] read_tsc+0x9/0x20 > [2578818.429166] [<ffffffff8026aa98>] getnstimeofday+0x48/0xc0 > [2578818.429166] [<ffffffff802b3c71>] sys_select+0x51/0x110 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] bash S 00000000ffffffff 0 32670 32669 > [2578818.429166] ffff88022607de88 0000000000000082 ffff8800b773cc60 > 00000000006c4e5c > [2578818.429166] ffffffff807cd000 ffff8801006a8410 ffffffff8071a340 > ffff8801006a8640 > [2578818.429166] 00000000006a8410 000000019977482f ffff8801006a8640 > ffffffff807258c8 > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff8045be2b>] tty_check_change+0x11b/0x130 > [2578818.429166] [<ffffffff8025191e>] session_of_pgrp+0xe/0x50 > [2578818.429166] [<ffffffff8045c6f2>] tty_ioctl+0x8b2/0x920 > [2578818.429166] [<ffffffff80252872>] do_wait+0x272/0x350 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff802529e5>] sys_wait4+0x95/0xf0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] sr S 00000000ffffffff 0 32677 32670 > [2578818.429166] ffff88008f50fe88 0000000000000086 ffff88010ccebbb8 > 00000000006c4e5c > [2578818.429166] ffffffff807cd000 ffff880148a6f260 ffffffff8071a340 > ffff880148a6f490 > [2578818.429166] 0000000048a6f260 000000019977482f ffff880148a6f490 > ffffffff807258c8 > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff80252872>] do_wait+0x272/0x350 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff802529e5>] sys_wait4+0x95/0xf0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] screen S 00000000ffffffff 0 32683 32677 > [2578818.429166] ffff88020a9e5f68 0000000000000086 ffff88022ba8f160 > ffff88020a9e5f28 > [2578818.429166] ffffffff807cd000 ffff88022ba8f160 ffff88022b8950e0 > ffff88022ba8f390 > [2578818.429166] 000000015afa2f00 0000000199b0f5e0 ffff88022ba8f390 > 00007fff5afa5be2 > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff80253955>] alarm_setitimer+0x35/0x70 > [2578818.429166] [<ffffffff8025a2e9>] sys_pause+0x19/0x30 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] sshd S 00000000ffffffff 0 32684 10156 > [2578818.429166] ffff880198c4bbe8 0000000000000082 ffff880228808000 > ffff880198c4bb68 > [2578818.429166] ffffffff807cd000 ffff880100552090 ffff88022b8f2bb0 > ffff8801005522c0 > [2578818.429166] 0000000398c4bb68 000000019977506f ffff8801005522c0 > ffff8800058e33c0 > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff805de205>] unix_stream_sendmsg+0x3b5/0x3d0 > [2578818.429166] [<ffffffff80608ced>] schedule_timeout+0xad/0xf0 > [2578818.429166] [<ffffffff80264b03>] prepare_to_wait+0x23/0x80 > [2578818.429166] [<ffffffff805ddc92>] unix_stream_recvmsg+0x432/0x5f0 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802aeb6c>] __link_path_walk+0xdbc/0xf20 > [2578818.429166] [<ffffffff8056c60f>] sock_aio_read+0x14f/0x160 > [2578818.429166] [<ffffffff802a3ed3>] do_sync_read+0xe3/0x130 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff802a4b3e>] vfs_read+0x15e/0x170 > [2578818.429166] [<ffffffff802a4c53>] sys_read+0x53/0xa0 > [2578818.429166] [<ffffffff8022986b>] system_call_fastpath+0x16/0x1b > [2578818.429166] sshd S 00000000ffffffff 0 32686 32684 > [2578818.429166] ffff880040dff998 0000000000000086 ffff880040dff9a8 > ffffffff8040c250 > [2578818.429166] ffffffff807cd000 ffff8801e96411e0 ffff88022b8f2bb0 > ffff8801e9641410 > [2578818.429166] 0000000328057c18 0000000199b0a381 ffff8801e9641410 > ffff880040dff9a8 > [2578818.429166] Call Trace: > [2578818.429166] [<ffffffff8040c250>] rb_insert_color+0x90/0x130 > [2578818.429166] [<ffffffff8026800f>] hrtimer_start_range_ns+0xdf/0x1b0 > [2578818.429166] [<ffffffff80267eb9>] hrtimer_try_to_cancel+0x39/0x80 > [2578818.429166] [<ffffffff80609415>] schedule_hrtimeout_range+0xb5/0x150 > [2578818.429166] [<ffffffff802678e0>] hrtimer_wakeup+0x0/0x30 > [2578818.429166] [<ffffffff802b35d9>] do_select+0x539/0x630 > [2578818.429166] [<ffffffff802b3d30>] __pollwait+0x0/0x130 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80249e30>] default_wake_function+0x0/0x10 > [2578818.429166] [<ffffffff80575f57>] memcpy_toiovec+0x57/0x80 > [2578818.429166] [<ffffffff8060a529>] _spin_lock_bh+0x9/0x20 > [2578818.429166] [<ffffffff8056fcc3>] release_sock+0x13/0xa0 > [2578818.429166] [<ffffffff805ab7dc>] tcp_recvmsg+0x32c/0x940 > [2578818.429166] [<ffffffff8056f110>] sock_common_recvmsg+0x30/0x50 > [2578818.429166] [<ffffffff8056c60f>] sock_aio_read+0x14f/0x160 > [2578818.429166] [<ffffffff802b38cf>] core_sys_select+0x1ff/0x310 > [2578818.429166] [<ffffffff8045e7a1>] n_tty_read+0x371/0x870 > [2578818.429166] [<ffffffff80264970>] autoremove_wake_function+0x0/0x30 > [2578818.429166] [<ffffffff80249e30>] default_wake_fun > > Request:- 31st January 2009 at 2:24 > Just as I was about to give up, I went to the machine, woke up the > screensaver (moved mouse) and logged in and then EVERYTHING started working > again?? > >
| |