Bug 680730

Summary: [libvirt] libvirt fails to start when qemu driver init fails
Product: Red Hat Enterprise Linux 6 Reporter: Haim <hateya>
Component: libvirtAssignee: Michal Privoznik <mprivozn>
Status: CLOSED WORKSFORME QA Contact: Virtualization Bugs <virt-bugs>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.1CC: abaron, berrange, dallan, danken, dnaori, eblake, hateya, mgoldboi, xen-maint, yeylon, ykaul, yoyzhang
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-04-27 09:47:52 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:
Bug Depends On:    
Bug Blocks: 682015    

Description Haim 2011-02-27 12:05:23 UTC
Description of problem:

problem: 

libvirt service crash when it fails to initialize qemu driver: 

13:54:58.793: 30090: error : main:3305 : Driver state initialization failed
13:57:45.391: 30109: warning : qemudDispatchSignalEvent:403 : Shutting down on signal 3

then, running /etc/init.d/libvirtd status I get: 

libvirtd dead but subsys locked

cause: 

it appears that when 'vdsm-hook-vhostmd' is installed with older selinux policy version (selinux-policy-targeted-3.7.19-54.el6.noarch) libvirt fails to initialize qemu driver due to permission error and crash. 

please note that libvirt didn't dump core file when it crash and I had to run the following to catch the crash: 

service libvirtd restart && gdb -p `pgrep libvirtd`

reproduces all time. 
doesn't happen with selinux-policy-targeted-3.7.19-54.el6_0.3.noarch. 

gdb crash: 

Continuing.                                                                                                                                                    
Detaching after fork from child process 30242.                                                                                                                 
Detaching after fork from child process 30245.                                                                                                                 
Detaching after fork from child process 30248.                                                                                                                 
Detaching after fork from child process 30251.                                                                                                                 
Detaching after fork from child process 30252.                                                                                                                 
Detaching after fork from child process 30253.                                                                                                                 
Detaching after fork from child process 30254.                                                                                                                 
Detaching after fork from child process 30255.                                                                                                                 
Detaching after fork from child process 30256.                                                                                                                 
Detaching after fork from child process 30257.                                                                                                                 

Program received signal SIGQUIT, Quit.
0x0000003fe5032c87 in kill () at ../sysdeps/unix/syscall-template.S:82
82      T_PSEUDO (SYSCALL_SYMBOL, SYSCALL_NAME, SYSCALL_NARGS)        
(gdb) bt                                                              
#0  0x0000003fe5032c87 in kill () at ../sysdeps/unix/syscall-template.S:82
#1  0x000000000041faa6 in main (argc=<value optimized out>, argv=<value optimized out>) at libvirtd.c:3330
(gdb) info threads 
  7 Thread 0x7ffae9772710 (LWP 30109)  0x0000003fe50d7e33 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87                                                                                                               
  6 Thread 0x7ffae8d71710 (LWP 30110)  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162                
  5 Thread 0x7ffae3fff710 (LWP 30111)  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162                
  4 Thread 0x7ffae35fe710 (LWP 30112)  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162                
  3 Thread 0x7ffae2bfd710 (LWP 30113)  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162                
  2 Thread 0x7ffae21fc710 (LWP 30114)  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162                
* 1 Thread 0x7ffaf09b7800 (LWP 30090)  0x0000003fe5032c87 in kill () at ../sysdeps/unix/syscall-template.S:82                                             
(gdb) thread al
alarm                   algos.8226              all_dom_sets            alloc_ptr               allow_ldso              alphasort
alarm@plt               alias_compare           all_edge_sets           alloc_reg               allow_libc              alphasort64
alarmfunc               alias_map               all_mask                alloc_secure_func       allow_libdl             already_called.11756
alg_get                 aliasent                allipv6Attributes       allocate                allow_libpthread        alt_attr            
algo_list               align_attr              alloc_addbyter          allocate_nodemask_v1    allow_seed_file_update                      
algorithms              aligned_heap_area       alloc_end               allocator               allowmask                                   
algos.8163              allAttributes           alloc_func              allowPCData             alpha_lower_list                            
algos.8184              allHdrFilterDef         alloc_last_block        allow_customize         alpha_upper_list                            
algos.8205              all_closure_sets        alloc_proppool          allow_customize_debug   alphabet                                    
(gdb) thread al                                                                                                                             
alarm                   algos.8226              all_dom_sets            alloc_ptr               allow_ldso              alphasort           
alarm@plt               alias_compare           all_edge_sets           alloc_reg               allow_libc              alphasort64         
alarmfunc               alias_map               all_mask                alloc_secure_func       allow_libdl             already_called.11756
alg_get                 aliasent                allipv6Attributes       allocate                allow_libpthread        alt_attr            
algo_list               align_attr              alloc_addbyter          allocate_nodemask_v1    allow_seed_file_update                      
algorithms              aligned_heap_area       alloc_end               allocator               allowmask                                   
algos.8163              allAttributes           alloc_func              allowPCData             alpha_lower_list                            
algos.8184              allHdrFilterDef         alloc_last_block        allow_customize         alpha_upper_list                            
algos.8205              all_closure_sets        alloc_proppool          allow_customize_debug   alphabet                                    
(gdb) thread apply all 
Display all 60587 possibilities? (y or n)
(gdb) thread apply all bt
bt_activate               bt_create@plt             bt_platform_finddevs      bt_read_linux             bt_setfilter_linux        btowc
bt_create                 bt_inject_linux           bt_platform_finddevs@plt  bt_setdirection_linux     bt_stats_linux            btowc@plt
(gdb) thread apply all bt                                                                                                                  
bt_activate               bt_create@plt             bt_platform_finddevs      bt_read_linux             bt_setfilter_linux        btowc    
bt_create                 bt_inject_linux           bt_platform_finddevs@plt  bt_setdirection_linux     bt_stats_linux            btowc@plt
(gdb) thread apply all bt                                                                                                                  

