[rhauch]

I should add that even when I have the "...bmunit.versbose" set to "false", I still get these in the console:

BMUNit : loading agent id = 4142

byteman jar is /Users/rhauch/.m2/repository/org/jboss/byteman/byteman/1.5.1/byteman-1.5.1.jar

BMUNit : loading file script = src/test/byteman/jcr-configuration-failure.txt

BMUNit : unloading file script = src/test/byteman/jcr-configuration-failure.txt

BMUNit : loading file script = src/test/byteman/jcr-performance.txt

BMUNit : unloading file script = src/test/byteman/jcr-performance.txt

[adinn]

Randall Hauch wrote:

I've started using Byteman 1.5.1 (thanks, btw!), and everything works great in Eclipse and in Maven using Surefire as long as I use this configuration for the Surefire plugin:

  <configuration>

    <systemProperties>

      <property>

        <name>org.jboss.byteman.contrib.bmunit.verbose</name>

        <value>false</value>

      </property>

    </systemProperties>

    <skip>false</skip>

    <additionalClasspathElements>

      <additionalClasspathElement>${env.JAVA_HOME}/lib/tools.jar</additionalClasspathElement>

    </additionalClasspathElements>

  </configuration>

However, if I remove the "systemProperties" fragment, I get this error on System.out/err:

     java.lang.Exception: BMUnit : Unable to identify test JVM process during agent load

and this result in my unit tests:

java.lang.Exception: Unexpected exception, expected<java.lang.SecurityException> but was<java.net.ConnectException>

          at org.junit.internal.runners.statements.ExpectException.evaluate(ExpectException.java:28)

          . . .

Caused by: java.net.ConnectException: Connection refused

          at java.net.PlainSocketImpl.socketConnect(Native Method)

          at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)

          at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)

          at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)

          at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:432)

          at java.net.Socket.connect(Socket.java:529)

          at java.net.Socket.connect(Socket.java:478)

          at java.net.Socket.<init>(Socket.java:375)

          at java.net.Socket.<init>(Socket.java:189)

          at org.jboss.byteman.agent.submit.Submit$Comm.<init>(Submit.java:797)

          at org.jboss.byteman.agent.submit.Submit.submitRequest(Submit.java:735)

          at org.jboss.byteman.agent.submit.Submit.addScripts(Submit.java:574)

          at org.jboss.byteman.agent.submit.Submit.addRulesFromFiles(Submit.java:547)

          at org.jboss.byteman.contrib.bmunit.BMUnit.loadScriptFile(BMUnit.java:295)

          at org.jboss.byteman.contrib.bmunit.BMUnitRunner$5.evaluate(BMUnitRunner.java:248)

          at org.junit.internal.runners.statements.ExpectException.evaluate(ExpectException.java:21)

Any ideas what might be happening? Might it be the timing? For now I can keep the property in the pom.xml file, but it just seems odd. I can log an bug report if you think that's appropriate.

Hmm, that's very strange. I don't know why that is happening. I'll see if I can find out what is happening.

Is this  just for a specific test or for allyour tests?

Can you point me at some code which reproduces the problem?

[adinn]

Randall Hauch wrote:

I should add that even when I have the "...bmunit.versbose" set to "false", I still get these in the console:

BMUNit : loading agent id = 4142

byteman jar is /Users/rhauch/.m2/repository/org/jboss/byteman/byteman/1.5.1/byteman-1.5.1.jar

BMUNit : loading file script = src/test/byteman/jcr-configuration-failure.txt

BMUNit : unloading file script = src/test/byteman/jcr-configuration-failure.txt

BMUNit : loading file script = src/test/byteman/jcr-performance.txt

BMUNit : unloading file script = src/test/byteman/jcr-performance.txt

Yes, that's expected. The verbose mode is switched on by setting the System property to any non-null value. It's not a boolean. The same applies witht he agent verbose property org.jboss.byteman.verbose. This may possibly have been a bad choice :-)

[adinn]

Hi Randall,

I think this might be something to do with class leakage between the submit jar and the agent jar.

What is the order of the byteman jars in your dependency list? Well, actually, I don't know if there is any guarantee what order maven adds these jars to the classpath. What I really need to know is what is the order when they appear in the test JVM classpath -- you could print the value of System.getProperty("java.class.path") from your test to identify this. Does the agent jar precede

Could you try removing the dependency on byteman-submit.jar and see what happens?

[rhauch]

