Bug 736125

Summary: syslog messages are going to active VT
Product: [Fedora] Fedora Reporter: Orion Poplawski <orion>
Component: anacondaAssignee: Ales Kozumplik <akozumpl>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 16CC: akozumpl, anaconda-maint-list, jonathan, jzeleny, vanmeeuwen+fedora
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: anaconda-16.17-1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-11-22 23:26:42 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
screenshot none

Description Orion Poplawski 2011-09-06 18:46:45 UTC 
Description of problem:

Booting kickstart install in text mode.  Kernel messages are sent to whatever the active console/VT is instead of VT4.

Version-Release number of selected component (if applicable):
16.16
Comment 1 Ales Kozumplik 2011-09-07 08:23:06 UTC 
I'm debugging this. For some reason systemd doesn't start rsyslog.service for us.
Comment 2 Ales Kozumplik 2011-09-08 06:09:39 UTC 
Fixed by 77ad52a7eb3c4a40b22e8feefae5bff939c122ce on master, a045ef5fef08a3f0150c248b65e05851adbdc5ea on f16-branch.
Comment 3 Orion Poplawski 2011-09-08 20:36:07 UTC 
Confirmed mostly fixed, although a few messages do appear to make it onto the text screen putting garbage up there.  It does stop though and messages are in /tmp/syslog.
Comment 4 Ales Kozumplik 2011-09-09 07:30:44 UTC 
Can you poe(In reply to comment #3)
> Confirmed mostly fixed, although a few messages do appear to make it onto the
> text screen putting garbage up there.  It does stop though and messages are in
> /tmp/syslog.

Can you post a screenshot please?
Comment 5 Orion Poplawski 2011-09-09 15:39:57 UTC 
Created attachment 522356 [details]
screenshot

I suspect it is the output of the kernel INFO message below.  I seem to remember that it is normal for such messages to go to the text console as well.

15:32:25,770 WARNING kernel:[   44.748137] 
15:32:25,770 WARNING kernel:[   44.748138] =================================
15:32:25,770 WARNING kernel:[   44.748334] [ INFO: inconsistent lock state ]
15:32:25,770 WARNING kernel:[   44.748465] 3.1.0-0.rc3.git0.0.fc16.x86_64 #1
15:32:25,770 WARNING kernel:[   44.748595] ---------------------------------
15:32:25,770 WARNING kernel:[   44.748723] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
15:32:25,770 WARNING kernel:[   44.748916] kswapd0/21 [HC0[0]:SC0[0]:HE1:SE1] takes:
15:32:25,770 WARNING kernel:[   44.749013]  (&sb->s_type->i_mutex_key#14){+.+.?.}, at: [<ffffffff811ae562>] ext4_evict_inode+0x76/0x33c
15:32:25,770 WARNING kernel:[   44.749013] {RECLAIM_FS-ON-W} state was registered at:
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8108f2f0>] mark_held_locks+0x6d/0x95
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8108f8ff>] lockdep_trace_alloc+0x9f/0xc2
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8112ed60>] slab_pre_alloc_hook+0x1e/0x54
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff81132638>] kmem_cache_alloc+0x25/0x13a
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff81155932>] __d_alloc+0x26/0x168
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff81155c8e>] d_alloc+0x1f/0x62
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8114bea5>] d_alloc_and_lookup+0x2c/0x6b
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8114cb8a>] walk_component+0x215/0x3e8
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8114cd98>] lookup_last+0x3b/0x3d
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8114da93>] path_lookupat+0x82/0x2af
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8114dce8>] do_path_lookup+0x28/0x97
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8114decc>] user_path_at+0x59/0x96
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff81146946>] vfs_fstatat+0x44/0x6e
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff811469ab>] vfs_stat+0x1b/0x1d
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff81146aaa>] sys_newstat+0x1a/0x33
15:32:25,770 WARNING kernel:[   44.749013]   [<ffffffff8150b082>] system_call_fastpath+0x16/0x1b
15:32:25,770 WARNING kernel:[   44.749013] irq event stamp: 109571
15:32:25,770 WARNING kernel:[   44.749013] hardirqs last  enabled at (109571): [<ffffffff810f9735>] free_hot_cold_page+0x128/0x13f
15:32:25,770 WARNING kernel:[   44.749013] hardirqs last disabled at (109570): [<ffffffff810f9668>] free_hot_cold_page+0x5b/0x13f
15:32:25,770 WARNING kernel:[   44.749013] softirqs last  enabled at (109548): [<ffffffff81062ca4>] __do_softirq+0x200/0x25a
15:32:25,770 WARNING kernel:[   44.749013] softirqs last disabled at (109543): [<ffffffff8150d37c>] call_softirq+0x1c/0x30
15:32:25,770 WARNING kernel:[   44.749013] 
15:32:25,770 WARNING kernel:[   44.749013] other info that might help us debug this:
15:32:25,770 WARNING kernel:[   44.749013]  Possible unsafe locking scenario:
15:32:25,770 WARNING kernel:[   44.749013] 
15:32:25,770 WARNING kernel:[   44.749013]        CPU0
15:32:25,770 WARNING kernel:[   44.749013]        ----
15:32:25,770 WARNING kernel:[   44.749013]   lock(&sb->s_type->i_mutex_key);
15:32:25,770 WARNING kernel:[   44.749013]   <Interrupt>
15:32:25,770 WARNING kernel:[   44.749013]     lock(&sb->s_type->i_mutex_key);
15:32:25,770 WARNING kernel:[   44.749013] 
15:32:25,770 WARNING kernel:[   44.749013]  *** DEADLOCK ***
15:32:25,770 WARNING kernel:[   44.749013] 
15:32:25,770 WARNING kernel:[   44.749013] 2 locks held by kswapd0/21:
15:32:25,770 WARNING kernel:[   44.749013]  #0:  (shrinker_rwsem){++++..}, at: [<ffffffff81101aac>] shrink_slab+0x39/0x2ef
15:32:25,770 WARNING kernel:[   44.749013]  #1:  (&type->s_umount_key#36){+++++.}, at: [<ffffffff811452e4>] grab_super_passive+0x57/0x7b
15:32:25,770 WARNING kernel:[   44.749013] 
15:32:25,770 WARNING kernel:[   44.749013] stack backtrace:
15:32:25,770 WARNING kernel:[   44.749013] Pid: 21, comm: kswapd0 Not tainted 3.1.0-0.rc3.git0.0.fc16.x86_64 #1
15:32:25,770 WARNING kernel:[   44.749013] Call Trace:
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff814f9d6c>] print_usage_bug+0x1e7/0x1f8
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8101a85d>] ? save_stack_trace+0x2c/0x49
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108d5bc>] ? print_irq_inversion_bug.part.18+0x1a0/0x1a0
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108dcea>] mark_lock+0x106/0x220
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108e198>] __lock_acquire+0x394/0xcf7
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8101a85d>] ? save_stack_trace+0x2c/0x49
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108b09f>] ? __bfs+0x137/0x1c7
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff811ae562>] ? ext4_evict_inode+0x76/0x33c
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108eff1>] lock_acquire+0xf3/0x13e
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff811ae562>] ? ext4_evict_inode+0x76/0x33c
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff811ae562>] ? ext4_evict_inode+0x76/0x33c
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff815025db>] __mutex_lock_common+0x5d/0x39a
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff811ae562>] ? ext4_evict_inode+0x76/0x33c
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff810801e9>] ? sched_clock_local+0x12/0x75
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108b885>] ? trace_hardirqs_off+0xd/0xf
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff8108bdf0>] ? lock_release_holdtime.part.9+0x59/0x62
15:32:25,770 WARNING kernel:[   44.749013]  [<ffffffff81502a27>] mutex_lock_nested+0x40/0x45
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff811ae562>] ext4_evict_inode+0x76/0x33c
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81157cf2>] evict+0x99/0x153
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81157f78>] dispose_list+0x32/0x43
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81158c13>] prune_icache_sb+0x257/0x266
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff811453e2>] prune_super+0xda/0x145
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81101c11>] shrink_slab+0x19e/0x2ef
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81104c44>] balance_pgdat+0x2e7/0x57e
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81105217>] kswapd+0x33c/0x395
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff8107a9f8>] ? __init_waitqueue_head+0x4b/0x4b
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff81104edb>] ? balance_pgdat+0x57e/0x57e
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff8107a18d>] kthread+0xa8/0xb0
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff8150d284>] kernel_thread_helper+0x4/0x10
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff815046f4>] ? retint_restore_args+0x13/0x13
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff8107a0e5>] ? __init_kthread_worker+0x5a/0x5a
15:32:25,778 WARNING kernel:[   44.749013]  [<ffffffff8150d280>] ? gs_change+0x13/0x13

it appeared after pre-init scripts and before device probing.
Comment 6 Ales Kozumplik 2011-09-12 06:35:45 UTC 
yes, it's not related to this bug, I see you opened kernel bug 737098 for it, thanks.