Skip to contentSkip to conversation

[ 11.333737] is this a ghost?

DISCUSSION Justin P. Mattock 2 participants 6 messages Nov 18, 2008 ACPI

lore
Share & tools
lore

Justin P. Mattock

author
#0 lore raw

in dmesg I see:

[   11.333737]  
but nothing else.
          ---------------(cut)-----------------
[   11.247147] Monitor-Mwait will be used to enter C-1 state
[   11.247151] Monitor-Mwait will be used to enter C-2 state
[   11.247154] Monitor-Mwait will be used to enter C-3 state
[   11.247671] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   11.247996] processor ACPI_CPU:00: registered as cooling_device0
[   11.248008] ACPI: Processor [CPU0] (supports 8 throttling states)
[   11.306465] ACPI: SSDT 3FEB8F10, 0087 (r1 APPLE   Cpu1Ist     3000
INTL 20050309)<7>power_supply ADP1: No power supply yet
[   11.306831] power_supply ADP1: power_supply_changed
[   11.306839] ACPI: AC Adapter [ADP1] (on-line)
[   11.333737]                         <------------what's with this!!!
[   11.342937] power_supply ADP1: power_supply_changed_work
[   11.351901] power_supply ADP1: power_supply_update_gen_leds 1
[   11.351916] ACPI: SSDT 3FEB7F10, 0085 (r1 APPLE   Cpu1Cst     3000
INTL 20050309)
[   11.357477] Marking TSC unstable due to TSC halts in idle
[   11.382273] power_supply ADP1: uevent
[   11.392955] power_supply ADP1: POWER_SUPPLY_NAME=ADP1
[   11.403674] power_supply ADP1: Static prop TYPE=Mains
[   11.413736] power_supply ADP1: 1 dynamic props
[   11.424526] power_supply ADP1: prop ONLINE=1
[   11.437151] ACPI: CPU1 (power states: C1[C1] C2[C2] C3[C3])

if you need to see the full dmesg I can attach..
I've seen this happen on a random.

regards;

Signature · 1 line
Justin P. Mattock <[email protected]>
#1 lore raw
Quoted 11 lines · Justin P. Mattock

in dmesg I see:

[   11.333737]
but nothing else.
          ---------------(cut)-----------------
[   11.247147] Monitor-Mwait will be used to enter C-1 state
[   11.247151] Monitor-Mwait will be used to enter C-2 state
[   11.247154] Monitor-Mwait will be used to enter C-3 state
[   11.247671] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   11.247996] processor ACPI_CPU:00: registered as cooling_device0
[   11.248008] ACPI: Processor [CPU0] (supports 8 throttling states)
[   11.306465] ACPI: SSDT 3FEB8F10, 0087 (r1 APPLE   Cpu1Ist     3000
Quoted 1 line

INTL 20050309)<7>power_supply ADP1: No power supply yet

Look at this last line. The "<7>" is a priority marker. Normally it marks the start of a line, and should be hidden. So you seem to be missing a line break just after "20050309)"...

Quoted 3 lines
[   11.306831] power_supply ADP1: power_supply_changed
[   11.306839] ACPI: AC Adapter [ADP1] (on-line)
[   11.333737]                         <------------what's with this!!!

...which seems to be delayed and reappears here?

Quoted 7 lines
[   11.342937] power_supply ADP1: power_supply_changed_work
[   11.351901] power_supply ADP1: power_supply_update_gen_leds 1
[   11.351916] ACPI: SSDT 3FEB7F10, 0085 (r1 APPLE   Cpu1Cst     3000

INTL 20050309)

if you need to see the full dmesg I can attach..
I've seen this happen on a random.

I guess you have a multicore processor (or some other sort of SMP), right?

I think kernel messages are not completely synchronized by design, for reliability reasons. (e.g. to make sure critical error messages / backtraces can get through on a dying system).

author
#2 lore raw
Quoted 29 lines · Alan Jenkins
Quoted 11 lines · Justin P. Mattock

