URL:
https://github.com/SSSD/sssd/pull/5585
Title: #5585: Poor man's backtrace.
elkoniu commented:
"""
Small test I did by injecting some debug messages into LDAP `sbus_issue_request_done()`:
```
[sssd.conf]
debug_backtrace_enabled = true
debug_level = 0x3ff0
```
Extra log lines added to code:
```
[src/sbus/router/sbus_router_handler.c]
137 DEBUG(SSSDBG_TRACE_LDB, "11> SSSDBG_TRACE_LDB\n");
138 DEBUG(SSSDBG_BE_FO, "10>SSSDBG_BE_FO\n");
139 DEBUG(SSSDBG_TRACE_ALL, "9> SSSDBG_TRACE_ALL\n");
140 DEBUG(SSSDBG_TRACE_INTERNAL, "8> SSSDBG_TRACE_INTERNAL\n");
141 DEBUG(SSSDBG_TRACE_LIBS, "7> SSSDBG_TRACE_LIBS\n");
142 DEBUG(SSSDBG_TRACE_FUNC, "6> SSSDBG_TRACE_FUNC\n");
143 DEBUG(SSSDBG_FUNC_DATA, "5> SSSDBG_FUNC_DATA\n");
144 DEBUG(SSSDBG_CONF_SETTINGS, "4> SSSDBG_CONF_SETTINGS\n");
145 DEBUG(SSSDBG_MINOR_FAILURE, "3> SSSDBG_MINOR_FAILURE\n");
146 DEBUG(SSSDBG_OP_FAILURE, "2> SSSDBG_OP_FAILURE\n");
147 //DEBUG(SSSDBG_CRIT_FAILURE, "1> SSSDBG_CRIT_FAILURE\n");
148 //DEBUG(SSSDBG_FATAL_FAILURE, "0> SSSDBG_FATAL_FAILURE\n");
149
150 DEBUG(SSSDBG_TRACE_LDB, "11> SSSDBG_TRACE_LDB\n");
151 DEBUG(SSSDBG_BE_FO, "10>SSSDBG_BE_FO\n");
152 DEBUG(SSSDBG_TRACE_ALL, "9> SSSDBG_TRACE_ALL\n");
153 DEBUG(SSSDBG_TRACE_INTERNAL, "8> SSSDBG_TRACE_INTERNAL\n");
154 DEBUG(SSSDBG_TRACE_LIBS, "7> SSSDBG_TRACE_LIBS\n");
155 DEBUG(SSSDBG_TRACE_FUNC, "6> SSSDBG_TRACE_FUNC\n");
156 DEBUG(SSSDBG_FUNC_DATA, "5> SSSDBG_FUNC_DATA\n");
157 DEBUG(SSSDBG_CONF_SETTINGS, "4> SSSDBG_CONF_SETTINGS\n");
158 DEBUG(SSSDBG_MINOR_FAILURE, "3> SSSDBG_MINOR_FAILURE\n");
159 //DEBUG(SSSDBG_OP_FAILURE, "2> SSSDBG_OP_FAILURE\n");
160 DEBUG(SSSDBG_CRIT_FAILURE, "1> SSSDBG_CRIT_FAILURE\n");
161 //DEBUG(SSSDBG_FATAL_FAILURE, "0> SSSDBG_FATAL_FAILURE\n");
162
163 DEBUG(SSSDBG_TRACE_LDB, "11> SSSDBG_TRACE_LDB\n");
164 DEBUG(SSSDBG_BE_FO, "10>SSSDBG_BE_FO\n");
165 DEBUG(SSSDBG_TRACE_ALL, "9> SSSDBG_TRACE_ALL\n");
166 DEBUG(SSSDBG_TRACE_INTERNAL, "8> SSSDBG_TRACE_INTERNAL\n");
167 DEBUG(SSSDBG_TRACE_LIBS, "7> SSSDBG_TRACE_LIBS\n");
168 DEBUG(SSSDBG_TRACE_FUNC, "6> SSSDBG_TRACE_FUNC\n");
169 DEBUG(SSSDBG_FUNC_DATA, "5> SSSDBG_FUNC_DATA\n");
170 DEBUG(SSSDBG_CONF_SETTINGS, "4> SSSDBG_CONF_SETTINGS\n");
171 DEBUG(SSSDBG_MINOR_FAILURE, "3> SSSDBG_MINOR_FAILURE\n");
172 //DEBUG(SSSDBG_OP_FAILURE, "2> SSSDBG_OP_FAILURE\n");
173 //DEBUG(SSSDBG_CRIT_FAILURE, "1> SSSDBG_CRIT_FAILURE\n");
174 DEBUG(SSSDBG_FATAL_FAILURE, "0> SSSDBG_FATAL_FAILURE\n");
175
176 DEBUG(SSSDBG_TRACE_LDB, "11> SSSDBG_TRACE_LDB\n");
177 DEBUG(SSSDBG_BE_FO, "10>SSSDBG_BE_FO\n");
178 DEBUG(SSSDBG_TRACE_ALL, "9> SSSDBG_TRACE_ALL\n");
179 DEBUG(SSSDBG_TRACE_INTERNAL, "8> SSSDBG_TRACE_INTERNAL\n");
180 DEBUG(SSSDBG_TRACE_LIBS, "7> SSSDBG_TRACE_LIBS\n");
181 DEBUG(SSSDBG_TRACE_FUNC, "6> SSSDBG_TRACE_FUNC\n");
182 DEBUG(SSSDBG_FUNC_DATA, "5> SSSDBG_FUNC_DATA\n");
183 DEBUG(SSSDBG_CONF_SETTINGS, "4> SSSDBG_CONF_SETTINGS\n");
184 DEBUG(SSSDBG_MINOR_FAILURE, "3> SSSDBG_MINOR_FAILURE\n");
185 DEBUG(SSSDBG_OP_FAILURE, "2> SSSDBG_OP_FAILURE\n");
186 DEBUG(SSSDBG_CRIT_FAILURE, "1> SSSDBG_CRIT_FAILURE\n");
187 DEBUG(SSSDBG_FATAL_FAILURE, "0> SSSDBG_FATAL_FAILURE\n");
```
Result log with backtrace:
```
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0040): 2>
SSSDBG_OP_FAILURE
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400):
org.freedesktop.DBus.NameOwnerChanged: Success
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_dispatch] (0x4000): Dispatching.
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_dispatch] (0x4000): Dispatching.
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_method_handler] (0x2000): Received D-Bus
method sssd.dataprovider.getDomains on /sssd
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_senders_lookup] (0x2000): Looking for
identity of sender [sssd.nss]
* (2021-04-28 21:42:47): [be[ldap.vm]] [dp_attach_req] (0x0400): DP Request
[Subdomains #3]: New request. Flags [0000].
* (2021-04-28 21:42:47): [be[ldap.vm]] [dp_attach_req] (0x0400): Number of active DP
request: 1
* (2021-04-28 21:42:47): [be[ldap.vm]] [dp_find_method] (0x0100): Target [subdomains]
is not initialized
* (2021-04-28 21:42:47): [be[ldap.vm]] [_dp_req_recv] (0x0400): DP Request [Subdomains
#3]: Receiving request data.
* (2021-04-28 21:42:47): [be[ldap.vm]] [dp_req_destructor] (0x0400): DP Request
[Subdomains #3]: Request removed.
* (2021-04-28 21:42:47): [be[ldap.vm]] [dp_req_destructor] (0x0400): Number of active
DP request: 0
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x8000):
10>SSSDBG_BE_FO
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x4000): 9>
SSSDBG_TRACE_ALL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0040): 2>
SSSDBG_OP_FAILURE
********************** BACKTRACE DUMP ENDS HERE *********************************
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0020): 1>
SSSDBG_CRIT_FAILURE
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x8000):
10>SSSDBG_BE_FO
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x4000): 9>
SSSDBG_TRACE_ALL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0020): 1>
SSSDBG_CRIT_FAILURE
********************** BACKTRACE DUMP ENDS HERE *********************************
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0010): 0>
SSSDBG_FATAL_FAILURE
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x8000):
10>SSSDBG_BE_FO
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x4000): 9>
SSSDBG_TRACE_ALL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0010): 0>
SSSDBG_FATAL_FAILURE
********************** BACKTRACE DUMP ENDS HERE *********************************
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0040): 2>
SSSDBG_OP_FAILURE
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x8000):
10>SSSDBG_BE_FO
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x4000): 9>
SSSDBG_TRACE_ALL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x2000): 8>
SSSDBG_TRACE_INTERNAL
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x1000): 7>
SSSDBG_TRACE_LIBS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0400): 6>
SSSDBG_TRACE_FUNC
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0200): 5>
SSSDBG_FUNC_DATA
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0100): 4>
SSSDBG_CONF_SETTINGS
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0080): 3>
SSSDBG_MINOR_FAILURE
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0040): 2>
SSSDBG_OP_FAILURE
********************** BACKTRACE DUMP ENDS HERE *********************************
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0020): 1>
SSSDBG_CRIT_FAILURE
(2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0010): 0>
SSSDBG_FATAL_FAILURE
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0020): 1>
SSSDBG_CRIT_FAILURE
* (2021-04-28 21:42:47): [be[ldap.vm]] [sbus_issue_request_done] (0x0010): 0>
SSSDBG_FATAL_FAILURE
********************** BACKTRACE DUMP ENDS HERE *********************************
```
Result:
- `SSSDBG_TRACE_LDB` is not covered by `debug_level = 0x3ff0` and it is not included in
backtrace `_all_levels_enabled()` so it is not presented in logs and backtrace dump
- `SSSDBG_TRACE_ALL` and `SSSDBG_BE_FO` are not covered by `debug_level = 0x3ff0` but are
included in backtrace `_all_levels_enabled()` so they are not presented in logs but
presented in backtrace dump
- `SSSDBG_FATAL_FAILURE`, `SSSDBG_CRIT_FAILURE` and `SSSDBG_OP_FAILURE` triggers
backtrace dump
- with situation where two backtrace triggers are close to each other having treshold in
`_bt_empty()` set to `2` is the right choice
"""
See the full comment at
https://github.com/SSSD/sssd/pull/5585#issuecomment-828810740