Can you point me at some code which reproduces the problem?

Sure. I just pushed my code into the 'mode-1085' branch in my GitHub fork:

     $ git clone git://github.com/rhauch/modeshape.git --depth 1 --branch mode-1085

     $ cd modeshape

If you don't have git, then you can get the source as a ZIP file and automatically extract it, using

     $ curl -L https://github.com/rhauch/modeshape/zipball/mode-1085 | tar xz

     $ cd rhauch-modeshape-4bff2cb

You can then build everything first (takes about 4 minutes, or longer if dependencies must be downloaded from the JBoss Maven repository):

     $ mvn -Pintegration install -DskipTests     # takes about 4 minutes, longer if dependencies have to be downloaded first

And then you can go into the module where we've started using Byteman and run the test case as is:

     $ cd modeshape-integration

     $ mvn install -Dtest=JcrEnginePerformanceTest

It should run successfully. Then edit the POM file in that module to remove the "systemProperties" fragment (near the bottom of the file) as described above, save the file, and the same test should fail at the command line:

     $ vi pom.xml

     $ mvn install -Dtest=JcrEnginePerformanceTest

Hopefully that helps.

[rhauch]

Could you try removing the dependency on byteman-submit.jar and see what happens?

Yup. Removing that dependency and removing the "systemProperties" fragment results in the same error I mentioned earlier (from running with the 'byteman-submit' dependency and no "systemProperties" fragment).

[rhauch]

And I should add that putting the systemProperties back but still having no dependency on the 'byteman-submit' artifact results in success tests with debug output printed to the console.

[adinn]

Hi Randall,

Well, I downloaded and built modeshape and ran the test and it worked on my system in both cases i.e. with or without the system property setting. So, I can only assume this is either a timing bug or something to do with your runtime is set up. What OS and JDK are you using? What is set in your shell  environment?

Could you try debugging the test on you rsystem to see if the agent gets installed successfully? A breakpoint in method

  org.jboss.byteman.agent.install.Install.install()

would allow you to see the agent being loaded from the client side. A breakpoint in

  org.jboss.byteman.agent.TransformListener.run()

would allow you to check that the agent is installed and  listening for requests to submit rules for upload.

[rhauch]

I'm on OS-X using bash, and here's the Java and Maven info:

$ java -version

Java(TM) SE Runtime Environment (build 1.6.0_22-b04-307-10M3261)

Java HotSpot(TM) 64-Bit Server VM (build 17.1-b03-307, mixed mode)

$ mvn --version

Apache Maven 2.2.1 (r801777; 2009-08-06 14:16:01-0500)

Java version: 1.6.0_22

Java home: /System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home

Default locale: en_US, platform encoding: MacRoman

OS name: "mac os x" version: "10.6.6" arch: "x86_64" Family: "mac"

Trying to remotely debug now.

[rhauch]

Could you try debugging the test on you rsystem to see if the agent gets installed successfully? A breakpoint in method

  org.jboss.byteman.agent.install.Install.install()

would allow you to see the agent being loaded from the client side. A breakpoint in

  org.jboss.byteman.agent.TransformListener.run()

would allow you to check that the agent is installed and  listening for requests to submit rules for upload.

BTW, there is no source for the "byteman-install" and "byteman-bmunit" artifacts in the Maven repository.

[rhauch]

When I remotely debugged, and stepped through the "install" and "run" methods **with the verbose property set**, my remote debugger was able to connect and step through both methods. However, when I remove the "systemProperties" fragment, my unit test waited normally and my remote debugger connected successfully, but the test immediately failed without stopping in either of those methods.

Let me know if there's anything else you want me to try.

[adinn]

Hi Randall,

Randall Hauch wrote:

BTW, there is no source for the "byteman-install" and "byteman-bmunit" artifacts in the Maven repository.

Yes, that's because the pom is a lie. The sources for all  the 1.5.1 jars are in byteman-sources.jar. One day (TM) I will  mavenize byteman from a git repo. For now it is an ant/svn fraud.

[adinn]

Hmm, here is my env

[adinn@localhost adinn]$ uname -a

Linux localhost.localdomain 2.6.34.7-66.fc13.x86_64 #1 SMP Wed Dec 15 07:04:30 UTC 2010 x86_64 x86_64 x86_64 GNU/Linux

[adinn@localhost adinn]$ java -version

java version "1.6.0_21"

Java(TM) SE Runtime Environment (build 1.6.0_21-b06)

