We tried adding some logging in one of our microservices, to learn more where in the microservice are we getting a performance issue.
- The first graph (left most) was the time difference between
LOG Marker #1
and LOG Marker #2
(i.e. Microservice #1 - Command creation to command handler)
- The 2nd graph was the time difference between
LOG Marker #2
and LOG Marker #3
(i.e. Microservice #1 - Command handler to ctx.thenPersist(…))
- The 3nd graph was the time difference between
LOG Marker #3
and LOG Marker #4
(i.e. Microservice #1 - ctx.thenPersist(…) to event publication)
- The 4th graph was the time difference between
LOG Marker #4
and LOG Marker #5
(i.e Microservice #2 event publication to Microservice #2 event subscription)
From the graphs above, the 3rd and 4th graph are the slowest. Any thoughts as to why that is and as to how to improve them?
Thanks!
Appendix. Code Snippets
public class Microservice1ExternalWebsocketListener {
// connects to an external service via websocket and creates a command per message
private void sendCommand(ExternalWebsocketMessage websocketMessage) {
PersistentEntityRef<MyCommand> entityRef = persistentEntityRegistry.refFor(MyEntity.class,
websocketMessage.getIdentifier());
MyUuid uuid = MyUuid.genThenLog(uuidLogger, SERVICE_NAME); // LOG Marker #1
MyCommand.Update updateCmd = new MyCommand.Update(uuid, websocketMessage);
entityRef.ask(updateCmd);
}
}
public class MyEntity {
...
behaviorBuilder.setCommandHandler(MyCommand.Update.class, (cmd, ctx) -> {
logger.debug("Got a new command {}", cmd);
cmd.getUuid().log(uuidLogger, "COMMANDRECEIVED"); // LOG Marker #2
return ctx.thenPersist(
new MyEventImpl.Updated(cmd.getUuid(), cmd.getPayload()),
evt -> {
MyUuid uuid = new MyUuid("COMMANDRECEIVED", cmd.getUuid().getUuid());
uuid.log(uuidLogger, "EVENTPERSISTED"); // LOG Marker #3
ctx.reply(Done.getInstance());
MyEventImpl.Updated updatedEvt = (MyEventImpl.Updated) evt;
pubSubEntityUpdated.publish(EntityToUIWebsocketMessage.translate(updatedEvt.getUuid(), updatedEvt.getPayload()));
}
);
}
);
...
}
public class Microservice1MyServiceImpl {
@Override
public Topic<MyEvent> myEventTopic() {
return TopicProducer.taggedStreamWithOffset(MyEventImpl.SHARDING_TAG.allTags(), (tag, offset) ->
persistentEntityRegistry.eventStream(tag, offset)
.map(this::convertEventImpl2Api));
}
private Pair<MyEvent, Offset> convertEventImpl2Api(Pair<MyEventImpl, Offset> eventOffsetPair) {
MyEvent eventToPublish;
if (eventOffsetPair.first() instanceof MyEventImpl.Updated) {
MyEventImpl.Updated updated =
(MyEventImpl.Updated) eventOffsetPair.first();
eventToPublish = new MyEvent.Updated(
updated.getUuid(),
updated.getPayload()
);
} else {
throw new IllegalArgumentException("Unknown event: " + eventOffsetPair.first());
}
MyUuid uuid = new MyUuid("EVENTPERSISTED", eventToPublish.getUuid().getUuid());
uuid.log(uuidLogger, "EVENTCONVERTED"); // LOG Marker #4
return Pair.create(eventToPublish, eventOffsetPair.second());
}
}
public class Microservice2Subscriber {
...
private void subscribeToMicroservice1MyService() {
microservice1MyService.myEventTopic()
.subscribe().atLeastOnce(myFlow());
}
private Flow<MyEvent, Done, NotUsed> myFlow() {
return Flow.<MyEvent>create().mapAsync(1, myEvent -> {
MyUuid uuid = new MyUuid("EVENTCONVERTED", myEvent.getUuid().getUuid());
uuid.log(uuidLogger, SERVICE_NAME); // LOG Marker #5
...
});
}
...
}