Skip to content

.log() should always behave the same, no matter where it is placed in a flow #3615

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

Closed
swiss-chris opened this issue Aug 19, 2021 · 7 comments · Fixed by #3769
Closed

.log() should always behave the same, no matter where it is placed in a flow #3615

swiss-chris opened this issue Aug 19, 2021 · 7 comments · Fixed by #3769

Comments

@swiss-chris
Copy link
Contributor

swiss-chris commented Aug 19, 2021

Expected Behavior

Given some code like this:

        .scatterGather(
                scatterer -> scatterer
                        .applySequence(true)
                        .recipientFlow(IntegrationFlows.from(MessageChannels.executor(myExecutorService))
                                .gateway(mySubFlow1())
                                .get())
                        .recipientFlow(IntegrationFlows.from(MessageChannels.executor(myExecutorService))
                                .log(/* some logging here */)
                                .gateway(mySubFlow2())
                                .get()),
                gatherer -> gatherer
                        .releaseStrategy(defaultReleaseStrategy)
                        .outputProcessor(myOutputProcessor))

if I move the .log() statement down one line, like this:

        .scatterGather(
                scatterer -> scatterer
                        .applySequence(true)
                        .recipientFlow(IntegrationFlows.from(MessageChannels.executor(myExecutorService))
                                .gateway(mySubFlow1())
                                .get())
                        .recipientFlow(IntegrationFlows.from(MessageChannels.executor(myExecutorService))
                                .gateway(mySubFlow2())
                                .log(/* some logging here */)
                                .get()),
                gatherer -> gatherer
                        .releaseStrategy(defaultReleaseStrategy)
                        .outputProcessor(myOutputProcessor))

I would expect everything to work exactly the same, except that the .log() statement is executed after the .gateway() call.

Current Behavior

Changing the position of .log() changes the behavior of the flow. In this case, the releaseStrategy never receives the output of the second recipientFlow. The reason for this is explained in the JavaDoc, where we read - "When this operator is used in the end of flow, it is treated as one-way handler without any replies to continue.".

Context

This is not the behavior one would expect, it's not intuitive, and it has caused an unexpected bug in our team that took a long time to debug. (https://en.m.wikipedia.org/wiki/Principle_of_least_astonishment) We were quite surprised to learn about .logAndReply() and consider it one of those things that make the SI DSL hard to work with. Sometimes things just don't work and you have not reason why and no easy and no quick way to find the cause.

IMO the .log() statement should behave the same no matter where you place it in a flow. If it is placed at the end of a flow, and if this flow has no output channel, throw the usual exception, and the developer will quickly realize they need to add .nullChannel() or something similar. Perhaps you could even detect if .log() needs to reply or not (it seems you can detect if it is at the end of a flow, so maybe at that moment you can also detect if an output channel is configured for this flow) ?

logAndReply() could be deprecated and ultimately removed.

Am I missing something that would prevent such a solution ?

@swiss-chris swiss-chris added status: waiting-for-triage The issue need to be evaluated and its future decided type: enhancement labels Aug 19, 2021
@swiss-chris swiss-chris changed the title .log() should always behave the same, not matter where it is placed in a flow .log() should always behave the same, no matter where it is placed in a flow Aug 19, 2021
@artembilan
Copy link
Member

Thank you for your report and such a great problem explanation, @swiss-chris !

We definitely keep our users in mind when we develop an API like this Java DSL, but indeed I missed that principle from the start.
As you noticed an unexpected behavior you spotted only after reading JavaDocs and hours of debugging.
So, that JavaDoc'ing still don't help.

Saying that I would like to share with you our journey how we came up with logAndReply() and why log() in the end is different.
See a related PR and its hard discussion including mentioned in the header JIRA ticket: #2535.

So, you are not the first who bumped his/her head against this log() wall in the end of flow, therefore I agree that we need to revise it.

