[rvm-research] Data collection got destroyed before shutdown hooks finish

--===============5121166470318369412==
Content-Type: multipart/related; boundary="000000000000d36bde05852337c7"

--000000000000d36bde05852337c7
Content-Type: multipart/alternative; boundary="000000000000d36bdd05852337c6"

--000000000000d36bdd05852337c6
Content-Type: text/plain; charset="UTF-8"

Hi,

I asked the similar question before. Our problem was populate all data we
collected in the end of VM execution so that we can make sure those I/O
operations would not affect the Jikesrvm behaviours.

At that time Erik Brangs suggested to use shutdown hooks to print out the
data. It worked (thanks!) until we increased the size of data to more than
20 thousand entries in an arraylist.

Right now we got around 50 thousand entries of arraylist and write it to a
file using shutdown hook, but I always get an NullPointerError for the
arraylist I created after around 15 thousand entries got printed.

I learned shutdown hooks would only be stopped in some certain cases via
signal like *user requesting a termination (Ctrl+C), a SIGTERM being issued
by O/S (normal kill command, without -9), or when the operating system is
shutting down* I don't think it belongs to any one of these cases.

If there is any place in JikesRVM would send terminate signal if the
shutdown procedure exceeds certain time limit? Or if there is a forced GC
cycles (or something similar) during VM shutdown time?

I have no clue why it would happen. It would be nice If there is a way to
trace the object gets destroyed.

Just in case, here is the error message:

===== DaCapo 9.12 sunflow starting =====
===== DaCapo 9.12 sunflow PASSED in 7466 msec =====
shutdown hook is invoked!!
JikesRVM: hardwareTrapHandler SignalNO:11 Context:0xd5c0400c -
InsPtr:0x64c803ba instFollowPtr:0x64c803bd threadPtr:0x6819a04c
jtocPtr:0x600802e0
JikesRVM: hardwareTrapHandler: trap context:
eip           0x64c803ba
eax (T0)      (nil)
ebx (ctrs)    (nil)
ecx (S0)      0x602949f0
edx (T1)      0xa00b
esi (TR)      0x6819a04c
edi (S1)      0x736701cc
ebp           (nil)
esp (SP)      0x6bd66f00
cs            0x23
ds            0x2b
es            0x2b
fs            (nil)
gs            0x63
ss            0x2b
trapno        0x0000000e
err           0x00000004
eflags        0x00010246
fpregs        0xd5c04090
oldmask       0x00020000
cr2           0x00000008
JikesRVM: trap code is 0
JikesRVM: trap info is 8
JikesRVM: set vmr_ip to 0x64c803bd
JikesRVM: set vmr_fp to 0x6bd66f68
JikesRVM: hardwareTrapHandler: trap context on exit:
eip           0x64ec22e0
eax (T0)      (nil)
ebx (ctrs)    (nil)
ecx (S0)      0x602949f0
edx (T1)      0x8
esi (TR)      0x6819a04c
edi (S1)      0x736701cc
ebp           0x6bd33e8c
esp (SP)      0x6bd33e7c
cs            0x23
ds            0x2b
es            0x2b
fs            (nil)
gs            0x63
ss            0x2b
trapno        0x0000000e
err           0x00000004
eflags        0x00010246
fpregs        0xd5c04090
oldmask       0x00020000
cr2           0x00000008
delivering hardware exception
we have a thread = 0x6819a04c
it's in state = 1
we have exception registers = 0x6818b850
Exception in thread "Thread-1" j*ava.lang.NullPointerException*
   at org.jikesrvm.energy.LogQueue.dumpLogQueue(LogQueue.java:82)
   at org.jikesrvm.VM$1.run(VM.java:495)
