New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

deserialize lambda that was already serialized in the log fails #58

Closed
binyuanchen opened this Issue Oct 14, 2015 · 2 comments

Comments

Projects
None yet
2 participants
@binyuanchen
Contributor

binyuanchen commented Oct 14, 2015

  • CorfuDB cluster setup
    1 configmaster + 1 sequencer + 1 logunit, launched using bin/corfuStreamingSingle.sh

  • Test case code used to report issue:
    A unit test case as below (line number is included to cross-reference with the exception stack.

    24 public class L2DeferredTxTest implements Serializable {
    25 /**
    26 * It is weird to make a test case class to implement Serializable, but
    27 * without this defined lambda won't work
    28 /
    29 private static final long serialVersionUID = 1L;
    30
    31 private static final Logger logger = LoggerFactory
    32 .getLogger(L2DeferredTxTest.class);
    33
    34 /*
    35 * make CorfuDBRuntime be transient otherwise there will be an attempt to
    36 * serialize it because the current test case class defines the lambda in it
    37 /
    38 private transient CorfuDBRuntime cdr;
    39
    40 /*
    41 * This must not be transient as the proposed transactions refers to it
    42 /
    43 private CDBSimpleMap table;
    44
    45 private void putTableTransactionally() throws Exception {
    46 ITransactionCommand writeCommand = (ITransactionCommand) (opts) -> {
    47 UUID newKey = UUID.randomUUID();
    48 String newValue = "dummy";
    49 table.put(newKey, newValue);
    50 String msg = "PUT into table : key = " + newKey + ", value = "
    51 + newValue;
    52 System.out.println(msg);
    53 return msg;
    54 };
    55 ITimestamp t = new DeferredTransaction<>(cdr.getLocalInstance(),
    56 writeCommand).propose();
    57 logger.info("PUT transaction is proposed at {}", t);
    58 }
    59
    60 private int countTableTransactionally() throws Exception {
    61 ITransactionCommand countCommand = (ITransactionCommand) (opts) -> {
    62 int count = table.size();
    63 String msg = "SHOWCOUNT = " + count;
    64 System.out.println(msg);
    65 return count;
    66 };
    67 ITimestamp t = null;
    68 t = new DeferredTransaction<>(cdr.getLocalInstance(), countCommand)
    69 .propose();
    70 logger.info("SHOWCOUNT transaction is proposed at {}", t);
    71 table.sync(t);
    72 return table.size();
    73 }
    74
    75 @test
    76 public void testDeferredTx() throws Exception {
    77 /*
    78 * create table as a CDBSimpleMap instance
    79 /
    80 UUID mapuuid = UUID.fromString("1442df14-7220-11e5-9d70-feff819cdc9f");
    81 Map options = new HashMap();
    82 options.put("--master", "http://localhost:8002/corfu");
    83 options.put("--stream-impl", "NewStream");
    84 CorfuDBFactory cdf = new CorfuDBFactory(options);
    85 cdr = cdf.getRuntime();
    86 IStream stream = cdr.getLocalInstance().openStream(mapuuid);
    87 table = (CDBSimpleMap) cdr.getLocalInstance().openObject(
    88 mapuuid, CDBSimpleMap.class);
    89 logger.info("Done initializing map instance.");
    90
    91 /*
    92 * tests:
    93 *
    94 * 1. issue a transaction to put a new key-value pair to table
    95 *
    96 * 2. issue a transaction to show the size of the table, sync the table
    97 * immediately to commit the write/read tx
    98 */
    99 putTableTransactionally();
    100 int count = countTableTransactionally();
    101 logger.info("after counting, count = {}", count);
    102
    103 cdr.close();
    104 logger.info("Test finished.");
    105 }
    106 }

  • Steps to reproduce this issue:
    Reset (or restart) the CorfuDB cluster, run the test case twice to see the issue happen on the 2nd run of the test case.

Test behaves normally in the 1st run of the test, see logs:

[main] INFO com.vmware.nsx.demo.test.l2.L2DeferredTxTest - PUT transaction is proposed at 0

[main] INFO com.vmware.nsx.demo.test.l2.L2DeferredTxTest - SHOWCOUNT transaction is proposed at 1

[main] INFO org.corfudb.runtime.view.LocalCorfuDBInstance - got cached stream

[ForkJoinPool.commonPool-worker-2] INFO org.corfudb.runtime.smr.DeferredTransaction - Executing transaction.

PUT into table : key = 2f7865a6-fd5c-4eab-9a40-9663963d7571, value = dummy

[ForkJoinPool.commonPool-worker-2] INFO org.corfudb.runtime.smr.DeferredTransaction - Executing transaction.

