yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1558699] [NEW] 25 second timeout while polling the machine-id file/dev/urandom

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Martin Ward <1558699@xxxxxxxxxxxxxxxxxx>
Date: Thu, 17 Mar 2016 17:32:11 -0000
Reply-to: Bug 1558699 <1558699@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

I am installing OpenStack using Nova, Glance and Keystone. The system
mostly works (I have another bug report open but it is not linked to
this problem at all).

I find that whatever command I run, Nova or Glance or even an openstack
one, takes a substantial number of seconds to complete, whether it works
or not. This is true for 'openstack --help' so it's going to be an
OpenStack issue.

I ran a few commands through 'strace -T' and found the system call that
is causing the delay:

poll([{fd=11, events=POLLIN}], 1, 25000) = 0 (Timeout)

I traced the file descriptor back to where it was created:

socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC, 0) = 11
connect(11, {sa_family=AF_LOCAL, sun_path=@"/tmp/dbus-CDsvziK6kt"}, 23) = 0
fcntl(11, F_GETFL)                      = 0x2 (flags O_RDWR)
fcntl(11, F_SETFL, O_RDWR|O_NONBLOCK)   = 0

It then polls this FD and sends and receives a number of bits of data
through it, indicating that it's all working correctly.

Further down you can see where it stops, for no apparent reason:

recvmsg(11, {msg_name(0)=NULL, msg_iov(1)=[{"l\3\1\1H\0\0\0\3\0\0\0u\0\0\0\6\1s\0\6\0\0\0:1.182\0\0"..., 2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 208
write(12, "\1\0\0\0\0\0\0\0", 8)        = 8
recvmsg(11, 0x7ffddb6d0cb0, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
sendmsg(11, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\0\1 \0\0\0\3\0\0\0\210\0\0\0\1\1o\0\25\0\0\0/org/fre"..., 152}, {"\27\0\0\0org.freedesktop.secrets\0\0\0\0\0", 32}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
poll([{fd=11, events=POLLIN}], 1, 25000) = 0 (Timeout)

I can consistently repeat this.

Find attached the strace file for this.

I am running:
OpenStack v1.7.0 (even generating this caused the delay).
Nova v2.30.1
Glance v1.1.0

I installed it all via pkg-add:

glance/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed]
glance-api/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
glance-common/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
glance-registry/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
nova-api/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
nova-cert/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
nova-common/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed,automatic]
nova-conductor/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
nova-consoleauth/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
nova-novncproxy/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
nova-scheduler/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
python-glance/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
python-glance-store/trusty-updates,now 0.9.1-1ubuntu1~cloud0 all [installed,automatic]
python-glanceclient/trusty-updates,now 1:1.1.0-0ubuntu1~cloud0 all [installed]
python-nova/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed,automatic]
python-novaclient/trusty-updates,now 2:2.30.1-1~cloud0 all [installed]
python-openstackclient/trusty-updates,now 1.7.0-1~cloud0 all [installed]


|\/|artin

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1558699

Title:
  25 second timeout while polling the machine-id file/dev/urandom

Status in OpenStack Compute (nova):
  New

Bug description:
  I am installing OpenStack using Nova, Glance and Keystone. The system
  mostly works (I have another bug report open but it is not linked to
  this problem at all).

  I find that whatever command I run, Nova or Glance or even an
  openstack one, takes a substantial number of seconds to complete,
  whether it works or not. This is true for 'openstack --help' so it's
  going to be an OpenStack issue.

  I ran a few commands through 'strace -T' and found the system call
  that is causing the delay:

  poll([{fd=11, events=POLLIN}], 1, 25000) = 0 (Timeout)

  I traced the file descriptor back to where it was created:

  socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC, 0) = 11
  connect(11, {sa_family=AF_LOCAL, sun_path=@"/tmp/dbus-CDsvziK6kt"}, 23) = 0
  fcntl(11, F_GETFL)                      = 0x2 (flags O_RDWR)
  fcntl(11, F_SETFL, O_RDWR|O_NONBLOCK)   = 0

  It then polls this FD and sends and receives a number of bits of data
  through it, indicating that it's all working correctly.

  Further down you can see where it stops, for no apparent reason:

  recvmsg(11, {msg_name(0)=NULL, msg_iov(1)=[{"l\3\1\1H\0\0\0\3\0\0\0u\0\0\0\6\1s\0\6\0\0\0:1.182\0\0"..., 2048}], msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 208
  write(12, "\1\0\0\0\0\0\0\0", 8)        = 8
  recvmsg(11, 0x7ffddb6d0cb0, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)
  sendmsg(11, {msg_name(0)=NULL, msg_iov(2)=[{"l\1\0\1 \0\0\0\3\0\0\0\210\0\0\0\1\1o\0\25\0\0\0/org/fre"..., 152}, {"\27\0\0\0org.freedesktop.secrets\0\0\0\0\0", 32}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 184
  poll([{fd=11, events=POLLIN}], 1, 25000) = 0 (Timeout)

  I can consistently repeat this.

  Find attached the strace file for this.

  I am running:
  OpenStack v1.7.0 (even generating this caused the delay).
  Nova v2.30.1
  Glance v1.1.0

  I installed it all via pkg-add:

  glance/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed]
  glance-api/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
  glance-common/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
  glance-registry/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
  nova-api/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
  nova-cert/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
  nova-common/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed,automatic]
  nova-conductor/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
  nova-consoleauth/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
  nova-novncproxy/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
  nova-scheduler/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed]
  python-glance/trusty-updates,now 2:11.0.1-0ubuntu1~cloud0 all [installed,automatic]
  python-glance-store/trusty-updates,now 0.9.1-1ubuntu1~cloud0 all [installed,automatic]
  python-glanceclient/trusty-updates,now 1:1.1.0-0ubuntu1~cloud0 all [installed]
  python-nova/trusty-updates,now 2:12.0.1-0ubuntu1~cloud0 all [installed,automatic]
  python-novaclient/trusty-updates,now 2:2.30.1-1~cloud0 all [installed]
  python-openstackclient/trusty-updates,now 1.7.0-1~cloud0 all [installed]

  
  |\/|artin

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1558699/+subscriptions
Follow ups

[Bug 1558699] Re: 25 second timeout while polling the machine-id file/dev/urandom
From: Matt Riedemann, 2016-03-21