in dmesg I see:

[   11.333737]
but nothing else.
          ---------------(cut)-----------------
[   11.247147] Monitor-Mwait will be used to enter C-1 state
[   11.247151] Monitor-Mwait will be used to enter C-2 state
[   11.247154] Monitor-Mwait will be used to enter C-3 state
[   11.247671] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   11.247996] processor ACPI_CPU:00: registered as cooling_device0
[   11.248008] ACPI: Processor [CPU0] (supports 8 throttling states)
[   11.306465] ACPI: SSDT 3FEB8F10, 0087 (r1 APPLE   Cpu1Ist     3000
Quoted 1 line

INTL 20050309)<7>power_supply ADP1: No power supply yet

Look at this last line. The "<7>" is a priority marker. Normally it marks the start of a line, and should be hidden. So you seem to be missing a line break just after "20050309)"...

Quoted 3 lines
[   11.306831] power_supply ADP1: power_supply_changed
[   11.306839] ACPI: AC Adapter [ADP1] (on-line)
[   11.333737]                         <------------what's with this!!!

...which seems to be delayed and reappears here?

Quoted 4 lines
[   11.342937] power_supply ADP1: power_supply_changed_work
[   11.351901] power_supply ADP1: power_supply_update_gen_leds 1
[   11.351916] ACPI: SSDT 3FEB7F10, 0085 (r1 APPLE   Cpu1Cst     3000

INTL 20050309)

Quoted 8 lines
Quoted 2 lines

if you need to see the full dmesg I can attach..
I've seen this happen on a random.

I guess you have a multicore processor (or some other sort of SMP), right?

I think kernel messages are not completely synchronized by design, for reliability reasons. (e.g. to make sure critical error messages / backtraces can get through on a dying system).

Cool.
makes good sense to me,
As long as it's not something that shouldn't be there, or something that's broken. As for this happening again looking at dmesg nothing, all synchronized. Seems to randomly show itself.

regards;

Signature · 1 line
Justin P. Mattock <[email protected]>
#3 lore raw
Quoted 45 lines · Justin P. Mattock
Quoted 32 lines · Alan Jenkins
Quoted 11 lines · Justin P. Mattock

in dmesg I see:

[   11.333737]
but nothing else.
          ---------------(cut)-----------------
[   11.247147] Monitor-Mwait will be used to enter C-1 state
[   11.247151] Monitor-Mwait will be used to enter C-2 state
[   11.247154] Monitor-Mwait will be used to enter C-3 state
[   11.247671] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   11.247996] processor ACPI_CPU:00: registered as cooling_device0
[   11.248008] ACPI: Processor [CPU0] (supports 8 throttling states)
[   11.306465] ACPI: SSDT 3FEB8F10, 0087 (r1 APPLE   Cpu1Ist     3000
Quoted 2 lines

INTL 20050309)<7>power_supply ADP1: No power supply yet

Look at this last line. The "<7>" is a priority marker. Normally it marks the start of a line, and should be hidden. So you seem to be missing a line break just after "20050309)"...

Quoted 4 lines
[   11.306831] power_supply ADP1: power_supply_changed
[   11.306839] ACPI: AC Adapter [ADP1] (on-line)
[   11.333737]                         <------------what's with this!!!

...which seems to be delayed and reappears here?

Quoted 5 lines
[   11.342937] power_supply ADP1: power_supply_changed_work
[   11.351901] power_supply ADP1: power_supply_update_gen_leds 1
[   11.351916] ACPI: SSDT 3FEB7F10, 0085 (r1 APPLE   Cpu1Cst     3000

INTL 20050309)

Quoted 9 lines
Quoted 3 lines

if you need to see the full dmesg I can attach..
I've seen this happen on a random.

I guess you have a multicore processor (or some other sort of SMP), right?

I think kernel messages are not completely synchronized by design, for reliability reasons. (e.g. to make sure critical error messages / backtraces can get through on a dying system).

