search

ragnor / simple-spring-memcached

A drop-in library to enable memcached caching in Spring beans via annotations
MIT License
189 stars 91 forks source link

Jmemcached-maven-plugin starts but TimeoutException in maven test #40

Closed RNiveau closed 10 years ago

RNiveau commented 10 years ago

Hi,

I would like to do some integration tests in my project which uses memcached. So I try jmemcached-maven-plugin which seems a good solution.

If I have well understood the plugin, it starts a memcached server and catches requests.

Here is the pom.xml plugins section:

<plugin>
                <groupId>com.google.code.simple-spring-memcached</groupId>
                <artifactId>jmemcached-maven-plugin</artifactId>
                <version>3.5.0</version>
                <configuration>
                    <servers>
                        <server>
                            <port>11242</port>
                            <binary>true</binary>
                        </server>
                    </servers>
                </configuration>
                <executions>
                    <execution>
                        <id>start-memcached</id>
                        <phase>pre-integration-test</phase>
                        <goals>
                            <goal>start</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>stop-memcached</id>
                        <phase>post-integration-test</phase>
                        <goals>
                            <goal>stop</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>

Here is my spring configuration:

<bean id="memcachedClient" class="net.spy.memcached.spring.MemcachedClientFactoryBean">
        <property name="servers" value="#{systemProperties['memcached.servers']?:'127.0.0.1:11242'}" />
        <property name="protocol" value="BINARY" />
        <property name="transcoder">
            <bean class="net.spy.memcached.transcoders.SerializingTranscoder">
                <property name="compressionThreshold" value="1024" />
            </bean>
        </property>
        <property name="opTimeout" value="1000" />
        <property name="timeoutExceptionThreshold" value="1998" />
        <property name="locatorType" value="CONSISTENT" />
        <property name="failureMode" value="Redistribute" />
        <property name="useNagleAlgorithm" value="false" />
    </bean>

And when I run "mvn clean install", I get this (it's seem good):

[INFO] --- jmemcached-maven-plugin:3.5.0:start (start-memcached) @ clientprofile-webapp ---
[INFO] Startng jmemcached daemons: [Server [port=11242, maximumCapacity=1000, maximumMemoryCapacity=10000000, binary=true]]
[INFO] Listening on localhost:11242
[INFO] Memcached has been started: Server [port=11242, maximumCapacity=1000, maximumMemoryCapacity=10000000, binary=true]
[INFO] Jmemcached daemons have been started

But after during my test, I get:

net.spy.memcached.OperationTimeoutException: Timeout waiting for value: waited 1 000 ms. Node status: Connection Status { /127.0.0.1:11242 active: true, authed: true, last read: 9 002 ms ago }
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1240)
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1257)

What's wrong in my configuration ? The port number matches. Does jmemcached-maven-plugin work only with ssm ?

Thanks for your help.

ragnor commented 10 years ago

The jmemcached-maven-plugin can be used in any project not only with SSM. It was created for SSM to provide easy way of running integration tests during build. The plugin doesn't start memcached process but jmemcached which is java implementation of memcached protocol.

Could you post full pom.xml and build log? What plugin do you use to run tests?

RNiveau commented 10 years ago

