<div dir="ltr">I have similar issue on one of my IdP servers, though all of them are similar. Everything is checked out fro SVN. <div>But there are few differences from your case. I use IdP 3.1.2 and only idp-process.log is affected. The newly created log file has records only related to the sealer key rotation.<div><br></div><div>
<p class=""><span class="">2015-12-15 23:41:08,835 - INFO [net.shibboleth.utilities.java.support.security.BasicKeystoreKeyStrategy:327] - Default key version has not changed, still secret6</span></p><p class="">2015-12-15 23:56:08,834 - INFO [net.shibboleth.utilities.java.support.security.BasicKeystoreKeyStrategy:327] - Default key version has not changed, still secret6</p><p class=""><span class="">Restarting Jetty/IdP solves the issue. </span></p></div></div></div><div class="gmail_extra"><br><div class="gmail_quote">On Fri, Dec 18, 2015 at 4:30 PM, Jeffrey Eaton <span dir="ltr"><<a href="mailto:jeaton@cmu.edu" target="_blank">jeaton@cmu.edu</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">I just came across an unusual log rotation bug with IDP v3.2.0.<br>
<br>
Something happened in the IDP which caused it to create these files:<br>
<br>
Dec 18 15:10 idp-process.log<br>
Dec 18 16:21 idp-process.log598435536912956.tmp<br>
Dec 18 15:10 idp-warn.log<br>
Dec 18 11:48 idp-warn.log598435701916956.tmp<br>
<br>
<br>
Interestingly, it looks like at 15:10, it renamed the files to the .tmp names, and opened new files. Then, after writing a few lines to the new file, things switched back to being appended to the files with the .tmp names. The only things in the idp-process.log and idp-warn.log files are a few entries, all in the 15:10 minute. The .tmp files contain everything prior to, and after that minute (but nothing during the 15:10 minute itself).<br>
<br>
Right around that moment, we had an LDAP server crash, which may be related. The entries in the .log files contain just the errors about the LDAP pool:<br>
<br>
2015-12-18 15:10:03,992 - WARN [org.ldaptive.pool.BlockingConnectionPool:808] - connection failed validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@2f610ca4<br>
2015-12-18 15:10:03,995 - WARN [org.ldaptive.pool.BlockingConnectionPool:808] - connection failed validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@6e5e02ad<br>
2015-12-18 15:10:04,005 - WARN [org.ldaptive.pool.BlockingConnectionPool:808] - connection failed validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@5ffac6e2<br>
2015-12-18 15:10:04,024 - ERROR [org.ldaptive.pool.BlockingConnectionPool:310] - validation task failed for [org.ldaptive.pool.BlockingConnectionPool@1540597622::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@910152844::minPoolSize=3, maxPoolSize=10,<br>
validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=1800], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@208490607::searchRequest=[org.ldaptive.SearchRequest@1431755003::baseDn=dc=cm<br>
,dc=edu, searchFilter=[org.ldaptive.SearchFilter@-1126260291::filter=objectClass=*, parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, se<br>
rchEntryHandlers=null, searchReferenceHandlers=null, controls=null, followReferrals=false, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@46268698::prunePeriod=300, idleTime=600], connectOnCreate=true, connectionFac<br>
ory=[org.ldaptive.DefaultConnectionFactory@1682622213::provider=org.ldaptive.provider.jndi.JndiProvider@16cbd173, config=[org.ldaptive.ConnectionConfig@1427384267::ldapUrl=ldaps://<a href="http://ldap.cmu.edu:636" rel="noreferrer" target="_blank">ldap.cmu.edu:636</a>, connectTimeout=-1, responseTimeout=-1, sslConfig=[org.lda<br>
tive.ssl.SslConfig@1906615546::credentialConfig=org.ldaptive.ssl.CredentialConfigFactory$2@422073a0, trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=false, useStartTLS=false, connectionInitial<br>
zer=[org.ldaptive.BindConnectionInitializer@1242784182::bindDn=uid=compserv-shibboleth-prod,ou=specials,dc=cmu,dc=edu, bindSaslConfig=null, bindControls=null]]], initialized=true, availableCount=0, activeCount=0]<br>
2015-12-18 15:10:04,166 - WARN [org.ldaptive.pool.BlockingConnectionPool:808] - connection failed validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@7f73f3cc<br>
2015-12-18 15:10:04,168 - WARN [org.ldaptive.pool.BlockingConnectionPool:808] - connection failed validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@3e4efe05<br>
2015-12-18 15:10:04,175 - WARN [org.ldaptive.pool.BlockingConnectionPool:808] - connection failed validation: org.ldaptive.pool.AbstractConnectionPool$DefaultPooledConnectionProxy@f3adea8<br>
2015-12-18 15:10:04,200 - ERROR [org.ldaptive.pool.BlockingConnectionPool:310] - validation task failed for [org.ldaptive.pool.BlockingConnectionPool@865402979::name=null, poolConfig=[org.ldaptive.pool.PoolConfig@1764378042::minPoolSize=3, maxPoolSize=10,<br>
validateOnCheckIn=false, validateOnCheckOut=false, validatePeriodically=true, validatePeriod=1800], activator=null, passivator=null, validator=[org.ldaptive.pool.SearchValidator@1168114438::searchRequest=[org.ldaptive.SearchRequest@1431755003::baseDn=dc=c<br>
u,dc=edu, searchFilter=[org.ldaptive.SearchFilter@-1126260291::filter=objectClass=*, parameters={}], returnAttributes=[1.1], searchScope=OBJECT, timeLimit=0, sizeLimit=1, derefAliases=null, typesOnly=false, binaryAttributes=null, sortBehavior=UNORDERED, s<br>
archEntryHandlers=null, searchReferenceHandlers=null, controls=null, followReferrals=false, intermediateResponseHandlers=null]] pruneStrategy=[org.ldaptive.pool.IdlePruneStrategy@1777388116::prunePeriod=300, idleTime=600], connectOnCreate=true, connection<br>
actory=[org.ldaptive.DefaultConnectionFactory@1929206033::provider=org.ldaptive.provider.jndi.JndiProvider@49c1c561, config=[org.ldaptive.ConnectionConfig@1441003144::ldapUrl=ldaps://<a href="http://ldap.cmu.edu:636" rel="noreferrer" target="_blank">ldap.cmu.edu:636</a>, connectTimeout=-1, responseTimeout=-1, sslConfig=[org.<br>
daptive.ssl.SslConfig@1118499005::credentialConfig=org.ldaptive.ssl.CredentialConfigFactory$2@1d25dd6a, trustManagers=null, enabledCipherSuites=null, enabledProtocols=null, handshakeCompletedListeners=null], useSSL=false, useStartTLS=false, connectionInit<br>
alizer=[org.ldaptive.BindConnectionInitializer@9118940::bindDn=uid=compserv-shibboleth-prod,ou=specials,dc=cmu,dc=edu, bindSaslConfig=null, bindControls=null]]], initialized=true, availableCount=0, activeCount=0]<br>
<br>
<br>
Both files are identical.<br>
<br>
Could there be a bug with log handling relating to the LDAP pooling somehow?<br>
<br>
-jeaton<br>
<span class="HOEnZb"><font color="#888888"><br>
<br>
--<br>
To unsubscribe from this list send an email to <a href="mailto:users-unsubscribe@shibboleth.net">users-unsubscribe@shibboleth.net</a><br>
</font></span></blockquote></div><br><br clear="all"><div><br></div>-- <br><div class="gmail_signature"><div dir="ltr"><font size="2"><span title="yy27" style="padding:0px;border:0px none;list-style-type:none;color:rgb(0,0,0);font-family:verdana,arial,helvetica,sans-serif;line-height:16px"><span style="padding:0px;border:0px none;list-style-type:none">Yavor Yanakiev</span> </span><br style="padding:0px;border:0px none;list-style-type:none;color:rgb(0,0,0);font-family:verdana,arial,helvetica,sans-serif;line-height:16px"><span style="padding:0px;border:0px none;list-style-type:none;color:rgb(0,0,0);font-family:verdana,arial,helvetica,sans-serif;line-height:16px">Systems Developer for Identity Services</span></font><br><div>212-992-7585<br></div></div></div>
</div>