On a recent rolling (12/30), it appears firewall rules aren't being logged despite having log enable on them.
The fix was simply:
sudo systemctl restart rsyslog
and firewall rules immediately started being logged.
Not sure if this is an ordering problem or what.
It definitely remains in my config:
# show system syslog
global {
facility all {
level info
}
facility protocols {
level debug
}
preserve-fqdn
}
host 10.22.22.108 {
facility all {
level all
protocol udp
}
port 1514
}systemctl renamed it to syslog, so it won't be restarted correctly and the conf script won't generate the files correctly. It is correctly named within init.d.
https://github.com/vyos/vyos-1x/commit/3863e5dc24a622090f52c13f8aa04e5c9f00341a should fix it.
(http://dev.packages.vyos.net/repositories/current/pool/main/v/vyos-1x/vyos-1x_1.3.0-16_all.deb if you want to manually install and test or wait for tomorrows iso).
@hagbard This problem is back on a rolling built on the 14th. Fix again was to run
sudo systemctl restart rsyslog
I've just encountered this bug with Vyos 1.2.5 (final, official ISO)
tim@ferrari# show firewall name LAN-IN
default-action accept
rule 500 {
action drop
description "Drop Camera Internet Traffic"
log enable
source {
address 192.168.0.11-192.168.0.12
}
}
tim@ferrari:~$ sudo dmesg
<snip lots of other logs>
[17307.419805] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=35628 SEQ=86
[17308.420206] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=35628 SEQ=87
[17309.420410] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=35628 SEQ=88
tim@ferrari:~$ show log firewall name LAN-IN rule 500
tim@ferrari:~$ show log firewall name LAN-IN
tim@ferrari:~$Then I've done
sudo systemctl restart rsyslog
And now:
tim@ferrari:~$ show log firewall name LAN-IN rule 500 Apr 15 13:48:08 ferrari kernel: [17008.910748] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=64297 SEQ=0 Apr 15 13:48:08 ferrari kernel: [17009.925573] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=64297 SEQ=1 Apr 15 13:48:08 ferrari kernel: [17012.263513] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=20266 SEQ=0 Apr 15 13:48:08 ferrari kernel: [17013.264533] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=20266 SEQ=1 Apr 15 13:48:08 ferrari kernel: [17014.264657] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=20266 SEQ=2
However the restart trick only seems to work once, additional logs being written to dmesg aren't being logged to the firewall log, even if I restart syslog
Hi @tjh
Thanks for confirming this.
I have also seeing this behavior.
Logs are just buffered somewhere. Everytime you restart syslog they appears and then again start buffering.
And for me the strange thing is this only appears in a physical box. If I run the same image in a vm everything just works fine.
Can you confirm this that for you it is also happening in physical box not in a vm?
Regards
Do they appear in the journal? sudo journalctl -f
I think logs go to systemd-journald first, then are forwarded to rsyslog,
which logs them to files. I've said some time ago, ever since 1.2 moved
to Buster and journald came in, that we should move more to native
journald logging away from rsyslog. I enable persistent journal storage
in /etc/systemd/journald.conf after every upgrade just because of this,
the rsyslog config is buggy/broken, it doesn't log half of what it
should, it stays in journald, so I just use journalctl to look at all
logs. I don't know if journald supports logging to separate files like
rsyslog though, by default it uses its own binary format, I think that
can be changed and maybe rsyslog file behavior moved to journald.
@jjakob No, it's not logged in the journal either:
Note test ping sent with FW rule and logging applied appears in dmesg:
[Sat Apr 25 00:00:07 2020] Process accounting resumed [Sat Apr 25 08:48:13 2020] [LAN-IN-500-D] IN=eth1 OUT=pppoe0 MAC=de:dd:38:7c:da:e9:78:11:dc:70:b9:4d:08:00 SRC=192.168.0.11 DST=139.130.4.5 LEN=84 TOS=0x00 PREC=0x00 TTL=63 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=19726 SEQ=0
But does not appear in journal:
Apr 25 08:47:13 ferrari sudo[32339]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/dmesg Apr 25 08:47:13 ferrari sudo[32339]: pam_unix(sudo:session): session opened for user root by tim(uid=0) Apr 25 08:47:13 ferrari sudo[32339]: pam_unix(sudo:session): session closed for user root Apr 25 08:47:21 ferrari newgrp[32397]: user 'tim' (login 'tim' on pts/1) switched to group 'vyattacfg' Apr 25 08:48:13 ferrari newgrp[32397]: user 'tim' (login 'tim' on pts/1) returned to group 'users' Apr 25 08:48:14 ferrari sudo[32542]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/dmesg Apr 25 08:48:14 ferrari sudo[32542]: pam_unix(sudo:session): session opened for user root by tim(uid=0) Apr 25 08:48:14 ferrari sudo[32542]: pam_unix(sudo:session): session closed for user root Apr 25 08:48:18 ferrari sudo[32544]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/dmesg Apr 25 08:48:18 ferrari sudo[32544]: pam_unix(sudo:session): session opened for user root by tim(uid=0) Apr 25 08:48:18 ferrari sudo[32544]: pam_unix(sudo:session): session closed for user root Apr 25 08:48:40 ferrari sudo[32562]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/journalctl -f Apr 25 08:48:40 ferrari sudo[32562]: pam_unix(sudo:session): session opened for user root by tim(uid=0) Apr 25 08:48:44 ferrari sudo[32562]: pam_unix(sudo:session): session closed for user root Apr 25 08:49:21 ferrari sudo[32581]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/dmesg -T Apr 25 08:49:21 ferrari sudo[32581]: pam_unix(sudo:session): session opened for user root by tim(uid=0) Apr 25 08:49:21 ferrari sudo[32581]: pam_unix(sudo:session): session closed for user root Apr 25 08:49:50 ferrari sudo[32583]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/journalctl -f Apr 25 08:49:50 ferrari sudo[32583]: pam_unix(sudo:session): session opened for user root by tim(uid=0) Apr 25 08:50:00 ferrari sudo[32583]: pam_unix(sudo:session): session closed for user root Apr 25 08:50:03 ferrari sudo[32585]: tim : TTY=pts/1 ; PWD=/home/tim ; USER=root ; COMMAND=/bin/journalctl Apr 25 08:50:03 ferrari sudo[32585]: pam_unix(sudo:session): session opened for user root by tim(uid=0)
@sajiby3k Nice idea re: Virtualised, but my Vyos is in KVM:
tim@ferrari:~$ show version Version: VyOS 1.2.5 Built by: Sentrium S.L. Built on: Sun 12 Apr 2020 15:18 UTC Build UUID: 1695c660-d785-4b16-a54b-66d6a02ea24f Build Commit ID: 48cc9fc46569e6 Architecture: x86_64 Boot via: installed image System type: KVM guest Hardware vendor: QEMU Hardware model: Standard PC (i440FX + PIIX, 1996) Hardware S/N: Hardware UUID: c5e52633-5bc7-4002-afa2-2b5ec2ec5766 Copyright: VyOS maintainers and contributors
I am happy to provide remote access to my Vyos instance to the Vyos devs if you feel testing on a live box would help - This box is just my home Internet router.
My syslog config:
tim@ferrari:~$ conf
show[edit]
tim@ferrari# show system syslog
global {
facility all {
level info
}
facility protocols {
level debug
}
}
host 192.168.0.252 {
facility all {
level debug
protocol udp
}
}
[edit]Just wanted to add an update on this, as of today May-6-2020
Seems like the bug is still present, per @kroy < Thanks a lot for pointing me to the bug number.
As soon as I ran the command sudo systemctl restart rsyslog
I was able to see the log details, but if I try to check for new logs, I will need to run the command again to refresh or like another member said above, I will have to check dmesg messages.
$ show version
Version: VyOS 1.2.5 Built by: Sentrium S.L. Built on: Sun 12 Apr 2020 15:18 UTC Build UUID: 1695c660-d785-4b16-a54b-66d6a02ea24f Build Commit ID: 48cc9fc46569e6 Architecture: x86_64 Boot via: installed image System type: KVM guest Hardware vendor: QEMU Hardware model: Standard PC (i440FX + PIIX, 1996) Hardware S/N: Hardware UUID: 41499136-d501-4949-bd96-ac3cfc1fa2ae Copyright: VyOS maintainers and contributors
Sincerely,
Just adding that I too am experiencing this same issue with 1.2.5 while sending firewall logs to a remote syslog server. Running the command
sudo systemctl restart rsyslog
will show firewall logging for a few seconds before it stops completely. Issuing the command again will result in the same thing - logs for a few seconds and then stop. It appears that logging outside of the firewall still functions as expected as regular console log entries are still being sent.
We are running in a VMware vSphere 6.7 environment. I've reverted back to 1.2.4 for the time being.
Hmmm is it the fact I have a remote syslog configured that triggers this bug?
I didn't realise that, I'll have to remove it and see if it helps.
It's very frustrating not having the firewall logs available to view.
It looks like this bug is in the kernel.
1.2.5 - 4.19.106-amd64
I created iso (for crux) with kernel version - 4.19.114-amd64 and the firewall remote log works fine.
vyos@my-crux:~$ show version Version: VyOS 1.2.5.my Release Train: crux Built by: sever Built on: Wed 24 Jun 2020 13:50 UTC Build UUID: b1633e79-9f67-4147-a1be-576650b94914 Build Commit ID: e2ec2c5dfb2861 Architecture: x86_64 Boot via: installed image System type: KVM guest Hardware vendor: QEMU Hardware model: Standard PC (Q35 + ICH9, 2009) Hardware S/N: Hardware UUID: 5b48a5b7-2fec-4b3f-a3ba-cfa5a2669da4 Copyright: VyOS maintainers and contributors
Tested configuration:
vyos@my-crux:~$ show conf com | match "syslog|firew" set firewall all-ping 'enable' set firewall broadcast-ping 'disable' set firewall config-trap 'disable' set firewall ipv6-receive-redirects 'disable' set firewall ipv6-src-route 'disable' set firewall ip-src-route 'disable' set firewall log-martians 'enable' set firewall name LOCAL-IN default-action 'accept' set firewall name LOCAL-IN enable-default-log set firewall name LOCAL-IN rule 10 action 'accept' set firewall name LOCAL-IN rule 10 destination port '22' set firewall name LOCAL-IN rule 10 protocol 'tcp' set firewall name LOCAL-IN rule 10 source address '192.168.122.0/24' set firewall name LOCAL-IN rule 20 action 'accept' set firewall name LOCAL-IN rule 20 protocol 'icmp' set firewall name LOCAL-IN rule 20 source address '1.1.1.1' set firewall name LOCAL-IN rule 30 action 'drop' set firewall name LOCAL-IN rule 30 log 'enable' set firewall name LOCAL-IN rule 30 protocol 'icmp' set firewall name LOCAL-IN rule 30 source address '8.8.8.8' set firewall receive-redirects 'disable' set firewall send-redirects 'enable' set firewall source-validation 'disable' set firewall syn-cookies 'enable' set firewall twa-hazards-protection 'disable' set interfaces ethernet eth0 firewall local name 'LOCAL-IN' set system syslog global facility all level 'info' set system syslog global facility protocols level 'debug' set system syslog global preserve-fqdn set system syslog host 192.168.122.1 facility all level 'all' set system syslog host 192.168.122.1 facility all protocol 'udp'
Logs from the remote log server:
Jun 24 17:49:05 my-crux kernel: [ 996.589617] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN= Jun 24 17:49:06 my-crux kernel: [ 997.617255] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN= Jun 24 17:49:07 my-crux kernel: [ 998.641222] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN= Jun 24 17:49:08 my-crux kernel: [ 999.665399] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN= Jun 24 17:49:09 my-crux kernel: [ 1000.689109] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN= Jun 24 17:49:10 my-crux kernel: [ 1001.713388] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN= Jun 24 17:49:11 my-crux kernel: [ 1002.737682] [LOCAL-IN-30-D] IN=eth0 OUT= MAC=52:54:00:64:33:ea:52:54:00:52:8b:fd:08:00 SRC=8.8.8.8 DST=192.168.122.11 LEN=