Re: Linux 3.4 dom0 kernel error loading xen-acpi-processor: Input/output error

[Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>]

On Sun, Mar 03, 2013 at 08:53:47PM +0200, Pasi Kärkkäinen wrote:
> On Mon, Feb 25, 2013 at 12:05:24AM +0200, Pasi Kärkkäinen wrote:
> > On Thu, Feb 21, 2013 at 07:29:13AM -0500, Konrad Rzeszutek Wilk wrote:
> > > On Thu, Feb 21, 2013 at 11:24:34AM +0200, Pasi Kärkkäinen wrote:
> > > > Hello,
> > > > 
> > > > Does anyone know why loading xen-acpi-processor driver fails like this?:
> > > > 
> > > > # modprobe xen-acpi-processor
> > > > FATAL: Error inserting xen_acpi_processor (/lib/modules/3.4.32-6.el6.centos.alt.x86_64/kernel/drivers/xen/xen-acpi-processor.ko): Input/output error
> > > > 
> > > > Using "modprobe -v" doesn't provide any more information about the problem.
> > > > Also there's nothing in dom0 kernel dmesg.
> > > > 
> > > > Hardware is Dell R510 server with Intel Xeon 5600 series CPU. 
> > > > Xen 4.2.1.
> > > > 
> > > > Kernel is based on 3.4.32 (so the upstream kernel.org longterm stable version) 
> > > > with some additional Xen patches backported from later upstream kernels. 
> > > > Any tips how to troubleshoot this? 
> > > 
> > > Rebuild the module and add this
> > > diff --git a/drivers/xen/xen-acpi-processor.c b/drivers/xen/xen-acpi-processor.c
> > > index 316df65..5d824a2 100644
> > > --- a/drivers/xen/xen-acpi-processor.c
> > > +++ b/drivers/xen/xen-acpi-processor.c
> > > @@ -16,6 +16,7 @@
> > >   * more details.
> > >   *
> > >   */
> > > +#define DEBUG 1
> > >  
> > >  #include <linux/cpumask.h>
> > >  #include <linux/cpufreq.h>
> > > 
> > > 
> > > That should help in figuring it out.
> > > 
> > 
> > This is what I get with DEBUG enabled:
> > 
> > # modprobe -v xen-acpi-processor
> > insmod /lib/modules/3.4.32-6.dbg1.el6.x86_64/kernel/drivers/xen/xen-acpi-processor.ko
> > FATAL: Error inserting xen_acpi_processor (/lib/modules/3.4.32-6.dbg1.el6.x86_64/kernel/drivers/xen/xen-acpi-processor.ko): Input/output error
> > 
> > in dom0 kernel dmesg:
> > xen-acpi-processor: Max ACPI ID: 24
> > 
> > .. and that's all.
> > 
> > Adding more debug options on the kernel cmdline I see this:
> > initcall xen_acpi_processor_init+0x0/0x6b0 [xen_acpi_processor] returned -5 after 67 usecs
> > initcall xen_acpi_processor_init+0x0/0x6b0 [xen_acpi_processor] returned with error code -5
> > 
> > And enabling some ACPI debug options:
> > processor_perflib-0430 [00] processor_get_performa: ACPI-based processor performance control unavailable
> > 
> > 
> > I added a bunch of more calls to pr_debug() in xen_acpi_processor_init() and it seems:
> > 
> >         /* Do initialization in ACPI core. It is OK to fail here. */
> >         (void)acpi_processor_preregister_performance(acpi_perf_data);
> > 
> >         for_each_possible_cpu(i) {
> >                 struct acpi_processor_performance *perf;
> > 
> >                 perf = per_cpu_ptr(acpi_perf_data, i);
> >                 rc = acpi_processor_register_performance(perf, i);
> >                 if (rc)
> >                         goto err_out;
> >         }
> > 
> > "goto err_out" is the path taken from here..
> > It seems acpi_processor_register_performance() returns -EIO.
> > 
> > .. which means in acpi_processor_register_performance()
> > 
> >         if (acpi_processor_get_performance_info(pr)) {
> >                 pr->performance = NULL;
> >                 mutex_unlock(&performance_mutex);
> >                 return -EIO;
> >         }
> > 
> > 
> > It seems acpi_processor_get_performance_info() returns -ENODEV:
> > 
> >         if (ACPI_FAILURE(status)) {
> >                 ACPI_DEBUG_PRINT((ACPI_DB_INFO,
> >                                   "ACPI-based processor performance control unavailable\n"));
> >                 return -ENODEV;
> >         }
> > 
> > 
> > Does this ring any bells? 
> > 
> 
> so in acpi_processor_get_performance_info():
> 
> status = acpi_get_handle(pr->handle, "_PCT", &handle);
> if (ACPI_FAILURE(status)) {
> 	ACPI_DEBUG_PRINT((ACPI_DB_INFO,
> 			  "ACPI-based processor performance control unavailable\n"));
> 	return -ENODEV;
> }
> 
> This is the issue I'm hitting. 
> acpi_get_handle() returns an error so -ENODEV is returned from acpi_processor_get_performance_info().
> 
> Debugging acpi_get_handle() reveals the pathname[] ("_PCT") passed isn't valid for some reason,
> so acpi_ns_valid_root_prefix(pathname[0]) returns false, and a bunch of code is skipped in acpi_get_handle().
> 
> Later in acpi_get_handle(): status = acpi_ns_get_node() shows this in dmesg:
> 
>  nsutils-0363 [82933056] [00] ns_build_internal_name: Returning [ffff8800040f6240] (rel) "_PCT"
>  utmutex-0261 [82933056] [00] ut_acquire_mutex      : Thread 82933056 attempting to acquire Mutex [ACPI_MTX_Namespace]
>      osl-1058 [82933056] [00] os_wait_semaphore     : Waiting for semaphore[ffff880039c01aa0|1|65535]
>      osl-1077 [82933056] [00] os_wait_semaphore     : Acquired semaphore[ffff880039c01aa0|1|65535] utmutex-0269 [82933056] [00] ut_acquire_mutex      : Thread 82933056 acquired Mutex [ACPI_MTX_Namespace]
> nsaccess-0398 [82933056] [00] ns_lookup             : Searching relative to prefix scope [CPU1] (ffff880039699240)
> nsaccess-0510 [82933056] [00] ns_lookup             : Simple Pathname (1 segment, Flags=2)
>   nsdump-0087 [82933056] [00] ns_print_pathname     : [_PCT]
> nssearch-0114 [82933056] [00] ns_search_one_scope   : Searching \_PR_.CPU1 (ffff880039699240) For [_PCT] (Untyped)
> nssearch-0168 [82933056] [00] ns_search_one_scope   : Name [_PCT] (Untyped) not found in search in scope [CPU1] ffff880039699240 first child ffff8800396a4e48
> nssearch-0379 [82933056] [00] ns_search_and_enter   : _PCT Not found in ffff880039699240 [Not adding]
> nsaccess-0571 [82933056] [00] ns_lookup             : Name [_PCT] not found in scope [CPU1] ffff880039699240
>  nsutils-0743 [82933056] [00] ns_get_node           : _PCT, AE_NOT_FOUND
>  utmutex-0300 [82933056] [00] ut_release_mutex      : Thread 82933056 releasing Mutex [ACPI_MTX_Namespace]
>      osl-1097 [82933056] [00] os_signal_semaphore   : Signaling semaphore[ffff880039c01aa0|1]
> 
> 
> .. and thus ACPI_SUCCESS(status) is false. _PCT was not found.
> Any ideas why the Performance Control stuff can't be found? 


