Corda RP C связь. Медленная производительность - PullRequest
Новая
       36

Corda RP C связь. Медленная производительность

3 голосов
/ 08 января 2020

Есть сценарий, когда клиент запускает Cordapp через RP C и ждет результата. 

rpcConnection.proxy
.startFlow(::ImportAssetFlow, importDto)
.returnValue
.get(importTimeout /* 30000 ms */, TimeUnit.MILLISECONDS)

Поток срабатывает правильно и возвращает ответ, но проблема с медленным ответом после обработки потока. В конце кодового блока FlowLogi c .call () ответ должен быть возвращен клиенту через сообщение Артемиды. Результат возвращается клиенту через Corda в будущем через 12 секунд.

На стороне клиента в журнале отладки lvl RPCClientProxyHandler, чтобы проверить, как работает процесс: 

2020-01-08 12:12:45.982 DEBUG [,,,] 78798 --- [global-threads)] n.c.c.r.internal.RPCClientProxyHandler   : Got message from RPC server RpcReply(id=fc317c4a-3de4-4936-b4c3-768b8b727245, timestamp: 2020-01-08T10:12:44.237Z, entityType: Invocation, result=Success(FlowHandleImpl(id=[16566124-f7d2-41cf-b3a4-f86846073632], returnValue=net.corda.core.internal.concurrent.CordaFutureImpl@58f8aa01)), deduplicationIdentity=e3f6d696-dea4-45b0-95b8-f9c0fe363a9f)
2020-01-08 12:12:45.986 DEBUG [,,,] 78798 --- [global-threads)] n.c.c.r.internal.RPCClientProxyHandler   : Got message from RPC server Observation(id=b3f0b064-6d82-4900-85e6-e70b7d00926a, timestamp: 2020-01-08T10:11:26.411Z, entityType: Invocation, content=[rx.Notification@b461fac0 OnNext Added(stateMachineInfo=StateMachineInfo([16566124-f7d2-41cf-b3a4-f86846073632], ***.workflow.asset.flow.ImportAssetFlow))], deduplicationIdentity=e3f6d696-dea4-45b0-95b8-f9c0fe363a9f)
2020-01-08 12:12:45.987 DEBUG [,,,] 78798 --- [global-threads)] n.c.c.r.internal.RPCClientProxyHandler   : Got message from RPC server Observation(id=12887a04-f22c-422d-b684-c679f137d66b, timestamp: 2020-01-08T10:12:45.979Z, entityType: Invocation, content=[rx.Notification@4c59250 OnNext Starting], deduplicationIdentity=e3f6d696-dea4-45b0-95b8-f9c0fe363a9f)
2020-01-08 12:12:58.603 DEBUG [,,,] 78798 --- [global-threads)] n.c.c.r.internal.RPCClientProxyHandler   : Got message from RPC server Observation(id=b83c15ca-9047-4958-a106-65165e5abfbd, timestamp: 2020-01-08T10:12:45.975Z, entityType: Invocation, content=[rx.Notification@e03cfa2d OnNext [B@2dceac3d], deduplicationIdentity=e3f6d696-dea4-45b0-95b8-f9c0fe363a9f)
2020-01-08 12:12:58.605 DEBUG [,,,] 78798 --- [global-threads)] n.c.c.r.internal.RPCClientProxyHandler   : Got message from RPC server Observation(id=b83c15ca-9047-4958-a106-65165e5abfbd, timestamp: 2020-01-08T10:12:45.975Z, entityType: Invocation, content=[rx.Notification@15895539 OnCompleted], deduplicationIdentity=e3f6d696-dea4-45b0-95b8-f9c0fe363a9f)

Существует большой разрыв между событиями

  • 12:12:45.987 OnNext Starting - начало потока, который потребляет 1к объектов
  • 12:12:58.603 OnNext [B@2dceac3d] - фактический результат операции. Так что ~ 12,5 с, чтобы вернуть ответ.

Согласно Jprofiler Corda обработал поток в ~ 1,3 с и отправил результат обратно. Corda thread calls

Что может быть причиной такого поведения, медленного журналирования сообщений Артемиды?

UPD: обнаружено, что Corda имеет механизм приостановки / возобновления (контрольные точки) , чтобы сохранить состояние потока на диске и в будущем прочитать его снова и возобновить эту тему. net .corda.node.services.statemachine.FlowStateMachineImpl # run, запускающий co.paralleluniverse.fibers.Fiber # parkAndSerialize. Кажется, это один из потребителей времени.

Заранее большое спасибо

Ответы [ 2 ]

0 голосов
/ 23 января 2020

Найдена root причина задержки, похоже, что все транзакции entityManager сбрасываются в конце потока, но не после окончания блока с помощью EntityManager, как я ожидал 

fun save(assetBatch: PCAssetBatch): PCAssetBatch {
    return serviceHub.withEntityManager {
        persist(assetBatch)
        logger.debug("Batch [${assetBatch.batchId} - ${assetBatch.batchName}] has been persisted")
        assetBatch
    }
}

It Потребовалось время, чтобы понять это, потому что я считал, что данные сохраняются. Это связано с тем, что объект с аннотацией OneToMany PCAssetBatch содержит столбец Список PCAssetBatchItem, похоже, что hibernate сохраняет их один за другим, не используя пакетную обработку. Задержка была устранена путем исправления этой части кода.

0 голосов
/ 21 января 2020

Причин может быть несколько:

  1. Возможно, JProfiler неправильно сообщает о продолжительности потока. Другие инструменты профилирования, безусловно, испытывают трудности с парковкой, которую делают Fibers, поскольку каждое резюме из приостановки выглядит как отдельный вызов метода. Я бы добавил некоторые записи в ваш поток, чтобы проверить, сколько времени это действительно займет.
  2. Если вы возвращаете действительно большой результат из вашего потока (например, большую коллекцию крупных объектов), сериализация и десериализация этого через RP C может занять разумное количество времени. Так вы возвращаете большой результат?
...