search

OpenNTF / org.openntf.nsfodp

Maven and Eclipse tooling for working with NSF on-disk-project representations
Apache License 2.0
14 stars 6 forks source link

Domino 14: OutOfMemoryError: Java heap space #329

Open edy opened 1 week ago

edy commented 1 week ago

Dear Jesse,

after you fixed #327, I was able to continue compiling the project. However, after a few minutes an error occurred and Domino crashed.

This is the maven output:

[INFO] --- nsfodp:4.0.6:compile (default-compile) @ Edy ---
[INFO] Compiling ODP
[INFO] Writing ACL from pom.xml into AppProperties/database.properties
[INFO] Compiling with server: http://myserver:8052/org.openntf.nsfodp/compiler
[INFO] Installing bundles
[INFO] - Installed no bundles
[INFO] Initializing libraries
[INFO] Compiling Java source
[INFO] - Compiling 1,288 classes
[INFO] Compiling custom controls
[INFO] Compiling XPages
[INFO] Creating destination NSF
[INFO] Importing DB properties
[INFO] Importing basic design elements - early part (Java libs)
[INFO] Importing LotusScript libraries
[INFO] Importing basic design elements

Then after some minutes Domino crashes and i get this error (while using the -e flag for maven). I was not able to increase the heap space.

I'm not really sure, but this seems to be a place in the code that receives the successful build after the POST request.

java.lang.OutOfMemoryError: Java heap space
    at java.util.Arrays.copyOf (Arrays.java:3541)
    at java.io.ByteArrayOutputStream.ensureCapacity (ByteArrayOutputStream.java:100)
    at java.io.ByteArrayOutputStream.write (ByteArrayOutputStream.java:112)
    at org.openntf.maven.nsfodp.util.ResponseUtil.readLine (ResponseUtil.java:128)
    at org.openntf.maven.nsfodp.util.ResponseUtil.monitorResponse (ResponseUtil.java:75)
    at org.openntf.maven.nsfodp.CompileODPMojo.compileOdpOnServer (CompileODPMojo.java:564)
    at org.openntf.maven.nsfodp.CompileODPMojo.execute (CompileODPMojo.java:370)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:126)
    at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute2 (MojoExecutor.java:328)
    at org.apache.maven.lifecycle.internal.MojoExecutor.doExecute (MojoExecutor.java:316)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:212)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:174)
    at org.apache.maven.lifecycle.internal.MojoExecutor.access$000 (MojoExecutor.java:75)
    at org.apache.maven.lifecycle.internal.MojoExecutor$1.run (MojoExecutor.java:162)
    at org.apache.maven.plugin.DefaultMojosExecutionStrategy.execute (DefaultMojosExecutionStrategy.java:39)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:159)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:105)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:73)
    at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:53)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:118)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:261)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:173)
    at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:101)
    at org.apache.maven.cli.MavenCli.execute (MavenCli.java:906)
    at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:283)
    at org.apache.maven.cli.MavenCli.main (MavenCli.java:206)
    at java.lang.invoke.DirectMethodHandle$Holder.invokeStatic (DirectMethodHandle$Holder)
    at java.lang.invoke.LambdaForm$MH/0x0000011b44009400.invoke (LambdaForm$MH)
    at java.lang.invoke.LambdaForm$MH/0x0000011b44009800.invokeExact_MT (LambdaForm$MH)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invokeImpl (DirectMethodHandleAccessor.java:155)
    at jdk.internal.reflect.DirectMethodHandleAccessor.invoke (DirectMethodHandleAccessor.java:103)
    at java.lang.reflect.Method.invoke (Method.java:580)

With Domino 12 we get an nsf of about 70mb.

jesse-gallagher commented 1 week ago

Hmm, interesting, and your suspicion on where it's going awry is presumably correct. I wonder if there's something about the changed JVM or library code that makes the process not realize it's done the "JSON" part and on to the "binary" part. I'll have to see if I can reproduce it. It didn't happen with the example projects in the repo for me, but maybe it's only after the compiled NSF ends up a certain size or above.

jesse-gallagher commented 6 days ago

I found a project that reproduces it, but it makes the situation thornier: it looks like the trouble is that the call to compile LotusScript in a note will crash the server given some combination of input, even though the same won't happen on 12.0.2. I see this stack from the NSD:

