question about pr_info (newbie)

question about pr_info (newbie)

[Kevin Wilson]

Hi,

I have the following very simply kernel module.
The module_init() method has one call to pr_info("Hello world!\n").
However, when I run "insmod helloWorld.ko" I get TWO messages in the
kernel log and not one, as I expected:

..
Dec 29 11:24:40 kv kernel: [67479.245642] Hello world!
Dec 29 11:24:40 kv kernel: Hello world!
...

The same is for "rmmod helloWorld" (TWO messages instead of one)

I built and run this module under kernel 3.17.6-300.fc21.x86_64, Fedora 21.
Any ideas ? Is there some way to configure the kernel to emit only one
message in such a case ?

Following is the code:

static int __init hello_init(void)
{
        pr_info("Hello world!\n");
        return 0;
ded.
}

static void __exit hello_cleanup(void)
        {
        pr_info("Cleaning up module.\n");
        }

module_init(hello_init);
module_exit(hello_cleanup);


Regards,
Kevin

question about pr_info (newbie)

[Valdis.Kletnieks at vt.edu]

On Mon, 29 Dec 2014 11:32:22 +0200, Kevin Wilson said:

> The module_init() method has one call to pr_info("Hello world!\n").
> However, when I run "insmod helloWorld.ko" I get TWO messages in the
> kernel log and not one, as I expected:
>
> ..
> Dec 29 11:24:40 kv kernel: [67479.245642] Hello world!
> Dec 29 11:24:40 kv kernel: Hello world!

Check to make sure you don't have a bug in your syslog.conf causing
it to log the message twice....

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 848 bytes
Desc: not available
Url : http://lists.kernelnewbies.org/pipermail/kernelnewbies/attachments/20141229/90d578fb/attachment.bin 

question about pr_info (newbie)

[Larry Martin]

Hi, Kevin -

This gets me all the time.  I think your system is working correctly.

This is the log entry showing your system call:
> Dec 29 11:24:40 kv kernel: [67479.245642] Hello world!

And this is your actual output:
> Dec 29 11:24:40 kv kernel: Hello world!

If you reduce your log level you will lose the first message but not the 
second.

BR,
Larry

question about pr_info (newbie)

[Kevin Wilson]

Hi,

>If you reduce your log level you will lose the first message but not the
>second.

I would appreciate if somebody can be more specific, how this can be done.
I am using the defaults for syslog, which came with Fedora 21 x86_64.

Regards,
Kevin





On Mon, Dec 29, 2014 at 7:11 PM, Larry Martin <Larry@gluelogix.com> wrote:
> Hi, Kevin -
>
> This gets me all the time.  I think your system is working correctly.
>
> This is the log entry showing your system call:
>> Dec 29 11:24:40 kv kernel: [67479.245642] Hello world!
>
> And this is your actual output:
>> Dec 29 11:24:40 kv kernel: Hello world!
>
> If you reduce your log level you will lose the first message but not the
> second.
>
> BR,
> Larry
>
> _______________________________________________
> Kernelnewbies mailing list
> Kernelnewbies at kernelnewbies.org
> http://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies

question about pr_info (newbie)

[Larry Martin]

>

> I would appreciate if somebody can be more specific, how this can be
> done. I am using the defaults for syslog, which came with Fedora 21
> x86_64.
>

Kevin, I understand your frustration.  I think I used the wrong term.
It's not a "log level" thing, but a "dynamic debug" thing.  Dynamic 
Debug lets you turn on your specific message without seeing all other 
messages of the same "level."  But that means you may have to explicitly 
turn it off.

See:

google://pr_info
http://lwn.net/Articles/487437/
https://lwn.net/Articles/434833/

 From the last link:
> Turning on dynamic debug causes a new virtual file to appear at
> /sys/kernel/debug/dynamic_debug/control (modulo any individual
> preferences for the location of debugfs, naturally). Writing to that
> file will enable or disable specific debugging functions, as
> specified by a simple but flexible language.

> echo file tpm_nsc.c function init_nsc +p > .../dynamic_debug/control

So your incantation would be something like:

echo file myfile.c function init_me -p > mypath/dynamic_debug/control

LWN has a dynamic debug howto.  I assume it's in kernel docs too.

-- 
Larry Martin
www.GlueLogix.com
Design, Test and Support of Computerized Systems
desk USA 919.342.0201
cell USA 919.641.1733