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.

New events

Description

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.226/0.226/0.226/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
Mar 10 09:32:20.323206 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:32:20.323817 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:32:20.323861 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:32:20.332923 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:32:20.649433 osdx osdx-coredump[54415]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:32:20.657124 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:32:21.125355 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:21.203397 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:32:21.285497 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
Mar 10 09:32:21.352283 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:32:21.464047 osdx INFO[54439]: FRR daemons did not change
Mar 10 09:32:21.491856 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:32:21.596127 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:21.598815 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:32:21.601614 osdx ulogd[54508]: registering plugin `NFCT'
Mar 10 09:32:21.602424 osdx ulogd[54508]: registering plugin `IP2STR'
Mar 10 09:32:21.602479 osdx ulogd[54508]: registering plugin `PRINTFLOW'
Mar 10 09:32:21.603507 osdx ulogd[54508]: registering plugin `SYSLOG'
Mar 10 09:32:21.603513 osdx ulogd[54508]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:21.603554 osdx ulogd[54508]: NFCT plugin working in event mode
Mar 10 09:32:21.603562 osdx ulogd[54508]: Changing UID / GID
Mar 10 09:32:21.603631 osdx ulogd[54508]: initialization finished, entering main loop
Mar 10 09:32:21.611857 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:21.613276 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:21.638769 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:21.655981 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:22.496516 osdx ulogd[54508]: [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
Mar 10 09:32:22.588620 osdx ulogd[54508]: [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

Update events

Description

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.253/0.253/0.253/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
Mar 10 09:32:27.309155 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:32:27.309849 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:32:27.309896 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:32:27.320138 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:32:27.679332 osdx osdx-coredump[54658]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:32:27.686892 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:32:28.230978 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:28.333724 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:32:28.408108 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
Mar 10 09:32:28.516141 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:32:28.583803 osdx INFO[54682]: FRR daemons did not change
Mar 10 09:32:28.609860 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:32:28.718148 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:28.719320 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:28.719545 osdx ulogd[54751]: registering plugin `NFCT'
Mar 10 09:32:28.719606 osdx ulogd[54751]: registering plugin `IP2STR'
Mar 10 09:32:28.719643 osdx ulogd[54751]: registering plugin `PRINTFLOW'
Mar 10 09:32:28.720036 osdx ulogd[54751]: registering plugin `SYSLOG'
Mar 10 09:32:28.720042 osdx ulogd[54751]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:28.720081 osdx ulogd[54751]: NFCT plugin working in event mode
Mar 10 09:32:28.720087 osdx ulogd[54751]: Changing UID / GID
Mar 10 09:32:28.720153 osdx ulogd[54751]: initialization finished, entering main loop
Mar 10 09:32:28.721287 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:28.748555 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:28.773523 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:29.608535 osdx ulogd[54751]: [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
Mar 10 09:32:29.689555 osdx ulogd[54751]: [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

Destroy events

Description

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.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 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.215 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.334 ms
64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.260 ms

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2032ms
rtt min/avg/max/mdev = 0.215/0.269/0.334/0.049 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
Mar 10 09:32:33.000191 osdx systemd-timedated[49917]: Changed local time to Mon 2025-03-10 09:32:33 UTC
Mar 10 09:32:33.001376 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'set date 2025-03-10 09:32:33'.
Mar 10 09:32:33.001698 osdx systemd-journald[1668]: Time jumped backwards, rotating.
Mar 10 09:32:33.408868 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.3M free.
Mar 10 09:32:33.410017 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:32:33.410080 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:32:33.420611 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:32:33.751977 osdx osdx-coredump[54902]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:32:33.759586 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:32:34.319000 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:34.402276 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:32:34.527753 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
Mar 10 09:32:34.595310 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Mar 10 09:32:34.732452 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service ssh'.
Mar 10 09:32:34.809077 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:32:34.920709 osdx INFO[54934]: FRR daemons did not change
Mar 10 09:32:34.949724 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:32:35.074042 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:35.074800 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:32:35.075133 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:35.076116 osdx ulogd[55005]: registering plugin `NFCT'
Mar 10 09:32:35.076162 osdx ulogd[55005]: registering plugin `IP2STR'
Mar 10 09:32:35.076206 osdx ulogd[55005]: registering plugin `PRINTFLOW'
Mar 10 09:32:35.076258 osdx ulogd[55005]: registering plugin `SYSLOG'
Mar 10 09:32:35.076262 osdx ulogd[55005]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:35.076313 osdx ulogd[55005]: NFCT plugin working in event mode
Mar 10 09:32:35.076320 osdx ulogd[55005]: Changing UID / GID
Mar 10 09:32:35.076401 osdx ulogd[55005]: initialization finished, entering main loop
Mar 10 09:32:35.142042 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Mar 10 09:32:35.155903 osdx sshd[55011]: Server listening on 0.0.0.0 port 22.
Mar 10 09:32:35.156197 osdx sshd[55011]: Server listening on :: port 22.
Mar 10 09:32:35.156365 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Mar 10 09:32:35.179953 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:35.206933 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:35.248500 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:37.297314 osdx ulogd[55005]: [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
Mar 10 09:32:38.321204 osdx ulogd[55005]: [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

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.239/0.239/0.239/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
Mar 10 09:32:46.304476 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:32:46.306383 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:32:46.306475 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:32:46.314936 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:32:46.704330 osdx osdx-coredump[55186]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:32:46.711978 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:32:47.175971 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:47.252828 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:32:47.336178 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:32:47.407701 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:32:47.502899 osdx INFO[55210]: FRR daemons did not change
Mar 10 09:32:47.526380 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:32:47.618909 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:47.620512 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:32:47.621532 osdx ulogd[55279]: registering plugin `NFCT'
Mar 10 09:32:47.621607 osdx ulogd[55279]: registering plugin `IP2STR'
Mar 10 09:32:47.621672 osdx ulogd[55279]: registering plugin `PRINTFLOW'
Mar 10 09:32:47.621738 osdx ulogd[55279]: registering plugin `SYSLOG'
Mar 10 09:32:47.621744 osdx ulogd[55279]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:47.621818 osdx ulogd[55279]: NFCT plugin working in event mode
Mar 10 09:32:47.621829 osdx ulogd[55279]: Changing UID / GID
Mar 10 09:32:47.621950 osdx ulogd[55279]: initialization finished, entering main loop
Mar 10 09:32:47.634424 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:47.635623 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:47.661600 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:47.690670 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:48.550168 osdx ulogd[55279]: [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
Mar 10 09:32:48.550186 osdx ulogd[55279]: [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
Mar 10 09:32:48.627970 osdx ulogd[55279]: [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
Mar 10 09:32:48.627989 osdx ulogd[55279]: [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

Identity logging

Description

Set a simple configuration with identity OSDx_DUT0 for logs entries, send a ping command from one device to other and check that the identity has changed 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 conntrack logging identity OSDx_DUT0
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.284 ms

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

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

Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

OSDx_DUT0\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2
Show output
Mar 10 09:32:52.318425 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.1M, max 15.3M, 13.2M free.
Mar 10 09:32:52.320329 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:32:52.320398 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:32:52.329937 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:32:52.642420 osdx osdx-coredump[55429]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:32:52.650510 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:32:53.111887 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:53.188006 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:32:53.271942 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:32:53.328664 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Mar 10 09:32:53.447280 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:32:53.515178 osdx INFO[55454]: FRR daemons did not change
Mar 10 09:32:53.544365 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:32:53.648584 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:53.649251 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:53.649523 osdx ulogd[55523]: registering plugin `NFCT'
Mar 10 09:32:53.649580 osdx ulogd[55523]: registering plugin `IP2STR'
Mar 10 09:32:53.649627 osdx ulogd[55523]: registering plugin `PRINTFLOW'
Mar 10 09:32:53.649679 osdx ulogd[55523]: registering plugin `SYSLOG'
Mar 10 09:32:53.649684 osdx ulogd[55523]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:53.649741 osdx ulogd[55523]: NFCT plugin working in event mode
Mar 10 09:32:53.649754 osdx OSDx_DUT0[55523]: Changing UID / GID
Mar 10 09:32:53.649840 osdx OSDx_DUT0[55523]: initialization finished, entering main loop
Mar 10 09:32:53.650930 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:53.677147 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:53.708887 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:54.615405 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.615426 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.695033 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.695057 osdx OSDx_DUT0[55523]: [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

Note

If the identity is not provided, “ulogd” will be used by default.

Step 6: Modify the following configuration lines in DUT0 :

delete system conntrack logging identity

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.273/0.273/0.273/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))\].*SRC=192.168.100.2
Show output
Mar 10 09:32:52.318425 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.1M, max 15.3M, 13.2M free.
Mar 10 09:32:52.320329 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:32:52.320398 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:32:52.329937 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:32:52.642420 osdx osdx-coredump[55429]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:32:52.650510 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:32:53.111887 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:53.188006 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:32:53.271942 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:32:53.328664 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Mar 10 09:32:53.447280 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:32:53.515178 osdx INFO[55454]: FRR daemons did not change
Mar 10 09:32:53.544365 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:32:53.648584 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:53.649251 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:53.649523 osdx ulogd[55523]: registering plugin `NFCT'
Mar 10 09:32:53.649580 osdx ulogd[55523]: registering plugin `IP2STR'
Mar 10 09:32:53.649627 osdx ulogd[55523]: registering plugin `PRINTFLOW'
Mar 10 09:32:53.649679 osdx ulogd[55523]: registering plugin `SYSLOG'
Mar 10 09:32:53.649684 osdx ulogd[55523]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:53.649741 osdx ulogd[55523]: NFCT plugin working in event mode
Mar 10 09:32:53.649754 osdx OSDx_DUT0[55523]: Changing UID / GID
Mar 10 09:32:53.649840 osdx OSDx_DUT0[55523]: initialization finished, entering main loop
Mar 10 09:32:53.650930 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:53.677147 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:53.708887 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:54.615405 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.615426 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.695033 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.695057 osdx OSDx_DUT0[55523]: [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
Mar 10 09:32:54.803425 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.
Mar 10 09:32:54.966242 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:32:55.024740 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'.
Mar 10 09:32:55.118899 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show changes'.
Mar 10 09:32:55.195616 osdx INFO[55559]: FRR daemons did not change
Mar 10 09:32:55.205192 osdx OSDx_DUT0[55523]: Terminal signal received, exiting
Mar 10 09:32:55.205261 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:55.205493 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Mar 10 09:32:55.205587 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:55.228588 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:32:55.229216 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:32:55.230349 osdx ulogd[55568]: registering plugin `NFCT'
Mar 10 09:32:55.230465 osdx ulogd[55568]: registering plugin `IP2STR'
Mar 10 09:32:55.230573 osdx ulogd[55568]: registering plugin `PRINTFLOW'
Mar 10 09:32:55.230678 osdx ulogd[55568]: registering plugin `SYSLOG'
Mar 10 09:32:55.230687 osdx ulogd[55568]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:32:55.230796 osdx ulogd[55568]: NFCT plugin working in event mode
Mar 10 09:32:55.230815 osdx ulogd[55568]: Changing UID / GID
Mar 10 09:32:55.230995 osdx ulogd[55568]: initialization finished, entering main loop
Mar 10 09:32:55.231149 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:32:55.234301 osdx ulogd[55568]: [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
Mar 10 09:32:55.234340 osdx ulogd[55568]: [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
Mar 10 09:32:55.235034 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:32:55.253389 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:32:55.400012 osdx ulogd[55568]: [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
Mar 10 09:32:55.400033 osdx ulogd[55568]: [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

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

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

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1030ms
rtt min/avg/max/mdev = 0.260/0.315/0.370/0.055 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
Mar 10 09:33:00.293377 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.3M free.
Mar 10 09:33:00.297303 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:00.297369 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:00.303718 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:00.638287 osdx osdx-coredump[55699]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:00.648429 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:01.103968 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:01.183013 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Mar 10 09:33:01.266504 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic label TEST'.
Mar 10 09:33:01.335209 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
Mar 10 09:33:01.433150 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
Mar 10 09:33:01.491471 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:01.591562 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:01.675466 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:01.776982 osdx INFO[55733]: FRR daemons did not change
Mar 10 09:33:01.801247 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:01.917604 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:01.918503 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:01.918595 osdx ulogd[55805]: registering plugin `NFCT'
Mar 10 09:33:01.918836 osdx ulogd[55805]: registering plugin `IP2STR'
Mar 10 09:33:01.918926 osdx ulogd[55805]: registering plugin `PRINTFLOW'
Mar 10 09:33:01.919004 osdx ulogd[55805]: registering plugin `SYSLOG'
Mar 10 09:33:01.919035 osdx ulogd[55805]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:01.919101 osdx ulogd[55805]: NFCT plugin working in event mode
Mar 10 09:33:01.919133 osdx ulogd[55805]: Changing UID / GID
Mar 10 09:33:01.919224 osdx ulogd[55805]: initialization finished, entering main loop
Mar 10 09:33:01.932974 osdx ulogd[55805]: Terminal signal received, exiting
Mar 10 09:33:01.933058 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:01.933268 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Mar 10 09:33:01.933366 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:01.934327 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:01.935210 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:01.935412 osdx ulogd[55811]: registering plugin `NFCT'
Mar 10 09:33:01.935467 osdx ulogd[55811]: registering plugin `IP2STR'
Mar 10 09:33:01.935514 osdx ulogd[55811]: registering plugin `PRINTFLOW'
Mar 10 09:33:01.935582 osdx ulogd[55811]: registering plugin `SYSLOG'
Mar 10 09:33:01.935586 osdx ulogd[55811]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:01.935635 osdx ulogd[55811]: NFCT plugin working in event mode
Mar 10 09:33:01.935646 osdx ulogd[55811]: Changing UID / GID
Mar 10 09:33:01.935728 osdx ulogd[55811]: initialization finished, entering main loop
Mar 10 09:33:02.098265 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:02.132027 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:02.155568 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:03.131107 osdx ulogd[55811]: [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
Mar 10 09:33:03.131130 osdx ulogd[55811]: [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
Mar 10 09:33:03.222611 osdx ulogd[55811]: [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
Mar 10 09:33:03.222635 osdx ulogd[55811]: [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

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

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.273/0.273/0.273/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
Mar 10 09:33:08.283128 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:08.285905 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:08.285964 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:08.292900 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:08.673835 osdx osdx-coredump[56005]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:08.681700 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:09.250992 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:09.375061 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
Mar 10 09:33:09.438439 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'.
Mar 10 09:33:09.545685 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system vrf RED'.
Mar 10 09:33:09.606360 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:09.704985 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:09.778403 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:09.885104 osdx INFO[56032]: FRR daemons did not change
Mar 10 09:33:09.899314 osdx (udev-worker)[56044]: RED: Could not disable auto negotiation, ignoring: Operation not supported
Mar 10 09:33:09.899602 osdx (udev-worker)[56044]: Network interface NamePolicy= disabled on kernel command line.
Mar 10 09:33:09.925907 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:09.993912 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:10.102200 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:10.103100 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:10.103170 osdx ulogd[56154]: registering plugin `NFCT'
Mar 10 09:33:10.103433 osdx ulogd[56154]: registering plugin `IP2STR'
Mar 10 09:33:10.103481 osdx ulogd[56154]: registering plugin `PRINTFLOW'
Mar 10 09:33:10.103523 osdx ulogd[56154]: registering plugin `SYSLOG'
Mar 10 09:33:10.103529 osdx ulogd[56154]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:10.103572 osdx ulogd[56154]: NFCT plugin working in event mode
Mar 10 09:33:10.103578 osdx ulogd[56154]: Changing UID / GID
Mar 10 09:33:10.103642 osdx ulogd[56154]: initialization finished, entering main loop
Mar 10 09:33:10.104496 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:10.130249 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:10.156553 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:11.159010 osdx ulogd[56154]: [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
Mar 10 09:33:11.159037 osdx ulogd[56154]: [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
Mar 10 09:33:11.238384 osdx ulogd[56154]: [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
Mar 10 09:33:11.238409 osdx ulogd[56154]: [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

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

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

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.346/0.346/0.346/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
Mar 10 09:33:15.290729 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:15.293050 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:15.293118 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:15.303963 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:15.728886 osdx osdx-coredump[56364]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:15.738045 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:16.214388 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:16.290580 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Mar 10 09:33:16.384968 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:16.454152 osdx INFO[56387]: FRR daemons did not change
Mar 10 09:33:16.473047 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Mar 10 09:33:16.541692 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:16.580513 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:16.597489 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:16.752465 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Mar 10 09:33:16.904925 osdx file_operation[56482]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
Mar 10 09:33:16.927851 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
Mar 10 09:33:17.080578 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:17.166631 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Mar 10 09:33:17.272806 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
Mar 10 09:33:17.338551 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'.
Mar 10 09:33:17.408534 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
Mar 10 09:33:17.532147 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
Mar 10 09:33:17.622056 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
Mar 10 09:33:17.687528 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
Mar 10 09:33:17.790744 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
Mar 10 09:33:17.856841 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
Mar 10 09:33:17.967837 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:18.022425 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:18.164623 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:18.281318 osdx INFO[56531]: FRR daemons did not change
Mar 10 09:33:18.305065 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:18.421294 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:18.422204 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:18.422554 osdx ulogd[56600]: registering plugin `NFCT'
Mar 10 09:33:18.422597 osdx ulogd[56600]: registering plugin `IP2STR'
Mar 10 09:33:18.422635 osdx ulogd[56600]: registering plugin `PRINTFLOW'
Mar 10 09:33:18.422673 osdx ulogd[56600]: registering plugin `SYSLOG'
Mar 10 09:33:18.422677 osdx ulogd[56600]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:18.422715 osdx ulogd[56600]: NFCT plugin working in event mode
Mar 10 09:33:18.422720 osdx ulogd[56600]: Changing UID / GID
Mar 10 09:33:18.422782 osdx ulogd[56600]: initialization finished, entering main loop
Mar 10 09:33:18.702011 osdx systemd[1]: Reloading.
Mar 10 09:33:18.793042 osdx systemd-sysv-generator[56637]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
Mar 10 09:33:18.929439 osdx systemd[1]: Starting logrotate.service - Rotate log files...
Mar 10 09:33:18.935214 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata.
Mar 10 09:33:18.936284 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
Mar 10 09:33:18.959218 osdx systemd[1]: logrotate.service: Deactivated successfully.
Mar 10 09:33:18.959326 osdx systemd[1]: Finished logrotate.service - Rotate log files.
Mar 10 09:33:19.199447 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
Mar 10 09:33:19.585784 osdx INFO[56619]: Rules successfully loaded
Mar 10 09:33:19.600117 osdx ulogd[56600]: Terminal signal received, exiting
Mar 10 09:33:19.600237 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:19.600537 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Mar 10 09:33:19.600666 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:19.617390 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:19.618024 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:33:19.618924 osdx ulogd[56666]: registering plugin `NFCT'
Mar 10 09:33:19.619005 osdx ulogd[56666]: registering plugin `IP2STR'
Mar 10 09:33:19.619077 osdx ulogd[56666]: registering plugin `PRINTFLOW'
Mar 10 09:33:19.619151 osdx ulogd[56666]: registering plugin `SYSLOG'
Mar 10 09:33:19.619157 osdx ulogd[56666]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:19.619230 osdx ulogd[56666]: NFCT plugin working in event mode
Mar 10 09:33:19.619241 osdx ulogd[56666]: Changing UID / GID
Mar 10 09:33:19.619357 osdx ulogd[56666]: initialization finished, entering main loop
Mar 10 09:33:19.625085 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:19.628441 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:19.654894 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:19.675344 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:20.493043 osdx ulogd[56666]: [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)
Mar 10 09:33:20.493070 osdx ulogd[56666]: [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)
Mar 10 09:33:20.594243 osdx ulogd[56666]: [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)
Mar 10 09:33:20.594262 osdx ulogd[56666]: [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)

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

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

--- 192.168.200.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.383/0.383/0.383/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' (ECDSA) to the list of known hosts.
admin@192.168.200.2's password:
Welcome to Teldat OSDx v4.2.3.2

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

Last login: Mon Mar 10 08:26:22 2025
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
Mar 10 09:33:28.344500 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:28.347643 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:28.347704 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:28.354032 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:28.706080 osdx osdx-coredump[56888]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:28.713784 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:29.180406 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:29.269562 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
Mar 10 09:33:29.349251 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:29.406237 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:29.522748 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:29.602101 osdx INFO[56915]: FRR daemons did not change
Mar 10 09:33:29.631649 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Mar 10 09:33:29.707646 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:29.811929 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:29.812983 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:33:29.815673 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:29.816207 osdx ulogd[57037]: registering plugin `NFCT'
Mar 10 09:33:29.816248 osdx ulogd[57037]: registering plugin `IP2STR'
Mar 10 09:33:29.816285 osdx ulogd[57037]: registering plugin `PRINTFLOW'
Mar 10 09:33:29.816323 osdx ulogd[57037]: registering plugin `SYSLOG'
Mar 10 09:33:29.816326 osdx ulogd[57037]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:29.816363 osdx ulogd[57037]: NFCT plugin working in event mode
Mar 10 09:33:29.816370 osdx ulogd[57037]: Changing UID / GID
Mar 10 09:33:29.816432 osdx ulogd[57037]: initialization finished, entering main loop
Mar 10 09:33:29.817039 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:29.849430 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:29.867967 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:31.562629 osdx ulogd[57037]: [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
Mar 10 09:33:31.562651 osdx ulogd[57037]: [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
Mar 10 09:33:31.669725 osdx ulogd[57037]: [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
Mar 10 09:33:31.669746 osdx ulogd[57037]: [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
Mar 10 09:33:31.754769 osdx ulogd[57037]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0
Mar 10 09:33:31.754894 osdx ulogd[57037]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0
Mar 10 09:33:31.755015 osdx ulogd[57037]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0 [OFFLOAD]
Mar 10 09:33:32.029275 osdx ulogd[57037]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0
Mar 10 09:33:32.029301 osdx ulogd[57037]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0 [OFFLOAD]
Mar 10 09:33:32.030664 osdx ulogd[57037]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0
Mar 10 09:33:32.030775 osdx ulogd[57037]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47782 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47782 PKTS=0 BYTES=0 [OFFLOAD]

App detect logging

Description

Set a simple configuration enabling app detection in system conntrack, send a ping command from DUT1 and check app detect field appears when running system journal show. After that, enabling app detection in system conntrack for http host, try to copy index.html from a http server and check that the app detect field appears and belongs to the http server 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 app-detect
set system conntrack logging events all
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.372 ms

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

Step 4: Ping IP address 192.168.100.1 from DUT1:

admin@DUT1$ ping 192.168.100.1 count 3 size 56 timeout 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.280 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.328 ms
64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.310 ms

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2043ms
rtt min/avg/max/mdev = 0.280/0.306/0.328/0.019 ms

Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[NEW\].*APPDETECT\[L3:1\]
Show output
Mar 10 09:33:36.291013 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:36.292665 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:36.292730 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:36.301849 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:36.641545 osdx osdx-coredump[57195]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:36.651158 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:37.129990 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:37.203328 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Mar 10 09:33:37.304144 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Mar 10 09:33:37.416711 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:37.469802 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:37.585610 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:37.652894 osdx INFO[57221]: FRR daemons did not change
Mar 10 09:33:37.804650 osdx kernel: app-detect: module init
Mar 10 09:33:37.804718 osdx kernel: app-detect: registered: sysctl net.appdetect
Mar 10 09:33:37.804731 osdx kernel: app-detect: expression init
Mar 10 09:33:37.804743 osdx kernel: app-detect: appid cache initialized
Mar 10 09:33:37.804755 osdx kernel: app-detect: appid cache changes counter initialized
Mar 10 09:33:37.811209 osdx modulelauncher[57224]: AppDetect: no change in application dictionaries, thus nothing more to do
Mar 10 09:33:37.840673 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:37.944918 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:37.945786 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:33:37.946144 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:37.948132 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:37.948296 osdx ulogd[57313]: registering plugin `NFCT'
Mar 10 09:33:37.948341 osdx ulogd[57313]: registering plugin `IP2STR'
Mar 10 09:33:37.948380 osdx ulogd[57313]: registering plugin `PRINTFLOW'
Mar 10 09:33:37.948419 osdx ulogd[57313]: registering plugin `SYSLOG'
Mar 10 09:33:37.948423 osdx ulogd[57313]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:37.948463 osdx ulogd[57313]: NFCT plugin working in event mode
Mar 10 09:33:37.948469 osdx ulogd[57313]: Changing UID / GID
Mar 10 09:33:37.948533 osdx ulogd[57313]: initialization finished, entering main loop
Mar 10 09:33:37.975348 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:37.999913 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:38.816078 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.816102 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901210 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901235 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920231 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920256 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920270 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944218 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944239 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944250 osdx ulogd[57313]: [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 APPDETECT[L3:1]

Step 6: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[UPDATE\].*APPDETECT\[L3:1\]
Show output
Mar 10 09:33:36.291013 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:36.292665 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:36.292730 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:36.301849 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:36.641545 osdx osdx-coredump[57195]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:36.651158 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:37.129990 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:37.203328 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Mar 10 09:33:37.304144 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Mar 10 09:33:37.416711 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:37.469802 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:37.585610 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:37.652894 osdx INFO[57221]: FRR daemons did not change
Mar 10 09:33:37.804650 osdx kernel: app-detect: module init
Mar 10 09:33:37.804718 osdx kernel: app-detect: registered: sysctl net.appdetect
Mar 10 09:33:37.804731 osdx kernel: app-detect: expression init
Mar 10 09:33:37.804743 osdx kernel: app-detect: appid cache initialized
Mar 10 09:33:37.804755 osdx kernel: app-detect: appid cache changes counter initialized
Mar 10 09:33:37.811209 osdx modulelauncher[57224]: AppDetect: no change in application dictionaries, thus nothing more to do
Mar 10 09:33:37.840673 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:37.944918 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:37.945786 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:33:37.946144 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:37.948132 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:37.948296 osdx ulogd[57313]: registering plugin `NFCT'
Mar 10 09:33:37.948341 osdx ulogd[57313]: registering plugin `IP2STR'
Mar 10 09:33:37.948380 osdx ulogd[57313]: registering plugin `PRINTFLOW'
Mar 10 09:33:37.948419 osdx ulogd[57313]: registering plugin `SYSLOG'
Mar 10 09:33:37.948423 osdx ulogd[57313]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:37.948463 osdx ulogd[57313]: NFCT plugin working in event mode
Mar 10 09:33:37.948469 osdx ulogd[57313]: Changing UID / GID
Mar 10 09:33:37.948533 osdx ulogd[57313]: initialization finished, entering main loop
Mar 10 09:33:37.975348 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:37.999913 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:38.816078 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.816102 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901210 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901235 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920231 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920256 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920270 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944218 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944239 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944250 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:41.047884 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.

Step 7: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[DESTROY\].*APPDETECT\[L3:1\]
Show output
Mar 10 09:33:36.291013 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:36.292665 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:36.292730 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:36.301849 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:36.641545 osdx osdx-coredump[57195]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:36.651158 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:37.129990 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:37.203328 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Mar 10 09:33:37.304144 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Mar 10 09:33:37.416711 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:37.469802 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:37.585610 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:37.652894 osdx INFO[57221]: FRR daemons did not change
Mar 10 09:33:37.804650 osdx kernel: app-detect: module init
Mar 10 09:33:37.804718 osdx kernel: app-detect: registered: sysctl net.appdetect
Mar 10 09:33:37.804731 osdx kernel: app-detect: expression init
Mar 10 09:33:37.804743 osdx kernel: app-detect: appid cache initialized
Mar 10 09:33:37.804755 osdx kernel: app-detect: appid cache changes counter initialized
Mar 10 09:33:37.811209 osdx modulelauncher[57224]: AppDetect: no change in application dictionaries, thus nothing more to do
Mar 10 09:33:37.840673 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:37.944918 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:37.945786 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:33:37.946144 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:37.948132 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:37.948296 osdx ulogd[57313]: registering plugin `NFCT'
Mar 10 09:33:37.948341 osdx ulogd[57313]: registering plugin `IP2STR'
Mar 10 09:33:37.948380 osdx ulogd[57313]: registering plugin `PRINTFLOW'
Mar 10 09:33:37.948419 osdx ulogd[57313]: registering plugin `SYSLOG'
Mar 10 09:33:37.948423 osdx ulogd[57313]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:37.948463 osdx ulogd[57313]: NFCT plugin working in event mode
Mar 10 09:33:37.948469 osdx ulogd[57313]: Changing UID / GID
Mar 10 09:33:37.948533 osdx ulogd[57313]: initialization finished, entering main loop
Mar 10 09:33:37.975348 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:37.999913 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:38.816078 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.816102 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901210 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901235 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920231 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920256 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920270 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944218 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944239 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944250 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:41.047884 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.
Mar 10 09:33:41.162236 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.

Step 8: Modify the following configuration lines in DUT0 :

set interfaces ethernet eth1 address 10.215.168.64/24
set system conntrack app-detect http-host

Step 9: 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.173 ms

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

Step 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:

Show output
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   972    0   972    0     0   152k      0 --:--:-- --:--:-- --:--:--  158k

Step 11: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*APPDETECT\[L4:80 http-host:10.215.168.1\]
Show output
Mar 10 09:33:36.291013 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:36.292665 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:36.292730 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:36.301849 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:36.641545 osdx osdx-coredump[57195]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:36.651158 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:37.129990 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:37.203328 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Mar 10 09:33:37.304144 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Mar 10 09:33:37.416711 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Mar 10 09:33:37.469802 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Mar 10 09:33:37.585610 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:37.652894 osdx INFO[57221]: FRR daemons did not change
Mar 10 09:33:37.804650 osdx kernel: app-detect: module init
Mar 10 09:33:37.804718 osdx kernel: app-detect: registered: sysctl net.appdetect
Mar 10 09:33:37.804731 osdx kernel: app-detect: expression init
Mar 10 09:33:37.804743 osdx kernel: app-detect: appid cache initialized
Mar 10 09:33:37.804755 osdx kernel: app-detect: appid cache changes counter initialized
Mar 10 09:33:37.811209 osdx modulelauncher[57224]: AppDetect: no change in application dictionaries, thus nothing more to do
Mar 10 09:33:37.840673 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Mar 10 09:33:37.944918 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Mar 10 09:33:37.945786 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Mar 10 09:33:37.946144 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Mar 10 09:33:37.948132 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:37.948296 osdx ulogd[57313]: registering plugin `NFCT'
Mar 10 09:33:37.948341 osdx ulogd[57313]: registering plugin `IP2STR'
Mar 10 09:33:37.948380 osdx ulogd[57313]: registering plugin `PRINTFLOW'
Mar 10 09:33:37.948419 osdx ulogd[57313]: registering plugin `SYSLOG'
Mar 10 09:33:37.948423 osdx ulogd[57313]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Mar 10 09:33:37.948463 osdx ulogd[57313]: NFCT plugin working in event mode
Mar 10 09:33:37.948469 osdx ulogd[57313]: Changing UID / GID
Mar 10 09:33:37.948533 osdx ulogd[57313]: initialization finished, entering main loop
Mar 10 09:33:37.975348 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:37.999913 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:38.816078 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.816102 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901210 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:38.901235 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920231 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920256 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:39.920270 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944218 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944239 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:40.944250 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:41.047884 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.
Mar 10 09:33:41.162236 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.
Mar 10 09:33:41.305391 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal show | cat'.
Mar 10 09:33:41.503585 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:41.589569 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Mar 10 09:33:41.689697 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Mar 10 09:33:41.772302 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show changes'.
Mar 10 09:33:41.851341 osdx INFO[57366]: FRR daemons did not change
Mar 10 09:33:41.876658 osdx kernel: app-detect: expression destroy
Mar 10 09:33:41.908651 osdx kernel: app-detect: expression init
Mar 10 09:33:41.908698 osdx kernel: app-detect: appid cache initialized
Mar 10 09:33:41.908707 osdx kernel: app-detect: appid cache changes counter initialized
Mar 10 09:33:41.912287 osdx modulelauncher[57369]: AppDetect: no change in application dictionaries, thus nothing more to do
Mar 10 09:33:41.932648 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Mar 10 09:33:42.002061 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:42.033937 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:42.033980 osdx ulogd[57313]: [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 APPDETECT[L3:1]
Mar 10 09:33:42.034794 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:42.050678 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:42.199042 osdx ulogd[57313]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1]
Mar 10 09:33:42.200100 osdx ulogd[57313]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1]
Mar 10 09:33:42.200371 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Mar 10 09:33:42.336962 osdx file_operation[57474]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Mar 10 09:33:42.343061 osdx ulogd[57313]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40120 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40120 PKTS=0 BYTES=0 APPDETECT[L4:80]
Mar 10 09:33:42.343185 osdx ulogd[57313]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40120 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40120 PKTS=0 BYTES=0 APPDETECT[L4:80]
Mar 10 09:33:42.343204 osdx ulogd[57313]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40120 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40120 PKTS=0 BYTES=0 APPDETECT[L4:80]
Mar 10 09:33:42.345478 osdx ulogd[57313]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40120 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40120 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Mar 10 09:33:42.345508 osdx ulogd[57313]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40120 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40120 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Mar 10 09:33:42.345587 osdx ulogd[57313]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40120 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40120 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Mar 10 09:33:42.365684 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.

App Detect Drop Packet

Description

Set a traffic policy with action drop for all the packets matching an appid specified by a traffic selector. Enable http-host and http-url option in system conntrack appdetect path in order to see relevant information about http packets. Finnally, log that packets with app-id option and check that appdetect field appear in journal 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 interfaces ethernet eth1 traffic policy out DROP
set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1
set system conntrack app-detect enable_dict_match_priv_ip
set system conntrack app-detect http-host
set system conntrack app-detect http-url
set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
set traffic policy DROP rule 1 action drop
set traffic policy DROP rule 1 log app-id
set traffic policy DROP rule 1 selector APPID
set traffic selector APPID rule 1 app-id custom 155

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

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

Step 3: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

osdx kernel:.*APPDETECT\[U:155 http-url:/~robot/ http-host:10.215.168.1\]
Show output
Mar 10 09:33:46.000168 osdx systemd-timedated[49917]: Changed local time to Mon 2025-03-10 09:33:46 UTC
Mar 10 09:33:46.001827 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'set date 2025-03-10 09:33:46'.
Mar 10 09:33:46.003919 osdx systemd-journald[1668]: Time jumped backwards, rotating.
Mar 10 09:33:46.294870 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/8c78421431714dc5b42d4f61b2ec278e) is 2.0M, max 15.3M, 13.2M free.
Mar 10 09:33:46.295927 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Mar 10 09:33:46.295974 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/8c78421431714dc5b42d4f61b2ec278e.
Mar 10 09:33:46.304054 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system journal clear'.
Mar 10 09:33:46.622424 osdx osdx-coredump[57632]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Mar 10 09:33:46.630450 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'system coredump delete all'.
Mar 10 09:33:47.095735 osdx OSDxCLI[54267]: User 'admin' entered the configuration menu.
Mar 10 09:33:47.162581 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'.
Mar 10 09:33:47.256391 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'.
Mar 10 09:33:47.314232 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'.
Mar 10 09:33:47.454531 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'.
Mar 10 09:33:47.514252 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'.
Mar 10 09:33:47.610285 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'.
Mar 10 09:33:47.666884 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'.
Mar 10 09:33:47.774858 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'.
Mar 10 09:33:47.827628 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Mar 10 09:33:47.932141 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Mar 10 09:33:48.016134 osdx OSDxCLI[54267]: User 'admin' added a new cfg line: 'show working'.
Mar 10 09:33:48.118804 osdx INFO[57678]: FRR daemons did not change
Mar 10 09:33:48.291927 osdx kernel: app-detect: module init
Mar 10 09:33:48.291979 osdx kernel: app-detect: registered: sysctl net.appdetect
Mar 10 09:33:48.291993 osdx kernel: app-detect: expression init
Mar 10 09:33:48.292007 osdx kernel: app-detect: appid cache initialized
Mar 10 09:33:48.292023 osdx kernel: app-detect: appid cache changes counter initialized
Mar 10 09:33:48.331928 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Mar 10 09:33:48.601036 osdx cfgd[1455]: [54267]Completed change to active configuration
Mar 10 09:33:48.627506 osdx OSDxCLI[54267]: User 'admin' committed the configuration.
Mar 10 09:33:48.651033 osdx OSDxCLI[54267]: User 'admin' left the configuration menu.
Mar 10 09:33:48.815556 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Mar 10 09:33:48.948733 osdx file_operation[57824]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Mar 10 09:33:48.955925 osdx kernel: [DROP-1] DROP IN= OUT=eth1 SRC=10.215.168.64 DST=10.215.168.1 LEN=306 TOS=0x00 PREC=0x00 TTL=64 ID=20645 DF PROTO=TCP SPT=40122 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Mar 10 09:33:49.159930 osdx kernel: [DROP-1] DROP IN= OUT=eth1 SRC=10.215.168.64 DST=10.215.168.1 LEN=306 TOS=0x00 PREC=0x00 TTL=64 ID=20646 DF PROTO=TCP SPT=40122 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Mar 10 09:33:49.576060 osdx kernel: [DROP-1] DROP IN= OUT=eth1 SRC=10.215.168.64 DST=10.215.168.1 LEN=306 TOS=0x00 PREC=0x00 TTL=64 ID=20647 DF PROTO=TCP SPT=40122 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Mar 10 09:33:50.407968 osdx kernel: [DROP-1] DROP IN= OUT=eth1 SRC=10.215.168.64 DST=10.215.168.1 LEN=306 TOS=0x00 PREC=0x00 TTL=64 ID=20648 DF PROTO=TCP SPT=40122 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Mar 10 09:33:51.893638 osdx file_operation.py[57824]: Operation aborted by user.
Mar 10 09:33:51.907937 osdx kernel: [DROP-1] DROP IN= OUT=eth1 SRC=10.215.168.64 DST=10.215.168.1 LEN=306 TOS=0x00 PREC=0x00 TTL=64 ID=20649 DF PROTO=TCP SPT=40122 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Mar 10 09:33:51.912148 osdx OSDxCLI[54267]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.