Bug 1246525

Summary: rhel-osp-director: Repeating "ironic-api" errors in /var/log/messages on the undercloud node.
Product: Red Hat OpenStack Reporter: Alexander Chuzhoy <sasha>
Component: openstack-puppet-modulesAssignee: Ivan Chavero <ichavero>
Status: CLOSED DUPLICATE QA Contact: Raviv Bar-Tal <rbartal>
Severity: medium Docs Contact:
Priority: high    
Version: 7.0 (Kilo)CC: augol, calfonso, dblack, dcain, dhill, dmacpher, felipe.alfaro, gtrellu, jmelvin, jslagle, lmartins, mburns, michele, mori, oblaut, rhel-osp-director-maint, rhosp-bugs-internal, sclewis, ukalifon, yeylon
Target Milestone: z3Keywords: Triaged, ZStream
Target Release: 7.0 (Kilo)   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: openstack-puppet-modules-2015.1.8-22.el7ost Doc Type: Known Issue
Doc Text:
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.
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-12-15 12:51:20 UTC Type: Bug
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
messages file none

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 ***