URL:
https://github.com/SSSD/sssd/pull/5712
Title: #5712: Health and Support Analyzer - Add request log parsing utility
alexey-tikhonov commented:
"""
Hi,
I played with a tool a bit.
1) About `--cid` parsing:
```
# sssctl analyze request --cid
usage: sss_analyze request [-h] [--list] [--cid CID] [--pam] [--cachereq]
sss_analyze request: error: argument --cid: expected one argument
-- ok
# sssctl analyze request --cid=
-- nothing, feels weird
# sssctl analyze request --cid=z
******** Checking nss responder for Client ID{client_id} *******
********* Checking Backend for Client ID z ********
-- wouldn't it make sense to say something like "id 'z' not
found"?
```
2) It seems `{client_id}` is printed instead of var value:
```
# sssctl analyze request --cid=711
******** Checking nss responder for Client ID{client_id} *******
(2021-07-22 19:58:05:232246): [nss] [cache_req_send] (0x0400): CR #1111: REQ_TRACE: New
request [CID #711] 'Service by name'
********* Checking Backend for Client ID 711 ********
```
3) Sometime line is dulicated in backend logs:
```
********* Checking Backend for Client ID 711 ********
(2021-07-22 19:58:05): [be[ipasubid2.test]] [dp_attach_req] (0x0400): [RID#200] DP Request
[Account #200]: REQ_TRACE: New request. [sssd.nss CID #711] Flags [0x0001].
(2021-07-22 19:58:05): [be[ipasubid2.test]] [dp_attach_req] (0x0400): [RID#200] DP Request
[Account #200]: REQ_TRACE: New request. [sssd.nss CID #711] Flags [0x0001].
(2021-07-22 19:58:05): [be[ipasubid2.test]] [dp_attach_req] (0x0400): [RID#200] Number of
active DP request: 1
(2021-07-22 19:58:05): [be[ipasubid2.test]] [sss_domain_get_state] (0x1000): [RID#200]
Domain ipasubid2.test is Active
```
(`grep` yields single "DP Request [Account..." line)
4) When responder is restarted, `CID` is reset and log can contain multiple unrelated
requests with the same CID. Tool greps everything and this might be misleading. There is
enough info in the logs to catch this, but not very simple.
5) Probably `--merge` option to merge responder and backend logs into single log (sorted
by timestamp) might make some sense (not sure).
6) What are we going to do with long running clients that issue thousands of requests per
single connection? Currently tool will grep everything. It definitely makes sense for case
like `id user`, but not for a long running process like db. Probably `--cr=N` option would
make sense?
7) (Most important)
Currently `--list` output looks like:
```
(2021-07-22 21:33:21:956195): [nss] [accept_fd_handler] (0x0400): Client [CID #3][cmd
id][0xd18ac0][27] connected!
```
This looks very similar to `grep` output.
At the very least I would shorten this to:
```
2021-07-22 21:33:21:956195: CID #3: cmd='id'
```
-- all those `[nss] [accept_fd_handler] (0x0400)` doesn't add value here but makes
reading more difficult.
Ideally output could look like following:
```
2021-07-22 21:33:21:956195: CID #3: cmd='id', cache requests:
- 'User by name' : 'rpc'
- 'Group by ID' : '32'
- 'Initgroups by name' : 'rpc'
...
```
But this is, of course, not very trivial and again, we need to handle case of long running
process that does a lot of requests under the same CID.
"""
See the full comment at
https://github.com/SSSD/sssd/pull/5712#issuecomment-885206857