Quoted 7 lines

Cool.
makes good sense to me,
As long as it's not something that shouldn't be there, or something that's broken. As for this happening again looking at dmesg nothing, all synchronized. Seems to randomly show itself.

It's the ACPICA OS abstraction layer - it splits every message into multiple printk() calls. Other subsystems don't do this... it probably could and should be fixed.

drivers/acpi/utmisc.c:

    void ACPI_INTERNAL_VAR_XFACE
    acpi_ut_info(const char *module_name, u32 line_number, const char
    *format, ...)
    {
        va_list args;

        /*
         * Removed module_name, line_number, and acpica version, not needed
         * for info output
         */
        acpi_os_printf("ACPI: ");

        va_start(args, format);
        acpi_os_vprintf(format, args);
        acpi_os_printf("\n");
        va_end(args);
    }

The alternative is to use the preprocessor, i.e. macros and string concatenation to generate a single printk().

Alan

author
#4 lore raw
Quoted 78 lines · Alan Jenkins
Quoted 45 lines · Justin P. Mattock
Quoted 32 lines · Alan Jenkins
Quoted 11 lines · Justin P. Mattock

in dmesg I see:

[   11.333737]
but nothing else.
          ---------------(cut)-----------------
[   11.247147] Monitor-Mwait will be used to enter C-1 state
[   11.247151] Monitor-Mwait will be used to enter C-2 state
[   11.247154] Monitor-Mwait will be used to enter C-3 state
[   11.247671] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   11.247996] processor ACPI_CPU:00: registered as cooling_device0
[   11.248008] ACPI: Processor [CPU0] (supports 8 throttling states)
[   11.306465] ACPI: SSDT 3FEB8F10, 0087 (r1 APPLE   Cpu1Ist     3000
Quoted 2 lines

INTL 20050309)<7>power_supply ADP1: No power supply yet

Look at this last line. The "<7>" is a priority marker. Normally it marks the start of a line, and should be hidden. So you seem to be missing a line break just after "20050309)"...

Quoted 4 lines
[   11.306831] power_supply ADP1: power_supply_changed
[   11.306839] ACPI: AC Adapter [ADP1] (on-line)
[   11.333737]                         <------------what's with this!!!

...which seems to be delayed and reappears here?

Quoted 5 lines
[   11.342937] power_supply ADP1: power_supply_changed_work
[   11.351901] power_supply ADP1: power_supply_update_gen_leds 1
[   11.351916] ACPI: SSDT 3FEB7F10, 0085 (r1 APPLE   Cpu1Cst     3000

INTL 20050309)

Quoted 9 lines
Quoted 3 lines

if you need to see the full dmesg I can attach..
I've seen this happen on a random.

I guess you have a multicore processor (or some other sort of SMP), right?

I think kernel messages are not completely synchronized by design, for reliability reasons. (e.g. to make sure critical error messages / backtraces can get through on a dying system).

Quoted 7 lines

Cool.
makes good sense to me,
As long as it's not something that shouldn't be there, or something that's broken. As for this happening again looking at dmesg nothing, all synchronized. Seems to randomly show itself.

It's the ACPICA OS abstraction layer - it splits every message into multiple printk() calls. Other subsystems don't do this... it probably could and should be fixed.

drivers/acpi/utmisc.c:

    void ACPI_INTERNAL_VAR_XFACE
    acpi_ut_info(const char *module_name, u32 line_number, const char
    *format, ...)
    {
        va_list args;

        /*
         * Removed module_name, line_number, and acpica version, not needed
         * for info output
         */
        acpi_os_printf("ACPI: ");

        va_start(args, format);
        acpi_os_vprintf(format, args);
        acpi_os_printf("\n");
        va_end(args);
    }
Quoted 4 lines

The alternative is to use the preprocessor, i.e. macros and string concatenation to generate a single printk().

Alan

