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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.252/0.252/0.252/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 20 12:47:18.340787 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:47:18.343701 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:18.343792 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:18.353081 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:18.680185 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:18.969333 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:19.051613 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:19.163284 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
Jun 20 12:47:19.249146 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:19.360830 osdx ubnt-cfgd[144781]: inactive
Jun 20 12:47:19.381494 osdx INFO[144789]: FRR daemons did not change
Jun 20 12:47:19.407721 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:19.551924 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:19.554536 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:47:19.554842 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:19.556091 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:19.558177 osdx ulogd[144880]: registering plugin `NFCT'
Jun 20 12:47:19.559172 osdx ulogd[144880]: registering plugin `IP2STR'
Jun 20 12:47:19.559273 osdx ulogd[144880]: registering plugin `PRINTFLOW'
Jun 20 12:47:19.560321 osdx ulogd[144880]: registering plugin `SYSLOG'
Jun 20 12:47:19.560360 osdx ulogd[144880]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:19.560434 osdx ulogd[144880]: NFCT plugin working in event mode
Jun 20 12:47:19.560466 osdx ulogd[144880]: Changing UID / GID
Jun 20 12:47:19.560563 osdx ulogd[144880]: initialization finished, entering main loop
Jun 20 12:47:19.567833 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:19.584321 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:20.476298 osdx ulogd[144880]: [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 20 12:47:20.552688 osdx ulogd[144880]: [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.384 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.259/0.259/0.259/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 20 12:47:24.000153 osdx systemd-timedated[143315]: Changed local time to Fri 2025-06-20 12:47:24 UTC
Jun 20 12:47:24.001827 osdx systemd-journald[1762]: Time jumped backwards, rotating.
Jun 20 12:47:24.001788 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'set date 2025-06-20 12:47:24'.
Jun 20 12:47:24.299358 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:47:24.301835 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:24.301900 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:24.309359 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:24.544424 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:24.793073 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:24.886662 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:24.982361 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
Jun 20 12:47:25.065505 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:25.173046 osdx ubnt-cfgd[145064]: inactive
Jun 20 12:47:25.192358 osdx INFO[145072]: FRR daemons did not change
Jun 20 12:47:25.213839 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:25.306164 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:25.307209 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:25.307375 osdx ulogd[145163]: registering plugin `NFCT'
Jun 20 12:47:25.307741 osdx ulogd[145163]: registering plugin `IP2STR'
Jun 20 12:47:25.307821 osdx ulogd[145163]: registering plugin `PRINTFLOW'
Jun 20 12:47:25.307898 osdx ulogd[145163]: registering plugin `SYSLOG'
Jun 20 12:47:25.307926 osdx ulogd[145163]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:25.307988 osdx ulogd[145163]: NFCT plugin working in event mode
Jun 20 12:47:25.308016 osdx ulogd[145163]: Changing UID / GID
Jun 20 12:47:25.308105 osdx ulogd[145163]: initialization finished, entering main loop
Jun 20 12:47:25.308563 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:25.320904 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:25.351664 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:26.222669 osdx ulogd[145163]: [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 20 12:47:26.340041 osdx ulogd[145163]: [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.437 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.437/0.437/0.437/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.271 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.320 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 2025ms
rtt min/avg/max/mdev = 0.271/0.290/0.320/0.021 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 20 12:47:31.305013 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.1M, max 15.3M, 13.2M free.
Jun 20 12:47:31.305984 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:31.306052 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:31.317699 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:31.550820 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:31.829109 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:31.917719 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:32.002735 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
Jun 20 12:47:32.132910 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 20 12:47:32.201688 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service ssh'.
Jun 20 12:47:32.327637 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:32.402166 osdx ubnt-cfgd[145349]: inactive
Jun 20 12:47:32.425565 osdx INFO[145363]: FRR daemons did not change
Jun 20 12:47:32.449988 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:32.526288 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:32.527089 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:32.527189 osdx ulogd[145456]: registering plugin `NFCT'
Jun 20 12:47:32.527229 osdx ulogd[145456]: registering plugin `IP2STR'
Jun 20 12:47:32.527265 osdx ulogd[145456]: registering plugin `PRINTFLOW'
Jun 20 12:47:32.527303 osdx ulogd[145456]: registering plugin `SYSLOG'
Jun 20 12:47:32.527306 osdx ulogd[145456]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:32.527344 osdx ulogd[145456]: NFCT plugin working in event mode
Jun 20 12:47:32.527350 osdx ulogd[145456]: Changing UID / GID
Jun 20 12:47:32.527414 osdx ulogd[145456]: initialization finished, entering main loop
Jun 20 12:47:32.590437 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Jun 20 12:47:32.601441 osdx sshd[145462]: Server listening on 0.0.0.0 port 22.
Jun 20 12:47:32.601465 osdx sshd[145462]: Server listening on :: port 22.
Jun 20 12:47:32.601541 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Jun 20 12:47:32.621855 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:32.634501 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:32.662789 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:34.696751 osdx ulogd[145456]: [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 20 12:47:35.720708 osdx ulogd[145456]: [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.385 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.222/0.222/0.222/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 20 12:47:43.347469 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.1M, max 15.3M, 13.2M free.
Jun 20 12:47:43.350824 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:43.350899 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:43.358233 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:43.643742 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:43.885614 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:43.983136 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:44.067691 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:47:44.182476 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:44.245188 osdx ubnt-cfgd[145670]: inactive
Jun 20 12:47:44.267838 osdx INFO[145678]: FRR daemons did not change
Jun 20 12:47:44.290777 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:44.379032 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:44.379940 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:47:44.380237 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:44.381960 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:44.382079 osdx ulogd[145769]: registering plugin `NFCT'
Jun 20 12:47:44.382118 osdx ulogd[145769]: registering plugin `IP2STR'
Jun 20 12:47:44.382155 osdx ulogd[145769]: registering plugin `PRINTFLOW'
Jun 20 12:47:44.382193 osdx ulogd[145769]: registering plugin `SYSLOG'
Jun 20 12:47:44.382196 osdx ulogd[145769]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:44.382235 osdx ulogd[145769]: NFCT plugin working in event mode
Jun 20 12:47:44.382241 osdx ulogd[145769]: Changing UID / GID
Jun 20 12:47:44.382305 osdx ulogd[145769]: initialization finished, entering main loop
Jun 20 12:47:44.392665 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:44.417007 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:45.315583 osdx ulogd[145769]: [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 20 12:47:45.315609 osdx ulogd[145769]: [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 20 12:47:45.393726 osdx ulogd[145769]: [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 20 12:47:45.393744 osdx ulogd[145769]: [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.371 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.248/0.248/0.248/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 20 12:47:50.310962 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:47:50.312644 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:50.312706 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:50.322010 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:50.548961 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:50.775660 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:50.853865 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:50.936948 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:47:50.995255 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Jun 20 12:47:51.104560 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:51.166519 osdx ubnt-cfgd[145953]: inactive
Jun 20 12:47:51.186196 osdx INFO[145961]: FRR daemons did not change
Jun 20 12:47:51.208650 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:51.288904 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:51.289745 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:51.289909 osdx ulogd[146052]: registering plugin `NFCT'
Jun 20 12:47:51.290125 osdx ulogd[146052]: registering plugin `IP2STR'
Jun 20 12:47:51.290193 osdx ulogd[146052]: registering plugin `PRINTFLOW'
Jun 20 12:47:51.290258 osdx ulogd[146052]: registering plugin `SYSLOG'
Jun 20 12:47:51.290282 osdx ulogd[146052]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:51.290342 osdx ulogd[146052]: NFCT plugin working in event mode
Jun 20 12:47:51.290370 osdx OSDx_DUT0[146052]: Changing UID / GID
Jun 20 12:47:51.290468 osdx OSDx_DUT0[146052]: initialization finished, entering main loop
Jun 20 12:47:51.291144 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:51.302641 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:51.323180 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:52.148383 osdx OSDx_DUT0[146052]: [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 20 12:47:52.148407 osdx OSDx_DUT0[146052]: [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 20 12:47:52.230365 osdx OSDx_DUT0[146052]: [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 20 12:47:52.230383 osdx OSDx_DUT0[146052]: [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.241 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.241/0.241/0.241/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 20 12:47:50.310962 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:47:50.312644 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:50.312706 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:50.322010 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:50.548961 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:50.775660 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:50.853865 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:50.936948 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:47:50.995255 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Jun 20 12:47:51.104560 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:51.166519 osdx ubnt-cfgd[145953]: inactive
Jun 20 12:47:51.186196 osdx INFO[145961]: FRR daemons did not change
Jun 20 12:47:51.208650 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:51.288904 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:51.289745 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:51.289909 osdx ulogd[146052]: registering plugin `NFCT'
Jun 20 12:47:51.290125 osdx ulogd[146052]: registering plugin `IP2STR'
Jun 20 12:47:51.290193 osdx ulogd[146052]: registering plugin `PRINTFLOW'
Jun 20 12:47:51.290258 osdx ulogd[146052]: registering plugin `SYSLOG'
Jun 20 12:47:51.290282 osdx ulogd[146052]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:51.290342 osdx ulogd[146052]: NFCT plugin working in event mode
Jun 20 12:47:51.290370 osdx OSDx_DUT0[146052]: Changing UID / GID
Jun 20 12:47:51.290468 osdx OSDx_DUT0[146052]: initialization finished, entering main loop
Jun 20 12:47:51.291144 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:51.302641 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:51.323180 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:52.148383 osdx OSDx_DUT0[146052]: [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 20 12:47:52.148407 osdx OSDx_DUT0[146052]: [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 20 12:47:52.230365 osdx OSDx_DUT0[146052]: [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 20 12:47:52.230383 osdx OSDx_DUT0[146052]: [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 20 12:47:52.306127 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 20 12:47:52.458791 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:52.526677 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'.
Jun 20 12:47:52.633424 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show changes'.
Jun 20 12:47:52.696099 osdx ubnt-cfgd[146088]: inactive
Jun 20 12:47:52.712850 osdx INFO[146094]: FRR daemons did not change
Jun 20 12:47:52.723797 osdx OSDx_DUT0[146052]: Terminal signal received, exiting
Jun 20 12:47:52.723816 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:52.724324 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jun 20 12:47:52.724418 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:52.748968 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:52.749797 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:47:52.750400 osdx ulogd[146102]: registering plugin `NFCT'
Jun 20 12:47:52.750607 osdx ulogd[146102]: registering plugin `IP2STR'
Jun 20 12:47:52.750676 osdx ulogd[146102]: registering plugin `PRINTFLOW'
Jun 20 12:47:52.750747 osdx ulogd[146102]: registering plugin `SYSLOG'
Jun 20 12:47:52.750777 osdx ulogd[146102]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:52.750852 osdx ulogd[146102]: NFCT plugin working in event mode
Jun 20 12:47:52.750887 osdx ulogd[146102]: Changing UID / GID
Jun 20 12:47:52.750983 osdx ulogd[146102]: initialization finished, entering main loop
Jun 20 12:47:52.764686 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:52.765873 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:52.767224 osdx ulogd[146102]: [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 20 12:47:52.767274 osdx ulogd[146102]: [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 20 12:47:52.767774 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:52.784916 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:47:52.940714 osdx ulogd[146102]: [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 20 12:47:52.940742 osdx ulogd[146102]: [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.299 ms

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

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1008ms
rtt min/avg/max/mdev = 0.238/0.245/0.252/0.007 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 20 12:47:57.384528 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:47:57.385021 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:47:57.385053 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:47:57.397228 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:47:57.635126 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:47:58.071598 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:47:58.188728 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jun 20 12:47:58.282684 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic label TEST'.
Jun 20 12:47:58.398710 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
Jun 20 12:47:58.489679 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
Jun 20 12:47:58.567245 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:47:58.626253 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:47:58.741503 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:47:58.818915 osdx ubnt-cfgd[146267]: inactive
Jun 20 12:47:58.850180 osdx INFO[146281]: FRR daemons did not change
Jun 20 12:47:58.877053 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:47:58.965322 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:58.966176 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:47:58.966697 osdx ulogd[146372]: registering plugin `NFCT'
Jun 20 12:47:58.966893 osdx ulogd[146372]: registering plugin `IP2STR'
Jun 20 12:47:58.966968 osdx ulogd[146372]: registering plugin `PRINTFLOW'
Jun 20 12:47:58.967031 osdx ulogd[146372]: registering plugin `SYSLOG'
Jun 20 12:47:58.967056 osdx ulogd[146372]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:58.967117 osdx ulogd[146372]: NFCT plugin working in event mode
Jun 20 12:47:58.967147 osdx ulogd[146372]: Changing UID / GID
Jun 20 12:47:58.967232 osdx ulogd[146372]: initialization finished, entering main loop
Jun 20 12:47:58.981054 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:58.991631 osdx ulogd[146372]: Terminal signal received, exiting
Jun 20 12:47:58.991676 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:58.992186 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jun 20 12:47:58.992279 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:58.993131 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:47:58.993876 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:47:58.994376 osdx ulogd[146378]: registering plugin `NFCT'
Jun 20 12:47:58.994557 osdx ulogd[146378]: registering plugin `IP2STR'
Jun 20 12:47:58.994631 osdx ulogd[146378]: registering plugin `PRINTFLOW'
Jun 20 12:47:58.994701 osdx ulogd[146378]: registering plugin `SYSLOG'
Jun 20 12:47:58.994730 osdx ulogd[146378]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:47:58.994797 osdx ulogd[146378]: NFCT plugin working in event mode
Jun 20 12:47:58.994828 osdx ulogd[146378]: Changing UID / GID
Jun 20 12:47:58.994913 osdx ulogd[146378]: initialization finished, entering main loop
Jun 20 12:47:59.009062 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:47:59.173836 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:47:59.185707 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:47:59.203321 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:00.101185 osdx ulogd[146378]: [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 20 12:48:00.101202 osdx ulogd[146378]: [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 20 12:48:00.180090 osdx ulogd[146378]: [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 20 12:48:00.180110 osdx ulogd[146378]: [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.320 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.235/0.235/0.235/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 20 12:48:06.291631 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.4M, max 15.3M, 12.9M free.
Jun 20 12:48:06.294889 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:06.294937 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:06.301567 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:06.516433 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:06.744873 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:06.826442 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
Jun 20 12:48:06.916508 osdx OSDxCLI[138046]: 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 20 12:48:06.965870 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system vrf RED'.
Jun 20 12:48:07.069100 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:07.128340 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:07.242745 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:07.307563 osdx ubnt-cfgd[146609]: inactive
Jun 20 12:48:07.328960 osdx INFO[146617]: FRR daemons did not change
Jun 20 12:48:07.338814 osdx (udev-worker)[146625]: RED: Could not disable auto negotiation, ignoring: Operation not supported
Jun 20 12:48:07.339067 osdx (udev-worker)[146625]: Network interface NamePolicy= disabled on kernel command line.
Jun 20 12:48:07.366890 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:07.418882 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:07.527124 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:07.528064 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:07.528533 osdx ulogd[146783]: registering plugin `NFCT'
Jun 20 12:48:07.528698 osdx ulogd[146783]: registering plugin `IP2STR'
Jun 20 12:48:07.528769 osdx ulogd[146783]: registering plugin `PRINTFLOW'
Jun 20 12:48:07.528831 osdx ulogd[146783]: registering plugin `SYSLOG'
Jun 20 12:48:07.528856 osdx ulogd[146783]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:07.528916 osdx ulogd[146783]: NFCT plugin working in event mode
Jun 20 12:48:07.528944 osdx ulogd[146783]: Changing UID / GID
Jun 20 12:48:07.529027 osdx ulogd[146783]: initialization finished, entering main loop
Jun 20 12:48:07.542908 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:07.544068 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:07.555452 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:07.577442 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:08.443996 osdx ulogd[146783]: [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 20 12:48:08.444020 osdx ulogd[146783]: [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 20 12:48:08.522427 osdx ulogd[146783]: [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 20 12:48:08.522445 osdx ulogd[146783]: [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.230 ms

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.451/0.451/0.451/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.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 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 20 12:48:13.323824 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:13.327196 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:13.327255 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:13.336894 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:13.637831 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:13.868851 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:13.959736 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jun 20 12:48:14.046263 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:14.148999 osdx ubnt-cfgd[147047]: inactive
Jun 20 12:48:14.174621 osdx INFO[147055]: FRR daemons did not change
Jun 20 12:48:14.195202 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 20 12:48:14.257329 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:14.268110 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:14.294518 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:14.480512 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jun 20 12:48:14.630841 osdx file_operation[147172]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
Jun 20 12:48:14.656083 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
Jun 20 12:48:14.817810 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:14.895481 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jun 20 12:48:14.993308 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
Jun 20 12:48:15.064726 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'.
Jun 20 12:48:15.140217 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
Jun 20 12:48:15.252847 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
Jun 20 12:48:15.374747 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
Jun 20 12:48:15.449255 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
Jun 20 12:48:15.552944 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
Jun 20 12:48:15.619371 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
Jun 20 12:48:15.738339 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:15.793410 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:15.924011 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:16.002391 osdx ubnt-cfgd[147206]: inactive
Jun 20 12:48:16.041602 osdx INFO[147223]: FRR daemons did not change
Jun 20 12:48:16.063188 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:16.127513 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:16.128596 osdx ulogd[147314]: registering plugin `NFCT'
Jun 20 12:48:16.128645 osdx ulogd[147314]: registering plugin `IP2STR'
Jun 20 12:48:16.128692 osdx ulogd[147314]: registering plugin `PRINTFLOW'
Jun 20 12:48:16.128744 osdx ulogd[147314]: registering plugin `SYSLOG'
Jun 20 12:48:16.128748 osdx ulogd[147314]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:16.128798 osdx ulogd[147314]: NFCT plugin working in event mode
Jun 20 12:48:16.128806 osdx ulogd[147314]: Changing UID / GID
Jun 20 12:48:16.128884 osdx ulogd[147314]: initialization finished, entering main loop
Jun 20 12:48:16.129613 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:16.451113 osdx systemd[1]: Reloading.
Jun 20 12:48:16.511179 osdx systemd-sysv-generator[147351]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
Jun 20 12:48:16.643702 osdx systemd[1]: Starting logrotate.service - Rotate log files...
Jun 20 12:48:16.649467 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata.
Jun 20 12:48:16.650685 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
Jun 20 12:48:16.668999 osdx systemd[1]: logrotate.service: Deactivated successfully.
Jun 20 12:48:16.669180 osdx systemd[1]: Finished logrotate.service - Rotate log files.
Jun 20 12:48:16.941406 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
Jun 20 12:48:17.413376 osdx INFO[147333]: Rules successfully loaded
Jun 20 12:48:17.427465 osdx ulogd[147314]: Terminal signal received, exiting
Jun 20 12:48:17.427543 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:17.428116 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jun 20 12:48:17.428211 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:17.451592 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:17.452617 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:17.453101 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:17.453934 osdx ulogd[147379]: registering plugin `NFCT'
Jun 20 12:48:17.454193 osdx ulogd[147379]: registering plugin `IP2STR'
Jun 20 12:48:17.454288 osdx ulogd[147379]: registering plugin `PRINTFLOW'
Jun 20 12:48:17.454369 osdx ulogd[147379]: registering plugin `SYSLOG'
Jun 20 12:48:17.454406 osdx ulogd[147379]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:17.454488 osdx ulogd[147379]: NFCT plugin working in event mode
Jun 20 12:48:17.454529 osdx ulogd[147379]: Changing UID / GID
Jun 20 12:48:17.454639 osdx ulogd[147379]: initialization finished, entering main loop
Jun 20 12:48:17.454931 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:17.466457 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:17.499284 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:18.519771 osdx ulogd[147379]: [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 20 12:48:18.519790 osdx ulogd[147379]: [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 20 12:48:18.628986 osdx ulogd[147379]: [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 20 12:48:18.629006 osdx ulogd[147379]: [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.313 ms

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

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

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

Last login: Fri Jun 20 12:46:44 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 20 12:48:26.391614 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:26.393695 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:26.393769 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:26.401182 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:26.636839 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:26.916426 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:27.003569 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
Jun 20 12:48:27.095396 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:27.158451 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:27.285375 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:27.354089 osdx ubnt-cfgd[147657]: inactive
Jun 20 12:48:27.379178 osdx INFO[147667]: FRR daemons did not change
Jun 20 12:48:27.405680 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 20 12:48:27.465688 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:27.549915 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:27.550591 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:27.551093 osdx ulogd[147833]: registering plugin `NFCT'
Jun 20 12:48:27.551276 osdx ulogd[147833]: registering plugin `IP2STR'
Jun 20 12:48:27.551341 osdx ulogd[147833]: registering plugin `PRINTFLOW'
Jun 20 12:48:27.551409 osdx ulogd[147833]: registering plugin `SYSLOG'
Jun 20 12:48:27.551438 osdx ulogd[147833]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:27.551500 osdx ulogd[147833]: NFCT plugin working in event mode
Jun 20 12:48:27.551532 osdx ulogd[147833]: Changing UID / GID
Jun 20 12:48:27.551620 osdx ulogd[147833]: initialization finished, entering main loop
Jun 20 12:48:27.569732 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:27.571008 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:27.582631 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:27.601117 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:29.607314 osdx ulogd[147833]: [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 20 12:48:29.607330 osdx ulogd[147833]: [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 20 12:48:29.747273 osdx ulogd[147833]: [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 20 12:48:29.747292 osdx ulogd[147833]: [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 20 12:48:29.849723 osdx ulogd[147833]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 PKTS=0 BYTES=0
Jun 20 12:48:29.849909 osdx ulogd[147833]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 PKTS=0 BYTES=0
Jun 20 12:48:29.849973 osdx ulogd[147833]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 PKTS=0 BYTES=0 [OFFLOAD]
Jun 20 12:48:30.098071 osdx ulogd[147833]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 PKTS=0 BYTES=0
Jun 20 12:48:30.098087 osdx ulogd[147833]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 PKTS=0 BYTES=0 [OFFLOAD]
Jun 20 12:48:30.099360 osdx ulogd[147833]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 PKTS=0 BYTES=0
Jun 20 12:48:30.099439 osdx ulogd[147833]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=47872 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=47872 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.347 ms

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

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2030ms
rtt min/avg/max/mdev = 0.233/0.256/0.270/0.016 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 20 12:48:34.351872 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:34.353269 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:34.353365 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:34.364114 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:34.606275 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:34.950528 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:35.033084 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 20 12:48:35.118355 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 20 12:48:35.258922 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:35.317653 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:35.437361 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:35.525411 osdx ubnt-cfgd[148048]: inactive
Jun 20 12:48:35.549517 osdx INFO[148056]: FRR daemons did not change
Jun 20 12:48:35.725248 osdx kernel: app-detect: module init
Jun 20 12:48:35.725306 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 20 12:48:35.725316 osdx kernel: app-detect: expression init
Jun 20 12:48:35.725324 osdx kernel: app-detect: appid cache initialized
Jun 20 12:48:35.725332 osdx kernel: app-detect: appid cache changes counter initialized
Jun 20 12:48:35.729187 osdx modulelauncher[148059]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 20 12:48:35.761301 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:35.847109 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:35.849054 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:35.849913 osdx ulogd[148170]: registering plugin `NFCT'
Jun 20 12:48:35.849964 osdx ulogd[148170]: registering plugin `IP2STR'
Jun 20 12:48:35.850014 osdx ulogd[148170]: registering plugin `PRINTFLOW'
Jun 20 12:48:35.850066 osdx ulogd[148170]: registering plugin `SYSLOG'
Jun 20 12:48:35.850071 osdx ulogd[148170]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:35.850132 osdx ulogd[148170]: NFCT plugin working in event mode
Jun 20 12:48:35.850140 osdx ulogd[148170]: Changing UID / GID
Jun 20 12:48:35.850257 osdx ulogd[148170]: initialization finished, entering main loop
Jun 20 12:48:35.865346 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:35.867266 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:35.879780 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:35.904140 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:36.809538 osdx ulogd[148170]: [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 20 12:48:36.809557 osdx ulogd[148170]: [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 20 12:48:36.902214 osdx ulogd[148170]: [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 20 12:48:36.902233 osdx ulogd[148170]: [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 20 12:48:37.907935 osdx ulogd[148170]: [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 20 12:48:37.907959 osdx ulogd[148170]: [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 20 12:48:37.907973 osdx ulogd[148170]: [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 20 12:48:38.931938 osdx ulogd[148170]: [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 20 12:48:38.931964 osdx ulogd[148170]: [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 20 12:48:38.931978 osdx ulogd[148170]: [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 20 12:48:34.351872 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:34.353269 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:34.353365 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:34.364114 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:34.606275 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:34.950528 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:35.033084 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 20 12:48:35.118355 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 20 12:48:35.258922 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:35.317653 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:35.437361 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:35.525411 osdx ubnt-cfgd[148048]: inactive
Jun 20 12:48:35.549517 osdx INFO[148056]: FRR daemons did not change
Jun 20 12:48:35.725248 osdx kernel: app-detect: module init
Jun 20 12:48:35.725306 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 20 12:48:35.725316 osdx kernel: app-detect: expression init
Jun 20 12:48:35.725324 osdx kernel: app-detect: appid cache initialized
Jun 20 12:48:35.725332 osdx kernel: app-detect: appid cache changes counter initialized
Jun 20 12:48:35.729187 osdx modulelauncher[148059]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 20 12:48:35.761301 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:35.847109 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:35.849054 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:35.849913 osdx ulogd[148170]: registering plugin `NFCT'
Jun 20 12:48:35.849964 osdx ulogd[148170]: registering plugin `IP2STR'
Jun 20 12:48:35.850014 osdx ulogd[148170]: registering plugin `PRINTFLOW'
Jun 20 12:48:35.850066 osdx ulogd[148170]: registering plugin `SYSLOG'
Jun 20 12:48:35.850071 osdx ulogd[148170]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:35.850132 osdx ulogd[148170]: NFCT plugin working in event mode
Jun 20 12:48:35.850140 osdx ulogd[148170]: Changing UID / GID
Jun 20 12:48:35.850257 osdx ulogd[148170]: initialization finished, entering main loop
Jun 20 12:48:35.865346 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:35.867266 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:35.879780 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:35.904140 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:36.809538 osdx ulogd[148170]: [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 20 12:48:36.809557 osdx ulogd[148170]: [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 20 12:48:36.902214 osdx ulogd[148170]: [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 20 12:48:36.902233 osdx ulogd[148170]: [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 20 12:48:37.907935 osdx ulogd[148170]: [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 20 12:48:37.907959 osdx ulogd[148170]: [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 20 12:48:37.907973 osdx ulogd[148170]: [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 20 12:48:38.931938 osdx ulogd[148170]: [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 20 12:48:38.931964 osdx ulogd[148170]: [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 20 12:48:38.931978 osdx ulogd[148170]: [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 20 12:48:39.050724 osdx OSDxCLI[138046]: 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 20 12:48:34.351872 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:34.353269 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:34.353365 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:34.364114 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:34.606275 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:34.950528 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:35.033084 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 20 12:48:35.118355 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 20 12:48:35.258922 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:35.317653 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:35.437361 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:35.525411 osdx ubnt-cfgd[148048]: inactive
Jun 20 12:48:35.549517 osdx INFO[148056]: FRR daemons did not change
Jun 20 12:48:35.725248 osdx kernel: app-detect: module init
Jun 20 12:48:35.725306 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 20 12:48:35.725316 osdx kernel: app-detect: expression init
Jun 20 12:48:35.725324 osdx kernel: app-detect: appid cache initialized
Jun 20 12:48:35.725332 osdx kernel: app-detect: appid cache changes counter initialized
Jun 20 12:48:35.729187 osdx modulelauncher[148059]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 20 12:48:35.761301 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:35.847109 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:35.849054 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:35.849913 osdx ulogd[148170]: registering plugin `NFCT'
Jun 20 12:48:35.849964 osdx ulogd[148170]: registering plugin `IP2STR'
Jun 20 12:48:35.850014 osdx ulogd[148170]: registering plugin `PRINTFLOW'
Jun 20 12:48:35.850066 osdx ulogd[148170]: registering plugin `SYSLOG'
Jun 20 12:48:35.850071 osdx ulogd[148170]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:35.850132 osdx ulogd[148170]: NFCT plugin working in event mode
Jun 20 12:48:35.850140 osdx ulogd[148170]: Changing UID / GID
Jun 20 12:48:35.850257 osdx ulogd[148170]: initialization finished, entering main loop
Jun 20 12:48:35.865346 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:35.867266 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:35.879780 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:35.904140 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:36.809538 osdx ulogd[148170]: [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 20 12:48:36.809557 osdx ulogd[148170]: [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 20 12:48:36.902214 osdx ulogd[148170]: [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 20 12:48:36.902233 osdx ulogd[148170]: [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 20 12:48:37.907935 osdx ulogd[148170]: [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 20 12:48:37.907959 osdx ulogd[148170]: [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 20 12:48:37.907973 osdx ulogd[148170]: [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 20 12:48:38.931938 osdx ulogd[148170]: [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 20 12:48:38.931964 osdx ulogd[148170]: [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 20 12:48:38.931978 osdx ulogd[148170]: [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 20 12:48:39.050724 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 20 12:48:39.199341 osdx OSDxCLI[138046]: 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.231 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.231/0.231/0.231/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  1086    0  1086    0     0   119k      0 --:--:-- --:--:-- --:--:--  132k

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 20 12:48:34.351872 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:34.353269 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:34.353365 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:34.364114 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:34.606275 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:34.950528 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:35.033084 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jun 20 12:48:35.118355 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jun 20 12:48:35.258922 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jun 20 12:48:35.317653 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jun 20 12:48:35.437361 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:35.525411 osdx ubnt-cfgd[148048]: inactive
Jun 20 12:48:35.549517 osdx INFO[148056]: FRR daemons did not change
Jun 20 12:48:35.725248 osdx kernel: app-detect: module init
Jun 20 12:48:35.725306 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 20 12:48:35.725316 osdx kernel: app-detect: expression init
Jun 20 12:48:35.725324 osdx kernel: app-detect: appid cache initialized
Jun 20 12:48:35.725332 osdx kernel: app-detect: appid cache changes counter initialized
Jun 20 12:48:35.729187 osdx modulelauncher[148059]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 20 12:48:35.761301 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
Jun 20 12:48:35.847109 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jun 20 12:48:35.849054 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jun 20 12:48:35.849913 osdx ulogd[148170]: registering plugin `NFCT'
Jun 20 12:48:35.849964 osdx ulogd[148170]: registering plugin `IP2STR'
Jun 20 12:48:35.850014 osdx ulogd[148170]: registering plugin `PRINTFLOW'
Jun 20 12:48:35.850066 osdx ulogd[148170]: registering plugin `SYSLOG'
Jun 20 12:48:35.850071 osdx ulogd[148170]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jun 20 12:48:35.850132 osdx ulogd[148170]: NFCT plugin working in event mode
Jun 20 12:48:35.850140 osdx ulogd[148170]: Changing UID / GID
Jun 20 12:48:35.850257 osdx ulogd[148170]: initialization finished, entering main loop
Jun 20 12:48:35.865346 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jun 20 12:48:35.867266 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:35.879780 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:35.904140 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:36.809538 osdx ulogd[148170]: [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 20 12:48:36.809557 osdx ulogd[148170]: [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 20 12:48:36.902214 osdx ulogd[148170]: [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 20 12:48:36.902233 osdx ulogd[148170]: [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 20 12:48:37.907935 osdx ulogd[148170]: [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 20 12:48:37.907959 osdx ulogd[148170]: [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 20 12:48:37.907973 osdx ulogd[148170]: [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 20 12:48:38.931938 osdx ulogd[148170]: [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 20 12:48:38.931964 osdx ulogd[148170]: [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 20 12:48:38.931978 osdx ulogd[148170]: [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 20 12:48:39.050724 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 20 12:48:39.199341 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 20 12:48:39.316725 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal show | cat'.
Jun 20 12:48:39.587826 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:39.669098 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jun 20 12:48:39.760175 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Jun 20 12:48:39.846676 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show changes'.
Jun 20 12:48:39.931178 osdx ubnt-cfgd[148221]: inactive
Jun 20 12:48:39.959166 osdx INFO[148229]: FRR daemons did not change
Jun 20 12:48:39.997272 osdx kernel: app-detect: expression destroy
Jun 20 12:48:40.005264 osdx kernel: app-detect: expression init
Jun 20 12:48:40.005304 osdx kernel: app-detect: appid cache initialized
Jun 20 12:48:40.005316 osdx kernel: app-detect: appid cache changes counter initialized
Jun 20 12:48:40.009956 osdx modulelauncher[148232]: AppDetect: no change in application dictionaries, thus nothing more to do
Jun 20 12:48:40.029248 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 20 12:48:40.084801 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:40.096938 osdx ulogd[148170]: [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 20 12:48:40.096959 osdx ulogd[148170]: [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 20 12:48:40.097645 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:40.149002 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:40.325085 osdx ulogd[148170]: [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 20 12:48:40.325288 osdx ulogd[148170]: [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 20 12:48:40.327113 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jun 20 12:48:40.465968 osdx file_operation[148359]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Jun 20 12:48:40.470606 osdx ulogd[148170]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=33064 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=33064 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jun 20 12:48:40.470724 osdx ulogd[148170]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=33064 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=33064 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jun 20 12:48:40.470738 osdx ulogd[148170]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=33064 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=33064 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jun 20 12:48:40.477063 osdx ulogd[148170]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=33064 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=33064 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jun 20 12:48:40.477171 osdx ulogd[148170]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=33064 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=33064 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jun 20 12:48:40.477183 osdx ulogd[148170]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=33064 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=33064 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jun 20 12:48:40.495994 osdx OSDxCLI[138046]: 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.200 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.200/0.200/0.200/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 20 12:48:45.334294 osdx systemd-journald[1762]: Runtime Journal (/run/log/journal/a9538f26f6924eb58d28105803b55de8) is 2.0M, max 15.3M, 13.3M free.
Jun 20 12:48:45.336704 osdx systemd-journald[1762]: Received client request to rotate journal, rotating.
Jun 20 12:48:45.336761 osdx systemd-journald[1762]: Vacuuming done, freed 0B of archived journals from /run/log/journal/a9538f26f6924eb58d28105803b55de8.
Jun 20 12:48:45.343705 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system journal clear'.
Jun 20 12:48:45.574093 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'system coredump delete all'.
Jun 20 12:48:45.811390 osdx OSDxCLI[138046]: User 'admin' entered the configuration menu.
Jun 20 12:48:45.878802 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'.
Jun 20 12:48:45.975637 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'.
Jun 20 12:48:46.035817 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'.
Jun 20 12:48:46.140291 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'.
Jun 20 12:48:46.197309 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'.
Jun 20 12:48:46.291710 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'.
Jun 20 12:48:46.348735 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'.
Jun 20 12:48:46.474861 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'.
Jun 20 12:48:46.528911 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jun 20 12:48:46.618604 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Jun 20 12:48:46.693848 osdx OSDxCLI[138046]: User 'admin' added a new cfg line: 'show working'.
Jun 20 12:48:46.809098 osdx ubnt-cfgd[148579]: inactive
Jun 20 12:48:46.850874 osdx INFO[148601]: FRR daemons did not change
Jun 20 12:48:47.044689 osdx kernel: app-detect: module init
Jun 20 12:48:47.044765 osdx kernel: app-detect: registered: sysctl net.appdetect
Jun 20 12:48:47.044785 osdx kernel: app-detect: expression init
Jun 20 12:48:47.044798 osdx kernel: app-detect: appid cache initialized
Jun 20 12:48:47.044810 osdx kernel: app-detect: appid cache changes counter initialized
Jun 20 12:48:47.088688 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
Jun 20 12:48:47.333877 osdx cfgd[1460]: [138046]Completed change to active configuration
Jun 20 12:48:47.348674 osdx OSDxCLI[138046]: User 'admin' committed the configuration.
Jun 20 12:48:47.365988 osdx OSDxCLI[138046]: User 'admin' left the configuration menu.
Jun 20 12:48:47.532714 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jun 20 12:48:47.674627 osdx file_operation[148769]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Jun 20 12:48:47.684686 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=34252 DF PROTO=TCP SPT=56974 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 20 12:48:47.888698 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=34253 DF PROTO=TCP SPT=56974 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 20 12:48:48.316743 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=34254 DF PROTO=TCP SPT=56974 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 20 12:48:49.148788 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=34255 DF PROTO=TCP SPT=56974 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 20 12:48:50.664259 osdx file_operation.py[148769]: Operation aborted by user.
Jun 20 12:48:50.676706 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=34256 DF PROTO=TCP SPT=56974 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jun 20 12:48:50.680456 osdx OSDxCLI[138046]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.