JDK-8193369 : post_field_access does not work for some functions, possibly related to fast_getfield
  • Type: Bug
  • Component: hotspot
  • Sub-Component: jvmti
  • Affected Version: 8u151
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: linux_ubuntu
  • CPU: x86_64
  • Submitted: 2017-12-11
  • Updated: 2021-12-20
  • Resolved: 2018-03-12
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 11
11 b07Fixed
Related Reports
Relates :  
Relates :  
Relates :  
Description
FULL PRODUCT VERSION :
java version "1.8.0_151"
Java(TM) SE Runtime Environment (build 1.8.0_151-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.151-b12, mixed mode)


FULL OS VERSION :
Relevant at least to x86_64, both linux and windows. 


A DESCRIPTION OF THE PROBLEM :
"fast_getfield" commands do not trigger JVMTI access events, only regular getfield.

Also see note on fast_getfield on "JDK-4300409 SetFieldAccessWatch not implemented" regarding faulty implementation on fast_getfield.

See steps to reproduce for more information.


THE PROBLEM WAS REPRODUCIBLE WITH -Xint FLAG: Yes

THE PROBLEM WAS REPRODUCIBLE WITH -server FLAG: Yes

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Using JVMTI, do SetFieldAccessWatch recusrively on an object that holds an ArrayList.

Performing "itemList.add(index, new_item)" will show all field access events.
Performing "itemList.add(new_item)" will NOT show all field access events.

The reason is that in the first case the template interpreter treats the bytecode as "getfield" and in the second case the interpreter runs it as "fast_getfield".

Whatever is a "fast_getfield" - no events are sent on it.

Attached all the code required to reproduce.


EXPECTED VERSUS ACTUAL BEHAVIOR :
Expected to recieve events on getfield commands in ArrayList.add (public boolean add(E);)
on codes #2, #11, #16 and modification on #22.

Actual behavior: only get events on #16 and modification on #22.

REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
#################### java code (jvmti agent code follows ###################
public class Main {

    public static void main(String[] args) throws IOException, InterruptedException, NoSuchFieldException {
        inspectField(MyList.class, MyList.class.getDeclaredField("items"));

        MyList root = new MyList();
        MyItem item = new MyItem();

        System.out.println("############### add(index, item), get all getfield events");
        root.items.add(0, item);
        System.out.println("############### add(item), missing getfield events");
        root.items.add(item);
        System.out.println("############### add(index, item), get all getfield events");
        root.items.add(1, item);
        
    }

    private static native void inspectField(Class klass, Field field);
}

public class MyList {
    public List<MyItem> items = new ArrayList<>();

}

public class MyItem {

}



##################### C++ code for JVMTI AGENT ########################
#include "string.h"
#include "stdlib.h"
#include "jvmti.h"
#include "com_vfunction_Main.h"

static jvmtiEnv *jvmti;

static void printFieldAccessInfo(jmethodID method,
	jfieldID field,
	jclass field_klass,
	bool modified,
	jlocation location);

static void tagAndWatch(JNIEnv * jni_env, const jobject newObject);

static void JNICALL onFieldAccess(jvmtiEnv *jvmti_env,
	JNIEnv* jni_env,
	jthread thread,
	jmethodID method,
	jlocation location,
	jclass field_klass,
	jobject parentObject,
	jfieldID field)
{
	printFieldAccessInfo(method, field, field_klass, false, location);
}


static void JNICALL onFieldModified(jvmtiEnv *jvmti_env,
	JNIEnv* jni_env,
	jthread thread,
	jmethodID method,
	jlocation location,
	jclass field_klass,
	jobject parentObject,
	jfieldID field,
	char signature_type,
	jvalue new_value)
{
	printFieldAccessInfo(method, field, field_klass, true, location);
	
	if (signature_type == 'L')
	{
		jobject newObject = new_value.l;
		tagAndWatch(jni_env, newObject);
	}
}

