You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ranger.apache.org by Alok Lal <al...@hortonworks.com> on 2015/09/01 20:16:35 UTC
Re: Review Request 37916: Add start/stop/progress log messages so
processing of Audit's JVM shutdown hooks can be monitored
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/37916/
-----------------------------------------------------------
(Updated Sept. 1, 2015, 11:16 a.m.)
Review request for ranger and Madhan Neethiraj.
Changes
-------
Log output of another test done to simulate backlog in db audit using TestEvents test script.
Bugs: RANGER-627
https://issues.apache.org/jira/browse/RANGER-627
Repository: ranger
Description
-------
Add start/stop/progress log messages so processing of Audit's JVM shutdown hooks can be monitored
Diffs
-----
agents-audit/src/main/java/org/apache/ranger/audit/provider/AsyncAuditProvider.java f469d80
agents-audit/src/main/java/org/apache/ranger/audit/provider/AuditProviderFactory.java 1146e0b
agents-audit/src/main/java/org/apache/ranger/audit/provider/DbAuditProvider.java f23f17d
agents-audit/src/main/java/org/apache/ranger/audit/provider/MultiDestAuditProvider.java 26108ca
Diff: https://reviews.apache.org/r/37916/diff/
Testing (updated)
-------
Simulate backlog in db queue and ensure that progress messages are logged, entry exit messages are logged by waitToComplete, stop and JVMShowdownHook run methods. Spurious methods that can confuse admin are removed.
Following is log when using TestEvents to simulate backup of audit log events:
- First is the output of normal shutdown
- Second is the output when kill -1 is sent to the process to simulate a attempt to abort the service.
First Test output
=====
2015-09-01 10:59:46,450 [AsyncAuditProvider1] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:173) - <== AsyncAuditProvider.run()
2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.test.TestEvents (TestEvents.java:120) - <== TestEvents.main()
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AuditProviderFactory$JVMShutdownHook (AuditProviderFactory.java:454) - ==> JVMShutdownHook.run()
2015-09-01 10:59:46,451 [Thread-0] DEBUG org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:251) - ==> AsyncAuditProvider.waitToComplete()
2015-09-01 10:59:46,451 [Thread-0] DEBUG org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:266) - <== AsyncAuditProvider.waitToComplete()
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:116) - ==> AsyncAuditProvider.stop()
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:118) - Interrupting child thread of DbAuditProvider...
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AuditProviderFactory$JVMShutdownHook (AuditProviderFactory.java:459) - <== JVMShutdownHook.run()
Second test output
====
2015-09-01 11:14:44,173 [AsyncAuditProvider1] DEBUG org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:123) - <== DbAuditProvider.log()
2015-09-01 11:14:44,174 [AsyncAuditProvider1] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:159) - AsyncAuditProvider.run - Interrupted! Breaking out of while loop.
2015-09-01 11:14:44,174 [AsyncAuditProvider1] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:173) - <== AsyncAuditProvider.run()
2015-09-01 11:14:44,175 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
2015-09-01 11:14:44,175 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
2015-09-01 11:14:44,175 [main] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
2015-09-01 11:14:44,176 [main] INFO org.apache.ranger.audit.test.TestEvents (TestEvents.java:120) - <== TestEvents.main()
2015-09-01 11:14:44,404 [Thread-0] DEBUG org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:266) - <== AsyncAuditProvider.waitToComplete()
2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:116) - ==> AsyncAuditProvider.stop()
2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:118) - Interrupting child thread of DbAuditProvider...
2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AuditProviderFactory$JVMShutdownHook (AuditProviderFactory.java:459) - <== JVMShutdownHook.run()
Thanks,
Alok Lal
Re: Review Request 37916: Add start/stop/progress log messages so
processing of Audit's JVM shutdown hooks can be monitored
Posted by Madhan Neethiraj <ma...@apache.org>.
-----------------------------------------------------------
This is an automatically generated e-mail. To reply, visit:
https://reviews.apache.org/r/37916/#review98698
-----------------------------------------------------------
Ship it!
Changes look good. Thanks for the effort to verify this tricky one.. It helps!
- Madhan Neethiraj
On Sept. 1, 2015, 6:16 p.m., Alok Lal wrote:
>
> -----------------------------------------------------------
> This is an automatically generated e-mail. To reply, visit:
> https://reviews.apache.org/r/37916/
> -----------------------------------------------------------
>
> (Updated Sept. 1, 2015, 6:16 p.m.)
>
>
> Review request for ranger and Madhan Neethiraj.
>
>
> Bugs: RANGER-627
> https://issues.apache.org/jira/browse/RANGER-627
>
>
> Repository: ranger
>
>
> Description
> -------
>
> Add start/stop/progress log messages so processing of Audit's JVM shutdown hooks can be monitored
>
>
> Diffs
> -----
>
> agents-audit/src/main/java/org/apache/ranger/audit/provider/AsyncAuditProvider.java f469d80
> agents-audit/src/main/java/org/apache/ranger/audit/provider/AuditProviderFactory.java 1146e0b
> agents-audit/src/main/java/org/apache/ranger/audit/provider/DbAuditProvider.java f23f17d
> agents-audit/src/main/java/org/apache/ranger/audit/provider/MultiDestAuditProvider.java 26108ca
>
> Diff: https://reviews.apache.org/r/37916/diff/
>
>
> Testing
> -------
>
> Simulate backlog in db queue and ensure that progress messages are logged, entry exit messages are logged by waitToComplete, stop and JVMShowdownHook run methods. Spurious methods that can confuse admin are removed.
>
> Following is log when using TestEvents to simulate backup of audit log events:
> - First is the output of normal shutdown
> - Second is the output when kill -1 is sent to the process to simulate a attempt to abort the service.
>
> First Test output
> =====
> 2015-09-01 10:59:46,450 [AsyncAuditProvider1] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:173) - <== AsyncAuditProvider.run()
> 2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
> 2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
> 2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
> 2015-09-01 10:59:46,451 [main] INFO org.apache.ranger.audit.test.TestEvents (TestEvents.java:120) - <== TestEvents.main()
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AuditProviderFactory$JVMShutdownHook (AuditProviderFactory.java:454) - ==> JVMShutdownHook.run()
> 2015-09-01 10:59:46,451 [Thread-0] DEBUG org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:251) - ==> AsyncAuditProvider.waitToComplete()
> 2015-09-01 10:59:46,451 [Thread-0] DEBUG org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:266) - <== AsyncAuditProvider.waitToComplete()
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:116) - ==> AsyncAuditProvider.stop()
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:118) - Interrupting child thread of DbAuditProvider...
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
> 2015-09-01 10:59:46,451 [Thread-0] INFO org.apache.ranger.audit.provider.AuditProviderFactory$JVMShutdownHook (AuditProviderFactory.java:459) - <== JVMShutdownHook.run()
>
> Second test output
> ====
>
> 2015-09-01 11:14:44,173 [AsyncAuditProvider1] DEBUG org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:123) - <== DbAuditProvider.log()
> 2015-09-01 11:14:44,174 [AsyncAuditProvider1] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:159) - AsyncAuditProvider.run - Interrupted! Breaking out of while loop.
> 2015-09-01 11:14:44,174 [AsyncAuditProvider1] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:173) - <== AsyncAuditProvider.run()
> 2015-09-01 11:14:44,175 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
> 2015-09-01 11:14:44,175 [main] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
> 2015-09-01 11:14:44,175 [main] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
> 2015-09-01 11:14:44,176 [main] INFO org.apache.ranger.audit.test.TestEvents (TestEvents.java:120) - <== TestEvents.main()
> 2015-09-01 11:14:44,404 [Thread-0] DEBUG org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:266) - <== AsyncAuditProvider.waitToComplete()
> 2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:116) - ==> AsyncAuditProvider.stop()
> 2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:118) - Interrupting child thread of DbAuditProvider...
> 2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:167) - DbAuditProvider.stop()
> 2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.DbAuditProvider (DbAuditProvider.java:215) - DbAuditProvider: cleanUp()
> 2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AsyncAuditProvider (AsyncAuditProvider.java:132) - <== AsyncAuditProvider.stop()
> 2015-09-01 11:14:44,404 [Thread-0] INFO org.apache.ranger.audit.provider.AuditProviderFactory$JVMShutdownHook (AuditProviderFactory.java:459) - <== JVMShutdownHook.run()
>
>
> Thanks,
>
> Alok Lal
>
>