Here is my full pom.xml purges from private dependencies (I can't post them here):

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <parent>
        <groupId>com</groupId>
        <artifactId>artifact</artifactId>
        <version>3.1.4-SNAPSHOT</version>
    </parent>
    <artifactId>artifact-webapp</artifactId>
    <packaging>war</packaging>

    <properties>
        <selma.version>0.6</selma.version>
        <jbehave.core.version>3.8</jbehave.core.version>
    </properties>
    <dependencies>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-core</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-expression</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-beans</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-aop</artifactId>
        </dependency>
        <dependency>
            <groupId>cglib</groupId>
            <artifactId>cglib</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-context</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-context-support</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-webmvc</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-oxm</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.security</groupId>
            <artifactId>spring-security-core</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.security</groupId>
            <artifactId>spring-security-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.security</groupId>
            <artifactId>spring-security-config</artifactId>
        </dependency>

        <dependency>
            <groupId>com.google.code.simple-spring-memcached</groupId>
            <artifactId>simple-spring-memcached</artifactId>
        </dependency>
        <dependency>
            <groupId>net.spy</groupId>
            <artifactId>spymemcached</artifactId>
        </dependency>

        <dependency>
            <groupId>com.esotericsoftware.kryo</groupId>
            <artifactId>kryo</artifactId>
        </dependency>

        <dependency>
            <groupId>commons-lang</groupId>
            <artifactId>commons-lang</artifactId>
        </dependency>

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
        </dependency>

        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
        </dependency>

        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-core</artifactId>
        </dependency>

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>jcl-over-slf4j</artifactId>
            <version>${slf4j.version}</version>
        </dependency>

        <dependency>
            <groupId>org.codehaus.janino</groupId>
            <artifactId>janino</artifactId>
            <version>2.6.1</version>
            <scope>runtime</scope>
        </dependency>

        <dependency>
            <groupId>net.java.dev.rome</groupId>
            <artifactId>rome</artifactId>
        </dependency>

        <dependency>
            <groupId>fr.xebia.extras</groupId>
            <artifactId>selma-processor</artifactId>
            <version>${selma.version}</version>
            <scope>provided</scope>
        </dependency>

        <dependency>
            <groupId>fr.xebia.extras</groupId>
            <artifactId>selma</artifactId>
            <version>${selma.version}</version>
        </dependency>

        <!--== TEST SCOPE == -->
        <dependency>
            <groupId>org.mockito</groupId>
            <artifactId>mockito-all</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>junit</groupId>
            <artifactId>junit</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.jbehave</groupId>
            <artifactId>jbehave-spring</artifactId>
            <version>${jbehave.core.version}</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.jbehave</groupId>
            <artifactId>jbehave-core</artifactId>
            <version>${jbehave.core.version}</version>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>com.github.tomakehurst</groupId>
            <artifactId>wiremock</artifactId>
            <version>1.47</version>
            <!-- Pas de dépendances transitives pouvant entrer en conflit avec les librairies du projet -->
            <classifier>standalone</classifier>
            <scope>test</scope>
        </dependency>

        <dependency>
            <groupId>org.apache.cxf</groupId>
            <artifactId>cxf-rt-frontend-jaxws</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>commons-logging</groupId>
                    <artifactId>commons-logging</artifactId>
                </exclusion>
                <exclusion>
                    <groupId>org.apache.geronimo.specs</groupId>
                    <artifactId>geronimo-activation_1.1_spec</artifactId>
                </exclusion>
                <exclusion>
                    <groupId>org.apache.geronimo.specs</groupId>
                    <artifactId>geronimo-javamail_1.4_spec</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

        <dependency>
            <groupId>org.apache.cxf</groupId>
            <artifactId>cxf-rt-transports-http</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework</groupId>
                    <artifactId>spring-web</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

    </dependencies>
    <profiles>
        <profile>
            <id>integration-test</id>
            <build>
                <plugins>
                    <plugin>
                        <groupId>org.jbehave</groupId>
                        <artifactId>jbehave-maven-plugin</artifactId>
                        <version>3.9.3</version>
                        <configuration>
                            <scope>test</scope>
                            <includes>
                                <include>com/**/*.java</include>
                            </includes>
                            <ignoreFailureInStories>true</ignoreFailureInStories>
                            <ignoreFailureInView>false</ignoreFailureInView>
                        </configuration>
                        <executions>
                            <execution>
                                <id>run-stories-as-embeddables</id>
                                <phase>integration-test</phase>
                                <goals>
                                    <goal>run-stories-as-embeddables</goal>
                                </goals>
                            </execution>
                        </executions>
                        <dependencies>
                            <dependency>
                                <groupId>log4j</groupId>
                                <artifactId>log4j</artifactId>
                                <version>1.2.17</version>
                            </dependency>
                        </dependencies>
                    </plugin>
                </plugins>
            </build>
        </profile>

    </profiles>
    <build>
        <plugins>
            <plugin>
                <groupId>com.google.code.simple-spring-memcached</groupId>
                <artifactId>jmemcached-maven-plugin</artifactId>
                <version>3.5.0</version>
                <configuration>
                    <servers>
                        <server>
                            <port>11242</port>
                            <binary>true</binary>
                        </server>
                    </servers>
                </configuration>
                <executions>
                    <execution>
                        <id>start-memcached</id>
                        <phase>pre-integration-test</phase>
                        <goals>
                            <goal>start</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>stop-memcached</id>
                        <phase>post-integration-test</phase>
                        <goals>
                            <goal>stop</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>
        </plugins>
    </build>
</project>

Here is the build report.

I have unit tests (work fine) and integration tests in bdd mode with jbehave. It's here where I want to use jmemcached-maven-plugin.

[INFO] Scanning for projects...
[INFO]                                                                         
[INFO] ------------------------------------------------------------------------
[INFO] Building Webapp 3.1.4-SNAPSHOT
[INFO] ------------------------------------------------------------------------
[INFO] 
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ webapp ---
[INFO] Deleting /Users/romainn/Documents/workspace/intelliJ/webapp/target
[INFO] 
[INFO] --- maven-resources-plugin:2.5:resources (default-resources) @ webapp ---
[debug] execute contextualize
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 16 resources
[INFO] 
[INFO] --- maven-compiler-plugin:2.5:compile (default-compile) @ webapp ---
[INFO] Compiling 107 source files to /Users/romainn/Documents/workspace/intelliJ/webapp/target/classes
[INFO] 
[INFO] --- maven-resources-plugin:2.5:testResources (default-testResources) @ webapp ---
[debug] execute contextualize
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 16 resources
[INFO] 
[INFO] --- maven-compiler-plugin:2.5:testCompile (default-testCompile) @ webapp ---
[INFO] Compiling 36 source files to /Users/romainn/Documents/workspace/intelliJ/webapp/target/test-classes
[INFO] 
[INFO] --- maven-surefire-plugin:2.12:test (default-test) @ webapp ---
[INFO] Surefire report directory: /Users/romainn/Documents/workspace/intelliJ/webapp/target/surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running com.algorithm.AroEligibiliteTest
10:20:45,592 |-INFO in ch.qos.logback.classic.LoggerContext[] - Could NOT find resource [logback.groovy]
10:20:45,592 |-INFO in ch.qos.logback.classic.LoggerContext[] - Could NOT find resource [logback-test.xml]
10:20:45,592 |-INFO in ch.qos.logback.classic.LoggerContext[] - Found resource [logback.xml] at [file:/Users/romainn/Documents/workspace/intelliJ/webapp/target/classes/logback.xml]
10:20:45,653 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
10:20:45,658 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Setting ReconfigureOnChangeFilter scanning period to 30 seconds
10:20:45,658 |-INFO in ReconfigureOnChangeFilter{invocationCounter=0} - Will scan for changes in [[/Users/romainn/Documents/workspace/intelliJ/webapp/target/classes/logback.xml]] every 30 seconds. 
10:20:45,658 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - Adding ReconfigureOnChangeFilter as a turbo filter
10:20:45,665 |-INFO in ch.qos.logback.classic.joran.action.ContextNameAction - Setting logger context name as []
10:20:45,666 |-INFO in ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Adding LoggerContextListener of type [ch.qos.logback.classic.jul.LevelChangePropagator] to the object stack
10:20:45,683 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating DEBUG level on Logger[ROOT] onto the JUL framework
10:20:45,683 |-INFO in ch.qos.logback.classic.joran.action.LoggerContextListenerAction - Starting LoggerContextListener
10:20:45,683 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
10:20:45,686 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [console]
10:20:45,694 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:20:45,743 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
10:20:45,745 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [auditfile]
10:20:45,751 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:20:45,762 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
10:20:45,764 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern /tmp/logs/audit.log%d{-yyyyMMdd} for the active file
10:20:45,767 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is '-yyyyMMdd' from file name pattern '/tmp/logs/audit.log%d{-yyyyMMdd}'.
10:20:45,767 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
10:20:45,769 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Mon Aug 18 10:26:08 CEST 2014
10:20:45,771 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[auditfile] - Active log file name: /tmp/logs/audit.log
10:20:45,771 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[auditfile] - File property is set to [/tmp/logs/audit.log]
10:20:45,772 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
10:20:45,772 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [debugfile]
10:20:45,773 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@27:20 - no applicable action for [withJansi], current ElementPath  is [[configuration][appender][withJansi]]
10:20:45,773 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:20:45,777 |-INFO in ch.qos.logback.core.rolling.FixedWindowRollingPolicy@70596c33 - No compression will be used
10:20:45,784 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[debugfile] - Active log file name: /tmp/logs/debug.log
10:20:45,784 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[debugfile] - File property is set to [/tmp/logs/debug.log]
10:20:45,784 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
10:20:45,784 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [synchronousfile]
10:20:45,784 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@42:20 - no applicable action for [withJansi], current ElementPath  is [[configuration][appender][withJansi]]
10:20:45,785 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:20:45,786 |-INFO in ch.qos.logback.core.rolling.FixedWindowRollingPolicy@7ecec1e4 - No compression will be used
10:20:45,787 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[synchronousfile] - Active log file name: /tmp/logs/synchronous.log
10:20:45,787 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[synchronousfile] - File property is set to [/tmp/logs/synchronous.log]
10:20:45,787 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.rolling.RollingFileAppender]
10:20:45,787 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [logfile]
10:20:45,787 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
10:20:45,792 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - No compression will be used
10:20:45,792 |-INFO in c.q.l.core.rolling.TimeBasedRollingPolicy - Will use the pattern /tmp/logs/.log%d{-yyyyMMdd} for the active file
10:20:45,793 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - The date pattern is '-yyyyMMdd' from file name pattern '/tmp/logs/.log%d{-yyyyMMdd}'.
10:20:45,793 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Roll-over at midnight.
10:20:45,793 |-INFO in c.q.l.core.rolling.DefaultTimeBasedFileNamingAndTriggeringPolicy - Setting initial period to Tue Aug 19 10:20:03 CEST 2014
10:20:45,793 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[logfile] - Active log file name: /tmp/logs/.log
10:20:45,793 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[logfile] - File property is set to [/tmp/logs/.log]
10:20:45,793 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to WARN
10:20:45,793 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[ROOT] onto the JUL framework
10:20:46,026 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [logfile] to Logger[ROOT]
10:20:46,027 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [debugfile] to Logger[ROOT]
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.security.event.authentication.LoggerListener] to INFO
10:20:46,028 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating INFO level on Logger[org.springframework.security.event.authentication.LoggerListener] onto the JUL framework
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.springframework.security.event.authentication.LoggerListener] to false
10:20:46,028 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [auditfile] to Logger[org.springframework.security.event.authentication.LoggerListener]
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.asynch.AsynchronousManager] to DEBUG
10:20:46,028 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating DEBUG level on Logger[com.asynch.AsynchronousManager] onto the JUL framework
10:20:46,028 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [synchronousfile] to Logger[com.asynch.AsynchronousManager]
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [AuditLoggerFilter.request] to DEBUG
10:20:46,028 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating DEBUG level on Logger[AuditLoggerFilter.request] onto the JUL framework
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [AuditLoggerFilter.request] to false
10:20:46,028 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [auditfile] to Logger[AuditLoggerFilter.request]
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [AuditLoggerFilter.response] to DEBUG
10:20:46,028 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating DEBUG level on Logger[AuditLoggerFilter.response] onto the JUL framework
10:20:46,028 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [AuditLoggerFilter.response] to false
10:20:46,028 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [auditfile] to Logger[AuditLoggerFilter.response]
10:20:46,031 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.cxf.services] to WARN
10:20:46,031 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[org.apache.cxf.services] onto the JUL framework
10:20:46,031 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.apache.cxf.services] to false
10:20:46,031 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [auditfile] to Logger[org.apache.cxf.services]
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.cxf] to WARN
10:20:46,032 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[org.apache.cxf] onto the JUL framework
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.apache.cxf] to false
10:20:46,032 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [debugfile] to Logger[org.apache.cxf]
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com..] to DEBUG
10:20:46,032 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating DEBUG level on Logger[com..] onto the JUL framework
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com..springframework.security] to INFO
10:20:46,032 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating INFO level on Logger[com..springframework.security] onto the JUL framework
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.security] to INFO
10:20:46,032 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating INFO level on Logger[org.springframework.security] onto the JUL framework
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.web] to WARN
10:20:46,032 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[org.springframework.web] onto the JUL framework
10:20:46,032 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.web.client] to WARN
10:20:46,032 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[org.springframework.web.client] onto the JUL framework
10:20:46,033 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.springframework.ws.server.MessageTracing] to WARN
10:20:46,033 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[org.springframework.ws.server.MessageTracing] onto the JUL framework
10:20:46,033 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [org.apache.http.client] to WARN
10:20:46,033 |-INFO in ch.qos.logback.classic.jul.LevelChangePropagator@5fff4631 - Propagating WARN level on Logger[org.apache.http.client] onto the JUL framework
10:20:46,033 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
10:20:46,034 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@381ba0c6 - Registering current configuration as safe fallback point

Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.808 sec
Running com.algorithm.DonneesClientTest
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.088 sec
Running com.algorithm.GElibitiliteTest
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.056 sec
Running com.algorithm.SElibitiliteTest
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.054 sec
Running com.algorithm.MElibitiliteTest
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.012 sec
Running com.business.AdapterTest
Tests run: 12, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.02 sec
Running com.business.BackEndRequestConverterTest
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.033 sec
Running com.business.BackEndRequestHelperTest
Tests run: 15, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.04 sec
Running com.business.ResponseConverterTest
Tests run: 12, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.028 sec
Running com.business.responseHandler.CpfResponse31HandlerTest
Tests run: 34, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.045 sec
Running com.business.TestPersonneHelper
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.001 sec
Running com.cache.CacheServiceTest
Tests run: 8, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.018 sec
Running com.cache.TestTaskExecutorLocator
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.338 sec
Running com.ssa.request.DonneesSimulationAMEParametersTest
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.001 sec
Running com.utils.RequestHelperTest
Tests run: 9, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.005 sec
Running sandbox.apache.TestHashcodebuilder
-1799056398
1335056340
-1799056398
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.004 sec
Running sandbox.dozer.DozerTest
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.119 sec
Running sandbox.jaxb.TestJaxbMarshaller
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.199 sec
Running sandbox.spring.PropertyOverrideConfigurerTest
toto
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.108 sec
Running sandbox.spring.TestTaskExecutor
before for loop
thread 0 running...
thread 1 running...
thread 8 running...
thread 9 running...
before for loop
thread 0 running...
thread 1 running...
thread 8 running...
after for loop
thread 9 running...
thread 0 ending...
thread 9 ending...
thread 8 ending...
thread 2 running...
thread 1 ending...
thread 4 running...
thread 5 running...
thread 3 running...
thread 2 ending...
thread 5 ending...
thread 3 ending...
thread 4 ending...
thread 7 running...
thread 6 running...
thread 7 ending...
thread 6 ending...
end testing
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.044 sec

