You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Kirk Lund (Jira)" <ji...@apache.org> on 2020/06/30 17:24:00 UTC

[jira] [Comment Edited] (GEODE-7254) ServerOperationException While performing a remote put

    [ 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:23 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 put key/value so your value 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 that 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. 

You could potentially defend against this problem in a unit test that performs 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.


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}


> 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)