SHOWCOUNT = 1

[main] INFO com.vmware.nsx.demo.test.l2.L2DeferredTxTest - after counting, count = 1

[main] INFO com.vmware.nsx.demo.test.l2.L2DeferredTxTest - Test finished.

On the 2nd run of the test, these errors are seen below:

[main] INFO com.vmware.nsx.demo.test.l2.L2DeferredTxTest - PUT transaction is proposed at 2

[main] INFO com.vmware.nsx.demo.test.l2.L2DeferredTxTest - SHOWCOUNT transaction is proposed at 3

[main] INFO org.corfudb.runtime.view.LocalCorfuDBInstance - got cached stream

[org.corfudb.runtime.protocols.AbstractNettyProtocol$2-event-1] ERROR org.corfudb.runtime.protocols.NettyRPCChannelInboundHandlerAdapter - Exception during channel handling.

java.lang.ClassCastException: cannot assign instance of java.lang.invoke.SerializedLambda to field org.corfudb.runtime.smr.DeferredTransaction.transaction of type org.corfudb.runtime.smr.ITransactionCommand in instance of org.corfudb.runtime.smr.DeferredTransaction

at java.io.ObjectStreamClass$FieldReflector.setObjFieldValues(ObjectStreamClass.java:2089)

at java.io.ObjectStreamClass.setObjFieldValues(ObjectStreamClass.java:1261)

at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2006)

at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1924)

at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1801)

at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)

at java.io.ObjectInputStream.readObject(ObjectInputStream.java:371)

at org.corfudb.util.serializer.JavaSerializer.deserialize(JavaSerializer.java:29)

at org.corfudb.runtime.smr.smrprotocol.TransactionalLambdaSMRCommand.fromBuffer(TransactionalLambdaSMRCommand.java:78)

at org.corfudb.runtime.smr.smrprotocol.SMRCommand.deserialize(SMRCommand.java:86)

at org.corfudb.util.serializer.CorfuSerializer.deserialize(CorfuSerializer.java:80)

at org.corfudb.infrastructure.wireprotocol.NettyLogUnitPayloadMsg.getPayload(NettyLogUnitPayloadMsg.java:36)

at org.corfudb.runtime.protocols.logunits.INewWriteOnceLogUnit$ReadResult.(INewWriteOnceLogUnit.java:80)

at org.corfudb.runtime.protocols.logunits.NettyLogUnitProtocol$NettyLogUnitHandler.handleMessage(NettyLogUnitProtocol.java:158)

at org.corfudb.runtime.protocols.NettyRPCChannelInboundHandlerAdapter.channelRead(NettyRPCChannelInboundHandlerAdapter.java:138)

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)

at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)

at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:244)

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)

at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:32)

at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:299)

at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:36)

at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)

at java.lang.Thread.run(Thread.java:745)

[org.corfudb.runtime.protocols.AbstractNettyProtocol$2-event-1] ERROR org.corfudb.runtime.protocols.NettyRPCChannelInboundHandlerAdapter - Exception during channel handling.

java.lang.ClassCastException: cannot assign instance of java.lang.invoke.SerializedLambda to field org.corfudb.runtime.smr.DeferredTransaction.transaction of type org.corfudb.runtime.smr.ITransactionCommand in instance of org.corfudb.runtime.smr.DeferredTransaction

at java.io.ObjectStreamClass$FieldReflector.setObjFieldValues(ObjectStreamClass.java:2089)

at java.io.ObjectStreamClass.setObjFieldValues(ObjectStreamClass.java:1261)

at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2006)

at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1924)

at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1801)

at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1351)

at java.io.ObjectInputStream.readObject(ObjectInputStream.java:371)

at org.corfudb.util.serializer.JavaSerializer.deserialize(JavaSerializer.java:29)

at org.corfudb.runtime.smr.smrprotocol.TransactionalLambdaSMRCommand.fromBuffer(TransactionalLambdaSMRCommand.java:78)

at org.corfudb.runtime.smr.smrprotocol.SMRCommand.deserialize(SMRCommand.java:86)

at org.corfudb.util.serializer.CorfuSerializer.deserialize(CorfuSerializer.java:80)

at org.corfudb.infrastructure.wireprotocol.NettyLogUnitPayloadMsg.getPayload(NettyLogUnitPayloadMsg.java:36)

at org.corfudb.runtime.protocols.logunits.INewWriteOnceLogUnit$ReadResult.(INewWriteOnceLogUnit.java:80)

at org.corfudb.runtime.protocols.logunits.NettyLogUnitProtocol$NettyLogUnitHandler.handleMessage(NettyLogUnitProtocol.java:158)

