tac_plus-ng: syslog facility
beranf opened this issue · 7 comments
Hi Marc,
settings syslog facility at tac_plus-ng works properly only with destination = <ip address>
example of working config:
log authclog { destination = <ip_ address>
syslog facility = local4
}
As soon as configuration above is combined either with a custom format and/or destination = syslog then facility is not applied. Real my examples are below:
1) not working facility with destination = <ip_address> + custom format:
log authclog { destination = 100.64.37.29
authentication format = "%Y-%m-%d %H:%M:%S %z \t${server.address}\t${type}\tnas=${nas}\tuser=${user}\tport=${port}\tnac=${nac}\trule={rule}\tlabel={label}\tidentity-source={identity-source}\taction=${action} ${hint}\n"
syslog facility = local4
}
log authzlog { destination = 100.64.37.29
authorization format = "%Y-%m-%d %H:%M:%S %z\t${server.address}\t${type}\tnas=${nas}\tuser=${user}\tport=${port}\tnac=${nac}\tprofile=${profile}\tresult=${result}\tservice=${service}\tcmd=${cmd}\n"
syslog facility = local5
}
log acctlog { destination = 100.64.37.29
syslog facility = local6
}
accounting log = acctlog
authentication log = authclog
authorization log = authzlog
In the attached file syslog_custom_format.zip, you can see that only facility6 at accounting events is applied facility4 and facility5 aren't applied int authentication and authorization events.
2) not working facility with destination = syslog:
If applied destination = syslog then it seems facility probably does not work either. It does not matter if format is default or custom.
log authclog { destination = syslog
authentication format = "%Y-%m-%d %H:%M:%S %z \t${server.address}\t${type}\tnas=${server.address}\tuser=${user}\tport=${port}\tnac=${nac}\trule={rule}\tlabel={label}\tidentity-source={identity-source}\taction=${action} ${hint}\n"
syslog facility = local4
}
log authzlog { destination = syslog
authorization format = "%Y-%m-%d %H:%M:%S %z\t${server.address}\tnas=${nas}\tuser=${user}\tport=${port}\tnac=${nac}\tprofile=${profile}\tresult=${result}\tservice=${service}\tcmd=${cmd}\n"
syslog facility = local5
}
log acctlog { destination = syslog
syslog facility = local6
}
accounting log = acctlog
authentication log = authclog
authorization log = authzlog
My specific rsysylog configuration is applied in /etc/rsyslog.d/50-tac_plus.conf file:
local4.* /var/log/tac_plus/authc.log
local5.* /var/log/tac_plus/authz.log
local6.* /var/log/tac_plus/acct.log
At least my rsyslogd does not see any facility at tac_plus-ng events and write all of them into /var/log/messages file.
I don't know what is the best way to troubleshoot rsyslog input events queue, so I was only able to check rsyslog debug output where I can find only events with default format and no events with my custom configured format. Below is an authentication example event what I was able to find in rsyslog debug (strange the authentication event should have custom format but it has default format):
4356.411217575:main Q:Reg/w0 : ruleset.c: processBATCH: next msg 23: 100.64.67.2|test_admin1@fbe-test.local|tty10|100.64.226.2|shell login succeeded
4356.411238447:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local4.*'
4356.411277916:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X FF X X X X X
4356.411595218:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
4356.411603932:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local5.*'
4356.411621304:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X FF X X X X
4356.411774726:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
4356.411780635:main Q:Reg/w0 : rainerscript.c: PRIFILT 'local6.*'
4356.411807775:main Q:Reg/w0 : rainerscript.c: pmask: X X X X X X X X X X X X X X X X X X X X X X FF X X X
4356.412002137:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 0
4356.412021000:main Q:Reg/w0 : rainerscript.c: PRIFILT '*.info;mail.none;authpriv.none;cron.none'
4356.412082494:main Q:Reg/w0 : rainerscript.c: pmask: 7F 7F X 7F 7F 7F 7F 7F 7F X X 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F 7F
4356.412277868:main Q:Reg/w0 : ruleset.c: PRIFILT condition result is 1
4356.412313707:main Q:Reg/w0 : rainerscript.c: ACTION 3 [builtin:omfile:/var/log/messages]
4356.412354651:main Q:Reg/w0 : ruleset.c: executing action 3
Please could you verify/check facility behavior at your environment?
Thank you,
Regards,
Filip
Hi Filip,
for log definitions with "destination = ip-address": The custom format must include the priority prefix ("<${priority}>%Y-%m-...").
Regarding "destination = syslog": I got the "openlog" facility argument wrong, I'll push a fix. Thanks!
Cheers,
Marc
Hi Filip,
is it ok to close this issue?
Cheers,
Marc
Closed. Please open a new issue if the problem persists.
Cheers,
Marc
Hi Marc,
sorry for my quite delay answer.
Actually facility is working fine also with destination = syslog, thank you!
Unfortunately one strange thing to troubleshooting described below (maybe regarding a text transcoding issue or incorrect clearing variable ???).
At logging athorization events with destination = syslog some logged messages contains a binary values like:
\000\000\000\000\000\000\002\000\377\377\377 \377
My authorization config on tac_plus-ng side:
log authzlog {
authorization format = "${type}|nas=${device.address}|user='${user}'|port='${port}'|nac='${client.address}'|rule='${rule}'|rulset-label='${label}'|profile='${profile}'|result='${result}'|service='${service}'|cmd='${cmd}'\n"
destination = syslog
syslog facility = local5
}
authorization log = authzlog
Example of an issue events logged internally by tac-plus-ng shows everything fine (no binary values):
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 New session
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 ---<start packet>---
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 key used: MySecurityKey123
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 version: 192, type: 2, seq no: 1, flags: unencrypted
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 session id: 3e54bfd8, data length: 46
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 packet body (len: 46): \006\000\002\003\v\003\000\002\v\vtest_admin1sshservice=pppprotocol=ip
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 0000 06 00 02 03 0b 03 00 02 0b 0b 74 65 73 74 5f 61 ........ ..test_a
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 0010 64 6d 69 6e 31 73 73 68 73 65 72 76 69 63 65 3d dmin1ssh service=
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 0020 70 70 70 70 72 6f 74 6f 63 6f 6c 3d 69 70 pppproto col=ip
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 AUTHOR, priv_lvl=0
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 authen_type=pap (2)
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 authen_method=tacacs+ (6)
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 service=ppp (3)
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 user_len=11 port_len=3 rem_addr_len=0 arg_cnt=2
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 user (len: 11): test_admin1
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 port (len: 3): ssh
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 rem_addr (len: 0):
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 arg[0] (len: 11): service=ppp
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 arg[1] (len: 11): protocol=ip
245618: 23:03:02.219 2/d8bf543e: 100.64.67.3 ---<end packet>---
Then the same event logged by rsyslogd (here is logged strange value at cmd= like '\000...'):
2023-08-03 23:03:02.2270 tacplus[245618]:author|nas=100.64.67.3|user='test_admin1@fbe-test.local'|port='ssh'|nac=''|rule='REMOTE_ActiveDirectory_ADMIN'|rulset-label=''|profile='Admin'|result='permit'|service='ppp'|cmd='\000\000\000\000\000\000\002\000\377\377\377 \377rotocol=ip'
Thank you,
Regards,
Filip
Hi Filip,
thanks, I'll push a fix within the next couple of minutes.
Cheers,
Marc
Hi Marc,
thanks! Binary values from rsyslog messages disappeard :-).
But another issue arises :-(.
Actually if a cisco IOS device sends command="configure terminal" to tac_plus-ng to authorize then tac_plus-ng crashes:
248136: 00:07:23.645 1/be83329f: 100.64.67.2 New session
248136: 00:07:23.645 1/be83329f: 100.64.67.2 ---<start packet>---
248136: 00:07:23.645 1/be83329f: 100.64.67.2 key used: MySecurityKey123
248136: 00:07:23.645 1/be83329f: 100.64.67.2 version: 192, type: 2, seq no: 1, flags: unencrypted
248136: 00:07:23.645 1/be83329f: 100.64.67.2 session id: 9f3283be, data length: 94
248136: 00:07:23.645 1/be83329f: 100.64.67.2 packet body (len: 94): \001\017\001\000\v\005\f\004\r\r\020\ftest_admin1tty10100.64.226.2service=shellcmd=configurecmd-arg=terminalcmd-arg=<cr>
248136: 00:07:23.645 1/be83329f: 100.64.67.2 0000 01 0f 01 00 0b 05 0c 04 0d 0d 10 0c 74 65 73 74 ........ ....test
248136: 00:07:23.645 1/be83329f: 100.64.67.2 0010 5f 61 64 6d 69 6e 31 74 74 79 31 30 31 30 30 2e _admin1t ty10100.
248136: 00:07:23.645 1/be83329f: 100.64.67.2 0020 36 34 2e 32 32 36 2e 32 73 65 72 76 69 63 65 3d 64.226.2 service=
248136: 00:07:23.645 1/be83329f: 100.64.67.2 0030 73 68 65 6c 6c 63 6d 64 3d 63 6f 6e 66 69 67 75 shellcmd =configu
248136: 00:07:23.645 1/be83329f: 100.64.67.2 0040 72 65 63 6d 64 2d 61 72 67 3d 74 65 72 6d 69 6e recmd-ar g=termin
248136: 00:07:23.645 1/be83329f: 100.64.67.2 0050 61 6c 63 6d 64 2d 61 72 67 3d 3c 63 72 3e alcmd-ar g=<cr>
248136: 00:07:23.645 1/be83329f: 100.64.67.2 AUTHOR, priv_lvl=15
248136: 00:07:23.645 1/be83329f: 100.64.67.2 authen_type=ascii (1)
248136: 00:07:23.645 1/be83329f: 100.64.67.2 authen_method=none (1)
248136: 00:07:23.645 1/be83329f: 100.64.67.2 service=unknown (0)
248136: 00:07:23.645 1/be83329f: 100.64.67.2 user_len=11 port_len=5 rem_addr_len=12 arg_cnt=4
248136: 00:07:23.645 1/be83329f: 100.64.67.2 user (len: 11): test_admin1
248136: 00:07:23.645 1/be83329f: 100.64.67.2 port (len: 5): tty10
248136: 00:07:23.645 1/be83329f: 100.64.67.2 rem_addr (len: 12): 100.64.226.2
248136: 00:07:23.645 1/be83329f: 100.64.67.2 arg[0] (len: 13): service=shell
248136: 00:07:23.645 1/be83329f: 100.64.67.2 arg[1] (len: 13): cmd=configure
248136: 00:07:23.645 1/be83329f: 100.64.67.2 arg[2] (len: 16): cmd-arg=terminal
248136: 00:07:23.645 1/be83329f: 100.64.67.2 arg[3] (len: 12): cmd-arg=<cr>
248136: 00:07:23.645 1/be83329f: 100.64.67.2 ---<end packet>---
248136: 00:07:23.645 1/be83329f: 100.64.67.2 Start authorization request
248136: 00:07:23.645 1/be83329f: 100.64.67.2 pcre2: '.*@.*$' <=> 'test_admin1' = 0
248136: 00:07:23.645 1/be83329f: 100.64.67.2 line 79: [user] <pcre-regex> '.*@.*$' => false
248136: 00:07:23.645 1/be83329f: 100.64.67.2 line 79: [!] => true
248136: 00:07:23.645 1/be83329f: 100.64.67.2 pcre2: '^(user0[0-9]|test_fb)$' <=> 'test_admin1' = 0
248136: 00:07:23.645 1/be83329f: 100.64.67.2 line 79: [user] <pcre-regex> '^(user0[0-9]|test_fb)$' => false
248136: 00:07:23.645 1/be83329f: 100.64.67.2 line 79: [!] => true
248136: 00:07:23.645 1/be83329f: 100.64.67.2 line 79: [&&] => true
248136: 00:07:23.645 1/be83329f: 100.64.67.2 pcre2: '^.*$' <=> 'test_admin1' = 1
248136: 00:07:23.645 1/be83329f: 100.64.67.2 pcre2: setting username to 'test_admin1@fbe-test.local'
248136: 00:07:23.645 1/be83329f: 100.64.67.2 line 80: [rewrite]
malloc(): invalid next size (unsorted)
Aborted (core dumped)
My rewrite rule configuration:
Other commands are processing normal way by tac_plus-ng without any interruption/crash. Only command="configure terminal" causes a crash.
Regards,
Filip
Hi Filip,
fixed, thanks. Weirdly, this caused no immediate issues on my non-x64 development system but crashed immediately on x64 :-(
Cheers,
Marc