[PATCH] [HBAC]: Better libhbac debuging
by Petr Cech
Hi,
according to
https://fedorahosted.org/sssd/ticket/2703
I tried to add logging to the library HBAC.
A)
Logging is performed using an external function, which you can set by:
# hbac_enable_debug(...)
B)
The specific implementation of such a function, you can see
# hbac_debug_messages(...)
C)
You can specify debug level:
'...' stands for
sssd_cygnus.dev.log:(Fri Jul 24 10:29:36 2015) [sssd[be[cygnus.dev]]]
[hbac] (0x0080): [../src/providers/ipa/
* SSSDBG_MINOR_FAILURE produces:
Question: What kind of information could I add for request into this level?
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:173] DISALLOWED by rule [szabo_allowed].
...hbac_evaluator.c:180] ALLOWED by rule [Test_rule].
...hbac_evaluator.c:214] hbac_evaluate() >]
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:173] DISALLOWED by rule [szabo_allowed].
...hbac_evaluator.c:173] DISALLOWED by rule [Test_rule].
...hbac_evaluator.c:214] hbac_evaluate() >]
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:173] DISALLOWED by rule [szabo_allowed].
...hbac_evaluator.c:173] DISALLOWED by rule [Test_rule].
...hbac_evaluator.c:214] hbac_evaluate() >]
* SSSDBG_TRACE_ALL produces:
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:410] REQUEST:
...hbac_evaluator.c:391] service [sshd]
...hbac_evaluator.c:400] service_group (none)
...hbac_evaluator.c:391] user [csikos]
...hbac_evaluator.c:395] user_group:
...hbac_evaluator.c:397] [ipausers]
...hbac_evaluator.c:391] targethost [albireo.cygnus.dev]
...hbac_evaluator.c:400] targethost_group (none)
...hbac_evaluator.c:391] srchost [192.168.122.106]
...hbac_evaluator.c:400] srchost_group (none)
...hbac_evaluator.c:417] request time Fri Jul 24 14:29:36 2015
...hbac_evaluator.c:454] RULE [szabo_allowed] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:435] services_names (none)
...hbac_evaluator.c:440] services_groups:
...hbac_evaluator.c:442] [Sudo]
...hbac_evaluator.c:462] users:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:435] users_names (none)
...hbac_evaluator.c:445] users_groups (none)
...hbac_evaluator.c:468] targethosts:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] targethosts_names:
...hbac_evaluator.c:432] [albireo.cygnus.dev]
...hbac_evaluator.c:445] targethosts_groups (none)
...hbac_evaluator.c:474] srchosts:
...hbac_evaluator.c:427] category [0x1] [ALL]
...hbac_evaluator.c:173] DISALLOWED by rule [szabo_allowed].
...hbac_evaluator.c:454] RULE [Test_rule] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] services_names:
...hbac_evaluator.c:432] [login]
...hbac_evaluator.c:432] [sshd]
...hbac_evaluator.c:432] [su]
...hbac_evaluator.c:445] services_groups (none)
...hbac_evaluator.c:462] users:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] users_names:
...hbac_evaluator.c:432] [csikos]
...hbac_evaluator.c:445] users_groups (none)
...hbac_evaluator.c:468] targethosts:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] targethosts_names:
...hbac_evaluator.c:432] [albireo.cygnus.dev]
...hbac_evaluator.c:445] targethosts_groups (none)
...hbac_evaluator.c:474] srchosts:
...hbac_evaluator.c:427] category [0x1] [ALL]
...hbac_evaluator.c:180] ALLOWED by rule [Test_rule].
...hbac_evaluator.c:214] hbac_evaluate() >]
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:410] REQUEST:
...hbac_evaluator.c:391] service [systemd-user]
...hbac_evaluator.c:400] service_group (none)
...hbac_evaluator.c:391] user [csikos]
...hbac_evaluator.c:395] user_group:
...hbac_evaluator.c:397] [ipausers]
...hbac_evaluator.c:391] targethost [albireo.cygnus.dev]
...hbac_evaluator.c:400] targethost_group (none)
...hbac_evaluator.c:400] srchost_group (none)
...hbac_evaluator.c:417] request time Fri Jul 24 14:29:36 2015
...hbac_evaluator.c:454] RULE [szabo_allowed] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:435] services_names (none)
...hbac_evaluator.c:440] services_groups:
...hbac_evaluator.c:442] [Sudo]
...hbac_evaluator.c:462] users:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:435] users_names (none)
...hbac_evaluator.c:445] users_groups (none)
...hbac_evaluator.c:468] targethosts:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] targethosts_names:
...hbac_evaluator.c:432] [albireo.cygnus.dev]
...hbac_evaluator.c:445] targethosts_groups (none)
...hbac_evaluator.c:474] srchosts:
...hbac_evaluator.c:427] category [0x1] [ALL]
...hbac_evaluator.c:173] DISALLOWED by rule [szabo_allowed].
...hbac_evaluator.c:454] RULE [Test_rule] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] services_names:
...hbac_evaluator.c:432] [login]
...hbac_evaluator.c:432] [sshd]
...hbac_evaluator.c:432] [su]
...hbac_evaluator.c:445] services_groups (none)
...hbac_evaluator.c:462] users:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] users_names:
...hbac_evaluator.c:432] [csikos]
...hbac_evaluator.c:445] users_groups (none)
...hbac_evaluator.c:468] targethosts:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] targethosts_names:
...hbac_evaluator.c:432] [albireo.cygnus.dev]
...hbac_evaluator.c:445] targethosts_groups (none)
...hbac_evaluator.c:474] srchosts:
...hbac_evaluator.c:427] category [0x1] [ALL]
...hbac_evaluator.c:173] DISALLOWED by rule [Test_rule].
...hbac_evaluator.c:214] hbac_evaluate() >]
...hbac_evaluator.c:150] [< hbac_evaluate()
...hbac_evaluator.c:410] REQUEST:
...hbac_evaluator.c:391] service [sshd]
...hbac_evaluator.c:400] service_group (none)
...hbac_evaluator.c:391] user [szabo]
...hbac_evaluator.c:395] user_group:
...hbac_evaluator.c:397] [ipausers]
...hbac_evaluator.c:391] targethost [albireo.cygnus.dev]
...hbac_evaluator.c:400] targethost_group (none)
...hbac_evaluator.c:391] srchost [192.168.122.106]
...hbac_evaluator.c:400] srchost_group (none)
...hbac_evaluator.c:417] request time Fri Jul 24 14:29:46 2015
...hbac_evaluator.c:454] RULE [szabo_allowed] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:435] services_names (none)
...hbac_evaluator.c:440] services_groups:
...hbac_evaluator.c:442] [Sudo]
...hbac_evaluator.c:462] users:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] users_names:
...hbac_evaluator.c:432] [szabo]
...hbac_evaluator.c:445] users_groups (none)
...hbac_evaluator.c:468] targethosts:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] targethosts_names:
...hbac_evaluator.c:432] [albireo.cygnus.dev]
...hbac_evaluator.c:445] targethosts_groups (none)
...hbac_evaluator.c:474] srchosts:
...hbac_evaluator.c:427] category [0x1] [ALL]
...hbac_evaluator.c:173] DISALLOWED by rule [szabo_allowed].
...hbac_evaluator.c:454] RULE [Test_rule] [ENABLED]:
...hbac_evaluator.c:456] services:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] services_names:
...hbac_evaluator.c:432] [login]
...hbac_evaluator.c:432] [sshd]
...hbac_evaluator.c:432] [su]
...hbac_evaluator.c:445] services_groups (none)
...hbac_evaluator.c:462] users:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] users_names:
...hbac_evaluator.c:432] [csikos]
...hbac_evaluator.c:445] users_groups (none)
...hbac_evaluator.c:468] targethosts:
...hbac_evaluator.c:427] category [0] [NONE]
...hbac_evaluator.c:430] targethosts_names:
...hbac_evaluator.c:432] [albireo.cygnus.dev]
...hbac_evaluator.c:445] targethosts_groups (none)
...hbac_evaluator.c:474] srchosts:
...hbac_evaluator.c:427] category [0x1] [ALL]
...hbac_evaluator.c:173] DISALLOWED by rule [Test_rule].
...hbac_evaluator.c:214] hbac_evaluate() >]
Thanks.
Petr
8 years
RFC: Improving the debug messages
by Jakub Hrozek
Hi,
I spent many hours debugging SSSD in different scenarios last week and I
admit it wasn't always easy -- and I have the source code knowledge I
can use. I imagine it's considerably harder for users and admins..
So this is a brainstorm request on how can we make debugging with SSSD
easier. Maybe there are some low-hanging fruits that can be fixed
easily. Off the top of my head:
- it should be easier to see start and end of a request in the back end.
Instead of:
[be_get_account_info] (0x0200): Got request for [0x1001][1][name=admin]
[acctinfo_callback] (0x0100): Request processed. Returned 0,0,Success (Success)
We could make the debug messages more explicit:
[be_get_account_info] (0x0200): Received request for [object=user][key=name][value=admin]
[acctinfo_callback] (0x0200): Finished request for [object=user][key=name][value=admin]. Returned 0,0,Success
Then we could document the messages in our troubleshooting document.
Please note I'm not proposing to turn debug messages into any kind of
API and keep them the same forever, but decorate the usual flow with
messages that make sense without source level knowledge.
- same for authentication
- same for responder cache requests. We seem to have gotten better with
the new cache_req code there, so this is mostly about using the new
code in all responders. But also the commands we receive from sockets
should be printed in human-readable form.
- Running sssd in environment where all actions complete successfully
should emit no debug messages. Default log level should be moved to
SSSDBG_OP_FAILURE or CRIT_FAILURE. (This basically amounts to checking
all OP, FATAL and CRIT failure messages..)
The reason is that sometimes sssd fails, but because logging is
totally silent, we don't know what happened at all. Currently we have
a couple of small bugs where we might print a loud DEBUG message just
because we search for an entry which is not there etc.
- anything that causes SSSD to fail to start should also emit a syslog
message. Admins don't really know about sssd debug logs.
- our man pages are not structured well, especially the LDAP man page is
too big and contains too many options.
One reason I'm bringing this up now is that we'll have a new SSSD developer
starting soon and these might be nice tasks to start with AND they're
also needed.
8 years
[PATCH] [sssd-1.11] pysss_nss_idmap: Use wrapper for older python
by Lukas Slebodnik
ehlo,
we dropped support for old version of python (<2.6)
in recent version of sssd. It should work in 1.11 branch
but there was a small issue in pysss_nss_idmap bindings.
Attached is a simple patch wich reuse our internal python wrappers.
LS
8 years
[PATCH] DATA_PROVIDER: BE_REQ as string in log message
by Petr Cech
Hi,
I investigated the situation around the log message, which mentioned
Lukas. I prepared this patch. The result is that the original message
> [sssd[be[cygnus.dev]]] [be_get_account_info] (0x0200): Got request
for [0x1001][1][name=celestian]
changed to
> [sssd[be[cygnus.dev]]] [be_get_account_info] (0x0200): Got request
for [0x1001][FAST BE_REQ_USER][1][name=celestian]
A)
I would like to ask if mark 'FAST' is useful, or if I should remove it.
B)
While writing a patch Lukas noticed another similar logging messages
> [sssd[pam]] [sss_dp_get_account_msg] (0x0400): Creating request for
[LDAP][3][1][name=mof_user6]
I investigated it. This is the same thing -- BE_REQ_*, but it is no
longer in the provider, but in the responder. Can you please advise me
where I could the function 'be_req2str' write?
The first message is coming from
> src/providers/data_provider_be.c --> be_get_account_info,
the second is from
> src/responder/common/responder_dp --> sss_dp_get_account_msg
Thanks.
Petr
8 years
[PATCH] Workaround for dyndns_test_ok failiure on mips(el). Child part has finished before the child handler was created.
by Jurica Stanojkovic
Hello,
Package sssd_1.11.5.1-1 on Debian FTBFS for mips and mipsel.
https://buildd.debian.org/status/fetch.php?pkg=sssd&arch=mips&ver=1.11.5....
https://buildd.debian.org/status/fetch.php?pkg=sssd&arch=mipsel&ver=1.11....
dyndns_test_ok is failing with following log:
[ RUN ] dyndns_test_ok(Tue Jul 8 15:53:55:004476 2014) [sssd] [be_nsupdate_args] (0x0200): (Tue Jul 8 15:53:55:004521 2014) [sssd] [child_handler_setup] (0x2000): nsupdate auth type: GSS-TSIGSetting up signal handler up for pid [21397](Tue Jul 8 15:53:55:004693 2014) [sssd] [__wrap_execv] (0x0200): nsupdate success test case(Tue Jul 8 15:53:55:004825 2014) [sssd] [__wrap_execv] (0x1000): Child exiting with status 0(Tue Jul 8 15:53:55:005275 2014) [sssd] [child_handler_setup] (0x2000): Signal handler set up for pid [21397](Tue Jul 8 15:54:55:837623 2014) [sssd] [write_pipe_handler] (0x0020): write failed [32][Broken pipe].(Tue Jul 8 15:54:55:837801 2014) [sssd] [nsupdate_child_stdin_done] (0x1000): Sending nsupdate data complete(Tue Jul 8 15:54:55:837869 2014) [sssd] [nsupdate_child_stdin_done] (0x0040): Sending nsupdate data failed [32]: Broken pipe(Tue Jul 8 15:54:55:837947 2014) [sssd] [be_nsupdate_done] (0x0040): nsupdate child execution failed [1432158228]: Dynamic DNS update failed(Tue Jul 8 15:54:55:837985 2014) [sssd] [dyndns_test_ok] (0x1000): Child request returned [1432158228]: Unknown error 14321582280x555d0014 != 0../src/tests/cmocka/test_dyndns.c:222: error: Failure![ FAILED ] dyndns_test_okChild part has finished before the child handler was created.
I have created and attached a patch which is workaround for this issue.
Could someone please take a look and comment this?
Thank you!
Sincerely,
Jurica
8 years