VerifyError

[radek.koubsky]

Hello,

I am getting VerifyError after running bmsubmit.

Byteman 3.0.2-SNAPSHOT

wildfly-8.2.0.Final

source code: https://github.com/wildfly/wildfly/blob/8.x/ejb3/src/main/java/org/jboss/as/ejb3/component/stateful/StatefulSessionSynchronizationInterceptor.java

Method

@Override
    public Object processInvocation(final InterceptorContext context) throws Exception {
        final StatefulSessionComponent component = getComponent(context, StatefulSessionComponent.class);
        final StatefulSessionComponentInstance instance = getComponentInstance(context);


        final OwnableReentrantLock lock = instance.getLock();
        final Object threadLock = instance.getThreadLock();


        final TransactionSynchronizationRegistry transactionSynchronizationRegistry = component.getTransactionSynchronizationRegistry();
        final Object lockOwner = getLockOwner(transactionSynchronizationRegistry);
        lock.pushOwner(lockOwner);
        try {
            final AccessTimeoutDetails timeout = component.getAccessTimeout(context.getMethod());
            if (ROOT_LOGGER.isTraceEnabled()) {
                ROOT_LOGGER.trace("Trying to acquire lock: " + lock + " for stateful component instance: " + instance + " during invocation: " + context);
            }
            // we obtain a lock in this synchronization interceptor because the lock needs to be tied to the synchronization
            // so that it can released on the tx synchronization callbacks
            boolean acquired = lock.tryLock(timeout.getValue(), timeout.getTimeUnit());
            if (!acquired) {
                throw MESSAGES.failToObtainLock(context, timeout.getValue(), timeout.getTimeUnit());
            }
            synchronized (threadLock) {
                if (ROOT_LOGGER.isTraceEnabled()) {
                    ROOT_LOGGER.trace("Acquired lock: " + lock + " for stateful component instance: " + instance + " during invocation: " + context);
                }


                Object currentTransactionKey = null;
                boolean wasTxSyncRegistered = false;
                try {
                    //we never register a sync for bean managed transactions
                    //the inner BMT interceptor is going to setup the correct transaction anyway
                    //so enrolling in an existing transaction is not correct
                    if(containerManagedTransactions) {
                        if (!instance.isSynchronizationRegistered()) {
                            // get the key to current transaction associated with this thread
                            currentTransactionKey = transactionSynchronizationRegistry.getTransactionKey();
                            final int status = transactionSynchronizationRegistry.getTransactionStatus();
                            // if this SFSB instance is already associated with a different transaction, then it's an error
                            // if the thread is currently associated with a tx, then register a tx synchronization
                            if (currentTransactionKey != null && status != Status.STATUS_COMMITTED && status != Status.STATUS_ROLLEDBACK) {
                                // register a tx synchronization for this SFSB instance
                                final Synchronization statefulSessionSync = new StatefulSessionSynchronization(instance, lockOwner);
                                transactionSynchronizationRegistry.registerInterposedSynchronization(statefulSessionSync);
                                wasTxSyncRegistered = true;
                                if (ROOT_LOGGER.isTraceEnabled()) {
                                    ROOT_LOGGER.trace("Registered tx synchronization: " + statefulSessionSync + " for tx: " + currentTransactionKey +
                                            " associated with stateful component instance: " + instance);
                                }
                                // invoke the afterBegin callback on the SFSB
                                instance.afterBegin();
                                instance.setSynchronizationRegistered(true);
                                context.putPrivateData(StatefulTransactionMarker.class, StatefulTransactionMarker.of(true));
                            }
                        } else {
                            context.putPrivateData(StatefulTransactionMarker.class, StatefulTransactionMarker.of(false));
                        }
                    }
                    // proceed with the invocation
                    return context.proceed();


                } finally {
                    // if the current call did *not* register a tx SessionSynchronization, then we have to explicitly mark the
                    // SFSB instance as "no longer in use". If it registered a tx SessionSynchronization, then releasing the lock is
                    // taken care off by a tx synchronization callbacks.
                    if (!wasTxSyncRegistered && !instance.isSynchronizationRegistered()) {
                        releaseInstance(instance);
                    } else if (!wasTxSyncRegistered) {
                        //if we don't release the lock here then it will be acquired multiple times
                        //and only released once
                        releaseLock(instance);
                        //we also call the cache release to decrease the usage count
                        if (!instance.isDiscarded()) {
                            instance.getComponent().getCache().release(instance);
                        }
                    }
                }
            }
        } finally {
            lock.popOwner();
        }
    }

