[
https://issues.apache.org/jira/browse/GEODE-7254?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17148826#comment-17148826
]
Kirk Lund edited comment on GEODE-7254 at 6/30/20, 5:29 PM:
------------------------------------------------------------
The ServerOperationException is logged at debug/fine level which is why you
only see it at debug/fine or lower.
The complete stack is:
{noformat}
org.apache.geode.cache.client.ServerOperationException: remote server on
RGOTETPF0T711Q(5296:loner):51773:b186be82: : While performing a remote put
at
org.apache.geode.cache.client.internal.PutOp$PutOpImpl.processAck(PutOp.java:384)
at
org.apache.geode.cache.client.internal.PutOp$PutOpImpl.processResponse(PutOp.java:308)
at
org.apache.geode.cache.client.internal.PutOp$PutOpImpl.attemptReadResponse(PutOp.java:449)
at
org.apache.geode.cache.client.internal.AbstractOp.attempt(AbstractOp.java:386)
at
org.apache.geode.cache.client.internal.ConnectionImpl.execute(ConnectionImpl.java:274)
at
org.apache.geode.cache.client.internal.pooling.PooledConnection.execute(PooledConnection.java:325)
at
org.apache.geode.cache.client.internal.OpExecutorImpl.executeWithPossibleReAuthentication(OpExecutorImpl.java:892)
at
org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:171)
at
org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:128)
at
org.apache.geode.cache.client.internal.PoolImpl.execute(PoolImpl.java:758)
at org.apache.geode.cache.client.internal.PutOp.execute(PutOp.java:89)
at
org.apache.geode.cache.client.internal.ServerRegionProxy.put(ServerRegionProxy.java:152)
at
org.apache.geode.internal.cache.LocalRegion.serverPut(LocalRegion.java:3032)
at
org.apache.geode.internal.cache.LocalRegion.cacheWriteBeforePut(LocalRegion.java:3144)
at
org.apache.geode.internal.cache.ProxyRegionMap.basicPut(ProxyRegionMap.java:238)
at
org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5664)
at
org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:152)
at
org.apache.geode.internal.cache.LocalRegion.basicPut(LocalRegion.java:5090)
at
org.apache.geode.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1635)
at
org.apache.geode.internal.cache.LocalRegion.put(LocalRegion.java:1622)
at
org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:411)
at
com.actuate.iserver.utils.cache.GeodeCacheClient.cacheObject(GeodeCacheClient.java:41)
at
com.actuate.iserver.utils.CachedUserProperties.cache(CachedUserProperties.java:88)
at
com.actuate.iserver.services.api.LoginServiceBase.updateTokenMappings(LoginServiceBase.java:144)
at
com.actuate.iserver.services.api.LoginServiceBase.doExecute(LoginServiceBase.java:139)
at com.actuate.iserver.services.ServiceBase.execute(ServiceBase.java:72)
at
com.actuate.iserver.services.api.idapi.actuate11.ActuateSoapBindingImpl.login(ActuateSoapBindingImpl.java:29)
at
com.actuate.schemas.actuate11.wsdl.ActuateAPIMessageReceiverInOut.invokeBusinessLogic(ActuateAPIMessageReceiverInOut.java:2245)
at
com.actuate.iserver.services.api.idapi.actuate11.ActuateAPIMessageReceiver.invokeBusinessLogic(ActuateAPIMessageReceiver.java:29)
at
org.apache.axis2.receivers.AbstractInOutMessageReceiver.invokeBusinessLogic(AbstractInOutMessageReceiver.java:40)
at
org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:114)
at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:173)
at
org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:173)
at
org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:144)
at
com.actuate.webserver.NimbleAxis2Servlet.doPostWrapper(NimbleAxis2Servlet.java:88)
at
com.actuate.ihub.filter.LocalFilter.processRequest(LocalFilter.java:331)
at
com.actuate.ihub.filter.RequestFilter.doFilter(RequestFilter.java:269)
at
com.actuate.ihub.filter.RequestFilterChain.processFilter(RequestFilterChain.java:52)
at
com.actuate.ihub.filter.RequestFilterManager.processFilters(RequestFilterManager.java:264)
at com.actuate.ihub.web.FilterServlet.doRequest(FilterServlet.java:153)
at com.actuate.ihub.web.FilterServlet.doPost(FilterServlet.java:82)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:660)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:668)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:834)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1417)
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ExceptionInInitializerError
at
com.actuate.iserver.utils.CachedUserProperties.<clinit>(CachedUserProperties.java:33)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at
org.apache.geode.internal.ClassPathLoader.forName(ClassPathLoader.java:157)
at
org.apache.geode.internal.InternalDataSerializer.getCachedClass(InternalDataSerializer.java:3359)
at
org.apache.geode.internal.InternalDataSerializer$DSObjectInputStream.resolveClass(InternalDataSerializer.java:3774)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1868)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1751)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2042)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1573)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:431)
at
org.apache.geode.internal.InternalDataSerializer.readSerializable(InternalDataSerializer.java:2932)
at
org.apache.geode.internal.InternalDataSerializer.basicReadObject(InternalDataSerializer.java:2876)
at org.apache.geode.DataSerializer.readObject(DataSerializer.java:2977)
at
org.apache.geode.internal.util.BlobHelper.deserializeBlob(BlobHelper.java:99)
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1981)
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1974)
at
org.apache.geode.internal.cache.VMCachedDeserializable.getDeserializedForReading(VMCachedDeserializable.java:161)
at
org.apache.geode.internal.cache.VMCachedDeserializable.getStringForm(VMCachedDeserializable.java:251)
at
org.apache.geode.internal.lang.StringUtils.objectToString(StringUtils.java:171)
at
org.apache.geode.internal.lang.StringUtils.forceToString(StringUtils.java:147)
at
org.apache.geode.internal.cache.EntryEventImpl.getOldValueStringForm(EntryEventImpl.java:1076)
at
org.apache.geode.internal.cache.entries.AbstractRegionEntry.generateVersionTag(AbstractRegionEntry.java:1656)
at
org.apache.geode.internal.cache.LocalRegion.generateAndSetVersionTag(LocalRegion.java:6015)
at
org.apache.geode.internal.cache.EntryEventImpl.setNewValueInRegion(EntryEventImpl.java:1640)
at
org.apache.geode.internal.cache.EntryEventImpl.putExistingEntry(EntryEventImpl.java:1584)
at
org.apache.geode.internal.cache.map.RegionMapPut.updateEntry(RegionMapPut.java:433)
at
org.apache.geode.internal.cache.map.RegionMapPut.createOrUpdateEntry(RegionMapPut.java:242)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutAndDeliverEvent(AbstractRegionMapPut.java:297)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.runWithIndexUpdatingInProgress(AbstractRegionMapPut.java:305)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutIfPreconditionsSatisified(AbstractRegionMapPut.java:293)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutOnSynchronizedRegionEntry(AbstractRegionMapPut.java:279)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutOnRegionEntryInMap(AbstractRegionMapPut.java:270)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.addRegionEntryToMapAndDoPut(AbstractRegionMapPut.java:248)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutRetryingIfNeeded(AbstractRegionMapPut.java:213)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doWithIndexInUpdateMode(AbstractRegionMapPut.java:195)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPut(AbstractRegionMapPut.java:177)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.runWhileLockedForCacheModification(AbstractRegionMapPut.java:119)
at
org.apache.geode.internal.cache.map.RegionMapPut.runWhileLockedForCacheModification(RegionMapPut.java:150)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.put(AbstractRegionMapPut.java:167)
at
org.apache.geode.internal.cache.AbstractRegionMap.basicPut(AbstractRegionMap.java:2100)
at
org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5664)
at
org.apache.geode.internal.cache.DistributedRegion.virtualPut(DistributedRegion.java:370)
at
org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:152)
at
org.apache.geode.internal.cache.LocalRegion.basicUpdate(LocalRegion.java:5644)
at
org.apache.geode.internal.cache.LocalRegion.basicBridgePut(LocalRegion.java:5281)
at
org.apache.geode.internal.cache.tier.sockets.command.Put65.cmdExecute(Put65.java:388)
at
org.apache.geode.internal.cache.tier.sockets.BaseCommand.execute(BaseCommand.java:178)
at
org.apache.geode.internal.cache.tier.sockets.ServerConnection.doNormalMessage(ServerConnection.java:844)
at
org.apache.geode.internal.cache.tier.sockets.OriginalServerConnection.doOneMessage(OriginalServerConnection.java:74)
at
org.apache.geode.internal.cache.tier.sockets.ServerConnection.run(ServerConnection.java:1214)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.lambda$initializeServerConnectionThreadPool$3(AcceptorImpl.java:594)
at
org.apache.geode.internal.logging.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:121)
... 1 more
{noformat}
The 9th line from the bottom of the stack trace is:
{noformat}
at
org.apache.geode.internal.cache.tier.sockets.command.Put65.cmdExecute(Put65.java:388)
{noformat}
Looking at {{Put65.java}} (this is the code being executed on the Server for
the put from your client), we can see the catch block which catches the
ServerOperationException:
{noformat}
} catch (Exception ce) {
// If an interrupted exception is thrown , rethrow it
checkForInterrupt(serverConnection, ce);
// If an exception occurs during the put, preserve the connection
writeException(clientMessage, ce, false, serverConnection);
serverConnection.setAsTrue(RESPONDED);
if (ce instanceof GemFireSecurityException) {
// Fine logging for security exceptions since these are already
// logged by the security logger
if (isDebugEnabled) {
logger.debug("{}: Unexpected Security exception",
serverConnection.getName(), ce);
}
} else if (isDebugEnabled) {
logger.debug("{}: Unexpected Exception", serverConnection.getName(),
ce);
}
return;
} finally {
{noformat}
The condition `if (ce instanceof GemFireSecurityException)` is false, so it
enters the `else` block and logs the exception at debug level which is fine
level:
{noformat}
logger.debug("{}: Unexpected Exception", serverConnection.getName(), ce);
{noformat}
Earlier you said that this problem does not occur at info level or above. This
would seem to indicate that something ends up trying to log your put key/value
only at debug/fine level and that the act of logging the value causes it to be
deserialized which then throws ExceptionInInitializerError.
In Geode, it's very possible that when the log level is above debug/fine,
nothing tries to use your value other than storing it, so it is left in
serialized form. Geode intentionally leaves values in serialized form on the
Server unless it needs the value for some purpose such as a query or a function
or a log statement, etc.
This is intentional behavior. I agree that it's not ideal for you to not
discover the problem with your class until it does get deserialized, but Geode
servers will not deserialize your class unless they need to for some reason.
The server simply did not need to deserialize your class until you changed the
log level to debug/fine.
I recommend writing unit tests that perform Geode serialization/deserialization
of your class. You could use org.apache.geode.DataSerializer directly (in
tests) or even write a custom DataSerializer for your class which should give
you more control.
Apache Commons Lang3 contains org.apache.commons.lang3.SerializationUtils which
can also be useful if you need to write unit tests for Java
serialization/deserialization of your class.
was (Author: klund):
The ServerOperationException is logged at debug/fine level which is why you
only see it at debug/fine or lower.
The complete stack is:
{noformat}
org.apache.geode.cache.client.ServerOperationException: remote server on
RGOTETPF0T711Q(5296:loner):51773:b186be82: : While performing a remote put
at
org.apache.geode.cache.client.internal.PutOp$PutOpImpl.processAck(PutOp.java:384)
at
org.apache.geode.cache.client.internal.PutOp$PutOpImpl.processResponse(PutOp.java:308)
at
org.apache.geode.cache.client.internal.PutOp$PutOpImpl.attemptReadResponse(PutOp.java:449)
at
org.apache.geode.cache.client.internal.AbstractOp.attempt(AbstractOp.java:386)
at
org.apache.geode.cache.client.internal.ConnectionImpl.execute(ConnectionImpl.java:274)
at
org.apache.geode.cache.client.internal.pooling.PooledConnection.execute(PooledConnection.java:325)
at
org.apache.geode.cache.client.internal.OpExecutorImpl.executeWithPossibleReAuthentication(OpExecutorImpl.java:892)
at
org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:171)
at
org.apache.geode.cache.client.internal.OpExecutorImpl.execute(OpExecutorImpl.java:128)
at
org.apache.geode.cache.client.internal.PoolImpl.execute(PoolImpl.java:758)
at org.apache.geode.cache.client.internal.PutOp.execute(PutOp.java:89)
at
org.apache.geode.cache.client.internal.ServerRegionProxy.put(ServerRegionProxy.java:152)
at
org.apache.geode.internal.cache.LocalRegion.serverPut(LocalRegion.java:3032)
at
org.apache.geode.internal.cache.LocalRegion.cacheWriteBeforePut(LocalRegion.java:3144)
at
org.apache.geode.internal.cache.ProxyRegionMap.basicPut(ProxyRegionMap.java:238)
at
org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5664)
at
org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:152)
at
org.apache.geode.internal.cache.LocalRegion.basicPut(LocalRegion.java:5090)
at
org.apache.geode.internal.cache.LocalRegion.validatedPut(LocalRegion.java:1635)
at
org.apache.geode.internal.cache.LocalRegion.put(LocalRegion.java:1622)
at
org.apache.geode.internal.cache.AbstractRegion.put(AbstractRegion.java:411)
at
com.actuate.iserver.utils.cache.GeodeCacheClient.cacheObject(GeodeCacheClient.java:41)
at
com.actuate.iserver.utils.CachedUserProperties.cache(CachedUserProperties.java:88)
at
com.actuate.iserver.services.api.LoginServiceBase.updateTokenMappings(LoginServiceBase.java:144)
at
com.actuate.iserver.services.api.LoginServiceBase.doExecute(LoginServiceBase.java:139)
at com.actuate.iserver.services.ServiceBase.execute(ServiceBase.java:72)
at
com.actuate.iserver.services.api.idapi.actuate11.ActuateSoapBindingImpl.login(ActuateSoapBindingImpl.java:29)
at
com.actuate.schemas.actuate11.wsdl.ActuateAPIMessageReceiverInOut.invokeBusinessLogic(ActuateAPIMessageReceiverInOut.java:2245)
at
com.actuate.iserver.services.api.idapi.actuate11.ActuateAPIMessageReceiver.invokeBusinessLogic(ActuateAPIMessageReceiver.java:29)
at
org.apache.axis2.receivers.AbstractInOutMessageReceiver.invokeBusinessLogic(AbstractInOutMessageReceiver.java:40)
at
org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:114)
at org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:173)
at
org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:173)
at
org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:144)
at
com.actuate.webserver.NimbleAxis2Servlet.doPostWrapper(NimbleAxis2Servlet.java:88)
at
com.actuate.ihub.filter.LocalFilter.processRequest(LocalFilter.java:331)
at
com.actuate.ihub.filter.RequestFilter.doFilter(RequestFilter.java:269)
at
com.actuate.ihub.filter.RequestFilterChain.processFilter(RequestFilterChain.java:52)
at
com.actuate.ihub.filter.RequestFilterManager.processFilters(RequestFilterManager.java:264)
at com.actuate.ihub.web.FilterServlet.doRequest(FilterServlet.java:153)
at com.actuate.ihub.web.FilterServlet.doPost(FilterServlet.java:82)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:660)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at
org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:668)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:834)
at
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1417)
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.ExceptionInInitializerError
at
com.actuate.iserver.utils.CachedUserProperties.<clinit>(CachedUserProperties.java:33)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at
org.apache.geode.internal.ClassPathLoader.forName(ClassPathLoader.java:157)
at
org.apache.geode.internal.InternalDataSerializer.getCachedClass(InternalDataSerializer.java:3359)
at
org.apache.geode.internal.InternalDataSerializer$DSObjectInputStream.resolveClass(InternalDataSerializer.java:3774)
at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1868)
at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1751)
at
java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2042)
at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1573)
at java.io.ObjectInputStream.readObject(ObjectInputStream.java:431)
at
org.apache.geode.internal.InternalDataSerializer.readSerializable(InternalDataSerializer.java:2932)
at
org.apache.geode.internal.InternalDataSerializer.basicReadObject(InternalDataSerializer.java:2876)
at org.apache.geode.DataSerializer.readObject(DataSerializer.java:2977)
at
org.apache.geode.internal.util.BlobHelper.deserializeBlob(BlobHelper.java:99)
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1981)
at
org.apache.geode.internal.cache.EntryEventImpl.deserialize(EntryEventImpl.java:1974)
at
org.apache.geode.internal.cache.VMCachedDeserializable.getDeserializedForReading(VMCachedDeserializable.java:161)
at
org.apache.geode.internal.cache.VMCachedDeserializable.getStringForm(VMCachedDeserializable.java:251)
at
org.apache.geode.internal.lang.StringUtils.objectToString(StringUtils.java:171)
at
org.apache.geode.internal.lang.StringUtils.forceToString(StringUtils.java:147)
at
org.apache.geode.internal.cache.EntryEventImpl.getOldValueStringForm(EntryEventImpl.java:1076)
at
org.apache.geode.internal.cache.entries.AbstractRegionEntry.generateVersionTag(AbstractRegionEntry.java:1656)
at
org.apache.geode.internal.cache.LocalRegion.generateAndSetVersionTag(LocalRegion.java:6015)
at
org.apache.geode.internal.cache.EntryEventImpl.setNewValueInRegion(EntryEventImpl.java:1640)
at
org.apache.geode.internal.cache.EntryEventImpl.putExistingEntry(EntryEventImpl.java:1584)
at
org.apache.geode.internal.cache.map.RegionMapPut.updateEntry(RegionMapPut.java:433)
at
org.apache.geode.internal.cache.map.RegionMapPut.createOrUpdateEntry(RegionMapPut.java:242)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutAndDeliverEvent(AbstractRegionMapPut.java:297)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.runWithIndexUpdatingInProgress(AbstractRegionMapPut.java:305)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutIfPreconditionsSatisified(AbstractRegionMapPut.java:293)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutOnSynchronizedRegionEntry(AbstractRegionMapPut.java:279)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutOnRegionEntryInMap(AbstractRegionMapPut.java:270)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.addRegionEntryToMapAndDoPut(AbstractRegionMapPut.java:248)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPutRetryingIfNeeded(AbstractRegionMapPut.java:213)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doWithIndexInUpdateMode(AbstractRegionMapPut.java:195)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.doPut(AbstractRegionMapPut.java:177)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.runWhileLockedForCacheModification(AbstractRegionMapPut.java:119)
at
org.apache.geode.internal.cache.map.RegionMapPut.runWhileLockedForCacheModification(RegionMapPut.java:150)
at
org.apache.geode.internal.cache.map.AbstractRegionMapPut.put(AbstractRegionMapPut.java:167)
at
org.apache.geode.internal.cache.AbstractRegionMap.basicPut(AbstractRegionMap.java:2100)
at
org.apache.geode.internal.cache.LocalRegion.virtualPut(LocalRegion.java:5664)
at
org.apache.geode.internal.cache.DistributedRegion.virtualPut(DistributedRegion.java:370)
at
org.apache.geode.internal.cache.LocalRegionDataView.putEntry(LocalRegionDataView.java:152)
at
org.apache.geode.internal.cache.LocalRegion.basicUpdate(LocalRegion.java:5644)
at
org.apache.geode.internal.cache.LocalRegion.basicBridgePut(LocalRegion.java:5281)
at
org.apache.geode.internal.cache.tier.sockets.command.Put65.cmdExecute(Put65.java:388)
at
org.apache.geode.internal.cache.tier.sockets.BaseCommand.execute(BaseCommand.java:178)
at
org.apache.geode.internal.cache.tier.sockets.ServerConnection.doNormalMessage(ServerConnection.java:844)
at
org.apache.geode.internal.cache.tier.sockets.OriginalServerConnection.doOneMessage(OriginalServerConnection.java:74)
at
org.apache.geode.internal.cache.tier.sockets.ServerConnection.run(ServerConnection.java:1214)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.geode.internal.cache.tier.sockets.AcceptorImpl.lambda$initializeServerConnectionThreadPool$3(AcceptorImpl.java:594)
at
org.apache.geode.internal.logging.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:121)
... 1 more
{noformat}
The 9th line from the bottom of the stack trace is:
{noformat}
at
org.apache.geode.internal.cache.tier.sockets.command.Put65.cmdExecute(Put65.java:388)
{noformat}
Looking at {{{Put65.java}}} (this is the code being executed on the Server for
the put from your client), we can see the catch block which catches the
ServerOperationException:
{noformat}
} catch (Exception ce) {
// If an interrupted exception is thrown , rethrow it
checkForInterrupt(serverConnection, ce);
// If an exception occurs during the put, preserve the connection
writeException(clientMessage, ce, false, serverConnection);
serverConnection.setAsTrue(RESPONDED);
if (ce instanceof GemFireSecurityException) {
// Fine logging for security exceptions since these are already
// logged by the security logger
if (isDebugEnabled) {
logger.debug("{}: Unexpected Security exception",
serverConnection.getName(), ce);
}
} else if (isDebugEnabled) {
logger.debug("{}: Unexpected Exception", serverConnection.getName(),
ce);
}
return;
} finally {
{noformat}
The condition `if (ce instanceof GemFireSecurityException)` is false, so it
enters the `else` block and logs the exception at debug level which is fine
level:
{noformat}
logger.debug("{}: Unexpected Exception", serverConnection.getName(), ce);
{noformat}
Earlier you said that this problem does not occur at info level or above. This
would seem to indicate that something ends up trying to log your put key/value
only at debug/fine level and that the act of logging the value causes it to be
deserialized which then throws ExceptionInInitializerError.
In Geode, it's very possible that when the log level is above debug/fine,
nothing tries to use your value other than storing it, so it is left in
serialized form. Geode intentionally leaves values in serialized form on the
Server unless it needs the value for some purpose such as a query or a function
or a log statement, etc.
This is intentional behavior. I agree that it's not ideal for you to not
discover the problem with your class until it does get deserialized, but Geode
servers will not deserialize your class unless they need to for some reason.
The server simply did not need to deserialize your class until you changed the
log level to debug/fine.
I recommend writing unit tests that perform Geode serialization/deserialization
of your class. You could use org.apache.geode.DataSerializer directly (in
tests) or even write a custom DataSerializer for your class which should give
you more control.
Apache Commons Lang3 contains org.apache.commons.lang3.SerializationUtils which
can also be useful if you need to write unit tests for Java
serialization/deserialization of your class.
> ServerOperationException While performing a remote put
> ------------------------------------------------------
>
> Key: GEODE-7254
> URL: https://issues.apache.org/jira/browse/GEODE-7254
> Project: Geode
> Issue Type: Bug
> Components: client/server, serialization
> Affects Versions: 1.8.0
> Reporter: rajesh
> Priority: Blocker
> Attachments: iHubCacheLocatorProcess.log, iHubCacheServerProcess.log,
> ihub.5296.RGOTETPF0T711Q.2019-09-30_20_44_40+0530.0.log,
> meta-iHubCacheLocatorProcess-01.log, meta-iHubCacheServerProcess-02.log
>
>
> Configuration: Locator and Server are running as different process using
> peer to peer configuration.
> while trying to insert a custom object in to a cache region using client
> cache we are getting the following exception.
> This occurs only when the Geode Locator/Server are started with log level set
> to fine, finer, finest and all.
> If the log level is set to severe, error, warning, info, config everything
> works fine.
> I am not sure if log level change has anything to do with put operation. I am
> attaching the locator and server log files.
>
> Also we have recently upgraded the geode version from 1.1.0 to 1.8. we have
> been using 1.1.0 for quite sometime without any major issues. upgraded to
> 1.8 and no code changes were made but still getting this issue.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
