Logging
The following scenarios show how to configure the conntrack logging option with different traffic policies and services enabled, in order to check that all fields are displayed correctly and all events are captured.
Test new events
Description
Test to check NEW sessions events are captured
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set system conntrack logging events new set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.976 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.976/0.976/0.976/0.000 ms
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.370 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.370/0.370/0.370/0.000 ms
Step 5: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[NEW\].*SRC=192.168.100.2Show output
Dec 04 16:22:51.283796 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.3M free. Dec 04 16:22:51.284898 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:22:51.284937 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:22:51.295782 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:22:51.602384 osdx osdx-coredump[295070]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:22:51.610188 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:22:52.079712 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:22:52.161812 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:22:52.269935 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. Dec 04 16:22:52.346380 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:22:52.464920 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:22:52.561312 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:22:52.563953 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Dec 04 16:22:52.566617 osdx ulogd[295155]: registering plugin `NFCT' Dec 04 16:22:52.567402 osdx ulogd[295155]: registering plugin `IP2STR' Dec 04 16:22:52.567459 osdx ulogd[295155]: registering plugin `PRINTFLOW' Dec 04 16:22:52.568380 osdx ulogd[295155]: registering plugin `SYSLOG' Dec 04 16:22:52.568387 osdx ulogd[295155]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:22:52.568428 osdx ulogd[295155]: NFCT plugin working in event mode Dec 04 16:22:52.568433 osdx ulogd[295155]: Changing UID / GID Dec 04 16:22:52.568504 osdx ulogd[295155]: initialization finished, entering main loop Dec 04 16:22:52.576971 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:22:52.578457 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:22:52.604347 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:22:52.618834 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:22:53.376509 osdx ulogd[295155]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:22:53.446680 osdx ulogd[295155]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
Test update events
Description
Test to check UPDATE sessions events are captured
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set system conntrack logging events update set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.806 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.806/0.806/0.806/0.000 ms
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.291 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.291/0.291/0.291/0.000 ms
Step 5: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[UPDATE\].*SRC=192.168.100.2Show output
Dec 04 16:22:57.281881 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.2M free. Dec 04 16:22:57.283394 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:22:57.283447 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:22:57.290656 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:22:57.584086 osdx osdx-coredump[295298]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:22:57.590919 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:22:58.025288 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:22:58.047682 osdx zebra[1204]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Dec 04 16:22:58.089256 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:22:58.171591 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. Dec 04 16:22:58.236713 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:22:58.359396 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:22:58.463767 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:22:58.464749 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Dec 04 16:22:58.465180 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:22:58.466369 osdx ulogd[295383]: registering plugin `NFCT' Dec 04 16:22:58.466408 osdx ulogd[295383]: registering plugin `IP2STR' Dec 04 16:22:58.466443 osdx ulogd[295383]: registering plugin `PRINTFLOW' Dec 04 16:22:58.466459 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:22:58.466482 osdx ulogd[295383]: registering plugin `SYSLOG' Dec 04 16:22:58.466485 osdx ulogd[295383]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:22:58.466523 osdx ulogd[295383]: NFCT plugin working in event mode Dec 04 16:22:58.466529 osdx ulogd[295383]: Changing UID / GID Dec 04 16:22:58.466597 osdx ulogd[295383]: initialization finished, entering main loop Dec 04 16:22:58.491811 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:22:58.510395 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:22:59.258980 osdx ulogd[295383]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:22:59.326673 osdx ulogd[295383]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
Test destroy events
Description
Test to check DESTROY sessions events are captured
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set service ssh set system conntrack logging events destroy set system conntrack timeout icmp 1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.372 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.372/0.372/0.372/0.000 ms
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 3 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.378 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.636 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.534 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2030ms rtt min/avg/max/mdev = 0.378/0.516/0.636/0.106 ms
Step 5: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[DESTROY\].*SRC=192.168.100.2Show output
Dec 04 16:23:03.351824 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.3M free. Dec 04 16:23:03.352373 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:23:03.352414 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:23:03.362903 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:23:03.715993 osdx osdx-coredump[295531]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:23:03.725594 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:23:04.177905 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:04.257067 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:23:04.345114 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. Dec 04 16:23:04.410016 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Dec 04 16:23:04.517073 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service ssh'. Dec 04 16:23:04.618560 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:04.752386 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:04.852662 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:04.853619 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Dec 04 16:23:04.854195 osdx ulogd[295626]: registering plugin `NFCT' Dec 04 16:23:04.854270 osdx ulogd[295626]: registering plugin `IP2STR' Dec 04 16:23:04.854343 osdx ulogd[295626]: registering plugin `PRINTFLOW' Dec 04 16:23:04.854423 osdx ulogd[295626]: registering plugin `SYSLOG' Dec 04 16:23:04.854429 osdx ulogd[295626]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:04.854504 osdx ulogd[295626]: NFCT plugin working in event mode Dec 04 16:23:04.854516 osdx ulogd[295626]: Changing UID / GID Dec 04 16:23:04.854642 osdx ulogd[295626]: initialization finished, entering main loop Dec 04 16:23:04.860393 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:04.906620 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Dec 04 16:23:04.924244 osdx sshd[295632]: Server listening on 0.0.0.0 port 22. Dec 04 16:23:04.924268 osdx sshd[295632]: Server listening on :: port 22. Dec 04 16:23:04.924434 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Dec 04 16:23:04.949580 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:04.980046 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:05.000126 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:07.016107 osdx ulogd[295626]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 Dec 04 16:23:08.017549 osdx ulogd[295626]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84
Test default logging
Description
Set a simple configuration, send a ping
command from one device to other
and check that default fields appear when running system journal show
.
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set system conntrack logging events all set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.372 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.372/0.372/0.372/0.000 ms
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.361 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.361/0.361/0.361/0.000 ms
Step 5: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Dec 04 16:23:14.339718 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.3M free. Dec 04 16:23:14.343606 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:23:14.343663 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:23:14.351855 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:23:14.675427 osdx osdx-coredump[295800]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:23:14.682935 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:23:15.118977 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:15.182486 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:23:15.266217 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Dec 04 16:23:15.330952 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:15.455595 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:15.523418 osdx zebra[1204]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Dec 04 16:23:15.571913 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:15.572663 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Dec 04 16:23:15.572989 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:15.573500 osdx ulogd[295885]: registering plugin `NFCT' Dec 04 16:23:15.573696 osdx ulogd[295885]: registering plugin `IP2STR' Dec 04 16:23:15.573762 osdx ulogd[295885]: registering plugin `PRINTFLOW' Dec 04 16:23:15.573832 osdx ulogd[295885]: registering plugin `SYSLOG' Dec 04 16:23:15.573860 osdx ulogd[295885]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:15.573922 osdx ulogd[295885]: NFCT plugin working in event mode Dec 04 16:23:15.573954 osdx ulogd[295885]: Changing UID / GID Dec 04 16:23:15.574183 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:15.574369 osdx ulogd[295885]: initialization finished, entering main loop Dec 04 16:23:15.603105 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:15.621834 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:16.363866 osdx ulogd[295885]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:16.363887 osdx ulogd[295885]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:16.441633 osdx ulogd[295885]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:16.441657 osdx ulogd[295885]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
Test policies logging
Description
Set a simple configuration with mark and label traffic policies,
send a ping
command from one device to other
and check that default, mark and label fields appear when running system journal show
.
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set interfaces ethernet eth0 traffic policy in POLICY set system conntrack logging events all set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0' set traffic label TEST set traffic policy POLICY rule 1 set connmark 33 set traffic policy POLICY rule 1 set label TEST
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.385 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.385/0.385/0.385/0.000 ms
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 2 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.315 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.504 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1013ms rtt min/avg/max/mdev = 0.315/0.409/0.504/0.094 ms
Step 5: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*MARK=33.*LABELS=TESTShow output
Dec 04 16:23:21.288909 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.3M free. Dec 04 16:23:21.290119 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:23:21.290163 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:23:21.299076 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:23:21.631491 osdx osdx-coredump[296030]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:23:21.640806 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:23:22.089680 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:22.153398 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Dec 04 16:23:22.239654 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set traffic label TEST'. Dec 04 16:23:22.295304 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. Dec 04 16:23:22.388812 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. Dec 04 16:23:22.441594 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:23:22.534932 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Dec 04 16:23:22.604900 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:22.730126 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:22.822389 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:22.823003 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Dec 04 16:23:22.823321 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:22.824301 osdx ulogd[296125]: registering plugin `NFCT' Dec 04 16:23:22.824593 osdx ulogd[296125]: registering plugin `IP2STR' Dec 04 16:23:22.824676 osdx ulogd[296125]: registering plugin `PRINTFLOW' Dec 04 16:23:22.824746 osdx ulogd[296125]: registering plugin `SYSLOG' Dec 04 16:23:22.824774 osdx ulogd[296125]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:22.824839 osdx ulogd[296125]: NFCT plugin working in event mode Dec 04 16:23:22.824871 osdx ulogd[296125]: Changing UID / GID Dec 04 16:23:22.824961 osdx ulogd[296125]: initialization finished, entering main loop Dec 04 16:23:22.833139 osdx ulogd[296125]: Terminal signal received, exiting Dec 04 16:23:22.833213 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:22.833408 osdx systemd[1]: ulogd2.service: Deactivated successfully. Dec 04 16:23:22.833507 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:22.834390 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:22.835290 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:22.835489 osdx ulogd[296131]: registering plugin `NFCT' Dec 04 16:23:22.835564 osdx ulogd[296131]: registering plugin `IP2STR' Dec 04 16:23:22.835601 osdx ulogd[296131]: registering plugin `PRINTFLOW' Dec 04 16:23:22.835648 osdx ulogd[296131]: registering plugin `SYSLOG' Dec 04 16:23:22.835651 osdx ulogd[296131]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:22.835689 osdx ulogd[296131]: NFCT plugin working in event mode Dec 04 16:23:22.835697 osdx ulogd[296131]: Changing UID / GID Dec 04 16:23:22.835759 osdx ulogd[296131]: initialization finished, entering main loop Dec 04 16:23:23.034989 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:23.059447 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:23.075294 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:23.871605 osdx ulogd[296131]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 LABELS=TEST Dec 04 16:23:23.871631 osdx ulogd[296131]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 Dec 04 16:23:23.944923 osdx ulogd[296131]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 LABELS=TEST Dec 04 16:23:23.944943 osdx ulogd[296131]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33
Test VRF logging
Description
Set a simple configuration with a vrf,
send a ping
command from one device to other
and check that default and vrf fields appear when running system journal show
.
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set interfaces ethernet eth0 vrf RED set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2 set system conntrack logging events all set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0' set system vrf RED
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.330 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.330/0.330/0.330/0.000 ms
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.384 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.384/0.384/0.384/0.000 ms
Step 5: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*VRF=REDShow output
Dec 04 16:23:29.288603 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.3M free. Dec 04 16:23:29.289734 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:23:29.289792 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:23:29.298198 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:23:29.649459 osdx osdx-coredump[296312]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:23:29.657352 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:23:30.125769 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:30.195544 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. Dec 04 16:23:30.275651 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. Dec 04 16:23:30.324364 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system vrf RED'. Dec 04 16:23:30.423258 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:23:30.475819 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Dec 04 16:23:30.587151 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:30.677712 osdx (udev-worker)[296349]: RED: Could not disable auto negotiation, ignoring: Operation not supported Dec 04 16:23:30.677970 osdx (udev-worker)[296349]: Network interface NamePolicy= disabled on kernel command line. Dec 04 16:23:30.693826 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:30.765739 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:30.871092 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:30.872590 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:30.872876 osdx ulogd[296430]: registering plugin `NFCT' Dec 04 16:23:30.872917 osdx ulogd[296430]: registering plugin `IP2STR' Dec 04 16:23:30.872966 osdx ulogd[296430]: registering plugin `PRINTFLOW' Dec 04 16:23:30.873010 osdx ulogd[296430]: registering plugin `SYSLOG' Dec 04 16:23:30.873013 osdx ulogd[296430]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:30.873427 osdx ulogd[296430]: NFCT plugin working in event mode Dec 04 16:23:30.873436 osdx ulogd[296430]: Changing UID / GID Dec 04 16:23:30.873507 osdx ulogd[296430]: initialization finished, entering main loop Dec 04 16:23:30.873949 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:30.902734 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:30.918390 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:31.349802 osdx ulogd[296430]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=48874 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=48874 PKTS=0 BYTES=0 Dec 04 16:23:31.349803 osdx zebra[1204]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Dec 04 16:23:31.349821 osdx ulogd[296430]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=41645 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=41645 PKTS=0 BYTES=0 Dec 04 16:23:31.725636 osdx ulogd[296430]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:31.725653 osdx ulogd[296430]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:31.805809 osdx ulogd[296430]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:31.805828 osdx ulogd[296430]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
Test Not-Bypass logging
Description
Set a simple configuration with a firewall service,
send a ping
command from one device to other
and check that default and bypass fields appear when running system journal show
.
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth1 address 10.215.168.64/24 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Ping IP address 10.215.168.1
from DUT0
:
admin@DUT0$ ping 10.215.168.1 count 1 size 56 timeout 1Show output
PING 10.215.168.1 (10.215.168.1) 56(84) bytes of data. 64 bytes from 10.215.168.1: icmp_seq=1 ttl=64 time=0.198 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.198/0.198/0.198/0.000 ms
Step 3: Run command file copy http://10.215.168.1/~robot/test-performance.rules running:// force
at DUT0
and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 129 100 129 0 0 33350 0 --:--:-- --:--:-- --:--:-- 43000
Step 4: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set interfaces ethernet eth0 traffic policy in POLICY set interfaces ethernet eth1 address 10.215.168.64/24 set service firewall FW mode inline queue FW_Q set service firewall FW ruleset file 'running://test-performance.rules' set service firewall FW stream bypass mark 129834765 set service firewall FW stream bypass mask 129834765 set service firewall FW stream bypass set-connmark set system conntrack logging events all set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0' set traffic policy POLICY rule 1 action enqueue FW_Q set traffic queue FW_Q elements 1
Step 5: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 6: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.450 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.450/0.450/0.450/0.000 ms
Step 7: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.323 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.323/0.323/0.323/0.000 ms
Step 8: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*Sc: not-bypassShow output
Dec 04 16:23:35.291314 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.2M free. Dec 04 16:23:35.293439 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:23:35.293505 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:23:35.300807 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:23:35.593629 osdx osdx-coredump[296610]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:23:35.600410 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:23:36.034601 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:36.101819 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Dec 04 16:23:36.196144 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:36.269442 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Dec 04 16:23:36.348120 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:36.375923 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:36.395651 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:36.538416 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Dec 04 16:23:36.670581 osdx file_operation[296716]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// Dec 04 16:23:36.695356 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. Dec 04 16:23:36.850942 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:36.922859 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Dec 04 16:23:37.034871 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. Dec 04 16:23:37.085298 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file 'running://test-performance.rules''. Dec 04 16:23:37.180378 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. Dec 04 16:23:37.236527 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. Dec 04 16:23:37.324397 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. Dec 04 16:23:37.375343 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. Dec 04 16:23:37.470437 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. Dec 04 16:23:37.527375 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. Dec 04 16:23:37.628473 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:23:37.680279 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Dec 04 16:23:37.802976 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:37.933446 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:38.033741 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:38.034388 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:38.034571 osdx ulogd[296825]: registering plugin `NFCT' Dec 04 16:23:38.034617 osdx ulogd[296825]: registering plugin `IP2STR' Dec 04 16:23:38.034661 osdx ulogd[296825]: registering plugin `PRINTFLOW' Dec 04 16:23:38.034709 osdx ulogd[296825]: registering plugin `SYSLOG' Dec 04 16:23:38.034712 osdx ulogd[296825]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:38.034751 osdx ulogd[296825]: NFCT plugin working in event mode Dec 04 16:23:38.034757 osdx ulogd[296825]: Changing UID / GID Dec 04 16:23:38.034819 osdx ulogd[296825]: initialization finished, entering main loop Dec 04 16:23:38.190740 osdx systemd[1]: Reloading. Dec 04 16:23:38.305444 osdx systemd-sysv-generator[296857]: stat() failed on /etc/init.d/README, ignoring: No such file or directory Dec 04 16:23:38.417923 osdx systemd[1]: Starting logrotate.service - Rotate log files... Dec 04 16:23:38.421156 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... Dec 04 16:23:38.442672 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. Dec 04 16:23:38.450425 osdx systemd[1]: logrotate.service: Deactivated successfully. Dec 04 16:23:38.450525 osdx systemd[1]: Finished logrotate.service - Rotate log files. Dec 04 16:23:38.674027 osdx INFO[296838]: Rules successfully loaded Dec 04 16:23:38.688457 osdx ulogd[296825]: Terminal signal received, exiting Dec 04 16:23:38.688558 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:38.688881 osdx systemd[1]: ulogd2.service: Deactivated successfully. Dec 04 16:23:38.689009 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:38.709742 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:38.710537 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:38.711160 osdx ulogd[296884]: registering plugin `NFCT' Dec 04 16:23:38.711396 osdx ulogd[296884]: registering plugin `IP2STR' Dec 04 16:23:38.711469 osdx ulogd[296884]: registering plugin `PRINTFLOW' Dec 04 16:23:38.711537 osdx ulogd[296884]: registering plugin `SYSLOG' Dec 04 16:23:38.711567 osdx ulogd[296884]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:38.711632 osdx ulogd[296884]: NFCT plugin working in event mode Dec 04 16:23:38.711663 osdx ulogd[296884]: Changing UID / GID Dec 04 16:23:38.711751 osdx ulogd[296884]: initialization finished, entering main loop Dec 04 16:23:38.712680 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:38.737637 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:38.754447 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:39.554898 osdx ulogd[296884]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass) Dec 04 16:23:39.554921 osdx ulogd[296884]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass) Dec 04 16:23:39.652608 osdx ulogd[296884]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass) Dec 04 16:23:39.652626 osdx ulogd[296884]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass)
Test Offload flag
Description
Set a simple configuration with DUT0
as an intermediary between DUT1
and DUT2
. Initiate a ssh
connection from DUT1
to DUT2
and check that default and offload fields appear when running system journal show
.
Scenario
Step 1: Set the following configuration in DUT0
:
set interfaces ethernet eth0 address 192.168.100.1/24 set interfaces ethernet eth1 address 192.168.200.1/24 set system conntrack logging events all set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Set the following configuration in DUT1
:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Set the following configuration in DUT2
:
set interfaces ethernet eth0 address 192.168.200.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.200.1 set service ssh set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 4: Ping IP address 192.168.100.1
from DUT1
:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.388 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.388/0.388/0.388/0.000 ms
Step 5: Ping IP address 192.168.200.1
from DUT2
:
admin@DUT2$ ping 192.168.200.1 count 1 size 56 timeout 1Show output
PING 192.168.200.1 (192.168.200.1) 56(84) bytes of data. 64 bytes from 192.168.200.1: icmp_seq=1 ttl=64 time=0.520 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.520/0.520/0.520/0.000 ms
Step 6: Init an SSH connection from DUT1
to IP address 192.168.200.2
with the user admin
:
admin@DUT1$ ssh admin@192.168.200.2 option StrictHostKeyChecking=no option UserKnownHostsFile=/dev/nullShow output
Warning: Permanently added '192.168.200.2' (ED25519) to the list of known hosts. admin@192.168.200.2's password: Welcome to Teldat OSDx v4.1.1.4 This system includes free software. Contact Teldat for licenses information and source code. Last login: Wed Dec 4 15:35:19 2024 from 40.0.0.2 admin@osdx$
Step 7: Run command system journal show | cat
at DUT0
and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*\[OFFLOAD\]Show output
Dec 04 16:23:46.273327 osdx systemd-journald[1574]: Runtime Journal (/run/log/journal/2754912ae611401eb118833e63cf0c07) is 2.0M, max 15.3M, 13.2M free. Dec 04 16:23:46.277056 osdx systemd-journald[1574]: Received client request to rotate journal, rotating. Dec 04 16:23:46.277097 osdx systemd-journald[1574]: Vacuuming done, freed 0B of archived journals from /run/log/journal/2754912ae611401eb118833e63cf0c07. Dec 04 16:23:46.283232 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system journal clear'. Dec 04 16:23:46.584017 osdx osdx-coredump[297098]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Dec 04 16:23:46.590944 osdx OSDxCLI[257063]: User 'admin' executed a new command: 'system coredump delete all'. Dec 04 16:23:47.038240 osdx OSDxCLI[257063]: User 'admin' entered the configuration menu. Dec 04 16:23:47.100158 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. Dec 04 16:23:47.186793 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Dec 04 16:23:47.237787 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Dec 04 16:23:47.347869 osdx OSDxCLI[257063]: User 'admin' added a new cfg line: 'show working'. Dec 04 16:23:47.433073 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Dec 04 16:23:47.505056 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Dec 04 16:23:47.613372 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Dec 04 16:23:47.614068 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Dec 04 16:23:47.614364 osdx ulogd[297236]: registering plugin `NFCT' Dec 04 16:23:47.614686 osdx ulogd[297236]: registering plugin `IP2STR' Dec 04 16:23:47.614785 osdx ulogd[297236]: registering plugin `PRINTFLOW' Dec 04 16:23:47.614874 osdx ulogd[297236]: registering plugin `SYSLOG' Dec 04 16:23:47.614910 osdx ulogd[297236]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Dec 04 16:23:47.614995 osdx ulogd[297236]: NFCT plugin working in event mode Dec 04 16:23:47.615037 osdx ulogd[297236]: Changing UID / GID Dec 04 16:23:47.615150 osdx ulogd[297236]: initialization finished, entering main loop Dec 04 16:23:47.616392 osdx cfgd[1239]: [257063]Completed change to active configuration Dec 04 16:23:47.642151 osdx OSDxCLI[257063]: User 'admin' committed the configuration. Dec 04 16:23:47.656951 osdx OSDxCLI[257063]: User 'admin' left the configuration menu. Dec 04 16:23:49.312516 osdx ulogd[297236]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:49.312537 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:49.398157 osdx ulogd[297236]: [NEW] ORIG: SRC=192.168.200.2 DST=192.168.200.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.1 DST=192.168.200.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:49.398184 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.200.2 DST=192.168.200.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.1 DST=192.168.200.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 Dec 04 16:23:49.485731 osdx ulogd[297236]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 Dec 04 16:23:49.485852 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 Dec 04 16:23:49.485983 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 [OFFLOAD] Dec 04 16:23:49.756728 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 Dec 04 16:23:49.756774 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 [OFFLOAD] Dec 04 16:23:49.758489 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 Dec 04 16:23:49.758648 osdx ulogd[297236]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=52050 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=52050 PKTS=0 BYTES=0 [OFFLOAD]