Bug 1337462

Summary: Upgrade [6.1.9 -> 6.2 snap12] failed to detect boot server: ERF12-5139 [ProxyAPI::ProxyException]
Product: Red Hat Satellite Reporter: Sachin Ghai <sghai>
Component: DHCP & DNSAssignee: Marek Hulan <mhulan>
Status: CLOSED ERRATA QA Contact: Sachin Ghai <sghai>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.2.0CC: bbuckingham, ohadlevy
Target Milestone: UnspecifiedKeywords: Triaged
Target Release: Unused   
Hardware: Unspecified   
OS: Unspecified   
URL: http://projects.theforeman.org/issues/15213
Whiteboard:
Fixed In Version: foreman-1.11.0.33-1 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-07-27 11:04:49 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:
Bug Depends On:    
Bug Blocks: 1335807, 1337493    
Attachments:
Description Flags
foreman-debug logs none

Description Sachin Ghai 2016-05-19 09:20:59 UTC
Description of problem:
Following exception raised in production.log while performing "yum update"
to update packages from  sat6.1.9 -> Sat6.2 snap12. Though the log-level seems "warning" but following exception is being logged in production.log


==> /var/log/foreman/production.log <==
2016-05-19 04:32:23 [app] [W] failed to detect boot server: ERF12-5139 [ProxyAPI::ProxyException]: Unable to detect TFTP boot server ([Errno::ECONNREFUSED]: Connection refused - connect(2) for "qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.co...) for Capsule https://qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.com:9090/tftp
 | ProxyAPI::ProxyException: ERF12-5139 [ProxyAPI::ProxyException]: Unable to detect TFTP boot server ([Errno::ECONNREFUSED]: Connection refused - connect(2) for "qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.co...) for Capsule https://qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.com:9090/tftp
 | /usr/share/foreman/lib/proxy_api/tftp.rb:49:in `rescue in bootServer'
 | /usr/share/foreman/lib/proxy_api/tftp.rb:42:in `bootServer'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:72:in `boot_server'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:99:in `dhcp_attrs'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:20:in `dhcp_record'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:179:in `dhcp_conflict_detected?'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:424:in `block in make_lambda'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:231:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:231:in `block in halting'

Version-Release number of selected component (if applicable):

Sat[6.1.9 -> 6.2 snap12]

How reproducible:


Steps to Reproduce:
1. set sat6.2 repo
2. katello-service stop
3. yum update -y


Actual results:


Expected results:
No such exception in logs. If its a real issue then we need to fix it otherwise, we should suppress the exception, if possible. 

Additional info:

Comment 2 Sachin Ghai 2016-05-19 09:26:21 UTC
Created attachment 1159329 [details]
foreman-debug logs

Comment 4 Sachin Ghai 2016-05-20 08:28:24 UTC
Ok, This warning/exception is reproducible with following upgrade steps:

1. Disable sat6.1 repo 
2. Set/enable sat6.2 repo
3. yum install satellite -y
4. yum update -y
5. satellite-installer --scenario satellite --upgrade

2016-05-20 04:15:56 [app] [W] failed to detect boot server: ERF12-5139 [ProxyAPI::ProxyException]: Unable to detect TFTP boot server ([Errno::ECONNREFUSED]: Connection refused - connect(2) for "qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.co...) for Capsule https://qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.com:9090/tftp
 | ProxyAPI::ProxyException: ERF12-5139 [ProxyAPI::ProxyException]: Unable to detect TFTP boot server ([Errno::ECONNREFUSED]: Connection refused - connect(2) for "qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.co...) for Capsule https://qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.com:9090/tftp
 | /usr/share/foreman/lib/proxy_api/tftp.rb:49:in `rescue in bootServer'
 | /usr/share/foreman/lib/proxy_api/tftp.rb:42:in `bootServer'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:72:in `boot_server'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:99:in `dhcp_attrs'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:20:in `dhcp_record'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:179:in `dhcp_conflict_detected?'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:424:in `block in make_lambda'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:231:in `call'

Comment 5 Brad Buckingham 2016-05-24 14:48:32 UTC
I have not been able to reproduce this issue on my environment.  I am testing with changes that will be coming in snap 13; therefore, it could be related to those changes or environmental or procedural differences.  For now, I am going to triage this in, as we need to ensure the bug is resolved.

Comment 7 Sachin Ghai 2016-05-26 06:44:30 UTC
Reproducible with upgrade from sat6.1.9 -> sat6.2 snap13.1

steps to reproduce:
==================
1. Set sat6.2 repo on existing sat6.1 setup
2. yum update -y

==> /var/log/foreman/production.log <==
2016-05-26 00:38:44 [app] [W] failed to detect boot server: ERF12-5139 [ProxyAPI::ProxyException]: Unable to detect TFTP boot server ([Errno::ECONNREFUSED]: Connection refused - connect(2) for "qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.co...) for Capsule https://qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.com:9090/tftp
 | ProxyAPI::ProxyException: ERF12-5139 [ProxyAPI::ProxyException]: Unable to detect TFTP boot server ([Errno::ECONNREFUSED]: Connection refused - connect(2) for "qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.co...) for Capsule https://qe-sat6-upgrade-rhel7.satqe.lab.eng.rdu2.redhat.com:9090/tftp
 | /usr/share/foreman/lib/proxy_api/tftp.rb:49:in `rescue in bootServer'
 | /usr/share/foreman/lib/proxy_api/tftp.rb:42:in `bootServer'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:72:in `boot_server'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:99:in `dhcp_attrs'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:20:in `dhcp_record'
 | /usr/share/foreman/app/models/concerns/orchestration/dhcp.rb:179:in `dhcp_conflict_detected?'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:424:in `block in make_lambda'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:231:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:231:in `block in halting'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `block in halting'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `block in halting'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `block in halting'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `block in halting'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:229:in `block in halting'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:86:in `call'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activesupport-4.1.5/lib/active_support/callbacks.rb:86:in `run_callbacks'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/validations/callbacks.rb:111:in `run_validations!'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/validations.rb:318:in `valid?'
 | /opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/validations.rb:70:in `valid?'
 | /usr/share/foreman/app/models/concerns/orchestration.rb:69:in `valid?'
 | /usr/share/foreman/app/models/host/managed.rb:1044:in `trigger_nic_orchestration'

Comment 8 Ohad Levy 2016-05-26 11:00:11 UTC
the issue here is that a host object is being updated while being upgrade, triggering a proxy/capsule api call, which should not happen within a db migration.

if you look at the logs, it looks like the following line triggered the host save

/usr/share/foreman/db/migrate/20150612135546_create_host_status.rb:13:in `up'

Comment 9 Ohad Levy 2016-05-26 11:00:53 UTC
I would assume this is not a blocker (besides the spam in the logs) but would investigate regardless.

Comment 10 Marek Hulan 2016-05-27 14:21:46 UTC
Created redmine issue http://projects.theforeman.org/issues/15213 from this bug

Comment 11 Bryan Kearney 2016-05-27 16:16:45 UTC
Upstream bug component is DHCP & DNS

Comment 12 Brad Buckingham 2016-06-02 00:03:39 UTC
It appears that this bug will also require changes introduced in the upstream with http://projects.theforeman.org/issues/12425, which has been cloned to bug 1341860.

Without this change, the following is observed during upgrade:

[ERROR 2016-06-01 02:28:26 main] rake aborted!
StandardError: An error has occurred, this and all later migrations canceled:

undefined method `importing_facts=' for #<Host::Managed:0x000000098c19b0>/opt/rh/rh-ror41/root/usr/share/gems/gems/activemodel-4.1.5/lib/active_model/attribute_methods.rb:435:in `method_missing'
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/attribute_methods.rb:208:in `method_missing'
/usr/share/foreman/db/migrate/20150612135546_create_host_status.rb:19:in `ensure in block in up'
/usr/share/foreman/db/migrate/20150612135546_create_host_status.rb:19:in `block in up'
/opt/rh/rh-ror41/root/usr/share/gems/gems/activerecord-4.1.5/lib/active_record/relation/batches.rb:52:in `block (2 levels) in find_each'
...

Comment 13 Sachin Ghai 2016-06-02 09:47:55 UTC
Thanks Brad. You beat me on the issue in comment12. I just filed another bz for same issue: https://bugzilla.redhat.com/show_bug.cgi?id=1341974 (marked as duplicate)

Comment 14 Sachin Ghai 2016-06-02 09:50:51 UTC
Verified with upgrade from sat6.1.9 -> sat6.2 GA snap14 on rhel7.

The reported issue related boot_server is no longer reproducible with upgrade performed with above
builds. I don't find any exception during "yum update -y step". thank you for
the fix.

However I do see another issue as mentioned in comment12. But separate bz 1341860 is filed for this.

Comment 15 Bryan Kearney 2016-07-27 11:04:49 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:1501