Re: [RFC][PATCH] module: Limit line length of module prints

From: Laura Abbott
Date: Tue Dec 15 2015 - 17:47:52 EST


On 12/13/2015 05:06 PM, Rusty Russell wrote:
Laura Abbott <labbott@xxxxxxxxxx> writes:
On 12/11/2015 01:39 AM, Rusty Russell wrote:
Laura Abbott <labbott@xxxxxxxxxxxxxxxxx> writes:
print_modules currently uses pr_cont to print all module information.
This has the side effect of printing lots of modules on one very long
line. This makes copy/pasting oopses more effort if manual wrapping is
required. Place a reasonable limit (80 chars) on the number of modules
on each line.

Signed-off-by: Laura Abbott <labbott@xxxxxxxxxxxxxxxxx>
---
Does this bother anyone else or am I the only one who hates dealing
with the long lines of "Modules linked in"?

Never bothered me, but I'm a bit odd :) I worry more about the effect
on machine parsing.


Yes, that was a concern I had as well, but the module list seems to get
wrapped eventually (although at a much longer length) so it seems like
if machine parsing can handle one wrap it can handle multiple wraps.

Does it? I find that code very hard to parse, but seems like something
happens at 1024 chars.

But my testing here doesn't show any such break in dmesg, nor on serial
console.

diff --git a/kernel/module.c b/kernel/module.c
index 912e891e0e2f..f882d9d99844 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -3925,6 +3925,12 @@ static const struct file_operations proc_modules_operations = {

static int __init proc_modules_init(void)
{
+ int x;
+ printk("Test of long line:");
+ for (x = 0; x < 1024; x++)
+ pr_cont("%c%c", (x % 26) + 'A', (x % 26) + 'A');
+ pr_cont("\n");
+
proc_create("modules", 0, NULL, &proc_modules_operations);
return 0;
}

Confused,
Rusty.


So this is what I see from an example warning:

[ 51.432399] ------------[ cut here ]------------
[ 51.432406] WARNING: CPU: 2 PID: 77 at block/genhd.c:626 add_disk+0x480/0x4e0()
[ 51.432407] Modules linked in: uas usb_storage scsi_dh_alua rfcomm
fuse cmac ccm xt_CHECKSUM ipt_MASQUERADE nf_nat_masquerade_ipv4 tun
nf_conntrack_netbios_ns nf_conntrack_broadcast ip6t_rpfilter
ip6t_REJECT nf_reject_ipv6 xt_conntrack ebtable_filter ebtable_nat
ebtable_broute bridge stp llc ebtables ip6table_mangle ip6table_nat
nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6 ip6table_raw
ip6table_security ip6table_filter ip6_tables iptable_mangle iptable_nat
nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack
iptable_raw iptable_security bnep intel_rapl iTCO_wdt
iTCO_vendor_support iosf_mbi x86_pkg_temp_thermal coretemp kvm_intel
kvm irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel arc4 uvcvideo
iwlmvm videobuf2_vmalloc videobuf2_v4l2 btusb videobuf2_core mac80211
btrtl videobuf2_memops
[ 51.432460] v4l2_common joydev btbcm videodev btintel iwlwifi
snd_hda_codec_realtek media bluetooth cfg80211 snd_hda_codec_generic
snd_hda_codec_hdmi lpc_ich intel_pch_thermal i2c_i801 shpchp
snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep wmi snd_seq
thinkpad_acpi snd_seq_device rfkill snd_pcm mei_me snd_timer snd
soundcore mei tpm_tis tpm nfsd auth_rpcgss nfs_acl lockd grace sunrpc
i915 i2c_algo_bit drm_kms_helper serio_raw e1000e drm ptp pps_core
video fjes
[ 51.432501] CPU: 2 PID: 77 Comm: kworker/u16:1 Tainted: G W 4.4.0-0.rc4.git2.1.fc24.x86_64 #1
[ 51.432503] Hardware name: LENOVO 20BTS1N700/20BTS1N700, BIOS N14ET28W (1.06 ) 03/12/2015
[ 51.432507] Workqueue: events_unbound async_run_entry_fn
[ 51.432509] 0000000000000000 000000002902d154 ffff88021f893c38 ffffffff81427dc9
[ 51.432513] 0000000000000000 ffff88021f893c70 ffffffff810add82 ffff880203baa000
[ 51.432517] ffff880203baa0b0 ffff880203baa00c ffff880215028000 ffff880036108600
[ 51.432520] Call Trace:
[ 51.432525] [<ffffffff81427dc9>] dump_stack+0x4b/0x72
[ 51.432529] [<ffffffff810add82>] warn_slowpath_common+0x82/0xc0
[ 51.432531] [<ffffffff810adeca>] warn_slowpath_null+0x1a/0x20
[ 51.432534] [<ffffffff814088f0>] add_disk+0x480/0x4e0
[ 51.432538] [<ffffffff815d3d55>] sd_probe_async+0x115/0x1d0
[ 51.432541] [<ffffffff810d717a>] async_run_entry_fn+0x4a/0x140
[ 51.432544] [<ffffffff810cc160>] process_one_work+0x230/0x6a0
[ 51.432546] [<ffffffff810cc0c9>] ? process_one_work+0x199/0x6a0
[ 51.432549] [<ffffffff810cc61e>] worker_thread+0x4e/0x450
[ 51.432552] [<ffffffff810cc5d0>] ? process_one_work+0x6a0/0x6a0
[ 51.432554] [<ffffffff810d35b1>] kthread+0x101/0x120
[ 51.432558] [<ffffffff81108c89>] ? trace_hardirqs_on_caller+0x129/0x1b0
[ 51.432560] [<ffffffff810d34b0>] ? kthread_create_on_node+0x250/0x250
[ 51.432564] [<ffffffff8187875f>] ret_from_fork+0x3f/0x70
[ 51.432566] [<ffffffff810d34b0>] ? kthread_create_on_node+0x250/0x250
[ 51.432568] ---[ end trace ea38cc3cfd710baf ]---

The modules are split over two lines judging by the time stamps but I'm
not sure why. I don't see it when using pr_cont in the example.

Thanks,
Laura
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/