rule:

#Log StatefulSessionSynchronizationInterceptor - pop lock owner
RULE logStatefulSessionSynchronizationInterceptor.processInvocation.popOwner
CLASS org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor
METHOD processInvocation(InterceptorContext)
AT INVOKE org.jboss.as.ejb3.tx.OwnableReentrantLock.popOwner() ALL
IF true
DO log($CLASS, "DEBUG", "(Method processInvocation) Popping lock owner off the lock.")
ENDRULE

bmsubmit shows me verify error:

VerifyError during retransformation : some rules may not have been correctly injected or uninjected!

java.lang.VerifyError

at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)

at sun.instrument.InstrumentationImpl.retransformClasses(InstrumentationImpl.java:144)

at org.jboss.byteman.agent.Retransformer.installScript(Retransformer.java:144)

at org.jboss.byteman.agent.TransformListener.handleScripts(TransformListener.java:349)

at org.jboss.byteman.agent.TransformListener.loadScripts(TransformListener.java:272)

at org.jboss.byteman.agent.TransformListener.handleConnection(TransformListener.java:225)

at org.jboss.byteman.agent.TransformListener.run(TransformListener.java:158)

NOTE: If I remove ALL counter, it works. But I need to use ALL counter because I want the rule to inject code into every case when program reaches finally block.

[adinn]

Hi Radek,

I am getting VerifyError after running bmsubmit.

Interesting . . .!

Thanks for reporting this.  I will try to reproduce this and see what I can do to fix it.

Meanwhile, could you try to recreate the problem setting two extra properties on the Java command line

java -javaagent:... -Dorg.jboss.byteman.dump.generated.classes -Dorg.jboss.byteman.dump.generated.classes.intermediate ...

The first property configures Byteman so that when it modifies the bytecode for class org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor it dumps the transformed bytecode to a file

  org/jboss/as/ejb3/component/stateful/StatefulSessionSynchronizationInterceptor.class

The class file will be written below the current working directory of the java application. This is probably going to be the same dir as where you start java from (unless the startup script or the app server itself changes the current working directory).

The second flag is needed just in case the class has more than one rule injected into it. In that case Byteman will perform several transformations one after another. This flag ensues that it dumps the bytecode at each stage. In which case you may also see files like StatefulSessionSynchronizationInterceptor_0.class, StatefulSessionSynchronizationInterceptor_1.class , etc.

Could you please attach any resulting .class files to this thread so I can verify the transformed bytecode (by eyeball :-).

[radek.koubsky]

Hi,

ok I started Wildfly with your options, it generated two files, see attachment.

[adinn]

HI Radek,

Thanks very much for the class files. After looking at the source and the bytecode I have managed to create a much simpler class which reproduces the verify error and was able to use it to run java and see the full output from the verifier.