Java HotSpot(TM) 64-Bit Server VM (build 17.0-b16, mixed mode)

[adinn@localhost adinn]$ mvn -v

Maven version: 2.0.10

Java version: 1.6.0_21

OS name: "linux" version: "2.6.34.7-66.fc13.x86_64" arch: "amd64" Family: "unix"

[adinn@localhost adinn]$

So, one big difference is OS/X. I also have two processors (Core 2 Duo) -- is your hw just one core or more?

Randall Hauch wrote:

When I remotely debugged, and stepped through the "install" and "run" methods **with the verbose property set**, my remote debugger was able to connect and step through both methods. However, when I remove the "systemProperties" fragment, my unit test waited normally and my remote debugger connected successfully, but the test immediately failed without stopping in either of those methods.

Let me know if there's anything else you want me to try.

I was thinking might be a synchronization bug -- the agent installer on the server side of the agent upload creates an agent listener thread but does not wait to ensure it has opened the socket before returning control back to the client side. That might mean that the test script upload is attempted before the agent listener is is listening. However, the behaviour you see in the debugger seems to suggest otherwise.

Could you try breaking in  java.lang.Runtime.exit() and checking  the stack to see what thread is exiting and  -- maybe -- why? That might reveal something about what is going wrong. Meanwhile I will see if I can prepare a 1.5.2 snapshot which patches the listener startup so it synchronizes before returning. Also, thanks very much for helping to debug this.

[rhauch]

So, one big difference is OS/X. I also have two processors (Core 2 Duo) -- is your hw just one core or more?

I've got a 2.4GHz Core 2 Duo.

I was thinking might be a synchronization bug -- the agent installer on the server side of the agent upload creates an agent listener thread but does not wait to ensure it has opened the socket before returning control back to the client side. That might mean that the test script upload is attempted before the agent listener is is listening. However, the behaviour you see in the debugger seems to suggest otherwise.

Just to be clear, when I run the debugger it works fine, so I can't actually debug what is going wrong (e.g., looking in Runtime.exit()). It always seems to run fine in Eclipse, and always runs fine when running Maven (Surefire) when remotely debugging or when verbose logging is turned on. It never succeeds for me when running Maven (Surefire) at the command line when no verbose logging or debugging. That does sound to me like a timing issue, and your explanation that the test script completing before the agent listener is listening sounds reasonable.

[adinn]

Randall Hauch wrote:

Just to be clear, when I run the debugger it works fine, so I can't actually debug what is going wrong (e.g., looking in Runtime.exit()). It always seems to run fine in Eclipse, and always runs fine when running Maven (Surefire) when remotely debugging or when verbose logging is turned on. It never succeeds for me when running Maven (Surefire) at the command line when no verbose logging or debugging. That does sound to me like a timing issue, and your explanation that the test script completing before the agent listener is listening sounds reasonable.

Yes, it sounds  reasonable until I look at the agent install code. The agent main routine calls Retransformer.addListener() before it returns. This calls static method TransformListener.initialize() which executes this

            theServerSocket = new ServerSocket();
            theServerSocket.bind(new InetSocketAddress(hostname, port.intValue()));
            . . .
            theTransformListener = new TransformListener(retransformer);
            theTransformListener.start();

theTransformListener is a TransformListener thread with this run method

    public void run()
    {
        // we don't want to see any triggers in the listener thread

        Rule.disableTriggersInternal();

        while (true) {
            if (theServerSocket.isClosed()) {
                return;
            }
            Socket socket = null;
            try {
                socket = theServerSocket.accept();
            } catch (IOException e) {
                if (!theServerSocket.isClosed()) {
                    System.out.println("TransformListener.run : exception from server socket accept " + e);
                    e.printStackTrace();
                }
                return;
            }

            if (Transformer.isVerbose()) {
                System.out.println("TransformListener() : handling connection on port " + socket.getLocalPort());
            }
            try {
                handleConnection(socket);
            } catch (Exception e) {
                System.out.println("TransformListener() : error handling connection on port " + socket.getLocalPort());
                try {
                    socket.close();
                } catch (IOException e1) {
                    // do nothing
                }
            }
        }
    }

So, the server socket is bound before the agent install operation completes. The listener thread may not have entered accept() by the time the submit call occurs but there should not be a connection error because the socket has been bound. So, my idea  that this is a timing  issue in the agent soundsl like it is incorrect. I'm really puzzled now.