Thread 7 (Thread 0x7ffae9772710 (LWP 30109)):
#0  0x0000003fe50d7e33 in __poll (fds=<value optimized out>, nfds=<value optimized out>, timeout=<value optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87                                                                            
#1  0x0000000000418a1d in virEventRunOnce () at event.c:584                                                            
#2  0x000000000041b399 in qemudOneLoop () at libvirtd.c:2238                                                           
#3  0x000000000041b857 in qemudRunLoop (opaque=0x172c640) at libvirtd.c:2348                                           
#4  0x0000003fe58077e1 in start_thread (arg=0x7ffae9772710) at pthread_create.c:301                                    
#5  0x0000003fe50e153d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115                                    

Thread 6 (Thread 0x7ffae8d71710 (LWP 30110)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x00007ffaf0a12966 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:108
#2  0x000000000041c505 in qemudWorker (data=0x7ffae40008c0) at libvirtd.c:1561
#3  0x0000003fe58077e1 in start_thread (arg=0x7ffae8d71710) at pthread_create.c:301
#4  0x0000003fe50e153d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 5 (Thread 0x7ffae3fff710 (LWP 30111)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x00007ffaf0a12966 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:108
#2  0x000000000041c505 in qemudWorker (data=0x7ffae40008d8) at libvirtd.c:1561
#3  0x0000003fe58077e1 in start_thread (arg=0x7ffae3fff710) at pthread_create.c:301
#4  0x0000003fe50e153d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 4 (Thread 0x7ffae35fe710 (LWP 30112)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x00007ffaf0a12966 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:108
#2  0x000000000041c505 in qemudWorker (data=0x7ffae40008f0) at libvirtd.c:1561
#3  0x0000003fe58077e1 in start_thread (arg=0x7ffae35fe710) at pthread_create.c:301
#4  0x0000003fe50e153d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 3 (Thread 0x7ffae2bfd710 (LWP 30113)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x00007ffaf0a12966 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:108
#2  0x000000000041c505 in qemudWorker (data=0x7ffae4000908) at libvirtd.c:1561
#3  0x0000003fe58077e1 in start_thread (arg=0x7ffae2bfd710) at pthread_create.c:301
#4  0x0000003fe50e153d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115
---Type <return> to continue, or q <return> to quit---

Thread 2 (Thread 0x7ffae21fc710 (LWP 30114)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1  0x00007ffaf0a12966 in virCondWait (c=<value optimized out>, m=<value optimized out>) at util/threads-pthread.c:108
#2  0x000000000041c505 in qemudWorker (data=0x7ffae4000920) at libvirtd.c:1561
#3  0x0000003fe58077e1 in start_thread (arg=0x7ffae21fc710) at pthread_create.c:301
#4  0x0000003fe50e153d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Thread 1 (Thread 0x7ffaf09b7800 (LWP 30090)):
#0  0x0000003fe5032c87 in kill () at ../sysdeps/unix/syscall-template.S:82
#1  0x000000000041faa6 in main (argc=<value optimized out>, argv=<value optimized out>) at libvirtd.c:3330

Comment 1 Haim 2011-02-27 12:08:53 UTC
vdsm-hook-vhostmd-4.9-51.el6.x86_64
vdsm-reg-4.9-51.el6.x86_64
vdsm-debuginfo-4.9-51.el6.x86_64
vdsm-cli-4.9-51.el6.x86_64
vdsm-4.9-51.el6.x86_64
vdsm-hook-faqemu-4.9-51.el6.x86_64
libvirt-devel-0.8.7-8.el6.x86_64
libvirt-client-0.8.7-8.el6.x86_64
libvirt-0.8.7-8.el6.x86_64
libvirt-debuginfo-0.8.7-8.el6.x86_64
libvirt-python-0.8.7-8.el6.x86_64
libselinux-2.0.94-2.el6.x86_64
libselinux-python-2.0.94-2.el6.x86_64
libselinux-debuginfo-2.0.94-2.el6.x86_64
selinux-policy-targeted-3.7.19-54.el6.noarch
libselinux-utils-2.0.94-2.el6.x86_64
selinux-policy-3.7.19-54.el6.noarch

Comment 3 Daniel Berrangé 2011-02-28 10:38:31 UTC
This isn't a crash, libvirtd shuts down in an orderly fashion if a fatal error occurs during initialization.  Please set  log_debug=1 in libvirtd.conf and restart libvirtd & attach the full debug log it produces.

Comment 4 Daniel Berrangé 2011-02-28 11:00:14 UTC
Oh one question - do you have the 'blkio' cgroup mounted (see /proc/mounts) ? If so what kernel version do you have ?

Comment 6 Eric Blake 2011-03-31 11:51:40 UTC
This may also be related to bug 688774