Project

General

Profile

Bug #2283

Appserver persistence-related abend on subsequent connect

Added by Stanislav Lomany about 10 years ago. Updated about 8 years ago.

Status:
Closed
Priority:
Normal
Assignee:
-
Target version:
-
Start date:
04/12/2014
Due date:
% Done:

100%

billable:
No
vendor_id:
GCD
case_num:
version_reported:
version_resolved:

History

#1 Updated by Stanislav Lomany about 10 years ago

Testcase (called.p):

def temp-table tt field f1 as integer.
create tt. tt.f1 = 1.

calling.p:

def var hs as handle.
def var hp as handle.

create server hs.
hs:connect("-AppService app_server").
run called.p persistent set hp on server hs.

hs:disconnect().

Reproduction: the first run is successful, second - fails, third - successful, 4th - fails and so on.

Stacktrace:

[04/12/2014 12:37:19 TMT] (com.goldencode.p2j.util.Agent:WARNING) Agent encountered an error while executing a command for appserver app_server
java.lang.RuntimeException: invoke() of class com.goldencode.testcases.Called and  method execute failed
        at com.goldencode.p2j.util.ControlFlowOps.invokeError(ControlFlowOps.java:4667)
        at com.goldencode.p2j.util.ControlFlowOps.invokeExternalProcedure(ControlFlowOps.java:3392)
        at com.goldencode.p2j.util.Agent$7.execute(Agent.java:1017)
        at com.goldencode.p2j.util.Agent.listen(Agent.java:351)
        at com.goldencode.p2j.util.AgentPool.start(AgentPool.java:409)
        at com.goldencode.p2j.util.AppServerManager.startAppServer(AppServerManager.java:766)
        at com.goldencode.p2j.main.StandardServer.standardEntry(StandardServer.java:265)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:76)
        at com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:693)
        at com.goldencode.p2j.net.Conversation.block(Conversation.java:319)
        at com.goldencode.p2j.net.Conversation.run(Conversation.java:163)
        at java.lang.Thread.run(Thread.java:722)
Caused by: java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.goldencode.p2j.util.ControlFlowOps$InternalEntryCaller.invoke(ControlFlowOps.java:4844)
        at com.goldencode.p2j.util.ControlFlowOps.invokeExternalProcedure(ControlFlowOps.java:3322)
        at com.goldencode.p2j.util.Agent$7.execute(Agent.java:1017)
        at com.goldencode.p2j.util.Agent.listen(Agent.java:351)
        at com.goldencode.p2j.util.AgentPool.start(AgentPool.java:409)
        at com.goldencode.p2j.util.AppServerManager.startAppServer(AppServerManager.java:766)
        at com.goldencode.p2j.main.StandardServer.standardEntry(StandardServer.java:265)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:76)
        at com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:693)
        at com.goldencode.p2j.net.Conversation.block(Conversation.java:319)
        at com.goldencode.p2j.net.Conversation.run(Conversation.java:163)
        at java.lang.Thread.run(Thread.java:722)
Caused by: java.lang.NullPointerException
        at com.goldencode.p2j.persist.BufferManager.resetState(BufferManager.java:862)
        at com.goldencode.p2j.util.TransactionManager.processResettables(TransactionManager.java:1786)
        at com.goldencode.p2j.util.TransactionManager.rollbackWorker(TransactionManager.java:1726)
        at com.goldencode.p2j.util.TransactionManager.rollback(TransactionManager.java:1587)
        at com.goldencode.p2j.util.TransactionManager.rollback(TransactionManager.java:1544)
        at com.goldencode.p2j.util.TransactionManager.abnormalEnd(TransactionManager.java:3313)
        at com.goldencode.p2j.util.TransactionManager.abnormalEnd(TransactionManager.java:3234)
        at com.goldencode.p2j.util.BlockManager.topLevelBlock(BlockManager.java:6896)
        at com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:218)
        at com.goldencode.p2j.util.BlockManager.externalProcedure(BlockManager.java:200)
        at com.goldencode.testcases.Called.execute(Called.java:16)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.goldencode.p2j.util.ControlFlowOps$InternalEntryCaller.invoke(ControlFlowOps.java:4844)
        at com.goldencode.p2j.util.ControlFlowOps.invokeExternalProcedure(ControlFlowOps.java:3322)
        at com.goldencode.p2j.util.Agent$7.execute(Agent.java:1017)
        at com.goldencode.p2j.util.Agent.listen(Agent.java:351)
        at com.goldencode.p2j.util.AgentPool.start(AgentPool.java:409)
        at com.goldencode.p2j.util.AppServerManager.startAppServer(AppServerManager.java:766)
        at com.goldencode.p2j.main.StandardServer.standardEntry(StandardServer.java:265)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at com.goldencode.p2j.util.MethodInvoker.invoke(MethodInvoker.java:76)
        at com.goldencode.p2j.net.Dispatcher.processInbound(Dispatcher.java:693)
        at com.goldencode.p2j.net.Conversation.block(Conversation.java:319)
        at com.goldencode.p2j.net.Conversation.run(Conversation.java:163)
        at java.lang.Thread.run(Thread.java:722)