*logQueue size is : 56170*
[Here is the context of the call to VM.sysExit(0)...:
Dumping stack for Thread #52
-- Stack --
(0x69356df4 21346)   at [0x69356df4, 0x64915a8f] Lorg/jikesrvm/VM;
sysExit(I)V at line 2405 at bytecode index 65 at machine code offset
0x0000044a
(0x69356e14 8264)   at [0x69356e14, 0x64916ed6] Ljava/lang/VMRuntime;
exit(I)V at line 80 at bytecode index 1 at machine code offset 0x00000057
   at [0x69356e14, 0x64916ed6] Ljava/lang/Runtime; halt(I)V at line 399 at
bytecode index 14 at machine code offset 0x00000057
(0x69356e4c 8260)   at [0x69356e4c, 0x64baeaa2] Ljava/lang/Runtime;
exit(I)V at line 174 at bytecode index 22 at machine code offset 0x00000076
(0x69356e6c 5222)   at [0x69356e6c, 0x6883a21a] Ljava/lang/System; exit(I)V
at line 586 at bytecode index 4 at machine code offset 0x00000042
(0x69356e88 23006)   at [0x69356e88, 0x64a6578e] LHarness;
main([Ljava/lang/String;)V at line 18 at bytecode index 5 at machine code
offset 0x0000006e
(0x69356ea0 -1)   at [0x69356ea0, 0x64ae7644] <invisible method>
(0x69356f2c 6569)   at [0x69356f2c, 0x648ab78a]
Lorg/jikesrvm/runtime/Reflection;
outOfLineInvoke(Lorg/jikesrvm/classloader/RVMMethod;Ljava/lang/Object;[Ljava/lang/Object;Z)Ljava/lang/Object;
at line 223 at bytecode index 433 at machine code offset 0x000006b4
(0x69356f80 13219)   at [0x69356f80, 0x64bd7236]
Lorg/jikesrvm/runtime/Reflection;
invoke(Lorg/jikesrvm/classloader/RVMMethod;Lorg/jikesrvm/runtime/ReflectionBase;Ljava/lang/Object;[Ljava/lang/Object;Z)Ljava/lang/Object;
at line 93 at bytecode index 50 at machine code offset 0x00000676
   at [0x69356f80, 0x64bd7236] Lorg/jikesrvm/scheduler/MainThread; run()V
at line 201 at bytecode index 173 at machine code offset 0x00000676
(0x69356fc0 22729)   at [0x69356fc0, 0x64eb64c4]
Lorg/jikesrvm/scheduler/RVMThread; run()V at line 2837 at bytecode index 46
at machine code offset 0x00000262
(0x69356ff8 22818)   at [0x69356ff8, 0xf77ab618]
Lorg/jikesrvm/scheduler/RVMThread; startoff()V at line 2898 at bytecode
index 78 at machine code offset 0x000001f4
... END context of the call to VM.sysExit]

Here is the Number of entries gets printed out:
[image: image.png]

Thanks,
Kenan
-- 
Kenan Liu
PhD Candidate in Computer Science
SUNY Binghamton

--000000000000d36bdd05852337c6
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr"><div dir=3D"ltr"><div><div>Hi,<br><br></div>I asked the si=
milar question before. Our problem was populate all data we collected in th=
e end of VM execution so that we can make sure those I/O operations would n=
ot affect the Jikesrvm behaviours. <br><br></div>At that time Erik Brangs s=
uggested to use shutdown hooks to print out the data. It worked (thanks!) u=
ntil we increased the size of data to more than 20 thousand entries in an a=
rraylist.<br clear=3D"all"><div><div><div><br></div><div>Right now we got a=
round 50 thousand entries of arraylist and write it to a file using shutdow=
n hook, but I always get an NullPointerError for the arraylist I created af=
ter around 15 thousand entries got printed.<br><br></div><div>I learned shu=
tdown hooks would only be stopped in some certain cases via signal like <i>=
user requesting a termination (Ctrl+C), a SIGTERM being issued by O/S=20
(normal kill command, without -9), or when the operating system is=20
shutting down</i> I don&#39;t think it belongs to any one of these cases. <=
br><br></div><div>If there is any place in JikesRVM would send terminate si=
gnal if the shutdown procedure exceeds certain time limit? Or if there is a=
 forced GC cycles (or something similar) during VM shutdown time?<br><br></=
div><div>I have no clue why it would happen. It would be nice If there is a=
 way to trace the object gets destroyed.<br><br></div><div>Just in case, he=
re is the error message:<br><br>=3D=3D=3D=3D=3D DaCapo 9.12 sunflow startin=
g =3D=3D=3D=3D=3D<br>=3D=3D=3D=3D=3D DaCapo 9.12 sunflow PASSED in 7466 mse=
c =3D=3D=3D=3D=3D<br>shutdown hook is invoked!!<br>JikesRVM: hardwareTrapHa=
ndler SignalNO:11 Context:0xd5c0400c - InsPtr:0x64c803ba instFollowPtr:0x64=
c803bd threadPtr:0x6819a04c jtocPtr:0x600802e0<br>JikesRVM: hardwareTrapHan=
dler: trap context:<br>eip=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=
=C2=A0=C2=A0 0x64c803ba<br>eax (T0)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 (nil)<br>=
ebx (ctrs)=C2=A0=C2=A0=C2=A0 (nil)<br>ecx (S0)=C2=A0=C2=A0=C2=A0=C2=A0=C2=
=A0 0x602949f0<br>edx (T1)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0xa00b<br>esi (TR)=
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x6819a04c<br>edi (S1)=C2=A0=C2=A0=C2=A0=C2=
=A0=C2=A0 0x736701cc<br>ebp=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=
=C2=A0=C2=A0 (nil)<br>esp (SP)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x6bd66f00<br>=
cs=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x23<b=
r>ds=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x2b=
<br>es=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x=
2b<br>fs=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 =
(nil)<br>gs=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=
=A0 0x63<br>ss=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=
=C2=A0 0x2b<br>trapno=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x0000000e<=
br>err=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x000000=
04<br>eflags=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x00010246<br>fpregs=
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0xd5c04090<br>oldmask=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x00020000<br>cr2=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x00000008<br>JikesRVM: trap code is 0<br>Ji=
kesRVM: trap info is 8<br>JikesRVM: set vmr_ip to 0x64c803bd<br>JikesRVM: s=
et vmr_fp to 0x6bd66f68<br>JikesRVM: hardwareTrapHandler: trap context on e=
xit:<br>eip=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x6=
4ec22e0<br>eax (T0)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 (nil)<br>ebx (ctrs)=C2=A0=
=C2=A0=C2=A0 (nil)<br>ecx (S0)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x602949f0<br>=
edx (T1)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x8<br>esi (TR)=C2=A0=C2=A0=C2=A0=C2=
=A0=C2=A0 0x6819a04c<br>edi (S1)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x736701cc<b=
r>ebp=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x6bd33e8=
c<br>esp (SP)=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x6bd33e7c<br>cs=C2=A0=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x23<br>ds=C2=A0=C2=A0=
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x2b<br>es=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x2b<br>fs=C2=A0=
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 (nil)<br>gs=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x63<br>ss=
=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x2b<br>=
trapno=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x0000000e<br>err=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x00000004<br>eflags=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 0x00010246<br>fpregs=C2=A0=C2=A0=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0 0xd5c04090<br>oldmask=C2=A0=C2=A0=C2=A0=C2=A0=
=C2=A0=C2=A0 0x00020000<br>cr2=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=
=A0=C2=A0=C2=A0 0x00000008<br>delivering hardware exception<br>we have a th=
read =3D 0x6819a04c<br>it&#39;s in state =3D 1<br>we have exception registe=
rs =3D 0x6818b850<br>Exception in thread &quot;Thread-1&quot;<span style=3D=
"background-color:rgb(255,0,0)"> j<b>ava.lang.NullPointerException</b></spa=
n><br>=C2=A0=C2=A0 at org.jikesrvm.energy.LogQueue.dumpLogQueue(LogQueue.ja=
va:82)<br>=C2=A0=C2=A0 at org.jikesrvm.VM$1.run(VM.java:495)<br><span style=
=3D"background-color:rgb(255,255,0)"><b>logQueue size is : 56170</b></span>=
<br>[Here is the context of the call to VM.sysExit(0)...:<br>Dumping stack =
for Thread #52<br>-- Stack --<br>(0x69356df4 21346)=C2=A0=C2=A0 at [0x69356=
df4, 0x64915a8f] Lorg/jikesrvm/VM; sysExit(I)V at line 2405 at bytecode ind=
ex 65 at machine code offset 0x0000044a<br>(0x69356e14 8264)=C2=A0=C2=A0 at=
 [0x69356e14, 0x64916ed6] Ljava/lang/VMRuntime; exit(I)V at line 80 at byte=
code index 1 at machine code offset 0x00000057<br>=C2=A0=C2=A0 at [0x69356e=
14, 0x64916ed6] Ljava/lang/Runtime; halt(I)V at line 399 at bytecode index =
14 at machine code offset 0x00000057<br>(0x69356e4c 8260)=C2=A0=C2=A0 at [0=
x69356e4c, 0x64baeaa2] Ljava/lang/Runtime; exit(I)V at line 174 at bytecode=
 index 22 at machine code offset 0x00000076<br>(0x69356e6c 5222)=C2=A0=C2=
=A0 at [0x69356e6c, 0x6883a21a] Ljava/lang/System; exit(I)V at line 586 at =
bytecode index 4 at machine code offset 0x00000042<br>(0x69356e88 23006)=C2=
=A0=C2=A0 at [0x69356e88, 0x64a6578e] LHarness; main([Ljava/lang/String;)V =
at line 18 at bytecode index 5 at machine code offset 0x0000006e<br>(0x6935=
6ea0 -1)=C2=A0=C2=A0 at [0x69356ea0, 0x64ae7644] &lt;invisible method&gt;<b=
r>(0x69356f2c 6569)=C2=A0=C2=A0 at [0x69356f2c, 0x648ab78a] Lorg/jikesrvm/r=
untime/Reflection; outOfLineInvoke(Lorg/jikesrvm/classloader/RVMMethod;Ljav=
a/lang/Object;[Ljava/lang/Object;Z)Ljava/lang/Object; at line 223 at byteco=
de index 433 at machine code offset 0x000006b4<br>(0x69356f80 13219)=C2=A0=
=C2=A0 at [0x69356f80, 0x64bd7236] Lorg/jikesrvm/runtime/Reflection; invoke=
(Lorg/jikesrvm/classloader/RVMMethod;Lorg/jikesrvm/runtime/ReflectionBase;L=
java/lang/Object;[Ljava/lang/Object;Z)Ljava/lang/Object; at line 93 at byte=
code index 50 at machine code offset 0x00000676<br>=C2=A0=C2=A0 at [0x69356=
f80, 0x64bd7236] Lorg/jikesrvm/scheduler/MainThread; run()V at line 201 at =
bytecode index 173 at machine code offset 0x00000676<br>(0x69356fc0 22729)=
=C2=A0=C2=A0 at [0x69356fc0, 0x64eb64c4] Lorg/jikesrvm/scheduler/RVMThread;=
 run()V at line 2837 at bytecode index 46 at machine code offset 0x00000262=
<br>(0x69356ff8 22818)=C2=A0=C2=A0 at [0x69356ff8, 0xf77ab618] Lorg/jikesrv=
m/scheduler/RVMThread; startoff()V at line 2898 at bytecode index 78 at mac=
hine code offset 0x000001f4<br>... END context of the call to VM.sysExit]<b=
r><br></div><div>Here is the Number of entries gets printed out: <br><div><=
img src=3D"cid:ii_jtsd9hzz2" alt=3D"image.png" width=3D"61" height=3D"30"><=
br><br></div><div>Thanks,<br></div><div>Kenan<br></div></div><div><i></i></=
div><div>-- <br><div dir=3D"ltr" class=3D"gmail_signature"><div dir=3D"ltr"=
><div><div>Kenan Liu<br></div>PhD Candidate in Computer Science<br></div>SU=
NY Binghamton<br></div></div></div></div></div></div></div>

--000000000000d36bdd05852337c6--
--000000000000d36bde05852337c7
Content-Type: image/png; name="image.png"
Content-Disposition: inline; filename="image.png"
Content-Transfer-Encoding: base64
Content-ID: <ii_jtsd9hzz2>
X-Attachment-Id: ii_jtsd9hzz2

iVBORw0KGgoAAAANSUhEUgAAAD0AAAAeCAIAAAAQOIEmAAAAA3NCSVQICAjb4U/gAAADBUlEQVRY
R2M04FJhGIKAaQi6GeTkUXfTN+JGw3s0vIkJgdF0QkwoUU8NSeHNxG2QMPX5rbVFiizILuDUK79z
+/xXODpRY86JJI9dFxOfbsTsdXs/AXVd3bmvNVCbixGuh4CBIHUoDsATHKxiht7Fhdk5liIMDPfR
1DFz8nH9v1kTU7f743+g1P/fH+79gCjBqYtZzH3+knLri7MSIo+8kXKsba7byfVWv/jQ238gjbgN
hNtMpLs5VAs6sq0uLY4sN5rdKYfmbiYuQY7vTy5evXXlK6oMTl1MYraRHlzXCytnrnsKdOnVJC6z
G42Jnu1HlrwCORyngQjjiXT3j2vVHm7////nsdJBczTQFj4JAZYfb3nEhHkevf3yF0kepy6gw7gY
/r17+QUcvAz/3ly99JzJ3UyabckrYEzhNhBhNtHpG+hoDBdDBFh4+b6/ZHFdtmvPyxvHzs1IdxFl
hqvEoevP89OnnzMZFcUaibMyMrHzKygJszOwcLJAkjg+A2EmExneOJwMFv51fWay6kxgquRVsQxq
7SnYOO+PcdDcG7/x6fl2eXpsv/zSwrn38sHKQLH0+NEnSGQRYyDR4Y3PFRC5v5/vHFmU1XDyt4a3
jwyh8Pj36fi0LGVtB3VnP01LV881bxk+XTn85BeKLfgMpKK7wXYyQQ1EFGp4PPz/18cnj55+kA3r
DhO+u2LxKbRsjc9AQuECs5WRU0xeSZCVR46PlYFDUklVh/XL8/uP3/5mYOTRzUs3eX/55qMvjCJq
9tmF5qw3p219CkklOHUxMHHKqqkqyylbOPhkhBqxH+11nXLjG9gyvAZCvCLg1shIZH+Hw7x5674I
IaTAu1/rFtZ3/w+zqF1LT0GUqaIIKwPD12cn96xu6lx84DUkpeLUxcCpP2XfgkTedzcvndq0esmk
TVffwQoivAaC7WfXaNtFrLuRHDzwTCYRK2LTycA7FuoCRi5N77iyVGrnS5r77z8Dn4rC731DMp0A
A2fIhTc0QkfdTfOUjWLBaHiPhjcxITBU0wkA2+VrafvqnPgAAAAASUVORK5CYIIA
--000000000000d36bde05852337c7--


--===============5121166470318369412==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline


--===============5121166470318369412==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

_______________________________________________
Jikesrvm-researchers mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/jikesrvm-researchers

--===============5121166470318369412==--