Results :

Tests run: 136, Failures: 0, Errors: 0, Skipped: 0

[INFO] 
[INFO] --- maven-war-plugin:2.2:war (default-war) @ webapp ---
[INFO] Packaging webapp
[INFO] Assembling webapp [webapp] in [/Users/romainn/Documents/workspace/intelliJ/webapp/target/webapp-3.1.4-SNAPSHOT]
[INFO] Processing war project
[INFO] Copying webapp resources [/Users/romainn/Documents/workspace/intelliJ/webapp/src/main/webapp]
[INFO] Webapp assembled in [290 msecs]
[INFO] Building war: /Users/romainn/Documents/workspace/intelliJ/webapp/target/webapp-3.1.4-SNAPSHOT.war
[INFO] WEB-INF/web.xml already added, skipping
[INFO] 
[INFO] >>> maven-source-plugin:2.1.2:jar (sources) @ webapp >>>
[INFO] 
[INFO] <<< maven-source-plugin:2.1.2:jar (sources) @ webapp <<<
[INFO] 
[INFO] --- maven-source-plugin:2.1.2:jar (sources) @ webapp ---
[INFO] Building jar: /Users/romainn/Documents/workspace/intelliJ/webapp/target/webapp-3.1.4-SNAPSHOT-sources.jar
[INFO] 
[INFO] --- jmemcached-maven-plugin:3.5.0:start (start-memcached) @ webapp ---
[INFO] Startng jmemcached daemons: [Server [port=11242, maximumCapacity=1000, maximumMemoryCapacity=10000000, binary=true]]
[INFO] Listening on localhost:11242
[INFO] Memcached has been started: Server [port=11242, maximumCapacity=1000, maximumMemoryCapacity=10000000, binary=true]
[INFO] Jmemcached daemons have been started
[INFO] 
[INFO] --- jbehave-maven-plugin:3.9.3:run-stories-as-embeddables (run-stories-as-embeddables) @ webapp ---
[INFO] Running stories as embeddables using embedder Embedder[storyMapper=StoryMapper,storyRunner=StoryRunner,embedderMonitor=MavenEmbedderMonitor,classLoader=EmbedderClassLoader
[INFO] Found class names: [com.bdd.AbstractBdd, com.bdd.integration.Integration, com.bdd.simulationame.CallSimulationAme]
[INFO] Using controls UnmodifiableEmbedderControls[EmbedderControls[batch=false,skip=false,generateViewAfterStories=true,ignoreFailureInStories=true,ignoreFailureInView=false,verboseFailures=false,verboseFiltering=false,storyTimeoutInSecs=300,failOnStoryTimeout=false,threads=1]]
[INFO] Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@3d844f2f: startup date [Tue Aug 19 10:20:54 CEST 2014]; root of context hierarchy
[INFO] Loading XML bean definitions from class path resource [spring/context.xml]
[INFO] JSR-330 'javax.inject.Named' annotation found and supported for component scanning
[INFO] Loading XML bean definitions from class path resource [spring/taskExecutorLocator-context.xml]
[INFO] Loading XML bean definitions from class path resource [spring/connector-ws-context.xml]
[INFO] Loading XML bean definitions from class path resource [META-INF/cxf/cxf.xml]
[INFO] Loading properties file from class path resource [conf/taskExecutor-test.properties]
[INFO] Loading properties file from class path resource [conf/application-test.properties]
[INFO] Loading properties file from class path resource [conf/ws-props-test.properties]
[WARNING] Could not load properties from class path resource [conf/ws-props-test.properties]: class path resource [conf/ws-props-test.properties] cannot be opened because it does not exist
[INFO] JSR-330 'javax.inject.Inject' annotation found and supported for autowiring
[INFO] Using controls UnmodifiableEmbedderControls[EmbedderControls[batch=false,skip=false,generateViewAfterStories=true,ignoreFailureInStories=true,ignoreFailureInView=false,verboseFailures=false,verboseFiltering=false,storyTimeoutInSecs=300,failOnStoryTimeout=false,threads=1]]

(BeforeStories)

[INFO] Running story stories/integration/Integration.story

(stories/integration/Integration.story)
Scenario: Call 0622379842 with ficheUtilisationOnly true
[INFO] Logging to org.slf4j.impl.SimpleLogger(wiremock.org.mortbay.log) via wiremock.org.mortbay.log.Slf4jLog
[INFO] jetty-6.1.x
[INFO] Started DelayableSocketConnector@0.0.0.0:8180
Given A phone number 0622379842
Given A sale channel S
Given A ficheUtilisateurOnly true
[INFO] RequestHandlerClass from context returned com.github.tomakehurst.wiremock.http.AdminRequestHandler
When I call  (FAILED)
(net.spy.memcached.OperationTimeoutException: Timeout waiting for value: waited 1 000 ms. Node status: Connection Status { /127.0.0.1:11242 active: true, authed: true, last read: 8 730 ms ago })
Then A response COMPLETE (NOT PERFORMED)
Then 2 ssa were been called (NOT PERFORMED)
Then The line is type MOBILE (NOT PERFORMED)
Then The contract is S (NOT PERFORMED)
Then The brand is S (NOT PERFORMED)

net.spy.memcached.OperationTimeoutException: Timeout waiting for value: waited 1 000 ms. Node status: Connection Status { /127.0.0.1:11242 active: true, authed: true, last read: 8 730 ms ago }
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1240)
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1257)
    at com.cache.MemcachedClientWrapper.get(MemcachedClientWrapper.java:80)
    at com.cache.CacheService.isCacheExpired(CacheService.java:46)
    at com.business.Business.getResponses(Business.java:129)
    at com.bdd.integration.Integration.when(Integration.java:80)
    (reflection-invoke)
    at org.jbehave.core.steps.StepCreator$ParametrisedStep.perform(StepCreator.java:595)
    at org.jbehave.core.embedder.StoryRunner$FineSoFar.run(StoryRunner.java:535)