#2 Updated by Constantin Asofiei about 10 years ago

Stanislav, if you look into the TM.resettables list, there are two BufferManager instances, when it should have been only one. This is again a "chicken-and-the-egg" problem, this time in SecurityManager.resetContext(). Currently, SecurityContext has no explicit order to save/process the tokens, and while resetting the Agent's context, the stacktrace ends up like this:

TransactionManager$WorkArea.access$11(TransactionManager$WorkArea) line: 5346    
TransactionManager.registerResettable(Resettable) line: 991    
BufferManager.<init>() line: 467    
BufferManager.<init>(BufferManager) line: 463    
BufferManager$1.initialValue() line: 355    
BufferManager$1.initialValue() line: 1    
BufferManager$1(ContextLocal<T>).get() line: 177    
BufferManager.get() line: 493    
BufferManager$3.createScopeable() line: 510    
TransactionManager$ContextContainer.obtain() line: 5734    
TransactionManager.registerBatchListener(BatchListener) line: 1484    
BufferManager.<init>() line: 465    
BufferManager.<init>(BufferManager) line: 463    
BufferManager$1.initialValue() line: 355    
BufferManager$1.initialValue() line: 1    
BufferManager$1(ContextLocal<T>).get() line: 177    
BufferManager.get() line: 493    
Persistence$Context.<init>(Persistence) line: 4396    
Persistence$Context.<init>(Persistence, Persistence$Context) line: 4433    
Persistence$1.initialValue() line: 626    
Persistence$1.initialValue() line: 1    
Persistence$1(ContextLocal<T>).get() line: 177    
Persistence.isTransactionOpen() line: 3604    
TemporaryBuffer$Context.dropAllTables() line: 4012    
TemporaryBuffer$Context.sessionEvent(SessionListener$Event) line: 3714    
Persistence$Context.notifySessionEvent(SessionListener$Event) line: 5315    
Persistence$Context.closeSessionImpl(boolean) line: 5254    
Persistence$Context.closeSession(boolean) line: 5138    
Persistence$Context.cleanup() line: 5371    
Persistence$1.cleanup(Persistence$Context) line: 627    
Persistence$1.cleanup(Object) line: 1    
ContextLocal$Wrapper.cleanup() line: 393    
SecurityContext.reset() line: 434    
SecurityManager.resetContext() line: 2944    
Agent$ResetContextCommand.execute() line: 1446    
Agent.listen() line: 351    
AgentPool$BoundPool(AgentPool).start() line: 409    
AppServerManager.startAppServer() line: 766    
StandardServer.standardEntry(ClientParameters) line: 266    
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]    
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 57    
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 43    
Method.invoke(Object, Object...) line: 606    
MethodInvoker.invoke(Object[]) line: 76    
Dispatcher.processInbound(InboundRequest, boolean, NetResource) line: 694    
Conversation.block() line: 319    
Conversation.run() line: 163    
Thread.run() line: 744    

As you can see, the BufferManager.<init>() init code is called twice. I think this is because the TM's and BufferManager's context-local vars are cleaned too early by SecurityContext.reset:410, which clears the entire token map. But even if the token map is not cleared, this does not ensure proper ordering of the tokens, when resetting them... I'm not sure, but using a linked hash map for the tokens and processing this in reverse order might help.

#3 Updated by Greg Shah about 8 years ago

Is this still an issue?

#4 Updated by Constantin Asofiei about 8 years ago

Greg Shah wrote:

Is this still an issue?

No, is not. I've double-checked and is fixed. The fix was using correct order of ContextLocal vars, when the Agent's context was reset.

#5 Updated by Eric Faulhaber about 8 years ago

  • Status changed from New to Closed
  • % Done changed from 0 to 100

Also available in: Atom PDF