Description of problem: /var/log/vdsm-reg/vdsm-reg.log is created but there is no logs during registration process. rhev-hypervisor7-7.0-20141006.0.iso # rpm -qa | grep -i vdsm vdsm-cli-4.16.6-1.el7.noarch vdsm-yajsonrpc-4.16.6-1.el7.noarch ovirt-node-plugin-vdsm-0.2.0-9.el7.noarch vdsm-python-zombiereaper-4.16.6-1.el7.noarch vdsm-xmlrpc-4.16.6-1.el7.noarch vdsm-jsonrpc-4.16.6-1.el7.noarch vdsm-hook-vhostmd-4.16.6-1.el7.noarch vdsm-reg-4.16.6-1.el7.noarch vdsm-python-4.16.6-1.el7.noarch vdsm-4.16.6-1.el7.x86_64 Additional info: - Selinux is Permissive. - Registration happens and host got UP. - No log is generated in /var/log/vdsm-reg/vdsm-reg.log Strace ========= 4527 munmap(0x7f8bc990f000, 4096) = 0 4527 socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 3 4527 open("/var/log/vdsm-reg/vdsm-reg.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 4 4527 lseek(4, 0, SEEK_END) = 0 4527 fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 4527 close(9) = 0 4527 stat("/data/updates", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 4527 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f8bc98ffa10) = 4535 4527 exit_group(0) = ? 4527 +++ exited with 0 +++ Attached to process: select(0, NULL, NULL, NULL, {2, 522252}) = 0 (Timeout) gettimeofday({1412704959, 625660}, NULL) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 open("/etc/hosts", O_RDONLY|O_CLOEXEC) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=105, ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fc7cd6df000 read(3, "127.0.0.1\t\tlocalhost.localdomain localhost localhost.localdomain\n::1\t\tlocalhost6.localdomain6 localhost6\n", 1024) = 105 read(3, "", 1024) = 0 close(3) = 0 munmap(0x7fc7cd6df000, 4096) = 0 sendto(3, "<15>2014-10-07 18:02:39,625 DEBUG Total retry count: 17, waited: 7 seconds.\0", 76, 0, {sa_family=AF_INET, sin_port=htons(514), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EBADF (Bad file descriptor) write(2, "Traceback (most recent call last):\n", 35) = 35 write(2, " File \"/usr/lib64/python2.7/logging/handlers.py\", line 862, in emit\n", 69) = 69 stat("/usr/lib64/python2.7/logging/handlers.py", 0x7fff08347f30) = -1 ENOENT (No such file or directory) write(2, "error: [Errno 9] Bad file descriptor\n", 37) = 37 write(2, "Logged from file vdsm-reg-setup, line 397\n", 42) = 42 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(4, "MainThread::DEBUG::2014-10-07 18:02:39,625::vdsm-reg-setup::397::vdsRegistrator::Total retry count: 17, waited: 7 seconds.\n", 123) = -1 EBADF (Bad file descriptor)
Created attachment 944707 [details] /etc/vdsm-reg/logger.conf
Raising priority because we can not debug vdsm-reg related bugs.
When I turned the disk to rw the log is written. Can it be that during the image setup we don't create /var/log/vdsm-reg/vdsm-reg.log file ? it must be there, as the script can't create a file on ro fs.. please check that out
This issue is not related to the log. I noticed that vdsm-reg-setup script gets stuck somewhere while forking to daemon. I need to debug it more, but printing to the log works fine if i add them before calling to createDaemon.createDaemon(). this issue only effects rhel7
Verified on rhevh-20141218.0.el7ev & rhev-m 3.5.0-0.27.el6ev
vdsm-python-4.16.8.1-4.el7ev.noarch