Bug 1006480

Summary: when deploying configuration files and /var/log/rhncfg-actions do not exists, action fails
Product: Red Hat Satellite 5 Reporter: Jan Hutař <jhutar>
Component: ClientAssignee: Grant Gainey <ggainey>
Status: CLOSED CURRENTRELEASE QA Contact: Martin Korbel <mkorbel>
Severity: high Docs Contact:
Priority: high    
Version: 560CC: cperry, mkorbel, tkasparek, tlestach
Target Milestone: ---Keywords: Regression
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: rhncfg-5.10.55-5-sat Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-10-01 19:59:16 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: 924171    

Description Jan Hutař 2013-09-10 17:00:00 UTC
Description of problem:
When deploying configuration files and /var/log/rhncfg-actions do not exists (like when you have just installed rhncfg packages), action fails


Version-Release number of selected component (if applicable):
rhncfg-5.10.55-2.el6sat.noarch


How reproducible:
always


Steps to Reproduce:
1. # rm -f /var/log/rhncfg-actions
2. On webUI schedule deployment of some configuration files
3. # rhn_check -vv


Actual results:
# rhn_check -vv
D: check_action{'action': "<?xml version='1.0'?>\n<methodCall>\n<methodName>configfiles.deploy</methodName>\n<params>\n<param>\n<value><struct>\n<member>\n<name>files</name>\n<value><array><data>\n<value><struct>\n<member>\n<name>config_channel</name>\n<value><string>jhutar-test</string></value>\n</member>\n<member>\n<name>username</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>encoding</name>\n<value><string></string></value>\n</member>\n<member>\n<name>checksum</name>\n<value><string></string></value>\n</member>\n<member>\n<name>filetype</name>\n<value><string>directory</string></value>\n</member>\n<member>\n<name>delim_start</name>\n<value><string></string></value>\n</member>\n<member>\n<name>delim_end</name>\n<value><string></string></value>\n</member>\n<member>\n<name>symlink</name>\n<value><string></string></value>\n</member>\n<member>\n<name>modified</name>\n<value><string></string></value>\n</member>\n<member>\n<name>groupname</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>file_contents</name>\n<value><string></string></value>\n</member>\n<member>\n<name>filemode</name>\n<value><int>644</int></value>\n</member>\n<member>\n<name>checksum_type</name>\n<value><string></string></value>\n</member>\n<member>\n<name>path</name>\n<value><string>/tmp/aaa</string></value>\n</member>\n<member>\n<name>selinux_ctx</name>\n<value><string></string></value>\n</member>\n<member>\n<name>revision</name>\n<value><int>1</int></value>\n</member>\n</struct></value>\n<value><struct>\n<member>\n<name>config_channel</name>\n<value><string>jhutar-test</string></value>\n</member>\n<member>\n<name>username</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>encoding</name>\n<value><string>base64</string></value>\n</member>\n<member>\n<name>checksum</name>\n<value><string>aa3a5ce5191d853e7c9c166a3924bfe3</string></value>\n</member>\n<member>\n<name>filetype</name>\n<value><string>file</string></value>\n</member>\n<member>\n<name>delim_start</name>\n<value><string>{|</string></value>\n</member>\n<member>\n<name>delim_end</name>\n<value><string>|}</string></value>\n</member>\n<member>\n<name>symlink</name>\n<value><string></string></value>\n</member>\n<member>\n<name>modified</name>\n<value><string></string></value>\n</member>\n<member>\n<name>groupname</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>file_contents</name>\n<value><string>UG9zdGF2ZW7DrSBSb23FryBzZSB2IMSMZXNrdSBwcnVkY2UgemhvcsWhdWplLCB0dnJkw60genBy\nw6F2YSBoZWxzaW5za8OpaG8gdsO9Ym9ydQ==\n</string></value>\n</member>\n<member>\n<name>filemode</name>\n<value><int>644</int></value>\n</member>\n<member>\n<name>checksum_type</name>\n<value><string>md5</string></value>\n</member>\n<member>\n<name>path</name>\n<value><string>/tmp/bbb</string></value>\n</member>\n<member>\n<name>selinux_ctx</name>\n<value><string></string></value>\n</member>\n<member>\n<name>revision</name>\n<value><int>1</int></value>\n</member>\n</struct></value>\n</data></array></value>\n</member>\n</struct></value>\n</param>\n</params>\n</methodCall>\n", 'version': 2, 'id': 88}
updateLoginInfo() login info
D: login(forceUpdate=True) invoked
logging into up2date server
D: rpcServer: Calling XMLRPC up2date.login
D: writeCachedLogin() invoked
D: Wrote pickled loginInfo at 1378831564.08 with expiration of 1378835164.08 seconds.
successfully retrieved authentication token from up2date server
D: logininfo:{'X-RHN-Server-Id': 1000010011, 'X-RHN-Auth-Server-Time': '1378831563.73', 'X-RHN-Auth': 'RbilX3vOIV1uYpft+iQF1A==', 'X-RHN-Auth-Channels': [['rhel-x86_64-server-6', '20130906055033', '1', '1'], ['rhn-tools-rhel-x86_64-server-6', '20130906055005', '0', '1'], ['gss-test-day-x86_64-6', '20130906082032', '0', '1']], 'X-RHN-Auth-User-Id': '', 'X-RHN-Auth-Expire-Offset': '3600.0'}
D: handle_action{'action': "<?xml version='1.0'?>\n<methodCall>\n<methodName>configfiles.deploy</methodName>\n<params>\n<param>\n<value><struct>\n<member>\n<name>files</name>\n<value><array><data>\n<value><struct>\n<member>\n<name>config_channel</name>\n<value><string>jhutar-test</string></value>\n</member>\n<member>\n<name>username</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>encoding</name>\n<value><string></string></value>\n</member>\n<member>\n<name>checksum</name>\n<value><string></string></value>\n</member>\n<member>\n<name>filetype</name>\n<value><string>directory</string></value>\n</member>\n<member>\n<name>delim_start</name>\n<value><string></string></value>\n</member>\n<member>\n<name>delim_end</name>\n<value><string></string></value>\n</member>\n<member>\n<name>symlink</name>\n<value><string></string></value>\n</member>\n<member>\n<name>modified</name>\n<value><string></string></value>\n</member>\n<member>\n<name>groupname</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>file_contents</name>\n<value><string></string></value>\n</member>\n<member>\n<name>filemode</name>\n<value><int>644</int></value>\n</member>\n<member>\n<name>checksum_type</name>\n<value><string></string></value>\n</member>\n<member>\n<name>path</name>\n<value><string>/tmp/aaa</string></value>\n</member>\n<member>\n<name>selinux_ctx</name>\n<value><string></string></value>\n</member>\n<member>\n<name>revision</name>\n<value><int>1</int></value>\n</member>\n</struct></value>\n<value><struct>\n<member>\n<name>config_channel</name>\n<value><string>jhutar-test</string></value>\n</member>\n<member>\n<name>username</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>encoding</name>\n<value><string>base64</string></value>\n</member>\n<member>\n<name>checksum</name>\n<value><string>aa3a5ce5191d853e7c9c166a3924bfe3</string></value>\n</member>\n<member>\n<name>filetype</name>\n<value><string>file</string></value>\n</member>\n<member>\n<name>delim_start</name>\n<value><string>{|</string></value>\n</member>\n<member>\n<name>delim_end</name>\n<value><string>|}</string></value>\n</member>\n<member>\n<name>symlink</name>\n<value><string></string></value>\n</member>\n<member>\n<name>modified</name>\n<value><string></string></value>\n</member>\n<member>\n<name>groupname</name>\n<value><string>root</string></value>\n</member>\n<member>\n<name>file_contents</name>\n<value><string>UG9zdGF2ZW7DrSBSb23FryBzZSB2IMSMZXNrdSBwcnVkY2UgemhvcsWhdWplLCB0dnJkw60genBy\nw6F2YSBoZWxzaW5za8OpaG8gdsO9Ym9ydQ==\n</string></value>\n</member>\n<member>\n<name>filemode</name>\n<value><int>644</int></value>\n</member>\n<member>\n<name>checksum_type</name>\n<value><string>md5</string></value>\n</member>\n<member>\n<name>path</name>\n<value><string>/tmp/bbb</string></value>\n</member>\n<member>\n<name>selinux_ctx</name>\n<value><string></string></value>\n</member>\n<member>\n<name>revision</name>\n<value><int>1</int></value>\n</member>\n</struct></value>\n</data></array></value>\n</member>\n</struct></value>\n</param>\n</params>\n</methodCall>\n", 'version': 2, 'id': 88}
D: handle_action actionid = 88, version = 2
D: do_call configfiles.deploy({'files': [{'config_channel': 'jhutar-test', 'username': 'root', 'encoding': '', 'checksum': '', 'filetype': 'directory', 'delim_start': '', 'modified': '', 'symlink': '', 'groupname': 'root', 'delim_end': '', 'selinux_ctx': '', 'filemode': 644, 'file_contents': '', 'checksum_type': '', 'path': '/tmp/aaa', 'revision': 1}, {'config_channel': 'jhutar-test', 'username': 'root', 'encoding': 'base64', 'checksum': 'aa3a5ce5191d853e7c9c166a3924bfe3', 'filetype': 'file', 'delim_start': '{|', 'modified': '', 'symlink': '', 'groupname': 'root', 'delim_end': '|}', 'selinux_ctx': '', 'filemode': 644, 'file_contents': 'UG9zdGF2ZW7DrSBSb23FryBzZSB2IMSMZXNrdSBwcnVkY2UgemhvcsWhdWplLCB0dnJkw60genBy\nw6F2YSBoZWxzaW5za8OpaG8gdsO9Ym9ydQ==\n', 'checksum_type': 'md5', 'path': '/tmp/bbb', 'revision': 1}]},){'cache_only': None}
does not have permissions to create file  /var/log/rhncfg-actions
D: Sending back response((6,), 'Fatal error in Python code occured', {})
D: do_call packages.checkNeedUpdate('rhnsd=1',){}
Loaded plugins: product-id, rhnplugin
D: rpcServer: Calling XMLRPC up2date.listChannels
This system is receiving updates from RHN Classic or RHN Satellite.
D: local action status: (0, 'rpm database not modified since last update (or package list recently updated)', {})
D: rpcServer: Calling XMLRPC registration.welcome_message