This is a very interesting bug. It seems Byteman is getting mixed up about the scope of the monitorenter + monitorexit byecodes which bracket the synchronized region. Byteman seems to think that the injected code for the outer finally block can be called on a path where a monitorenter has been executed without a corresponding monitorexit. A bytecode dump shows that this is not so. Byteman thinks the locked object is still stored in the lcoals area whereas the verifier knows that the object has been unlocked and hence that the locals slot should be regarded as empty (it's nto actually emptied but logically the object is not available).

The presence of the retun in the inner synchronized block seems to be the key to making this happen. I'll need to walk through the code generation algorithm with a debugger to see what Byteman is getting wrong. I'll let you know when I find more details.

[adinn]

Hi Radek,

I have investigated this and found the root of the problem. I raised  BYTEMAN-297 to document it and record the fix. I have tested the fix on my reproducer and I will push a new snapshot relase for you to use to confirm that it resolves your issue. If so it will go into the next release.

Ok, now close your eyes if you don't want to know the gory details.

Essentally Byteman is incorrectly analysing some of the exception flow  through the method. So, it thinks that an excpetion in the synchronized block can enter the finally block without an intervening monitorexit instruction having been executed.

Synchronized blocks translate to monitorenter and monitorexit bytecodes but note that monitorexit can be executed on both the normal flow path and also on flow thorough to exception handlers. Exception flow passes through an intermediate handler which does the unlock. This intermediate handler is itself protected by two nested try-catch regions. The first guards against any error arising up to the montiorexit and redirects control back to the start of the intermediate handler. The second region covers the whole intermediate handler and guards against any error in the rethrow which redirects control to the fially code. That means that the second region can only generate an exceptional flow of control into the finally block after the locked object has been unlocked by monitorexit.

Byteman failed ot detect this specific nesting of try-catch regions (where the two regiosn start at the same position). So, it assumed that in the finally block the synchronized object might still be locked. As a consequence, whenit injected the rule triggering code it placed a monitorexit into the handlers which deal with exceptions thrown by the rule. The verifier detects that this monitorexit is invalid because the object is guaranteed ot be unlocked by the time control reaches the finally block.

[adinn]

By the way, just for completeness here is the code for the simple reproducer I created

public class FinallyTest
{
    public static void main (String[] args)
    {
        FinallyTest f = new FinallyTest();
        f.test(args.length);
    }
    public void test(int x)
    {
        try {
            synchronized(this) {
                sub(x);
                return;
            }
        } finally {
            System.out.println("outer finally");
            sub2(0);
        }
    }

    public void sub(int x)
    {
        if ((x & 1) != 0) {
            throw new RuntimeException("haha!");
        }
        System.out.println("sub: x = " + x);
    }
    public void sub2(int x) {
        System.out.println("sub2: x = " + x);
    }
}

and here is the Byteman rule which causes the bug to manifest

RULE test finally
CLASS FinallyTest
METHOD test
AT INVOKE sub2 ALL
IF TRUE
DO traceln("test: x = " + $x)
ENDRULE

[adinn]

Hi Radek,

I have uploaded a new shapshot release to maven central. Could you please download it and see if it fixes the original problem. Thanks.

regards,

Andrew Dinn

[radek.koubsky]

Hi,

thanks for trying to fix that. I assume the new snapshot is the byteman-download-3.0.2-20151013.140955-3-full.zip from Tue Oct 13 14:10:01 UTC 2015.

However, I am not able to run my byteman script. I found another exception which could provide you more information.

The original VerifyError showed up after these steps:

I have running wildfly instance

1) I add the ALL counter to the rule

2) I run bmsubmit /path/to/script

3) I run bmsubmit

Now I just run Wildfly which loads the script at start, and it shows this exception (and it shows it with the previous byteman snapshot as well):

22:40:43,834 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-5) MSC000001: Failed to start service jboss.deployment.subunit."wildfly-ejb-in-ear-ear.ear"."wildfly-ejb-in-ear-ejb.jar".INSTALL: org.jboss.msc.service.StartException in service jboss.deployment.subunit."wildfly-ejb-in-ear-ear.ear"."wildfly-ejb-in-ear-ejb.jar".INSTALL: JBAS018733: Failed to process phase INSTALL of subdeployment "wildfly-ejb-in-ear-ejb.jar" of deployment "wildfly-ejb-in-ear-ear.ear"
  at org.jboss.as.server.deployment.DeploymentUnitPhaseService.start(DeploymentUnitPhaseService.java:166) [wildfly-server-8.2.0.Final.jar:8.2.0.Final]
  at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1948) [jboss-msc-1.2.2.Final.jar:1.2.2.Final]
  at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1881) [jboss-msc-1.2.2.Final.jar:1.2.2.Final]
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_80]
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_80]
  at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_80]