...
Scenario: Call 0622379842
Given A phone number 0622379842
Given A sale channel S

When I call  (FAILED)
(net.spy.memcached.OperationTimeoutException: Timeout waiting for value: waited 1 000 ms. Node status: Connection Status { /127.0.0.1:11242 active: true, authed: true, last read: 9 854 ms ago })
Then A response COMPLETE (NOT PERFORMED)
Then 7 ssa were been called (NOT PERFORMED)
Then The line is type MOBILE (NOT PERFORMED)
Then The contract is S (NOT PERFORMED)
Then The brand is S (NOT PERFORMED)
Then The contract has 4 options (NOT PERFORMED)

net.spy.memcached.OperationTimeoutException: Timeout waiting for value: waited 1 000 ms. Node status: Connection Status { /127.0.0.1:11242 active: true, authed: true, last read: 9 854 ms ago }
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1240)
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1257)
    at com.cache.MemcachedClientWrapper.get(MemcachedClientWrapper.java:80)
    at com.cache.CacheService.isCacheExpired(CacheService.java:46)
    at com.business.Business.getResponses(Business.java:129)
    at com.bdd.integration.Integration.when(Integration.java:80)
    (reflection-invoke)
    at org.jbehave.core.steps.StepCreator$ParametrisedStep.perform(StepCreator.java:595)
    at org.jbehave.core.embedder.StoryRunner$FineSoFar.run(StoryRunner.java:535)
