Feature: Reactive Soy #26

sgammon · 2019-11-13T07:12:33Z

This changeset amends the Soy view renderer, to support a new interface called ReactiveViewRenderer. The new interface generates a Flowable instead of a Writable, so that reactive chunked responses can be generated when the renderer is waiting on Future values to resolve.

Refactor async views to use Flowable.generate
Rename AsyncViewsRenderer -> ReactiveViewRenderer
Render until told to DETACH or LIMIT(ED), then wait for future
Bug: Does not work for views that hit DETACH (see below)

This changeset introduces a new Micronaut package to render views via *[Soy](https://github.com/google/closure-templates)* (also known as *Closure Templates*). For now, the renderer simply uses `SoyTofu` to render views from Soy template sources. There are more efficient ways to render Soy templates in Java, and I'm planning to add those, too, subject to feedback from the Micronaut team. I've based this proposal on the structure of `views-freemarker`, to make sure I've adopted Micronaut's coding style as closely as I can. There is a corresponding set of unit tests as well, that pass, at least locally. _NOTE:_ This change requires a patched version of Soy Java, which applies a PR upstream to support querying a `SoyTofu` instance for templates (see: google/closure-templates#185). A patched JAR for Soy can be installed with the script `patch-soy.sh` added at the root of the repo. This is run in Travis, for instance, but can be eliminated when the upstream PR is merged and a release is cut. Changes made: - [x] Support for `SoyTofu` - i.e. rendering from template sources - [x] `SoyTofuRenderer` - where the rendering happens - [x] `SoyTofuViewsRendererConfiguration` - where a `SoyFileSet` is loaded and configured - [x] `SoyFileSetProvider` - uses DI to resolve a `SoyFileSet`, which is used to back the `SoyTofu.Renderer` - [x] Unit tests for `SoyTofuViewsRenderer` - [ ] Coming shortly: `SoySauce` - i.e. rendering via templates pre-compiled to Java sources

- Add bean for generating or using `SoySauce`-based renderer - Move `AppendableToWritable` to its own file, enhance it with support for `AdvisingAppendable` - Add `SoySauceRenderer` - Add ability for `SoyFileSetProvider` to provide pre-compiled templates via an existing `SoySauce` instance

Adopts upstream release after request at google/closure-templates#188

Force-SecureRandom defaults to `false`, to avoid infinitely blocking if there isn't enough entropy available. This can be mitigated with an overridden Java system property in Linux like so: -Djava.security.egd=file:/dev/./urandom

This changeset proposes a structure for an alternate `View` annotation, `AsyncView`. If `AsyncView` is used with a controller, it will try to load an `AsyncViewsRenderer` rather than a regular one, which is allowed to return a `Publisher` rather than producing an HTTP response synchronously from template context. Changes so far: - [x] Add `AsyncView` annotation - [x] Add `AsyncViewsRenderer` interface - [x] Refactor common items to `BaseViewsRenderer` - [x] Make `ViewsRenderer` comply with `BaseViewsRenderer`

This changeset builds upon PRs micronaut-projects#13 (*Soy Views Renderer*) and micronaut-projects#14 (*CSP Nonces*) to enable Soy with integrated CSP support when used with Micronaut. The CSP nonce may be provided via the Soy injected data, as documented [here](https://csp.withgoogle.com/docs/faq.html#passing-nonces). When the nonce value is provided, this way, inline scripts will automatically gain a `nonce="{nonceValue"}` attribute. All one must do in Micronaut to enable this is: ``` micronaut.views.soy.enabled = true micronaut.views.soy.engine = "sauce" micronaut.views.csp.enabled = true micronaut.views.csp.generateNonce = true micronaut.views.csp.policyDirectives = "default-src self:; script-src 'nonce-{#nonceValue}';" ``` And the framework will take care of the rest. Changes so far: - [x] Resolve CSP nonce when rendering templates via Soy - [x] Provide CSP nonce to Soy render context - [x] Add unit tests to make sure nonce lines up, is injected on both `<script>` tags and headers

This changeset amends the Soy view renderer, to support a new interface called `ReactiveViewRenderer`. The new interface generates a `Flowable` instead of a `Writable`, so that reactive chunked responses can be generated when the renderer is waiting on `Future` values to resolve. - [x] Refactor async views to use Flowable.generate - [x] Rename AsyncViewsRenderer -> ReactiveViewRenderer - [x] Render until told to DETACH or LIMIT(ED), then wait for future - [ ] Bug: Does not work for views that hit DETACH (see below)

sgammon · 2019-11-13T07:27:14Z

@graemerocher This works great, save for one rather large issue. When Soy gives the DETACH signal, indicating it is waiting on a Future value of some kind, the renderer correctly yields out and waits for another turn of Flowable.generate. It continues the render, finalizing with emitter.onNext() and emitter.onComplete(), which should terminate the flow.

But, it doesn't terminate it. It just hangs somehow, forever, never emitting a response to the unit test client I have setup in SoySauceReactiveRendererSpec.

I've debugged extensively and added plenty of debug/trace logging. The trace log appears to be the correct flow. I'll take another crack at debugging this but it would help immensely if you could take a look - perhaps what I'm doing wrong is simple.

Here is the trace log, which can be obtained by running SoySauceReactiveRendererSpec:

22:49:47.936 [nioEventLoopGroup-1-4] DEBUG i.m.context.condition.Condition - Bean [Definition: io.micronaut.management.endpoint.caches.CachesEndpoint] will not be loaded due to failing conditions:
22:49:47.936 [nioEventLoopGroup-1-4] DEBUG i.m.context.condition.Condition - * Custom condition [class io.micronaut.management.endpoint.EndpointEnabledCondition] failed evaluation
22:49:47.938 [nioEventLoopGroup-1-4] DEBUG i.m.context.condition.Condition - Bean [Definition: io.micronaut.management.endpoint.stop.ServerStopEndpoint] will not be loaded due to failing conditions:
22:49:47.938 [nioEventLoopGroup-1-4] DEBUG i.m.context.condition.Condition - * Custom condition [class io.micronaut.management.endpoint.EndpointEnabledCondition] failed evaluation
22:49:47.975 [pool-1-thread-1] INFO  io.micronaut.docs.SoyController - Rendering async Soy page.
22:49:47.978 [pool-1-thread-1] INFO  io.micronaut.docs.SoyController - Kicking off async task
22:49:48.011 [pool-1-thread-1] INFO  io.micronaut.docs.SoyController - Task is immediately: NOT DONE.
22:49:48.028 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - Preparing render for template path 'sample.home'
22:49:48.063 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - CSP nonce injection is active.
22:49:48.063 [pool-1-thread-1] TRACE i.m.views.soy.SoySauceViewsRenderer - Injecting nonce value 'ldHUV1x8Bah93o7B3SNrJA'.
22:49:48.064 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - Style renaming is disabled.
22:49:48.078 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Allocating chunk of sizing = i: 1024, m: 2048
22:49:48.080 [pool-1-thread-1] TRACE i.m.views.soy.SoySauceViewsRenderer - Initial render for view 'sample.home'
22:49:48.085 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 30 (c: 30, b: 0)
22:49:48.085 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.085 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 56 (c: 86, b: 0)
22:49:48.085 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.087 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 8 (c: 94, b: 0)
22:49:48.087 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.088 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 22 (c: 116, b: 0)
22:49:48.088 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.088 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 1 (c: 117, b: 0)
22:49:48.088 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.088 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 44 (c: 161, b: 0)
22:49:48.088 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.088 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 20 (c: 181, b: 0)
22:49:48.089 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.090 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 7 (c: 188, b: 0)
22:49:48.090 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 12 (c: 200, b: 0)
22:49:48.090 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:48.091 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - Render emitting chunk
22:49:48.093 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Allocating chunk of sizing = i: 1024, m: 2048
22:49:48.094 [pool-1-thread-1] DEBUG io.micronaut.views.soy.SoyRender - Exporting capped chunk: ReadOnlyByteBuf(ridx: 0, widx: 200, cap: 200/200, unwrapped: UnpooledSlicedByteBuf(ridx: 0, widx: 200, cap: 200/200, unwrapped: CompositeByteBuf(ridx: 200, widx: 200, cap: 200, components=1)))
22:49:48.110 [pool-1-thread-1] DEBUG io.micronaut.views.soy.SoyRender - SoyRender received DETACH signal.
22:49:48.110 [pool-1-thread-1] TRACE i.m.views.soy.SoySauceViewsRenderer - Continue render for view 'sample.home'
22:49:48.110 [pool-1-thread-1] DEBUG io.micronaut.views.soy.SoyRender - SoyRender received DETACH signal.
22:49:48.111 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Still waiting on future value
22:49:48.111 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Future value is not yet ready. Blocking for return.
22:49:53.006 [pool-3-thread-1] INFO  io.micronaut.docs.SoyController - Emitting async content
22:49:53.008 [pool-3-thread-1] INFO  io.micronaut.docs.SoyController - Told executor to kick rocks
22:49:53.009 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Future value block finished.
22:49:53.009 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Future value has arrived: SoyRender is READY.
22:49:53.009 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - Render is READY to proceed. Continuing.
22:49:53.009 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 10 (c: 10, b: 200)
22:49:53.009 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:53.009 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 7 (c: 17, b: 200)
22:49:53.010 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 14 (c: 31, b: 200)
22:49:53.010 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:53.010 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Appended char seq of size = 14 (c: 45, b: 200)
22:49:53.010 [pool-1-thread-1] TRACE io.micronaut.views.soy.SoyRender - Soft limit not yet reached
22:49:53.011 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - Render emitting chunk
22:49:53.011 [pool-1-thread-1] TRACE i.m.views.soy.SoyResponseBuffer - Allocating chunk of sizing = i: 1024, m: 2048
22:49:53.012 [pool-1-thread-1] DEBUG io.micronaut.views.soy.SoyRender - Exporting capped chunk: ReadOnlyByteBuf(ridx: 0, widx: 45, cap: 45/45, unwrapped: UnpooledSlicedByteBuf(ridx: 0, widx: 45, cap: 45/45, unwrapped: CompositeByteBuf(ridx: 245, widx: 245, cap: 245, components=2)))
22:49:53.012 [pool-1-thread-1] DEBUG io.micronaut.views.soy.SoyRender - SoyRender flow is DONE.
22:49:53.012 [pool-1-thread-1] DEBUG i.m.views.soy.SoySauceViewsRenderer - Finished Soy render routine. Calling `onComplete`.
22:49:53.012 [pool-1-thread-1] DEBUG io.micronaut.views.soy.SoyRender - Closing render buffer (state: CLOSED)
22:49:53.012 [pool-1-thread-1] DEBUG i.m.views.soy.SoyResponseBuffer - Closing render buffer (state: CLOSED)
22:49:53.013 [pool-1-thread-1] DEBUG i.m.views.soy.SoyResponseBuffer - Chunk references = 0
22:49:53.013 [pool-1-thread-1] DEBUG i.m.views.soy.SoyResponseBuffer - Buffer references = 0

Expected no exception to be thrown, but got 'io.micronaut.http.client.exceptions.ReadTimeoutException'
Expected no exception to be thrown, but got 'io.micronaut.http.client.exceptions.ReadTimeoutException'
	at spock.lang.Specification.noExceptionThrown(Specification.java:118)
	at io.micronaut.docs.SoySauceReactiveRendererSpec.invoking /soy/asyncContent should produce a chunked response(SoySauceReactiveRendererSpec.groovy:69)
Caused by: io.micronaut.http.client.exceptions.ReadTimeoutException: Read Timeout
	at io.micronaut.http.client.exceptions.ReadTimeoutException.<clinit>(ReadTimeoutException.java:26)
	at io.micronaut.http.client.DefaultHttpClient$10.exceptionCaught(DefaultHttpClient.java:1917)
	at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:285)
	at io.netty.channel.AbstractChannelHandlerContext.invokeExceptionCaught(AbstractChannelHandlerContext.java:264)
	at io.netty.channel.AbstractChannelHandlerContext.fireExceptionCaught(AbstractChannelHandlerContext.java:256)

