[GitHub] [geode] boglesby commented on pull request #4928: GEODE-7971: Gw sender deliver TX events atomically to Gw receivers
boglesby commented on pull request #4928: URL: https://github.com/apache/geode/pull/4928#issuecomment-620813007 When I start site 2, I see 3 batches received: ``` ServerConnection on port 5185 Thread 1: GatewayReceiverCommand.cmdExecute received batch 0 containing 5 events ServerConnection on port 5185 Thread 1: GatewayReceiverCommand.cmdExecute received batch 1 containing 5 events ServerConnection on port 5185 Thread 1: GatewayReceiverCommand.cmdExecute received batch 2 containing 1 events ``` This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: us...@infra.apache.org
[GitHub] [geode] boglesby commented on pull request #4928: GEODE-7971: Gw sender deliver TX events atomically to Gw receivers
boglesby commented on pull request #4928: URL: https://github.com/apache/geode/pull/4928#issuecomment-620812923 The next peeked batch doesn't contain 11 events. It only contains 5. This is because the previous batch failed to be sent which causes addPeekedEvents to actually do something. In this case, it adds batchSize number of events to the batch since these events have already been peeked. When this method returns, the batch contains batchSize events so the loop is short-circuited, and the incompleteTransactionsInBatch processing doesn't occur. Here is the behavior: addPeekedEvents adds 5 previously peeked events to the batch: ``` Event Processor for GatewaySender_ny_3: ParallelGatewaySenderQueue.addPeekedEvents added 5 previously peeked events to the batch: GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=0;bucketId=48];action=0;operation=CREATE;region=/customer;key=0;value=Customer[id=0; name=name-0];creationTime=1588101080903;shadowKey=161;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=1;bucketId=48];action=0;operation=CREATE;region=/order;key=0-0;value=Order[id=0-0; customerId=0];creationTime=1588101080906;shadowKey=274;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=2;bucketId=48];action=0;operation=CREATE;region=/order;key=0-1;value=Order[id=0-1; customerId=0];creationTime=1588101080906;shadowKey=387;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=3;bucketId=48];action=0;operation=CREATE;region=/order;key=0-2;value=Order[id=0-2; customerId=0];creationTime=1588101080906;shadowKey=500;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=4;bucketId=48];action=0;operation=CREATE;region=/order;key=0-3;value=Order[id=0-3; customerId=0];creationTime=1588101080906;shadowKey=613;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] ``` peekEventsFromIncompleteTransactions short-circuits because returns because areAllTransactionsCompleteInBatch is true: ``` Event Processor for GatewaySender_ny_3: ParallelGatewaySenderQueue.peekEventsFromIncompleteTransactions areAllTransactionsCompleteInBatch=true ``` The final batch contains 5 events: ``` Event Processor for GatewaySender_ny_3: ParallelGatewaySenderQueue.peek final batch 1156975981 contains 5 events: GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=0;bucketId=48];action=0;operation=CREATE;region=/customer;key=0;value=Customer[id=0; name=name-0];creationTime=1588101080903;shadowKey=161;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=1;bucketId=48];action=0;operation=CREATE;region=/order;key=0-0;value=Order[id=0-0; customerId=0];creationTime=1588101080906;shadowKey=274;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=2;bucketId=48];action=0;operation=CREATE;region=/order;key=0-1;value=Order[id=0-1; customerId=0];creationTime=1588101080906;shadowKey=387;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=3;bucketId=48];action=0;operation=CREATE;region=/order;key=0-2;value=Order[id=0-2; customerId=0];creationTime=1588101080906;shadowKey=500;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=4;bucketId=48];action=0;operation=CREATE;region=/order;key=0-3;value=Order[id=0-3; customerId=0];creationTime=1588101080906;shadowKey=613;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] ``` This is
[GitHub] [geode] boglesby commented on pull request #4928: GEODE-7971: Gw sender deliver TX events atomically to Gw receivers
boglesby commented on pull request #4928: URL: https://github.com/apache/geode/pull/4928#issuecomment-620812755 Here are the details. The first batch has the 11 events. 5 events are peeked initially: ``` Event Processor for GatewaySender_ny_3: ParallelGatewaySenderQueue.peek peeked a batch of 5 events into batch: GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=0;bucketId=48];action=0;operation=CREATE;region=/customer;key=0;value=Customer[id=0; name=name-0];shadowKey=161;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=1;bucketId=48];action=0;operation=CREATE;region=/order;key=0-0;value=Order[id=0-0; customerId=0];shadowKey=274;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=2;bucketId=48];action=0;operation=CREATE;region=/order;key=0-1;value=Order[id=0-1; customerId=0];shadowKey=387;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=3;bucketId=48];action=0;operation=CREATE;region=/order;key=0-2;value=Order[id=0-2; customerId=0];shadowKey=500;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=4;bucketId=48];action=0;operation=CREATE;region=/order;key=0-3;value=Order[id=0-3; customerId=0];shadowKey=613;timeStamp=1588101080897;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] ``` The remaining 6 from the transaction are peeked in peekEventsFromIncompleteTransactions: ``` Event Processor for GatewaySender_ny_3: ParallelGatewaySenderQueue.peekEventsFromIncompleteTransactions areAllTransactionsCompleteInBatch=false Event Processor for GatewaySender_ny_3: ParallelGatewaySenderQueue.peekEventsFromIncompleteTransactions getting missing transactions for transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1; bucketId=48 Event Processor for GatewaySender_ny_3: BucketRegionQueue.getElementsMatching key=726; object=GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=5;bucketId=48];action=0;operation=CREATE;region=/order;key=0-4;value=Order[id=0-4; customerId=0];shadowKey=726;timeStamp=1588101080898;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] Event Processor for GatewaySender_ny_3: BucketRegionQueue.getElementsMatching key=839; object=GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=6;bucketId=48];action=0;operation=CREATE;region=/order;key=0-5;value=Order[id=0-5; customerId=0];shadowKey=839;timeStamp=1588101080898;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] Event Processor for GatewaySender_ny_3: BucketRegionQueue.getElementsMatching key=952; object=GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=7;bucketId=48];action=0;operation=CREATE;region=/order;key=0-6;value=Order[id=0-6; customerId=0];shadowKey=952;timeStamp=1588101080898;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] Event Processor for GatewaySender_ny_3: BucketRegionQueue.getElementsMatching key=1065; object=GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=8;bucketId=48];action=0;operation=CREATE;region=/order;key=0-7;value=Order[id=0-7; customerId=0];shadowKey=1065;timeStamp=1588101080898;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] Event Processor for GatewaySender_ny_3: BucketRegionQueue.getElementsMatching key=1178; object=GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=9;bucketId=48];action=0;operation=CREATE;region=/order;key=0-8;value=Order[id=0-8; customerId=0];shadowKey=1178;timeStamp=1588101080898;transactionId=TXId: 192.168.1.8(ln-client:93385:loner):55648:ae6333c2:ln-client:1;isLastEventInTransaction=false] Event Processor for GatewaySender_ny_3: BucketRegionQueue.getElementsMatching key=1291; object=GatewaySenderEventImpl[id=EventID[id=23 bytes;threadID=0x10030|4;sequenceID=10;bucketId=48];action=0;operation=CREATE;region=/order;key=0-9;value=Order[id=0-9; customerId=0];shadowKey=1291;timeStamp=1588101080898;transactionId=TXId:
[GitHub] [geode] boglesby commented on pull request #4928: GEODE-7971: Gw sender deliver TX events atomically to Gw receivers
boglesby commented on pull request #4928: URL: https://github.com/apache/geode/pull/4928#issuecomment-620812494 If I do this: - start site 1 with a sender with batch size = 5 - do a transaction with 1 customer and 10 orders - don't start site 2 immediately I see behavior like below: The first call to peek is correct. It returns 11 events. Since the batch can't be sent, the batch is recreated. This batch only contains 5 events. This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: us...@infra.apache.org
[GitHub] [geode] boglesby commented on pull request #4928: GEODE-7971: Gw sender deliver TX events atomically to Gw receivers
boglesby commented on pull request #4928: URL: https://github.com/apache/geode/pull/4928#issuecomment-620307053 I ran a test with this scenario: - 2 colocated partitioned regions called customer and order attached to a parallel sender - 1 replicated region called customer_creation_time attached to a serial sender The transaction does: - put 1 customer into customer region - put 10 orders into order region - put customer create time into customer_creation_time region Here are some notes from this test: GatewaySenderFactoryImpl.configureGatewaySender needs a line like below. Otherwise, the Geode xml case doesn't pass the boolean to the sender. ``` this.attrs.isGroupTransactionEvents = senderCreation.isGroupTransactionEvents() ``` The scenario above is not supported since the transaction is spanning multiple senders. I don't think there is a way to determine that during configuration, but the message that is logged needs additional info: ``` [error 2020/04/27 15:45:57.439 PDT tid=0x57] Not all events in transaction go to the same senders that group transactions ``` At least the sender ids should be logged if not which events go to which senders. I see `TXLastEventInTransactionUtils.checkAllEventsGoToSameGroupingSenders` is throwing the ServiceConfigurationError. Maybe that ServiceConfigurationError's message can contain this info. Then you can log the error. Maybe even the actual stack. Also, I see that the test above succeeds. The batch is sent with the customer and orders. Other than that warning which the customer could easily miss, there is no evidence that all the events in the transaction were not sent in the same batch. Maybe the commit should fail? I'll change my test to remove the serial sender and continue to look at this. This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: us...@infra.apache.org
