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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.236/0.236/0.236/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
Jun 25 11:57:05.305742 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:05.307334 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:05.307378 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:05.315943 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:05.520690 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:05.742545 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:05.817332 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:05.905138 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
Jun 25 11:57:05.980077 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:06.071244 osdx ubnt-cfgd[9152]: inactive
Jun 25 11:57:06.091029 osdx INFO[9160]: FRR daemons did not change
Jun 25 11:57:06.115347 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:06.203571 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:06.207511 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:06.210665 osdx ulogd[9251]: registering plugin `NFCT'
Jun 25 11:57:06.211638 osdx ulogd[9251]: registering plugin `IP2STR'
Jun 25 11:57:06.211727 osdx ulogd[9251]: registering plugin `PRINTFLOW'
Jun 25 11:57:06.212734 osdx ulogd[9251]: registering plugin `SYSLOG'
Jun 25 11:57:06.212766 osdx ulogd[9251]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:06.212831 osdx ulogd[9251]: NFCT plugin working in event mode
Jun 25 11:57:06.212864 osdx ulogd[9251]: Changing UID / GID
Jun 25 11:57:06.212949 osdx ulogd[9251]: initialization finished, entering main loop
Jun 25 11:57:06.223378 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:06.225156 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:06.243112 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:06.264883 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:07.126468 osdx ulogd[9251]: [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
Jun 25 11:57:07.201420 osdx ulogd[9251]: [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.354 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.264/0.264/0.264/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
Jun 25 11:57:11.322317 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:11.325183 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:11.325259 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:11.332582 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:11.547632 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:11.772287 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:11.849233 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:11.933190 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
Jun 25 11:57:12.006137 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:12.104936 osdx ubnt-cfgd[9432]: inactive
Jun 25 11:57:12.125771 osdx INFO[9440]: FRR daemons did not change
Jun 25 11:57:12.149175 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:12.233582 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:12.234534 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:12.234657 osdx ulogd[9531]: registering plugin `NFCT'
Jun 25 11:57:12.234699 osdx ulogd[9531]: registering plugin `IP2STR'
Jun 25 11:57:12.234884 osdx ulogd[9531]: registering plugin `PRINTFLOW'
Jun 25 11:57:12.234925 osdx ulogd[9531]: registering plugin `SYSLOG'
Jun 25 11:57:12.234930 osdx ulogd[9531]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:12.234971 osdx ulogd[9531]: NFCT plugin working in event mode
Jun 25 11:57:12.234977 osdx ulogd[9531]: Changing UID / GID
Jun 25 11:57:12.235045 osdx ulogd[9531]: initialization finished, entering main loop
Jun 25 11:57:12.236718 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:12.247849 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:12.265502 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:13.079339 osdx ulogd[9531]: [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
Jun 25 11:57:13.168602 osdx ulogd[9531]: [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.308 ms

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

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2025ms
rtt min/avg/max/mdev = 0.211/0.262/0.292/0.036 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
Jun 25 11:57:17.296606 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:17.299575 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:17.299629 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:17.308161 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:17.517449 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:17.739806 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:17.880153 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:17.947468 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
Jun 25 11:57:18.039239 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 25 11:57:18.097790 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service ssh'.
Jun 25 11:57:18.200232 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:18.267970 osdx ubnt-cfgd[9716]: inactive
Jun 25 11:57:18.374788 osdx INFO[9730]: FRR daemons did not change
Jun 25 11:57:18.399575 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:18.467822 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:18.468519 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:18.469175 osdx ulogd[9823]: registering plugin `NFCT'
Jun 25 11:57:18.469536 osdx ulogd[9823]: registering plugin `IP2STR'
Jun 25 11:57:18.469682 osdx ulogd[9823]: registering plugin `PRINTFLOW'
Jun 25 11:57:18.469820 osdx ulogd[9823]: registering plugin `SYSLOG'
Jun 25 11:57:18.469876 osdx ulogd[9823]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:18.470011 osdx ulogd[9823]: NFCT plugin working in event mode
Jun 25 11:57:18.470077 osdx ulogd[9823]: Changing UID / GID
Jun 25 11:57:18.470264 osdx ulogd[9823]: initialization finished, entering main loop
Jun 25 11:57:18.491605 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:18.547848 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Jun 25 11:57:18.559324 osdx sshd[9829]: Server listening on 0.0.0.0 port 22.
Jun 25 11:57:18.559538 osdx sshd[9829]: Server listening on :: port 22.
Jun 25 11:57:18.559677 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Jun 25 11:57:18.578718 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:18.589456 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:18.611389 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:20.547791 osdx ulogd[9823]: [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
Jun 25 11:57:21.571774 osdx ulogd[9823]: [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.345 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.264/0.264/0.264/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
Jun 25 11:57:28.287591 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:28.290880 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:28.290937 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:28.297149 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:28.508151 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:28.750063 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:28.827079 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:28.915447 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:57:28.987036 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:29.083316 osdx ubnt-cfgd[10035]: inactive
Jun 25 11:57:29.109310 osdx INFO[10043]: FRR daemons did not change
Jun 25 11:57:29.134896 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:29.219128 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:29.219981 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:29.220365 osdx ulogd[10134]: registering plugin `NFCT'
Jun 25 11:57:29.220600 osdx ulogd[10134]: registering plugin `IP2STR'
Jun 25 11:57:29.220688 osdx ulogd[10134]: registering plugin `PRINTFLOW'
Jun 25 11:57:29.220772 osdx ulogd[10134]: registering plugin `SYSLOG'
Jun 25 11:57:29.220809 osdx ulogd[10134]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:29.220891 osdx ulogd[10134]: NFCT plugin working in event mode
Jun 25 11:57:29.220931 osdx ulogd[10134]: Changing UID / GID
Jun 25 11:57:29.221038 osdx ulogd[10134]: initialization finished, entering main loop
Jun 25 11:57:29.221348 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:29.232537 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:29.248872 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:30.086204 osdx ulogd[10134]: [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
Jun 25 11:57:30.086227 osdx ulogd[10134]: [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
Jun 25 11:57:30.168381 osdx ulogd[10134]: [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
Jun 25 11:57:30.168410 osdx ulogd[10134]: [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.348 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.251/0.251/0.251/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
Jun 25 11:57:35.306468 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:35.308448 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:35.308519 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:35.316148 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:35.527801 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:35.755762 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:35.833441 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:35.932600 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:57:35.988581 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Jun 25 11:57:36.095912 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:36.160654 osdx ubnt-cfgd[10316]: inactive
Jun 25 11:57:36.182088 osdx INFO[10324]: FRR daemons did not change
Jun 25 11:57:36.204452 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:36.276687 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:36.277377 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:36.277750 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:36.279125 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:36.279590 osdx ulogd[10415]: registering plugin `NFCT'
Jun 25 11:57:36.279788 osdx ulogd[10415]: registering plugin `IP2STR'
Jun 25 11:57:36.279854 osdx ulogd[10415]: registering plugin `PRINTFLOW'
Jun 25 11:57:36.279918 osdx ulogd[10415]: registering plugin `SYSLOG'
Jun 25 11:57:36.279960 osdx ulogd[10415]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:36.280027 osdx ulogd[10415]: NFCT plugin working in event mode
Jun 25 11:57:36.280060 osdx OSDx_DUT0[10415]: Changing UID / GID
Jun 25 11:57:36.280144 osdx OSDx_DUT0[10415]: initialization finished, entering main loop
Jun 25 11:57:36.289637 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:36.307351 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:37.150030 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.150053 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.247653 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.247672 osdx OSDx_DUT0[10415]: [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.223 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.223/0.223/0.223/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
Jun 25 11:57:35.306468 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:35.308448 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:35.308519 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:35.316148 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:35.527801 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:35.755762 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:35.833441 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:35.932600 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:57:35.988581 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Jun 25 11:57:36.095912 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:36.160654 osdx ubnt-cfgd[10316]: inactive
Jun 25 11:57:36.182088 osdx INFO[10324]: FRR daemons did not change
Jun 25 11:57:36.204452 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:36.276687 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:36.277377 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:36.277750 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:36.279125 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:36.279590 osdx ulogd[10415]: registering plugin `NFCT'
Jun 25 11:57:36.279788 osdx ulogd[10415]: registering plugin `IP2STR'
Jun 25 11:57:36.279854 osdx ulogd[10415]: registering plugin `PRINTFLOW'
Jun 25 11:57:36.279918 osdx ulogd[10415]: registering plugin `SYSLOG'
Jun 25 11:57:36.279960 osdx ulogd[10415]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:36.280027 osdx ulogd[10415]: NFCT plugin working in event mode
Jun 25 11:57:36.280060 osdx OSDx_DUT0[10415]: Changing UID / GID
Jun 25 11:57:36.280144 osdx OSDx_DUT0[10415]: initialization finished, entering main loop
Jun 25 11:57:36.289637 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:36.307351 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:37.150030 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.150053 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.247653 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.247672 osdx OSDx_DUT0[10415]: [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
Jun 25 11:57:37.340603 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 25 11:57:37.608821 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:37.678871 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'.
Jun 25 11:57:37.785965 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show changes'.
Jun 25 11:57:37.849906 osdx ubnt-cfgd[10451]: inactive
Jun 25 11:57:37.867066 osdx INFO[10457]: FRR daemons did not change
Jun 25 11:57:37.877906 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:37.877917 osdx OSDx_DUT0[10415]: Terminal signal received, exiting
Jun 25 11:57:37.878520 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jun 25 11:57:37.878613 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:37.896740 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:37.897648 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:37.898127 osdx ulogd[10465]: registering plugin `NFCT'
Jun 25 11:57:37.898301 osdx ulogd[10465]: registering plugin `IP2STR'
Jun 25 11:57:37.898373 osdx ulogd[10465]: registering plugin `PRINTFLOW'
Jun 25 11:57:37.898439 osdx ulogd[10465]: registering plugin `SYSLOG'
Jun 25 11:57:37.898467 osdx ulogd[10465]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:37.898528 osdx ulogd[10465]: NFCT plugin working in event mode
Jun 25 11:57:37.898560 osdx ulogd[10465]: Changing UID / GID
Jun 25 11:57:37.898646 osdx ulogd[10465]: initialization finished, entering main loop
Jun 25 11:57:37.912468 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:37.913620 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:37.915095 osdx ulogd[10465]: [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
Jun 25 11:57:37.915156 osdx ulogd[10465]: [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
Jun 25 11:57:37.915669 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:37.932582 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:38.090121 osdx ulogd[10465]: [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
Jun 25 11:57:38.090140 osdx ulogd[10465]: [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.378 ms

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

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1029ms
rtt min/avg/max/mdev = 0.234/0.242/0.250/0.008 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
Jun 25 11:57:42.323612 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:42.326846 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:42.326919 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:42.334096 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:42.572943 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:42.809471 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:42.900298 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jun 25 11:57:42.971188 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic label TEST'.
Jun 25 11:57:43.075306 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
Jun 25 11:57:43.135499 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
Jun 25 11:57:43.237248 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:43.297470 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:57:43.430642 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:43.496275 osdx ubnt-cfgd[10626]: inactive
Jun 25 11:57:43.527505 osdx INFO[10640]: FRR daemons did not change
Jun 25 11:57:43.550843 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:43.643202 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:43.643818 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:43.644047 osdx ulogd[10731]: registering plugin `NFCT'
Jun 25 11:57:43.644742 osdx ulogd[10731]: registering plugin `IP2STR'
Jun 25 11:57:43.644840 osdx ulogd[10731]: registering plugin `PRINTFLOW'
Jun 25 11:57:43.645486 osdx ulogd[10731]: registering plugin `SYSLOG'
Jun 25 11:57:43.645540 osdx ulogd[10731]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:43.645612 osdx ulogd[10731]: NFCT plugin working in event mode
Jun 25 11:57:43.645646 osdx ulogd[10731]: Changing UID / GID
Jun 25 11:57:43.645738 osdx ulogd[10731]: initialization finished, entering main loop
Jun 25 11:57:43.655127 osdx ulogd[10731]: Terminal signal received, exiting
Jun 25 11:57:43.655210 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:43.655587 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jun 25 11:57:43.655675 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:43.656500 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:43.657237 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:43.657550 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:43.658400 osdx ulogd[10737]: registering plugin `NFCT'
Jun 25 11:57:43.658578 osdx ulogd[10737]: registering plugin `IP2STR'
Jun 25 11:57:43.658640 osdx ulogd[10737]: registering plugin `PRINTFLOW'
Jun 25 11:57:43.658712 osdx ulogd[10737]: registering plugin `SYSLOG'
Jun 25 11:57:43.658737 osdx ulogd[10737]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:43.658796 osdx ulogd[10737]: NFCT plugin working in event mode
Jun 25 11:57:43.658828 osdx ulogd[10737]: Changing UID / GID
Jun 25 11:57:43.658904 osdx ulogd[10737]: initialization finished, entering main loop
Jun 25 11:57:43.843798 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:43.854999 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:43.872014 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:44.683056 osdx ulogd[10737]: [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
Jun 25 11:57:44.683076 osdx ulogd[10737]: [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
Jun 25 11:57:44.757851 osdx ulogd[10737]: [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
Jun 25 11:57:44.757875 osdx ulogd[10737]: [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.348 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.278/0.278/0.278/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
Jun 25 11:57:50.320139 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:50.321231 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:50.321272 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:50.330381 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:50.540308 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:50.765900 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:50.841933 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
Jun 25 11:57:50.933932 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'.
Jun 25 11:57:50.985093 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system vrf RED'.
Jun 25 11:57:51.092161 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:51.149926 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:57:51.263576 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:51.326490 osdx ubnt-cfgd[10963]: inactive
Jun 25 11:57:51.351463 osdx INFO[10971]: FRR daemons did not change
Jun 25 11:57:51.363237 osdx (udev-worker)[10981]: RED: Could not disable auto negotiation, ignoring: Operation not supported
Jun 25 11:57:51.363553 osdx (udev-worker)[10981]: Network interface NamePolicy= disabled on kernel command line.
Jun 25 11:57:51.389254 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:51.437226 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:51.517490 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:51.518132 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:51.518769 osdx ulogd[11137]: registering plugin `NFCT'
Jun 25 11:57:51.518955 osdx ulogd[11137]: registering plugin `IP2STR'
Jun 25 11:57:51.519044 osdx ulogd[11137]: registering plugin `PRINTFLOW'
Jun 25 11:57:51.519141 osdx ulogd[11137]: registering plugin `SYSLOG'
Jun 25 11:57:51.519180 osdx ulogd[11137]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:51.519269 osdx ulogd[11137]: NFCT plugin working in event mode
Jun 25 11:57:51.519312 osdx ulogd[11137]: Changing UID / GID
Jun 25 11:57:51.519433 osdx ulogd[11137]: initialization finished, entering main loop
Jun 25 11:57:51.541242 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:51.542602 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:51.556626 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:51.574409 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:52.410224 osdx ulogd[11137]: [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
Jun 25 11:57:52.410241 osdx ulogd[11137]: [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
Jun 25 11:57:52.514631 osdx ulogd[11137]: [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
Jun 25 11:57:52.514649 osdx ulogd[11137]: [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.208 ms

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

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.337/0.337/0.337/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
Jun 25 11:57:56.000208 osdx systemd-timedated[7694]: Changed local time to Wed 2025-06-25 11:57:56 UTC
Jun 25 11:57:56.001457 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'set date 2025-06-25 11:57:56'.
Jun 25 11:57:56.002414 osdx systemd-journald[1668]: Time jumped backwards, rotating.
Jun 25 11:57:56.319138 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:57:56.322425 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:57:56.322473 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:57:56.330296 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:57:56.546858 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:57:56.834762 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:56.914642 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jun 25 11:57:57.004361 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:57.076437 osdx ubnt-cfgd[11400]: inactive
Jun 25 11:57:57.098648 osdx INFO[11408]: FRR daemons did not change
Jun 25 11:57:57.118412 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 25 11:57:57.170943 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:57.181774 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:57:57.205777 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:57:57.391474 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jun 25 11:57:57.526596 osdx file_operation[11525]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
Jun 25 11:57:57.551183 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
Jun 25 11:57:57.699381 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:57:57.764469 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jun 25 11:57:57.863486 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
Jun 25 11:57:57.918576 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'.
Jun 25 11:57:58.017822 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
Jun 25 11:57:58.077470 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
Jun 25 11:57:58.175899 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
Jun 25 11:57:58.234878 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
Jun 25 11:57:58.334778 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
Jun 25 11:57:58.393981 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
Jun 25 11:57:58.503463 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:57:58.557287 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:57:58.689861 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:57:58.763017 osdx ubnt-cfgd[11559]: inactive
Jun 25 11:57:58.800006 osdx INFO[11576]: FRR daemons did not change
Jun 25 11:57:58.822413 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:57:58.914727 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:58.915778 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:58.916001 osdx ulogd[11667]: registering plugin `NFCT'
Jun 25 11:57:58.916268 osdx ulogd[11667]: registering plugin `IP2STR'
Jun 25 11:57:58.916361 osdx ulogd[11667]: registering plugin `PRINTFLOW'
Jun 25 11:57:58.916446 osdx ulogd[11667]: registering plugin `SYSLOG'
Jun 25 11:57:58.916485 osdx ulogd[11667]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:58.916572 osdx ulogd[11667]: NFCT plugin working in event mode
Jun 25 11:57:58.916614 osdx ulogd[11667]: Changing UID / GID
Jun 25 11:57:58.916727 osdx ulogd[11667]: initialization finished, entering main loop
Jun 25 11:57:59.195855 osdx systemd[1]: Reloading.
Jun 25 11:57:59.250415 osdx systemd-sysv-generator[11704]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
Jun 25 11:57:59.370799 osdx systemd[1]: Starting logrotate.service - Rotate log files...
Jun 25 11:57:59.374900 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata.
Jun 25 11:57:59.375779 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
Jun 25 11:57:59.435779 osdx systemd[1]: logrotate.service: Deactivated successfully.
Jun 25 11:57:59.436014 osdx systemd[1]: Finished logrotate.service - Rotate log files.
Jun 25 11:57:59.666546 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
Jun 25 11:57:59.924506 osdx INFO[11686]: Rules successfully loaded
Jun 25 11:57:59.937532 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:59.937872 osdx ulogd[11667]: Terminal signal received, exiting
Jun 25 11:57:59.938355 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jun 25 11:57:59.938479 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:59.962751 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:57:59.963453 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:57:59.963826 osdx ulogd[11732]: registering plugin `NFCT'
Jun 25 11:57:59.964036 osdx ulogd[11732]: registering plugin `IP2STR'
Jun 25 11:57:59.964101 osdx ulogd[11732]: registering plugin `PRINTFLOW'
Jun 25 11:57:59.964167 osdx ulogd[11732]: registering plugin `SYSLOG'
Jun 25 11:57:59.964193 osdx ulogd[11732]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:57:59.964256 osdx ulogd[11732]: NFCT plugin working in event mode
Jun 25 11:57:59.964286 osdx ulogd[11732]: Changing UID / GID
Jun 25 11:57:59.964381 osdx ulogd[11732]: initialization finished, entering main loop
Jun 25 11:57:59.970429 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:57:59.972206 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:57:59.983641 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:00.002669 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:00.936596 osdx ulogd[11732]: [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)
Jun 25 11:58:00.936614 osdx ulogd[11732]: [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)
Jun 25 11:58:01.013759 osdx ulogd[11732]: [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)
Jun 25 11:58:01.013777 osdx ulogd[11732]: [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.317 ms

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

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

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

Last login: Wed Jun 25 11:56:41 2025 from 10.215.168.64
admin@osdx$

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

ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*\[OFFLOAD\]
Show output
Jun 25 11:58:08.338191 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.1M, max 15.3M, 13.2M free.
Jun 25 11:58:08.338600 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:58:08.338630 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:58:08.349791 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:58:08.589404 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:58:08.850874 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:08.943791 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
Jun 25 11:58:09.039175 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:58:09.118655 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:58:09.229782 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:58:09.297898 osdx ubnt-cfgd[12015]: inactive
Jun 25 11:58:09.322683 osdx INFO[12025]: FRR daemons did not change
Jun 25 11:58:09.346480 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 25 11:58:09.414475 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:58:09.506757 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:58:09.507658 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 25 11:58:09.508149 osdx ulogd[12191]: registering plugin `NFCT'
Jun 25 11:58:09.508187 osdx ulogd[12191]: registering plugin `IP2STR'
Jun 25 11:58:09.508221 osdx ulogd[12191]: registering plugin `PRINTFLOW'
Jun 25 11:58:09.508258 osdx ulogd[12191]: registering plugin `SYSLOG'
Jun 25 11:58:09.508261 osdx ulogd[12191]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:58:09.508299 osdx ulogd[12191]: NFCT plugin working in event mode
Jun 25 11:58:09.508306 osdx ulogd[12191]: Changing UID / GID
Jun 25 11:58:09.508375 osdx ulogd[12191]: initialization finished, entering main loop
Jun 25 11:58:09.514498 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:58:09.515860 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:09.528445 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:09.555355 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:11.297087 osdx ulogd[12191]: [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
Jun 25 11:58:11.297109 osdx ulogd[12191]: [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
Jun 25 11:58:11.392772 osdx ulogd[12191]: [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
Jun 25 11:58:11.392793 osdx ulogd[12191]: [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
Jun 25 11:58:11.467064 osdx ulogd[12191]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 PKTS=0 BYTES=0
Jun 25 11:58:11.467214 osdx ulogd[12191]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 PKTS=0 BYTES=0
Jun 25 11:58:11.467289 osdx ulogd[12191]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 PKTS=0 BYTES=0 [OFFLOAD]
Jun 25 11:58:11.739495 osdx ulogd[12191]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 PKTS=0 BYTES=0
Jun 25 11:58:11.739753 osdx ulogd[12191]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 PKTS=0 BYTES=0 [OFFLOAD]
Jun 25 11:58:11.741423 osdx ulogd[12191]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 PKTS=0 BYTES=0
Jun 25 11:58:11.741525 osdx ulogd[12191]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=46028 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=46028 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.317 ms

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

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2054ms
rtt min/avg/max/mdev = 0.214/0.264/0.299/0.036 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
Jun 25 11:58:16.345188 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.1M, max 15.3M, 13.2M free.
Jun 25 11:58:16.347319 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:58:16.347386 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:58:16.355062 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:58:16.587651 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:58:16.902899 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:16.972314 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 25 11:58:17.074324 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 25 11:58:17.194469 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:58:17.250734 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:58:17.372091 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:58:17.436860 osdx ubnt-cfgd[12404]: inactive
Jun 25 11:58:17.465268 osdx INFO[12412]: FRR daemons did not change
Jun 25 11:58:17.711302 osdx kernel: app-detect: module init
Jun 25 11:58:17.711350 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 25 11:58:17.711359 osdx kernel: app-detect: expression init
Jun 25 11:58:17.711367 osdx kernel: app-detect: appid cache initialized
Jun 25 11:58:17.711375 osdx kernel: app-detect: appid cache changes counter initialized
Jun 25 11:58:17.716207 osdx modulelauncher[12415]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 25 11:58:17.759306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:58:17.855558 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:58:17.856498 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:58:17.856602 osdx ulogd[12526]: registering plugin `NFCT'
Jun 25 11:58:17.856643 osdx ulogd[12526]: registering plugin `IP2STR'
Jun 25 11:58:17.856724 osdx ulogd[12526]: registering plugin `PRINTFLOW'
Jun 25 11:58:17.856765 osdx ulogd[12526]: registering plugin `SYSLOG'
Jun 25 11:58:17.856768 osdx ulogd[12526]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:58:17.856825 osdx ulogd[12526]: NFCT plugin working in event mode
Jun 25 11:58:17.856883 osdx ulogd[12526]: Changing UID / GID
Jun 25 11:58:17.856968 osdx ulogd[12526]: initialization finished, entering main loop
Jun 25 11:58:17.857753 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:17.869116 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:17.884837 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:18.836531 osdx ulogd[12526]: [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]
Jun 25 11:58:18.836548 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925923 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925941 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955526 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955544 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955560 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979495 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979515 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979527 osdx ulogd[12526]: [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
Jun 25 11:58:16.345188 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.1M, max 15.3M, 13.2M free.
Jun 25 11:58:16.347319 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:58:16.347386 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:58:16.355062 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:58:16.587651 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:58:16.902899 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:16.972314 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 25 11:58:17.074324 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 25 11:58:17.194469 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:58:17.250734 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:58:17.372091 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:58:17.436860 osdx ubnt-cfgd[12404]: inactive
Jun 25 11:58:17.465268 osdx INFO[12412]: FRR daemons did not change
Jun 25 11:58:17.711302 osdx kernel: app-detect: module init
Jun 25 11:58:17.711350 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 25 11:58:17.711359 osdx kernel: app-detect: expression init
Jun 25 11:58:17.711367 osdx kernel: app-detect: appid cache initialized
Jun 25 11:58:17.711375 osdx kernel: app-detect: appid cache changes counter initialized
Jun 25 11:58:17.716207 osdx modulelauncher[12415]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 25 11:58:17.759306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:58:17.855558 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:58:17.856498 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:58:17.856602 osdx ulogd[12526]: registering plugin `NFCT'
Jun 25 11:58:17.856643 osdx ulogd[12526]: registering plugin `IP2STR'
Jun 25 11:58:17.856724 osdx ulogd[12526]: registering plugin `PRINTFLOW'
Jun 25 11:58:17.856765 osdx ulogd[12526]: registering plugin `SYSLOG'
Jun 25 11:58:17.856768 osdx ulogd[12526]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:58:17.856825 osdx ulogd[12526]: NFCT plugin working in event mode
Jun 25 11:58:17.856883 osdx ulogd[12526]: Changing UID / GID
Jun 25 11:58:17.856968 osdx ulogd[12526]: initialization finished, entering main loop
Jun 25 11:58:17.857753 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:17.869116 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:17.884837 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:18.836531 osdx ulogd[12526]: [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]
Jun 25 11:58:18.836548 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925923 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925941 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955526 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955544 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955560 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979495 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979515 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979527 osdx ulogd[12526]: [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]
Jun 25 11:58:21.071342 osdx OSDxCLI[4070]: 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
Jun 25 11:58:16.345188 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.1M, max 15.3M, 13.2M free.
Jun 25 11:58:16.347319 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:58:16.347386 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:58:16.355062 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:58:16.587651 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:58:16.902899 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:16.972314 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 25 11:58:17.074324 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 25 11:58:17.194469 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:58:17.250734 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:58:17.372091 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:58:17.436860 osdx ubnt-cfgd[12404]: inactive
Jun 25 11:58:17.465268 osdx INFO[12412]: FRR daemons did not change
Jun 25 11:58:17.711302 osdx kernel: app-detect: module init
Jun 25 11:58:17.711350 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 25 11:58:17.711359 osdx kernel: app-detect: expression init
Jun 25 11:58:17.711367 osdx kernel: app-detect: appid cache initialized
Jun 25 11:58:17.711375 osdx kernel: app-detect: appid cache changes counter initialized
Jun 25 11:58:17.716207 osdx modulelauncher[12415]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 25 11:58:17.759306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:58:17.855558 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:58:17.856498 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:58:17.856602 osdx ulogd[12526]: registering plugin `NFCT'
Jun 25 11:58:17.856643 osdx ulogd[12526]: registering plugin `IP2STR'
Jun 25 11:58:17.856724 osdx ulogd[12526]: registering plugin `PRINTFLOW'
Jun 25 11:58:17.856765 osdx ulogd[12526]: registering plugin `SYSLOG'
Jun 25 11:58:17.856768 osdx ulogd[12526]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:58:17.856825 osdx ulogd[12526]: NFCT plugin working in event mode
Jun 25 11:58:17.856883 osdx ulogd[12526]: Changing UID / GID
Jun 25 11:58:17.856968 osdx ulogd[12526]: initialization finished, entering main loop
Jun 25 11:58:17.857753 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:17.869116 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:17.884837 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:18.836531 osdx ulogd[12526]: [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]
Jun 25 11:58:18.836548 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925923 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925941 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955526 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955544 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955560 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979495 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979515 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979527 osdx ulogd[12526]: [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]
Jun 25 11:58:21.071342 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 25 11:58:21.170204 osdx OSDxCLI[4070]: 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.229 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.229/0.229/0.229/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  4352    0  4352    0     0   898k      0 --:--:-- --:--:-- --:--:-- 1062k

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
Jun 25 11:58:16.345188 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.1M, max 15.3M, 13.2M free.
Jun 25 11:58:16.347319 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:58:16.347386 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:58:16.355062 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:58:16.587651 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:58:16.902899 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:16.972314 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 25 11:58:17.074324 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 25 11:58:17.194469 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 25 11:58:17.250734 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 25 11:58:17.372091 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:58:17.436860 osdx ubnt-cfgd[12404]: inactive
Jun 25 11:58:17.465268 osdx INFO[12412]: FRR daemons did not change
Jun 25 11:58:17.711302 osdx kernel: app-detect: module init
Jun 25 11:58:17.711350 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 25 11:58:17.711359 osdx kernel: app-detect: expression init
Jun 25 11:58:17.711367 osdx kernel: app-detect: appid cache initialized
Jun 25 11:58:17.711375 osdx kernel: app-detect: appid cache changes counter initialized
Jun 25 11:58:17.716207 osdx modulelauncher[12415]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 25 11:58:17.759306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 25 11:58:17.855558 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 25 11:58:17.856498 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 25 11:58:17.856602 osdx ulogd[12526]: registering plugin `NFCT'
Jun 25 11:58:17.856643 osdx ulogd[12526]: registering plugin `IP2STR'
Jun 25 11:58:17.856724 osdx ulogd[12526]: registering plugin `PRINTFLOW'
Jun 25 11:58:17.856765 osdx ulogd[12526]: registering plugin `SYSLOG'
Jun 25 11:58:17.856768 osdx ulogd[12526]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 25 11:58:17.856825 osdx ulogd[12526]: NFCT plugin working in event mode
Jun 25 11:58:17.856883 osdx ulogd[12526]: Changing UID / GID
Jun 25 11:58:17.856968 osdx ulogd[12526]: initialization finished, entering main loop
Jun 25 11:58:17.857753 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:17.869116 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:17.884837 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:18.836531 osdx ulogd[12526]: [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]
Jun 25 11:58:18.836548 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925923 osdx ulogd[12526]: [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]
Jun 25 11:58:18.925941 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955526 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955544 osdx ulogd[12526]: [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]
Jun 25 11:58:19.955560 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979495 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979515 osdx ulogd[12526]: [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]
Jun 25 11:58:20.979527 osdx ulogd[12526]: [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]
Jun 25 11:58:21.071342 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 25 11:58:21.170204 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 25 11:58:21.271621 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 25 11:58:21.430076 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:21.506268 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jun 25 11:58:21.587551 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Jun 25 11:58:21.653577 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show changes'.
Jun 25 11:58:21.750128 osdx ubnt-cfgd[12577]: inactive
Jun 25 11:58:21.770578 osdx INFO[12585]: FRR daemons did not change
Jun 25 11:58:21.815301 osdx kernel: app-detect: expression destroy
Jun 25 11:58:21.823299 osdx kernel: app-detect: expression init
Jun 25 11:58:21.823339 osdx kernel: app-detect: appid cache initialized
Jun 25 11:58:21.823351 osdx kernel: app-detect: appid cache changes counter initialized
Jun 25 11:58:21.826561 osdx modulelauncher[12588]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 25 11:58:21.851306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 25 11:58:21.899643 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:21.911148 osdx ulogd[12526]: [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]
Jun 25 11:58:21.911267 osdx ulogd[12526]: [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]
Jun 25 11:58:21.935618 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:21.973114 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:22.107815 osdx ulogd[12526]: [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]
Jun 25 11:58:22.108490 osdx ulogd[12526]: [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]
Jun 25 11:58:22.109254 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jun 25 11:58:22.244950 osdx file_operation[12715]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Jun 25 11:58:22.249754 osdx ulogd[12526]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=54770 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=54770 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jun 25 11:58:22.249890 osdx ulogd[12526]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=54770 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=54770 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jun 25 11:58:22.249903 osdx ulogd[12526]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=54770 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=54770 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jun 25 11:58:22.251594 osdx ulogd[12526]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=54770 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=54770 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jun 25 11:58:22.251676 osdx ulogd[12526]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=54770 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=54770 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jun 25 11:58:22.251688 osdx ulogd[12526]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=54770 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=54770 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jun 25 11:58:22.268658 osdx OSDxCLI[4070]: 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.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 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
Jun 25 11:58:26.000172 osdx systemd-timedated[7694]: Changed local time to Wed 2025-06-25 11:58:26 UTC
Jun 25 11:58:26.001105 osdx systemd-journald[1668]: Time jumped backwards, rotating.
Jun 25 11:58:26.002087 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'set date 2025-06-25 11:58:26'.
Jun 25 11:58:26.312391 osdx systemd-journald[1668]: Runtime Journal (/run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1) is 2.0M, max 15.3M, 13.3M free.
Jun 25 11:58:26.313082 osdx systemd-journald[1668]: Received client request to rotate journal, rotating.
Jun 25 11:58:26.313135 osdx systemd-journald[1668]: Vacuuming done, freed 0B of archived journals from /run/log/journal/af01d4ed6eb1488ea817da6aeebe5df1.
Jun 25 11:58:26.324154 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system journal clear'.
Jun 25 11:58:26.557099 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 25 11:58:26.781218 osdx OSDxCLI[4070]: User 'admin' entered the configuration menu.
Jun 25 11:58:26.856288 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'.
Jun 25 11:58:26.955537 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'.
Jun 25 11:58:27.012282 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'.
Jun 25 11:58:27.119057 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'.
Jun 25 11:58:27.173077 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'.
Jun 25 11:58:27.270642 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'.
Jun 25 11:58:27.328057 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'.
Jun 25 11:58:27.455360 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'.
Jun 25 11:58:27.511014 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jun 25 11:58:27.634320 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Jun 25 11:58:27.725691 osdx OSDxCLI[4070]: User 'admin' added a new cfg line: 'show working'.
Jun 25 11:58:27.806086 osdx ubnt-cfgd[12934]: inactive
Jun 25 11:58:27.845602 osdx INFO[12956]: FRR daemons did not change
Jun 25 11:58:28.041119 osdx kernel: app-detect: module init
Jun 25 11:58:28.041182 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 25 11:58:28.041200 osdx kernel: app-detect: expression init
Jun 25 11:58:28.041212 osdx kernel: app-detect: appid cache initialized
Jun 25 11:58:28.041224 osdx kernel: app-detect: appid cache changes counter initialized
Jun 25 11:58:28.085091 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 25 11:58:28.542345 osdx cfgd[1464]: [4070]Completed change to active configuration
Jun 25 11:58:28.556605 osdx OSDxCLI[4070]: User 'admin' committed the configuration.
Jun 25 11:58:28.582408 osdx OSDxCLI[4070]: User 'admin' left the configuration menu.
Jun 25 11:58:28.732161 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jun 25 11:58:28.877226 osdx file_operation[13130]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Jun 25 11:58:28.885089 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=58272 DF PROTO=TCP SPT=55816 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 25 11:58:29.093084 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=58273 DF PROTO=TCP SPT=55816 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 25 11:58:29.501138 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=58274 DF PROTO=TCP SPT=55816 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 25 11:58:30.333118 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=58275 DF PROTO=TCP SPT=55816 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 25 11:58:31.837032 osdx file_operation.py[13130]: Operation aborted by user.
Jun 25 11:58:31.849083 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=58276 DF PROTO=TCP SPT=55816 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 25 11:58:31.851867 osdx OSDxCLI[4070]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.