Expected results:
There should be no problem.


Additional info:
up2date log says:
[Tue Sep 10 12:46:04 2013] up2date D: do_call configfiles.deploy({'files': [{'config_channel': 'jhutar-test', 'username': 'root', 'encoding': '', 'checksum': '', 'filetype': 'directory', 'delim_start': '', 'modified': '', 'symlink': '', 'groupname': 'root', 'delim_end': '', 'selinux_ctx': '', 'filemode': 644, 'file_contents': '', 'checksum_type': '', 'path': '/tmp/aaa', 'revision': 1}, {'config_channel': 'jhutar-test', 'username': 'root', 'encoding': 'base64', 'checksum': 'aa3a5ce5191d853e7c9c166a3924bfe3', 'filetype': 'file', 'delim_start': '{|', 'modified': '', 'symlink': '', 'groupname': 'root', 'delim_end': '|}', 'selinux_ctx': '', 'filemode': 644, 'file_contents': 'UG9zdGF2ZW7DrSBSb23FryBzZSB2IMSMZXNrdSBwcnVkY2UgemhvcsWhdWplLCB0dnJkw60genBy\nw6F2YSBoZWxzaW5za8OpaG8gdsO9Ym9ydQ==\n', 'checksum_type': 'md5', 'path': '/tmp/bbb', 'revision': 1}]},){'cache_only': None}
[Tue Sep 10 12:46:04 2013] up2date 
Traceback (most recent call last):
  File "/usr/sbin/rhn_check", line 338, in __run_action
    (status, message, data) = CheckCli.__do_call(method, params, kwargs)
  File "/usr/sbin/rhn_check", line 331, in __do_call
    retval = method(*params, **kwargs)
  File "/usr/share/rhn/actions/configfiles.py", line 309, in deploy
    log_to_file(0, "Files successfully deployed: %s %s" % (format_file_string(files, create_key_list()), str(extras)))
  File "/usr/share/rhn/config_common/rhn_log.py", line 109, in log_to_file
    return apply(Logger().log_to_file, args)
  File "/usr/share/rhn/config_common/rhn_log.py", line 45, in log_to_file
    self.write_to_logfile(outstr)
  File "/usr/share/rhn/config_common/rhn_log.py", line 65, in write_to_logfile
    sys.exit(1)
