Bug 16302

Summary: Koha::Logger performance tests
Product: Koha Reporter: Olli-Antti Kivilahti <olli-antti.kivilahti>
Component: Architecture, internals, and plumbingAssignee: Olli-Antti Kivilahti <olli-antti.kivilahti>
Status: Failed QA --- QA Contact: Testopia <testopia>
Severity: enhancement    
Priority: P5 - low CC: kyle, lari.taskula
Version: master   
Hardware: All   
OS: All   
Change sponsored?: --- Patch complexity: ---
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
Bug Depends on: 14167    
Bug Blocks: 16304, 16312, 16313    
Attachments: Bug 16302 - Koha::Logger performance tests
Bug 16302 - Koha::Logger performance tests

Description Olli-Antti Kivilahti 2016-04-19 19:58:28 UTC
This test suite proves that Koha::Logger only incurs a ~25% performance hit vs the vanilla Log::Log4perl.

When the Log4perl config is defined in the %ENV, then the performance hit is only 9%

This is subjective and dependant on how the Logger is deployed in code. Regardless the performance is acceptable in my opinion.
Comment 1 Olli-Antti Kivilahti 2016-04-19 19:59:32 UTC Comment hidden (obsolete)
Comment 2 Olli-Antti Kivilahti 2016-04-19 21:42:20 UTC
Created attachment 50444 [details] [review]
Bug 16302 - Koha::Logger performance tests

Tests performance and regression in Koha::Logger
Comment 3 Kyle M Hall 2016-04-26 15:24:20 UTC
t/Koha/Logger_performance.t ..
    # Subtest: Log4perl vanilla, 10000 errors
    ok 1 - Test duration 0.740009069442749 < 0.984212062358856
    ok 2 - Log writing confirmed
    1..2
ok 1 - Log4perl vanilla, 10000 errors
    # Subtest: Log4perl Koha::Logger from KOHA_CONF, 10000 errors
    ok 1 - Test duration 0.0620830059051514 < 0.984212062358856
Use of uninitialized value $firstRow in pattern match (m//) at t/Koha/Logger_performance.t line 106.
    not ok 2 - Log writing confirmed

    #   Failed test 'Log writing confirmed'
    #   at t/Koha/Logger_performance.t line 106.
    1..2
    # Looks like you failed 1 test of 2.
not ok 2 - Log4perl Koha::Logger from KOHA_CONF, 10000 errors

#   Failed test 'Log4perl Koha::Logger from KOHA_CONF, 10000 errors'
#   at t/Koha/Logger_performance.t line 60.
    # Subtest: Log4perl Koha::Logger from ENV, 10000 errors
    ok 1 - Test duration 0.839640140533447 < 0.984212062358856
    ok 2 - Log writing confirmed
    1..2
ok 3 - Log4perl Koha::Logger from ENV, 10000 errors
1..3
# Looks like you failed 1 test of 3.
Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/3 subtests

Test Summary Report
-------------------
t/Koha/Logger_performance.t (Wstat: 256 Tests: 3 Failed: 1)
  Failed test:  2
  Non-zero exit status: 1
Files=1, Tests=3,  2 wallclock secs ( 0.02 usr  0.00 sys +  1.80 cusr  0.13 csys =  1.95 CPU)
Result: FAIL
Comment 4 Kyle M Hall 2016-04-26 15:25:08 UTC
If I comment out lines 108 and 109 the tests pass, but I don't think they'd be valid anymore.
Comment 5 Lari Taskula 2017-07-06 11:37:01 UTC
Most test runs are passing for me, however, every now and then it fails at the second test:

# Subtest: Log4perl vanilla, 10000 errors
    ok 1 - Test duration 0.710620880126953 < 0.945125770568848
    ok 2 - Log writing confirmed
    1..2
ok 1 - Log4perl vanilla, 10000 errors
# Subtest: Log4perl Koha::Logger from KOHA_CONF, 10000 errors
    not ok 1 - Test duration 1.00295996665955 < 0.945125770568848
    #   Failed test 'Test duration 1.00295996665955 < 0.945125770568848'
    #   at t/Koha/Logger_performance.t line 68.
    ok 2 - Log writing confirmed
    1..2
    # Looks like you failed 1 test of 2.
not ok 2 - Log4perl Koha::Logger from KOHA_CONF, 10000 errors
#   Failed test 'Log4perl Koha::Logger from KOHA_CONF, 10000 errors'
#   at t/Koha/Logger_performance.t line 60.
# Subtest: Log4perl Koha::Logger from ENV, 10000 errors
    ok 1 - Test duration 0.792418956756592 < 0.945125770568848
    ok 2 - Log writing confirmed
    1..2
ok 3 - Log4perl Koha::Logger from ENV, 10000 errors
1..3
# Looks like you failed 1 test of 3.