Bug 1246525 - rhel-osp-director: Repeating "ironic-api" errors in /var/log/messages on the undercloud node.
Summary: rhel-osp-director: Repeating "ironic-api" errors in /var/log/messages on the ...
Status: CLOSED DUPLICATE of bug 1287309
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-puppet-modules
Version: 7.0 (Kilo)
Hardware: Unspecified
OS: Unspecified
high
medium
Target Milestone: z3
: 7.0 (Kilo)
Assignee: Ivan Chavero
QA Contact: Raviv Bar-Tal
URL:
Whiteboard:
Keywords: Triaged, ZStream
: 1257784 1258979 1262596 1263645 1264200 1286407 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-07-24 13:57 UTC by Alexander Chuzhoy
Modified: 2018-02-08 10:47 UTC (History)
21 users (show)

(edit)
On the Undercloud, HAProxy is configured to run a HTTP check against the openstack-ironic-api service every 2 seconds. The check causes openstack-ironic-api to log a traceback to stderr with the errors:

 error: [Errno 104] Connection reset by peer
 error: [Errno 32] Broken pipe

Since the check runs every 2 seconds, these messages repeat frequently in /var/log/messages. As a workaround, switch to root permissions, edit /etc/haproxy/haproxy.cfg, and comment out the "option httpchk GET /" line from the ironic listener configuration:

 listen ironic
   bind 192.0.2.2:6385
   bind 192.0.2.3:6385
   # option httpchk GET /
   server 192.0.2.1 192.0.2.1:6385 check fall 5 inter 2000 rise 2

Save the file, then restart haproxy:

 sudo systemctl restart haproxy

No tracebacks from openstack-ironic-api are written to stderr.
Clone Of:
(edit)
Last Closed: 2015-12-15 12:51:20 UTC


Attachments (Terms of Use)
messages file (14.06 MB, application/x-gzip)
2015-07-24 18:54 UTC, Alexander Chuzhoy
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2015:2677 normal SHIPPED_LIVE openstack-packstack and openstack-puppet-modules bug fix advisory 2015-12-21 21:58:17 UTC
OpenStack gerrit 197904 None None None Never
Red Hat Bugzilla 1264236 None None None 2019-06-20 17:39 UTC
Red Hat Bugzilla 1299854 None CLOSED launch-fusor-undercloud-installer aborts with "neutron subnet-update: error: too few arguments" 2019-06-20 17:39 UTC

Internal Trackers: 1264236 1299854

Description Alexander Chuzhoy 2015-07-24 13:57:06 UTC
rhel-osp-director: Repeating "ironic-api" errors in /var/log/messages on the undercloud node.


Environment:

instack-undercloud-2.1.2-22.el7ost.noarch
openstack-ironic-conductor-2015.1.0-9.el7ost.noarch
python-ironicclient-0.5.1-9.el7ost.noarch
openstack-ironic-api-2015.1.0-9.el7ost.noarch
python-ironic-discoverd-1.1.0-5.el7ost.noarch
openstack-ironic-common-2015.1.0-9.el7ost.noarch
openstack-ironic-discoverd-1.1.0-5.el7ost.noarch


Steps to reproduce:
1. Deploy an undercloud and enable SSL.
2. Attempt to deploy an overcloud on top of the undercloud.
3. Check /var/log/messages on the undercloud node.

Result:
Repeating error:
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: 192.0.2.1 - - [24/Jul/2015 09:56:14] "GET / HTTP/1.0" 200 394                                                                                                       
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: Traceback (most recent call last):                                                                                                                                  
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/wsgiref/handlers.py", line 86, in run                                                                                                    
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.finish_response()                                                                                                                                              
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/wsgiref/handlers.py", line 128, in finish_response                                                                                       
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.write(data)                                                                                                                                                    
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/wsgiref/handlers.py", line 212, in write                                                                                                 
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.send_headers()                                                                                                                                                 
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/wsgiref/handlers.py", line 270, in send_headers                                                                                          
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.send_preamble()                                                                                                                                                
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/wsgiref/handlers.py", line 194, in send_preamble                                                                                         
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: 'Date: %s\r\n' % format_date_time(time.time())                                                                                                                      
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/socket.py", line 324, in write                                                                                                           
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.flush()                                                                                                                                                        
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/socket.py", line 303, in flush                                                                                                           
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self._sock.sendall(view[write_offset:write_offset+buffer_size])                                                                                                     
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 376, in sendall                                                                              
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: tail = self.send(data, flags)
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 359, in send
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: total_sent += fd.send(data[total_sent:], flags)
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: error: [Errno 104] Connection reset by peer
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: 192.0.2.1 - - [24/Jul/2015 09:56:14] "GET / HTTP/1.0" 500 59
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: Traceback (most recent call last):
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/SocketServer.py", line 593, in process_request_thread
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.finish_request(request, client_address)
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/SocketServer.py", line 334, in finish_request
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.RequestHandlerClass(request, client_address, self)
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/SocketServer.py", line 651, in __init__
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.finish()
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/SocketServer.py", line 710, in finish
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.wfile.close()
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/socket.py", line 279, in close
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self.flush()
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib64/python2.7/socket.py", line 303, in flush
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: self._sock.sendall(view[write_offset:write_offset+buffer_size])
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 376, in sendall
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: tail = self.send(data, flags)
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 359, in send
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: total_sent += fd.send(data[total_sent:], flags)
Jul 24 09:56:14 rhos-compute-node-13 ironic-api: error: [Errno 32] Broken pipe


