Dynamic Bytecode Instrumentation fails without any error

Question

Objective

I'm doing dynamic bytecode instrumentation using a JVMTI agent. I have to instrument those methods which are "hot", that is, the methods which invoke JIT compiler. To do so I listen to a CompiledLoadEvent and inside its call back function, call RetransformClasses. This in turn invokes ClassFileLoadHook on the class containing "hot" function and actual instrumentation begins.

Problem Premises

Currently I'm instrumenting my class to spawn some threads. I also listen to thread starts and print them within my agent. With simple ClassFileLoadHook at class load time (without RetransformClasses), my instrumentation works perfectly and spawns new threads. I get following output when ClassFileLoadHook instruments at class load time:

Running Thread: Signal Dispatcher, Priority: 9, context class loader:Not Null
Running Thread: main, Priority: 5, context class loader:Not Null
Running Thread: Thread-0, Priority: 5, context class loader:Not Null
Running Thread: Thread-1, Priority: 5, context class loader:Not Null
Running Thread: Thread-2, Priority: 5, context class loader:Not Null
Running Thread: Thread-3, Priority: 5, context class loader:Not Null
Running Thread: Thread-4, Priority: 5, context class loader:Not Null
Running Thread: Thread-6, Priority: 5, context class loader:Not Null
Running Thread: Thread-5, Priority: 5, context class loader:Not Null
Running Thread: Thread-7, Priority: 5, context class loader:Not Null
Running Thread: DestroyJavaVM, Priority: 5, context class loader:: NULL

When I instrument the class file by invoking RetransformClasses and then ClassFileLoadHook, everything works fine but no threads are spawned and hence no effective instrumentation takes place. VM takes a long time even to execute the original code.

I double checked both instrumentations using -XX:+TraceClassLoading. All the retransformed classes are loaded in both cases. Even the class I'm generating during runtime also gets loaded but no instrumentation happens. Below is the output of class loading trace:

[Loaded Test from __VM_RedefineClasses__]
[Loaded Test_Worker_main_0 from file:/home/saqib/workspace/test/bin]

I'm generating second class during runtime and it loads into VM but I don't get any thread spawning.

Questions

