Most recent kernel where this bug did not occur: Distribution: minimyth Hardware Environment: ASUS M2NPV-VM & Abit An-M2HD, both on AMD X2 4400 Software Environment: all minimyth versions based on 2.6.23 (older kernels not tested) Problem Description: I'm setting up 2 appliances based on AMD x2 4400 CPU and Nvidia Mobos: ASUS M2NPV-VM (6150 based) and Abit AN-M2HD (7050 based). Kernel is 2.6.23.9. NV are 169.04 Issue is stability of S3 resume: -on ASUS it hangs every 3-10 try and it not depends on maxcpus setting. -on Abit also it hangs every 3-10 try, but with maxcpus=1 is stable. Stability It is not depending on enabled HW on mobos - even with all HW disabled in BIOS S3, resume is still unstable. Observing resume process I didn't see any errors in syslog. There are warnings about cooling device (unable to turn on). Also when resume hangs it hangs always with still lightning CapsLock keyb led (keyb is not reacting on CapsLock pressing) -> it leads me that it isn't video issue. As Abit with maxcpus=1 and ASUS with UP kernel are working OK (I'm not able to reproduce this instability) - it hints me that resume issue is related to possible bugs in non-booting processor initialization phase or races/locking in SMP enabled phase of resume. Steps to reproduce: setup MythTV server, download minimyth (http://linpvr.org/minimyth/download/stable/latest/), boot it from TFTP and start series of many suspend/resume. In my case average 4-6 resume hangs.
First, we have to figure out what's the root of the problem. I have some patches that can help us do that, but they only apply on top of 2.6.24-rc. Would that be a problem to install 2.6.24-rc4 on these boxes?
Ok, now I have prepared booting image with .24-rc6 kernel. I'm ready to start debugging, so let's do it :-) (In reply to comment #1) > First, we have to figure out what's the root of the problem. > > I have some patches that can help us do that, but they only apply on top of > 2.6.24-rc. Would that be a problem to install 2.6.24-rc4 on these boxes? >
Please apply the series of patches from http://www.sisk.pl/kernel/hibernation_and_suspend/2.6.24-rc6/patches/ on top of 2.6.24-rc6, compile the kernel with CONFIG_PM_DEBUG set and see if that works (with maxcpus > 1): # echo core > /sys/power/pm_test # n=0; while test $n -lt 20; do \ > echo mem > /sys/power/state > sleep 1 > n=$(expr $n + 1) > done (it suspends all devices etc., but doesn't put the system into the low power state and only makes it busy-sleep for 5 seconds instead).
(In reply to comment #3) > Please apply the series of patches from > http://www.sisk.pl/kernel/hibernation_and_suspend/2.6.24-rc6/patches/ on top > of > 2.6.24-rc6, compile the kernel with CONFIG_PM_DEBUG set and see if that works > (with maxcpus > 1): > > # echo core > /sys/power/pm_test > # n=0; while test $n -lt 20; do \ > > echo mem > /sys/power/state > > sleep 1 > > n=$(expr $n + 1) > > done > > (it suspends all devices etc., but doesn't put the system into the low power > state and only makes it busy-sleep for 5 seconds instead). > Rafael, Thing are looking good. Abit AN-M2HD+X2 4400 with following script: echo core > /sys/power/pm_test while true; do echo "Entering Sleep" echo mem > /sys/power/state sleep 10 echo "Awaking" done I was able to do 150 cycles without error. I also made series of tests without pm_test. So far (after 100 sleep/resume cycles) all is OK. I'm wonder - where was problem.... Anyway Rafael, BIG THX for excellent job!!!!!
Perhaps the recent patches to fix the code ordering problems on ACPI 1.0x systems (patches 28-34 in the series) help here.
Rafael, After longer period of testing I can say that problem disapear only partially. Sometimes I can't reach hang (usually I'm ending test with 130-150 suspend/resume cycles) and sometimes 20-40 cycles is enough to hang. pm_test with core option always works reliably. For me it looks like in some cases kernel boots in state in which all is OK, but is other cases "some variables are not initialized" and STR is not reliable. Do You have ideas how we can trace this issue ? br
Rafael, Does it make sense to apply above patches to rc7 and test how it works ?
I'm going to prepare the analogous patchest against -rc7. I'll let you know when it's ready.
The new patches have been uploaded into: http://www.sisk.pl/kernel/hibernation_and_suspend/2.6.24-rc7/patches/
Rafael, I'm just finishing building new image with patched rc7. Next days I should have some feedback. BTW: Is rc8's http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=014d433f35d7f34b55dcc7b57c7635aaefc3757f relevant to our subject ?
Well, I don't think so.
Rafael, Sorry for silence in so long time. Some issuees with hardware hold me back... I made some tests with patched rc7 on Biostar TF7050 + X2 4400. Results: -2 series for approx 120 cycles. No hang. -Sometimes (i.e. 1 per 50 cycles), at the end of suspending phase, I receive a lot of traps for 1 or 2 sec, but finally kernel goes to sleep and resumes properly. Next days I will test further this issue and overall stability. Do You have plan to include above patches into official .24 kernel or rather it will be still in testing phase ? Little OT Q: When hw is sent to S3, all ram content, CPU/dev context is maintained in ram which is switched to low-power self-refresh mode. On one of my appliances I expierience kernel traps (system is fully functional, only some apps are triggering traps). I never saw such traps on other apliances (all them share the same network booted system image). Also I never saw traps before first s3 cycle - but sometimes after s3 cycle. As FS is implemented as ramdisk I suspect that my ram has defective self-refresh mode - so entering/staying in low-power mode for some time is introducing errors in ram content. Does kernel have a mechanizm suitable to verify that ram content stays valid across s3 cycle ?. It is hw related issue, but even single bit error in s3 sleep phase can cause system instability and all kind of unpleased apps behaviour... Lets assume: just after s3 resume, ram content checksum is checked, and if wrong sum is detected - kernel is still resuming, but also will notify user space that "system is in undefined state, all processes should be propoerly closed and system should be rebooted asap" ? For desktop usage such enhancements are less important imho, but for appliances booted 24/7 for months with many daily s3 cycles (imagine home HiFi system) - it is crucial for achieving good user experience and expected box stability (even if box will sometime ask itself for reboot....) What do You think ? br
(In reply to comment #12) > Rafael, > > Sorry for silence in so long time. Some issuees with hardware hold me back... > I made some tests with patched rc7 on Biostar TF7050 + X2 4400. > > Results: > -2 series for approx 120 cycles. No hang. Good. :-) > -Sometimes (i.e. 1 per 50 cycles), at the end of suspending phase, I receive > a > lot of traps for 1 or 2 sec, but finally kernel goes to sleep and resumes > properly. > Next days I will test further this issue and overall stability. > > Do You have plan to include above patches into official .24 kernel or rather > it will be still in testing phase ? They are scheduled for inclusion into 2.6.25, so they should appear in 2.6.25-rc kernels in two weeks or so, if there are no problems with them. > Little OT Q: > When hw is sent to S3, all ram content, CPU/dev context is maintained in ram > which is switched to low-power self-refresh mode. On one of my appliances I > expierience kernel traps (system is fully functional, only some apps are > triggering traps). > I never saw such traps on other apliances (all them share the same network > booted system image). Also I never saw traps before first s3 cycle - but > sometimes after s3 cycle. As FS is implemented as ramdisk I suspect that my > ram has defective self-refresh mode - so entering/staying in low-power mode > for some time is introducing errors in ram content. This is possible in principle. > Does kernel have a mechanizm suitable to verify that ram content stays valid > across s3 cycle ?. No, but you can try to use EDAC. > It is hw related issue, but even single bit error in s3 sleep phase can cause > system instability and all kind of unpleased apps behaviour... > Lets assume: just after s3 resume, ram content checksum is checked, and if > wrong sum is detected - kernel is still resuming, but also will notify user > space that "system is in undefined state, all processes should be propoerly > closed and system should be rebooted asap" ? > For desktop usage such enhancements are less important imho, but > for appliances > booted 24/7 for months with many daily s3 cycles (imagine home HiFi system) > - > it is crucial for achieving good user experience and expected box stability > (even if box will sometime ask itself for reboot....) > What do You think ? Well, we could try to do that, but some memory areas are modified during suspend/resume cycles, so we'd have to figure out what exactly to checksum.
Rafael, After some more test on 2 hw platforms (all on x2 4400) I can say: it is almost good. Observed issues: -sometimes before sleep I receive tons of tarps during 1-2 sec - but kernel finally sleeps -also sometimes kernel hangs with output on console like: Freezing userspace proceses.... (elapsed 0.16sec) done. Freezing remaining freezable tasks... kernel is hanging with above last msg br
Regarding my last message: "kernel is hanging with above last msg" in fact kernel is not hang but stopped for few tenths of seconds. After this it goes sleep. Also I'm able to resume.
Apparently, one of freezable kernel threads is slow to respond to freezing requests. How much delay does it cause?
Usually it is 20-40sec. I can measure it more precisely if You want. In Your opinion - for further testing should I stay with patched .24-rc7 or rather wait for another patchset applicable for just released .24 kernel ? br
The patchset against 2.6.24 is already available at: http://www.sisk.pl/kernel/hibernation_and_suspend/2.6.24/patches/ It contains patches that might break things (patches 40-42), but this is not likely to happen. With this patches applied, please see if you're able to reproduce the symptom in the "freezer" test mode, ie. # echo freezer > /sys/power/pm_test # echo mem > /sys/power/state (this will only try to freeze tasks, busy-wait for 5 sec. and thaw them).
Rafael, Unfortunately I'm not able to reproduce this error in test mode. But in normal operation this hang on suspend I'm observing quite frequently (every 5..10th suspend). Q is: is it possible to debug on which task kernel hangs during unsuccessful suspend ?
You should be able to read that from the dmesg output. Please attach dmesg output from after a failing suspend.
Well, Key issue is that my testbed is diskless (no storage) system booted via pxe from network. When, during suspend, kernel hangs - usually I loose access via network/console - so it is impossible to read content of log files. In such case only screen is usable to read any messages :-( Ideally will be when kernel will print all desired info on screen. Is it possible to manage such change in Your patches ? Of course we can consider mods of my system for using storage, but I even don't have suitable storage device in my testbed..... Generally: 2.6.24 has some general issues with s3 on smp architectures. Vanilla .24 kernel with maxcpus=1 or without is rather unusable with s3 as it hangs quite frequently on resume stage. Adding Your patches improves things little bit: no hang on resume but sometimes hang on suspend. In contrast 2.6.23.14 on smp with maxcpus=1 working really well. With all core enabled, it predictable hangs on every 3rd resume. br
(In reply to comment #21) > Well, > > Key issue is that my testbed is diskless (no storage) system booted via pxe > from network. > When, during suspend, kernel hangs - usually I loose access via > network/console > - so it is impossible to read content of log files. In such case only screen > is usable to read any messages :-( > Ideally will be when kernel will print all desired info on screen. Is it > possible to manage such change in Your patches ? It should even be possible without them. :-) Please boot with "no_console_suspend" in the kernel command line and remember to echo 7 or 8 to /proc/sys/kernel/printk prior to suspending. > Of course we can consider mods of my system for using storage, but I > even don't have suitable storage device in my testbed..... > > Generally: 2.6.24 has some general issues with s3 on smp architectures. Well, I test the code on SMP on a regular basis. > Vanilla .24 kernel with maxcpus=1 or without is rather unusable with s3 as > it hangs quite frequently on resume stage. Adding Your patches improves > things little bit: no hang on resume but sometimes hang on suspend. That should be easier to debug with the help of the pm_test thing. Have you tried to figure out where it hangs? I'd guess it's somewhere in the CPU hotplug. > In contrast 2.6.23.14 on smp with maxcpus=1 working really well. > With all core enabled, it predictable hangs on every 3rd resume. Thanks for the update.
Rafael, Here is log from unsuccessful suspend (kernel returns to fully operational state): (printk is set to 8, kernel boot params added no_console_suspend) ------------------------------------ Jan 2 06:51:43 (none) syslog.info syslogd started: BusyBox v1.8.2 Jan 2 06:51:43 (none) daemon.info init: Entering runlevel: 5 Jan 2 06:51:43 (none) local0.info minimyth: configuring shared libraries ... Jan 2 06:51:44 (none) local0.info minimyth: starting loopback network interface ... Jan 2 06:51:44 (none) auth.notice portmap[920]: Only binding to LOOPBACK address! Jan 2 06:51:44 (none) local0.info minimyth: starting DHCP client ... Jan 2 06:51:44 (none) local0.info udhcpc[982]: udhcpc (v1.8.2) started Jan 2 06:51:44 (none) local0.info udhcpc[982]: Sending discover... Jan 2 06:51:44 (none) local0.info udhcpc[982]: Sending select for 192.168.1.130... Jan 2 06:51:44 (none) local0.info udhcpc[982]: Lease of 192.168.1.130 obtained, lease time 7200 Jan 2 06:51:44 (none) local0.info minimyth: loading kernel modules (automatic) ... Jan 2 06:51:46 (none) local0.info minimyth: downloading configuration ... Jan 2 06:51:46 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/conf/FrontEnd3/minimyth.conf' downloaded. Jan 2 06:51:46 (none) local0.info minimyth: processing configuration ... Jan 2 06:51:46 (none) local0.info minimyth: stopping DHCP client ... Jan 2 06:51:46 (none) local0.info udhcpc[1087]: Received SIGTERM Jan 2 06:51:46 (none) local0.info minimyth: starting DHCP client ... Jan 2 06:51:46 (none) local0.info udhcpc[2031]: udhcpc (v1.8.2) started Jan 2 06:51:46 (none) local0.info udhcpc[2031]: Sending discover... Jan 2 06:51:46 (none) local0.info udhcpc[2031]: Sending select for 192.168.1.130... Jan 2 06:51:46 (none) local0.info udhcpc[2031]: Lease of 192.168.1.130 obtained, lease time 7200 Jan 2 07:51:46 (none) local0.info minimyth: processing configuration: checking variables ... Jan 2 07:51:46 (none) local0.info minimyth: checking variables for acpi Jan 2 07:51:46 (none) local0.info minimyth: checking variables for audio Jan 2 07:51:46 (none) local0.info minimyth: checking variables for auth Jan 2 07:51:46 (none) local0.info minimyth: checking variables for codecs Jan 2 07:51:46 (none) local0.info minimyth: checking variables for cpu Jan 2 07:51:46 (none) local0.info minimyth: checking variables for cron Jan 2 07:51:46 (none) local0.info minimyth: checking variables for debug Jan 2 07:51:46 (none) local0.info minimyth: checking variables for dhcp Jan 2 07:51:46 (none) local0.info minimyth: checking variables for external Jan 2 07:51:46 (none) local0.info minimyth: checking variables for extras Jan 2 07:51:46 (none) local0.info minimyth: checking variables for font Jan 2 07:51:46 (none) local0.info minimyth: checking variables for game Jan 2 07:51:46 (none) local0.info minimyth: checking variables for hardware Jan 2 07:51:46 (none) local0.info minimyth: checking variables for lcdproc Jan 2 07:51:46 (none) local0.info minimyth: checking variables for lirc Jan 2 07:51:46 (none) local0.info minimyth: checking variables for master Jan 2 07:51:46 (none) local0.info minimyth: checking variables for media Jan 2 07:51:46 (none) local0.info minimyth: checking variables for minimyth Jan 2 07:51:46 (none) local0.info minimyth: checking variables for mythdb Jan 2 07:51:46 (none) local0.info minimyth: checking variables for plugin Jan 2 07:51:46 (none) local0.info minimyth: checking variables for security Jan 2 07:51:46 (none) local0.info minimyth: checking variables for ssh_remote Jan 2 07:51:46 (none) local0.info minimyth: checking variables for ssh_server Jan 2 07:51:47 (none) local0.info minimyth: checking variables for theme Jan 2 07:51:47 (none) local0.info minimyth: checking variables for update Jan 2 07:51:47 (none) local0.info minimyth: checking variables for version Jan 2 07:51:47 (none) local0.info minimyth: checking variables for video Jan 2 07:51:47 (none) local0.info minimyth: checking variables for wiimote Jan 2 07:51:47 (none) local0.info minimyth: checking variables for x Jan 2 07:51:47 (none) local0.info minimyth: processing configuration: defaulting variables ... Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for acpi Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for audio Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for auth Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for codecs Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for cpu Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for cron Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for debug Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for dhcp Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for external Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for extras Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for font Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for game Jan 2 07:51:47 (none) local0.info minimyth: defaulting variables for hardware Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for lcdproc Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for lirc Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for master Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for media Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for minimyth Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for mythdb Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for plugin Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for security Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for ssh_remote Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for ssh_server Jan 2 07:51:48 (none) local0.info minimyth: defaulting variables for theme Jan 2 07:51:49 (none) local0.info minimyth: defaulting variables for update Jan 2 07:51:49 (none) local0.info minimyth: defaulting variables for version Jan 2 07:51:49 (none) local0.info minimyth: defaulting variables for video Jan 2 07:51:49 (none) local0.info minimyth: defaulting variables for wiimote Jan 2 07:51:49 (none) local0.info minimyth: defaulting variables for x Jan 2 07:51:49 (none) local0.info minimyth: processing configuration: writing variables ... Jan 2 07:51:49 (none) local0.info minimyth: writing variables for acpi Jan 2 07:51:49 (none) local0.info minimyth: writing variables for audio Jan 2 07:51:49 (none) local0.info minimyth: writing variables for auth Jan 2 07:51:49 (none) local0.info minimyth: writing variables for codecs Jan 2 07:51:49 (none) local0.info minimyth: writing variables for cpu Jan 2 07:51:49 (none) local0.info minimyth: writing variables for cron Jan 2 07:51:49 (none) local0.info minimyth: writing variables for debug Jan 2 07:51:49 (none) local0.info minimyth: writing variables for dhcp Jan 2 07:51:49 (none) local0.info minimyth: writing variables for external Jan 2 07:51:49 (none) local0.info minimyth: writing variables for extras Jan 2 07:51:49 (none) local0.info minimyth: writing variables for font Jan 2 07:51:49 (none) local0.info minimyth: writing variables for game Jan 2 07:51:49 (none) local0.info minimyth: writing variables for hardware Jan 2 07:51:49 (none) local0.info minimyth: writing variables for lcdproc Jan 2 07:51:49 (none) local0.info minimyth: writing variables for lirc Jan 2 07:51:49 (none) local0.info minimyth: writing variables for master Jan 2 07:51:49 (none) local0.info minimyth: writing variables for media Jan 2 07:51:49 (none) local0.info minimyth: writing variables for minimyth Jan 2 07:51:49 (none) local0.info minimyth: writing variables for mythdb Jan 2 07:51:49 (none) local0.info minimyth: writing variables for plugin Jan 2 07:51:49 (none) local0.info minimyth: writing variables for security Jan 2 07:51:49 (none) local0.info minimyth: writing variables for ssh_remote Jan 2 07:51:49 (none) local0.info minimyth: writing variables for ssh_server Jan 2 07:51:49 (none) local0.info minimyth: writing variables for theme Jan 2 07:51:49 (none) local0.info minimyth: writing variables for update Jan 2 07:51:49 (none) local0.info minimyth: writing variables for version Jan 2 07:51:49 (none) local0.info minimyth: writing variables for video Jan 2 07:51:49 (none) local0.info minimyth: writing variables for wiimote Jan 2 07:51:49 (none) local0.info minimyth: writing variables for x Jan 2 07:51:50 (none) local0.info minimyth: processing configuration: fetching additional files ... Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for acpi Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for audio Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for auth Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for codecs Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for cpu Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for cron Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for debug Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for dhcp Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for external Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for extras Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for font Jan 2 07:51:50 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/conf/FrontEnd3/subfont.ttf' downloaded. Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for game Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for hardware Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for lcdproc Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for lirc Jan 2 07:51:50 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/conf/FrontEnd3/lircd.conf' downloaded. Jan 2 07:51:50 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/conf/FrontEnd3/lircrc' downloaded. Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for master Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for media Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for minimyth Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for mythdb Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for plugin Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for security Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for ssh_remote Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for ssh_server Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for theme Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for update Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for version Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for video Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for wiimote Jan 2 07:51:50 (none) local0.info minimyth: fetching additional files for x Jan 2 07:51:50 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/conf/FrontEnd3/xorg.conf' downloaded. Jan 2 07:51:50 (none) local0.info minimyth: loading kernel modules (manual) ... Jan 2 07:51:50 (none) local0.info minimyth: starting system logging ... Jan 2 07:51:50 (none) user.notice kernel: klogd started: BusyBox v1.8.2 (2008-02-05 23:36:40 CET) Jan 2 07:51:50 (none) user.info kernel: 0000:00:0a.0: ifname eth0, PHY OUI 0x5043 @ 1, addr 00:50:8d:b2:09:fb Jan 2 07:51:50 (none) user.info kernel: forcedeth 0000:00:0a.0: highdma pwrctl mgmt timirq gbit lnktim msi desc-v3 Jan 2 07:51:50 (none) user.info kernel: PNP: No PS/2 controller found. Probing ports directly. Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for platform:i8042 Jan 2 07:51:50 (none) user.info kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for serio:serio0 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:mice Jan 2 07:51:50 (none) user.info kernel: mice: PS/2 mouse device common for all mice Jan 2 07:51:50 (none) user.info kernel: TCP cubic registered Jan 2 07:51:50 (none) user.info kernel: NET: Registered protocol family 1 Jan 2 07:51:50 (none) user.info kernel: RPC: Registered udp transport module. Jan 2 07:51:50 (none) user.info kernel: RPC: Registered tcp transport module. Jan 2 07:51:50 (none) user.info kernel: Starting balanced_irq Jan 2 07:51:50 (none) user.warn kernel: Using IPI No-Shortcut mode Jan 2 07:51:50 (none) user.warn kernel: Magic number: 7:91:872 Jan 2 07:51:50 (none) user.notice kernel: RAMDISK: squashfs filesystem found at block 0 Jan 2 07:51:50 (none) user.notice kernel: RAMDISK: Loading 54430KiB [1 disk] into ram disk... |^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\^H|^H/^H-^H\ Jan 2 07:51:50 (none) user.warn kernel: VFS: Mounted root (squashfs filesystem) readonly. Jan 2 07:51:50 (none) user.info kernel: Freeing unused kernel memory: 192k freed Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.info kernel: Registering unionfs 2.2.3 (for 2.6.24) Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.info kernel: unionfs: new lower inode mtime (bindex=1, name=console) Jan 2 07:51:50 (none) user.debug kernel: PM: Ad Jan 2 07:51:50 (none) user.info kernel: ding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.info kernel: unionfs: new lower inode mtime (bindex=1, name=console) Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.info kernel: unionfs: new lower inode mtime (bindex=1, name=console) Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.info kernel: usbcore: registered new interface driver usbfs Jan 2 07:51:50 (none) user.info kernel: usbcore: registered new interface driver hub Jan 2 07:51:50 (none) user.info kernel: usbcore: registered new device driver usb Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcs1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:vcsa1 Jan 2 07:51:50 (none) user.info kernel: NET: Registered protocol family 17 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:rtc Jan 2 07:51:50 (none) user.info kernel: Real Time Clock Driver v1.12ac Jan 2 07:51:50 (none) user.info kernel: io scheduler anticipatory registered Jan 2 07:51:50 (none) user.info kernel: loop: module loaded Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for platform:parport_pc.956 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for platform:parport_pc.956 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for platform:parport_pc.888 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for platform:parport_pc.888 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for platform:parport_pc.632 Jan 2 07:51:50 (none) user.debug kernel: PM: Removing info for platform:parport_pc.632 Jan 2 07:51:50 (none) user.info kernel: ppdev: user-space parallel port driver Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:input0 Jan 2 07:51:50 (none) user.info kernel: input: Power Button (FF) as /devices/virtual/input/input0 Jan 2 07:51:50 (none) user.debug kernel: ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [AUBA] enabled at IRQ 22 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:00:02.0[A] -> Link [AUBA] -> GSI 22 (level, low) -> IRQ 17 Jan 2 07:51:50 (none) user.info kernel: ACPI: Power Button (FF) [PWRF] Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:input1 Jan 2 07:51:50 (none) user.info kernel: input: Power Button (CM) as /devices/virtual/input/input1 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:02.0 to 64 Jan 2 07:51:50 (none) user.info kernel: ohci_hcd 0000:00:02.0: OHCI Host Controller Jan 2 07:51:50 (none) user.info kernel: ohci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1 Jan 2 07:51:50 (none) user.info kernel: ohci_hcd 0000:00:02.0: irq 17, io mem 0xfe02f000 Jan 2 07:51:50 (none) user.notice kernel: SCSI subsystem initialized Jan 2 07:51:50 (none) user.info kernel: ACPI: Power Button (CM) [PWRB] Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:usb1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev1.1_ep00 Jan 2 07:51:50 (none) user.info kernel: usb usb1: configuration #1 chosen from 1 choice Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:1-0:1.0 Jan 2 07:51:50 (none) user.info kernel: hub 1-0:1.0: USB hub found Jan 2 07:51:50 (none) user.info kernel: hub 1-0:1.0: 6 ports detected Jan 2 07:51:50 (none) user.debug kernel: libata version 3.00 loaded. Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:timer Jan 2 07:51:50 (none) user.info kernel: Linux agpgart interface v0.102 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev1.1_ep81 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev1.1 Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [AU1B] enabled at IRQ 21 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:00:04.0[A] -> Link [AU1B] -> GSI 21 (level, low) -> IRQ 18 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:04.0 to 64 Jan 2 07:51:50 (none) user.info kernel: ohci_hcd 0000:00:04.0: OHCI Host Controller Jan 2 07:51:50 (none) user.info kernel: ohci_hcd 0000:00:04.0: new USB bus registered, assigned bus number 2 Jan 2 07:51:50 (none) user.info kernel: ohci_hcd 0000:00:04.0: irq 18, io mem 0xfe02d000 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:usb2 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.1_ep00 Jan 2 07:51:50 (none) user.info kernel: usb usb2: configuration #1 chosen from 1 choice Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:2-0:1.0 Jan 2 07:51:50 (none) user.info kernel: hub 2-0:1.0: USB hub found Jan 2 07:51:50 (none) user.info kernel: hub 2-0:1.0: 6 ports detected Jan 2 07:51:50 (none) user.warn kernel: nvidia: module license 'NVIDIA' taints kernel. Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.1_ep81 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.1 Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [AUB2] enabled at IRQ 20 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:00:02.1[B] -> Link [AUB2] -> GSI 20 (level, low) -> IRQ 19 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:02.1 to 64 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:02.1: EHCI Host Controller Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:02.1: new USB bus registered, assigned bus number 3 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:02.1: debug port 1 Jan 2 07:51:50 (none) user.debug kernel: PCI: cache line size of 64 is not supported by device 0000:00:02.1 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:02.1: irq 19, io mem 0xfe02e000 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:02.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004, overcurrent ignored Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:usb3 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev3.1_ep00 Jan 2 07:51:50 (none) user.info kernel: usb usb3: configuration #1 chosen from 1 choice Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:3-0:1.0 Jan 2 07:51:50 (none) user.info kernel: hub 3-0:1.0: USB hub found Jan 2 07:51:50 (none) user.info kernel: hub 3-0:1.0: 6 ports detected Jan 2 07:51:50 (none) user.info kernel: ACPI: Thermal Zone [THRM] (50 C) Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev3.1_ep81 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev3.1 Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [AU2B] enabled at IRQ 23 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:00:04.1[B] -> Link [AU2B] -> GSI 23 (level, low) -> IRQ 16 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:04.1 to 64 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:04.1: EHCI Host Controller Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:04.1: new USB bus registered, assigned bus number 4 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:04.1: debug port 1 Jan 2 07:51:50 (none) user.debug kernel: PCI: cache line size of 64 is not supported by device 0000:00:04.1 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:event0 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:04.1: irq 16, io mem 0xfe02c000 Jan 2 07:51:50 (none) user.info kernel: ACPI: Fan [FAN] (on) Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:event1 Jan 2 07:51:50 (none) user.info kernel: usb 2-6: new full speed USB device using ohci_hcd and address 2 Jan 2 07:51:50 (none) user.info kernel: ehci_hcd 0000:00:04.1: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004, overcurrent ignored Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:usb4 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev4.1_ep00 Jan 2 07:51:50 (none) user.info kernel: usb usb4: configuration #1 chosen from 1 choice Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:4-0:1.0 Jan 2 07:51:50 (none) user.info kernel: hub 4-0:1.0: USB hub found Jan 2 07:51:50 (none) user.info kernel: hub 4-0:1.0: 6 ports detected Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev4.1_ep81 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev4.1 Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [APC4] enabled at IRQ 19 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:01:07.0[A] -> Link [APC4] -> GSI 19 (level, low) -> IRQ 20 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:01:07.0 to 64 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for ieee1394:fw-host0 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:fw-host0 Jan 2 07:51:50 (none) user.info kernel: ohci1394: fw-host0: OHCI-1394 1.1 (PCI): IRQ=[20] MMIO=[fd0ff000-fd0ff7ff] Max Packet=[2048] IR/IT contexts=[4/8] Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [AIGP] enabled at IRQ 22 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:00:12.0[A] -> Link [AIGP] -> GSI 22 (level, low) -> IRQ 17 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:12.0 to 64 Jan 2 07:51:50 (none) user.warn kernel: NVRM: loading NVIDIA UNIX x86 Kernel Module 169.09 Fri Jan 11 14:38:28 PST 2008 Jan 2 07:51:50 (none) user.debug kernel: pata_amd 0000:00:06.0: version 0.3.10 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:06.0 to 64 Jan 2 07:51:50 (none) user.info kernel: scsi0 : pata_amd Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:host0 Jan 2 07:51:50 (none) user.info kernel: scsi1 : pata_amd Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:host1 Jan 2 07:51:50 (none) user.info kernel: ata1: PATA max UDMA/133 cmd 0x1f0 ctl 0x3f6 bmdma 0xf000 irq 14 Jan 2 07:51:50 (none) user.info kernel: ata2: PATA max UDMA/133 cmd 0x170 ctl 0x376 bmdma 0xf008 irq 15 Jan 2 07:51:50 (none) user.debug kernel: ata2: port disabled. ignoring. Jan 2 07:51:50 (none) user.warn kernel: ACPI: PCI Interrupt Link [AAZA] enabled at IRQ 21 Jan 2 07:51:50 (none) user.info kernel: ACPI: PCI Interrupt 0000:00:07.0[A] -> Link [AAZA] -> GSI 21 (level, low) -> IRQ 18 Jan 2 07:51:50 (none) user.debug kernel: PCI: Setting latency timer of device 0000:00:07.0 to 64 Jan 2 07:51:50 (none) user.info kernel: hda_codec: Unknown model for ALC883, trying auto-probe from BIOS... Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:card0 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:pcmC0D2c Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:pcmC0D1p Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:pcmC0D0p Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:pcmC0D0c Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:controlC0 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:hwmon0 Jan 2 07:51:50 (none) user.info kernel: usb 2-6: new full speed USB device using ohci_hcd and address 3 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:2-6 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.3_ep00 Jan 2 07:51:50 (none) user.info kernel: usb 2-6: configuration #1 chosen from 1 choice Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for usb:2-6:1.0 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.3_ep01 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.3_ep81 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:usbdev2.3 Jan 2 07:51:50 (none) user.info kernel: lirc_dev: IR Remote Control driver registered, major 61 Jan 2 07:51:50 (none) user.info kernel: Jan 2 07:51:50 (none) user.info kernel: lirc_mceusb2: Philips eHome USB IR Transciever and Microsoft MCE 2005 Remote Control driver for LIRC $Revision: 1.41 $ Jan 2 07:51:50 (none) user.info kernel: lirc_mceusb2: Daniel Melander <lirc@rajidae.se>, Martin Blatter <martin_a_blatter@yahoo.com> Jan 2 07:51:50 (none) user.info kernel: usb 2-6: reset full speed USB device using ohci_hcd and address 3 Jan 2 07:51:50 (none) user.info kernel: lirc_dev: lirc_register_plugin: sample_rate: 0 Jan 2 07:51:50 (none) user.warn kernel: lirc_mceusb2[3]: Philips eHome Infrared Transceiver on usb2:3 Jan 2 07:51:50 (none) user.info kernel: usbcore: registered new interface driver lirc_mceusb2 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for ieee1394:00508d00009b0d27 Jan 2 07:51:50 (none) user.debug kernel: PM: Adding info for No Bus:00508d00009b0d27 Jan 2 07:51:50 (none) user.debug kernel: ieee1394: Host added: ID:BUS[0-00:1023] GUID[00508d00009b0d27 Jan 2 07:51:50 (none) user.info kernel: ] Jan 2 07:51:51 (none) local0.info minimyth: running minimyth.script ... Jan 2 07:51:51 (none) local0.info minimyth: starting CPU frequency scaling ... Jan 2 07:51:51 (none) user.info kernel: powernow-k8: Found 1 AMD Athlon(tm) 64 X2 Dual Core Processor 4400+ processors (2 cpu cores) (version 2.20.00) Jan 2 07:51:51 (none) user.info kernel: powernow-k8: 0 : fid 0xf (2300 MHz), vid 0xa Jan 2 07:51:51 (none) user.info kernel: powernow-k8: 1 : fid 0xe (2200 MHz), vid 0xb Jan 2 07:51:51 (none) user.info kernel: powernow-k8: 2 : fid 0xc (2000 MHz), vid 0xd Jan 2 07:51:51 (none) user.info kernel: powernow-k8: 3 : fid 0xa (1800 MHz), vid 0xf Jan 2 07:51:51 (none) user.info kernel: powernow-k8: 4 : fid 0x2 (1000 MHz), vid 0x12 Jan 2 07:51:51 (none) local0.info minimyth: starting virtual console ... Jan 2 07:51:51 (none) local0.info minimyth: starting telnet server ... Jan 2 07:51:52 (none) local0.info minimyth: configuring ssh server ... Jan 2 07:51:52 (none) local0.info minimyth: starting cron ... Jan 2 07:51:52 (none) local0.info minimyth: restoring selected game configuration files ... Jan 2 07:51:52 (none) local0.info minimyth: configuring MythTV master backend communication ... Jan 2 07:51:53 (none) local0.info minimyth: installing binary codecs ... Jan 2 07:51:53 (none) local0.info minimyth: installing extras ... Jan 2 07:51:53 (none) local0.info minimyth: checking sensors ... Jan 2 07:51:53 (none) local0.info minimyth: starting ACPI ... Jan 2 07:51:53 (none) daemon.info acpid: starting up Jan 2 07:51:53 (none) daemon.info acpid: 1 rule loaded Jan 2 07:51:53 (none) local0.info minimyth: setting time ... Jan 2 07:51:54 (none) daemon.notice ntpdate[6189]: step time server 192.168.1.254 offset 35044535.645106 sec Feb 11 22:27:29 (none) local0.info minimyth: starting NTP daemon ... Feb 11 22:27:29 (none) daemon.notice ntpd[6199]: ntpd 4.2.4p4@1.1520 Wed Feb 6 00:10:34 UTC 2008 (1) Feb 11 22:27:29 (none) daemon.info ntpd[6200]: precision = 1.000 usec Feb 11 22:27:29 (none) daemon.debug ntpd[6200]: ntp_io: estimated max descriptors: 1024, initial socket boundary: 16 Feb 11 22:27:29 (none) daemon.info ntpd[6200]: Listening on interface #0 wildcard, 0.0.0.0#123 Disabled Feb 11 22:27:29 (none) daemon.info ntpd[6200]: Listening on interface #1 lo, 127.0.0.1#123 Enabled Feb 11 22:27:29 (none) daemon.info ntpd[6200]: Listening on interface #2 eth0, 192.168.1.130#123 Enabled Feb 11 22:27:29 (none) daemon.info ntpd[6200]: kernel time sync status 0040 Feb 11 22:27:29 (none) local0.info minimyth: starting web server ... Feb 11 22:27:29 (none) daemon.notice webfsd[6239]: started (listen on *:80, root=/srv/www, user=httpd, group=httpd) Feb 11 22:27:29 (none) daemon.notice webfsd[6242]: started (listen on *:8080, root=/, user=root, group=root) Feb 11 22:27:30 (none) local0.info minimyth: mounting media shares ... Feb 11 22:27:30 (none) local0.info minimyth: configuring audio ... Feb 11 22:27:30 (none) local0.info minimyth: configuring video ... Feb 11 22:27:31 (none) local0.info minimyth: starting remote control ... Feb 11 22:27:31 (none) local0.info minimyth: using remote control device: device='/dev/lirc0', driver='mceusb2' and remote='' lircd.conf='/etc/lircd.conf'. Feb 11 22:27:31 (none) local0.info minimyth: started '/usr/sbin/lircd --device=/dev/lirc0 --driver=default --output=/dev/lircd --pidfile=/var/run/lircd.pid'. Feb 11 22:27:31 (none) local0.info minimyth: starting LCD/VFD ... Feb 11 22:27:31 (none) local0.info minimyth: configuring ssh remote command execution ... Feb 11 22:27:31 (none) local0.info minimyth: configuring MythTV ... Feb 11 22:27:47 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/themes/blootube-wide-piotro.sfs' downloaded. Feb 11 22:27:47 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/themes/blootube-osd.sfs' downloaded. Feb 11 22:28:19 (none) local0.info minimyth: 'tftp://192.168.1.254/PXEclient/conf-rw/FrontEnd3+themecaches+blootube-wide-piotro.1600.1200.sfs' downloaded. Feb 11 22:28:19 (none) local0.info minimyth: updating fonts ... Feb 11 22:28:20 (none) local0.info minimyth: configuring X ... Feb 11 22:28:20 (none) local0.info minimyth: starting X ... Feb 11 22:28:20 (none) local0.info minimyth: starting X Feb 11 22:28:20 (none) auth.notice su: + none root:minimyth Feb 11 22:28:20 (none) user.debug kernel: PM: Adding info for No Bus:vcs2 Feb 11 22:28:20 (none) user.debug kernel: PM: Adding info for No Bus:vcsa2 Feb 11 22:28:20 (none) local0.info minimyth: stopping splash screen Feb 11 21:28:20 (none) daemon.info init: no more processes left in this runlevel Feb 11 22:28:21 (none) user.debug kernel: PM: Adding info for No Bus:i2c-0 Feb 11 22:28:21 (none) user.debug kernel: PM: Adding info for No Bus:i2c-1 Feb 11 22:28:21 (none) user.debug kernel: PM: Adding info for No Bus:i2c-2 Feb 11 22:28:21 (none) user.debug kernel: PM: Adding info for No Bus:i2c-3 Feb 11 22:28:21 (none) daemon.notice acpid: client connected from 7829[0:1000] Feb 11 22:28:21 (none) daemon.info acpid: 1 client rule loaded Feb 11 22:28:51 (none) auth.info login[7916]: root login on 'pts/0' Feb 11 22:29:13 (none) user.info kernel: PM: Syncing filesystems ... Feb 11 22:29:13 (none) user.info kernel: done. Feb 11 22:29:13 (none) user.debug kernel: PM: Preparing system for mem sleep Feb 11 22:29:36 (none) user.warn kernel: Freezing user space processes ... Feb 11 22:29:36 (none) user.info kernel: cifs_oplock_thread+0x38/0x1eb [cifs] Feb 11 22:29:36 (none) user.warn kernel: [<c011b95b>] complete+0x36/0x44 Feb 11 22:29:36 (none) user.warn kernel: [<f8d16705>] cifs_oplock_thread+0x0/0x1eb [cifs] Feb 11 22:29:36 (none) user.warn kernel: [<c01307c1>] kthread+0x38/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0130789>] kthread+0x0/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0105037>] kernel_thread_helper+0x7/0x10 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: cifsdnotifyd S f64bdf70 0 6064 2 Feb 11 22:29:36 (none) user.warn kernel: fffd367a 00000046 00000002 f64bdf70 f64bdf68 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f77f5a90 f77f5bc0 c17914c0 00000001 f64bdf94 f64bdf94 f7c6a000 000000ff Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 f64bdf94 fffdaba6 00000000 00000000 c02d680b Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c02d680b>] schedule_timeout+0x70/0x8f Feb 11 22:29:36 (none) user.warn kernel: [<c0127fc1>] process_timeout+0x0/0x5 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6806>] schedule_timeout+0x6b/0x8f Feb 11 22:29:36 (none) user.warn kernel: [<f8d16148>] cifs_dnotify_thread+0x0/0x8f [cifs] Feb 11 22:29:36 (none) user.warn kernel: [<f8d161c0>] cifs_dnotify_thread+0x78/0x8f [cifs] Feb 11 22:29:36 (none) user.warn kernel: [<c01307c1>] kthread+0x38/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0130789>] kthread+0x0/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0105037>] kernel_thread_helper+0x7/0x10 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: cifsd D 00000009 0 6070 2 Feb 11 22:29:36 (none) user.warn kernel: 00000023 00000046 f765a000 00000009 f64e5f0c 00011280 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7c86030 f7c86160 c17894c0 00000000 f64e5f30 f64e5f30 c03d6f60 00000286 Feb 11 22:29:36 (none) user.warn kernel: c0128394 00000000 00000286 f64e5f30 fffd51f6 fffffff5 00000023 c02d680b Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c0128394>] __mod_timer+0x9a/0xa4 Feb 11 22:29:36 (none) user.warn kernel: [<c02d680b>] schedule_timeout+0x70/0x8f Feb 11 22:29:36 (none) user.warn kernel: [<c0127fc1>] process_timeout+0x0/0x5 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6806>] schedule_timeout+0x6b/0x8f Feb 11 22:29:36 (none) user.warn kernel: [<c01283ab>] msleep+0xd/0x12 Feb 11 22:29:36 (none) user.warn kernel: [<f8d22532>] cifs_demultiplex_thread+0x21b/0xb1d [cifs] Feb 11 22:29:36 (none) user.warn kernel: [<f8d22317>] cifs_demultiplex_thread+0x0/0xb1d [cifs] Feb 11 22:29:36 (none) user.warn kernel: [<c01307c1>] kthread+0x38/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0130789>] kthread+0x0/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0105037>] kernel_thread_helper+0x7/0x10 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: acpid D f6461f04 0 6148 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000000 f6461f04 c0165d71 00000030 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f75eea90 f75eebc0 c17894c0 00000000 00000001 00000000 00001000 00000000 Feb 11 22:29:36 (none) user.warn kernel: 00000002 00000003 00000001 bfee5b00 00000000 f6461fb8 f6461f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c0165d71>] link_path_walk+0xa9/0xb3 Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c0166030>] do_path_lookup+0x15a/0x175 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c027f126>] sys_send+0x37/0x3b Feb 11 22:29:36 (none) user.warn kernel: [<c027fe0e>] sys_socketcall+0x12d/0x242 Feb 11 22:29:36 (none) user.warn kernel: [<c0168d67>] sys_poll+0x3a/0x6b Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: ntpd D 00000000 0 6200 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000082 00000000 00000000 00000000 f64bfe88 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f75daa90 f75dabc0 c17914c0 00000001 bfeb5058 00000008 7b000002 fe01a8c0 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 00000000 00000000 f64bffb8 f64bff10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c027f0cf>] sys_sendto+0x115/0x135 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0150056>] handle_mm_fault+0x29a/0x58a Feb 11 22:29:36 (none) user.warn kernel: [<c01bf95f>] copy_to_user+0x25/0x3a Feb 11 22:29:36 (none) user.warn kernel: [<c0168f87>] sys_select+0x143/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: webfsd D 00000000 0 6239 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000000 00000000 00000000 04000063 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7078560 f7078690 c17894c0 00000000 00000000 f78364b8 f753a740 00000000 Feb 11 22:29:36 (none) user.warn kernel: c014536a 47b0bdc1 fffffff7 00000000 00000000 f64e7fb8 f64e7f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c014536a>] filemap_fault+0x1fa/0x354 Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0150056>] handle_mm_fault+0x29a/0x58a Feb 11 22:29:36 (none) user.warn kernel: [<c0168ee4>] sys_select+0xa0/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: webfsd D 00000000 0 6242 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000000 00000000 00000000 00000044 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f76d1560 f76d1690 c17894c0 00000000 00000000 f78364b8 f7654140 00000000 Feb 11 22:29:36 (none) user.warn kernel: c014536a 47b0bdc1 00000000 00000000 00000000 f642dfb8 f642df10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c014536a>] filemap_fault+0x1fa/0x354 Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0150056>] handle_mm_fault+0x29a/0x58a Feb 11 22:29:36 (none) user.warn kernel: [<c0168ee4>] sys_select+0xa0/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: lircd D 00000000 0 6917 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000082 00000000 00000000 00000000 c02f7274 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7722030 f7722160 c17894c0 00000000 c02f7274 f7cd572c 00000001 f7cd5728 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000001 00000286 00000000 00000000 f6525fb8 f6525f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c015ca33>] fd_install+0x1b/0x41 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0159567>] shmem_getpage+0x572/0x59a Feb 11 22:29:36 (none) user.warn kernel: [<c02d7844>] _spin_lock_bh+0x8/0x18 Feb 11 22:29:36 (none) user.warn kernel: [<c02807ca>] release_sock+0x12/0x8c Feb 11 22:29:36 (none) user.warn kernel: [<c0281e3f>] sock_setsockopt+0x48b/0x495 Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<c0159dd9>] shmem_file_write+0x28d/0x299 Feb 11 22:29:36 (none) user.warn kernel: [<c0168ee4>] sys_select+0xa0/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c01bf95f>] copy_to_user+0x25/0x3a Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: irexec D 00000000 0 6922 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000082 00000000 00000000 c02f7274 f78f9080 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7721a90 f7721bc0 c17894c0 00000000 00000000 f78364b8 00000000 00000064 Feb 11 22:29:36 (none) user.warn kernel: f78f9080 c0166030 f6401e4c 00000000 00000000 f6401fb8 f6401f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c0166030>] do_path_lookup+0x15a/0x175 Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<c015e7d4>] vfs_read+0x9c/0x110 Feb 11 22:29:36 (none) user.warn kernel: [<c015ebb2>] sys_read+0x41/0x67 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: loop0 S f6473f4c 0 7257 2 Feb 11 22:29:36 (none) user.warn kernel: fffca344 00000046 00000002 f6473f4c f6473f44 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f75af030 f75af160 c17914c0 00000001 f7c501c0 f75b7240 f7c907ec 000000ff Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 f7570110 00000000 f6473fc8 f7570000 f887b40e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<f887b40e>] loop_thread+0xa2/0x3ac [loop] Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<f887b36c>] loop_thread+0x0/0x3ac [loop] Feb 11 22:29:36 (none) user.warn kernel: [<c01307c1>] kthread+0x38/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0130789>] kthread+0x0/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0105037>] kernel_thread_helper+0x7/0x10 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: loop1 S 00000292 0 7401 2 Feb 11 22:29:36 (none) user.warn kernel: f7572e00 00000046 00000001 00000292 c011b9e6 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f76d1a90 f76d1bc0 c17914c0 00000001 f7c501c0 f7c8f580 f7c9046c c014577c Feb 11 22:29:36 (none) user.warn kernel: f7c9046c c0179f35 00000246 f7572f10 00000000 f651bfc8 f7572e00 f887b40e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c011b9e6>] __wake_up+0x32/0x42 Feb 11 22:29:36 (none) user.warn kernel: [<c014577c>] mempool_free+0x6a/0x6f Feb 11 22:29:36 (none) user.warn kernel: [<c0179f35>] end_bio_bh_io_sync+0x0/0x29 Feb 11 22:29:36 (none) user.warn kernel: [<f887b40e>] loop_thread+0xa2/0x3ac [loop] Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<f887b36c>] loop_thread+0x0/0x3ac [loop] Feb 11 22:29:36 (none) user.warn kernel: [<c01307c1>] kthread+0x38/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0130789>] kthread+0x0/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0105037>] kernel_thread_helper+0x7/0x10 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: loop2 S f6447f4c 0 7528 2 Feb 11 22:29:36 (none) user.warn kernel: fffc6652 00000046 00000002 f6447f4c f6447f44 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f77ffa90 f77ffbc0 c17914c0 00000001 f7c501c0 f7c8fc40 f7c9064c 000000ff Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 f7572910 00000000 f6447fc8 f7572800 f887b40e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<f887b40e>] loop_thread+0xa2/0x3ac [loop] Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<f887b36c>] loop_thread+0x0/0x3ac [loop] Feb 11 22:29:36 (none) user.warn kernel: [<c01307c1>] kthread+0x38/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0130789>] kthread+0x0/0x5f Feb 11 22:29:36 (none) user.warn kernel: [<c0105037>] kernel_thread_helper+0x7/0x10 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: xinit D 013cd000 0 7825 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 c17868f0 013cd000 00000000 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7c80030 f7c80160 c17894c0 00000000 00000000 00000000 00000000 00000000 Feb 11 22:29:36 (none) user.warn kernel: 00000002 00000000 00000001 ffffff00 00000000 f6 Feb 11 22:29:36 (none) user.info kernel: 6c9fb8 f66c9f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c01309dc>] remove_wait_queue+0xb/0x2f Feb 11 22:29:36 (none) user.warn kernel: [<c0123274>] do_wait+0x9a8/0xa12 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6695>] wait_for_common+0xbf/0x11a Feb 11 22:29:36 (none) user.warn kernel: [<c011bea8>] default_wake_function+0x0/0x8 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: X D f66cbe94 0 7829 7825 Feb 11 22:29:36 (none) user.warn kernel: fffd34cb 00200086 00000002 f66cbe94 f66cbe8c 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7732a90 f7732bc0 c17914c0 00000001 00000001 00005605 f760a000 000000ff Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 00000100 00000000 f66cbfb8 f66cbf10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c01c4bf7>] pci_user_read_config_word+0x58/0x75 Feb 11 22:29:36 (none) user.warn kernel: [<c01ca098>] pci_read_config+0x154/0x1a1 Feb 11 22:29:36 (none) user.warn kernel: [<c01bf95f>] copy_to_user+0x25/0x3a Feb 11 22:29:36 (none) user.warn kernel: [<c018ea3d>] read+0x130/0x13a Feb 11 22:29:36 (none) user.warn kernel: [<c0168ee4>] sys_select+0xa0/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c0167c46>] vfs_ioctl+0x22b/0x23d Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: xinitrc D 013c5000 0 7857 7825 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 c178e8f0 013c5000 00000000 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f77f4560 f77f4690 c17914c0 00000001 00000000 00000000 00000000 00000000 Feb 11 22:29:36 (none) user.warn kernel: 00000002 00000000 00000001 ffffff00 00000000 e605dfb8 e605df10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c01309dc>] remove_wait_queue+0xb/0x2f Feb 11 22:29:36 (none) user.warn kernel: [<c0123274>] do_wait+0x9a8/0xa12 Feb 11 22:29:36 (none) user.warn kernel: [<c011bea8>] default_wake_function+0x0/0x8 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: x11vnc D 00000000 0 7877 1 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000082 00000000 00000000 00000000 f7ab3680 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f77fe030 f77fe160 c17914c0 00000001 00000000 f78364b8 00000040 00000000 Feb 11 22:29:36 (none) user.warn kernel: 00000001 00000003 00000001 00000000 00000000 e60bdfb8 e60bdf10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<c02c31b8>] unix_ioctl+0x8c/0x95 Feb 11 22:29:36 (none) user.warn kernel: [<c01bf95f>] copy_to_user+0x25/0x3a Feb 11 22:29:36 (none) user.warn kernel: [<c0168f87>] sys_select+0x143/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: ratpoison D 00000000 0 7879 7857 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000000 00000000 00000000 f7aa5240 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7c83030 f7c83160 c17914c0 00000001 00000000 f7880bd4 00000040 00000020 Feb 11 22:29:36 (none) user.warn kernel: f7aa5240 00000003 e60c1e4c 00000000 00000000 e60c1fb8 e60c1f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0137290>] clockevents_program_event+0xed/0xfc Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<c02c31b8>] unix_ioctl+0x8c/0x95 Feb 11 22:29:36 (none) user.warn kernel: [<c0168ee4>] sys_select+0xa0/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c015ebb2>] sys_read+0x41/0x67 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: mythfrontend D 00000000 0 7905 7857 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000000 00000000 00000000 c02f7274 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7c89030 f7c89160 c17914c0 00000001 013cd000 00000000 00000040 00000000 Feb 11 22:29:36 (none) user.warn kernel: 00000001 00000003 00000001 00000000 00000000 e60b9fb8 e60b9f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<c02c31b8>] unix_ioctl+0x8c/0x95 Feb 11 22:29:36 (none) user.warn kernel: [<c01bf95f>] copy_to_user+0x25/0x3a Feb 11 22:29:36 (none) user.warn kernel: [<c0168f87>] sys_select+0x143/0x166 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: mythfrontend D 00000000 0 7908 7857 Feb 11 22:29:36 (none) user.warn kernel: e60c3f10 00000086 00000000 00000000 00000000 00000082 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f77ff560 f77ff690 c17894c0 00000000 b5724000 00000064 e60c3e88 e60c3e88 Feb 11 22:29:36 (none) user.warn kernel: e60c3e90 e60c3e90 00000001 0816cd00 00000000 e60c3fb8 e60c3f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c010906a>] restore_i387+0x75/0xc9 Feb 11 22:29:36 (none) user.warn kernel: [<c0103324>] restore_sigcontext+0x162/0x1b3 Feb 11 22:29:36 (none) user.warn kernel: [<c013abb9>] sys_futex+0xe5/0xf7 Feb 11 22:29:36 (none) user.warn kernel: [<c0103b34>] sys_rt_sigreturn+0xc4/0xe7 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: mythfrontend D 00000000 0 7909 7857 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000000 00000000 c02f7274 ef259080 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f77ff030 f77ff160 c17894c0 00000000 08172000 c01519e7 00000000 00000064 Feb 11 22:29:36 (none) user.warn kernel: ef259080 00000097 e633be4c 00000000 00000000 e633bfb8 e633bf10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c01519e7>] find_extend_vma+0x12/0x49 Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c0137290>] clockevents_program_event+0xed/0xfc Feb 11 22:29:36 (none) user.warn kernel: [<c0130889>] autoremove_wake_function+0x0/0x33 Feb 11 22:29:36 (none) user.warn kernel: [<c0127d19>] run_timer_softirq+0x30/0x1a0 Feb 11 22:29:36 (none) user.warn kernel: [<c0137f8e>] tick_program_event+0x33/0x52 Feb 11 22:29:36 (none) user.warn kernel: [<c012e972>] __rcu_process_callbacks+0x7c/0x14c Feb 11 22:29:36 (none) user.warn kernel: [<c015e7d4>] vfs_read+0x9c/0x110 Feb 11 22:29:36 (none) user.warn kernel: [<c015ebd0>] sys_read+0x5f/0x67 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: mythfrontend D 00000002 0 7914 7857 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000002 00000002 00000800 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7c80560 f7c80690 c17894c0 00000000 00000000 00000000 ffffffff 00000000 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 b3cb7300 00000000 e63cbfb8 e63cbf10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6539>] schedule+0x542/0x578 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c01330c1>] lock_hrtimer_base+0x15/0x2f Feb 11 22:29:36 (none) user.warn kernel: [<c013316e>] hrtimer_try_to_cancel+0x5f/0x67 Feb 11 22:29:36 (none) user.warn kernel: [<c0133180>] hrtimer_cancel+0xa/0x14 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6bcb>] do_nanosleep+0x4f/0x73 Feb 11 22:29:36 (none) user.warn kernel: [<c01332e4>] hrtimer_nanosleep+0x50/0xd5 Feb 11 22:29:36 (none) user.warn kernel: [<c0132d84>] hrtimer_wakeup+0x0/0x18 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6bb9>] do_nanosleep+0x3d/0x73 Feb 11 22:29:36 (none) user.warn kernel: [<c01333b8>] sys_nanosleep+0x4f/0x81 Feb 11 22:29:36 (none) user.warn kernel: [<c012500f>] irq_exit+0x53/0x6b Feb 11 22:29:36 (none) user.warn kernel: [<c0115af0>] smp_apic_timer_interrupt+0x74/0x80 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: mythfrontend D 00000200 0 7915 7857 Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000086 00000200 00000200 00000800 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7c83560 f7c83690 c17894c0 00000000 c17894f4 b857964a 00000005 c17894c0 Feb 11 22:29:36 (none) user.warn kernel: f7c83560 c17894f4 f7c83590 b260f300 00000000 e63a9fb8 e63a9f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6539>] schedule+0x542/0x578 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c01330c1>] lock_hrtimer_base+0x15/0x2f Feb 11 22:29:36 (none) user.warn kernel: [<c013316e>] hrtimer_try_to_cancel+0x5f/0x67 Feb 11 22:29:36 (none) user.warn kernel: [<c0133180>] hrtimer_cancel+0xa/0x14 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6bcb>] do_nanosleep+0x4f/0x73 Feb 11 22:29:36 (none) user.warn kernel: [<c01332e4>] hrtimer_nanosleep+0x50/0xd5 Feb 11 22:29:36 (none) user.warn kernel: [<c0132d84>] hrtimer_wakeup+0x0/0x18 Feb 11 22:29:36 (none) user.warn kernel: [<c02d6bb9>] do_nanosleep+0x3d/0x73 Feb 11 22:29:36 (none) user.warn kernel: [<c01333b8>] sys_nanosleep+0x4f/0x81 Feb 11 22:29:36 (none) user.warn kernel: [<c012500f>] irq_exit+0x53/0x6b Feb 11 22:29:36 (none) user.warn kernel: [<c0115af0>] smp_apic_timer_interrupt+0x74/0x80 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: ash D f6543e94 0 7916 5572 Feb 11 22:29:36 (none) user.warn kernel: fffd34cb 00000086 00000002 f6543e94 f6543e8c 00000000 c03c1d30 c03c44c0 Feb 11 22:29:36 (none) user.warn kernel: f7749030 f7749160 c17914c0 00000001 00000000 00000000 00000000 000000ff Feb 11 22:29:36 (none) user.warn kernel: 00000000 00000000 00000000 ffffff00 00000000 f6543fb8 f6543f10 c013ff6e Feb 11 22:29:36 (none) user.warn kernel: Call Trace: Feb 11 22:29:36 (none) user.warn kernel: [<c013ff6e>] refrigerator+0xb5/0xbf Feb 11 22:29:36 (none) user.warn kernel: [<c012a47d>] get_signal_to_deliver+0x33/0x417 Feb 11 22:29:36 (none) user.warn kernel: [<c01034d5>] do_notify_resume+0x84/0x61f Feb 11 22:29:36 (none) user.warn kernel: [<c01309dc>] remove_wait_queue+0xb/0x2f Feb 11 22:29:36 (none) user.warn kernel: [<c0123274>] do_wait+0x9a8/0xa12 Feb 11 22:29:36 (none) user.warn kernel: [<c011bea8>] default_wake_function+0x0/0x8 Feb 11 22:29:36 (none) user.warn kernel: [<c0103efe>] work_notifysig+0x13/0x25 Feb 11 22:29:36 (none) user.warn kernel: ======================= Feb 11 22:29:36 (none) user.info kernel: echo R running 0 7924 7916 Feb 11 22:29:36 (none) user.err kernel: cifsd Feb 11 22:29:36 (none) user.warn kernel: Feb 11 22:29:36 (none) user.warn kernel: Restarting tasks .. Feb 11 22:29:36 (none) user.info kernel: . done. bugme-daemon@bugzilla.kernel.org wrote: > http://bugzilla.kernel.org/show_bug.cgi?id=9500 > > > > > > ------- Comment #22 from rjw@sisk.pl 2008-02-10 11:04 ------- > (In reply to comment #21) > >> Well, >> >> Key issue is that my testbed is diskless (no storage) system booted via pxe >> from network. >> When, during suspend, kernel hangs - usually I loose access via >> network/console >> - so it is impossible to read content of log files. In such case only >> screen >> is usable to read any messages :-( >> Ideally will be when kernel will print all desired info on screen. Is it >> possible to manage such change in Your patches ? >> > > It should even be possible without them. :-) > > Please boot with "no_console_suspend" in the kernel command line and remember > to echo 7 or 8 to /proc/sys/kernel/printk prior to suspending. > > >> Of course we can consider mods of my system for using storage, but I >> even don't have suitable storage device in my testbed..... >> >> Generally: 2.6.24 has some general issues with s3 on smp architectures. >> > > Well, I test the code on SMP on a regular basis. > > >> Vanilla .24 kernel with maxcpus=1 or without is rather unusable with s3 as >> it hangs quite frequently on resume stage. Adding Your patches improves >> things little bit: no hang on resume but sometimes hang on suspend. >> > > That should be easier to debug with the help of the pm_test thing. Have you > tried to figure out where it hangs? I'd guess it's somewhere in the CPU > hotplug. > > >> In contrast 2.6.23.14 on smp with maxcpus=1 working really well. >> With all core enabled, it predictable hangs on every 3rd resume. >> > > Thanks for the update. > > > Spam detection software, running on the system "murdock.linux-foundation.org", has identified this incoming email as possible spam. The original message has been attached to this so you can view it (if it isn't spam) or label similar future email. If you have any questions, see the administrator of that system for details. Content preview: Rafael, Here is log from unsuccessful suspend (kernel returns to fully operational state): (printk is set to 8, kernel boot params added no_console_suspend) [...] Content analysis details: (7.2 points, 5.0 required) pts rule name description ---- ---------------------- -------------------------------------------------- -1.0 OSDL_HEADER_SUBJECT_BRACKETED Subject starts with []'d phrase 0.6 J_CHICKENPOX_46 BODY: 4alpha-pock-6alpha 0.6 J_CHICKENPOX_65 BODY: 6alpha-pock-5alpha 0.6 J_CHICKENPOX_34 BODY: 3alpha-pock-4alpha 0.6 J_CHICKENPOX_33 BODY: 3alpha-pock-3alpha 0.6 J_CHICKENPOX_66 BODY: 6alpha-pock-6alpha 0.1 TW_CB BODY: Odd Letter Triples with CB 0.1 TW_WR BODY: Odd Letter Triples with WR 0.8 SARE_BAYES_6x8 BODY: Bayes poison 6x8 0.6 J_CHICKENPOX_43 BODY: 4alpha-pock-3alpha 0.6 J_CHICKENPOX_48 BODY: 4alpha-pock-8alpha 0.1 TW_BF BODY: Odd Letter Triples with BF 0.1 TW_BM BODY: Odd Letter Triples with BM 1.0 SARE_BAYES_7x8 BODY: Bayes poison 7x8 0.6 J_CHICKENPOX_44 BODY: 4alpha-pock-4alpha 0.6 J_CHICKENPOX_35 BODY: 3alpha-pock-5alpha 0.8 SARE_BAYES_5x8 BODY: Bayes poison 5x8 0.1 TW_PX BODY: Odd Letter Triples with PX 0.6 J_CHICKENPOX_45 BODY: 4alpha-pock-5alpha 0.1 TW_DF BODY: Odd Letter Triples with DF 1.5 INFO_TLD URI: Contains an URL in the INFO top-level domain -2.3 BAYES_00 BODY: Bayesian spam probability is 0 to 1% [score: 0.0000]
I thought you'd create an attachment. Never mind, though. It looks like cifsd is the process that refuses to freeze. To verify if that's really the case, can you unload cifsd before the suspend and retest?
Rafael, Ok, I was able to modify system to not use cifs. Well - first 2 series of tests (60 & 130 s3 cycles) looks good. Now susupend/resume is predictable & really quick (as quick as in reliable for me 2.6.23 kernel). I will test it further, but only suspend/resume time aspect IMHO is ehough to trigger close look on cifs code and make it more "SMP firendly" (especially in s3 area). Also I will try temporailrly switch solution to NFS - will see how s3 will cope in NFS scenario. BTW: Regarding my non-standard log providing in previous mail: sorry for that. It was hurry :-/ br
Created attachment 14854 [details] Make the cifs multiplexer thread nonfreezable If you can, please also test the configuration containing cifs with the attached patch, which should make it possible to suspend with cifsd running.
Rafael, I made some extensive tests. Sys is based on 2.6.24 + all patches provided by You. I was tested 3 configs, all cores & all HW enabled: 1.patched kernel without any shares 2.above with cifs (patched) shares 3.patched kernel with NFS shares Here are results: 1: I stopped tests on 3 series, every about 200-220 cycles. No hang Suspend/resume time is predictable and constant (in resonable boundaries) 2.Hangs are sometimes after 60 cycles sometimes after 200 cycles. Randomly (every 5-20 cycle) suspend is long (5-10 sec) but sys finally suspends. 3.Hangs on 8-20 cycle and almost always on suspend. Suspend/resume is however quite predictable. Probably it looks like sharing subsystem need more polishing... When I have hang console is black, network is dead so I haven't chance to examine log :-( Adding no_console_suspend couses hang after 3-4 suspend. I try 2.6.25-rc2 but due issues with Nvidia driver module compile I'm not able test .25-rc2 :-( br
Some additional comments: I modify system to automatically unmount all shares before suspend and mount after resume. With cifs, kernel still hangs after avg 100 cycles. Suspend/resume time is short and predictable. With nfs, kernel quite frequently pauses suspend with "freezing userspace processes" for 1-2sec but finally suspends. I made 2 test series - 200 & 250 cycles - so far so good.... br
Rafael, How things are going ? Should I forget 2.6.24 kernel or politely wait for next set of patches ?
Well, I'm afraid the problems you're experiencing are also present in the 2.6.25-rc kernels. Moreover, if my suspicion about the possible cause of these problems is correct, it won't be easy to fix. I'll try to prepare a patch for you to test in the next few days.
Thx for answer. May You give little more light where problems is ?. Maybe we will able to minimize effects as full resolution is impossible/v.difficult is in short-term perspective. After some tests I can summarize: -kernel without usage of network sharing doing s3 well -s3 with mounted shares is problematic -s3 with used but unmounted shares looks good but I still get occasionally hangs Above tells me that even with unmounted shares, kernel still "somehow remembers" state - as I observe decreased s3 stability after using shares. (or maybe it is false conclusion as I had simply luck not to catch yet hang in "no shares used" case) br
Rafael, I'm tracing decreased resume stability probably caused by shared interrupts (I think). Currently, when sys hangs (it hangs only with SMP) - it hangs always with horizontally half rendered mgs on console: pci_express 0000:00:0c.0:pcie00: resuming Do we have possibility to change something within kernel to leave pcie "untouched" (as I don't have any pcie dev in my system) during suspend/resume ? Maybe it will increase stability of s3... br br
(In reply to comment #31) > Thx for answer. > May You give little more light where problems is ?. [Sorry for being late, I have lots of other things to take care of.] I think that the problem is somehow related to the fact that we stopped to send signals to kernel threads in order to freeze them. Apparently, the kernel threads related to the remote disk shares need to be frozen for suspend, because otherwise they cause problems. However, we should send them signals for this purpose, because they behave very much like user space tasks in that respect. When I'm a bit less busy, I'll prepare a patch to test this theory.
(In reply to comment #32) > Rafael, > I'm tracing decreased resume stability probably caused by shared interrupts > (I > think). > Currently, when sys hangs (it hangs only with SMP) - it hangs always with > horizontally half rendered mgs on console: > > pci_express 0000:00:0c.0:pcie00: resuming > > Do we have possibility to change something within kernel to leave pcie > "untouched" (as I don't have any pcie dev in my system) during suspend/resume Are you sure there are no PCIe devices in there? Even any planar ones? Well, I'd try to figure out what device that is (eg. use lspci to identify it) and hack its driver's ->resume() and ->suspend() callbacks (I think I can help you with that a bit).
Rafael, I understand Your question about planar dev following: do I have any on-board device connected to system vie pcie bus. I checked - there is no such one (as my sys is diskless terminal with gf, snd & eth only). For veryfying this, I complied kernel with option_pcieportbus=n. After such compile I haven't any pcie statements in dmsg - so I assume pcie is now fully omitted by kernel. I made it with 2.6.24.2 + yours patches (which AFAIR are for 2.6.24). Unfortunately I still have hangs. But as I experienced much better stability with 2.6.24 than with 2.6.24.2 - next days I will experiment with: 2.6.24 + patches + disabled pcie 2.6.24-rc7 + patches + disabled pcie I know we are catching moving target & rather looking for workaround than for solution - but from functional point of view it make sence for me (as workaround will decrease user frustration by decreasing number of forced system reboots) BTW: is cifs patch applicable also to rc7 ?
Well, it should be. If it doesn't apply, it's probably easy to fix.
Created attachment 15388 [details] Screenshot1 of trap
Created attachment 15389 [details] Screenshot2 of trap
Rafael, As Nvidia finally compiles with .25 kernel we can resume our debugging related to smp s3 stability. Currently I'm testing rc6 on X2 4400. On clean .25-rc6 average sys hangs after 20-30 cycles with trap (see attached screenshots) when I'm using CIFS shares. If I don't touch network - hang was after 200 cycles - but trap info was the same. Can You look on screenshots and try to investigate where is problem ? thx
No idea, sorry. This is looks like a signal delivery that went wrong. A couple of questions, though: (1) Can you decode what's at dequeue_signal+0x85 and at error_code+0x72? (2) Is there any particular reason for using a 32-bit kernel? PS Please don't compress attachments, that makes it difficult to view them. Especially JPGs, as they are compressed already. ;-)
Rafael, After some extensive test I can preliminary report: -adding CIFS patch improves stability. With this patch and NFS I was able to do 8h continues suspend-resume (500 cycles, still testing) without issue. Tests without use of any shares I ended successfully after 11h tests (750 cycles) - no issues. I'm still verifying this theory. -it looks like CIFS is somehow problematic. My previous post (about hang in config without shares) was result of issue where RCA points to CIFS stuff. I observed that if I have resume hang when CIFS is used - it causes whole L2 segment to big slowdown (it is putting my eth switch is strange state where it works v.slow). I have impression that this net state is cause further resume instabilities. When I reset active net devices - NFS or "no share" scenarios shows expected stability as described in above (still verifying this). -In .25-rc6 (also in .24.3) I have issue with analog sound after resume. Simply: there is no analog sound after resume. SPDIF works always OK. With .23.xx kernels all was OK - so it looks like .24.xx/25.xx have regression from 23.xx. in analog sound area. HW is nv7050 (MCP630) and codec Realtek888. I don't know - should I report this issue here (as it is related to s3 stuff) or rather in alsa forums (as it is related to sound stuff). br
Thanks for the update. Your description suggests that the CIFS threads should be frozen for the suspend. Unfortunately, I haven't had the time to prepare a patch for that recently. Please file a separate bug report for the sound issue. Please file it against Drivers->Sound (ALSA) and make it block bug #7216.
Rafael, I'm wonder about Your opinion regarding following issue: Rarely I have problem with system resume to fully operational state. In such case kernel is alive (ping, telnet are usable) but console is only in text mode. Also in such case top reports 50% constant CPU usage by process using graphics mode. Below are kernel last messages for 2 cases: successful resume and unsuccessful resume: Successful one: ....................................... Apr 14 08:26:50 (none) user.debug kernel: PM: Writing back config space on device 0000:01:07.0 at offset 1 (was 2100000, writing 2100006) Apr 14 08:26:50 (none) user.info kernel: ohci1394: fw-host0: OHCI-1394 1.1 (PCI): IRQ=[19] MMIO=[fd0ff000-fd0ff7ff] Max Packet=[2048] IR/IT contexts=[4/8] Apr 14 08:26:50 (none) user.warn kernel: lirc_mceusb2[2]: resume Apr 14 08:26:50 (none) user.warn kernel: Restarting tasks ... Apr 14 08:26:50 (none) user.info kernel: done. Apr 14 08:26:50 (none) user.info kernel: ata1.00: ACPI cmd ef/03:44:00:00:00:a0 filtered out Apr 14 08:26:50 (none) user.info kernel: ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out Apr 14 08:26:50 (none) user.debug kernel: ata1: nv_mode_filter: 0x1f01f&0x1f01f->0x1f01f, BIOS=0x1f000 (0xc5000000) ACPI=0x1f01f (30:600:0x13) Apr 14 08:26:50 (none) user.warn kernel: ACPI: Unable to turn cooling device [f4038edc] 'off' Apr 14 08:26:50 (none) user.info kernel: ata1.00: configured for UDMA/66 Apr 14 08:26:50 (none) daemon.notice acpid: client connected from 9325[0:1000] Apr 14 08:26:50 (none) daemon.info acpid: 1 client rule loaded and when unsucessful resume: .................................... Apr 14 08:27:49 (none) user.debug kernel: PM: Writing back config space on device 0000:01:07.0 at offset 1 (was 2100000, writing 2100006) Apr 14 08:27:49 (none) user.info kernel: ohci1394: fw-host0: OHCI-1394 1.1 (PCI): IRQ=[19] MMIO=[fd0ff000-fd0ff7ff] Max Packet=[2048] IR/IT contexts=[4/8] Apr 14 08:27:49 (none) user.warn kernel: lirc_mceusb2[2]: resume Apr 14 08:27:49 (none) user.warn kernel: Restarting tasks ... Apr 14 08:27:49 (none) user.info kernel: done. Apr 14 08:27:49 (none) user.info kernel: ata1.00: ACPI cmd ef/03:44:00:00:00:a0 filtered out Apr 14 08:27:49 (none) user.info kernel: ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 filtered out Apr 14 08:27:49 (none) user.debug kernel: ata1: nv_mode_filter: 0x1f01f&0x1f01f->0x1f01f, BIOS=0x1f000 (0xc5000000) ACPI=0x1f01f (30:600:0x13) Apr 14 08:27:49 (none) user.warn kernel: ACPI: Unable to turn cooling device [f4038edc] 'off' Apr 14 08:27:49 (none) user.info kernel: ata1.00: configured for UDMA/66 Diference is lacking 2 last lines: Apr 14 08:26:50 (none) daemon.notice acpid: client connected from 9325[0:1000] Apr 14 08:26:50 (none) daemon.info acpid: 1 client rule loaded Is it possible that this issue is related to ACPID ?
Well, I really can't say much about that. Perhaps it's better to open another bug entry for this one in the ACPI category.
Created attachment 15929 [details] Freezer patch This patch changes the freezer so that is uses a new process flag to check which tasks to send signals to in order to freeze them.
Created attachment 15930 [details] Make the CIFS connect thread be sent a signal before freezing To verify the theory described in Comment #33, can you please test the system with CIFS shares and with the patches from Comment #45 and from this comment applied?
Both patches from the previous two comment should apply to 2.6.25. Please let me know if they don't and I'll fix them.
Rafael, Thanx for keeping eye on my issues ! Is it possible to prepare above patches for rc8 kernel ? cifs patch applies OK for rc8, but freezer is failing on one hunk: piotro@debian:~/Desktop/x/linux-2.6.25-rc8$ patch --dry-run --verbose -p1 < freezer-face-lifting.patch.txt Hmm... Looks like a unified diff to me... The text leading up to this was: -------------------------- |From: Rafael J. Wysocki <rjw@sisk.pl> | |The freezer currently attempts to distinguish kernel threads from |user space tasks by checking if their mm pointer is unset and it |does not send fake signals to kernel threads. However, there are |kernel threads, mostly related to networking, that behave like |user space tasks and may want to be sent a fake signal to be frozen. | |Introduce the new process flag PF_FREEZER_NOSIG that will be set |by default for all kernel threads and make the freezer only send |fake signals to the tasks having PF_FREEZER_NOSIG unset. Provide |the set_freezable_with_signal() function to be called by the kernel |threads that want to be sent a fake signal for freezing. | |This patch should not change the freezer's observable behavior. | |Signed-off-by: Rafael J. Wysocki <rjw@sisk.pl> |--- | include/linux/freezer.h | 10 ++++ | include/linux/sched.h | 1 | kernel/kthread.c | 2 | kernel/power/process.c | 97 ++++++++++++++++++++---------------------------- | 4 files changed, 54 insertions(+), 56 deletions(-) | |Index: linux-2.6/include/linux/freezer.h |=================================================================== |--- linux-2.6.orig/include/linux/freezer.h |+++ linux-2.6/include/linux/freezer.h -------------------------- Patching file include/linux/freezer.h using Plan A... Hunk #1 succeeded at 128. Hunk #2 succeeded at 183. Hmm... The next patch looks like a unified diff to me... The text leading up to this was: -------------------------- |Index: linux-2.6/include/linux/sched.h |=================================================================== |--- linux-2.6.orig/include/linux/sched.h |+++ linux-2.6/include/linux/sched.h -------------------------- Patching file include/linux/sched.h using Plan A... Hunk #1 succeeded at 1475 (offset -24 lines). Hmm... The next patch looks like a unified diff to me... The text leading up to this was: -------------------------- |Index: linux-2.6/kernel/power/process.c |=================================================================== |--- linux-2.6.orig/kernel/power/process.c |+++ linux-2.6/kernel/power/process.c -------------------------- Patching file kernel/power/process.c using Plan A... Hunk #1 succeeded at 19. Hunk #2 FAILED at 81. Hunk #3 succeeded at 143. Hunk #4 succeeded at 162. Hunk #5 succeeded at 222. Hunk #6 succeeded at 238. Hunk #7 succeeded at 247. Hunk #8 succeeded at 258. 1 out of 8 hunks FAILED -- saving rejects to file kernel/power/process.c.rej Hmm... The next patch looks like a unified diff to me... The text leading up to this was: -------------------------- |Index: linux-2.6/kernel/kthread.c |=================================================================== |--- linux-2.6.orig/kernel/kthread.c |+++ linux-2.6/kernel/kthread.c -------------------------- Patching file kernel/kthread.c using Plan A... Hunk #1 succeeded at 234. done piotro@debian:~/Desktop/x/linux-2.6.25-rc8$
Well, for me both patches apply to vanilla 2.6.25-rc8 (as well as to 2.6.25, for that matter). In particular, nothing has changed in kernel/power/process.c between 2.6.25-rc8 and the current -git. Please check if you have any other patches applied to your tree.
Hmm, Here is what I'm doing(pls repeat these steeps as I can't find where is error): 1.Download rc8 http://www.eu.kernel.org/pub/linux/kernel/v2.6/testing/linux-2.6.25-rc8.tar.gz 2.Place patches in kernel top dir. 3.Run piotro@debian:~/Desktop/x/linux-2.6.25-rc8$ patch --dry-run --verbose -p1 < freezer-face-lifting.patch 4.Result: piotro@debian:~/Desktop/x/linux-2.6.25-rc8$ patch --dry-run --verbose -p1 < freezer-face-lifting.patch Hmm... Looks like a unified diff to me... The text leading up to this was: -------------------------- |From: Rafael J. Wysocki <rjw@sisk.pl> | |The freezer currently attempts to distinguish kernel threads from |user space tasks by checking if their mm pointer is unset and it |does not send fake signals to kernel threads. However, there are |kernel threads, mostly related to networking, that behave like |user space tasks and may want to be sent a fake signal to be frozen. | |Introduce the new process flag PF_FREEZER_NOSIG that will be set |by default for all kernel threads and make the freezer only send |fake signals to the tasks having PF_FREEZER_NOSIG unset. Provide |the set_freezable_with_signal() function to be called by the kernel |threads that want to be sent a fake signal for freezing. | |This patch should not change the freezer's observable behavior. | |Signed-off-by: Rafael J. Wysocki <rjw@sisk.pl> |--- | include/linux/freezer.h | 10 ++++ | include/linux/sched.h | 1 | kernel/kthread.c | 2 | kernel/power/process.c | 97 ++++++++++++++++++++---------------------------- | 4 files changed, 54 insertions(+), 56 deletions(-) | |Index: linux-2.6/include/linux/freezer.h |=================================================================== |--- linux-2.6.orig/include/linux/freezer.h |+++ linux-2.6/include/linux/freezer.h -------------------------- Patching file include/linux/freezer.h using Plan A... Hunk #1 succeeded at 128. Hunk #2 succeeded at 183. Hmm... The next patch looks like a unified diff to me... The text leading up to this was: -------------------------- |Index: linux-2.6/include/linux/sched.h |=================================================================== |--- linux-2.6.orig/include/linux/sched.h |+++ linux-2.6/include/linux/sched.h -------------------------- Patching file include/linux/sched.h using Plan A... Hunk #1 succeeded at 1475 (offset -24 lines). Hmm... The next patch looks like a unified diff to me... The text leading up to this was: -------------------------- |Index: linux-2.6/kernel/power/process.c |=================================================================== |--- linux-2.6.orig/kernel/power/process.c |+++ linux-2.6/kernel/power/process.c -------------------------- Patching file kernel/power/process.c using Plan A... Hunk #1 succeeded at 19. Hunk #2 FAILED at 81. Hunk #3 succeeded at 143. Hunk #4 succeeded at 162. Hunk #5 succeeded at 222. Hunk #6 succeeded at 238. Hunk #7 succeeded at 247. Hunk #8 succeeded at 258. 1 out of 8 hunks FAILED -- saving rejects to file kernel/power/process.c.rej Hmm... The next patch looks like a unified diff to me... The text leading up to this was: -------------------------- |Index: linux-2.6/kernel/kthread.c |=================================================================== |--- linux-2.6.orig/kernel/kthread.c |+++ linux-2.6/kernel/kthread.c -------------------------- Patching file kernel/kthread.c using Plan A... Hunk #1 succeeded at 234. done piotro@debian:~/Desktop/x/linux-2.6.25-rc8$
Created attachment 15980 [details] Updated freezer patch Well, there was a problem with white space in a comment. Strangely enough, the patch applied cleanly with quilt.
Rafael, I tested little bit rc8 with above patches and I would say: stability is worse and has different sympthoms. After many, many test and quite long period of use different kernels I can sumarize: .25.x GA: generally are quite problematic for me (user space apps hangs, slowdowns, etc). Also s3 is quite unstable (avg. broken resume after 50-200 cycles. If there is issue with s3 it is with X apps; console/network/telnet are usable) .25-rc8, NFS: - best kernel ever for me (no any issues with user space apps). s3 is also quite stable (kernel always resume (1200 cycles tested) with text console/network/telnet. If there is problem - it is with resuming X apps) .25-rc8 + initial CIFS patches + CIFS: like above .25-rc8 + last CIFS patches: s3 quite unstable, but when hangs it hangs with black screen, no telnet, no netowrk. I will try test .26-rc2 (as soon as I resolve unionfs issue...) br BTW: Takashi suggested me that .26 can resolve my sound issues (see bug 10338). As I'm fighting with it since 3 months without results, and screening changelog for .26 is not pointing to any big changes in alsa - I start to doubt for quick resolution :-( As best combination for me is: sound subsystem from in-tree 2.6.23.17 and rest from .25-rc8 + initial cifs path - do You believe it is feasible and worth to combine .25-rc8 and in-tree alsa from 2.6.23.17 ? If so may You help me with such effort ? br
Created attachment 16128 [details] Freezer patch updated 2x Unfortunately the freezer patch from Comment #51 is buggy. Can you please test this one instead along with the patch from Comment #46? If that doesn't help, can you test this patch with the patch from Comment #26 (if that still applies). Re: ALSA: I'm not a driver expert and I know next to nothing about ALSA. I'm afraid I won't be able to help you with the sound problem.
commit ebb12db51f6c13b30752fcf506baad4c617b153c Author: Rafael J. Wysocki <rjw@sisk.pl> Date: Wed Jun 11 22:04:29 2008 +0200 Freezer: Introduce PF_FREEZER_NOSIG shipped in 2.6.27-rc1 closed