Expected result:
no ironic-api erros in /var/log/messages

Comment 3 Alexander Chuzhoy 2015-07-24 18:54:34 UTC
Created attachment 1055876 [details]
messages file

Comment 4 James Slagle 2015-07-24 19:09:22 UTC
i can reproduce this on my non-SSL undercloud as well. It's the haproxy check, it must terminate the connection early for some reason, even though it gets a 200 OK from the ironic-api. If you comment out the check in /etc/haproxy/haproxy.cfg so that the ironic listener section looks like:

listen ironic
  bind 192.0.2.2:6385
  bind 192.0.2.3:6385
  # option httpchk GET /
  server 192.0.2.1 192.0.2.1:6385 check fall 5 inter 2000 rise 2


Then the messages stop.

I definitely don't consider this a blocker for GA, but will add the doc text as a known issue with the workaround.

Comment 6 James Slagle 2015-08-28 16:10:35 UTC
*** Bug 1257784 has been marked as a duplicate of this bug. ***

Comment 7 Jon Thomas 2015-09-03 16:11:37 UTC
*** Bug 1258979 has been marked as a duplicate of this bug. ***

Comment 8 James Slagle 2015-09-16 12:01:19 UTC
*** Bug 1263645 has been marked as a duplicate of this bug. ***

Comment 9 James Slagle 2015-09-22 16:26:02 UTC
*** Bug 1264200 has been marked as a duplicate of this bug. ***

Comment 10 James Slagle 2015-09-28 11:49:51 UTC
*** Bug 1262596 has been marked as a duplicate of this bug. ***

Comment 11 James Slagle 2015-10-05 19:52:31 UTC
the fix for this will be on the openstack-puppet-modules side.

the upstream fix was included in https://review.openstack.org/#/c/197904

i see there is a downstream patch for that in the openstack-puppet-modules source (0023-Remove-httpchk-option-from-haproxy-listeners.patch) but it is actually missing the diff from the patch that removed this code from the haproxy::listen class for ironic:

      options          => {
        'option' => [ 'httpchk GET /' ],
      },


I believe this patch just needs to be updated or carry a new patch that removes the above lines from the ironic haproxy::listen class

Comment 12 Ivan Chavero 2015-10-09 02:59:42 UTC
This bug has been fixed, but i need acks. can i have them please?

Comment 13 Ivan Chavero 2015-10-09 20:31:52 UTC
(In reply to James Slagle from comment #11)
> the fix for this will be on the openstack-puppet-modules side.
> 
> the upstream fix was included in https://review.openstack.org/#/c/197904
> 
> i see there is a downstream patch for that in the openstack-puppet-modules
> source (0023-Remove-httpchk-option-from-haproxy-listeners.patch) but it is
> actually missing the diff from the patch that removed this code from the
> haproxy::listen class for ironic:
> 
>       options          => {
>         'option' => [ 'httpchk GET /' ],
>       },
> 
> 
> I believe this patch just needs to be updated or carry a new patch that
> removes the above lines from the ironic haproxy::listen class

The patch does not have the removal of this code because the ironic section for haproxy::listen does not contain it. This bug is fixed in current OPM package.

Can you confirm this?

Comment 14 Ivan Chavero 2015-10-09 23:23:58 UTC
Updated OPM package with latest patch

Comment 16 James Slagle 2015-11-30 12:50:27 UTC
*** Bug 1286407 has been marked as a duplicate of this bug. ***

Comment 17 James Slagle 2015-11-30 12:54:44 UTC
(In reply to Ivan Chavero from comment #13)
> (In reply to James Slagle from comment #11)
> > the fix for this will be on the openstack-puppet-modules side.
> > 
> > the upstream fix was included in https://review.openstack.org/#/c/197904
> > 
> > i see there is a downstream patch for that in the openstack-puppet-modules
> > source (0023-Remove-httpchk-option-from-haproxy-listeners.patch) but it is
> > actually missing the diff from the patch that removed this code from the
> > haproxy::listen class for ironic:
> > 
> >       options          => {
> >         'option' => [ 'httpchk GET /' ],
> >       },
> > 
> > 
> > I believe this patch just needs to be updated or carry a new patch that
> > removes the above lines from the ironic haproxy::listen class
> 
> The patch does not have the removal of this code because the ironic section
> for haproxy::listen does not contain it. This bug is fixed in current OPM
> package.
> 
> Can you confirm this?

qe is reporting it's not fixed.

Comment 18 Lucas Alvares Gomes 2015-12-14 14:33:10 UTC
The bug seems duplicated with https://bugzilla.redhat.com/show_bug.cgi?id=1287309

Comment 19 Raviv Bar-Tal 2015-12-15 12:51:20 UTC
The triggers for this bug in python http://bugs.python.org/issue14574 that 
raise an exception.
once we change to oslo.service this will stop.
But it we only can add a dependency on oslo.service for osp8+

*** This bug has been marked as a duplicate of bug 1287309 ***


Note You need to log in before you can comment on or make changes to this bug.