No, but I usually do one more thing to check my assumptions. I extract
the SSDT and DSDT:

cat /sys/firmware/acpi/DSDT > /tmp/dsdt

iasl -d /tmp/dsdt
and search for the _PCT to make sure they are actually there.


Independetly of this I was looking at seeing why on v3.9-rc1 it would not work, and
found out that this patch:

d5aaffa9dd531c978c6f3fea06a2972653bd7fc8
Author: Dirk Brandewie <dirk.j.brandewie@intel.com>
Date:   Thu Jan 17 16:22:21 2013 +0000

    cpufreq: handle cpufreq being disabled for all exported function.

makes acpi_processor_register_performance return -22. Which is b/c


824         if (!(acpi_processor_ppc_status & PPC_REGISTERED)) {

and that is b/c:

227 void acpi_processor_ppc_init(void)
228 {
229         if (!cpufreq_register_notifier
230             (&acpi_ppc_notifier_block, CPUFREQ_POLICY_NOTIFIER))
231                 acpi_processor_ppc_status |= PPC_REGISTERED;
232         else
233                 printk(KERN_DEBUG
234                        "Warning: Processor Platform Limit not supported.\n");
235 }

'cpufreq_register_notifier' fails and acpi_processor_ppc_status is not set
to PPC_REGISTERED. 


> 
> Thanks,
> 
> -- Pasi
> 
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xen.org
> http://lists.xen.org/xen-devel
>