Bug 885446

Summary: restart engine-notifierd service follow linux error.
Product: Red Hat Enterprise Virtualization Manager Reporter: Ilanit Stein <istein>
Component: ovirt-engine-notification-serviceAssignee: Greg Padgett <gpadgett>
Status: CLOSED CURRENTRELEASE QA Contact: Ilanit Stein <istein>
Severity: low Docs Contact:
Priority: unspecified    
Version: 3.1.0CC: amureini, bazulay, dyasny, iheim, Rhev-m-bugs, sgrinber, ykaul, yzaslavs
Target Milestone: ---   
Target Release: 3.2.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: infra
Fixed In Version: sf7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 910603 (view as bug list) Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Infra RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 910603, 915537    

Description Ilanit Stein 2012-12-09 14:46:51 UTC 
Description of problem:

When moving to DEBUG mode in /etc/ovirt-engine/notifier/log4j.xml,
After notifier service restart, linux error appear:
"find: failed to restore initial working directory: Permission denied"


Log:
===
> [root@lilach-rhel ~]# vi /etc/ovirt-engine/notifier/log4j.xml (set mode to DEBUG)


> [root@lilach-rhel ~]# /etc/rc.d/init.d/engine-notifierd restart

Printed on cli screen as response to the restart:

> Stopping engine-notifier:                                  [  OK  ]
> Starting engine-notifier: at Tue Dec  4 16:59:46 IST 2012find: failed to
> restore initial working directory: Permission denied find: failed to
> restore initial working directory: Permission denied find: failed to
> restore initial working directory: Permission denied find: failed to
> restore initial working directory: Permission denied find: failed to
> restore initial working directory: Permission denied [  OK  ]


> [root@lilach-rhel ~]# DEBUG: JavaMail version 1.4.4-redhat-1
> DEBUG: successfully loaded resource: /META-INF/javamail.default.providers
> DEBUG: Tables of loaded providers
> DEBUG: Providers Listed By Class Name:
> {com.sun.mail.smtp.SMTPSSLTransport=javax.mail.Provider[TRANSPORT,smtps,com
> .sun.mail.smtp.SMTPSSLTransport,Sun Microsystems, Inc],
> com.sun.mail.smtp.SMTPTransport=javax.mail.Provider[TRANSPORT,smtp,com.sun.
> mail.smtp.SMTPTransport,Sun Microsystems, Inc],
> com.sun.mail.imap.IMAPSSLStore=javax.mail.Provider[STORE,imaps,com.sun.mail
> .imap.IMAPSSLStore,Sun Microsystems, Inc],
> com.sun.mail.pop3.POP3SSLStore=javax.mail.Provider[STORE,pop3s,com.sun.mail
> .pop3.POP3SSLStore,Sun Microsystems, Inc],
> com.sun.mail.imap.IMAPStore=javax.mail.Provider[STORE,imap,com.sun.mail.ima
> p.IMAPStore,Sun Microsystems, Inc],
> com.sun.mail.pop3.POP3Store=javax.mail.Provider[STORE,pop3,com.sun.mail.pop
> 3.POP3Store,Sun Microsystems, Inc]} DEBUG: Providers Listed By Protocol:
> {imaps=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Sun
> Microsystems, Inc],
> imap=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Sun
> Microsystems, Inc],
> smtps=javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTranspor
> t,Sun Microsystems, Inc],
> pop3=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Sun
> Microsystems, Inc],
> pop3s=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Sun
> Microsystems, Inc],
> smtp=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Sun
> Microsystems, Inc]} DEBUG: successfully loaded resource:
> /META-INF/javamail.default.address.map
Comment 1 Yair Zaslavsky 2012-12-30 11:25:07 UTC 
Are you sure this relates to setting to debug? what happens when you set back to info?
Comment 2 Ilanit Stein 2012-12-31 12:26:27 UTC 
The linux error "find: failed to restore initial working directory: Permission denied" appear for all priority levels (DEBUG, INFO, ERROR).
for DEBUG level,

Messages "DEBUG: JavaMail version 1.4.4-redhat-1
> DEBUG: successfully loaded resource: /META-INF/javamail.default.providers ..."
from the above bug description appear only for DEBUG priority level.

Bug subject has been changed accordingly.
Comment 3 Barak 2013-01-02 14:22:19 UTC 
Is it a file permissions issue ?
What are the permissions of: 

/etc/ovirt-engine/notifier
/etc/ovirt-engine/notifier/log4j.xml
/etc/ovirt-engine/notifier/notifier.conf
Comment 4 Ilanit Stein 2013-01-16 09:38:35 UTC 
drwxr-xr-x. 2 root  root  4096 Jan  8 15:43 notifier
-rw-r-----. 1 ovirt ovirt 3106 Dec 26 15:59 notifier.conf
-rw-r--r--. 1 root  root  1320 Dec 26 15:59 log4j.xml
Comment 5 Greg Padgett 2013-02-06 17:59:02 UTC 
(In reply to comment #2)
> The linux error "find: failed to restore initial working directory:
> Permission denied" appear for all priority levels (DEBUG, INFO, ERROR).
> for DEBUG level,

I was able to reproduce this; it's due to the init script executing `find` as user ovirt from root's home directory.  I've submitted a simple fix to upstream, linked in the ovirt gerrit tracker.

> Messages "DEBUG: JavaMail version 1.4.4-redhat-1
> > DEBUG: successfully loaded resource: /META-INF/javamail.default.providers ..."
> from the above bug description appear only for DEBUG priority level.

Can you attach your /etc/ovirt-engine/notifier/log4j.xml file?
Comment 6 Ilanit Stein 2013-02-07 06:21:32 UTC 
/etc/ovirt-engine/notifier/log4j.xml 
(priority set by priority value="INFO","DEBUG", "ERROR"):
====================================================================
<?xml version="1.0" encoding="UTF-8"?><!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/" debug="false">

    <!-- Log levels:DEBUG,INFO,WARN,ERROR,FATAL -->
    <appender name="FILE" class="org.apache.log4j.RollingFileAppender">
        <param name="File" value="/var/log/ovirt-engine/notifier/notifier.log" />
        <param name="Append" value="true" />
        <param name="MaxFileSize" value="10000KB" />
        <param name="MaxBackupIndex" value="5" />

        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d %-5p [%c] %m%n" />
            <!--  <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}] %m%n" /> -->

        </layout>
    </appender>

    <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
        <param name="Target" value="System.out" />
        <layout class="org.apache.log4j.PatternLayout">
            <!-- The default pattern: Date Priority [Category] Message\n -->
            <param name="ConversionPattern" value="%d %-5p [%c] (%t) %m%n" />
        </layout>
    </appender>

    <root>
        <priority value="INFO" />
        <!-- appender-ref ref="CONSOLE" /-->
        <appender-ref ref="FILE" />
    </root>

</log4j:configuration>
Comment 7 Greg Padgett 2013-02-12 23:26:51 UTC 
New bug 910603 was cloned from this one to split up the 2 issues here:
this bug - "find" error printed to terminal upon notifier startup
bug 910603 - JavaMail debug output printed to terminal upon notifier startup
Comment 8 Greg Padgett 2013-02-12 23:33:29 UTC 
Merged change id: I83622cbb8b39ea5792907e6efc68d824ca4b02da
Comment 9 Itamar Heim 2013-06-11 09:09:54 UTC 
3.2 has been released
Comment 10 Itamar Heim 2013-06-11 09:10:02 UTC 
3.2 has been released
Comment 11 Itamar Heim 2013-06-11 09:37:47 UTC 
3.2 has been released