Here is my suggestion (which is not different from yours):

  1. If log() in the end of flow, add implicit bridge() to align replying behavior for log() how it is used in the middle of the flow.
  2. It is probably going to be the most use-cases when people place log() in the end of flow, so they really expect replying back to the caller as it would work even without log().
  3. If you want to stop the flow at this point, the nullChannel() is indeed the way to go. Exactly same behavior if you would remove that log() from your flow definition.
  4. Deprecate (and remove eventually) logAndReply() since its behavior will be included into a log().
  5. If end-user will encounter "no output-channel or replyChannel header available" at this point, they would get it even without log() anyway.

In general we are pursuing the same behavior as it would be even without log(), so logically not a breaking change from the high perspective, but still behavior change for current log() in the end of flow. So, we can do this only in the next 6.0 version starting this fall.

Any further comments are welcome!

(Sorry for late reply: was on vacation)

@artembilan artembilan added this to the 6.0.x milestone Aug 30, 2021
@artembilan artembilan added in: core and removed status: waiting-for-triage The issue need to be evaluated and its future decided labels Aug 30, 2021
@swiss-chris
Copy link
Contributor Author

Hi Artem
Thank you for this ! I'm happy to hear my proposal makes sense and look forward to the update ! We've been using the SI DSL a lot lately in our projects and will love every improvement.

@artembilan
Copy link
Member

@garyrussell ,

I also need your opinion on this and if we are in an agreement, WDYT about deprecating logAndReply() just right now, so we can remove it easily in 6.0 ?

Thanks

@garyrussell
Copy link
Contributor

Yes; it sounds reasonable, but not clear how you can deprecate, unless you say deprecated in favor of .log().bridge() in this release and the .bridge() becomes unnecessary in 6.0 (and you'd end up with - logically - .log().bridge().bridge() until it's removed.

@artembilan
Copy link
Member

If it is an explicit .log().bridge(), then we are not going to add our internal .bridge(). Just need to be smart enough 😄
Although I see your point: let's don't make people to move away from logAndReply() right now since they will forget to fix it in the future!
When we realign log() behavior, we will deprecate logAndReply(), so end-user would need to do only one refactoring in their code.

Taking back my deprecation suggestion for the current version even if we will live with it in 6.x for some time.
Sorry for a noise

@swiss-chris
Copy link
Contributor Author

@artembilan Is this still scheduled for inclusion in 6.0 ?

@artembilan
Copy link
Member

Same here: it is in plan for the current 6.0.
Again, contribution is welcome: The contribution is welcome though: https://github.com/spring-projects/spring-integration/blob/main/CONTRIBUTING.adoc !

artembilan added a commit to artembilan/spring-integration that referenced this issue Apr 7, 2022
Fixes spring-projects#3615

The `log()` operator for Java DSL in the end of flow causes a confusion
for its different behavior and, therefore, inconsistency with expectations

* Populate a `bridge()` in the end of flow instead of `nullChannel` when
the current component is `WireTapSpec` (relevant to `wireTap()` and `log()`)
* Deprecate a `logAndReply()` operator since its behavior is now included into the `log()` in the end if flow
* Fix tests to use just `log()` in the end from now on
* Fix `dsl.adoc` for the new `log()` behaviour in the end of flow
@artembilan artembilan modified the milestones: 6.0.x, 6.0 M3 Apr 7, 2022
garyrussell pushed a commit that referenced this issue Apr 7, 2022
Fixes #3615

The `log()` operator for Java DSL in the end of flow causes a confusion
for its different behavior and, therefore, inconsistency with expectations

* Populate a `bridge()` in the end of flow instead of `nullChannel` when
the current component is `WireTapSpec` (relevant to `wireTap()` and `log()`)
* Deprecate a `logAndReply()` operator since its behavior is now included into the `log()` in the end if flow
* Fix tests to use just `log()` in the end from now on
* Fix `dsl.adoc` for the new `log()` behaviour in the end of flow
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants