|
Description
|
A customer faces with an infinite loop in their application.
They got Full thread dump and gcore for the process several times.
They investigated the data.
REQUEST :
To take a look at the report and send Sun's commento for their thought.
------- Customer Report ------
What we found were,
In the compiled code of java.util.HashMap.transfer() (the code was inlined in HashMap.put()),
the variable (Oop) mapped in the stack was not registered to OopMap.
When GC occurred, (Oop) in the stack was not updated. Then this causes the infinite
loop problem.
The followings are more detail information by our resposible engineer.
Please take a look at that and give us Sun's comment.
====
CONFIGURATION:
OS : Redhat Enterprise Linux 4 (x86)
JDK : 1.4.2_11 Server VM
When java.util.LinkedHashMap.transfer() method is executed in compiled code,
there occurs an infinite loop.
( The transfer() method is inlined in compiled code of java.util.HashMap.put() method.)
When this problem occurs, we got Full Thread Dump several times.
We found the infinite loop occurs in "for" loop in java.util.LinkedHashMap.transfer().
--- Thread dump ---
"main" prio=1 tid=0x09c4a060 nid=0x6905 runnable [0xbfe54000..0xbfe54448]
at java.util.LinkedHashMap.transfer(LinkedHashMap.java:224)
at java.util.HashMap.resize(HashMap.java:452)
at java.util.LinkedHashMap.addEntry(LinkedHashMap.java:399)
at java.util.HashMap.put(HashMap.java:392)
at jp.go.maff.rinya.nfims.AB1.AB1Z.cbm.AB1ShuFukumeiSQLEntity.lumpSelectShukakuYoteiSoukatu3(AB1ShuFukumeiSQLEntity.java:9684)
-- Source Code ----
java/util/LinkedHashMap.java
222 void transfer(HashMap.Entry[] newTable) {
223 int newCapacity = newTable.length;
224 for (Entry e = header.after; e != header; e = e.after) {
225 int index = indexFor(e.hash, newCapacity);
226 e.next = newTable[index];
227 newTable[index] = e;
228 }
229 }
The compiled code corresponding to the above "for" loop in line# 224 are as follows.
--- Compiled Code ----
.....
0xfd48c0: mov 0x14(%esi),%ebx e.hash
0xfd48c3: and %edi,%ebx HashMap.indexFor()
0xfd48c5: cmp %eax,%ebx if (index >= newTable.length)
0xfd48c7: jae 0xfd49bc goto Deopt_range_check
0xfd48cd: mov 0x10(%esp),%ecx newTable
0xfd48d1: mov 0xc(%ecx,%ebx,4),%ebp tmp = newTable[index]
0xfd48d5: mov %esi,0xc(%ecx,%ebx,4) newTable[index] = e;
0xfd48d9: lea 0xc(%ecx,%ebx,4),%ebx
0xfd48dd: mov %ebp,0x10(%esi) e.next = tmp
0xfd48e0: mov 0x1c(%esi),%ecx e.after
0xfd48e3: mov %esi,%edx e
0xfd48e5: shr $0x9,%edx
0xfd48e8: movb $0x0,0xffdd2e00(%edx)
0xfd48ef: shr $0x9,%ebx
0xfd48f2: movb $0x0,0xffdd2e00(%ebx)
0xfd48f9: nop
0xfd48fa: nop
0xfd48fb: cmp 0x18(%esp),%ecx if (e.after==header)
0xfd48ff: je 0xfd4905 exit for-loop-body
0xfd4901: mov %ecx,%esi e = e.after
0xfd4903: jmp 0xfd48c0
...
------
0x18(%esp) at 0xfd48fb is header variable.
The following list is the trace to track e from header.after to e.after.
-----
header
(gdb) x /x $esp+0x18
0xbfe54178: 0x9811fc10
(gdb) x/8x 0x9811fc10
0x9811fc10: 0xa29aa12b 0xb26466c8 0x00000000 0x00000000
0x9811fc20: 0x00000000 0xffffffff 0xa29aa3f8 0xa29aa148
next hash before after
(gdb) x/8x 0xa29aa148
0xa29aa148: 0x00000001 0xb26466c8 0xb26caed8 0xb24a6650
0xa29aa158: 0xa29aa148 0xe3a280bc 0xa29aa128 0xa29aa168
(gdb) x/8x 0xa29aa168
0xa29aa168: 0x00000001 0xb26466c8 0xb26caf08 0xb24a6650
0xa29aa178: 0xa29aa2a0 0xfd82794d 0xa29aa148 0xa29aa1b8
(gdb) x/8x 0xa29aa1b8
0xa29aa1b8: 0x00000001 0xb26466c8 0xb26caf38 0xa29aa188
0xa29aa1c8: 0xa29aa1b8 0xaa576896 0xa29aa168 0xa29aa208
(gdb) x/8x 0xa29aa208
0xa29aa208: 0x00000001 0xb26466c8 0xb26cf950 0xa29aa1d8
0xa29aa218: 0xa29aa208 0x2b7c0652 0xa29aa1b8 0xa29aa250
(gdb) x/8x 0xa29aa250
0xa29aa250: 0x00000001 0xb26466c8 0xb26cf980 0xa29aa228
0xa29aa260: 0xa29aa3a8 0xfd4b0af0 0xa29aa208 0xa29aa2a0
(gdb) x/8x 0xa29aa2a0
0xa29aa2a0: 0x00000001 0xb26466c8 0xb26cf9b0 0xa29aa270
0xa29aa2b0: 0xa29aa168 0xd0a3186d 0xa29aa250 0xa29aa2c0
(gdb) x/8x 0xa29aa2c0
0xa29aa2c0: 0x00000001 0xb26466c8 0xb26cfa08 0xb24a6650
0xa29aa2d0: 0xa29aa2c0 0xaf73e914 0xa29aa2a0 0xa29aa318
(gdb) x/8x 0xa29aa318
0xa29aa318: 0x00000001 0xb26466c8 0xb26cfa40 0xa29aa2e0
0xa29aa328: 0xa29aa318 0xf0ad2ce8 0xa29aa2c0 0xa29aa338
(gdb) x/8x 0xa29aa338
0xa29aa338: 0x00000001 0xb26466c8 0xb26cfa70 0xb24a6650
0xa29aa348: 0xa29aa250 0x465a1570 0xa29aa318 0xa29aa358
(gdb) x/8x 0xa29aa358
0xa29aa358: 0x00000001 0xb26466c8 0xb26cfaa0 0xb24a6ce8
0xa29aa368: 0xa29aa128 0x9d47a85f 0xa29aa338 0xa29aa3a8
(gdb) x/8x 0xa29aa3a8
0xa29aa3a8: 0x00000001 0xb26466c8 0xb26cfad0 0xa29aa378
0xa29aa3b8: 0xa29aa338 0xaa987bb0 0xa29aa358 0xa29aa3f8
(gdb) x/8x 0xa29aa3f8
0xa29aa3f8: 0x00000001 0xb26466c8 0xb26cfb00 0xa29aa3c8
0xa29aa408: 0xa29aa3f8 0xa674fdc2 0xa29aa3a8 0xa29aa128
(gdb) x/8x 0xa29aa128
0xa29aa128: 0x00000001 0xb26466c8 0x00000000 0x00000000
0xa29aa138: 0xa29aa358 0xffffffff 0xa29aa3f8 0xa29aa148
==========
....
----------
Here,
- There is no LinkedHashMap.header(=0x9811fc10) which is the exit condition
for the "for" loop.
- 0x9811fc10 exists in "to" space in NEW area. However, LinkedHashMap and all the objects
connected to the map are in OLD area.
- The address of newTable allocated just before transfer() is set to 0x10(%esp)
and in "from" space in NEW area.
----
......
java/util/HashMap.java
Entry[] newTable = new Entry[newCapacity];
transfer(newTable);
00xfd48aa: mov 0xc(%esp),%ecx newTable (set at 0xfd48a0)
0xfd48ae: mov %ecx,0x10(%esp) newTable
...
------
According to the aboves,
LinkedHashMap and all the objects connected to the map are moved to OLD area by GC,
but 0x18(%esp) is not updated for unexpected reason.
It is strange that both "from" and "to" seems used. 0x18(%esp) could be garbage.
We feel that the compiled code missed an OopMap. That's why 0x18(%esp) is garbage.
We investigated OopMaps and found the OopMap for 0x18(%esp) seems lost at the safepoint
in "for" block and in just before "for" block.
The program refers to 0x18(%esp) where header variable is stored at the line (*A) and (*B),
but there is no OopMap for 0x18(%esp) in OopMap #4 nor OopMap #5.
-----
.....
0xfd489b: call 0xeda2e0 ((RuntimeStub*)0x00eda288) _new_objArray_Java
OopMap #4 offset:0x340 (0xfd48a0)
OopMap #4 at_call:1
ESI=Oop [32]=Oop [40]=Callers_EBP [44]=Callers_EDI [48]=Callers_ESI
------ HashMap.transfer() -----
0xfd48a0: mov %eax,0xc(%esp) Entry[] newTable
0xfd48a4: movss 0x10(%esp),%xmm0
0xfd48aa: mov 0xc(%esp),%ecx newTable
0xfd48ae: mov %ecx,0x10(%esp)
0xfd48b2: cmp 0x18(%esp),%esi if (header==header.after) ------------(*A)
0xfd48b6: je 0xfd4905 goto end of for-loop-block
0xfd48b8: mov 0x8(%ecx),%eax newCapacity = newTable.length;
0xfd48bb: mov %eax,%edi
0xfd48bd: dec %edi (length-1) at HashMap.indexFor()
0xfd48be: nop
0xfd48bf: nop
--------------------- for-looop-block -----------------------------+
0xfd48c0: mov 0x14(%esi),%ebx e.hash A
0xfd48c3: and %edi,%ebx HashMap.indexFor() |
0xfd48c5: cmp %eax,%ebx if (index >= newTable.length)
0xfd48c7: jae 0xfd49bc goto Deopt_range_check
0xfd48cd: mov 0x10(%esp),%ecx newTable
0xfd48d1: mov 0xc(%ecx,%ebx,4),%ebp tmp = newTable[index]
0xfd48d5: mov %esi,0xc(%ecx,%ebx,4) newTable[index] = e;
0xfd48d9: lea 0xc(%ecx,%ebx,4),%ebx
0xfd48dd: mov %ebp,0x10(%esi) e.next = tmp
0xfd48e0: mov 0x1c(%esi),%ecx e.after
0xfd48e3: mov %esi,%edx e
0xfd48e5: shr $0x9,%edx
0xfd48e8: movb $0x0,0xffdd2e00(%edx)
0xfd48ef: shr $0x9,%ebx
0xfd48f2: movb $0x0,0xffdd2e00(%ebx)
OopMap #5 offset:0x399 (0xfd48f9)
OopMap #5 at_call:0
ECX=Oop [16]=Oop [32]=Oop [40]=Callers_EBP [44]=Callers_EDI [48]=Callers_ESI
0xfd48f9: nop
0xfd48fa: nop
0xfd48fb: cmp 0x18(%esp),%ecx if (e.after==header) ------------(*B)
0xfd48ff: je 0xfd4905 exit for-loop-body
0xfd4901: mov %ecx,%esi e = e.after Ażinfinity loop
0xfd4903: jmp 0xfd48c0 |
-------------------- end of for-loop-block ------------------------+
Appendix 1 :
0x18(%esp) is set at line#410 in java/util/LinkedHashMap.java. This corresponds to "move"
instruction at 0xfd479a.
bucketIndex * 4 is set to 0x18(%esp) until 0xfd4787.
407 void createEntry(int hash, Object key, Object value, int bucketIndex) {
408 Entry e = new Entry(hash, key, value, table[bucketIndex]);
409 table[bucketIndex] = e;
410 e.addBefore(header);
411 size++;
0xfd4766: mov 0x10(%esi),%edx this.table
0xfd4769: mov 0x8(%edx),%edi this.table._length
0xfd476c: mov 0x10(%esp),%ebx backetIndex
0xfd4770: cmp %edi,%ebx if (buketIndex >= table._length
0xfd4772: jae 0xfd4a6d goto Deopt_range_check
0xfd4778: mov 0x4(%edx),%ecx this.table._klass
0xfd477b: cmp $0xb22c5248,%ecx if (table._klass != HashMap$Ent
0xfd4781: jne 0xfd4a4e goto Deopt_array_store_check
0xfd4787: mov 0x18(%esp),%esi i*4 (bucketIndex*4) <--- not for header
0xfd478b: mov %eax,0xc(%edx,%esi,1) table[bucketIndex] = e;
------- e.addBefore at createEntry() ------
0xfd478f: lea 0xc(%edx,%esi,1),%edx &(table[bucketIndex])
0xfd4793: mov 0x20(%esp),%esi this
0xfd4797: mov 0x28(%esi),%esi this.header
0xfd479a: mov %esi,0x18(%esp) !!!!!!! save header !!!!!!!!
0xfd479e: mov %esi,0x1c(%eax) after = existingEntry; (==head
0xfd47a1: mov %eax,%ecx e
0xfd47a3: mov %edx,%ebx &(table[bucketIndex])
Appendix 2 :
java.util.LinkedHashMap.transfer() is inlined in the compiled code of java.util.HashMap.put()
method.
HashMap#put
LinkedHashMap#addEntry
LinkedHashMap#createEntry
LinkedHashMap$Entry#<init>
HashMap$Entry#<init>
HashMap#resize
LinkedHashMap#transfer
=====
==================================================================================================
Posted Date : 2008-10-21 08:27:25.0
|