• Given my understanding of the problem (There is a high probability that I'd be wrong), why ClassFileLoadHook retransforms the class successfully during load time, but somehow doesn't behave correctly when JIT is invoked?
• Just writing the RetransformClasses function, with empty ClassFileLoadHook call back, also takes a lot of time without incurring any sort of error. What could be taking time?

Agent Code

Compiled Load Event Call Back

static int x = 1;
void JNICALL
compiled_method_load(jvmtiEnv *jvmti, jmethodID method, jint code_size,
        const void* code_addr, jint map_length, const jvmtiAddrLocationMap* map,
        const void* compile_info) {
    jvmtiError err;
    jclass klass;

    char* name = NULL;
    char* signature = NULL;
    char* generic_ptr = NULL;

    err = (*jvmti)->RawMonitorEnter(jvmti, lock);
    check_jvmti_error(jvmti, err, "raw monitor enter");

    err = (*jvmti)->GetMethodName(jvmti, method, &name, &signature,
            &generic_ptr);
    check_jvmti_error(jvmti, err, "Get Method Name");

    printf("\nCompiled method load event\n");
    printf("Method name %s %s %s\n\n", name, signature,
            generic_ptr == NULL ? "" : generic_ptr);

    if (strstr(name, "main") != NULL && x == 1) {
        x++;
        err = (*jvmti)->GetMethodDeclaringClass(jvmti, method, &klass);
        check_jvmti_error(jvmti, err, "Get Declaring Class");

        err = (*jvmti)->RetransformClasses(jvmti, 1, &klass);
        check_jvmti_error(jvmti, err, "Retransform class");

    }

    if (name != NULL) {
        err = (*jvmti)->Deallocate(jvmti, (unsigned char*) name);
        check_jvmti_error(jvmti, err, "deallocate name");
    }
    if (signature != NULL) {
        err = (*jvmti)->Deallocate(jvmti, (unsigned char*) signature);
        check_jvmti_error(jvmti, err, "deallocate signature");
    }
    if (generic_ptr != NULL) {
        err = (*jvmti)->Deallocate(jvmti, (unsigned char*) generic_ptr);
        check_jvmti_error(jvmti, err, "deallocate generic_ptr");
    }

    err = (*jvmti)->RawMonitorExit(jvmti, lock);
    check_jvmti_error(jvmti, err, "raw monitor exit");
}

Class File Load Hook

void JNICALL
Class_File_Load_Hook(jvmtiEnv *jvmti_env, JNIEnv* jni_env,
        jclass class_being_redefined, jobject loader, const char* name,
        jobject protection_domain, jint class_data_len,
        const unsigned char* class_data, jint* new_class_data_len,
        unsigned char** new_class_data) {
    jvmtiError err;
    unsigned char* jvmti_space = NULL;

    if (strstr(name, "Test") != NULL && x == 2) {
        char* args = "op";

        javab_main(2, args, class_data, class_data_len);

        err = (*jvmti_env)->Allocate(jvmti_env, (jlong)global_pos, &jvmti_space);
        check_jvmti_error(jvmti_env, err, "Allocate new class Buffer.");

        (void)memcpy((void*)jvmti_space, (void*)new_class_ptr, (int)global_pos);

        *new_class_data_len = (jint)global_pos;
        *new_class_data = jvmti_space;

        if ( new_class_ptr != NULL ) {
            (void)free((void*)new_class_ptr);
        }

#if DEBUG
        printf("Size of the class is: %d\n", class_data_len);
        for (int i = 0; i < class_data_len; i += 4) {
            if (i % 16 == 0)
                printf("\n");

            printf("%02x%02x  %02x%02x  ", new_class_data[i],
                    new_class_data[i + 1], new_class_data[i + 2],
                    new_class_data[i + 3]);
        }
        printf("\n");
        system("javap -c -v Test_debug");
#endif
        x++;
    }
}

Here javab_main returns the instrumented char * array which is correct. The instrumented array is stored in a global variable new_class_ptr which is copied into new_class_data. To debug the output of the instrumentation, I also printed the instrumented class in a file called Test_debug and invoking javap on it produces desired result.

The complete agent file is given here: Agent.c

Original Code:

            for (int i = 0; i < s; i++)
                for (int j = 0; j < s; j++) {
                    c2[i][j] = 0;
                    for (int k = 0; k < s; k++)
                        c2[i][j] += a[i][k] * b[k][j];
                }

Instrumented Code: (Equivalent)

Thread[] threads = new Thread[NTHREADS];    
            for (int i = 0; i < NTHREADS ; i++) {
                final int lb = i * SIZE/NTHREADS;
                final int ub = (i+1) * SIZE/NTHREADS;
                threads[i] = new Thread(new Runnable() {

                    public void run() {
                        for (int i = lb; i < ub; i++)
                            for (int j = 0; j < SIZE; j++) {
                                c2[i][j] = 0;
                                for (int k = 0; k < SIZE; k++)
                                    c2[i][j] += a[i][k] * b[k][j];
                            }
                    }
                });
                threads[i].start();
            }

            // wait for completion
            for (int i = 0; i < NTHREADS; i++) {
                try {
                    threads[i].join();
                } catch (InterruptedException ignore) {
                }
            }

Java Version

openjdk version "1.8.0-internal-debug"
OpenJDK Runtime Environment (build 1.8.0-internal-debug-saqib_2016_12_26_10_52-b00)
OpenJDK 64-Bit Server VM (build 25.71-b00-debug, mixed mode)

Answer 1

I'm constructing this answer mainly from the comments. There are still some riddles unsolved but the main question has been resolved. Bytecode instrumentation does not fail in my case. It actually never happens. According to the theory,

Dynamic bytecode instrumentation of an executing function takes place at subsequent call of the function. If a function has only one invocation, it cannot be instrumented while execution using current hotswap techniques in JVM.

I was trying to instrument a class which had only one function, i.e. main. I was trying to instrument that during runtime. This was the main problem. To check the validity of this argument, I tried to put my code in another function and called it from main in a loop. It got instrumented and everything worked. Nothing has to be changed in the agent.