#0  0x00007f93b2e3ee7d in select () from /lib64/libc.so.6
#1  0x00007f93b35a5f0f in FRDoSleep (secs=secs@entry=1, usecs=usecs@entry=0) at cleanup.c:944
#2  0x00007f93b35ad6bd in OSRunExternalScript (passed_script=passed_script@entry=0x7f92e68189e0 "\"/opt/hcl/domino/notes/latest/linux/nsd.sh\" -batch -crashpid 1164 -crashtid 3867268672", flags=flags@entry=1) at cleanup.c:3909
#3  0x00007f93b35b0587 in OSFaultCleanupExt (action2take=action2take@entry=0, CleanupScriptExecFlag=CleanupScriptExecFlag@entry=4096, iniFileName=iniFileName@entry=0x0, szProcess=szProcess@entry=0x0, Length=Length@entry=0, CrashedPID=CrashedPID@entry=0x0) at cleanup.c:1495
#4  0x00007f93b35b05c1 in OSFaultCleanup (action2take=action2take@entry=0, CleanupScriptExecFlag=CleanupScriptExecFlag@entry=4096, iniFileName=iniFileName@entry=0x0) at cleanup.c:1281
#5  0x00007f93b357a6cf in fatal_error (signl=11, info=<optimized out>, context=<optimized out>) at break.c:2207
#6  <signal handler called>
#7  LSsExprList::GetNumExprs (this=0x0, pMoreExprs=pMoreExprs@entry=0x7f92e681998e) at lsprsnod.cpp:398
#8  0x00007f93b542a0cd in SIcParser::DoArray (this=this@entry=0x7f913c3ed850, iArraySymRel=iArraySymRel@entry=6108, arrSize=@0x7f92e6819a18: 0, bRedim=<optimized out>) at lsprsd2.cpp:1774
#9  0x00007f93b542aea6 in SIcParser::vardcl (this=this@entry=0x7f913c3ed850) at lsprsd2.cpp:322
#10 0x00007f93b542ffa5 in SIcParser::WalkSubTree (this=0x7f913c3ed850, pnode=0x7f913c445430) at lsprss2.cpp:1787
#11 0x00007f93b542fcb9 in SIcParser::WalkSubTree (this=0x7f913c3ed850, pnode=0x7f913c445470) at lsprss2.cpp:1607
#12 0x00007f93b542fcb9 in SIcParser::WalkSubTree (this=0x7f913c3ed850, pnode=0x7f913c4454b0) at lsprss2.cpp:1607
#13 0x00007f93b542fcb9 in SIcParser::WalkSubTree (this=this@entry=0x7f913c3ed850, pnode=0x7f913c449230, pnode@entry=0x7f913c40e770) at lsprss2.cpp:1607
#14 0x00007f93b5430050 in SIcParser::_script (this=0x7f913c3ed850) at lsprss2.cpp:103
#15 0x00007f93b541e340 in SIcParser::attach (this=this@entry=0x7f913c3ed850) at lsparse.cpp:1373
#16 0x00007f93b541ffd1 in SIcParser::Parse (this=this@entry=0x7f913c3ed850) at lsparse.cpp:1029
#17 0x00007f93b54215f8 in SIcParser::doParse (this=this@entry=0x7f913c3ed850, hMod=hMod@entry=0x7f913c3d8500, pfGetc=pfGetc@entry=0x7f93b53ee820 <GetcFromMem(LShINSTANCE, LShMODULE, PLSMEMSOURCE)>, pfErr=pfErr@entry=0x7f93b53ee0a0 <ApiErrorProc(LShINSTANCE, LShMODULE, LSUSHORT, LSUSHORT, LSLINE, LSREGNAME, LSREGNAME)>) at lsparse.cpp:260
#18 0x00007f93b53ed975 in LSsInstance::Compile (this=0x7f913c301e98, ModName=0x7f913c31c520, ModRefCon=0x7f913c0984c8, pMemSource=0x7f92e681a400, pModUseList=0x7f92e681a420, pGetcProc=0x7f93b53ee820 <GetcFromMem(LShINSTANCE, LShMODULE, PLSMEMSOURCE)>, pErrProc=0x7f93b3ca0fa3 <LsCompileErrorCallback>, flags=133, retMod=0x7f913c0984e0) at apimod.cpp:234
#19 0x00007f93b53b0352 in LSIModule::CompileScriptForSave(char*, unsigned int, short, unsigned short, unsigned char**) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#20 0x00007f93b53ba7dd in CLSIDocument::CompileTheLibrary(unsigned int, unsigned int, unsigned int) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#21 0x00007f93b53bb6fb in CLSIDocument::CompileTheNote(unsigned int, unsigned int, unsigned int) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#22 0x00007f93b53bc8ec in LSCompileNoteExt () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#23 0x00007f93b3ca1335 in NSFNoteLSCompileExt (hDB=250, hNote=100, dwFlags=0, pfnErrProc=0x7f92dc653b28 <J_LSCOMPILEERRPROC::FCT_LSCOMPILEERRPROC(LSCOMPILE_ERR_INFO const*, void*)>, pCtx=0x7f92e681a8a0) at wrap4.c:220
#24 0x00007f92dc64ed59 in Java_com_darwino_domino_napi_DominoAPIImpl_NSFNoteLSCompileExt () from /tmp/libdominonapi11296583853798654116.so