Maybe I'm missing a library or something.
The issue with this is the consistency.
one reboot I'll see it up higher in dmesg,
and then on another reboot nothing, then
maybe a few more reboots I'll see it down lower in dmesg(like what I posted). As for fixing this I'm not educated enough to go in and exactly know what to change(one day hopefully, so I can contribute), But I am willing to try a patch out to see if it resolves the issue.

regards;

Signature · 1 line
Justin P. Mattock <[email protected]>
#5 lore raw
Quoted 93 lines · Justin P. Mattock
Quoted 85 lines · Alan Jenkins
Quoted 51 lines · Justin P. Mattock
Quoted 41 lines · Alan Jenkins
Quoted 11 lines · Justin P. Mattock

in dmesg I see:

[   11.333737]
but nothing else.
          ---------------(cut)-----------------
[   11.247147] Monitor-Mwait will be used to enter C-1 state
[   11.247151] Monitor-Mwait will be used to enter C-2 state
[   11.247154] Monitor-Mwait will be used to enter C-3 state
[   11.247671] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   11.247996] processor ACPI_CPU:00: registered as cooling_device0
[   11.248008] ACPI: Processor [CPU0] (supports 8 throttling states)
[   11.306465] ACPI: SSDT 3FEB8F10, 0087 (r1 APPLE   Cpu1Ist     3000
Quoted 3 lines

INTL 20050309)<7>power_supply ADP1: No power supply yet

Look at this last line. The "<7>" is a priority marker. Normally it marks the start of a line, and should be hidden. So you seem to be missing a line break just after "20050309)"...

Quoted 5 lines
[   11.306831] power_supply ADP1: power_supply_changed
[   11.306839] ACPI: AC Adapter [ADP1] (on-line)
[   11.333737]                         <------------what's with this!!!

...which seems to be delayed and reappears here?

Quoted 9 lines
[   11.342937] power_supply ADP1: power_supply_changed_work
[   11.351901] power_supply ADP1: power_supply_update_gen_leds 1
[   11.351916] ACPI: SSDT 3FEB7F10, 0085 (r1 APPLE   Cpu1Cst     3000

INTL 20050309)

if you need to see the full dmesg I can attach..
I've seen this happen on a random.

Quoted 7 lines

I guess you have a multicore processor (or some other sort of SMP), right?

I think kernel messages are not completely synchronized by design, for reliability reasons. (e.g. to make sure critical error messages / backtraces can get through on a dying system).

Quoted 8 lines

Cool.
makes good sense to me,
As long as it's not something that shouldn't be there, or something that's broken. As for this happening again looking at dmesg nothing, all synchronized. Seems to randomly show itself.

It's the ACPICA OS abstraction layer - it splits every message into multiple printk() calls. Other subsystems don't do this... it probably could and should be fixed.

drivers/acpi/utmisc.c:

    void ACPI_INTERNAL_VAR_XFACE
    acpi_ut_info(const char *module_name, u32 line_number, const char
    *format, ...)
    {
        va_list args;

        /*
         * Removed module_name, line_number, and acpica version, not needed
         * for info output
         */
        acpi_os_printf("ACPI: ");

        va_start(args, format);
        acpi_os_vprintf(format, args);
        acpi_os_printf("\n");
        va_end(args);
    }
Quoted 5 lines

The alternative is to use the preprocessor, i.e. macros and string concatenation to generate a single printk().

Alan

Quoted 11 lines

Maybe I'm missing a library or something.
The issue with this is the consistency.
one reboot I'll see it up higher in dmesg,
and then on another reboot nothing, then
maybe a few more reboots I'll see it down lower in dmesg(like what I posted). As for fixing this I'm not educated enough to go in and exactly know what to change(one day hopefully, so I can contribute), But I am willing to try a patch out to see if it resolves the issue.

Right. It's simple enough, I can write a patch. Not sure what would be most acceptable though.

Len, this sounds like a genuine bug. Would you accept a patch changing ACPI_INFO(()) etc. to use GNU-style variadic macros?

Thanks
Alan