<type 'exceptions.SystemExit'>: 1


I have tried with currently released rhncfg-5.10.27-13.el5sat packages and it worked, so this is probably a regression.

Comment 1 Tomas Lestach 2013-09-11 10:23:45 UTC
/var/log/rhncfg-actions are part of the rhncfg-actions rpm:

# rpm -ql rhncfg-actions | grep log
/var/log/rhncfg-actions

Generally it's not a good idea to delete files/directories that came together with an rpm.

Comment 2 Jan Hutař 2013-09-11 10:44:44 UTC
During rhn_check no AVC is logged.

Comparing rhn_log.py from 5.10.27-13.el6sat and 5.10.55-2.el6sat, this is a diff with changes in the function mentioned in the log:

--- /usr/share/rhn/config_common/rhn_log.py.OLD	2013-09-11 06:37:38.000000000 -0400
+++ /usr/share/rhn/config_common/rhn_log.py	2013-08-28 14:32:34.000000000 -0400
@@ -1,5 +1,5 @@
 #
-# Copyright (c) 2008 Red Hat, Inc.
+# Copyright (c) 2008--2013 Red Hat, Inc.
 #
 # This software is licensed to you under the GNU General Public License,
 # version 2 (GPLv2). There is NO WARRANTY for this software, express or
@@ -14,6 +14,7 @@
 #
 
 import os