That's lower-level than anything I'm explicitly doing, and it seems like it's dying during parsing. I'll have to try to track down if there's a specific construct in LotusScript that causes this, which would be ideal for a support case. That could be a long process, though, since the app I picked has a huge amount of LS code in it.

jesse-gallagher commented 6 days ago

Oh: it's also on Linux specifically for me. 14.5 EAP1 on Windows worked without issue for me, while 14.0 and 14.5 EAP1 crash on Linux in containers.

jesse-gallagher commented 6 days ago

Ah, some good news! I was able to narrow it down to a single library, and it's a common one at that: this NSF uses OpenLog, and OpenLogFunctions reliably crashes the server when I add it to an ODP that was previously working fine. Even better, OpenLogFunctions has no external Use or UseLSX statement, so this should let me narrow it down. It may end up being a matter for HCL Support, but the simpler the reproduction the better.

edy commented 6 days ago

Hey Jesse, thank you for the support. I'm not sure if it helps but we use SLF4J for logging

jesse-gallagher commented 6 days ago

Since it seems like yours dies on "basic design elements", it could be that you have something in there that trips up the parser in the same way as OpenLog does.

Do you see NSDs from server crashes around when you try this compilation? That could help prove that it's the same problem, especially if you see "NSFNoteLSCompileExt" or "LSCompileNoteExt" anywhere in there.

edy commented 6 days ago

i'll try to get the nsd when i'm back from a business trip on saturday and get back to you

edy commented 4 days ago

I also see NSFNoteLSCompileExt and LSCompileNoteExt in the nsd

