Is log4j and Ice.logger conflict ?

[zhaoningbo]

Hi all,

My application has used log4j(slf4j) as logger. When I use 'java com.Test' to run the Demo, the logger file with directory together be created automatically. However, when I use 'icegridnode --Ice.Config=demo.config' to start Ice-Server, the request of Ice-Client cause a 'log4j:ERROR'.

So, I want to confirm, whether should I do some works on combining both to one, just following Ice.Logger, or do not have to do that because they do not conflict.

log4j.properties and the error in the console as following:

log4j.appender.logfile=org.apache.log4j.DailyRollingFileAppender
log4j.appender.logfile.File=/opt/demo/logs/demo.log
log4j.appender.logfile.DatePattern=.yyyy-MM-dd
log4j.appender.logfile.layout=org.apache.log4j.PatternLayout
log4j.appender.logfile.layout.ConversionPattern=%d %p [%c] - <%m>%n

-- 09/27/11 11:35:29.812 icegridnode: Activator: activating server `DemoIceBoxNode1'
log4j:ERROR setFile(null,true) call failed.
java.io.FileNotFoundException: /opt/demo/logs/demo.log (Permission denied)
        at java.io.FileOutputStream.openAppend(Native Method)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:177)
        at java.io.FileOutputStream.<init>(FileOutputStream.java:102)
        at org.apache.log4j.FileAppender.setFile(FileAppender.java:290)
... ...
        at IceBox.ServiceManagerI.start(ServiceManagerI.java:608)
        at IceBox.ServiceManagerI.run(ServiceManagerI.java:353)
        at IceBox.Server.run(Server.java:54)
        at Ice.Application.doMain(Application.java:202)
        at Ice.Application.main(Application.java:182)
        at IceBox.Server.main(Server.java:32)
log4j:ERROR Either File or DatePattern options are not set for appender [logfile].

Is there any 'Best Practice' for 'log4j' in ice java project ? I've finished reading 2 article searched by using keywords 'log4j', and falled into this wonder.

Best Regards

Thks

[bernard]

Hello,

You can use log4j with Ice. The issue here appears to be a permission problem:

java.io.FileNotFoundException: /opt/demo/logs/demo.log (Permission denied)

If you are running icegridnode as root, it will start servers as 'nobody' by default, which would explain this permission problem.

And if you are running icegridnode as a service using a non-root account, check that the user-account running icegridnode has read-write access to your log file.

Best regards,
Bernard

[zhaoningbo]

Hi bernard,

Thanks for your reply ! I have confirmed the authority is 'root'.

[root@WEB01 logs]# ps aux|grep ice
root      2212  0.0  0.0  61164   740 pts/1    S+   08:20   0:00 grep ice
root      3866  0.0  0.0   6452   380 ?        Ss   Jun23   0:00 gpm -m /dev/input/mice -t exps2
root     32004  0.0  0.0 271068 10828 ?        Sl   Sep27   0:00 icegridnode --Ice.Config=node115.config
[root@WEB01 logs]# ls -l
total 4
-rw-r--r-- 1 root root 57 09-27 09:08 demo.log
[root@WEB01 logs]# whoami
root
[root@WEB01 logs]#

I delete the 'logs' directory to give log4j a chance which may create 'logs/demo.log' itself, but the starting still faild as following

-- 09/28/11 08:30:55.394 icegridnode: Activator: activating server `DemoIceBoxNode1'
log4j:ERROR setFile(null,true) call failed.
java.io.FileNotFoundException: /opt/logs/demo.log (No such file or directory)
        at java.io.FileOutputStream.openAppend(Native Method)

I often make Logger references to a new path when use log4j, and I guess 'No such file or directory' is normal, because this file with directory will be created by log4j automatically...

Best Regards

Zhaoningbo

[bernard]

This permission error occurs because your server (_not_ icegridnode), launched by icegridnode, is running as user 'nobody', and not root, and fails to create this log file.

This run-as-nobody by default is just a safety measure, as you typically don't need or want to run your servers as root.

User nobody has limited privileges and most likely can't traverse to /opt/logs, or create a file in that directory.

You can fix this by:
- running icegridnode as a non-root user with read/write access to /opt/logs
in this case, the server with run as this non-root user

- changing the permissions on /opt/logs to allow nobody to create a log file in there

or
- keeping icegridnode as root and instruct icegridnode to start the server as a user with sufficient permissions on /opt/logs (for example: root). Simply set the user attribute in your server descriptor: Server Descriptor Element - Ice 3.4 - ZeroC

Best regards,
Bernard

[zhaoningbo]

Hi Bernard,

Thank you very much !

Now, I see that the focus of this issue is 'User' & 'Permission'. Just now, I have read Server Descriptor Element. but my DemoApp does not use 'Server' to deployment as following:

