CentOS - Apr 2007 - Strange content in the kernel dmesg traces

I am experimenting with the kernel (as some of you may know), and I
have added a whole slew of traces in some relatively sensitive code in
the lower levels of the page cache and i/o functions.  Most of this
tracing not only works but is highly revealing as to what the kernel
is doing and why.

However, I am now getting this odd content in the trace log (dmesg),
and I cannot figure out what it is or why it is there.  If anyone
recognizes this situation, I invite comment and suggestions on how to
eliminate or decipher it:

4296757675 pdflush(80): do_writepages: map>ops>wrtpgs ffffffffa0195ff5
4296757675 pdflush(80): mpage_writepages w/b index 49728 pages 256000
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7>__bio_add_page: 2x ph 88>128 ||
hw 88>88 || 360448>max
ffffffff802525d8 generic_make_request(bio 000001017c745300) 50729472, 704
__make_request(q 00000101b9293870, bio 000001017c745300: sdc; 50729600, 704)
ll_new_hw_segment: 70 + 29 > 88
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
<7><7><7><7>__bio_add_page: 2x ph 88>128 || hw
88>88 || 360448>max
ffffffff802525d8 generic_make_request(bio 000001017c745a80) 50730176, 704
__make_request(q 00000101b9293870, bio 000001017c745a80: sdc; 50730304, 704)
4296757684 swapper(0): dl_mv2dsp: sdc start 50710368 secs 1408

(The lines with the <7>s in them are long - I wrapped them for ease of
reading and to keep the width down somewhat.)

Or should I post this in the lkml?

Thanks.

-- 
Mark Hull-Richter, Linux Kernel Engineer
DATAllegro (www.datallegro.com)
85 Enterprise, Second Floor, Aliso Viejo, CA  92656
949-680-3082 - Office     949-330-7691 - fax

On 4/24/07, Mark Hull-Richter <mhullrich at gmail.com> wrote:
> (The lines with the <7>s in them are long - I wrapped them for ease
of
> reading and to keep the width down somewhat.)
You're the kernel engineer, you tell us what they are.
> Or should I post this in the lkml?
Yes. Or ask the upstream kernel vendor after paying them the
appropriately hefty 'developer support' fee.



-- 
During times of universal deceit, telling the truth becomes a revolutionary act.
George Orwell

Mark Hull-Richter wrote:
> However, I am now getting this odd content in the trace log (dmesg),
> and I cannot figure out what it is or why it is there.  If anyone
> recognizes this situation, I invite comment and suggestions on how to
> eliminate or decipher it:
> 
> 4296757675 pdflush(80): do_writepages: map>ops>wrtpgs
ffffffffa0195ff5
> 4296757675 pdflush(80): mpage_writepages w/b index 49728 pages 256000
>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
>
<7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7><7>
> <7><7><7><7><7>__bio_add_page: 2x ph
88>128 || hw 88>88 || 360448>max
> ffffffff802525d8 generic_make_request(bio 000001017c745300) 50729472, 704
> __make_request(q 00000101b9293870, bio 000001017c745300: sdc; 50729600,
> 704)
I am going to regret answering this, because it is not the right place
for such questions. However...

I suspect you are misusing printk and the KERN_XXX prefixes (KERN_DEBUG,
KERN_ERR, KERN_INFO, etc.) defined in include/linux/kernel.h. Try
dropping the comma between the prefix and the message. That is:

	printk(KERN_INFO "Hello World!\n");

rather than:

	printk(KERN_INFO, "Hello World!\n");

I leave it an exercise for a for the reader to figure out what the
difference is.

Cheers,
Michael