Thread 148 (Thread 0x7f02b3359640 (LWP 18829) "Thread-103"):
#0  0x00007f034cf4ce7d in select () from /lib64/libc.so.6
#1  0x00007f034d696c77 in FRDoSleep (secs=secs@entry=1, usecs=usecs@entry=0) at cleanup.c:944
#2  0x00007f034d69e425 in OSRunExternalScript (passed_script=passed_script@entry=0x7f02b33546e0 "\"/opt/hcl/domino/notes/latest/linux/nsd.sh\" -batch -crashpid 6592 -crashtid 3006633536", flags=flags@entry=1) at cleanup.c:3908
#3  0x00007f034d6a12ef in OSFaultCleanupExt (action2take=action2take@entry=0, CleanupScriptExecFlag=CleanupScriptExecFlag@entry=4096, iniFileName=iniFileName@entry=0x0, szProcess=szProcess@entry=0x0, Length=Length@entry=0, CrashedPID=CrashedPID@entry=0x0) at cleanup.c:1494
#4  0x00007f034d6a1329 in OSFaultCleanup (action2take=action2take@entry=0, CleanupScriptExecFlag=CleanupScriptExecFlag@entry=4096, iniFileName=iniFileName@entry=0x0) at cleanup.c:1280
#5  0x00007f034d66b6cf in fatal_error (signl=11, info=<optimized out>, context=<optimized out>) at break.c:2202
#6  <signal handler called>
#7  LSsExprList::GetNumExprs (this=0x0, pMoreExprs=pMoreExprs@entry=0x7f02b335505e) at lsprsnod.cpp:398
#8  0x00007f034f4bf2cd in SIcParser::DoArray (this=this@entry=0x7f0292110270, iArraySymRel=iArraySymRel@entry=4036, arrSize=@0x7f02b33550e8: 0, bRedim=<optimized out>) at lsprsd2.cpp:1764
#9  0x00007f034f4bfdd6 in SIcParser::vardcl (this=this@entry=0x7f0292110270) at lsprsd2.cpp:312
#10 0x00007f034f4c5151 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292132ba0) at lsprss2.cpp:1787
#11 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292132be0) at lsprss2.cpp:1607
#12 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292132c20) at lsprss2.cpp:1607
#13 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f02921336e0) at lsprss2.cpp:1607
#14 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292133760) at lsprss2.cpp:1607
#15 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f02921337a0) at lsprss2.cpp:1607
#16 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f02921337e0) at lsprss2.cpp:1607
#17 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292133860) at lsprss2.cpp:1607
#18 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f02921338a0) at lsprss2.cpp:1607
#19 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292136ee0) at lsprss2.cpp:1607
#20 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292136f60) at lsprss2.cpp:1607
#21 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=0x7f0292110270, pnode=0x7f0292136fa0) at lsprss2.cpp:1607
#22 0x00007f034f4c4e65 in SIcParser::WalkSubTree (this=this@entry=0x7f0292110270, pnode=0x7f0292137060, pnode@entry=0x7f0292124560) at lsprss2.cpp:1607
#23 0x00007f034f4c51fc in SIcParser::_script (this=0x7f0292110270) at lsprss2.cpp:103
#24 0x00007f034f4b3540 in SIcParser::attach (this=this@entry=0x7f0292110270) at lsparse.cpp:1373
#25 0x00007f034f4b51d1 in SIcParser::Parse (this=this@entry=0x7f0292110270) at lsparse.cpp:1029
#26 0x00007f034f4b67f8 in SIcParser::doParse (this=this@entry=0x7f0292110270, hMod=hMod@entry=0x7f0319ebb5d0, pfGetc=pfGetc@entry=0x7f034f483aca <GetcFromMem(LShINSTANCE, LShMODULE, PLSMEMSOURCE)>, pfErr=pfErr@entry=0x7f034f48334a <ApiErrorProc(LShINSTANCE, LShMODULE, LSUSHORT, LSUSHORT, LSLINE, LSREGNAME, LSREGNAME)>) at lsparse.cpp:260
#27 0x00007f034f482c1f in LSsInstance::Compile (this=0x7f0291da5648, ModName=0x7f0291cead80, ModRefCon=0x7f0291aee768, pMemSource=0x7f02b3355c80, pModUseList=0x7f02b3355ca0, pGetcProc=0x7f034f483aca <GetcFromMem(LShINSTANCE, LShMODULE, PLSMEMSOURCE)>, pErrProc=0x7f034dd6d3e2 <LsCompileErrorCallback>, flags=133, retMod=0x7f0291aee780) at apimod.cpp:234
#28 0x00007f034f44597a in LSIModule::CompileScriptForSave(char*, unsigned int, short, unsigned short, unsigned char**) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#29 0x00007f034f44d4f7 in CLSIDocument::CompileTheScript(unsigned int, unsigned int, unsigned int*, unsigned char*, unsigned short) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#30 0x00007f034f44d6cb in CLSIDocument::CompileFormatField(char*, char*, char*, char*, unsigned int, unsigned int) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#31 0x00007f034f450d4b in CLSIDocument::CompileTheNote(unsigned int, unsigned int, unsigned int) () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#32 0x00007f034f451ecc in LSCompileNoteExt () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#33 0x00007f034dd6d774 in NSFNoteLSCompileExt (hDB=248, hNote=49, dwFlags=0, pfnErrProc=0x7f01ab0a8507 <LsCompileErrorCallback(LSCOMPILE_ERR_INFO const*, void*)>, pCtx=0x7f0291ca80e0) at wrap4.c:220
#34 0x00007f01ab0a9886 in DxlNote::compileLotusScript() () from /opt/hcl/domino/notes/latest/linux/libdxli2.so
#35 0x00007f01ab0ad36c in DxlNote::processEpilogContent() () from /opt/hcl/domino/notes/latest/linux/libdxli2.so
#36 0x00007f01ab0a84e9 in DxlNote::process() () from /opt/hcl/domino/notes/latest/linux/libdxli2.so
#37 0x00007f01ab0977ec in DxlImporter::processDxl(XmlInputSource*, unsigned int) () from /opt/hcl/domino/notes/latest/linux/libdxli2.so
#38 0x00007f01ab0932f8 in DxliImpl::Process(XmlInputSource*, unsigned int, unsigned int*, char const*) () from /opt/hcl/domino/notes/latest/linux/libdxli2.so
#39 0x00007f034d6e7534 in DXLImport () from /opt/hcl/domino/notes/latest/linux/libnotes.so
#40 0x00007f01ab15fdc3 in Java_com_darwino_domino_napi_DominoAPIImpl_DXLImport () from /tmp/libdominonapi14039922458816362763.so
jesse-gallagher commented 4 days ago

Excellent, thank you. And that one comes from a slightly-different path to the same end, since that happens during the DXL import. Presumably, that means it’d be reproducible using just the normal LotusScript or Java API, removing another layer of user code in the stack - always a plus when narrowing things down.