[JIRA] Commented: (SSPCPP-523) Strange behaviour of native log

[Scott Cantor (JIRA)]

    [ https://issues.shibboleth.net/jira/browse/SSPCPP-523?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14560#comment-14560 ] 

Scott Cantor commented on SSPCPP-523:
-------------------------------------

I verified I get more or less what you saw in your native.log on the shibboleth.net server, which is CentOS 5.

I'm not clear on what the difference is, but could you find out if the server having a problem is running in prefork mode? My only guess is that this is broken in that mode, because I can't think of any other difference that might exist. My server has no special access, /var/log/httpd is limited to root, and all the log files are owned by root.

> Strange behaviour of native log 
> --------------------------------
>
>                 Key: SSPCPP-523
>                 URL: https://issues.shibboleth.net/jira/browse/SSPCPP-523
>             Project: Shibboleth SP - C++
>          Issue Type: Bug
>            Reporter: Lukas Haemmerle
>            Assignee: Scott Cantor
>            Priority: Minor
>
> One of our universities observed some strange behaviour of the native.log. With RedHat 5 they only hardly get any entries besides the ones below when starting the SP:
> 	2012-11-04 20:27:12 INFO XMLTooling.Config : xmltooling 1.5.1 library initialization complete
> 	2012-11-04 20:27:12 INFO Shibboleth.Config : shibboleth 2.5.0 library initialization complete
> 	2012-11-04 20:27:12 INFO Shibboleth.Config : shibboleth 2.5.0 library shutting down
> 	2012-11-04 20:27:12 INFO XMLTooling.Config : xmltooling 1.5.1 library shutdown complete
> 	2012-11-04 20:27:12 INFO Shibboleth.Config : shibboleth 2.5.0 library shutdown complete
> 	2012-11-04 20:27:12 INFO XMLTooling.Config : xmltooling 1.5.1 library initialization complete
> 	2012-11-04 20:27:12 INFO Shibboleth.Config : shibboleth 2.5.0 library initialization complete
> 	2012-11-04 20:27:12 INFO Shibboleth.Config : reload thread started...running when signaled
> 	2012-11-04 20:27:12 INFO Shibboleth.Config : reload thread started...running when signaled
> However, there should be more entries than this (in my centos 5 installation about 191 INFO entries)
> So, they added <InProcess logger="native.logger"/> to shibboleth2.xml, which by default is not included.
> This then results in the following CRIT entries:
> 	2012-11-04 20:55:04 CRIT XMLTooling.Logging : error in file permissions or logging configuration: exception creating appender: failed to open log file (/var/log/httpd/native.log)
> 	2012-11-04 20:55:04 CRIT Shibboleth.Config : failed to load new logging configuration from (native.logger)
> However, the file /var/log/httpd/native.log exists with root:root 644. It also does not play a difference if the native.log is written to /tmp/. Same result. Also, in this case the log rotation does not work and the log file grows larger and larger. After a while one will find exclusively entries like these:
> 	2012-11-07 13:46:17 INFO Shibboleth.Config : loaded XML resource (/etc/shibboleth/shibboleth2.xml)
> 	2012-11-07 13:46:45 INFO Shibboleth.Config : reload thread started...running when signaled
> Something else they observed are many entries like:
> 2012-11-06 04:25:46 WARN Shibboleth.ServiceProvider [27347] shib_check_user: can't export assertions without an exportLocation Sessions property
> Is it justified to make these WARN entries if exportAssertion is not used at all?

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira