Description of problem: This is a duplicate of kernel.org bug <a href="http://bugzilla.kernel.org/show_bug.cgi?id=11516"> 11516 </a>, as it not only happens with these upstream kernel 2.6.27-rc5 trees : git://git.kernel.org/pub/scm/linux/kernel/git/arjan/linux-2.6-hrtimer.git git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux-2.6.git but also with your latest 2.6.27-0.312.rc5.git7.fc10.x86_64 release. Upgrading with yum from 2.6.26-0.115.rc9.git2.fc10 to 2.6.27-0.305.rc5.git6.fc10 (and now also 2.6.27-0.312.rc5.git7.fc10) resulted in SEVERE performance degradation - it made my AMD TL-64 dual-core 2.2Ghz laptop perform like my first i286 with 512K RAM machine . The boot-up sequence, from boot to displaying the X-Windows login prompt, went from taking <1 minute to over 15 minutes. Just thought I should let you know - please see full details at: http://bugzilla.kernel.org/show_bug.cgi?id=11516 Version-Release number of selected component (if applicable): 2.6.27-0.312.rc5.git7.fc10, 2.6.26-0.115.rc9.git2.fc10 How reproducible: 100% Steps to Reproduce: Upgrade with yum / pup to latest rawhide kernel Actual results: system is hosed - @ 1500% performance degradation. Expected results: system should perform as well as or better than with previous releases Additional info: Logs, details at: http://bugzilla.kernel.org/show_bug.cgi?id=11516
Does anyone actually maintain the Fedora RawHide / Development kernels, or are they just there for show ? This is still happening with latest 2.6.27 based kernels. I've tried latest linux-2.6-tip and linux-2.6-acpi git kernels, and combining their diffs with Linus' latest linux-2.6 tree, and tried your latest 2.6.27-0.352.rc7.git1.fc10.x86_64 kernel, with udev-{124,126,128} versions, with the same results : CPU RUNS AT LOWEST FREQUENCY AND CPU FREQUENCY SWITCHING IS COMPLETELY DISABLED My CPU runs at 2.2GHz under the 2.6.26 kernels, but at 800KHz under the 2.6.27 kernels, both upstream and Fedora, compiled with either gcc-4.2.4 or gcc-4.3.2 or gcc-3.4.6, under either my own (initially Gentoo based) distro or under Fedora Core 10 Rawhide distro , with very similar configs, and all get the same results. The powernow-k8 driver and all governor modules load without complaint, and do not produce any messages when valid configuration commands are issued: $ echo 2200000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq $ echo 2200000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed $ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq 800000 PS: why can't powernow-k8 be auto-loaded by udev ? I'm sure it used to be ... The above command sequence prints "2200000" at the end under 2.6.26 kernels. I've tried completely disabling USB and ACPI, with the same result. I've attached the System.map, config, and boot.log from the occurence of this bug, and what I said about 2.6.27-6 still holds for 2.6.27-7 . Re: [Bug #11516] severe performance degradation on x86_64 going from 2.6.26-rc9 -> 2.6.27-rc5 From: Jason Vas Dias <jason.vas.dias> To: "Rafael J. Wysocki" <rjw>, Andrew Morton <akpm> CC: Linux Kernel Mailing List <linux-kernel.org>, Kernel Testers List <kernel-testers.org> Date: Tuesday 05:49:28 Hi - Yes, this bug is still a problem with both the latest 2.6.27-rc6 kernel (from Linus' tree 2008-09-21) and with the latest fedora 10 kernel . CPU Frequency switching is completely disabled both when powernow-k8 (the correct cpufreq module for my x86_64 AMD TL-64x2 2.2GHz CPU) is installed as a module or is built-in , and the CPU frequency remains at its lowest setting; attempts to modify /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq and /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed are not honored, even though /sys/devices/system/cpu/cpu0/cpufreq/governor is "userspace" and scaling_min_freq < scaling_setspeed > scaling_max_freq . I see no messages from powernow-k8 indicating that it is aware it was unable to set the speed, though I do see a message if I attempt to set an invalid speed (eg 600000) . With 2.6.26-rc9, I get a default CPU clock frequency of 2200000 ; with 2.6.27-rc6, it becomes 800000 and is not switchable. For some reason, powernow-k8 does not autoload with UDEV; but I don't really need it if the speed is already set to its highest level. On 2.6.27-rc6. after it manages to boot, any low-latency drivers time out (eg. USB, Terminal, Keyboard, Network) and the machine does not get through the boot-up sequence without becoming overloaded by the kernel's debugging log messages - neither the network , the terminal or the keyboard work usably. Building a kernel with USB completely disabled and turning off debug log messages allows the machine to boot (after @ 15 minutes) but the speed is still at its lowest setting and cannot be changed. Also, 2.6.27-rc6 is unable to reboot the machine: it can put the machine into the "HALT" state, with nothing displayed on the screen, but the machine does not power-off until manual reset with the power-button. Then, after the machine has powered-down, it cannot be powered up until the power-on button is depressed for at least two sections an released TWICE in a row. Neither booting with 'acpi=0' or compilation without USB support has any effect; it happens the same with a totally standard Fedora 10 install with the latest 2.6.27 kernel as with my own heavily customized distro , and occurs when either udev-{124,126,128} are installed, and regardless of compiling the kernel with gcc-4.2.4 , gcc-3.4.6, or gcc-4.3.2 . Any help / suggestions would be greatly appreciated ! I've attached the Config, System.map and boot.log (compressed) . Regards, Jason
Created attachment 317755 [details] kernel config for the 2.6.27-rc7.jvd version
Created attachment 317756 [details] System.map for the 2.6.27-7.rc7.jvd.bz2 version
Created attachment 317757 [details] boot log from boot, which took @15 minutes to display a login: prompt
booting with cpufreq.debug=7 should give some clues as to why it's picking the slow speed by default. Attach the dmesg log from that. (please don't bzip them either, as that makes them unviewable in the browser).
Created attachment 317890 [details] dmesg boot output from 2.6.27-tip-rc7.jvd
Hi Dave - thanks! I did as you suggested and booted with cpufreq.debug=7 . I've attached the log. Here is a "typescript" log of attempting to set the frequency and dmesg output after each action, running the latest 2.6.27-rc7-tip tree ( http://git.kernel.org/?p=linux/kernel/git/x86/linux-2.6-tip.git;a=commit;h=c4077bb0691bcd26c546daa52b76a47ba954fc49 ) : <![CDATA[ Script started on Sun Sep 28 03:33:44 2008 $ for f in /sys/devices/system/cpu/cpu0/cpufreq/*; do echo '+++ '$f:; cat $f; echo '---'; donedevices/system/cpu/cpu0/cpufreq/* +++ /sys/devices/system/cpu/cpu0/cpufreq/affected_cpus: 0 1 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_cur_freq: 800000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_max_freq: 2200000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/cpuinfo_min_freq: 800000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/related_cpus: 0 1 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies: 2200000 2000000 1800000 1600000 800000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_governors: ondemand powersave userspace performance --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq: 800000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_driver: powernow-k8 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor: userspace --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq: 880000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq: 800000 --- +++ /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed: 800000 --- $ dmesg -c > dev/null $ echo 2200000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq $ echo 2200000 > /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed $ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq; cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed 880000 800000 root@jvdspc:/home/jason/2.6.27-tip-rc7.jvd$ dmesg # ( @ 100 USB messages : [ 2557.957726] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.206950] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.208051] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.456366] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.457971] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.706019] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.707028] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.955902] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2558.956201] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2559.205958] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 # ... [ 2611.636188] APIC error on CPU1: 40(40) [ 2611.636354] APIC error on CPU0: 40(40) # ... [ 2618.206172] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2618.207182] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2618.455341] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2618.455341] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2618.707874] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0000 [ 2618.708174] hub 3-0:1.0: state 7 ports 2 chg 0000 evt 0000 # ... ) [ 2618.755459] cpufreq-core: setting new policy for CPU 0: 800000 - 2200000 kHz [ 2618.755727] freq-table: request for verification of policy (800000 - 2200000 kHz) for cpu 0 [ 2618.755959] freq-table: verification lead to (800000 - 2200000 kHz) for cpu 0 [ 2618.756966] freq-table: request for verification of policy (800000 - 880000 kHz) for cpu 0 [ 2618.757433] freq-table: verification lead to (800000 - 880000 kHz) for cpu 0 [ 2618.757667] cpufreq-core: new min and max freqs are 800000 - 880000 kHz [ 2618.757866] cpufreq-core: governor: change or update limits [ 2618.758300] cpufreq-core: __cpufreq_governor for CPU 0, event 3 [ 2618.758500] userspace: limit event for cpu 0: 800000 - 880000 kHz, currently 800000 kHz, last set to 2200000 kHz [ 2618.758767] cpufreq-core: target for CPU 0: 880000 kHz, relation 1 [ 2618.759296] powernow-k8: targ: cpu 0, 880000 kHz, min 800000, max 880000, relation 1 [ 2618.759496] powernow-k8: targ: curr fid 0x0, vid 0x1e [ 2618.759666] freq-table: request for target 880000 kHz (relation: 1) for cpu 0 [ 2618.759863] freq-table: target is 4 (800000 kHz, 7680) [ 2618.760327] powernow-k8: cpu 0 transition to index 4 [ 2618.760497] powernow-k8: table matched fid 0x0, giving vid 0x1e [ 2618.760662] powernow-k8: target matches current values (fid 0x0, vid 0x1e) [ 2643.387590] userspace: cpufreq_set for cpu 0, freq 2200000 kHz [ 2643.387856] cpufreq-core: target for CPU 0: 880000 kHz, relation 0 [ 2643.388891] powernow-k8: targ: cpu 0, 880000 kHz, min 800000, max 880000, relation 0 [ 2643.389328] powernow-k8: targ: curr fid 0x0, vid 0x1e [ 2643.389527] freq-table: request for target 880000 kHz (relation: 0) for cpu 0 [ 2643.389759] freq-table: target is 4 (800000 kHz, 7680) [ 2643.390364] powernow-k8: cpu 0 transition to index 4 [ 2643.390561] powernow-k8: table matched fid 0x0, giving vid 0x1e [ 2643.390826] powernow-k8: target matches current values (fid 0x0, vid 0x1e) $ dmesg -c > /dev/null ; $ cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq /sys/devices/system/cpu/cpu0/cpufreq/scaling_setspeed 880000 800000 $ exit Script done on Sun Sep 28 03:49:44 2008 ]]> Sorry about the bzips - bugzilla wouldn't accept one of the files because it was too large, so I bzip'ed them all. BTW, I would have gathered logs from latest Fedora 10 Rawhide, kernel 2.6.27-0.352.rc7.git1.fc10, which has the same problem, but the new Fedora boot-up sequence makes it impossible . With the boot args: 'kernel /boot/vmlinuz-2.6.27-0.352.rc7.git1.fc10.x86_64 root=/dev/sda10 enforcing=0 audit=0 smack=0 debug debug.cpufreq=7 rhgb=0 netconsole=6666.58.230/eth0,666 6.58.227/ vga=0x356 1 ' In vesa mode, when the new / modifed "PCI Radeon Express" driver is loaded, a "blank white screen of death" is displayed, VT switching is disabled , and seemingly the "rc" script is never run, because my "dmesg > /var/log/boot.dmesg.log" that I added to it is never executed. In VGA mode, I can see the boot-up initially for a few seconds, but then the boot argument "rhgb=0" is ignored, and X is started up; the silly "Fedora" splash screen was displayed for over an hour without a gdm or terminal login appearing - VT switching was again disabled, and my "dmesg" commands in the rc scripts were never run , so no logs could be gathered from the Fedora kernel. Also, netconsole seems to be disabled, or the boot argument 'netconsole=6666.58.230/eth0,6666.58.227/' is ignored - or perhaps it didn't get to initializing eth0 within the hour it had . The last Fedora kernel I was able to run was 2.6.27-0.323.rc6.fc10, which had the same crawling 0.8Ghz speed and frequency switch problems . I guess I'll have to remove 'rhgb*.rpm' and try again . I'm looking at hacking around the cpufreq code with crash(1) to see if I can figure out what the issue is . It seems to be that this log sequence shows several issues : [ 2643.387590] userspace: cpufreq_set for cpu 0, freq 2200000 kHz no, it wasn't ! this message suggests the frequency was set to 2200000 kHz, when it was not. [ 2643.387856] cpufreq-core: target for CPU 0: 880000 kHz, relation 0 Now it seems to be confused - wasn't it trying to set the freq to 2200000 kHz ? [ 2643.388891] powernow-k8: targ: cpu 0, 880000 kHz, min 800000, max 880000, relation 0 [ 2643.389328] powernow-k8: targ: curr fid 0x0, vid 0x1e [ 2643.389527] freq-table: request for target 880000 kHz (relation: 0) for cpu 0 No, the request was for 2200000 kHz !! It seems to me that cpufreq should not require a special debug.cpufreq setting to inform the user that their request for a new frequency A) failed to be set B) was set successfully IMHO, a dmesg should be emitted unconditionally on debug level in either case. I think this whole issue and the USB message flood are all due to the kernel being completely confused about its timing parameters, owing to ACPI not being set up correctly. I've attached a dump of all ACPI info, more @ the kernel.org bug report: http://bugzilla.kernel.org/show_bug.cgi?id=11516 .
Created attachment 317893 [details] all acpi info Output of command: $ (find /proc/acpi -type f | while read f; do if [[ "$f" != /proc/acpi/event ]]; then echo '+++ '$f':'; if [[ $f =~ dt$ ]]; then od -cx $f; else cat $f; echo '---'; fi; fi; done) 2>&1
Jason, it appears this is fixed after looking at the upstream kernel bug tracker. Can you confirm this so we can close this Jason?
Bug is fixed upstream.