the log shows:

the initial part of the response gathering in the buffer (Appended char seq...), then
emitting the first chunk (Exporting capped chunk...), then
the DETACH signal, and the generate routine kicking out, then
the engine calls back, this time it waits on the future, receives a value
more Appended char seq... as it keeps rendering, with the new future in-hand
Exporting capped chunk... again, this time 45 bytes to finish the stream, which should be chunk 2 in a Transfer-Encoding: chunked response
it notes where it calls onComplete
but then nothing happens. the next thing in the log is a read timeout, which i've tried at 8, 20, and 300 seconds.

AFAIK nothing else is broken. all other tests pass, including the existing suite for Soy. it's just when there is a future value in the Soy render context that isn't immediately ready.

…ws into soy/async-chunked

graemerocher · 2019-11-13T09:46:21Z

I will take a look shortly. Thanks.

sgammon · 2019-11-13T21:41:26Z

@graemerocher Two ideas popped into my head in case they are relevant. To yield a chunk, I am issuing a read-only slice of the backing render buffer (CompositeByteBuf), wrapping them in ByteBuffer (via ByteBufferFactory.wrap) and then emitting them up to Micronaut. These chunks each have a read index of 0 and a write index at their full capacity when emitted, which is set to the size of the chunk, not the render buffer.

The read-only slice is retained. After more real-world testing, I get a reference count for the underlying buffer (at close time) that approaches 10/12. Could it be that:

Micronaut doesn't release wrapped buffers and that is my responsibility to do? But I figure it is unlikely that an unreleased buffer would hang a response. Would still like to check into the proper procedure here to prevent leaks.
Perhaps Micronaut expects the full HTTP response and buffer to be yielded each time, but with a stateful read and write index, rather than a new buffer for each chunk?

If you point me to the relevant code, I'd be happy to understand more and try and pry it open, perhaps with some trace logging. Thank you for taking a look

EDIT: one final note. once we get this working, i'm happy to clean up this PR, add some more testing for the chunking/buffer sizing, and squash/rebase on master.

graemerocher · 2019-11-13T21:47:25Z

Logic is handled here I believe https://github.com/micronaut-projects/micronaut-core/blob/765d7261b11827ac128f4600ca437b1f2ef210e4/http-server-netty/src/main/java/io/micronaut/http/server/netty/RoutingInBoundHandler.java#L1531

graemerocher · 2019-11-13T21:48:52Z

What may be missing is the writing of the DefaultLastHttpContent

sgammon · 2019-11-13T22:44:07Z

@graemerocher Perfect! Thank you. I'll try debugging starting from isStreaming onward.

If I can generate a more useful log, I'll post it.

sgammon · 2019-11-15T18:51:17Z

@graemerocher I took a look at the code you pointed out, but I don't quite understand how DefaultLastHttpContent works into the flow here. Do I emit that myself? It appears as though RoutingInBoundHandler only invokes DefaultLastHttpContent when handling SSE streams, but perhaps I'm missing something.

graemerocher · 2019-11-20T10:31:31Z

@sgammon I will be looking at this this afternoon. Sorry for the delay

graemerocher · 2019-11-20T12:19:13Z

Yeah so the issue is that the decision to switch to streaming the data is statically decided based on the return type of the controller method, not based on the body of the response emitted. We need to add the streaming logic to core before we can proceed ahead with this otherwise dynamically switching to streaming is not possible.

sgammon · 2019-11-21T04:14:39Z

@graemerocher no problem on the delay, thank you for taking the time to look :)

i see, well that does explain it. for now, this isn't a blocker for us, because we resolve all futures before rendering anyway. but i am happy to pick it back up again or contribute to get it merged eventually. thank you again for your help

sgammon · 2020-02-13T21:09:49Z

@graemerocher, happy new year - is there any update on the upstream support for dynamically deciding on streaming vs. buffered responses?

sgammon · 2020-02-26T20:39:53Z

closing this because it is superseded by #34 (Reactive Soy v2)

sgammon added 29 commits August 22, 2019 10:37

Upgrade PRNG to faster implementation

dbaff2b

Cleanup after PRNG switchover

9914dca

Remove Soy patch, upgrade -> 2019-09-03

86797e8

Adopts upstream release after request at google/closure-templates#188

Cleanup docstrings, copyright headers

49656f7

Fix version tags for views-soy (since: 1.2.1)

ce87dcf

Remove DSI util - rely on normal Random

a5392b8

Remove Soy patch in CI

7b8b8eb

Remove Soy runtime dependencies

b0bea4d

Add coverage to Travis via Codecov

7e656ff

Invoke jacocoFullReport in CI

33944d7

Remove custom repositories in views-soy

8094791

Add documentation for Soy with Micronaut

dec5d05

Support injection of CSS/XID renaming maps

b6d70ba

Finish up docs, general cleanup for Soy

a0ba048

Add docs for CSP nonce generation

90cc831

Fixup copyright in SoyNamingMapProvider

336ec76

Fix response type with cast

3a1ca78

Fix copyright headers in added files for async render

73577d2

Merge branch 'feature/soy'

841ff99

Merge branch 'feature/csp-nonce'

6f94cc1

Merge branch 'feature/async'

c54490f

Convert to ByteBuf from Writable for chunked payloads

e7bdafa

Merge branch 'master' into soy/async-chunked

3e9cf5f

sgammon mentioned this pull request Nov 13, 2019

Feature: Async Views #18

Closed

7 tasks

sgammon added 3 commits November 12, 2019 23:48

Reject responses for Soy render that don't have status code 200

c600bf8

Merge branch 'soy/async-chunked' of github.com:bloombox/micronaut-vie…

c3444f7

…ws into soy/async-chunked

Bigger chunk sizes, swap chunk if write exceeds size

8a82029

sgammon force-pushed the soy/async-chunked branch 2 times, most recently from 613e267 to 9a5aae1 Compare November 13, 2019 08:37

Remove buffer max

99470af

sgammon force-pushed the soy/async-chunked branch from 9a5aae1 to 99470af Compare November 13, 2019 09:05

sgammon mentioned this pull request Feb 26, 2020

Feature: Reactive Soy (v2) #34

Open

sgammon closed this Feb 26, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Feature: Reactive Soy #26

Feature: Reactive Soy #26

sgammon commented Nov 13, 2019 •

edited

Loading

sgammon commented Nov 13, 2019 •

edited

Loading

graemerocher commented Nov 13, 2019

sgammon commented Nov 13, 2019 •

edited

Loading

graemerocher commented Nov 13, 2019

graemerocher commented Nov 13, 2019

sgammon commented Nov 13, 2019

sgammon commented Nov 15, 2019

graemerocher commented Nov 20, 2019

graemerocher commented Nov 20, 2019

sgammon commented Nov 21, 2019

sgammon commented Feb 13, 2020

sgammon commented Feb 26, 2020

Feature: Reactive Soy #26

Feature: Reactive Soy #26

Conversation

sgammon commented Nov 13, 2019 • edited Loading

sgammon commented Nov 13, 2019 • edited Loading

graemerocher commented Nov 13, 2019

sgammon commented Nov 13, 2019 • edited Loading

graemerocher commented Nov 13, 2019

graemerocher commented Nov 13, 2019

sgammon commented Nov 13, 2019

sgammon commented Nov 15, 2019

graemerocher commented Nov 20, 2019

graemerocher commented Nov 20, 2019

sgammon commented Nov 21, 2019

sgammon commented Feb 13, 2020

sgammon commented Feb 26, 2020

sgammon commented Nov 13, 2019 •

edited

Loading

sgammon commented Nov 13, 2019 •

edited

Loading

sgammon commented Nov 13, 2019 •

edited

Loading