<icegrid>
    <application name="cepsApp">
        <service-template id="DemoService">
            <parameter name="name" />
            <service name="${name}"
                entry="com.DemoService">
                <properties>
                    <property name="Demo.Identity" value="demo" />
                </properties>
                <adapter name="demoAdapter-${name}" endpoints="default"
                    id="demoAdapter-${name}" replica-group="DemoGroup"
                    server-lifetime="false" />
            </service>
        </service-template>
        <replica-group id="DemoGroup">
            <load-balancing type="round-robin" n-replicas="1" />
            <object identity="demo"
                type="com::Demo" />
        </replica-group>
        
        <!-- WEB01:10.1.90.115 -->
        <node name="node1">
	        <icebox id="DemoIceBoxNode1" activation="on-demand"
                exe="java">
                <option>IceBox.Server</option>
                <properties>
                    <property name="IceBox.InstanceName" value="${server}" />
                    <property name="Ice.Admin.Endpoints" value="tcp -h 10.1.90.115" />
                    <property name="IceBox.Trace.ServiceObserver" value="1" />
                </properties>
                <service-instance template="DemoService"
                    name="DemoNode1First" />
	        </icebox>
        </node>
    </application>
</icegrid>

and Ice-register-node-config as following:

#
# The IceGrid instance name.
#
IceGrid.InstanceName=demoPlugin

#
# The IceGrid locator proxy.
#
Ice.Default.Locator=demoPlugin/Locator:default -h 10.1.90.115 -p 4061

#
# IceGrid registry configuration.
#
IceGrid.Registry.Client.Endpoints=default -p 4061
IceGrid.Registry.Server.Endpoints=default
IceGrid.Registry.Internal.Endpoints=default

#
# Enable the admin session manager for use with Glacier2.
#
IceGrid.Registry.AdminSessionManager.Endpoints=default

IceGrid.Registry.Data=db/registry
IceGrid.Registry.PermissionsVerifier=demoPlugin/NullPermissionsVerifier
IceGrid.Registry.AdminPermissionsVerifier=demoPlugin/NullPermissionsVerifier
IceGrid.Registry.SSLPermissionsVerifier=demoPlugin/NullSSLPermissionsVerifier
IceGrid.Registry.AdminSSLPermissionsVerifier=demoPlugin/NullSSLPermissionsVerifier

#
# IceGrid node configuration.
#
IceGrid.Node.Name=node1
IceGrid.Node.Endpoints=default
IceGrid.Node.Data=db/node
IceGrid.Node.CollocateRegistry=1
#IceGrid.Node.Output=db
#IceGrid.Node.RedirectErrToOut=1

#
# Trace properties.
#
IceGrid.Node.Trace.Activator=1
#IceGrid.Node.Trace.Adapter=2
#IceGrid.Node.Trace.Server=3

#
# Dummy username and password for icegridadmin.
#
IceGridAdmin.Username=foo
IceGridAdmin.Password=bar

#
# Print debug informations
#
Ice.Trace.Network=2
Ice.Trace.Locator=2
Ice.Trace.Retry=1

I've try to put '<user value="root"></user>' into '<node></node>', add 'IceGrid.Node.UserAccounts' into config file, but All failed.

How should I do ?

Thanks a lot, Bernard

Zhaoningbo

[zhaoningbo]

Hi Bernard,

Under your guidance, I've fixed it as this:

1, add an user named 'demo' in my OS-rhel5. And chmod it './logs' owner permission;

2, add an attribute 'user="demo"' into '<icebox />'(in file 'application.xml' deployment by Ice-gird-box) which just like this:

<icegrid>
    <application name="demoApp">
    ... ...
        <!-- WEB01:10.1.90.115 -->
        <node name="node1">
	        <icebox id="ValidatorIceBoxNode1" activation="on-demand" user="demo"
                exe="java">
        ... ...

Now, My DemoApp's IceBox.Server runs on 'demo' user, and the Logger is running very well.

Thank you, Bernard !

Best Regards

Zhaoningbo

[bernard]

Hi Zhaoningbo,

Glad to hear you figured it out.

In your case, the server is an icebox server, and an icebox descriptor supports the same attributes as a server descriptor, in particular the 'user' attribute.

You could also use the IceGrid Admin tool, which would show all these attributes as fields.

Best regards,
Bernard

[zhaoningbo]

Hi bernard,

Thank you very much !

Yes,it is. I've find the 'user' attribute after the 'Run as' just in 'DemoApp -> Nodes -> node1 -> DemoIceBoxNode1' of IceGridAdmin GUI.

Thanks again ~.~

Best Wishes

Zhaoningbo