...

[WARNING] Failed to run story stories/integration/Integration.story
net.spy.memcached.OperationTimeoutException: Timeout waiting for value: waited 1 000 ms. Node status: Connection Status { /127.0.0.1:11242 active: true, authed: true, last read: 8 730 ms ago }
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1240)
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1257)
    at com.cache.MemcachedClientWrapper.get(MemcachedClientWrapper.java:80)
    at com.cache.CacheService.isCacheExpired(CacheService.java:46)
    at com.business.Business.getResponses(Business.java:129)
    at com.bdd.integration.Integration.when(Integration.java:80)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at org.jbehave.core.steps.StepCreator$ParametrisedStep.perform(StepCreator.java:595)
    at org.jbehave.core.embedder.StoryRunner$FineSoFar.run(StoryRunner.java:535)
    at org.jbehave.core.embedder.StoryRunner.runStepsWhileKeepingState(StoryRunner.java:515)
    at org.jbehave.core.embedder.StoryRunner.runScenarioSteps(StoryRunner.java:479)
    at org.jbehave.core.embedder.StoryRunner.runStepsWithLifecycle(StoryRunner.java:445)
    at org.jbehave.core.embedder.StoryRunner.runCancellable(StoryRunner.java:305)
    at org.jbehave.core.embedder.StoryRunner.run(StoryRunner.java:220)
    at org.jbehave.core.embedder.StoryRunner.run(StoryRunner.java:181)
    at org.jbehave.core.embedder.StoryManager$EnqueuedStory.call(StoryManager.java:235)
    at org.jbehave.core.embedder.StoryManager$EnqueuedStory.call(StoryManager.java:207)
    at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
    at java.util.concurrent.FutureTask.run(FutureTask.java:166)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:722)
