[Obm] Plus de synchronisation suite mise à jour en 2.4.1.2

Fri Nov 16 17:02:04 CET 2012

Bonjour Vince,

Aucune erreur n'apparait dans vos traces. Êtes vous certain que le 
serveur opush ait bien démarré ?

Sinon activez dans le logger /<logger 
name="org.obm.dbcp.DatabaseConnectionProviderImpl" level="DEBUG" />/ 
dans le fichier //etc/opush/logback.xml/.
Puis envoyez nous les traces générées dans le fichier de log 
//var/log/opush/opush.log/ ainsi que les logs jetty après avoir effectué 
un redémarrage.

Aussi veuillez vérifier que les entrées du fichier de configuration 
apache soit valide :

/ProxyPass /Microsoft-Server-ActiveSync 
http://127.0.0.1:8082/opush/ActiveSyncServlet/
ProxyPassReverse /Microsoft-Server-ActiveSync 
http://127.0.0.1:8082/opush/ActiveSyncServlet/
/
Que ce passe t'il quand vous essayez d'accéder directement à l'url 
d'opush via un navigateur ou wget ?

Merci,
Thomas

On 11/16/2012 02:45 PM, Vince wrote:
> Bonjour Matthieu,
>
> Et merci pour l'aide. J'ai fait le ménage dans les répertoires donnés et
> la synchro avec lightning fonctionne de nouveau.
>
> Par contre, je n'ai toujours pas de synchro avec les smartphones.
>
> Ci-dessous fichier log:
>
> /var/log/apache/obm-access.log
>
> 78.220.200.27 - - [16/Nov/2012:14:21:20 +0100] "POST
> /Microsoft-Server-ActiveSync?Cmd=Sync&User=cire.fr%5Cvboisseau&DeviceId=androidc876615970&DeviceType=Android
> HTTP/1.1" 404 1393
> 78.220.200.27 - - [16/Nov/2012:14:21:20 +0100] "POST
> /Microsoft-Server-ActiveSync?Cmd=Sync&User=cire.fr%5Cvboisseau&DeviceId=androidc876615970&DeviceType=Android
> HTTP/1.1" 404 1393
> 78.220.200.27 - - [16/Nov/2012:14:21:25 +0100] "POST
> /Microsoft-Server-ActiveSync?Cmd=Sync&User=cire.fr%5Cvboisseau&DeviceId=androidc876615970&DeviceType=Android
> HTTP/1.1" 404 1393
>
>
> /var/log/jetty/2012_11_16.stdout
>
> 2012-11-16 14:42:00.892:INFO::jetty-6.1.24
> 2012-11-16 14:42:00.921:INFO::Deploy /etc/jetty/contexts/javadoc.xml ->
> org.mortbay.jetty.handler.ContextHandler at 5caf993e{/javadoc,file:/usr/share/jetty/javadoc}
> 2012-11-16 14:42:00.997:INFO::NO JSP Support for /opush, did not find
> org.apache.jasper.servlet.JspServlet
> 14:42:01,027 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Could NOT find resource [logback.groovy]
> 14:42:01,028 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Could NOT find resource [logback-test.xml]
> 14:42:01,028 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Found resource [logback.xml] at
> [jar:file:/var/lib/jetty/webapps/opush/WEB-INF/lib/push-module-2.4.1.2.jar!/logback.xml]
> 14:42:01,041 |-INFO in
> ch.qos.logback.core.joran.spi.ConfigurationWatchList at 3c50507 - URL
> [jar:file:/var/lib/jetty/webapps/opush/WEB-INF/lib/push-module-2.4.1.2.jar!/logback.xml]
> is not of type file
> 14:42:01,165 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - debug
> attribute not set
> 14:42:01,170 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - Setting
> ReconfigureOnChangeFilter scanning period to 1 minutes
> 14:42:01,170 |-INFO in
> ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter at 7bcd107f - Will
> scan for changes in [[]] every 60 seconds.
> 14:42:01,170 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - Adding
> ReconfigureOnChangeFilter as a turbo filter
> 14:42:01,174 |-INFO in
> ch.qos.logback.core.joran.action.StatusListenerAction - Adding status
> listener of type [ch.qos.logback.core.status.OnConsoleStatusListener]
> 14:42:01,176 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.core.rolling.RollingFileAppender]
> 14:42:01,181 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [PROD]
> 14:42:01,206 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default type [ch.qos.logback.classic.PatternLayout] for [layout] property
> 14:42:01,238 |-WARN in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - This appender no
> longer admits a layout as a sub-component, set an encoder instead.
> 14:42:01,238 |-WARN in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - To ensure
> compatibility, wrapping your layout in LayoutWrappingEncoder.
> 14:42:01,238 |-WARN in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - See also
> http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
> 14:42:01,250 |-INFO in
> ch.qos.logback.core.rolling.FixedWindowRollingPolicy at 4cedf389 - No
> compression will be used
> 14:42:01,257 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - Active log file
> name: /var/log/opush/opush.log
> 14:42:01,257 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - File property is
> set to [/var/log/opush/opush.log]
> 14:42:01,258 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
> 14:42:01,260 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [STDOUT]
> 14:42:01,262 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default type [ch.qos.logback.classic.PatternLayout] for [layout] property
> 14:42:01,263 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] -
> This appender no longer admits a layout as a sub-component, set an
> encoder instead.
> 14:42:01,263 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To
> ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
> 14:42:01,263 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See
> also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
> 14:42:01,263 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.classic.sift.SiftingAppender]
> 14:42:01,267 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [SIFTING]
> 14:42:01,291 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for
> [discriminator] property
> 14:42:01,296 |-INFO in
> ch.qos.logback.core.joran.util.ConfigurationWatchListUtil at 34d507e9 -
> Adding [file:/etc/opush/logback.xml] to configuration watch list.
> 14:42:01,299 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction
> - Setting level of logger [org.obm.push.impl.ResponderImpl] to DEBUG
> 14:42:01,299 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction
> - Setting level of logger [org.obm.push.handler] to DEBUG
> 14:42:01,300 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction
> - Setting level of logger [org.obm.push.ActiveSyncServlet] to DEBUG
> 14:42:01,300 |-INFO in
> ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of
> ROOT logger to ERROR
> 14:42:01,300 |-INFO in
> ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender
> named [PROD] to Logger[ROOT]
> 14:42:01,027 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Could NOT find resource [logback.groovy]
> 14:42:01,028 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Could NOT find resource [logback-test.xml]
> 14:42:01,028 |-INFO in ch.qos.logback.classic.LoggerContext[default] -
> Found resource [logback.xml] at
> [jar:file:/var/lib/jetty/webapps/opush/WEB-INF/lib/push-module-2.4.1.2.jar!/logback.xml]
> 14:42:01,041 |-INFO in
> ch.qos.logback.core.joran.spi.ConfigurationWatchList at 3c50507 - URL
> [jar:file:/var/lib/jetty/webapps/opush/WEB-INF/lib/push-module-2.4.1.2.jar!/logback.xml]
> is not of type file
> 14:42:01,165 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - debug
> attribute not set
> 14:42:01,170 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - Setting
> ReconfigureOnChangeFilter scanning period to 1 minutes
> 14:42:01,170 |-INFO in
> ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter at 7bcd107f - Will
> scan for changes in [[]] every 60 seconds.
> 14:42:01,170 |-INFO in
> ch.qos.logback.classic.joran.action.ConfigurationAction - Adding
> ReconfigureOnChangeFilter as a turbo filter
> 14:42:01,174 |-INFO in
> ch.qos.logback.core.joran.action.StatusListenerAction - Adding status
> listener of type [ch.qos.logback.core.status.OnConsoleStatusListener]
> 14:42:01,176 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.core.rolling.RollingFileAppender]
> 14:42:01,181 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [PROD]
> 14:42:01,206 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default type [ch.qos.logback.classic.PatternLayout] for [layout] property
> 14:42:01,238 |-WARN in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - This appender no
> longer admits a layout as a sub-component, set an encoder instead.
> 14:42:01,238 |-WARN in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - To ensure
> compatibility, wrapping your layout in LayoutWrappingEncoder.
> 14:42:01,238 |-WARN in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - See also
> http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
> 14:42:01,250 |-INFO in
> ch.qos.logback.core.rolling.FixedWindowRollingPolicy at 4cedf389 - No
> compression will be used
> 14:42:01,257 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - Active log file
> name: /var/log/opush/opush.log
> 14:42:01,257 |-INFO in
> ch.qos.logback.core.rolling.RollingFileAppender[PROD] - File property is
> set to [/var/log/opush/opush.log]
> 14:42:01,258 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
> 14:42:01,260 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [STDOUT]
> 14:42:01,262 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default type [ch.qos.logback.classic.PatternLayout] for [layout] property
> 14:42:01,263 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] -
> This appender no longer admits a layout as a sub-component, set an
> encoder instead.
> 14:42:01,263 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To
> ensure compatibility, wrapping your layout in LayoutWrappingEncoder.
> 14:42:01,263 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See
> also http://logback.qos.ch/codes.html#layoutInsteadOfEncoder for details
> 14:42:01,263 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> About to instantiate appender of type
> [ch.qos.logback.classic.sift.SiftingAppender]
> 14:42:01,267 |-INFO in ch.qos.logback.core.joran.action.AppenderAction -
> Naming appender as [SIFTING]
> 14:42:01,291 |-INFO in
> ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming
> default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for
> [discriminator] property
> 14:42:01,296 |-INFO in
> ch.qos.logback.core.joran.util.ConfigurationWatchListUtil at 34d507e9 -
> Adding [file:/etc/opush/logback.xml] to configuration watch list.
> 14:42:01,299 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction
> - Setting level of logger [org.obm.push.impl.ResponderImpl] to DEBUG
> 14:42:01,299 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction
> - Setting level of logger [org.obm.push.handler] to DEBUG
> 14:42:01,300 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction
> - Setting level of logger [org.obm.push.ActiveSyncServlet] to DEBUG
> 14:42:01,300 |-INFO in
> ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of
> ROOT logger to ERROR
> 14:42:01,300 |-INFO in
> ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender
> named [PROD] to Logger[ROOT]
>
> 2012-11-16 14:42:02.343:INFO::NO JSP Support for , did not find
> org.apache.jasper.servlet.JspServlet
> 2012-11-16 14:42:02.363:INFO::NO JSP Support for /obm-locator, did not
> find org.apache.jasper.servlet.JspServlet
> 13:42:02.682 [main] DEBUG bitronix.tm.Configuration - loading default
> configuration
> 13:42:02.687 [main] INFO  b.tm.BitronixTransactionManager - Bitronix
> Transaction Manager version 2.1.0
> 13:42:02.688 [main] DEBUG b.tm.BitronixTransactionManager - JVM version
> 1.6.0_26
> 13:42:02.688 [main] INFO  bitronix.tm.Configuration - JVM unique ID:
> <obm-locator>
> 13:42:02.690 [main] DEBUG b.tm.BitronixTransactionManager - starting
> BitronixTransactionManager using a Configuration with
> [asynchronous2Pc=false, backgroundRecoveryInterval=1,
> backgroundRecoveryIntervalSeconds=60, currentNodeOnlyRecovery=true,
> defaultTransactionTimeout=60, disableJmx=true, filterLogStatus=false,
> forceBatchingEnabled=true, forcedWriteEnabled=true,
> gracefulShutdownInterval=60,
> jndiTransactionSynchronizationRegistryName=java:comp/TransactionSynchronizationRegistry,
> jndiUserTransactionName=java:comp/UserTransaction, journal=disk,
> logPart1Filename=/var/lib/obm-locator/obm-locator-btm1.tlog,
> logPart2Filename=/var/lib/obm-locator/obm-locator-btm2.tlog,
> maxLogSizeInMb=2, resourceConfigurationFilename=null,
> serverId=obm-locator, skipCorruptedLogs=false,
> warnAboutZeroResourceTransaction=true]
> 13:42:02.691 [main] DEBUG b.tm.TransactionManagerServices - using
> journal disk
> 13:42:02.692 [main] DEBUG bitronix.tm.journal.DiskJournal - disk journal
> files max length: 2097173
> 13:42:02.693 [main] DEBUG b.tm.journal.TransactionLogHeader - read
> header a Bitronix TransactionLogHeader with timestamp=1353066281103,
> state=UNCLEAN_LOG_STATE, position=21
> 13:42:02.693 [main] DEBUG b.tm.journal.TransactionLogAppender - spawning
> disk force batcher thread
> 13:42:02.694 [main] DEBUG b.tm.journal.TransactionLogHeader - read
> header a Bitronix TransactionLogHeader with timestamp=1353066281087,
> state=CLEAN_LOG_STATE, position=21
> 13:42:02.695 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceBatcherThread - disk force thread is up and running
> 13:42:02.695 [main] DEBUG bitronix.tm.journal.DiskJournal - logging to
> file 1: a TransactionLogAppender on obm-locator-btm1.tlog
> 13:42:02.695 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceBatcherThread - waiting for the wait queue to fill up
> 13:42:02.695 [main] DEBUG bitronix.tm.journal.DiskJournal - log file
> activated, forcing file state to disk
> 13:42:02.695 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceWaitQueue - waiting for some
> TransactionLogAppender to get enqueued
> 13:42:02.695 [main] DEBUG b.tm.journal.DiskForceWaitQueue - enqueued a
> TransactionLogAppender on obm-locator-btm1.tlog, 1
> TransactionLogAppender waiting for a disk force
> 13:42:02.695 [main] DEBUG b.tm.journal.DiskForceBatcherThread - batching
> disk force, there are 1 TransactionLogAppender in the wait queue
> 13:42:02.695 [main] DEBUG b.tm.journal.DiskForceWaitQueue - waiting for
> a TransactionLogAppender on obm-locator-btm1.tlog to get dequeued
> 13:42:02.696 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceBatcherThread - wait queue is not empty anymore (1
> in queue)
> 13:42:02.696 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceBatcherThread - forcing...
> 13:42:02.696 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceWaitQueue - returning head TransactionLogAppender
> 13:42:02.696 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.TransactionLogAppender - forcing log writing
> 13:42:02.696 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.TransactionLogAppender - done forcing log
> 13:42:02.696 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceWaitQueue - clearing list of waiting
> TransactionLogAppender
> 13:42:02.697 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceBatcherThread - waiting for the wait queue to fill up
> 13:42:02.697 [main] DEBUG b.tm.journal.DiskForceBatcherThread - wait
> queue got emptied, disk force is done
> 13:42:02.697 [bitronix-disk-force-batcher] DEBUG
> b.tm.journal.DiskForceWaitQueue - waiting for some
> TransactionLogAppender to get enqueued
> 13:42:02.697 [main] WARN  bitronix.tm.journal.DiskJournal - active log
> file is unclean, did you call BitronixTransactionManager.shutdown() at
> the end of the last run?
> 13:42:02.697 [main] DEBUG bitronix.tm.journal.DiskJournal - disk journal
> opened
> 13:42:02.698 [main] DEBUG bitronix.tm.resource.ResourceLoader - no
> resource configuration file specified
> 13:42:02.701 [main] DEBUG b.tm.journal.TransactionLogCursor - end of
> transaction log file reached at 21
> 13:42:02.701 [main] DEBUG bitronix.tm.journal.DiskJournal - collected
> dangling records of a TransactionLogAppender on obm-locator-btm1.tlog,
> committing: 0, committed: 0, delta: 0
> 13:42:02.701 [main] DEBUG bitronix.tm.recovery.Recoverer - found 0
> dangling record(s) in journal
> 13:42:02.701 [main] DEBUG bitronix.tm.recovery.Recoverer - committed 0
> dangling transaction(s)
> 13:42:02.702 [main] DEBUG bitronix.tm.recovery.Recoverer - rolling back
> aborted branch(es)
> 13:42:02.702 [main] DEBUG bitronix.tm.recovery.Recoverer - rolled back 0
> aborted branch(es)
> 13:42:02.702 [main] INFO  bitronix.tm.recovery.Recoverer - recovery
> committed 0 dangling transaction(s) and rolled back 0 aborted
> transaction(s) on 0 resource(s) [] (restricted to serverId 'obm-locator')
> 13:42:02.702 [main] DEBUG b.tm.BitronixTransactionManager - recovery
> will run in the background every 60 second(s)
> 13:42:02.706 [main] DEBUG bitronix.tm.timer.TaskScheduler - scheduling
> recovery task for Fri Nov 16 13:43:02 GMT 2012
> 13:42:02.707 [main] DEBUG bitronix.tm.timer.TaskScheduler - removing
> task by bitronix.tm.recovery.Recoverer at 396ab2e8
> 13:42:02.707 [main] DEBUG bitronix.tm.timer.TaskScheduler - scheduled a
> RecoveryTask scheduled for Fri Nov 16 13:43:02 GMT 2012, total task(s)
> queued: 1
> 13:42:02.707 [main] DEBUG b.tm.BitronixTransactionManager - creating new
> thread context
> 13:42:02.707 [main] DEBUG b.tm.BitronixTransactionManager - changing
> current thread context to a ThreadContext with transaction null, default
> timeout 60s
> 13:42:02.707 [main] DEBUG bitronix.tm.internal.ThreadContext - changing
> default timeout of thread context to 60s
> 13:42:02.711 [main] INFO  o.o.d.DatabaseConnectionProviderImpl -
> Database system is PGSQL
> 13:42:02.711 [main] INFO  o.o.d.DatabaseConnectionProviderImpl -
> Database used is obm on 127.0.0.1
> 13:42:02.712 [main] INFO  o.o.d.DatabaseConnectionProviderImpl -
> Database connection pool size : 10
> 13:42:02.712 [main] INFO  o.o.d.DatabaseConnectionProviderImpl -
> Starting OBM connection pool...
> 13:42:02.724 [main] DEBUG b.tm.resource.jdbc.PoolingDataSource -
> building XA pool for pgsql with 0 connection(s)
> 13:42:02.726 [main] DEBUG bitronix.tm.resource.common.XAPool - setting
> vendor property 'user' to 'obm'
> 13:42:02.726 [main] DEBUG bitronix.tm.resource.common.XAPool - setting
> vendor property 'password' to 'pop3smtp'
> 13:42:02.726 [main] DEBUG bitronix.tm.resource.common.XAPool - setting
> vendor property 'databaseName' to 'obm'
> 13:42:02.726 [main] DEBUG bitronix.tm.resource.common.XAPool - setting
> vendor property 'serverName' to '127.0.0.1'
> 13:42:02.727 [main] DEBUG bitronix.tm.timer.TaskScheduler - scheduling
> pool shrinking task on an XAPool of resource pgsql with 0 connection(s)
> (0 still available) for Fri Nov 16 13:43:02 GMT 2012
> 13:42:02.727 [main] DEBUG bitronix.tm.timer.TaskScheduler - removing
> task by an XAPool of resource pgsql with 0 connection(s) (0 still available)
> 13:42:02.727 [main] DEBUG bitronix.tm.timer.TaskScheduler - scheduled a
> PoolShrinkingTask scheduled for Fri Nov 16 13:43:02 GMT 2012 on an
> XAPool of resource pgsql with 0 connection(s) (0 still available), total
> task(s) queued: 2
> 13:42:02.727 [main] DEBUG b.tm.resource.ResourceRegistrar - transaction
> manager is running, recovering resource pgsql
> 13:42:02.728 [main] DEBUG b.tm.recovery.IncrementalRecoverer - start of
> incremental recovery on resource pgsql
> 13:42:02.728 [main] DEBUG bitronix.tm.resource.common.XAPool - getting a
> IN_POOL connection from an XAPool of resource pgsql with 0 connection(s)
> (0 still available)
> 13:42:02.728 [main] DEBUG bitronix.tm.resource.common.XAPool - no more
> free connection in an XAPool of resource pgsql with 0 connection(s) (0
> still available), trying to grow it
> 13:42:02.728 [main] DEBUG bitronix.tm.resource.common.XAPool -
> incrementing pgsql pool size by 1 unit(s) to reach 1 connection(s)
> 13:42:02.735 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - detected
> JDBC connection class 'class $Proxy17' is version 3 type
> 13:42:02.736 [main] DEBUG bitronix.tm.resource.common.XAPool - waiting
> for IN_POOL connections count to be>  0, currently is 1
> 13:42:02.736 [main] DEBUG bitronix.tm.resource.common.XAPool - found
> IN_POOL connection a JdbcPooledConnection from datasource pgsql in state
> IN_POOL with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261 from an XAPool of resource
> pgsql with 1 connection(s) (1 still available)
> 13:42:02.736 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - getting
> connection handle from a JdbcPooledConnection from datasource pgsql in
> state IN_POOL with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.736 [main] DEBUG b.t.r.c.AbstractXAStatefulHolder - notifying 2
> stateChangeEventListener(s) about state changing from IN_POOL to
> ACCESSIBLE in a JdbcPooledConnection from datasource pgsql in state
> IN_POOL with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.736 [main] DEBUG b.t.r.c.AbstractXAStatefulHolder - state
> changing from IN_POOL to ACCESSIBLE in a JdbcPooledConnection from
> datasource pgsql in state IN_POOL with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.736 [main] DEBUG b.t.r.c.AbstractXAStatefulHolder - notifying 2
> stateChangeEventListener(s) about state changed from IN_POOL to
> ACCESSIBLE in a JdbcPooledConnection from datasource pgsql in state
> ACCESSIBLE with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.736 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - connection
> org.postgresql.xa.PGXAConnection at 127f2261 was in state IN_POOL, testing it
> 13:42:02.736 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - testing with
> query 'SELECT 666' connection of a JdbcPooledConnection from datasource
> pgsql in state ACCESSIBLE with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.737 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - testQuery
> successfully tested connection of a JdbcPooledConnection from datasource
> pgsql in state ACCESSIBLE with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.738 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - got
> connection handle from a JdbcPooledConnection from datasource pgsql in
> state ACCESSIBLE with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.741 [main] DEBUG bitronix.tm.recovery.RecoveryHelper -
> recovering with STARTRSCAN
> 13:42:02.743 [main] DEBUG bitronix.tm.recovery.RecoveryHelper -
> STARTRSCAN recovered 0 xid(s) on an XAResourceHolderState with
> uniqueName=pgsql XAResource=org.postgresql.xa.PGXAConnection at 127f2261
> with XID null
> 13:42:02.743 [main] DEBUG bitronix.tm.recovery.RecoveryHelper -
> recovering with ENDRSCAN
> 13:42:02.743 [main] DEBUG bitronix.tm.recovery.RecoveryHelper - ENDRSCAN
> recovered 0 xid(s) on an XAResourceHolderState with uniqueName=pgsql
> XAResource=org.postgresql.xa.PGXAConnection at 127f2261 with XID null
> 13:42:02.743 [main] DEBUG b.tm.recovery.IncrementalRecoverer - 0
> dangling transaction(s) found on resource
> 13:42:02.743 [main] DEBUG b.tm.journal.TransactionLogCursor - end of
> transaction log file reached at 21
> 13:42:02.743 [main] DEBUG bitronix.tm.journal.DiskJournal - collected
> dangling records of a TransactionLogAppender on obm-locator-btm1.tlog,
> committing: 0, committed: 0, delta: 0
> 13:42:02.743 [main] DEBUG b.tm.recovery.IncrementalRecoverer - 0
> dangling transaction(s) found in journal
> 13:42:02.744 [main] INFO  b.tm.recovery.IncrementalRecoverer -
> incremental recovery committed 0 dangling transaction(s) and rolled back
> 0 aborted transaction(s) on resource [pgsql] (restricted to serverId
> 'obm-locator')
> 13:42:02.744 [main] DEBUG b.tm.resource.jdbc.PoolingDataSource -
> recovery xa resource is being closed:
> bitronix.tm.resource.common.RecoveryXAResourceHolder at 6fe30af
> 13:42:02.744 [main] DEBUG b.t.r.jdbc.JdbcConnectionHandle - closing a
> JdbcConnectionHandle of a JdbcPooledConnection from datasource pgsql in
> state ACCESSIBLE with usage count 1 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261 on Pooled connection wrapping
> physical connection org.postgresql.jdbc4.Jdbc4Connection at 1a2e34bf
> 13:42:02.744 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - releasing to
> pool a JdbcPooledConnection from datasource pgsql in state ACCESSIBLE
> with usage count 1 wrapping org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.TransactionContextHelper - delisting a
> JdbcPooledConnection from datasource pgsql in state ACCESSIBLE with
> usage count 0 wrapping org.postgresql.xa.PGXAConnection at 127f2261 from null
> 13:42:02.744 [main] DEBUG b.t.r.c.TransactionContextHelper - resource is
> not in enlisting global transaction context: a JdbcPooledConnection from
> datasource pgsql in state ACCESSIBLE with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.TransactionContextHelper - requeuing a
> JdbcPooledConnection from datasource pgsql in state ACCESSIBLE with
> usage count 0 wrapping org.postgresql.xa.PGXAConnection at 127f2261 from null
> 13:42:02.744 [main] DEBUG b.t.r.c.TransactionContextHelper - resource is
> not in enlisting global transaction context: a JdbcPooledConnection from
> datasource pgsql in state ACCESSIBLE with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.TransactionContextHelper - looking in
> in-flight transactions for XAResourceHolderState of a
> JdbcPooledConnection from datasource pgsql in state ACCESSIBLE with
> usage count 0 wrapping org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.AbstractXAResourceHolder - resource
> not enlisted in any transaction: a JdbcPooledConnection from datasource
> pgsql in state ACCESSIBLE with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.TransactionContextHelper - resource
> not in enlisting global transaction context, immediately releasing to
> pool a JdbcPooledConnection from datasource pgsql in state ACCESSIBLE
> with usage count 0 wrapping org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.AbstractXAStatefulHolder - notifying 2
> stateChangeEventListener(s) about state changing from ACCESSIBLE to
> IN_POOL in a JdbcPooledConnection from datasource pgsql in state
> ACCESSIBLE with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - closing 0
> dangling uncached statement(s)
> 13:42:02.744 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - clearing
> warnings of Pooled connection wrapping physical connection
> org.postgresql.jdbc4.Jdbc4Connection at 1a2e34bf
> 13:42:02.744 [main] DEBUG b.t.r.c.AbstractXAStatefulHolder - state
> changing from ACCESSIBLE to IN_POOL in a JdbcPooledConnection from
> datasource pgsql in state ACCESSIBLE with usage count 0 wrapping
> org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.744 [main] DEBUG b.t.r.c.AbstractXAStatefulHolder - notifying 2
> stateChangeEventListener(s) about state changed from ACCESSIBLE to
> IN_POOL in a JdbcPooledConnection from datasource pgsql in state IN_POOL
> with usage count 0 wrapping org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.745 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - requeued
> JDBC connection of a PoolingDataSource containing an XAPool of resource
> pgsql with 1 connection(s) (1 still available)
> 13:42:02.745 [main] DEBUG bitronix.tm.resource.common.XAPool - a
> connection's state changed to IN_POOL, notifying a thread eventually
> waiting for a connection
> 13:42:02.745 [main] DEBUG b.t.r.jdbc.JdbcPooledConnection - released to
> pool a JdbcPooledConnection from datasource pgsql in state IN_POOL with
> usage count 0 wrapping org.postgresql.xa.PGXAConnection at 127f2261
> 13:42:02.745 [main] DEBUG b.tm.recovery.IncrementalRecoverer - end of
> incremental recovery on resource pgsql
> 2012-11-16 14:42:02.746:INFO::Opened /var/log/jetty/2012_11_16.request.log
> 2012-11-16 14:42:02.753:INFO::Started SelectChannelConnector at 0.0.0.0:8082
> 2012-11-16 14:42:02.778:INFO::Started SelectChannelConnector at 0.0.0.0:8084
>
>
> Le 16/11/2012 10:00, Matthieu Baechler a écrit :
>> Bonjour,
>>
>> Il semble que vous avez des "jar" en double dans vos "webapp".
>>
>> Je m'explique : si lors de la mise à jour, tous les jars de la version
>> précédente ne sont pas enlevées, au démarrage de la nouvelle version,
>> ils seront chargé dans leur nouvelle et leur ancienne version.
>> Ça mène très souvent à des bugs multiples comme vous les rencontrez.
>>
>> Pouvez-vous vérifier le contenu des webapps (sous debian
>> c'est /var/lib/jetty/webapps/opush/WEB-INF/lib/, /var/lib/jetty/webapps/obm-locator/WEB-INF/lib/ et /usr/share/obm-sync/WEB-INF/lib/) ?
>>
> _______________________________________________
> Obm mailing list
> Obm at list.obm.org
> http://list.obm.org/mailman/listinfo/obm

-- 
Thomas Hilaire
Développeur LGS/OBM/R&D
+33 6 43 65 66 03

------------------

GROUPE LINAGORA
74-80 rue Roque de Fillol
92800 Puteaux

+33 (0)8 10 25 12 51
+33 (0)6 79 60 12 91
thilaire at linagora.com

------------------

La présente transmission contient des informations confidentielles
appartenant à Linagora, exclusivement destinées au(x) destinataire(s)
identifié(s) ci-dessus. Si vous n'en faites pas partie, toute
reproduction, distribution ou divulgation de tout ou partie des
informations de cette transmission, ou toute action effectuée sur la
base de celles-ci vous sont formellement interdites.
Si vous avez reçu cette transmission par erreur, nous vous remercions de
nous en avertir et de la détruire de votre système d'information.

The present transmission contains privileged and confidential
information belonging to Linagora, exclusively intended for the
recipient(s) thereabove identified. If you are not one of these
aforementioned recipients, any reproduction, distribution, disclosure of
said information in whole or in part, as well as any action undertaken
on the basis of said information are strictly prohbited. If you received
the present transmission by mistake, please inform us and destroy it
from your messenging and information systems.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://list.obm.org/pipermail/obm/attachments/20121116/e063381f/attachment-0001.htm 