void tagAndWatch(JNIEnv * jni_env, const jobject obj)
{
	if (obj == NULL)
	{
		return;
	}

	jclass klass = jni_env->GetObjectClass(obj);
	do
	{
		jfieldID* klassFields;
		jint fieldCount;
		jvmtiError err = jvmti->GetClassFields(klass, &fieldCount, &klassFields);
		if (err != JVMTI_ERROR_NONE)
		{
			printf("Failed to get class fields\n");
		}

		for (int i = 0; i < fieldCount; ++i)
		{
			err = jvmti->SetFieldModificationWatch(klass, klassFields[i]);
			if (err != JVMTI_ERROR_NONE && err != JVMTI_ERROR_DUPLICATE)
			{
				printf("%s Failed to set field modification %d\n", __FUNCTION__, err);
			}

			err = jvmti->SetFieldAccessWatch(klass, klassFields[i]);
			if (err != JVMTI_ERROR_NONE && err != JVMTI_ERROR_DUPLICATE)
			{
				printf("%s Failed to set field access %d\n", __FUNCTION__, err);
			}

			char *sig = NULL;
			err = jvmti->GetFieldName(klass, klassFields[i], NULL, &sig, NULL);
			if (sig)
			{
				if (sig[0] == 'L')
				{
					jobject fieldVal = jni_env->GetObjectField(obj, klassFields[i]);
					tagAndWatch(jni_env, fieldVal);
				}
				jvmti->Deallocate((unsigned char*)sig);
			}			
		}

		err = jvmti->Deallocate((unsigned char*)klassFields);
		if (err != JVMTI_ERROR_NONE)
		{
			printf("%s Failed to deallocate fields %d\n", __FUNCTION__, err);
		}

		klass = jni_env->GetSuperclass(klass);
	} while (klass != NULL);
}


JNIEXPORT void JNICALL Java_com_vfunction_Main_inspectField(JNIEnv * env,
	jclass caller,
	jclass klass,
	jobject field)
{
	jfieldID fieldId = env->FromReflectedField(field);

	jvmtiError err = jvmti->SetFieldModificationWatch(klass, fieldId);
	if (err != JVMTI_ERROR_NONE)
	{
		printf("%s Failed to set field modification %d\n", __FUNCTION__, err);
	}
	
	err = jvmti->SetFieldAccessWatch(klass, fieldId);
	if (err != JVMTI_ERROR_NONE)
	{
		printf("%s Failed to set field access %d\n", __FUNCTION__, err);
	}
}


JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM *jvm, char *options, void *reserved)
{
	jvmtiEventCallbacks callbacks = {};
	jvmtiError error;

	jint result = jvm->GetEnv((void **)&jvmti, JVMTI_VERSION_1_1);
	if (result != JNI_OK)
	{
		printf("ERROR: Unable to access JVMTI!\n");
		return JNI_ERR;
	}
	else
	{
		printf("Agent succesfully loaded\n");
	}

	jvmtiCapabilities capa = {};

	capa.can_generate_field_modification_events = 1;
	capa.can_generate_field_access_events = 1;
	capa.can_tag_objects = 1;
	error = jvmti->AddCapabilities(&capa);
	if (error != JVMTI_ERROR_NONE)
	{
		printf("Failed to set capabilities: %d\n", error);
	}

	callbacks.FieldModification = &onFieldModified;
	callbacks.FieldAccess = &onFieldAccess;

	error = jvmti->SetEventCallbacks(&callbacks, sizeof(callbacks));
	if (error != JVMTI_ERROR_NONE)
	{
		printf("Failed to set event callbacks: %d\n", error);
	}

	error = jvmti->SetEventNotificationMode(JVMTI_ENABLE, JVMTI_EVENT_FIELD_ACCESS, NULL);
	if (error != JVMTI_ERROR_NONE)
	{
		printf("Failed to set event notifications: %d\n", error);
	}

	error = jvmti->SetEventNotificationMode(JVMTI_ENABLE, JVMTI_EVENT_FIELD_MODIFICATION, NULL);
	if (error != JVMTI_ERROR_NONE)
	{
		printf("Failed to set event notifications: %d\n", error);
	}

	return JNI_OK;
}