Caused by: java.lang.VerifyError: Bad local variable type
Exception Details:
  Location:
    org/jboss/as/ejb3/component/stateful/StatefulSessionSynchronizationInterceptor.processInvocation(Lorg/jboss/invocation/InterceptorContext;)Ljava/lang/Object; @1145: aload
  Reason:
    Type top (current frame, locals[10]) is not assignable to reference type
  Current Frame:
    bci: @1145
    flags: { }
    locals: { 'org/jboss/as/ejb3/component/stateful/StatefulSessionSynchronizationInterceptor', 'org/jboss/invocation/InterceptorContext', 'org/jboss/as/ejb3/component/stateful/StatefulSessionComponent', 'org/jboss/as/ejb3/component/stateful/StatefulSessionComponentInstance', 'org/jboss/as/ejb3/tx/OwnableReentrantLock', 'java/lang/Object', 'javax/transaction/TransactionSynchronizationRegistry', 'java/lang/Object', top, top, top, top, top, top, top, top, top, 'java/lang/Throwable' }
    stack: { 'org/jboss/byteman/rule/exception/ExecuteException' }
  Bytecode:
    0000000: 2b12 2cb8 0030 c000 2c4d 2bb8 0036 4e12
    0000010: 382a 05bd 003a 5903 2d53 5904 123c 53b8
    0000020: 0042 2db6 004e 3a04 1250 2a05 bd00 3a59
    0000030: 0319 0453 5904 123c 53b8 0042 2db6 0054
    0000040: 3a05 1256 2a05 bd00 3a59 0319 0553 5904
    0000050: 123c 53b8 0042 2cb6 005a 3a06 1906 b800
    0000060: 5e3a 0719 0419 0712 602a 05bd 003a 5903
    0000070: 1907 5359 0412 3c53 b800 42b6 0066 2c2b
    0000080: b600 6cb6 0070 3a08 b200 76b9 007a 0100
    0000090: 9900 31b2 0076 bb00 7c59 b700 7d12 7fb6
    00000a0: 0083 1904 b600 8612 88b6 0083 2db6 0086
    00000b0: 128a b600 832b b600 86b6 008e b900 9102
    00000c0: 0019 0419 08b6 0097 1908 b600 9bb6 009f
    00000d0: 3609 12a1 2a05 bd00 3a59 0315 09bb 00a3
    00000e0: 5a5f b700 a653 5904 123c 53b8 0042 12a8
    00000f0: 2a05 bd00 3a59 0319 0853 5904 123c 53b8
    0000100: 0042 1509 9a00 17b2 00ae 2b19 08b6 0097
    0000110: 1908 b600 9bb9 00b2 0500 bf19 0559 3a0a
    0000120: c2b2 0076 b900 7a01 0099 0031 b200 76bb
    0000130: 007c 59b7 007d 12b4 b600 8319 04b6 0086
    0000140: 1288 b600 832d b600 8612 8ab6 0083 2bb6
    0000150: 0086 b600 8eb9 0091 0200 013a 0b03 360c
    0000160: 2ab4 0024 9901 252d b600 b712 b92a 05bd
    0000170: 003a 5903 2d53 5904 123c 53b8 0042 12bb
    0000180: 2a05 bd00 3a59 032d 5359 0412 3c53 b800
    0000190: 429a 00ed 1906 b900 c001 003a 0b12 c22a
    00001a0: 05bd 003a 5903 190b 5359 0412 3c53 b800
    00001b0: 4219 06b9 00c6 0100 360d 12c8 2a05 bd00
    00001c0: 3a59 0315 0dbb 00a3 5a5f b700 a653 5904
    00001d0: 123c 53b8 0042 190b c600 a315 0d06 9f00
    00001e0: 9d15 0d07 9f00 97bb 0007 592a 2d19 07b7
    00001f0: 00cb 3a0e 1906 190e b900 cf02 0004 360c
    0000200: b200 76b9 007a 0100 9900 32b2 0076 bb00
    0000210: 7c59 b700 7d12 d1b6 0083 190e b600 8612
    0000220: d3b6 0083 190b b600 8612 d5b6 0083 2db6
    0000230: 0086 b600 8eb9 0091 0200 2d12 d72a 04bd
    0000240: 003a 5903 123c 53b8 0042 b600 da2d 0412
    0000250: dc2a 04bd 003a 5903 123c 53b8 0042 b600
    0000260: df2b 12e1 04b8 00e5 b600 e912 eb2a 04bd
    0000270: 003a 5903 123c 53b8 0042 57a7 000e 2b12
    0000280: e103 b800 e5b6 00e9 572b 12ed 2a04 bd00
    0000290: 3a59 0312 3c53 b800 42b6 00f0 3a0d 150c
    00002a0: 9a00 212d b600 b79a 001a 2a2d 12f2 2a04
    00002b0: bd00 3a59 0312 3c53 b800 42b6 00f6 a700
    00002c0: 4415 0c9a 003f 2a2d 12f8 2a05 bd00 3a59
    00002d0: 032d 5359 0412 3c53 b800 42b6 00fb 2db6
    00002e0: 00fe 9a00 202d b601 01b6 0105 2d13 0107
    00002f0: 2a04 bd00 3a59 0312 3c53 b800 42b9 010d
    0000300: 0200 190a c319 0413 010f 2a04 bd00 3a59
    0000310: 0312 3c53 b800 42b6 0112 190d b03a 0f15
    0000320: 0c9a 0021 2db6 00b7 9a00 1a2a 2d12 f22a
    0000330: 04bd 003a 5903 123c 53b8 0042 b600 f6a7
    0000340: 0044 150c 9a00 3f2a 2d12 f82a 05bd 003a
    0000350: 5903 2d53 5904 123c 53b8 0042 b600 fb2d
    0000360: b600 fe9a 0020 2db6 0101 b601 052d 1301
    0000370: 072a 04bd 003a 5903 123c 53b8 0042 b901
    0000380: 0d02 0019 0fbf 3a10 190a c319 10bf 3a11
    0000390: 1904 1301 0f2a 04bd 003a 5903 123c 53b8
    00003a0: 0042 b601 1219 11bf b601 15b0 b601 19bf
    00003b0: bfb6 0115 b0b6 0119 bfbf b601 15b0 b601
    00003c0: 19bf bfb6 0115 b0b6 0119 bfbf b601 15b0
    00003d0: b601 19bf bfb6 0115 b0b6 0119 bfbf 190a
    00003e0: c3bf b601 15b0 b601 19bf bf19 0ac3 bfb6
    00003f0: 0115 b0b6 0119 bfbf 190a c3bf b601 15b0
    0000400: b601 19bf bf19 0ac3 bfb6 0115 b0b6 0119
    0000410: bfbf 190a c3bf b601 15b0 b601 19bf bf19
    0000420: 0ac3 bfb6 0115 b0b6 0119 bfbf 190a c3bf
    0000430: b601 15b0 b601 19bf bf19 0ac3 bfb6 0115
    0000440: b0b6 0119 bfbf 190a c3bf 190a c3bf b601
    0000450: 15b0 b601 19bf bf19 0ac3 bf19 0ac3 bfb6
    0000460: 0115 b0b6 0119 bfbf 190a c3bf 190a c3bf
    0000470: b601 15b0 b601 19bf bf19 0ac3 bfb6 0115
    0000480: b0b6 0119 bfbf                        
  Exception Handler Table:
    bci [15, 34] => handler: 936
    bci [15, 34] => handler: 940
    bci [15, 34] => handler: 944
    bci [40, 60] => handler: 945
    bci [40, 60] => handler: 949
    bci [40, 60] => handler: 953
    bci [66, 86] => handler: 954
    bci [66, 86] => handler: 958
    bci [66, 86] => handler: 962
    bci [103, 123] => handler: 963
    bci [103, 123] => handler: 967
    bci [103, 123] => handler: 971
    bci [210, 238] => handler: 981
    bci [210, 238] => handler: 985
    bci [210, 238] => handler: 989
    bci [210, 258] => handler: 972
    bci [210, 258] => handler: 976
    bci [210, 258] => handler: 980
    bci [363, 382] => handler: 1068
    bci [382, 401] => handler: 990
    bci [413, 433] => handler: 1003
    bci [442, 470] => handler: 1016
    bci [571, 586] => handler: 1029
    bci [591, 606] => handler: 1042
    bci [619, 634] => handler: 1055
    bci [650, 665] => handler: 1081
    bci [352, 670] => handler: 797
    bci [684, 699] => handler: 1094
    bci [712, 731] => handler: 1111
    bci [749, 765] => handler: 1128
    bci [289, 773] => handler: 902
    bci [126, 773] => handler: 910
    bci [775, 791] => handler: 1149
    bci [775, 791] => handler: 1153
    bci [775, 791] => handler: 1157
    bci [797, 799] => handler: 797
    bci [813, 828] => handler: 1098
    bci [841, 860] => handler: 1115
    bci [878, 894] => handler: 1132
    bci [797, 907] => handler: 902
    bci [797, 912] => handler: 910
    bci [914, 930] => handler: 1145
    bci [990, 994] => handler: 994
    bci [990, 994] => handler: 998
    bci [990, 994] => handler: 1002
    bci [1003, 1007] => handler: 1007
    bci [1003, 1007] => handler: 1011
    bci [1003, 1007] => handler: 1015
    bci [1016, 1020] => handler: 1020
    bci [1016, 1020] => handler: 1024
    bci [1016, 1020] => handler: 1028
    bci [1029, 1033] => handler: 1033
    bci [1029, 1033] => handler: 1037
    bci [1029, 1033] => handler: 1041
    bci [1042, 1046] => handler: 1046
    bci [1042, 1046] => handler: 1050
    bci [1042, 1046] => handler: 1054
    bci [1055, 1059] => handler: 1059
    bci [1055, 1059] => handler: 1063
    bci [1055, 1059] => handler: 1067
    bci [1068, 1072] => handler: 1072
    bci [1068, 1072] => handler: 1076
    bci [1068, 1072] => handler: 1080
    bci [1081, 1085] => handler: 1085
    bci [1081, 1085] => handler: 1089
    bci [1081, 1085] => handler: 1093
    bci [1094, 1098] => handler: 1102
    bci [1094, 1098] => handler: 1106
    bci [1094, 1098] => handler: 1110
    bci [1098, 1102] => handler: 1102
    bci [1098, 1102] => handler: 1106
    bci [1098, 1102] => handler: 1110
    bci [1111, 1115] => handler: 1119
    bci [1111, 1115] => handler: 1123
    bci [1111, 1115] => handler: 1127
    bci [1115, 1119] => handler: 1119
    bci [1115, 1119] => handler: 1123
    bci [1115, 1119] => handler: 1127
    bci [1128, 1132] => handler: 1136
    bci [1128, 1132] => handler: 1140
    bci [1128, 1132] => handler: 1144
    bci [1132, 1136] => handler: 1136
    bci [1132, 1136] => handler: 1140
    bci [1132, 1136] => handler: 1144
    bci [1145, 1149] => handler: 1149
    bci [1145, 1149] => handler: 1153
    bci [1145, 1149] => handler: 1157
  Stackmap Table:
    full_frame(@193,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147]},{})
    append_frame(@283,Integer)
    append_frame(@346,Object[#58])
    full_frame(@570,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Integer,Object[#7]},{})
    chop_frame(@635,1)
    full_frame(@638,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Null,Integer},{})
    full_frame(@649,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{})
    append_frame(@705,Object[#58])
    same_frame_extended(@770)
    full_frame(@797,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{Object[#305]})
    append_frame(@834,Top,Top,Object[#305])
    same_frame_extended(@899)
    full_frame(@902,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58]},{Object[#305]})
    full_frame(@910,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58]},{Object[#305]})
    full_frame(@936,{Object[#2],Object[#104],Object[#44],Object[#74]},{Object[#68]})
    same_locals_1_stack_item_frame(@940,Object[#70])
    same_locals_1_stack_item_frame(@944,Object[#72])
    full_frame(@945,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98]},{Object[#68]})
    same_locals_1_stack_item_frame(@949,Object[#70])
    same_locals_1_stack_item_frame(@953,Object[#72])
    full_frame(@954,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58]},{Object[#68]})
    same_locals_1_stack_item_frame(@958,Object[#70])
    same_locals_1_stack_item_frame(@962,Object[#72])
    full_frame(@963,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58]},{Object[#68]})
    same_locals_1_stack_item_frame(@967,Object[#70])
    same_locals_1_stack_item_frame(@971,Object[#72])
    full_frame(@972,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer},{Object[#68]})
    same_locals_1_stack_item_frame(@976,Object[#70])
    same_locals_1_stack_item_frame(@980,Object[#72])
    same_locals_1_stack_item_frame(@981,Object[#68])
    same_locals_1_stack_item_frame(@985,Object[#70])
    same_locals_1_stack_item_frame(@989,Object[#72])
    full_frame(@990,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Null,Integer},{Object[#72]})
    same_locals_1_stack_item_frame(@994,Object[#68])
    same_locals_1_stack_item_frame(@998,Object[#70])
    same_locals_1_stack_item_frame(@1002,Object[#72])
    full_frame(@1003,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{Object[#72]})
    same_locals_1_stack_item_frame(@1007,Object[#68])
    same_locals_1_stack_item_frame(@1011,Object[#70])
    same_locals_1_stack_item_frame(@1015,Object[#72])
    full_frame(@1016,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Integer},{Object[#72]})
    same_locals_1_stack_item_frame(@1020,Object[#68])
    same_locals_1_stack_item_frame(@1024,Object[#70])
    same_locals_1_stack_item_frame(@1028,Object[#72])
    full_frame(@1029,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Integer,Object[#7]},{Object[#72]})
    same_locals_1_stack_item_frame(@1033,Object[#68])
    same_locals_1_stack_item_frame(@1037,Object[#70])
    same_locals_1_stack_item_frame(@1041,Object[#72])
    same_locals_1_stack_item_frame(@1042,Object[#72])
    same_locals_1_stack_item_frame(@1046,Object[#68])
    same_locals_1_stack_item_frame(@1050,Object[#70])
    same_locals_1_stack_item_frame(@1054,Object[#72])
    same_locals_1_stack_item_frame(@1055,Object[#72])
    same_locals_1_stack_item_frame(@1059,Object[#68])
    same_locals_1_stack_item_frame(@1063,Object[#70])
    same_locals_1_stack_item_frame(@1067,Object[#72])
    full_frame(@1068,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Null,Integer},{Object[#72]})
    same_locals_1_stack_item_frame(@1072,Object[#68])
    same_locals_1_stack_item_frame(@1076,Object[#70])
    same_locals_1_stack_item_frame(@1080,Object[#72])
    full_frame(@1081,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{Object[#72]})
    same_locals_1_stack_item_frame(@1085,Object[#68])
    same_locals_1_stack_item_frame(@1089,Object[#70])
    same_locals_1_stack_item_frame(@1093,Object[#72])
    full_frame(@1094,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Object[#58]},{Object[#72]})
    full_frame(@1098,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Top,Top,Object[#305]},{Object[#72]})
    full_frame(@1102,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{Object[#68]})
    same_locals_1_stack_item_frame(@1106,Object[#70])
    same_locals_1_stack_item_frame(@1110,Object[#72])
    full_frame(@1111,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Object[#58]},{Object[#72]})
    full_frame(@1115,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Top,Top,Object[#305]},{Object[#72]})
    full_frame(@1119,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{Object[#68]})
    same_locals_1_stack_item_frame(@1123,Object[#70])
    same_locals_1_stack_item_frame(@1127,Object[#72])
    full_frame(@1128,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Object[#58]},{Object[#72]})
    full_frame(@1132,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer,Top,Top,Object[#305]},{Object[#72]})
    full_frame(@1136,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Object[#147],Integer,Object[#58],Object[#58],Integer},{Object[#68]})
    same_locals_1_stack_item_frame(@1140,Object[#70])
    same_locals_1_stack_item_frame(@1144,Object[#72])
    full_frame(@1145,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58],Top,Top,Top,Top,Top,Top,Top,Top,Top,Object[#305]},{Object[#72]})
    full_frame(@1149,{Object[#2],Object[#104],Object[#44],Object[#74],Object[#98],Object[#58],Object[#189],Object[#58]},{Object[#68]})
    same_locals_1_stack_item_frame(@1153,Object[#70])
    same_locals_1_stack_item_frame(@1157,Object[#72])


  at org.jboss.as.ejb3.component.stateful.StatefulComponentDescription$2.configure(StatefulComponentDescription.java:160)
  at org.jboss.as.ee.component.deployers.EEModuleConfigurationProcessor.deploy(EEModuleConfigurationProcessor.java:81)
  at org.jboss.as.server.deployment.DeploymentUnitPhaseService.start(DeploymentUnitPhaseService.java:159) [wildfly-server-8.2.0.Final.jar:8.2.0.Final]
  ... 5 more

[adinn]

Hi Radek,

Is this stlll the same rule set that I downloaded a few days ago and used ot identify the ClassCastException problem? If so then I will use it to reproduce the problem on my latets tree (whihc includes the local boolean fix),. If not then can I just pull your latest git repo and deploy the code form there as you described previously? Or do I also need to edit standalone.conf to include other rule sscritps in the -javagent options? and also do I need to run somethngn other than the ejb quickstart to reproduce it?

n.b. I only used two rules from the ejb script to reproduce the local boolean problme and only tested the fix with the same two rules in place. So, it would be good to know if the problem you are seeing is caused by some other ejb script rule or by a rul ein some other part. Wa sthere a message preceding the verify error which indicated what rule was being injected when the problem arose?

Also. I have uploaded a 4th SNAPSHOT to tehsnapshots repo

  https://oss.sonatype.org/content/repositories/snapshots/org/jboss/byteman/byteman/3.0.2-SNAPSHOT/byteman-3.0.2-20151015.101401-4.jar

This snapshot includes the boolan local fix. I doubt that this latest bug is caused by the local boolean fix being missing from the previous snapshot but you might as well have a jar with that fix in just so we can rule that out and also so you can get your lock check rule (the one which mentions $acquired) to work.

[adinn]

Hi Radek,

I eread your original comments and worked out what rule to change n order ot reproduce the second problem:

in

RULE logStatefulSessionSynchronizationInterceptor.processInvocation.popOwner

change location to

AT INVOKE org.jboss.as.ejb3.tx.OwnableReentrantLock.popOwner() ALL

I'm looking into this now

regars,

Andrew Dinn

[radek.koubsky]

Hi,

ok, I try to be more specific.

To my environment:

I downloaded the https://oss.sonatype.org/content/repositories/snapshots/org/jboss/byteman/byteman-download/3.0.2-SNAPSHOT/byteman-downlo…, then I downloaded your new jar https://oss.sonatype.org/content/repositories/snapshots/org/jboss/byteman/byteman/3.0.2-SNAPSHOT/byteman-3.0.2-20151015.… and replaced the old jar in the byteman directory (extracted from the zip) with the new one.

My script:

I use only the ejb.btm script from my github repo. Nothing has changed with the original rule, I only added new rules.

Rule with VerifyError:

I tested your fix with the same rule as the one  at the start of this discussion:

#Log StatefulSessionSynchronizationInterceptor - pop lock owner
RULE logStatefulSessionSynchronizationInterceptor.processInvocation.popOwner
CLASS org.jboss.as.ejb3.component.stateful.StatefulSessionSynchronizationInterceptor
METHOD processInvocation(InterceptorContext)
AT INVOKE org.jboss.as.ejb3.tx.OwnableReentrantLock.popOwner() ALL
IF true
DO log($CLASS, "DEBUG", "(Method processInvocation) Popping lock owner off the lock.")
ENDRULE

NOTE: In my repo, there is no ALL counter because I needed to run and test other rules and it was not possible with the VerifyError.

1) VerifyError after submitting rule to running Wildfly instance

This is the original problem. I have running Wildlfy instance. I add the "ALL" counter to the rule and then run "bmsubmit path/to/my/script" which tries to redefine my rules and it fails at the logStatefulSessionSynchronizationInterceptor.processInvocation.popOwner rule with the java.lang.VerifyError. I tried it just now with the latest version of byteman jar and it is giving me the same java.lang.VerifyError.

2) VerifyError when Wildfly starts with byteman script which contains the rule with ALL counter

This is the second problem. After running Wildfly, there is another java.lang.VerifyError in logs which is described in my last reply before this one.

FYI: I am going abroad for a few days until Monday 19, so I will be able to reply on Monday evening.

[adinn]

HI Radek,

I finally managed to pin down a second problem with injecting into finally blocks and I now have a fix for it.

It seems to fix the problem with the version of your rule which uses location

  AT INVOKE org.jboss.as.ejb3.tx.OwnableReentrantLock.popOwner() ALL

The Byteman issue for the bug is BYTEMAN-299. I have pushed a new snapshot for you to try (byteman-3.0.2-20151026.154644-5.jar). Could you try it and confirm whether or not it fixes with the latest problem you have seen?

[radek.koubsky]

Hi Andrew,

I have good news for you, I just tried to run Wildfly with the script and it works. Reinstalling the rule with bmsubmit works as well. So thanks again for fixing it. I finished work on my project for now, I wrote little documentation on the github page, feel free to use it.

[adinn]

Hi Radek,

Radek Koubský wrote:

Hi Andrew,

I have good news for you, I just tried to run Wildfly with the script and it works. Reinstalling the rule with bmsubmit works as well. So thanks again for fixing it. I finished work on my project for now, I wrote little documentation on the github page, feel free to use it.

Excellent news! Thanks very much for confirming the fix. The project looks really useful

I will mention your project in the 3.0.2 release announcement. It's a very good example of how Byteman can be used to implement a log/trace facility. I'll also give credit for all your effort in helping identify and test the issues that came up.