Caused by: net.spy.memcached.internal.CheckedOperationTimeoutException: Timed out waiting for operation - failing node: /127.0.0.1:11242
    at net.spy.memcached.internal.OperationFuture.get(OperationFuture.java:167)
    at net.spy.memcached.internal.GetFuture.get(GetFuture.java:69)
    at net.spy.memcached.MemcachedClient.get(MemcachedClient.java:1230)
    ... 24 more

(AfterStories)

[INFO] Generating reports view to '/Users/romainn/Documents/workspace/intelliJ/webapp/target/jbehave' using formats '[stats, console, html, xml]' and view properties '{navigator=ftl/jbehave-navigator.ftl, views=ftl/jbehave-views.ftl, reports=ftl/jbehave-reports-with-totals.ftl, nonDecorated=ftl/jbehave-report-non-decorated.ftl, decorated=ftl/jbehave-report-decorated.ftl, maps=ftl/jbehave-maps.ftl}'
[INFO] Reports view generated with 1 stories (of which 0 pending) containing 2 scenarios (of which 0 pending)
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 29.940s
[INFO] Finished at: Tue Aug 19 10:21:07 CEST 2014
[INFO] Final Memory: 62M/150M
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.jbehave:jbehave-maven-plugin:3.9.3:run-stories-as-embeddables (run-stories-as-embeddables) on project webapp: Failed to run stories as embeddables: Failure in running embeddable: com.bdd.integration.Integration: Failures in running stories: ReportsCount[stories=1,storiesNotAllowed=0,storiesPending=0,scenarios=2,scenariosFailed=2,scenariosNotAllowed=0,scenariosPending=0,stepsFailed=2] -> [Help 1]
[ERROR] 
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException
ragnor commented 10 years ago

Does your integration tests pass if instead of jmemcached-maven-plugin a dedicated memcached instance is run manually on port 11242 before running "mvn clean install" ?

Can you stop in one of your integration tests and try to connect using telnet/putty and execute some get command on the jmemcached instance started by jmemcached-maven-plugin?

RNiveau commented 10 years ago

Yes my integration tests pass with memcached launched manually like this:

memcached -p 11242 &

I can connect me with telnet when memcached is launched manually.

It works too with jmemcached when it's launched by maven

ragnor commented 10 years ago

I've never used jmemcached with authorization, could you try to disable it in your application and switch to text protocol?

RNiveau commented 10 years ago

Ok, it works with TEXT protocol.

Really weird error. I don't understand the bug but it works now.

Thanks for your help.

ragnor commented 10 years ago

I've found the cause of the bug in the plugin code. The value of binary parameter is not used so always text protocol is enabled.

Thank you for the issue report. I'll fix it in next release.

ragnor commented 10 years ago

Fix is on the master