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.368 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.439/0.439/0.439/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
Jul 03 14:44:42.280530 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.2M free.
Jul 03 14:44:42.283135 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:44:42.283194 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:44:42.292001 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:44:42.615776 osdx osdx-coredump[46231]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:44:42.623204 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:44:43.075042 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:44:43.142989 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:44:43.228598 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
Jul 03 14:44:43.304094 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:44:43.419130 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:44:43.483444 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:44:43.486099 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:44:43.487442 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:44:43.490260 osdx ulogd[46289]: registering plugin `NFCT'
Jul 03 14:44:43.491005 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:44:43.491799 osdx ulogd[46289]: registering plugin `IP2STR'
Jul 03 14:44:43.491899 osdx ulogd[46289]: registering plugin `PRINTFLOW'
Jul 03 14:44:43.493159 osdx ulogd[46289]: registering plugin `SYSLOG'
Jul 03 14:44:43.493166 osdx ulogd[46289]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:44:43.493223 osdx ulogd[46289]: NFCT plugin working in event mode
Jul 03 14:44:43.493232 osdx ulogd[46289]: Changing UID / GID
Jul 03 14:44:43.493329 osdx ulogd[46289]: initialization finished, entering main loop
Jul 03 14:44:43.507444 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:44:44.255763 osdx ulogd[46289]: [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
Jul 03 14:44:44.328843 osdx ulogd[46289]: [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.595 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.321/0.321/0.321/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
Jul 03 14:44:49.355062 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:44:49.358541 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:44:49.358610 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:44:49.368987 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:44:49.709826 osdx osdx-coredump[46424]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:44:49.720342 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:44:50.217189 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:44:50.339099 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:44:50.400992 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
Jul 03 14:44:50.529258 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:44:50.618524 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:44:50.674816 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:44:50.675528 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jul 03 14:44:50.676087 osdx ulogd[46482]: registering plugin `NFCT'
Jul 03 14:44:50.676129 osdx ulogd[46482]: registering plugin `IP2STR'
Jul 03 14:44:50.676168 osdx ulogd[46482]: registering plugin `PRINTFLOW'
Jul 03 14:44:50.676213 osdx ulogd[46482]: registering plugin `SYSLOG'
Jul 03 14:44:50.676216 osdx ulogd[46482]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:44:50.676256 osdx ulogd[46482]: NFCT plugin working in event mode
Jul 03 14:44:50.676263 osdx ulogd[46482]: Changing UID / GID
Jul 03 14:44:50.676331 osdx ulogd[46482]: initialization finished, entering main loop
Jul 03 14:44:50.694596 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:44:50.696289 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:44:50.698593 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:44:50.716772 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:44:51.478747 osdx ulogd[46482]: [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
Jul 03 14:44:51.556850 osdx ulogd[46482]: [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.626 ms

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

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2037ms
rtt min/avg/max/mdev = 0.293/0.334/0.377/0.034 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
Jul 03 14:44:55.283412 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:44:55.285814 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:44:55.285886 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:44:55.292973 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:44:55.601282 osdx osdx-coredump[46617]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:44:55.608904 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:44:56.074503 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:44:56.148179 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:44:56.259097 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
Jul 03 14:44:56.317265 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jul 03 14:44:56.410219 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service ssh'.
Jul 03 14:44:56.504241 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:44:56.633802 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:44:56.714105 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Jul 03 14:44:56.735640 osdx sshd[46685]: Server listening on 0.0.0.0 port 22.
Jul 03 14:44:56.735665 osdx sshd[46685]: Server listening on :: port 22.
Jul 03 14:44:56.735764 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Jul 03 14:44:56.802130 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:44:56.803002 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jul 03 14:44:56.803423 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:44:56.804301 osdx ulogd[46701]: registering plugin `NFCT'
Jul 03 14:44:56.804457 osdx ulogd[46701]: registering plugin `IP2STR'
Jul 03 14:44:56.804501 osdx ulogd[46701]: registering plugin `PRINTFLOW'
Jul 03 14:44:56.804547 osdx ulogd[46701]: registering plugin `SYSLOG'
Jul 03 14:44:56.804551 osdx ulogd[46701]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:44:56.804593 osdx ulogd[46701]: NFCT plugin working in event mode
Jul 03 14:44:56.804600 osdx ulogd[46701]: Changing UID / GID
Jul 03 14:44:56.804679 osdx ulogd[46701]: initialization finished, entering main loop
Jul 03 14:44:56.805120 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:44:56.807338 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:44:56.838426 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:44:58.745865 osdx ulogd[46701]: [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
Jul 03 14:44:59.769901 osdx ulogd[46701]: [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.749 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.749/0.749/0.749/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
Jul 03 14:45:07.300895 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:45:07.301724 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:45:07.301760 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:45:07.310869 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:45:07.640525 osdx osdx-coredump[46856]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:45:07.647968 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:45:08.098554 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:45:08.164468 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:45:08.239266 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jul 03 14:45:08.314966 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:45:08.417744 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:45:08.478005 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:45:08.479148 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jul 03 14:45:08.479446 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:45:08.480654 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:45:08.481133 osdx ulogd[46914]: registering plugin `NFCT'
Jul 03 14:45:08.481185 osdx ulogd[46914]: registering plugin `IP2STR'
Jul 03 14:45:08.481226 osdx ulogd[46914]: registering plugin `PRINTFLOW'
Jul 03 14:45:08.481270 osdx ulogd[46914]: registering plugin `SYSLOG'
Jul 03 14:45:08.481274 osdx ulogd[46914]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:45:08.481317 osdx ulogd[46914]: NFCT plugin working in event mode
Jul 03 14:45:08.481324 osdx ulogd[46914]: Changing UID / GID
Jul 03 14:45:08.481394 osdx ulogd[46914]: initialization finished, entering main loop
Jul 03 14:45:08.482902 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:45:08.498929 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:45:09.288602 osdx ulogd[46914]: [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
Jul 03 14:45:09.288628 osdx ulogd[46914]: [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
Jul 03 14:45:09.357712 osdx ulogd[46914]: [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
Jul 03 14:45:09.357738 osdx ulogd[46914]: [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 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.525 ms

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

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1012ms
rtt min/avg/max/mdev = 0.308/0.447/0.586/0.139 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
Jul 03 14:45:13.290640 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:45:13.292293 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:45:13.292348 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:45:13.301223 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:45:13.618498 osdx osdx-coredump[47051]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:45:13.625613 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:45:14.029120 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:45:14.098597 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jul 03 14:45:14.181773 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set traffic label TEST'.
Jul 03 14:45:14.237438 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
Jul 03 14:45:14.339969 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
Jul 03 14:45:14.417681 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:45:14.526137 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jul 03 14:45:14.613091 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:45:14.760234 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:45:15.020603 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:45:15.021588 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:45:15.022014 osdx ulogd[47140]: registering plugin `NFCT'
Jul 03 14:45:15.022061 osdx ulogd[47140]: registering plugin `IP2STR'
Jul 03 14:45:15.022109 osdx ulogd[47140]: registering plugin `PRINTFLOW'
Jul 03 14:45:15.022162 osdx ulogd[47140]: registering plugin `SYSLOG'
Jul 03 14:45:15.022166 osdx ulogd[47140]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:45:15.022213 osdx ulogd[47140]: NFCT plugin working in event mode
Jul 03 14:45:15.022220 osdx ulogd[47140]: Changing UID / GID
Jul 03 14:45:15.022295 osdx ulogd[47140]: initialization finished, entering main loop
Jul 03 14:45:15.023739 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:45:15.026157 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:45:15.041840 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:45:15.867969 osdx ulogd[47140]: [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
Jul 03 14:45:15.868158 osdx ulogd[47140]: [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
Jul 03 14:45:15.940366 osdx ulogd[47140]: [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
Jul 03 14:45:15.940557 osdx ulogd[47140]: [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 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.342 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.302/0.302/0.302/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
Jul 03 14:45:21.341047 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:45:21.343553 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:45:21.343643 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:45:21.353676 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:45:21.682161 osdx osdx-coredump[47294]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:45:21.690080 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:45:22.195666 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:45:22.263459 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
Jul 03 14:45:22.360691 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'.
Jul 03 14:45:22.413093 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system vrf RED'.
Jul 03 14:45:22.516452 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:45:22.578970 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jul 03 14:45:22.689091 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:45:22.775355 osdx (udev-worker)[47328]: RED: Could not disable auto negotiation, ignoring: Operation not supported
Jul 03 14:45:22.775388 osdx (udev-worker)[47328]: Network interface NamePolicy= disabled on kernel command line.
Jul 03 14:45:22.795545 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:45:22.815570 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:45:22.899921 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:45:22.900742 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jul 03 14:45:22.901101 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:45:22.901944 osdx ulogd[47383]: registering plugin `NFCT'
Jul 03 14:45:22.901988 osdx ulogd[47383]: registering plugin `IP2STR'
Jul 03 14:45:22.902035 osdx ulogd[47383]: registering plugin `PRINTFLOW'
Jul 03 14:45:22.902080 osdx ulogd[47383]: registering plugin `SYSLOG'
Jul 03 14:45:22.902083 osdx ulogd[47383]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:45:22.902124 osdx ulogd[47383]: NFCT plugin working in event mode
Jul 03 14:45:22.902131 osdx ulogd[47383]: Changing UID / GID
Jul 03 14:45:22.902202 osdx ulogd[47383]: initialization finished, entering main loop
Jul 03 14:45:22.903181 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:45:22.944815 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:45:22.969574 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:45:23.845835 osdx ulogd[47383]: [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
Jul 03 14:45:23.845865 osdx ulogd[47383]: [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
Jul 03 14:45:23.918488 osdx ulogd[47383]: [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
Jul 03 14:45:23.918516 osdx ulogd[47383]: [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.225 ms

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

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.910 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.409/0.409/0.409/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
Jul 03 14:45:28.299877 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:45:28.301143 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:45:28.301201 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:45:28.313825 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:45:28.657178 osdx osdx-coredump[47555]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:45:28.665814 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:45:29.180985 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:45:29.276641 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jul 03 14:45:29.345414 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:45:29.461166 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jul 03 14:45:29.486777 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:45:29.489097 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:45:29.510133 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:45:29.712886 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'ping 10.215.168.1      count 1 size 56 timeout 1'.
Jul 03 14:45:29.866914 osdx file_operation[47632]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
Jul 03 14:45:29.890301 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
Jul 03 14:45:30.050354 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:45:30.128626 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jul 03 14:45:30.226068 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
Jul 03 14:45:30.303861 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file 'running://test-performance.rules''.
Jul 03 14:45:30.399565 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
Jul 03 14:45:30.465730 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
Jul 03 14:45:30.556969 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
Jul 03 14:45:30.635530 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
Jul 03 14:45:30.694356 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
Jul 03 14:45:30.781044 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
Jul 03 14:45:30.841735 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:45:30.931177 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jul 03 14:45:31.012993 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:45:31.201159 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:45:31.481680 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:45:31.482516 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:45:31.482711 osdx ulogd[47730]: registering plugin `NFCT'
Jul 03 14:45:31.482771 osdx ulogd[47730]: registering plugin `IP2STR'
Jul 03 14:45:31.482828 osdx ulogd[47730]: registering plugin `PRINTFLOW'
Jul 03 14:45:31.482888 osdx ulogd[47730]: registering plugin `SYSLOG'
Jul 03 14:45:31.482893 osdx ulogd[47730]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:45:31.482949 osdx ulogd[47730]: NFCT plugin working in event mode
Jul 03 14:45:31.482958 osdx ulogd[47730]: Changing UID / GID
Jul 03 14:45:31.483055 osdx ulogd[47730]: initialization finished, entering main loop
Jul 03 14:45:31.538396 osdx systemd[1]: Reloading.
Jul 03 14:45:31.645159 osdx systemd-sysv-generator[47749]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
Jul 03 14:45:31.749851 osdx systemd[1]: Starting logrotate.service - Rotate log files...
Jul 03 14:45:31.755182 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata.
Jul 03 14:45:31.756350 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
Jul 03 14:45:31.774698 osdx systemd[1]: logrotate.service: Deactivated successfully.
Jul 03 14:45:31.774837 osdx systemd[1]: Finished logrotate.service - Rotate log files.
Jul 03 14:45:32.177076 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
Jul 03 14:45:32.517999 osdx INFO[47731]: Rules successfully loaded
Jul 03 14:45:32.522194 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:45:32.525077 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:45:32.542867 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:45:33.361192 osdx ulogd[47730]: [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)
Jul 03 14:45:33.361220 osdx ulogd[47730]: [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)
Jul 03 14:45:33.447788 osdx ulogd[47730]: [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)
Jul 03 14:45:33.447814 osdx ulogd[47730]: [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.450 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.450/0.450/0.450/0.000 ms

Step 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.858 ms

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

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

Last login: Wed Jul  3 14:44:27 2024 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
Jul 03 14:45:40.301752 osdx systemd-journald[19587]: Runtime Journal (/run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b) is 2.0M, max 15.3M, 13.3M free.
Jul 03 14:45:40.304649 osdx systemd-journald[19587]: Received client request to rotate journal, rotating.
Jul 03 14:45:40.304711 osdx systemd-journald[19587]: Vacuuming done, freed 0B of archived journals from /run/log/journal/aa1bd7befff24a8b91d1e90ef92c032b.
Jul 03 14:45:40.313770 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system journal clear'.
Jul 03 14:45:40.732899 osdx osdx-coredump[47969]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jul 03 14:45:40.742683 osdx OSDxCLI[44147]: User 'admin' executed a new command: 'system coredump delete all'.
Jul 03 14:45:41.339613 osdx OSDxCLI[44147]: User 'admin' entered the configuration menu.
Jul 03 14:45:41.456304 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
Jul 03 14:45:41.522103 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jul 03 14:45:41.623975 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jul 03 14:45:41.707296 osdx OSDxCLI[44147]: User 'admin' added a new cfg line: 'show working'.
Jul 03 14:45:41.824657 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jul 03 14:45:41.852660 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jul 03 14:45:41.901000 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jul 03 14:45:41.901652 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jul 03 14:45:41.902085 osdx ulogd[48053]: registering plugin `NFCT'
Jul 03 14:45:41.902292 osdx ulogd[48053]: registering plugin `IP2STR'
Jul 03 14:45:41.902369 osdx ulogd[48053]: registering plugin `PRINTFLOW'
Jul 03 14:45:41.902446 osdx ulogd[48053]: registering plugin `SYSLOG'
Jul 03 14:45:41.902479 osdx ulogd[48053]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jul 03 14:45:41.902550 osdx ulogd[48053]: NFCT plugin working in event mode
Jul 03 14:45:41.902588 osdx ulogd[48053]: Changing UID / GID
Jul 03 14:45:41.902684 osdx ulogd[48053]: initialization finished, entering main loop
Jul 03 14:45:41.916731 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jul 03 14:45:41.918232 osdx cfgd[1440]: [44147]Completed change to active configuration
Jul 03 14:45:41.920341 osdx OSDxCLI[44147]: User 'admin' committed the configuration.
Jul 03 14:45:41.941172 osdx OSDxCLI[44147]: User 'admin' left the configuration menu.
Jul 03 14:45:43.626132 osdx ulogd[48053]: [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
Jul 03 14:45:43.626153 osdx ulogd[48053]: [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
Jul 03 14:45:43.702193 osdx ulogd[48053]: [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
Jul 03 14:45:43.702213 osdx ulogd[48053]: [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
Jul 03 14:45:43.822024 osdx ulogd[48053]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42650 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42650 PKTS=0 BYTES=0
Jul 03 14:45:43.822248 osdx ulogd[48053]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42650 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42650 PKTS=0 BYTES=0
Jul 03 14:45:43.822517 osdx ulogd[48053]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42650 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42650 PKTS=0 BYTES=0 [OFFLOAD]
Jul 03 14:45:44.108942 osdx ulogd[48053]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42650 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42650 PKTS=0 BYTES=0
Jul 03 14:45:44.111181 osdx ulogd[48053]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42650 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42650 PKTS=0 BYTES=0
Jul 03 14:45:44.111311 osdx ulogd[48053]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42650 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42650 PKTS=0 BYTES=0 [OFFLOAD]