Bug 1263093
| Summary: | virt-who generate duplicated error log when failed to start virt-who service | ||
|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | Liushihui <shihliu> |
| Component: | virt-who | Assignee: | Radek Novacek <rnovacek> |
| Status: | CLOSED DUPLICATE | QA Contact: | xingge <gxing> |
| Severity: | medium | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 7.2 | CC: | gxing, hsun, ldai, ovasik, rnovacek, sgao, shihliu |
| Target Milestone: | rc | ||
| Target Release: | --- | ||
| Hardware: | x86_64 | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2015-09-15 08:54:21 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: | |||
This bug will be fixed together with 1243341 as the cause is very similar. *** This bug has been marked as a duplicate of bug 1243341 *** Sorry, wrong bug number. This is the correct one: bug 1254843. *** This bug has been marked as a duplicate of bug 1254843 *** when configure wrong env and owner, start virt-who service ,it will send the error info five times each interval. Yes, that's right. I consider it correct behavior. virt-who tries to send each report to the subscription manager five times before it is dropped. Each time it fails with this error and the error is logged. virt-who can't just stop itself because the organization might get created in the future. Radek, I have a problem, why does virt-who need send five times error info to subscription-manager before dropped it? I think it just need to send the error info one time. (In reply to Radek Novacek from comment #4) > Yes, that's right. I consider it correct behavior. virt-who tries to send > each report to the subscription manager five times before it is dropped. > Each time it fails with this error and the error is logged. virt-who can't > just stop itself because the organization might get created in the future. Radek, I found virt-who only send error info two times before dropped it when unregister system if set the refresh interval to 5s. please see the log as the following. However, virt-who will send error info one time before dropped it if set interval to 3600s. So I'm not sure which phenomenon is correct. send five times or just one time before drop it?
2015-09-16 13:34:33,473 [DEBUG] subscription-manager:13373 @certdirectory.py:216 - Installed product IDs: ['69']
2015-09-16 13:34:33,473 [DEBUG] subscription-manager:13373 @cert_sorter.py:126 - Unregistered, skipping server compliance check.
2015-09-16 13:34:33,474 [DEBUG] subscription-manager:13373 @identity.py:131 - Loading consumer info from identity certificates.
2015-09-16 13:34:33,474 [DEBUG] subscription-manager:13373 @identity.py:146 - Reload of consumer identity cert /etc/pki/consumer/cert.pem raised an exception with msg: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem'
2015-09-16 13:34:33,578 [INFO] rhsmd:13375 @rhsmd:229 - rhsmd started
2015-09-16 13:34:33,581 [DEBUG] rhsmd:13375 @rhsmd:184 - D-Bus interface com.redhat.SubscriptionManager.EntitlementStatus.update_status called with status = 0
2015-09-16 13:34:33,600 [DEBUG] @esx.py:142 - Waiting for ESX changes
2015-09-16 13:34:33,602 [DEBUG] @subscriptionmanager.py:112 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2015-09-16 13:34:33,602 [ERROR] @virtwho.py:180 - Error in communication with subscription manager:
Traceback (most recent call last):
File "/usr/share/virt-who/virtwho.py", line 172, in send
self._sendGuestAssociation(report)
File "/usr/share/virt-who/virtwho.py", line 203, in _sendGuestAssociation
report.config.type)
File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 145, in hypervisorCheckIn
self._connect(config)
File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 115, in _connect
"Unable to read certificate, system is not registered or you are not root")
SubscriptionManagerUnregisteredError: Unable to read certificate, system is not registered or you are not root
2015-09-16 13:34:33,614 [DEBUG] rhsmd:13375 @identity.py:131 - Loading consumer info from identity certificates.
2015-09-16 13:34:33,614 [DEBUG] rhsmd:13375 @identity.py:146 - Reload of consumer identity cert /etc/pki/consumer/cert.pem raised an exception with msg: [Errno 2] No such file or directory: '/etc/pki/consumer/key.pem'
2015-09-16 13:34:33,615 [DEBUG] rhsmd:13375 @rhsmd:152 - D-Bus signal com.redhat.SubscriptionManager.EntitlementStatus.entitlement_status_changed emitted
2015-09-16 13:34:33,615 [DEBUG] subscription-manager:13373 @utils.py:284 - Restarted virt-who
2015-09-16 13:34:33,615 [WARNING] @virtwho.py:356 - virt-who reload
2015-09-16 13:34:33,616 [INFO] @virtwho.py:710 - Reloading
2015-09-16 13:34:33,616 [DEBUG] @virtwho.py:215 - Starting infinite loop with 5 seconds interval
2015-09-16 13:34:33,618 [DEBUG] @esx.py:55 - Log into ESX
2015-09-16 13:34:33,812 [DEBUG] @esx.py:58 - Creating ESX event filter
2015-09-16 13:34:33,875 [DEBUG] @esx.py:142 - Waiting for ESX changes
2015-09-16 13:34:33,879 [DEBUG] @subscriptionmanager.py:112 - Authenticating with certificate: /etc/pki/consumer/cert.pem
2015-09-16 13:34:33,879 [ERROR] @virtwho.py:180 - Error in communication with subscription manager:
Traceback (most recent call last):
File "/usr/share/virt-who/virtwho.py", line 172, in send
self._sendGuestAssociation(report)
File "/usr/share/virt-who/virtwho.py", line 203, in _sendGuestAssociation
report.config.type)
File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 145, in hypervisorCheckIn
self._connect(config)
File "/usr/share/virt-who/manager/subscriptionmanager/subscriptionmanager.py", line 115, in _connect
"Unable to read certificate, system is not registered or you are not root")
SubscriptionManagerUnregisteredError: Unable to read certificate, system is not registered or you are not root
There is another phenomenon, when configure wrong username or password, start virt-who service ,it will send the error info one times each interval. However, if configure wrong env or owner, start virt-who service, it will send the error info five times each interval. I think virt-who should keep the same result(send the same number of times error info) mo matter virt-who detected any error info. Well, number of tries depends on the type of error. If virt-who detects incorrect username/password it know that it can't be easily fixed without virt-who restart. So it doesn't try it multiple times. If there is some non-critical error (network issue, timeout, some error in candlepin), virt-who tries to send the data five times before it stops. We can mark some special cases as critical (causing virt-who to stop) if we can detect it from the reply. |
Description of problem: When it hasn't configure VIRTWHO_ESX_OWNER or VIRTWHO_ESX_OWNER in /etc/sysconfig/virt-who, it will send duplicated error info in virt-who's log Version-Release number of selected component (if applicable): python-rhsm-1.15.4-4.el7.x86_64 subscription-manager-1.15.9-7.el7.x86_64 virt-who-0.14-7.el7.noarch SAM-1.4.1-RHEL-6-20141113.0 How reproducible: Always Steps to Reproduce: 1. Register system to SAM. 2. Configure virt-who run at esx mode and configure "owner" or "env" to NULL # cat /etc/virt-who.d/virt-who [test-esx1] type=esx server=10.66.78.2 username=Administrator password=qwer1234P! owner=ACME_Corporation env= 3. Restart virt-who service and check virt-who's log # systemctl restart virt-who # tail -f /var/log/rhsm/rhsm.log Actual results: Virt-who will generate duplicated error info as the following: ===================The first time========================= 2015-09-15 14:24:54,637 [ERROR] @virtwho.py:747 - Fatal error: Traceback (most recent call last): File "/usr/share/virt-who/virtwho.py", line 741, in <module> main() File "/usr/share/virt-who/virtwho.py", line 670, in main virtWho = VirtWho(logger, options) File "/usr/share/virt-who/virtwho.py", line 130, in __init__ self.configManager = ConfigManager(self.logger, config_dir, smType=options.smType) File "/usr/share/virt-who/config.py", line 352, in __init__ self._readConfig(parser) File "/usr/share/virt-who/config.py", line 359, in _readConfig config.checkOptions(self.smType, self.logger) File "/usr/share/virt-who/config.py", line 96, in checkOptions raise InvalidOption("Option `env` needs to be set in config `%s`" % (self.name)) InvalidOption: Option `env` needs to be set in config `test-esx1` ===================The Second time(duplicated info)========================= 2015-09-15 14:24:54,637 [ERROR] @virtwho.py:747 - Fatal error: Traceback (most recent call last): File "/usr/share/virt-who/virtwho.py", line 741, in <module> main() File "/usr/share/virt-who/virtwho.py", line 670, in main virtWho = VirtWho(logger, options) File "/usr/share/virt-who/virtwho.py", line 130, in __init__ self.configManager = ConfigManager(self.logger, config_dir, smType=options.smType) File "/usr/share/virt-who/config.py", line 352, in __init__ self._readConfig(parser) File "/usr/share/virt-who/config.py", line 359, in _readConfig config.checkOptions(self.smType, self.logger) File "/usr/share/virt-who/config.py", line 96, in checkOptions raise InvalidOption("Option `env` needs to be set in config `%s`" % (self.name)) InvalidOption: Option `env` needs to be set in config `test-esx1` Expected results: The error info should occur only once. And I also recommend to decrease the error info, just need to show "InvalidOption: Option `env` needs to be set in config `test-esx1`" Additional info: