Audit log initializer - moving to be optional on startup?

43 views
Skip to first unread message

Josh Zamor

unread,
Oct 30, 2017, 9:01:41 PM10/30/17
to OpenLMIS Dev
Hi all,

I wanted to get feedback on a quick idea and also share some latest learning from Audit log initialization.

Background:  remember that our audit log in services is handled by the library Javers.  Javers has a requirement that it knows about any entity which is auditable (i.e. has an audit log), before that entity is used with Javers.  In practice this means anything done through the API / Java Repository with that entity is OK.  Anything done directly to the database is something Javers doesn't know about.  When Javers doesn't know about that entity, it throws an exception and the processing stops.  Rather than put the onus (and performance penalty) of checking and correcting for this edge case in every read/write call in the service, we instead opted for a service startup solution that ensures everything in the service is known by Javers.

Problem:  This startup solution is slow, and there's no simple way to make it faster (essentially there's no way to ask Javers what it doesn't know about).  Right now it runs in every service, every-time the service starts.  In Service's like Requisition, this can currently take up to 8 hours.  Some issues:

  •  Unbeknownst to us, a CommandLineRunner or ApplicationRunner, Spring utilities that allow us to run Java code on service start, don't block the service from serving requests.
  • The only way to presently tell if AuditLogInitializer is done is to check the Service's log for the message which reads something like:  Application started in XXX seconds
  • Running the audit log initialization every time is not only slow, but it consumes resources: database credits, cpu cycles, memory, etc.  Most of the time these resources are spent for Javers to be able to say "yes, I know about that thing".
  • Presently we have a bug when we allow a service to be used, before the audit log initialization to complete:  if a request is made about an entity, before the initialization is complete, Javers will throw an exception.  AFAIK a user hasn't encountered this scenario yet.

Short term proposal:

  • Running the audit log initializer shouldn't be done every-time a service starts.  There are a few scenarios when it does need to run:
    • The admin/implementer has manually changed the database:  migrations from other systems, manual updates, etc
    • The service is being updated to a new version, and the release notes call for it:  an existing entity (i.e. there's data for it) has been made auditable.
  • Move running the audit log initialize to when the implementer requests it by way of a Spring profile environment.  Much like how we have "refresh-db" and "production", we'd either use "refresh-db" to also run the audit log initializer, or we'd introduce a new profile, such as "refresh-audit-log".  My preference is on using "refresh-db".
  • In our release notes of a Service we'd note when this profile to run the audit log initializer would be used.
  • Implementers, when they used this profile to run the audit log initializer, should check the service logs (all are in Scalyr), for that message which indicates the service is actually done starting, before letting users use the service.  Put another way, if the profile is ran, then expect 8 hours of downtime before the service is actually available.


Mid to longer term:

  • Audit log initialization clearly needs to be made more performant / less costly.  This likely means more in-process (as part of a read/write) checking of weather the item exists in the audit log.  I think we should get an idea of what the performance cost of this with Javers is, before we make the change.
  • Service health checks, and only routing traffic to a service when the health check passes, needs to keep making progress.  We shouldn't expect CommandLineRunner or ApplicationRunner to block service startup - they don't.


What I'd like your feedback on right now (in time for the 3.2.1 release):

  • Can audit log initialization be made optional (i.e. ran) only when asked for by using the Spring Profile "refresh-db"?


Best,

Josh

Nikodem Graczewski

unread,
Oct 31, 2017, 5:55:38 AM10/31/17
to OpenLMIS Dev
Hi Josh,

I have a question. How would Javers deal with a custom SQL called during runtime?

Best regards,
Nikodem

Sebastian Brudziński

unread,
Oct 31, 2017, 6:53:50 AM10/31/17
to openlm...@googlegroups.com

Nikodem, do we currently have custom SQL queries to insert/update/delete data? I don't think so, but even if we did, it's only a matter of annotating the methods appropriately - Javers uses aspects to inject auditing code into methods that modify the domain. We currently simply annotate the whole Spring Data Repository and Javers makes sure to inject the tracking code into save/delete methods from CRUD Repository.

On topic, +1 for making this step optional. I can pretty much confirm the issues mentioned by Josh. I don't have any preferences on a separate profile vs. re-using "refresh-db". I think there's no harm using the latter.

Best regards,
Sebastian


SolDevelo
Sp. z o.o. [LLC] / www.soldevelo.com
Al. Zwycięstwa 96/98, 81-451, Gdynia, Poland
Phone: +48 58 782 45 40 / Fax: +48 58 782 45 41

--
You received this message because you are subscribed to the Google Groups "OpenLMIS Dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openlmis-dev...@googlegroups.com.
To post to this group, send email to openlm...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/openlmis-dev/b3a563ce-1aa4-4a13-9897-bae0d86e4403%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

Sebastian Brudziński
Software Developer / Team Leader
sbrud...@soldevelo.com



SolDevelo
Sp. z o.o. [LLC] / www.soldevelo.com
Al. Zwycięstwa 96/98, 81-451, Gdynia, Poland
Phone: +48 58 782 45 40 / Fax: +48 58 782 45 41

Paweł Gesek

unread,
Oct 31, 2017, 9:14:45 AM10/31/17
to Sebastian Brudziński, OpenLMIS Dev
I'm also fine with making this optional, keep in mind that this mostly affects demo data in our setups (it doesn't have Javers history) and I assume performance data as well.

I know in some of the Javers tickets we've been thinking on optimizing by doing the sql query to update the Javers tables ourselves (instead of looping in Java code), but such solutions will probably have limited portability to other entities (for example it will only work for requisitions).

I second that we should check out the performance before we switch to a read/write based approach. Does Javers have any documentation and guidelines about this issue?

Regards,
Paweł

To unsubscribe from this group and stop receiving emails from it, send an email to openlmis-dev+unsubscribe@googlegroups.com.

To post to this group, send email to openlm...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/openlmis-dev/b3a563ce-1aa4-4a13-9897-bae0d86e4403%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
--

Sebastian Brudziński
Software Developer / Team Leader
sbrud...@soldevelo.com



SolDevelo
Sp. z o.o. [LLC] / www.soldevelo.com
Al. Zwycięstwa 96/98, 81-451, Gdynia, Poland
Phone: +48 58 782 45 40 / Fax: +48 58 782 45 41

--
You received this message because you are subscribed to the Google Groups "OpenLMIS Dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openlmis-dev+unsubscribe@googlegroups.com.

To post to this group, send email to openlm...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.



--

Paweł Gesek
Technical Project Manager
pge...@soldevelo.com / +48 690 020 875

Chongsun Ahn

unread,
Oct 31, 2017, 12:24:43 PM10/31/17
to OpenLMIS Dev
Hey all,

I’m also fine with making it optional, though I have a slight preference for “refresh-audit-log” so we have the option to run the right assignment refresh separately from the audit log initialization.

Shalom,
Chongsun

-- ​
There are 10 kinds of people in this world; those who understand binary, and those who don’t.

Software Development Engineer
 
VillageReach Starting at the Last Mile
2900 Eastlake Ave. E, Suite 230,  Seattle, WA 98102, USA
DIRECT: 1.206.512.1536   CELL: 1.206.910.0973   FAX: 1.206.860.6972
SKYPE: chongsun.ahn.vr
Connect on Facebook, Twitter and our Blog

To unsubscribe from this group and stop receiving emails from it, send an email to openlmis-dev...@googlegroups.com.

To post to this group, send email to openlm...@googlegroups.com.

Josh Zamor

unread,
Oct 31, 2017, 7:50:41 PM10/31/17
to OpenLMIS Dev
Thanks everyone for the quick feedback.

This made it just under the wire, see the main description on use in the README:  https://github.com/OpenLMIS/openlmis-ref-distro#refresh-database-profile

I did opt for using refresh-db since it makes the above instructions to implementers clearer I feel.  If in the future we need to break this up into separate, more task-oriented profiles, we can certainly do that (or perhaps use other deployment flags).

Best,
Josh


On Tuesday, October 31, 2017 at 9:24:43 AM UTC-7, chongsun.ahn wrote:
Hey all,

I’m also fine with making it optional, though I have a slight preference for “refresh-audit-log” so we have the option to run the right assignment refresh separately from the audit log initialization.

Shalom,
Chongsun

-- ​
There are 10 kinds of people in this world; those who understand binary, and those who don’t.

Josh Zamor

unread,
Oct 31, 2017, 7:57:38 PM10/31/17
to OpenLMIS Dev
I have a question. How would Javers deal with a custom SQL called during runtime?

A brief followup on this question, though it is a bit tangential.  The answer is that Javers currently would not do well if someone did an update to a Service's database (likely just INSERT or DELETE) directly (that is NOT through the HTTP REST API), while the Service was running.  Would it instantly throw an error?  No, not until the Java code tried to do something with the effected (that which was inserted/deleted) entity would Javers reach an impassable state.

That's what we have supported and that's what we continue to support - manual database changes require a restart of the service (now a restart with the right profile active).  We'll be looking at the performance cost of mitigating the Javer's impassable state while the service is running at some point here in the near future.  At the moment the driving factor for this is simply the expense of running the current solution.  There is less emphasis / demand that I've heard of being able to manually update a Service's database without a Service restart.

Best,
Josh

Nikodem Graczewski

unread,
Nov 3, 2017, 10:23:40 AM11/3/17
to OpenLMIS Dev
My main concern was whether introducing some custom SQL queries(something we're thinking about when we talk about performance improvements) in our repositories could break Javers, but as we're using the JaversSpringDataAuditable annotation we should have that covered.

Best regards,
Nikodem
Reply all
Reply to author
Forward
0 new messages