static void printFieldAccessInfo(jmethodID method,
	jfieldID field,
	jclass field_klass,
	bool modified,
	jlocation location)
{
	char *name;
	jvmtiError err = jvmti->GetFieldName(field_klass, field, &name, NULL, NULL);
	if (err != JVMTI_ERROR_NONE)
	{
		printf("%s: Failed to get field name", __FUNCTION__);
		return;
	}

	char *fname;
	err = jvmti->GetMethodName(method, &fname, NULL, NULL);
	if (err != JVMTI_ERROR_NONE)
	{
		printf("%s: Failed to get method name", __FUNCTION__);
		return;
	}

	jclass methodClass;
	err = jvmti->GetMethodDeclaringClass(method, &methodClass);
	if (err != JVMTI_ERROR_NONE)
	{
		printf("%s: Failed to get method class", __FUNCTION__);
		return;
	}

	char *csig;
	err = jvmti->GetClassSignature(methodClass, &csig, NULL);
	if (err != JVMTI_ERROR_NONE)
	{
		printf("%s: Failed to get class signature", __FUNCTION__);
		return;
	}

	printf("\"%s%s\" %s field \"%s\", location: %d\n",
		csig, fname, modified ? "modified" : "accessed", name, (int)location);

	jvmti->Deallocate((unsigned char*)csig);
	jvmti->Deallocate((unsigned char*)fname);
	jvmti->Deallocate((unsigned char*)name);
}

#############################################################
---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
No workaround found.


Comments
URL: http://hg.openjdk.java.net/jdk/jdk/rev/2d1d0c66966b User: jwilhelm Date: 2018-03-23 18:52:48 +0000
23-03-2018

URL: http://hg.openjdk.java.net/jdk/hs/rev/2d1d0c66966b User: amenkov Date: 2018-03-12 21:16:40 +0000
12-03-2018

add(index, item) also doesn't always work as expected. the code: list.items.add(0, new MyItem()); list.items.add(new MyItem()); list.items.add(1, new MyItem()); list.items.add(new MyItem()); list.items.add(1, new MyItem()); the last list.items.add(1, new MyItem()) does not generate all events
23-02-2018

Looking into ArrayList/AbstractList source code the expected notifications for any add(0, item), add(item) and add(1, item) are: "items" - accessed "modCount" - accessed and modified "size" - accessed and modified "elementData" - accessed (and may be modified) Tested different versions of JDK 8-11, for all tested versions some notifications are missed (sets of the missed notificationbs are different).
23-02-2018

I've modified the MyAgent.cpp a little bit to print a generic signature of the method where the field watch event was fired and got this output: "class: Lcom/vfunction/MyList; method: <init>(null)" modified field: "items", location: 12 "class: Ljava/util/Vector; method: addElement(TE;)V" accessed field: "modCount", location: 2 "class: Ljava/util/Vector; method: addElement(TE;)V" modified field: "modCount", location: 7 #### add(index, item), get all getfield events "class: Lcom/vfunction/Main; method: main(null)" accessed field: "items", location: 37 "class: Ljava/util/ArrayList; method: rangeCheckForAdd(null)" accessed field: "size", location: 2 "class: Ljava/util/ArrayList; method: add(ITE;)V" accessed field: "modCount", location: 7 "class: Ljava/util/ArrayList; method: add(ITE;)V" modified field: "modCount", location: 12 "class: Ljava/util/ArrayList; method: add(ITE;)V" accessed field: "size", location: 16 "class: Ljava/util/ArrayList; method: add(ITE;)V" accessed field: "elementData", location: 22 "class: Ljava/util/ArrayList; method: newCapacity(null)" accessed field: "DEFAULTCAPACITY_EMPTY_ELEMENTDATA", location: 22 "class: Ljava/util/ArrayList; method: grow(null)" modified field: "elementData", location: 14 "class: Ljava/util/ArrayList; method: add(ITE;)V" modified field: "size", location: 61 #### add(item), missing getfield events "class: Lcom/vfunction/Main; method: main(null)" accessed field: "items", location: 56 "class: Ljava/util/ArrayList; method: add(TE;)Z" accessed field: "modCount", location: 2 "class: Ljava/util/ArrayList; method: add(TE;)Z" modified field: "modCount", location: 7 "class: Ljava/util/ArrayList; method: add(TE;[Ljava/lang/Object;I)V" modified field: "size", location: 19 #### add(index, item), get all getfield events "class: Lcom/vfunction/Main; method: main(null)" accessed field: "items", location: 75 "class: Ljava/util/ArrayList; method: rangeCheckForAdd(null)" accessed field: "size", location: 2 "class: Ljava/util/ArrayList; method: add(ITE;)V" accessed field: "modCount", location: 7 "class: Ljava/util/ArrayList; method: add(ITE;)V" modified field: "modCount", location: 12 "class: Ljava/util/ArrayList; method: add(ITE;)V" accessed field: "size", location: 16 "class: Ljava/util/ArrayList; method: add(ITE;)V" accessed field: "elementData", location: 22 "class: Ljava/util/ArrayList; method: add(ITE;)V" modified field: "size", location: 61 It seems, the field watch events happen in different methods after the call to add(item): add(TE;)Z add(TE;[Ljava/lang/Object;I)V These are the methods where the watch event happen after the call to add(index, item): add(ITE;)V I can be wrong but it seems to me that an expectation to get the same events for a different code path is wrong. One more thing to check is to find this different method and print the bytecodes to see if the output we see matches the filed accesses. If so, then we have to close this bug as NAI or as Incomplete to request from the customer more details on this issue.
16-02-2018

