#48434 lib389 logging tools
Closed: wontfix None Opened 8 years ago by firstyear.

Lib389 should be able to read, process and interpret log outputs as part of it's tests. We should be integrating log pipe facilities to lib389 to enable this.


This will be really useful for things like #48007 where we need to detect lines like:

{{{
[13/Jan/2015:00:13:23 +0100] NSMMReplicationPlugin - changelog program -
cl5GetOperationCount: found DB object 7f072400df50
[13/Jan/2015:00:18:16 +0100] - Trimmed 5 changes from the changelog
}}}

Hi William,

'''dirsrv_log_test.py::test_access_log''' fails with an assertion error:

{{{
assert(
topology.standalone.ds_access_log.parse_line('[27/Apr/2016:12:49:49.736297002 +1000] conn=1 op=4 fd=64 closed - U1') ==
{'status': 'U1', 'fd': '64', 'action': 'closed', 'timestamp': '[27/Apr/2016:12:49:49.736297002 +1000]', 'conn': '1', 'op': '4'}
)
E assert {'action': 'D...op': '4', ...} == {'action': 'cl...op': '4', ...}
E Common items:
E {'conn': '1',
E 'fd': '64',
E 'op': '4',
E 'status': 'U1',
E 'timestamp': '[27/Apr/2016:12:49:49.736297002 +1000]'}
E Differing items:
E {'action': 'DISCONNECT'} != {'action': 'closed'}
E Full diff:
E - {'action': 'DISCONNECT',
E + {'action': 'closed',
E 'conn': '1',
E 'fd': '64',
E 'op': '4',
E 'status': 'U1',
E 'timestamp': '[27/Apr/2016:12:49:49.736297002 +1000]'}
}}}

This should fix the test case.

Thank you, William.

Looks good to me.

Only one thing. Could you please disable verbose?
{{{
standalone = DirSrv(verbose=True)
}}}

commit 47b9a51c013225790b575dd03a01b8944c589139

There is something lacking from this implementation that I'd like to see addressed before the next respin of lib389: The log matching only works for the current log, not for rotated logs of that type. For example, it should be able to search "all" the access logs for a pattern, not just the current access log. In some of my tests the value we need might be in a rotated log, so still need an option to allow for searching rotated logs.

Thanks!

Supplementary patch to add support for multiple files.
0001-Ticket-48434-lib389-logging-tools.3.patch

Thanks for adding the ability to check compressed and rotated logs! One issue I noticed, you have a sleep of 60 seconds for log buffering, but log buffering is set to 30 seconds by default. So we can probably reduce this sleep time.

Also, it might be best to ignore the rotationinfo files when processing multiple files: access.rotationinfo

I have another side request(we/I can do this in a separate ticket if you want), and that is to have the ability grab log output for debugging. If there is a failure in a test, it would be nice to be able to grab the last ## lines from the errors log, etc.

Thanks,
Mark

Replying to [comment:10 mreynolds]:

Thanks for adding the ability to check compressed and rotated logs! One issue I noticed, you have a sleep of 60 seconds for log buffering, but log buffering is set to 30 seconds by default. So we can probably reduce this sleep time.

Actually, what would be smarter is to disable logbuffering.

Also, it might be best to ignore the rotationinfo files when processing multiple files: access.rotationinfo

This is ignored already by the pattern match "%s.-" on the files.

I have another side request(we/I can do this in a separate ticket if you want), and that is to have the ability grab log output for debugging. If there is a failure in a test, it would be nice to be able to grab the last ## lines from the errors log, etc.

Ohhhh, I like that idea. I think that might need to go in a fixture somewhere though ..... Definitely a separate ticket item.

Latest update adds timestamp parsing code.

Looks good! Ack, but you could have used this function for disablign the log - they are both one liners so I guess it doesn't really matter:

standalone.setAccessLogBuffering(True/False)

commit f320ad53d2b1c973fbc674e0a18705d5ebcfd49a
Writing objects: 100% (6/6), 2.04 KiB | 0 bytes/s, done.
Total 6 (delta 5), reused 0 (delta 0)
To ssh://git.fedorahosted.org/git/389/lib389.git
2aef04f..f320ad5 master -> master

Thanks man, I think I need to write up a design doc, but I want to sit and have a revamp of a few parts of the lib389 library soon, so I'll leave the access log change for the moment ....

commit 924de2f2cf94ba149368475aae2798d8dd52e672

Compressing objects: 100% (6/6), done.
Writing objects: 100% (6/6), 764 bytes | 0 bytes/s, done.
Total 6 (delta 5), reused 0 (delta 0)
To ssh://git.fedorahosted.org/git/389/lib389.git
1f88f1d..924de2f master -> master

Metadata Update from @firstyear:
- Issue assigned to firstyear
- Issue set to the milestone: lib389 1.0.2

7 years ago

389-ds-base is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in 389-ds-base's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/389ds/389-ds-base/issues/1763

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.

Metadata Update from @spichugi:
- Issue close_status updated to: wontfix (was: Fixed)

3 years ago

Login to comment on this ticket.

Metadata