+import stat
 import sys
 import time
 import string
@@ -47,16 +48,21 @@
     def write_to_logfile(self, logstr):
         if os.access(self.logfile, os.F_OK|os.R_OK|os.W_OK):
             logname = open(self.logfile, "a")
+            logname.write(logstr)
+            logname.close()
         else:
             #pkilambi: bug#179367: check permissions before writing.
             #non-root users will not have permissions to create the file
+
+            # Set to root-RW-only if we have to create the file
+            mode = stat.S_IRUSR | stat.S_IWUSR  # octal 0o600
             try:
-                logname = open(self.logfile, "w")
+                fd = os.fdopen(os.open(self.logfile, os.O_WRONLY | os.O_CREAT, mode), 'w')
+                os.write(fd, logstr)
+                os.close(fd)
             except:
                 print "does not have permissions to create file  %s" % (self.logfile)
                 sys.exit(1)
-        logname.write(logstr)
-        logname.close()
     
     def set_logfile(self, filename):
         Logger.logfile = filename

Comment 3 Jan Hutař 2013-09-11 10:48:42 UTC
(In reply to Tomas Lestach from comment #1)
> /var/log/rhncfg-actions are part of the rhncfg-actions rpm:
> 
> # rpm -ql rhncfg-actions | grep log
> /var/log/rhncfg-actions
> 
> Generally it's not a good idea to delete files/directories that came
> together with an rpm.

Although the file is part of this rpm, it is not created in install time:

# yum remove rhncfg\* -y
[...]
# rm /var/log/rhncfg-actions 
rm: cannot lstat `/var/log/rhncfg-actions': No such file or directory
# yum install rhncfg\* -y --nogpgcheck
[...]
# rpm -qa rhncfg\*
rhncfg-management-5.10.55-2.el5sat
rhncfg-5.10.55-2.el5sat
rhncfg-client-5.10.55-2.el5sat
rhncfg-actions-5.10.55-2.el5sat
# ll /var/log/rhncfg-actions
ls: /var/log/rhncfg-actions: No such file or directory

Comment 4 Clifford Perry 2013-09-11 11:05:01 UTC
Commit/change was: 
https://git.fedorahosted.org/cgit/spacewalk.git/commit/client/tools/rhncfg/config_common/rhn_log.py?id=9f89d22a515a710ceaadd475a000d3827061c2ae


951243 - Let remote-cmds log to the local machine in addition to sending results back to SW


Which maps back to ON_QA Sat 5.6 RFE: 

Bug 579885 - [RFE] log the remote command results on the machine that runs them


Cliff

Comment 5 Tomas Lestach 2013-09-11 11:26:59 UTC
> Although the file is part of this rpm, it is not created in install time:

Correct, it's a ghost file:
$ grep log/rhncfg-actions client/tools/rhncfg/rhncfg.spec | grep attr
%ghost %attr(600,root,root) %{_localstatedir}/log/rhncfg-actions

In that case it's much more serious.

Comment 8 Martin Korbel 2013-09-18 13:01:39 UTC
VERIFIED on rhncfg-5.10.55-5.el5sat

Reproduce steps are in comment 0.

Comment 10 Clifford Perry 2013-10-01 19:59:16 UTC
This bug was fixed with updated packages being released within the RHN Tools channels. 


RHN Tools (for Sat 5.6 GA) Errata text:

https://rhn.redhat.com/errata/RHEA-2013-1391.html