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=1.47 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 1.467/1.467/1.467/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.316 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.316/0.316/0.316/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
May 11 21:05:09.000495 osdx systemd-timedated[78438]: Changed local time to Sun 2025-05-11 21:05:09 UTC May 11 21:05:09.002222 osdx systemd-journald[1583]: Time jumped backwards, rotating. May 11 21:05:09.002784 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'set date 2025-05-11 21:05:09'. May 11 21:05:09.442422 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.0M, max 15.3M, 13.2M free. May 11 21:05:09.446144 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:05:09.446212 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:05:09.458961 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:05:09.990890 osdx osdx-coredump[78455]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:05:10.001720 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:05:10.827670 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:05:11.003564 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:05:11.118552 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. May 11 21:05:11.277502 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:05:11.458145 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:05:11.626881 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:11.630321 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:05:11.634503 osdx ulogd[78540]: registering plugin `NFCT' May 11 21:05:11.635849 osdx ulogd[78540]: registering plugin `IP2STR' May 11 21:05:11.636058 osdx ulogd[78540]: registering plugin `PRINTFLOW' May 11 21:05:11.637373 osdx ulogd[78540]: registering plugin `SYSLOG' May 11 21:05:11.637444 osdx ulogd[78540]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:05:11.637562 osdx ulogd[78540]: NFCT plugin working in event mode May 11 21:05:11.637634 osdx ulogd[78540]: Changing UID / GID May 11 21:05:11.637802 osdx ulogd[78540]: initialization finished, entering main loop May 11 21:05:11.650264 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:11.652161 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:05:11.696326 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:05:11.730591 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:05:13.124078 osdx ulogd[78540]: [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 May 11 21:05:13.266258 osdx ulogd[78540]: [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.559 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.559/0.559/0.559/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.301 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.301/0.301/0.301/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
May 11 21:05:20.430510 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.1M, max 15.3M, 13.1M free. May 11 21:05:20.431716 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:05:20.431795 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:05:20.448173 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:05:21.107358 osdx osdx-coredump[78683]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:05:21.118315 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:05:21.850336 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:05:21.971903 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:05:22.096085 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. May 11 21:05:22.213489 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:05:22.343691 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:05:22.476200 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:22.477558 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:05:22.478261 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:22.478436 osdx ulogd[78768]: registering plugin `NFCT' May 11 21:05:22.478517 osdx ulogd[78768]: registering plugin `IP2STR' May 11 21:05:22.478597 osdx ulogd[78768]: registering plugin `PRINTFLOW' May 11 21:05:22.478683 osdx ulogd[78768]: registering plugin `SYSLOG' May 11 21:05:22.478689 osdx ulogd[78768]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:05:22.478765 osdx ulogd[78768]: NFCT plugin working in event mode May 11 21:05:22.478776 osdx ulogd[78768]: Changing UID / GID May 11 21:05:22.478896 osdx ulogd[78768]: initialization finished, entering main loop May 11 21:05:22.480812 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:05:22.537538 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:05:22.573788 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:05:23.935320 osdx ulogd[78768]: [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 May 11 21:05:24.082952 osdx ulogd[78768]: [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=2.27 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 2.272/2.272/2.272/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.362 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.289 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.368 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2038ms rtt min/avg/max/mdev = 0.289/0.339/0.368/0.035 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
May 11 21:05:31.492805 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.1M, max 15.3M, 13.2M free. May 11 21:05:31.495762 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:05:31.495864 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:05:31.511732 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:05:32.076255 osdx osdx-coredump[78911]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:05:32.090122 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:05:32.896792 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:05:33.047206 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:05:33.175095 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. May 11 21:05:33.331878 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 11 21:05:33.475177 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service ssh'. May 11 21:05:33.657859 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:05:33.815768 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:05:33.968306 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:33.970001 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:05:33.970944 osdx ulogd[79006]: registering plugin `NFCT' May 11 21:05:33.971034 osdx ulogd[79006]: registering plugin `IP2STR' May 11 21:05:33.971122 osdx ulogd[79006]: registering plugin `PRINTFLOW' May 11 21:05:33.971215 osdx ulogd[79006]: registering plugin `SYSLOG' May 11 21:05:33.971222 osdx ulogd[79006]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:05:33.971299 osdx ulogd[79006]: NFCT plugin working in event mode May 11 21:05:33.971312 osdx ulogd[79006]: Changing UID / GID May 11 21:05:33.971434 osdx ulogd[79006]: initialization finished, entering main loop May 11 21:05:33.983868 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:34.096299 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... May 11 21:05:34.135282 osdx sshd[79012]: Server listening on 0.0.0.0 port 22. May 11 21:05:34.135329 osdx sshd[79012]: Server listening on :: port 22. May 11 21:05:34.135478 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. May 11 21:05:34.175437 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:05:34.213242 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:05:34.264458 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:05:36.736690 osdx ulogd[79006]: [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 May 11 21:05:37.760763 osdx ulogd[79006]: [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.647 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.647/0.647/0.647/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.421 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.421/0.421/0.421/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
May 11 21:05:47.391408 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.0M, max 15.3M, 13.3M free. May 11 21:05:47.392682 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:05:47.392756 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:05:47.409875 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:05:48.092724 osdx osdx-coredump[79180]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:05:48.108690 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:05:48.930249 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:05:49.050815 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:05:49.174488 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 11 21:05:49.339536 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:05:49.464692 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:05:49.633099 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:49.634467 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:05:49.634945 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:49.636057 osdx ulogd[79265]: registering plugin `NFCT' May 11 21:05:49.636120 osdx ulogd[79265]: registering plugin `IP2STR' May 11 21:05:49.636179 osdx ulogd[79265]: registering plugin `PRINTFLOW' May 11 21:05:49.636246 osdx ulogd[79265]: registering plugin `SYSLOG' May 11 21:05:49.636251 osdx ulogd[79265]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:05:49.636307 osdx ulogd[79265]: NFCT plugin working in event mode May 11 21:05:49.636316 osdx ulogd[79265]: Changing UID / GID May 11 21:05:49.636405 osdx ulogd[79265]: initialization finished, entering main loop May 11 21:05:49.637250 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:05:49.692548 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:05:49.733810 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:05:50.822310 osdx ulogd[79265]: [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 May 11 21:05:50.822347 osdx ulogd[79265]: [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 May 11 21:05:50.933301 osdx ulogd[79265]: [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 May 11 21:05:50.933354 osdx ulogd[79265]: [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.581 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.581/0.581/0.581/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.348 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.299 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1013ms rtt min/avg/max/mdev = 0.299/0.323/0.348/0.024 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
May 11 21:05:56.547018 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.0M, max 15.3M, 13.3M free. May 11 21:05:56.550740 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:05:56.550830 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:05:56.567131 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:05:57.136082 osdx osdx-coredump[79408]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:05:57.150975 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:05:57.989333 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:05:58.131622 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. May 11 21:05:58.263702 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set traffic label TEST'. May 11 21:05:58.391032 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. May 11 21:05:58.483685 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. May 11 21:05:58.581403 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:05:58.710993 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 11 21:05:58.834384 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:05:59.074659 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:05:59.257983 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:59.257177 osdx ulogd[79503]: registering plugin `NFCT' May 11 21:05:59.258568 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:59.257263 osdx ulogd[79503]: registering plugin `IP2STR' May 11 21:05:59.257346 osdx ulogd[79503]: registering plugin `PRINTFLOW' May 11 21:05:59.257439 osdx ulogd[79503]: registering plugin `SYSLOG' May 11 21:05:59.257445 osdx ulogd[79503]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:05:59.257520 osdx ulogd[79503]: NFCT plugin working in event mode May 11 21:05:59.257533 osdx ulogd[79503]: Changing UID / GID May 11 21:05:59.257656 osdx ulogd[79503]: initialization finished, entering main loop May 11 21:05:59.285488 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:59.285958 osdx ulogd[79503]: Terminal signal received, exiting May 11 21:05:59.288932 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 11 21:05:59.289469 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:59.312718 osdx ulogd[79510]: registering plugin `NFCT' May 11 21:05:59.312804 osdx ulogd[79510]: registering plugin `IP2STR' May 11 21:05:59.312886 osdx ulogd[79510]: registering plugin `PRINTFLOW' May 11 21:05:59.312987 osdx ulogd[79510]: registering plugin `SYSLOG' May 11 21:05:59.312994 osdx ulogd[79510]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:05:59.313070 osdx ulogd[79510]: NFCT plugin working in event mode May 11 21:05:59.313082 osdx ulogd[79510]: Changing UID / GID May 11 21:05:59.313202 osdx ulogd[79510]: initialization finished, entering main loop May 11 21:05:59.314663 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:05:59.315374 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:05:59.548220 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:05:59.602425 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:05:59.657798 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:06:01.114483 osdx ulogd[79510]: [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 May 11 21:06:01.114526 osdx ulogd[79510]: [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 May 11 21:06:01.342085 osdx ulogd[79510]: [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 May 11 21:06:01.342127 osdx ulogd[79510]: [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.770 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.770/0.770/0.770/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.293 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.293/0.293/0.293/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
May 11 21:06:09.431031 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.0M, max 15.3M, 13.3M free. May 11 21:06:09.435517 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:06:09.435601 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:06:09.452527 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:06:10.087980 osdx osdx-coredump[79698]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:06:10.102835 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:06:10.920234 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:06:11.072010 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. May 11 21:06:11.249406 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. May 11 21:06:11.396849 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system vrf RED'. May 11 21:06:11.541353 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:06:11.672550 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 11 21:06:11.843691 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:06:11.996925 osdx (udev-worker)[79733]: RED: Could not disable auto negotiation, ignoring: Operation not supported May 11 21:06:11.996975 osdx (udev-worker)[79733]: Network interface NamePolicy= disabled on kernel command line. May 11 21:06:12.037658 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:06:12.185653 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:06:12.354130 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:06:12.355221 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:06:12.356308 osdx ulogd[79816]: registering plugin `NFCT' May 11 21:06:12.356414 osdx ulogd[79816]: registering plugin `IP2STR' May 11 21:06:12.356498 osdx ulogd[79816]: registering plugin `PRINTFLOW' May 11 21:06:12.356586 osdx ulogd[79816]: registering plugin `SYSLOG' May 11 21:06:12.356593 osdx ulogd[79816]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:06:12.356671 osdx ulogd[79816]: NFCT plugin working in event mode May 11 21:06:12.356687 osdx ulogd[79816]: Changing UID / GID May 11 21:06:12.356824 osdx ulogd[79816]: initialization finished, entering main loop May 11 21:06:12.377806 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:06:12.381196 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:06:12.428728 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:06:12.471883 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:06:13.777390 osdx ulogd[79816]: [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 May 11 21:06:13.777430 osdx ulogd[79816]: [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 May 11 21:06:13.900987 osdx ulogd[79816]: [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 May 11 21:06:13.901027 osdx ulogd[79816]: [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.398 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.398/0.398/0.398/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 37068 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.656 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.656/0.656/0.656/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.438 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.438/0.438/0.438/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
May 11 21:06:21.444255 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.0M, max 15.3M, 13.2M free. May 11 21:06:21.448215 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:06:21.448295 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:06:21.462008 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:06:21.933542 osdx osdx-coredump[79996]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:06:21.943008 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:06:22.683355 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:06:22.831520 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 11 21:06:22.990621 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:06:23.144213 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 May 11 21:06:23.241059 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:06:23.290987 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:06:23.320715 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:06:23.509360 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 11 21:06:23.721855 osdx file_operation[80102]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// May 11 21:06:23.755475 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. May 11 21:06:23.932657 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:06:24.054425 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. May 11 21:06:24.228095 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. May 11 21:06:24.354754 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file 'running://test-performance.rules''. May 11 21:06:24.471380 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. May 11 21:06:24.621401 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. May 11 21:06:24.740328 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. May 11 21:06:24.885213 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. May 11 21:06:24.986274 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. May 11 21:06:25.105735 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. May 11 21:06:25.211180 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:06:25.300245 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 11 21:06:25.462366 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:06:25.680224 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:06:25.816632 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:06:25.817815 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:06:25.818950 osdx ulogd[80211]: registering plugin `NFCT' May 11 21:06:25.819255 osdx ulogd[80211]: registering plugin `IP2STR' May 11 21:06:25.819386 osdx ulogd[80211]: registering plugin `PRINTFLOW' May 11 21:06:25.819534 osdx ulogd[80211]: registering plugin `SYSLOG' May 11 21:06:25.819603 osdx ulogd[80211]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:06:25.819717 osdx ulogd[80211]: NFCT plugin working in event mode May 11 21:06:25.819781 osdx ulogd[80211]: Changing UID / GID May 11 21:06:25.819936 osdx ulogd[80211]: initialization finished, entering main loop May 11 21:06:25.824233 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:06:26.102062 osdx systemd[1]: Reloading. May 11 21:06:26.256188 osdx systemd-sysv-generator[80246]: stat() failed on /etc/init.d/README, ignoring: No such file or directory May 11 21:06:26.404733 osdx systemd[1]: Starting logrotate.service - Rotate log files... May 11 21:06:26.412380 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata. May 11 21:06:26.413836 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... May 11 21:06:26.440475 osdx systemd[1]: logrotate.service: Deactivated successfully. May 11 21:06:26.440685 osdx systemd[1]: Finished logrotate.service - Rotate log files. May 11 21:06:26.805765 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. May 11 21:06:27.054576 osdx INFO[80228]: Rules successfully loaded May 11 21:06:27.072935 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:06:27.072990 osdx ulogd[80211]: Terminal signal received, exiting May 11 21:06:27.073706 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 11 21:06:27.073835 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:06:27.096683 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:06:27.097877 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:06:27.098672 osdx ulogd[80274]: registering plugin `NFCT' May 11 21:06:27.098740 osdx ulogd[80274]: registering plugin `IP2STR' May 11 21:06:27.098818 osdx ulogd[80274]: registering plugin `PRINTFLOW' May 11 21:06:27.098886 osdx ulogd[80274]: registering plugin `SYSLOG' May 11 21:06:27.098891 osdx ulogd[80274]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:06:27.098947 osdx ulogd[80274]: NFCT plugin working in event mode May 11 21:06:27.098956 osdx ulogd[80274]: Changing UID / GID May 11 21:06:27.099043 osdx ulogd[80274]: initialization finished, entering main loop May 11 21:06:27.112271 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:06:27.114810 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:06:27.158009 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:06:27.188423 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:06:28.380019 osdx ulogd[80274]: [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) May 11 21:06:28.380048 osdx ulogd[80274]: [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) May 11 21:06:28.523086 osdx ulogd[80274]: [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) May 11 21:06:28.523132 osdx ulogd[80274]: [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=1.62 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 1.624/1.624/1.624/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.785 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.785/0.785/0.785/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.5 This system includes free software. Contact Teldat for licenses information and source code. Last login: Sun May 11 21:03:36 2025 from 10.215.168.64 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
May 11 21:06:37.429811 osdx systemd-journald[1583]: Runtime Journal (/run/log/journal/f55f446d40464b198e70fbabb9c21674) is 2.0M, max 15.3M, 13.2M free. May 11 21:06:37.432657 osdx systemd-journald[1583]: Received client request to rotate journal, rotating. May 11 21:06:37.432740 osdx systemd-journald[1583]: Vacuuming done, freed 0B of archived journals from /run/log/journal/f55f446d40464b198e70fbabb9c21674. May 11 21:06:37.449809 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system journal clear'. May 11 21:06:38.073629 osdx osdx-coredump[80489]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 11 21:06:38.084285 osdx OSDxCLI[74986]: User 'admin' executed a new command: 'system coredump delete all'. May 11 21:06:39.067010 osdx OSDxCLI[74986]: User 'admin' entered the configuration menu. May 11 21:06:39.290725 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. May 11 21:06:39.415706 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 11 21:06:39.535180 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 11 21:06:39.698933 osdx OSDxCLI[74986]: User 'admin' added a new cfg line: 'show working'. May 11 21:06:39.892638 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 May 11 21:06:40.045178 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 11 21:06:40.241146 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 11 21:06:40.242898 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 11 21:06:40.243959 osdx ulogd[80627]: registering plugin `NFCT' May 11 21:06:40.244051 osdx ulogd[80627]: registering plugin `IP2STR' May 11 21:06:40.244148 osdx ulogd[80627]: registering plugin `PRINTFLOW' May 11 21:06:40.244241 osdx ulogd[80627]: registering plugin `SYSLOG' May 11 21:06:40.244247 osdx ulogd[80627]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 11 21:06:40.244326 osdx ulogd[80627]: NFCT plugin working in event mode May 11 21:06:40.244339 osdx ulogd[80627]: Changing UID / GID May 11 21:06:40.244467 osdx ulogd[80627]: initialization finished, entering main loop May 11 21:06:40.260713 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 11 21:06:40.262889 osdx cfgd[1244]: [74986]Completed change to active configuration May 11 21:06:40.307517 osdx OSDxCLI[74986]: User 'admin' committed the configuration. May 11 21:06:40.367186 osdx OSDxCLI[74986]: User 'admin' left the configuration menu. May 11 21:06:43.509255 osdx ulogd[80627]: [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 May 11 21:06:43.509294 osdx ulogd[80627]: [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 May 11 21:06:43.676349 osdx ulogd[80627]: [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 May 11 21:06:43.676384 osdx ulogd[80627]: [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 May 11 21:06:43.907266 osdx ulogd[80627]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 May 11 21:06:43.907498 osdx ulogd[80627]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 May 11 21:06:43.907767 osdx ulogd[80627]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 [OFFLOAD] May 11 21:06:44.345035 osdx ulogd[80627]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 May 11 21:06:44.345089 osdx ulogd[80627]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 [OFFLOAD] May 11 21:06:44.348080 osdx ulogd[80627]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 May 11 21:06:44.348383 osdx ulogd[80627]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41440 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41440 PKTS=0 BYTES=0 [OFFLOAD]