at org.corfudb.runtime.protocols.NettyRPCChannelInboundHandlerAdapter.channelRead(NettyRPCChannelInboundHandlerAdapter.java:138)

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)

at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:294)

at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:244)

at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:308)

at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:32)

at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:299)

at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:36)

at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)

at java.lang.Thread.run(Thread.java:745)

@no2chem

This comment has been minimized.

Show comment
Hide comment
@no2chem

no2chem Oct 14, 2015

Member

Ah, ok. I see what the issue is.

You shouldn't be executing IO (or anything that causes a side effect) during the transaction, as it will definitely be the case that it will be executed at every client non-deterministically.

But the core of the problem is that it's serializing the parent object because its being captured by the lambda. Can you change the CDBSimpleMap field to final, either by changing the field to final, or referring to it just before the lambda?

For example,

final CDBSimpleMap fTable = table;

and in the lambda use fTable.

Member

no2chem commented Oct 14, 2015

Ah, ok. I see what the issue is.

You shouldn't be executing IO (or anything that causes a side effect) during the transaction, as it will definitely be the case that it will be executed at every client non-deterministically.

But the core of the problem is that it's serializing the parent object because its being captured by the lambda. Can you change the CDBSimpleMap field to final, either by changing the field to final, or referring to it just before the lambda?

For example,

final CDBSimpleMap fTable = table;

and in the lambda use fTable.

@binyuanchen

This comment has been minimized.

Show comment
Hide comment
@binyuanchen

binyuanchen Oct 14, 2015

Contributor

Hi Michael,

I rerun the test with the change you mentioned, for example, for
putTableTransactionally() method, I changed it to

private void putTableTransactionally() throws Exception {
  •    final CDBSimpleMap ftable = table;*
    ITransactionCommand writeCommand = (ITransactionCommand) (opts) -> {
        UUID newKey = UUID.randomUUID();
        String newValue = "dummy";
        _ftable_.put(newKey, newValue);
        String msg = "PUT into table : key = " + newKey + ", value = "
                + newValue;
        System.out.println(msg);
        return msg;
    };
    ITimestamp t = new DeferredTransaction<>(cdr.getLocalInstance(),
            writeCommand).propose();
    logger.info("PUT transaction is proposed at {}", t);
    
    }

I did similar change to the countTableTransactionally() as well.

However, I am seeing the same result and and same error happened on the 2nd
run of the test.

Binyuan

On Wed, Oct 14, 2015 at 11:09 AM, Michael Wei notifications@github.com
wrote:

Ah, ok. I see what the issue is.

You shouldn't be executing IO (or anything that causes a side effect)
during the transaction, as it will definitely be the case that it will be
executed at every client non-deterministically.

But the core of the problem is that it's serializing the parent object
because its being captured by the lambda. Can you change the CDBSimpleMap
field to final, either by changing the field to final, or referring to it
just before the lambda?

For example,

final CDBSimpleMap fTable = table;

and in the lambda use fTable.


Reply to this email directly or view it on GitHub
#58 (comment).

Contributor

binyuanchen commented Oct 14, 2015

Hi Michael,

I rerun the test with the change you mentioned, for example, for
putTableTransactionally() method, I changed it to

private void putTableTransactionally() throws Exception {
  •    final CDBSimpleMap ftable = table;*
    ITransactionCommand writeCommand = (ITransactionCommand) (opts) -> {
        UUID newKey = UUID.randomUUID();
        String newValue = "dummy";
        _ftable_.put(newKey, newValue);
        String msg = "PUT into table : key = " + newKey + ", value = "
                + newValue;
        System.out.println(msg);
        return msg;
    };
    ITimestamp t = new DeferredTransaction<>(cdr.getLocalInstance(),
            writeCommand).propose();
    logger.info("PUT transaction is proposed at {}", t);
    
    }

I did similar change to the countTableTransactionally() as well.

However, I am seeing the same result and and same error happened on the 2nd
run of the test.

Binyuan

On Wed, Oct 14, 2015 at 11:09 AM, Michael Wei notifications@github.com
wrote:

Ah, ok. I see what the issue is.

You shouldn't be executing IO (or anything that causes a side effect)
during the transaction, as it will definitely be the case that it will be
executed at every client non-deterministically.

But the core of the problem is that it's serializing the parent object
because its being captured by the lambda. Can you change the CDBSimpleMap
field to final, either by changing the field to final, or referring to it
just before the lambda?

For example,

final CDBSimpleMap fTable = table;

and in the lambda use fTable.


Reply to this email directly or view it on GitHub
#58 (comment).

@no2chem no2chem closed this Feb 9, 2016

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment