search

veracitylab / provenance-injector

inject provenance into JEE applications
Apache License 2.0
0 stars 0 forks source link

Use `ThreadLocalProvenanceTracker` #22

Closed wtwhite closed 6 months ago

wtwhite commented 6 months ago

Resolves #21.

Also makes out-of-request tracked invocations (those that happen before, in between, or after any start()-finish() pair) available under the bucket ID NO_ACTIVE_REQUEST, even if they occur on the same thread as in-request tracked invocations. These can be made available to pickup() with an unpaired finish() call on the thread where the invocation happened (though there's currently no way to enumerate the list of all such threads).

Also throw an exception if start() is called twice on the same thread with no intervening finish() -- this indicates a bug.

Will do some testing with the movie demo before merging, and probably add some more tests.

wtwhite commented 6 months ago

Manual testing

Using:

After building the demo, incorporating this repo's provenance agent and starting the app (note no -javaagent:... needed):

wtwhite@wtwhite-vuw-vm:~/code/provenance-demonstrator-movie$ ./gradlew bootWar
Starting a Gradle Daemon (subsequent builds will be faster)

BUILD SUCCESSFUL in 6s
7 actionable tasks: 1 executed, 6 up-to-date
wtwhite@wtwhite-vuw-vm:~/code/provenance-demonstrator-movie$ cp web/build/libs/web-0.0.1-SNAPSHOT.war with_exploded_embedded_provenance-agent_jar.war 
wtwhite@wtwhite-vuw-vm:~/code/provenance-demonstrator-movie$ pushd ~/code/provenance-injector
~/code/provenance-injector ~/code/provenance-demonstrator-movie ~
wtwhite@wtwhite-vuw-vm:~/code/provenance-injector$ ./provenancify-spring-boot-app.sh ~/code/provenance-demonstrator-movie/with_exploded_embedded_provenance-agent_jar.war
APPJARPATH=/home/wtwhite/code/provenance-demonstrator-movie/with_exploded_embedded_provenance-agent_jar.war
PROVAGENTJARPATH=/home/wtwhite/code/provenance-injector/target/provenance-agent.jar
EXPLODEDIR=/tmp/tmp.xMu6Z7247V
DONE
wtwhite@wtwhite-vuw-vm:~/code/provenance-injector$ popd
~/code/provenance-demonstrator-movie ~
wtwhite@wtwhite-vuw-vm:~/code/provenance-demonstrator-movie$ java -jar with_exploded_embedded_provenance-agent_jar.war --debug

I opened the app in the browser at http://localhost:8080, logged in as user jens, and clicked the "Library" link in the top right to go to /library. This triggered a number of HTTP requests, including to /library itself, which returned a provenance-id: 17 HTTP header:

image

Logs show request 17 incurred 250 tracked invocations:

2024-03-14 18:47:01.008 DEBUG 669797 --- [nio-8080-exec-6] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to nz.ac.canterbury.dataprovenancedemo.controllers.LibraryController#libraryPage(Model, Optional, Optional)
2024-03-14 18:47:01.008 DEBUG 669797 --- [nio-8080-exec-6] o.s.web.servlet.DispatcherServlet        : GET "/library", parameters={}
2024-03-14 18:47:01.010 DEBUG 669797 --- [nio-8080-exec-6] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to nz.ac.canterbury.dataprovenancedemo.controllers.LibraryController#libraryPage(Model, Optional, Optional)
2024-03-14 18:47:01.010  INFO 669797 --- [nio-8080-exec-6] o.a.c.c.C.[Tomcat].[localhost].[/]       : pre handle: /library
ThreadLocalProvenanceTracker.start() called! Returning id 17
2024-03-14 18:47:01.036 DEBUG 669797 --- [nio-8080-exec-6] org.hibernate.SQL                        : select movie0_.id as id1_0_, movie0_.genres as genres2_0_, movie0_.poster_url as poster_u3_0_, movie0_.release_year as release_4_0_, movie0_.title as title5_0_ from movies movie0_ limit ?
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@56fcbdf4) called for ID 17!
ThreadLocalProvenanceTracker.track(): There are now 1 invocations tracked so far for ID 17.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@34befde2) called for ID 17!
ThreadLocalProvenanceTracker.track(): There are now 2 invocations tracked so far for ID 17.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@200b623d) called for ID 17!
ThreadLocalProvenanceTracker.track(): There are now 3 invocations tracked so far for ID 17.
--snip--
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@64ffffe5) called for ID 17!
ThreadLocalProvenanceTracker.track(): There are now 249 invocations tracked so far for ID 17.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@5a60b3c3) called for ID 17!
ThreadLocalProvenanceTracker.track(): There are now 250 invocations tracked so far for ID 17.
2024-03-14 18:47:01.097  INFO 669797 --- [nio-8080-exec-6] o.a.c.c.C.[Tomcat].[localhost].[/]       : post handle: /library
ThreadLocalProvenanceTracker.finish() called for ID 17! Will move 250 invocations to outbox.
2024-03-14 18:47:01.098 DEBUG 669797 --- [nio-8080-exec-6] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, application/xhtml+xml, image/avif, image/webp, application/xml;q=0.9, */*;q=0.8]
2024-03-14 18:47:01.143 DEBUG 669797 --- [nio-8080-exec-6] o.s.web.servlet.DispatcherServlet        : Completed 200 OK

While /recommendations returned a provenance-id: 25 header:

image

That triggered 64 tracked invocations:

2024-03-14 18:47:01.359 DEBUG 669797 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to nz.ac.canterbury.dataprovenancedemo.controllers.RecommendationController#libraryRecommendationsPage(Model, HttpServletRequest)
2024-03-14 18:47:01.360 DEBUG 669797 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet        : GET "/recommendations", parameters={}
2024-03-14 18:47:01.361 DEBUG 669797 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to nz.ac.canterbury.dataprovenancedemo.controllers.RecommendationController#libraryRecommendationsPage(Model, HttpServletRequest)
2024-03-14 18:47:01.361  INFO 669797 --- [nio-8080-exec-3] o.a.c.c.C.[Tomcat].[localhost].[/]       : pre handle: /recommendations
ThreadLocalProvenanceTracker.start() called! Returning id 25
2024-03-14 18:47:01.395 DEBUG 669797 --- [nio-8080-exec-3] org.hibernate.SQL                        : select movie0_.id as id1_0_, movie0_.genres as genres2_0_, movie0_.poster_url as poster_u3_0_, movie0_.release_year as release_4_0_, movie0_.title as title5_0_ from movies movie0_ where movie0_.id in (? , ? , ? , ? , ?)
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@1882b651) called for ID 25!
ThreadLocalProvenanceTracker.track(): There are now 1 invocations tracked so far for ID 25.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@48527b75) called for ID 25!
ThreadLocalProvenanceTracker.track(): There are now 2 invocations tracked so far for ID 25.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@5c885805) called for ID 25!
ThreadLocalProvenanceTracker.track(): There are now 3 invocations tracked so far for ID 25.
--snip--
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@d3213ef) called for ID 25!
ThreadLocalProvenanceTracker.track(): There are now 63 invocations tracked so far for ID 25.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@56cb6be) called for ID 25!
ThreadLocalProvenanceTracker.track(): There are now 64 invocations tracked so far for ID 25.
CallSiteVisitor: visiting class nz/ac/canterbury/dataprovenancedemo/provenance/ModelInfo$ModelInfoBuilder
CallSiteVisitor: visiting class nz/ac/canterbury/dataprovenancedemo/provenance/ModelInfo
CallSiteVisitor: visiting class nz/ac/canterbury/dataprovenancedemo/provenance/ProvenanceData$ProvenanceDataBuilder
2024-03-14 18:47:01.416  INFO 669797 --- [nio-8080-exec-3] o.a.c.c.C.[Tomcat].[localhost].[/]       : post handle: /recommendations
ThreadLocalProvenanceTracker.finish() called for ID 25! Will move 64 invocations to outbox.
2024-03-14 18:47:01.417 DEBUG 669797 --- [nio-8080-exec-3] o.s.w.s.v.ContentNegotiatingViewResolver : Selected '*/*' given [*/*]
2024-03-14 18:47:01.429 DEBUG 669797 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet        : Completed 200 OK

Both could be recovered with curl:

wtwhite@wtwhite-vuw-vm:~$ curl -i http://localhost:8080/prov/17
HTTP/1.1 200 
Vary: Origin
Vary: Access-Control-Request-Method
Vary: Access-Control-Request-Headers
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Pragma: no-cache
Expires: 0
X-Frame-Options: DENY
Content-Type: application/json
Transfer-Encoding: chunked
Date: Thu, 14 Mar 2024 05:54:41 GMT

[{"activities":[{"id":"e902bc69-d795-4816-87e6-714d8797cec3","type":"DBRead","endTime":"2024-03-14T05:47:01.037750Z"}],"associatedEntities":[]},{"activities":[{"id":"72d16fee-bf60-4809-b526-705ad4015a6e","type":"DBRead","endTime":"2024-03-14T05:47:01.037803Z"}],"associatedEntities":[]},{"activities":[{"id":"1466a670-6c63-4886-844d-222e8615477d","type":"DBRead","endTime":"2024-03-14T05:47:01.037862Z"}],"associatedEntities":[]},{"activities":[{"id":"a15f35fb-3930-429d-bd07-e833418a91c3","type":"DBRead","endTime":"2024-03-14T05:47:01.037871Z"}],"associatedEntities":[]},{"activities":[{"id":"7eca8468-512e-4f03-86c6-5f1c1eb5eec0","type":"DBRead","endTime":"2024-03-14T05:47:01.037957Z"}],"associatedEntities":[]},{"activities":[{"id":"fdb95ab0-3c74-4d84-9a2d-28705b587060","type":"DBRead","endTime":"2024-03-14T05:47:01.037969Z"}],"associatedEntities":[]},{"activities":[{"id":"ff611515-9bbd-4abc-9dc5-dfaf4e9ce41e","type":"DBRead","endTime":"2024-03-14T05:47:01.044342Z"}],"associatedEntities":[]},{"activities":[{"id":"446eae02-e746-409a-84b2-3801a3516c42","type":"DBRead","endTime":"2024-03-14T05:47:01.044366Z"}],"associatedEntities":[]},{"activities":[{"id":"d095938c-5f4f-4a2a-9ce4-a0def8a7f62a","type":"DBRead","endTime":"2024-03-14T05:47:01.044397Z"}],"associatedEntities":[]},{"activities":[{"id":"faf0094c-6ea0-47b6-9e78-0ba4e4d3d360","type":"DBRead","endTime":"2024-03-14T05:47:01.044405Z"}],"associatedEntities":[
--snip--
-5936c37e6c9b","type":"DBRead","endTime":"2024-03-14T05:47:01.080203Z"}],"associatedEntities":[]},{"activities":[{"id":"c10a3f0d-f698-47f1-bf87-30c99bb94a41","type":"DBRead","endTime":"2024-03-14T05:47:01.080222Z"}],"associatedEntities":[]},{"activities":[{"id":"6ce29ab9-b5d7-43df-b05d-48199efb1eda","type":"DBRead","endTime":"2024-03-14T05:47:01.080251Z"}],"associatedEntities":[]},{"activities":[{"id":"130a1004-8025-44e1-9fd6-2bf89a3d49e3","type":"DBRead","endTime":"2024-03-14T05:47:01.080259Z"}],"associatedEntities":[]}]wtwhite@wtwhite-vuw-vm:~$
wtwhite@wtwhite-vuw-vm:~$ curl -i http://localhost:8080/prov/25
HTTP/1.1 200 
Vary: Origin
Vary: Access-Control-Request-Method
Vary: Access-Control-Request-Headers
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Pragma: no-cache
Expires: 0
X-Frame-Options: DENY
Content-Type: application/json
Transfer-Encoding: chunked
Date: Thu, 14 Mar 2024 05:55:43 GMT

[{"activities":[{"id":"3eb8ee7f-c14d-4796-acc1-e84a4a447672","type":"DBRead","endTime":"2024-03-14T05:47:01.398045Z"}],"associatedEntities":[]},{"activities":[{"id":"0c6e06d8-41c4-41ed-b1fe-57d90f5b252d","type":"DBRead","endTime":"2024-03-14T05:47:01.398375Z"}],"associatedEntities":[]},{"activities":[{"id":"5675cac6-425d-4199-8a6b-8167899b2036","type":"DBRead","endTime":"2024-03-14T05:47:01.399044Z"}],"associatedEntities":[]},{"activities":[{"id":"d0953dbb-e896-4b40-b5bb-f6d6534275d2","type":"DBRead","endTime":"2024-03-14T05:47:01.399331Z"}],"associatedEntities":[]},{"activities":[{"id":"6b7db81b-d573-4ddb-b794-4d80ca50ce35","type":"DBRead","endTime":"2024-03-14T05:47:01.400605Z"}],"associatedEntities":[]},{"activities":[{"id":"335197ca-b491-44c4-9454-738a5b5c887f","type":"DBRead","endTime":"2024-03-14T05:47:01.401122Z"}],"associatedEntities":[]},{"activities":[{"id":"62867646-f1f7-4c64-b7ab-96be328c66e4","type":"DBRead","endTime":"2024-0
--snip--
,"type":"DBRead","endTime":"2024-03-14T05:47:01.413270Z"}],"associatedEntities":[]}]wtwhite@wtwhite-vuw-vm:~$

As discussed in #20, logging into the app triggered DB activities that were not assigned to any request:

2024-03-14 18:46:43.841 DEBUG 669797 --- [nio-8080-exec-8] o.s.w.s.handler.SimpleUrlHandlerMapping  : Mapped to ResourceHttpRequestHandler [URL [file:src/main/resources/static/], Classpath [static/], ServletContext [/]]
2024-03-14 18:46:43.912 DEBUG 669797 --- [nio-8080-exec-8] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2024-03-14 18:46:43.913 DEBUG 669797 --- [nio-8080-exec-8] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [select username,password,enabled from users where username = ?]
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@17c95144) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 1 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@6d709654) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 2 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@3c100dc4) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 3 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@77bbd3cf) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 4 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@2a25ff0d) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 5 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@430e0e2b) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 6 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@7f4c45a3) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 7 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@5640d42e) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 8 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@5398847c) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 9 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@6054b772) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 10 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@3a350712) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 11 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@7f1fc801) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 12 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@373a1388) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 13 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@36648aae) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 14 invocations tracked so far for ID NO_ACTIVE_REQUEST.
2024-03-14 18:46:43.921 DEBUG 669797 --- [nio-8080-exec-8] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2024-03-14 18:46:43.921 DEBUG 669797 --- [nio-8080-exec-8] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [select username,authority from authorities where username = ?]
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@77e95f83) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 15 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@1acac276) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 16 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@1f8013e0) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 17 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@1636f865) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 18 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@2b1ea867) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 19 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@678b0600) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 20 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@780b0602) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 21 invocations tracked so far for ID NO_ACTIVE_REQUEST.
recordActivity(capturedReturn=null, activityTypes=DBRead!
ThreadLocalProvenanceTracker.track(nz.ac.wgtn.veracity.provenance.injector.model.Invocation@595f3cb6) called for ID NO_ACTIVE_REQUEST!
ThreadLocalProvenanceTracker.track(): There are now 22 invocations tracked so far for ID NO_ACTIVE_REQUEST.
wtwhite commented 6 months ago

https://github.com/veracitylab/provenance-demonstrator-movie/commit/10b0724f58a8699a45e175fbd66f54f45cdf7276 is now in the movie demo repo, so the above manual testing should be reproducible.