I've targeted this issue to 11 and added the 'starter' label.
20-12-2017

The generation of the get/put_fastfield is disabled if the can_generate_breakpoint_events capability is enabled by the agent. It is done in the JvmtiManageCapabilities::update(): 331 if (avail.can_generate_breakpoint_events) { 332 RewriteFrequentPairs = false; 333 } It looks like the condition at the line 331 is missing the capabilities: avail.can_generate_field_access_events and avail.can_generate_field_modification_events So that, it has to be: 331 if (avail.can_generate_breakpoint_events || avail.can_generate_field_access_events || avail.can_generate_field_modification_events) { 332 RewriteFrequentPairs = false; 333 } This also suggests a user workaround. Enabling the capability can_generate_breakpoint_events should help to avoid this problem.
20-12-2017

From email discussion: http://mail.openjdk.java.net/pipermail/serviceability-dev/2017-December/022633.html Hi, I know the code has some relevant code, but it doesn't seem to work. You will see some differences: the CALL_VM to the post function has only 2 arguments and not 3, I'm not sure it matters. The platform is x86_64, Java version is 1.8.0-152. I can try other versions if you wish. Please find the attached MyAgent.cpp MyAgent.h and com_vfunction_Main.h to compile the agent. Please also find the attached com.vfunction.zip that holds the simple java util to reproduce the problem. You'll see the problem on ArrayList.add(item) where you'll get events only on codes #16 and #22 and not on #2 and #11 (see attached bytecode.txt of said function). Please let me know once you managed to reproduce it. I can also send you a patch file to disable the fast_getfield (and fast putfield) to show that the problem disappears. I'm currently looking at the actual assembly of the add function, both with the modified hotspot and without and will try to assist will offering a fix for this issue. One last thing. I saw a very old issue (resolved by Daniel Daugherty) stating that fast_getfield was not completely addressed with the resolution on this issue. The bug ID is https://bugs.openjdk.java.net/browse/JDK-4300409 I'll be happy to assist further. Best regards, Amir -----Original Message----- From: Vladimir Ivanov [mailto:vladimir.x.ivanov@oracle.com] Sent: Tuesday, December 12, 2017 2:46 PM To: Amir Rapson <amir@vfunction.com> Cc: Coleen.Phillimore@oracle.com; daniel.daugherty@oracle.com Subject: Re: JVMTI not receiving field access events with fast_getfield Thanks for the report, Amir! Unfortunately, I can't access the bug you filed. Can you, please, share the test case and instructions how to reproduce the problem? Also, what Java version & platform do you observe the bug on? I briefly looked into template interpreter code on x86 and it does have relevant code to post JVMTI events in fast accessors. Best regards, Vladimir Ivanov On 12/12/17 11:12 AM, Amir Rapson wrote: > Hi Daniel, Coleen and Vladimir, > > I tracked your email addresses from some mailing lists and hopefully > one of you is a relevant person for my problem. > > I also filed a bug request (ID 9051849) but since I don’t have an > option to add information I decided to email you. > > The problem I’m seeing is that JMTI does not receive field access > events (and probably field modification events) when /fast_getfield/ > is used instead of /get_field/. > > I verified this by disabling all the > /patch_bytecode(Bytecodes::_fast_?getfield, bc, rbx)/ in > /TemplateTable::getfield_or_static()/ and made sure that JVMTI > receives all the correct events. > > I have the agent code and a short java program that can reproduce the > problem and would be happy to assist in fixing and or debugging this > issue. > > I would appreciate any feedback. > > Best regards, > > Amir > > ​​​​​Amir Rapson | Founder & VP Eng @ *vFunction* | 7 HaPelech St. > Tel-Aviv |
20-12-2017