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 1
Show 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.682 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.682/0.682/0.682/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 1
Show 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 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[NEW\].*SRC=192.168.100.2
Show output
Oct 09 11:05:09.389008 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.1M, max 15.3M, 13.1M free.
Oct 09 11:05:09.393014 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:05:09.393100 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:05:09.406329 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:05:09.898023 osdx osdx-coredump[416697]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:05:09.908265 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:05:10.563735 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:05:10.712217 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:05:10.799041 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
Oct 09 11:05:10.943393 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:05:11.073035 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:05:11.221547 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:11.226524 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:11.228592 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:05:11.230161 osdx ulogd[416782]: registering plugin `NFCT'
Oct 09 11:05:11.231229 osdx ulogd[416782]: registering plugin `IP2STR'
Oct 09 11:05:11.231331 osdx ulogd[416782]: registering plugin `PRINTFLOW'
Oct 09 11:05:11.232622 osdx ulogd[416782]: registering plugin `SYSLOG'
Oct 09 11:05:11.232634 osdx ulogd[416782]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:05:11.232700 osdx ulogd[416782]: NFCT plugin working in event mode
Oct 09 11:05:11.232710 osdx ulogd[416782]: Changing UID / GID
Oct 09 11:05:11.232810 osdx ulogd[416782]: initialization finished, entering main loop
Oct 09 11:05:11.282666 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:05:11.320935 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:05:12.420050 osdx ulogd[416782]: [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
Oct 09 11:05:12.532568 osdx ulogd[416782]: [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 1
Show 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.453 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.453/0.453/0.453/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 1
Show 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.329 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.329/0.329/0.329/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.2
Show output
Oct 09 11:05:19.363161 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.0M, max 15.3M, 13.3M free.
Oct 09 11:05:19.365839 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:05:19.365922 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:05:19.378669 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:05:19.818624 osdx osdx-coredump[416925]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:05:19.828944 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:05:20.464548 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:05:20.601248 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:05:20.680918 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
Oct 09 11:05:20.827504 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:05:20.961790 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:05:21.118277 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:21.119788 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:21.119927 osdx ulogd[417010]: registering plugin `NFCT'
Oct 09 11:05:21.119992 osdx ulogd[417010]: registering plugin `IP2STR'
Oct 09 11:05:21.120051 osdx ulogd[417010]: registering plugin `PRINTFLOW'
Oct 09 11:05:21.120193 osdx ulogd[417010]: registering plugin `SYSLOG'
Oct 09 11:05:21.120198 osdx ulogd[417010]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:05:21.120256 osdx ulogd[417010]: NFCT plugin working in event mode
Oct 09 11:05:21.120266 osdx ulogd[417010]: Changing UID / GID
Oct 09 11:05:21.120405 osdx ulogd[417010]: initialization finished, entering main loop
Oct 09 11:05:21.122030 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:05:21.158554 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:05:21.186951 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:05:22.310806 osdx ulogd[417010]: [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
Oct 09 11:05:22.418402 osdx ulogd[417010]: [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 1
Show 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.504 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.504/0.504/0.504/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 1
Show 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
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.393 ms
64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.532 ms

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2028ms
rtt min/avg/max/mdev = 0.384/0.436/0.532/0.067 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.2
Show output
Oct 09 11:05:27.370044 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.0M, max 15.3M, 13.3M free.
Oct 09 11:05:27.371925 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:05:27.372003 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:05:27.387049 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:05:27.842974 osdx osdx-coredump[417153]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:05:27.856136 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:05:28.527707 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:05:28.664480 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:05:28.741967 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
Oct 09 11:05:28.858992 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Oct 09 11:05:28.951735 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service ssh'.
Oct 09 11:05:29.079243 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:05:29.227894 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:05:29.380401 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:29.381233 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:29.381360 osdx ulogd[417248]: registering plugin `NFCT'
Oct 09 11:05:29.381429 osdx ulogd[417248]: registering plugin `IP2STR'
Oct 09 11:05:29.381492 osdx ulogd[417248]: registering plugin `PRINTFLOW'
Oct 09 11:05:29.381559 osdx ulogd[417248]: registering plugin `SYSLOG'
Oct 09 11:05:29.381563 osdx ulogd[417248]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:05:29.381618 osdx ulogd[417248]: NFCT plugin working in event mode
Oct 09 11:05:29.381627 osdx ulogd[417248]: Changing UID / GID
Oct 09 11:05:29.381718 osdx ulogd[417248]: initialization finished, entering main loop
Oct 09 11:05:29.450586 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Oct 09 11:05:29.476594 osdx sshd[417254]: Server listening on 0.0.0.0 port 22.
Oct 09 11:05:29.476868 osdx sshd[417254]: Server listening on :: port 22.
Oct 09 11:05:29.477067 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Oct 09 11:05:29.505763 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:05:29.547567 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:05:29.586218 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:05:30.177138 osdx zebra[1399]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]):
Oct 09 11:05:31.795134 osdx ulogd[417248]: [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
Oct 09 11:05:32.796362 osdx ulogd[417248]: [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 1
Show 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.544 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.544/0.544/0.544/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 1
Show 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.394 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.394/0.394/0.394/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.2
Show output
Oct 09 11:05:42.378822 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.0M, max 15.3M, 13.3M free.
Oct 09 11:05:42.381730 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:05:42.381793 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:05:42.394561 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:05:42.843336 osdx osdx-coredump[417422]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:05:42.853057 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:05:43.500021 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:05:43.641093 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:05:43.725893 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Oct 09 11:05:43.841166 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:05:43.973715 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:05:44.130150 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:44.131287 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:44.131379 osdx ulogd[417507]: registering plugin `NFCT'
Oct 09 11:05:44.131442 osdx ulogd[417507]: registering plugin `IP2STR'
Oct 09 11:05:44.131499 osdx ulogd[417507]: registering plugin `PRINTFLOW'
Oct 09 11:05:44.131562 osdx ulogd[417507]: registering plugin `SYSLOG'
Oct 09 11:05:44.131566 osdx ulogd[417507]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:05:44.131621 osdx ulogd[417507]: NFCT plugin working in event mode
Oct 09 11:05:44.131630 osdx ulogd[417507]: Changing UID / GID
Oct 09 11:05:44.131718 osdx ulogd[417507]: initialization finished, entering main loop
Oct 09 11:05:44.134813 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:05:44.182625 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:05:44.208821 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:05:45.418604 osdx ulogd[417507]: [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
Oct 09 11:05:45.418645 osdx ulogd[417507]: [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
Oct 09 11:05:45.543358 osdx ulogd[417507]: [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
Oct 09 11:05:45.543408 osdx ulogd[417507]: [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
Oct 09 11:05:45.619021 osdx zebra[1399]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]):
Oct 09 11:05:45.619034 osdx ulogd[417507]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=56314 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=56314 PKTS=0 BYTES=0
Oct 09 11:05:45.619055 osdx ulogd[417507]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=40139 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=40139 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 1
Show 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.725 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.725/0.725/0.725/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 1
Show 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.441 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.491 ms

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1025ms
rtt min/avg/max/mdev = 0.441/0.466/0.491/0.025 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=TEST
Show output
Oct 09 11:05:51.376236 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.0M, max 15.3M, 13.3M free.
Oct 09 11:05:51.378123 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:05:51.378189 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:05:51.391981 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:05:51.867667 osdx osdx-coredump[417650]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:05:51.877239 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:05:52.581035 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:05:52.723528 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Oct 09 11:05:52.801212 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set traffic label TEST'.
Oct 09 11:05:52.948085 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
Oct 09 11:05:53.038951 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
Oct 09 11:05:53.129655 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:05:53.222662 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Oct 09 11:05:53.342804 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:05:53.510177 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:05:53.646578 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:53.647739 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:53.647941 osdx ulogd[417745]: registering plugin `NFCT'
Oct 09 11:05:53.648037 osdx ulogd[417745]: registering plugin `IP2STR'
Oct 09 11:05:53.648122 osdx ulogd[417745]: registering plugin `PRINTFLOW'
Oct 09 11:05:53.648214 osdx ulogd[417745]: registering plugin `SYSLOG'
Oct 09 11:05:53.648221 osdx ulogd[417745]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:05:53.648296 osdx ulogd[417745]: NFCT plugin working in event mode
Oct 09 11:05:53.648309 osdx ulogd[417745]: Changing UID / GID
Oct 09 11:05:53.648425 osdx ulogd[417745]: initialization finished, entering main loop
Oct 09 11:05:53.663404 osdx ulogd[417745]: Terminal signal received, exiting
Oct 09 11:05:53.663558 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:53.664056 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Oct 09 11:05:53.664236 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:53.665914 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:05:53.667447 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:05:53.667750 osdx ulogd[417751]: registering plugin `NFCT'
Oct 09 11:05:53.667835 osdx ulogd[417751]: registering plugin `IP2STR'
Oct 09 11:05:53.667916 osdx ulogd[417751]: registering plugin `PRINTFLOW'
Oct 09 11:05:53.667991 osdx ulogd[417751]: registering plugin `SYSLOG'
Oct 09 11:05:53.667996 osdx ulogd[417751]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:05:53.668049 osdx ulogd[417751]: NFCT plugin working in event mode
Oct 09 11:05:53.668058 osdx ulogd[417751]: Changing UID / GID
Oct 09 11:05:53.668145 osdx ulogd[417751]: initialization finished, entering main loop
Oct 09 11:05:53.859343 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:05:53.898740 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:05:53.926291 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:05:54.988571 osdx ulogd[417751]: [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
Oct 09 11:05:54.988595 osdx ulogd[417751]: [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
Oct 09 11:05:55.100144 osdx ulogd[417751]: [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
Oct 09 11:05:55.100170 osdx ulogd[417751]: [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
Oct 09 11:05:55.506285 osdx ulogd[417751]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=48436 DPT=2055 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=2055 DPT=48436 PKTS=0 BYTES=0

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 1
Show 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.636 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.636/0.636/0.636/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 1
Show 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.326 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.326/0.326/0.326/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=RED
Show output
Oct 09 11:06:02.361114 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.0M, max 15.3M, 13.3M free.
Oct 09 11:06:02.361880 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:06:02.361938 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:06:02.375586 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:06:02.805498 osdx osdx-coredump[417940]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:06:02.815166 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:06:03.469361 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:06:03.608387 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
Oct 09 11:06:03.695288 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'.
Oct 09 11:06:03.805151 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system vrf RED'.
Oct 09 11:06:03.902070 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:06:03.994922 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Oct 09 11:06:04.110576 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:06:04.229374 osdx (udev-worker)[417976]: RED: Could not disable auto negotiation, ignoring: Operation not supported
Oct 09 11:06:04.229694 osdx (udev-worker)[417976]: Network interface NamePolicy= disabled on kernel command line.
Oct 09 11:06:04.257694 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:06:04.353663 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:06:04.478063 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:06:04.479330 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:06:04.480036 osdx ulogd[418058]: registering plugin `NFCT'
Oct 09 11:06:04.480126 osdx ulogd[418058]: registering plugin `IP2STR'
Oct 09 11:06:04.480210 osdx ulogd[418058]: registering plugin `PRINTFLOW'
Oct 09 11:06:04.480300 osdx ulogd[418058]: registering plugin `SYSLOG'
Oct 09 11:06:04.480307 osdx ulogd[418058]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:06:04.480383 osdx ulogd[418058]: NFCT plugin working in event mode
Oct 09 11:06:04.480395 osdx ulogd[418058]: Changing UID / GID
Oct 09 11:06:04.480517 osdx ulogd[418058]: initialization finished, entering main loop
Oct 09 11:06:04.481764 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:06:04.518127 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:06:04.544502 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:06:05.635198 osdx ulogd[418058]: [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
Oct 09 11:06:05.635247 osdx ulogd[418058]: [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
Oct 09 11:06:05.756476 osdx ulogd[418058]: [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
Oct 09 11:06:05.756507 osdx ulogd[418058]: [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 1
Show 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.364 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.364/0.364/0.364/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  16889      0 --:--:-- --:--:-- --:--:-- 18428

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 1
Show 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.655 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.655/0.655/0.655/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 1
Show 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.460 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.460/0.460/0.460/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-bypass
Show output
Oct 09 11:06:11.370713 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.1M, max 15.3M, 13.2M free.
Oct 09 11:06:11.374255 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:06:11.374334 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:06:11.385183 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:06:11.824236 osdx osdx-coredump[418238]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:06:11.834075 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:06:12.461776 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:06:12.596432 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Oct 09 11:06:12.707057 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:06:12.826242 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Oct 09 11:06:12.923511 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:06:12.965167 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:06:12.990121 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:06:13.201687 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'ping 10.215.168.1      count 1 size 56 timeout 1'.
Oct 09 11:06:13.418200 osdx file_operation[418344]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
Oct 09 11:06:13.455841 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
Oct 09 11:06:13.631888 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:06:13.737151 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Oct 09 11:06:13.856114 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
Oct 09 11:06:13.954090 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file 'running://test-performance.rules''.
Oct 09 11:06:14.045100 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
Oct 09 11:06:14.139620 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
Oct 09 11:06:14.257247 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
Oct 09 11:06:14.351289 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
Oct 09 11:06:14.472282 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
Oct 09 11:06:14.570709 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
Oct 09 11:06:14.694506 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:06:14.778585 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Oct 09 11:06:14.925802 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:06:15.110209 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:06:15.258721 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:06:15.259856 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:06:15.260088 osdx ulogd[418453]: registering plugin `NFCT'
Oct 09 11:06:15.260178 osdx ulogd[418453]: registering plugin `IP2STR'
Oct 09 11:06:15.260258 osdx ulogd[418453]: registering plugin `PRINTFLOW'
Oct 09 11:06:15.260345 osdx ulogd[418453]: registering plugin `SYSLOG'
Oct 09 11:06:15.260351 osdx ulogd[418453]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:06:15.260425 osdx ulogd[418453]: NFCT plugin working in event mode
Oct 09 11:06:15.260438 osdx ulogd[418453]: Changing UID / GID
Oct 09 11:06:15.260553 osdx ulogd[418453]: initialization finished, entering main loop
Oct 09 11:06:15.444429 osdx zebra[1399]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]):
Oct 09 11:06:15.444444 osdx ulogd[418453]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=43828 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=43828 PKTS=0 BYTES=0
Oct 09 11:06:15.444474 osdx ulogd[418453]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=49428 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=49428 PKTS=0 BYTES=0
Oct 09 11:06:15.472213 osdx systemd[1]: Reloading.
Oct 09 11:06:15.630211 osdx systemd-sysv-generator[418484]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
Oct 09 11:06:15.834814 osdx systemd[1]: Starting logrotate.service - Rotate log files...
Oct 09 11:06:15.840243 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
Oct 09 11:06:15.870498 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
Oct 09 11:06:15.887802 osdx systemd[1]: logrotate.service: Deactivated successfully.
Oct 09 11:06:15.888037 osdx systemd[1]: Finished logrotate.service - Rotate log files.
Oct 09 11:06:15.904621 osdx INFO[418466]: Rules successfully loaded
Oct 09 11:06:15.926849 osdx ulogd[418453]: Terminal signal received, exiting
Oct 09 11:06:15.927038 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:06:15.927557 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Oct 09 11:06:15.927902 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:06:15.947051 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:06:15.948235 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:06:15.948312 osdx ulogd[418510]: registering plugin `NFCT'
Oct 09 11:06:15.948376 osdx ulogd[418510]: registering plugin `IP2STR'
Oct 09 11:06:15.948448 osdx ulogd[418510]: registering plugin `PRINTFLOW'
Oct 09 11:06:15.948513 osdx ulogd[418510]: registering plugin `SYSLOG'
Oct 09 11:06:15.948518 osdx ulogd[418510]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:06:15.948571 osdx ulogd[418510]: NFCT plugin working in event mode
Oct 09 11:06:15.948580 osdx ulogd[418510]: Changing UID / GID
Oct 09 11:06:15.948673 osdx ulogd[418510]: initialization finished, entering main loop
Oct 09 11:06:15.951477 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:06:16.007104 osdx ulogd[418510]: [DESTROY] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=43828 DPT=53 PKTS=1 BYTES=62 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=43828 PKTS=0 BYTES=0
Oct 09 11:06:16.007250 osdx ulogd[418510]: [DESTROY] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=49428 DPT=53 PKTS=1 BYTES=62 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=49428 PKTS=0 BYTES=0
Oct 09 11:06:16.008202 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:06:16.048287 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:06:17.247757 osdx ulogd[418510]: [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)
Oct 09 11:06:17.247788 osdx ulogd[418510]: [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)
Oct 09 11:06:17.406538 osdx ulogd[418510]: [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)
Oct 09 11:06:17.406570 osdx ulogd[418510]: [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 1
Show 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.670 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.670/0.670/0.670/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 1
Show 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.495 ms

--- 192.168.200.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.495/0.495/0.495/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/null
Show 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.3

This system includes free software.
Contact Teldat for licenses information and source code.

Last login: Wed Oct  9 11:00:42 2024
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
Oct 09 11:06:26.359889 osdx systemd-journald[402511]: Runtime Journal (/run/log/journal/da0729972954483f829d339572dde7c1) is 2.0M, max 15.3M, 13.3M free.
Oct 09 11:06:26.362712 osdx systemd-journald[402511]: Received client request to rotate journal, rotating.
Oct 09 11:06:26.362788 osdx systemd-journald[402511]: Vacuuming done, freed 0B of archived journals from /run/log/journal/da0729972954483f829d339572dde7c1.
Oct 09 11:06:26.373804 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system journal clear'.
Oct 09 11:06:26.953669 osdx osdx-coredump[418723]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Oct 09 11:06:26.965002 osdx OSDxCLI[410417]: User 'admin' executed a new command: 'system coredump delete all'.
Oct 09 11:06:27.584953 osdx OSDxCLI[410417]: User 'admin' entered the configuration menu.
Oct 09 11:06:27.724431 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
Oct 09 11:06:27.799455 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Oct 09 11:06:27.888511 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Oct 09 11:06:28.003032 osdx OSDxCLI[410417]: User 'admin' added a new cfg line: 'show working'.
Oct 09 11:06:28.146710 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Oct 09 11:06:28.250703 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Oct 09 11:06:28.411127 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Oct 09 11:06:28.412467 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Oct 09 11:06:28.412561 osdx ulogd[418861]: registering plugin `NFCT'
Oct 09 11:06:28.412626 osdx ulogd[418861]: registering plugin `IP2STR'
Oct 09 11:06:28.412691 osdx ulogd[418861]: registering plugin `PRINTFLOW'
Oct 09 11:06:28.412760 osdx ulogd[418861]: registering plugin `SYSLOG'
Oct 09 11:06:28.412765 osdx ulogd[418861]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Oct 09 11:06:28.412819 osdx ulogd[418861]: NFCT plugin working in event mode
Oct 09 11:06:28.412828 osdx ulogd[418861]: Changing UID / GID
Oct 09 11:06:28.412916 osdx ulogd[418861]: initialization finished, entering main loop
Oct 09 11:06:28.414889 osdx cfgd[1434]: [410417]Completed change to active configuration
Oct 09 11:06:28.460127 osdx OSDxCLI[410417]: User 'admin' committed the configuration.
Oct 09 11:06:28.485874 osdx OSDxCLI[410417]: User 'admin' left the configuration menu.
Oct 09 11:06:30.713308 osdx ulogd[418861]: [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
Oct 09 11:06:30.713342 osdx ulogd[418861]: [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
Oct 09 11:06:30.823693 osdx ulogd[418861]: [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
Oct 09 11:06:30.823731 osdx ulogd[418861]: [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
Oct 09 11:06:30.926731 osdx ulogd[418861]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0
Oct 09 11:06:30.926957 osdx ulogd[418861]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0
Oct 09 11:06:30.927157 osdx ulogd[418861]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0 [OFFLOAD]
Oct 09 11:06:30.976943 osdx zebra[1399]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]):
Oct 09 11:06:30.976964 osdx ulogd[418861]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=51132 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=51132 PKTS=0 BYTES=0
Oct 09 11:06:30.976990 osdx ulogd[418861]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=57489 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=57489 PKTS=0 BYTES=0
Oct 09 11:06:31.322743 osdx ulogd[418861]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0
Oct 09 11:06:31.322782 osdx ulogd[418861]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0 [OFFLOAD]
Oct 09 11:06:31.324875 osdx ulogd[418861]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0
Oct 09 11:06:31.325176 osdx ulogd[418861]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=35244 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=35244 PKTS=0 BYTES=0 [OFFLOAD]