Logging changes for __FUNC__, errno and debug guards
Hi again all, while the previous logging changes I've been working on have all been non-intrusive - i.e. no touching any zlog_* or flog_* lines - there are a few things I'd like to do at some point that do touch a lot of the zlog_* lines: - "factor out" strerror() / errno printing. This is why "flog_err_sys" exists, it currently does the exact same thing as "flog_err" but the idea is that "flog_err_sys" is used when there's some system error and errno is valid. The logging code would print strerror() automatically without this being a parameter. And we can put errno into a keyword, like systemd-journald has with "ERRNO=". flog_err_sys is already being used in quite a bit of the code, but this would need some double checking, and the strerror() argument would be removed. - "factor out" the __FUNC__ argument used on a lot of debug calls. The logging code can prefix *all* debug messages with the calling function name, without this being an extra parameter to the call. Also, RFC5424 and journald log targets can include the file/line/func information in the message metadata. - the debug guards could use a dump of massage units too - assimilating the if() into the macro and getting rid of the indentation level. We already have DEBUG*() in lib/debug.h plus debugf() in nhrpd/debug.h & babeld/util.h. These 3 should be unified and zlog_debug() marked deprecated (i.e. warning on any unguarded debugs) A particular consideration for this last item is the "parametrized debugs", e.g. "debug bgp neighbor-events <A.B.C.D|X:X::X:X|WORD>" A lot of this stuff can be done with coccinelle, but it'll be a large and annoying change, so I'd like to discuss *what* and *when* to do it here. (For starters, the 2nd and 3rd thing should happen at the same time since it's affecting most/all zlog_debug() calls.) None of this is "urgent" and a lot could also be done in smaller steps, e.g. converting babeld & nhrpd first. I'd also make these non-breaking changes as much as possible, i.e. have old & new forms both work for some period of time. Opinions & Comments? -David
All of these changes sound positive to me. Regarding usage of __FUNC__, I'm not sure if I agree on prefixing all debug messages with the function name. IMO text logs (ie no additional metadata) ought to be kept minimally noisy - if you reach a point where you need to know the function the log message originates from, there are plenty of other ways to do that, like RFC5424, perf, gdb, etc. IMO debugs are "INFO++" logs, something still intended for a user audience, just in excruciating detail. Your proposed path of going for alpha daemons first sounds good to me. As for when, at your leisure, I suppose. ________________________________________ From: dev <dev-bounces@lists.frrouting.org> on behalf of David Lamparter <equinox@diac24.net> Sent: Tuesday, April 13, 2021 4:09 PM To: dev Subject: [dev] Logging changes for __FUNC__, errno and debug guards External email: Use caution opening links or attachments Hi again all, while the previous logging changes I've been working on have all been non-intrusive - i.e. no touching any zlog_* or flog_* lines - there are a few things I'd like to do at some point that do touch a lot of the zlog_* lines: - "factor out" strerror() / errno printing. This is why "flog_err_sys" exists, it currently does the exact same thing as "flog_err" but the idea is that "flog_err_sys" is used when there's some system error and errno is valid. The logging code would print strerror() automatically without this being a parameter. And we can put errno into a keyword, like systemd-journald has with "ERRNO=". flog_err_sys is already being used in quite a bit of the code, but this would need some double checking, and the strerror() argument would be removed. - "factor out" the __FUNC__ argument used on a lot of debug calls. The logging code can prefix *all* debug messages with the calling function name, without this being an extra parameter to the call. Also, RFC5424 and journald log targets can include the file/line/func information in the message metadata. - the debug guards could use a dump of massage units too - assimilating the if() into the macro and getting rid of the indentation level. We already have DEBUG*() in lib/debug.h plus debugf() in nhrpd/debug.h & babeld/util.h. These 3 should be unified and zlog_debug() marked deprecated (i.e. warning on any unguarded debugs) A particular consideration for this last item is the "parametrized debugs", e.g. "debug bgp neighbor-events <A.B.C.D|X:X::X:X|WORD>" A lot of this stuff can be done with coccinelle, but it'll be a large and annoying change, so I'd like to discuss *what* and *when* to do it here. (For starters, the 2nd and 3rd thing should happen at the same time since it's affecting most/all zlog_debug() calls.) None of this is "urgent" and a lot could also be done in smaller steps, e.g. converting babeld & nhrpd first. I'd also make these non-breaking changes as much as possible, i.e. have old & new forms both work for some period of time. Opinions & Comments? -David _______________________________________________ dev mailing list dev@lists.frrouting.org https://nam11.safelinks.protection.outlook.com/?url=https%3A%2F%2Flists.frrouting.org%2Flistinfo%2Fdev&data=04%7C01%7Cqlyoung%40nvidia.com%7Cd73d518794684f2e2cf908d8feb88b9e%7C43083d15727340c1b7db39efd9ccc17a%7C0%7C1%7C637539415868676089%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=tVtplqJ67Ga8gOnZcywPXrMNt5Dvl9LGQQnDptl1wVs%3D&reserved=0
participants (2)
-
David Lamparter -
Quentin Young