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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.216/0.216/0.216/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
May 26 10:19:16.000350 osdx systemd-timedated[119565]: Changed local time to Mon 2025-05-26 10:19:16 UTC
May 26 10:19:16.001040 osdx systemd-journald[1942]: Time jumped backwards, rotating.
May 26 10:19:16.001817 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'set date 2025-05-26 10:19:16'.
May 26 10:19:16.304126 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.6M, max 15.3M, 12.6M free.
May 26 10:19:16.304705 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:16.304743 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:16.313594 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:16.662434 osdx osdx-coredump[119583]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:16.670037 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:17.127376 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:17.203216 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:17.321623 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
May 26 10:19:17.385260 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:17.492993 osdx INFO[119603]: FRR daemons did not change
May 26 10:19:17.520712 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:17.625045 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:17.628799 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:17.630090 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:17.632400 osdx ulogd[119672]: registering plugin `NFCT'
May 26 10:19:17.633745 osdx ulogd[119672]: registering plugin `IP2STR'
May 26 10:19:17.633879 osdx ulogd[119672]: registering plugin `PRINTFLOW'
May 26 10:19:17.635272 osdx ulogd[119672]: registering plugin `SYSLOG'
May 26 10:19:17.635328 osdx ulogd[119672]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:17.635434 osdx ulogd[119672]: NFCT plugin working in event mode
May 26 10:19:17.635479 osdx ulogd[119672]: Changing UID / GID
May 26 10:19:17.635596 osdx ulogd[119672]: initialization finished, entering main loop
May 26 10:19:17.660357 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:17.681746 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:18.613136 osdx ulogd[119672]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:18.701385 osdx ulogd[119672]: [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.336 ms

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

Step 4: Ping IP address 192.168.100.1 from DUT1:

admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1
Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.236 ms

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

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

ulogd\[.*\]:.*\[UPDATE\].*SRC=192.168.100.2
Show output
May 26 10:19:23.311047 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.1M, max 15.3M, 13.1M free.
May 26 10:19:23.311592 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:23.311635 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:23.323238 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:23.645725 osdx osdx-coredump[119817]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:23.653178 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:24.128619 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:24.205643 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:24.285779 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
May 26 10:19:24.356810 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:24.461936 osdx INFO[119837]: FRR daemons did not change
May 26 10:19:24.491623 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:24.587874 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:24.588534 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:19:24.589034 osdx ulogd[119906]: registering plugin `NFCT'
May 26 10:19:24.589071 osdx ulogd[119906]: registering plugin `IP2STR'
May 26 10:19:24.589106 osdx ulogd[119906]: registering plugin `PRINTFLOW'
May 26 10:19:24.589150 osdx ulogd[119906]: registering plugin `SYSLOG'
May 26 10:19:24.589153 osdx ulogd[119906]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:24.589191 osdx ulogd[119906]: NFCT plugin working in event mode
May 26 10:19:24.589197 osdx ulogd[119906]: Changing UID / GID
May 26 10:19:24.589256 osdx ulogd[119906]: initialization finished, entering main loop
May 26 10:19:24.603639 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:24.606277 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:24.632011 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:24.660050 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:25.510515 osdx ulogd[119906]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:25.590001 osdx ulogd[119906]: [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.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 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.228 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.304 ms
64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.338 ms

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2027ms
rtt min/avg/max/mdev = 0.228/0.290/0.338/0.045 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
May 26 10:19:30.305523 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.1M, max 15.3M, 13.2M free.
May 26 10:19:30.308394 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:30.308474 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:30.315787 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:30.650350 osdx osdx-coredump[120051]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:30.658592 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:31.160708 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:31.247308 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:31.331757 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
May 26 10:19:31.391077 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
May 26 10:19:31.490792 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service ssh'.
May 26 10:19:31.560905 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:31.666380 osdx INFO[120079]: FRR daemons did not change
May 26 10:19:31.692388 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:31.792737 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:31.793746 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:31.794759 osdx ulogd[120150]: registering plugin `NFCT'
May 26 10:19:31.794806 osdx ulogd[120150]: registering plugin `IP2STR'
May 26 10:19:31.794850 osdx ulogd[120150]: registering plugin `PRINTFLOW'
May 26 10:19:31.794894 osdx ulogd[120150]: registering plugin `SYSLOG'
May 26 10:19:31.794897 osdx ulogd[120150]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:31.794942 osdx ulogd[120150]: NFCT plugin working in event mode
May 26 10:19:31.794950 osdx ulogd[120150]: Changing UID / GID
May 26 10:19:31.795022 osdx ulogd[120150]: initialization finished, entering main loop
May 26 10:19:31.872653 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
May 26 10:19:31.883980 osdx sshd[120156]: Server listening on 0.0.0.0 port 22.
May 26 10:19:31.884005 osdx sshd[120156]: Server listening on :: port 22.
May 26 10:19:31.884094 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
May 26 10:19:31.905835 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:31.945554 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:31.967904 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:33.874764 osdx ulogd[120150]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84
May 26 10:19:34.898707 osdx ulogd[120150]: [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.414 ms

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

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

Step 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
May 26 10:19:42.294287 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.3M free.
May 26 10:19:42.296338 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:42.296386 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:42.304563 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:42.639017 osdx osdx-coredump[120326]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:42.648727 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:43.155729 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:43.244552 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:43.332372 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:19:43.414993 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:43.513809 osdx INFO[120346]: FRR daemons did not change
May 26 10:19:43.540349 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:43.644619 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:43.645430 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:19:43.645941 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:43.646991 osdx ulogd[120415]: registering plugin `NFCT'
May 26 10:19:43.647043 osdx ulogd[120415]: registering plugin `IP2STR'
May 26 10:19:43.647091 osdx ulogd[120415]: registering plugin `PRINTFLOW'
May 26 10:19:43.647141 osdx ulogd[120415]: registering plugin `SYSLOG'
May 26 10:19:43.647146 osdx ulogd[120415]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:43.647195 osdx ulogd[120415]: NFCT plugin working in event mode
May 26 10:19:43.647203 osdx ulogd[120415]: Changing UID / GID
May 26 10:19:43.647283 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:43.647286 osdx ulogd[120415]: initialization finished, entering main loop
May 26 10:19:43.674321 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:43.697018 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:44.504779 osdx ulogd[120415]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:44.504798 osdx ulogd[120415]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:44.581375 osdx ulogd[120415]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:44.581394 osdx ulogd[120415]: [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.409 ms

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

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

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.262/0.262/0.262/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
May 26 10:19:49.308762 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.3M free.
May 26 10:19:49.309242 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:49.309271 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:49.319041 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:49.681358 osdx osdx-coredump[120561]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:49.689182 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:50.207148 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:50.287731 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:50.369061 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:19:50.428656 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
May 26 10:19:50.584403 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:50.658678 osdx INFO[120582]: FRR daemons did not change
May 26 10:19:50.685042 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:50.809447 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:50.810357 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:50.810492 osdx ulogd[120651]: registering plugin `NFCT'
May 26 10:19:50.810720 osdx ulogd[120651]: registering plugin `IP2STR'
May 26 10:19:50.810754 osdx ulogd[120651]: registering plugin `PRINTFLOW'
May 26 10:19:50.810792 osdx ulogd[120651]: registering plugin `SYSLOG'
May 26 10:19:50.810796 osdx ulogd[120651]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:50.810835 osdx ulogd[120651]: NFCT plugin working in event mode
May 26 10:19:50.810841 osdx OSDx_DUT0[120651]: Changing UID / GID
May 26 10:19:50.810907 osdx OSDx_DUT0[120651]: initialization finished, entering main loop
May 26 10:19:50.811752 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:50.851638 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:50.884452 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:51.784535 osdx OSDx_DUT0[120651]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.784555 osdx OSDx_DUT0[120651]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.867151 osdx OSDx_DUT0[120651]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.867170 osdx OSDx_DUT0[120651]: [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.263 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.263/0.263/0.263/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
May 26 10:19:49.308762 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.3M free.
May 26 10:19:49.309242 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:49.309271 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:49.319041 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:49.681358 osdx osdx-coredump[120561]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:49.689182 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:50.207148 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:50.287731 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:50.369061 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:19:50.428656 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
May 26 10:19:50.584403 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:50.658678 osdx INFO[120582]: FRR daemons did not change
May 26 10:19:50.685042 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:50.809447 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:50.810357 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:50.810492 osdx ulogd[120651]: registering plugin `NFCT'
May 26 10:19:50.810720 osdx ulogd[120651]: registering plugin `IP2STR'
May 26 10:19:50.810754 osdx ulogd[120651]: registering plugin `PRINTFLOW'
May 26 10:19:50.810792 osdx ulogd[120651]: registering plugin `SYSLOG'
May 26 10:19:50.810796 osdx ulogd[120651]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:50.810835 osdx ulogd[120651]: NFCT plugin working in event mode
May 26 10:19:50.810841 osdx OSDx_DUT0[120651]: Changing UID / GID
May 26 10:19:50.810907 osdx OSDx_DUT0[120651]: initialization finished, entering main loop
May 26 10:19:50.811752 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:50.851638 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:50.884452 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:51.784535 osdx OSDx_DUT0[120651]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.784555 osdx OSDx_DUT0[120651]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.867151 osdx OSDx_DUT0[120651]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.867170 osdx OSDx_DUT0[120651]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:51.975867 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal show | cat'.
May 26 10:19:52.108566 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:52.188504 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'.
May 26 10:19:52.308691 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show changes'.
May 26 10:19:52.406720 osdx INFO[120687]: FRR daemons did not change
May 26 10:19:52.418651 osdx OSDx_DUT0[120651]: Terminal signal received, exiting
May 26 10:19:52.418720 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:52.418980 osdx systemd[1]: ulogd2.service: Deactivated successfully.
May 26 10:19:52.419073 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:52.437407 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:52.438128 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:52.438607 osdx ulogd[120696]: registering plugin `NFCT'
May 26 10:19:52.438847 osdx ulogd[120696]: registering plugin `IP2STR'
May 26 10:19:52.438939 osdx ulogd[120696]: registering plugin `PRINTFLOW'
May 26 10:19:52.439026 osdx ulogd[120696]: registering plugin `SYSLOG'
May 26 10:19:52.439064 osdx ulogd[120696]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:52.439147 osdx ulogd[120696]: NFCT plugin working in event mode
May 26 10:19:52.439191 osdx ulogd[120696]: Changing UID / GID
May 26 10:19:52.439298 osdx ulogd[120696]: initialization finished, entering main loop
May 26 10:19:52.439610 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:52.440934 osdx ulogd[120696]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84
May 26 10:19:52.441005 osdx ulogd[120696]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84
May 26 10:19:52.441489 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:52.474053 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:52.627234 osdx ulogd[120696]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:19:52.627255 osdx ulogd[120696]: [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.309 ms

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

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1018ms
rtt min/avg/max/mdev = 0.212/0.217/0.222/0.005 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
May 26 10:19:56.314266 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.3M free.
May 26 10:19:56.316098 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:19:56.316164 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:19:56.324939 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:19:56.646985 osdx osdx-coredump[120822]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:19:56.654535 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:19:57.151548 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:19:57.275912 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
May 26 10:19:57.327103 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic label TEST'.
May 26 10:19:57.432328 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
May 26 10:19:57.489548 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
May 26 10:19:57.588732 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:19:57.646494 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:19:57.774330 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:19:57.855949 osdx INFO[120852]: FRR daemons did not change
May 26 10:19:57.884096 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:19:58.004704 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:58.006545 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:58.007677 osdx ulogd[120921]: registering plugin `NFCT'
May 26 10:19:58.008552 osdx ulogd[120921]: registering plugin `IP2STR'
May 26 10:19:58.011040 osdx ulogd[120921]: registering plugin `PRINTFLOW'
May 26 10:19:58.011413 osdx ulogd[120921]: registering plugin `SYSLOG'
May 26 10:19:58.011544 osdx ulogd[120921]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:58.011760 osdx ulogd[120921]: NFCT plugin working in event mode
May 26 10:19:58.011876 osdx ulogd[120921]: Changing UID / GID
May 26 10:19:58.012182 osdx ulogd[120921]: initialization finished, entering main loop
May 26 10:19:58.033261 osdx ulogd[120921]: Terminal signal received, exiting
May 26 10:19:58.033461 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:58.034610 osdx systemd[1]: ulogd2.service: Deactivated successfully.
May 26 10:19:58.034889 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:58.037763 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:19:58.039367 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:19:58.040848 osdx ulogd[120927]: registering plugin `NFCT'
May 26 10:19:58.041473 osdx ulogd[120927]: registering plugin `IP2STR'
May 26 10:19:58.041715 osdx ulogd[120927]: registering plugin `PRINTFLOW'
May 26 10:19:58.041954 osdx ulogd[120927]: registering plugin `SYSLOG'
May 26 10:19:58.042051 osdx ulogd[120927]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:19:58.042264 osdx ulogd[120927]: NFCT plugin working in event mode
May 26 10:19:58.042371 osdx ulogd[120927]: Changing UID / GID
May 26 10:19:58.042666 osdx ulogd[120927]: initialization finished, entering main loop
May 26 10:19:58.204912 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:19:58.231355 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:19:58.257648 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:19:59.125145 osdx ulogd[120927]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 LABELS=TEST
May 26 10:19:59.125167 osdx ulogd[120927]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33
May 26 10:19:59.208043 osdx ulogd[120927]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 LABELS=TEST
May 26 10:19:59.208063 osdx ulogd[120927]: [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.305 ms

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

Step 4: Ping IP address 192.168.100.1 from DUT1:

admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1
Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.236 ms

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

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

ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*VRF=RED
Show output
May 26 10:20:05.323870 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:05.325827 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:05.325869 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:05.333477 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:05.651349 osdx osdx-coredump[121117]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:05.659196 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:06.130516 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:06.210974 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
May 26 10:20:06.292518 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'.
May 26 10:20:06.343277 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system vrf RED'.
May 26 10:20:06.444783 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:06.500328 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:06.621027 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:06.690741 osdx INFO[121140]: FRR daemons did not change
May 26 10:20:06.707470 osdx (udev-worker)[121156]: RED: Could not disable auto negotiation, ignoring: Operation not supported
May 26 10:20:06.707767 osdx (udev-worker)[121156]: Network interface NamePolicy= disabled on kernel command line.
May 26 10:20:06.729842 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:06.805832 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:06.906131 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:06.908087 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:06.908604 osdx ulogd[121262]: registering plugin `NFCT'
May 26 10:20:06.908735 osdx ulogd[121262]: registering plugin `IP2STR'
May 26 10:20:06.908858 osdx ulogd[121262]: registering plugin `PRINTFLOW'
May 26 10:20:06.909025 osdx ulogd[121262]: registering plugin `SYSLOG'
May 26 10:20:06.909036 osdx ulogd[121262]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:06.909183 osdx ulogd[121262]: NFCT plugin working in event mode
May 26 10:20:06.909203 osdx ulogd[121262]: Changing UID / GID
May 26 10:20:06.909401 osdx ulogd[121262]: initialization finished, entering main loop
May 26 10:20:06.912722 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:06.944890 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:06.962607 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:07.799710 osdx ulogd[121262]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:07.799729 osdx ulogd[121262]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:07.895821 osdx ulogd[121262]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:07.895844 osdx ulogd[121262]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0

Not-Bypass logging

Description

Set a simple configuration with a firewall service, send a ping command from one device to other and check that default and bypass fields appear when running system journal show.

Scenario

Step 1: Set the following configuration in DUT0 :

set interfaces ethernet eth1 address 10.215.168.64/24
set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'

Step 2: Ping IP address 10.215.168.1 from DUT0:

admin@DUT0$ ping 10.215.168.1 count 1 size 56 timeout 1
Show output
PING 10.215.168.1 (10.215.168.1) 56(84) bytes of data.
64 bytes from 10.215.168.1: icmp_seq=1 ttl=64 time=0.181 ms

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

Step 3: Run command file copy http://10.215.168.1/~robot/test-performance.rules running:// force at DUT0 and expect this output:

Show output
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   129  100   129    0     0  24956      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.480 ms

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

Step 7: Ping IP address 192.168.100.1 from DUT1:

admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1
Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.344 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.344/0.344/0.344/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
May 26 10:20:12.307731 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:12.309050 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:12.309094 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:12.320116 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:12.640980 osdx osdx-coredump[121467]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:12.648448 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:13.138247 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:13.212129 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
May 26 10:20:13.307103 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:13.371319 osdx INFO[121486]: FRR daemons did not change
May 26 10:20:13.389053 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
May 26 10:20:13.462926 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:13.489411 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:13.508281 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:13.663286 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
May 26 10:20:13.796610 osdx file_operation[121581]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
May 26 10:20:13.821487 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
May 26 10:20:13.965384 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:14.035766 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
May 26 10:20:14.118279 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
May 26 10:20:14.173532 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'.
May 26 10:20:14.274233 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
May 26 10:20:14.332976 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
May 26 10:20:14.432436 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
May 26 10:20:14.491082 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
May 26 10:20:14.592288 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
May 26 10:20:14.650125 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
May 26 10:20:14.746929 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:14.798988 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:14.939152 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:15.040612 osdx INFO[121626]: FRR daemons did not change
May 26 10:20:15.065058 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:15.173381 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:15.173904 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:20:15.177076 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:15.177300 osdx ulogd[121695]: registering plugin `NFCT'
May 26 10:20:15.177338 osdx ulogd[121695]: registering plugin `IP2STR'
May 26 10:20:15.177376 osdx ulogd[121695]: registering plugin `PRINTFLOW'
May 26 10:20:15.177414 osdx ulogd[121695]: registering plugin `SYSLOG'
May 26 10:20:15.177418 osdx ulogd[121695]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:15.177455 osdx ulogd[121695]: NFCT plugin working in event mode
May 26 10:20:15.177461 osdx ulogd[121695]: Changing UID / GID
May 26 10:20:15.177522 osdx ulogd[121695]: initialization finished, entering main loop
May 26 10:20:15.442749 osdx systemd[1]: Reloading.
May 26 10:20:15.557059 osdx systemd-sysv-generator[121732]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
May 26 10:20:15.681692 osdx systemd[1]: Starting logrotate.service - Rotate log files...
May 26 10:20:15.687596 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata.
May 26 10:20:15.688764 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
May 26 10:20:15.705039 osdx systemd[1]: logrotate.service: Deactivated successfully.
May 26 10:20:15.705147 osdx systemd[1]: Finished logrotate.service - Rotate log files.
May 26 10:20:15.950553 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
May 26 10:20:16.197266 osdx INFO[121714]: Rules successfully loaded
May 26 10:20:16.211339 osdx ulogd[121695]: Terminal signal received, exiting
May 26 10:20:16.211421 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:16.211639 osdx systemd[1]: ulogd2.service: Deactivated successfully.
May 26 10:20:16.211725 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:16.225355 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:16.226056 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:20:16.226573 osdx ulogd[121760]: registering plugin `NFCT'
May 26 10:20:16.226611 osdx ulogd[121760]: registering plugin `IP2STR'
May 26 10:20:16.226645 osdx ulogd[121760]: registering plugin `PRINTFLOW'
May 26 10:20:16.226682 osdx ulogd[121760]: registering plugin `SYSLOG'
May 26 10:20:16.226686 osdx ulogd[121760]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:16.226723 osdx ulogd[121760]: NFCT plugin working in event mode
May 26 10:20:16.226729 osdx ulogd[121760]: Changing UID / GID
May 26 10:20:16.226795 osdx ulogd[121760]: initialization finished, entering main loop
May 26 10:20:16.233094 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:16.235031 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:16.268527 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:16.287973 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:17.139959 osdx ulogd[121760]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass)
May 26 10:20:17.139980 osdx ulogd[121760]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass)
May 26 10:20:17.223896 osdx ulogd[121760]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass)
May 26 10:20:17.223918 osdx ulogd[121760]: [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.368 ms

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

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

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

Step 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.2.5

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

Last login: Mon May 26 10:18:04 2025 from 10.215.168.64
admin@osdx$

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

ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*\[OFFLOAD\]
Show output
May 26 10:20:24.333788 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:24.335404 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:24.335454 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:24.344191 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:24.673479 osdx osdx-coredump[121977]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:24.680974 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:25.153829 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:25.236682 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
May 26 10:20:25.307148 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:25.392663 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:25.481788 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:25.598414 osdx INFO[122000]: FRR daemons did not change
May 26 10:20:25.623410 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
May 26 10:20:25.699413 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:25.799842 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:25.801305 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:25.802555 osdx ulogd[122122]: registering plugin `NFCT'
May 26 10:20:25.802641 osdx ulogd[122122]: registering plugin `IP2STR'
May 26 10:20:25.802728 osdx ulogd[122122]: registering plugin `PRINTFLOW'
May 26 10:20:25.802806 osdx ulogd[122122]: registering plugin `SYSLOG'
May 26 10:20:25.802813 osdx ulogd[122122]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:25.802901 osdx ulogd[122122]: NFCT plugin working in event mode
May 26 10:20:25.802913 osdx ulogd[122122]: Changing UID / GID
May 26 10:20:25.803025 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:25.803039 osdx ulogd[122122]: initialization finished, entering main loop
May 26 10:20:25.833222 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:25.851254 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:27.597164 osdx ulogd[122122]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:27.597183 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:27.674861 osdx ulogd[122122]: [NEW] ORIG: SRC=192.168.200.2 DST=192.168.200.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.1 DST=192.168.200.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:27.674879 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.200.2 DST=192.168.200.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.1 DST=192.168.200.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
May 26 10:20:27.748697 osdx ulogd[122122]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 PKTS=0 BYTES=0
May 26 10:20:27.748911 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 PKTS=0 BYTES=0
May 26 10:20:27.748974 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 PKTS=0 BYTES=0 [OFFLOAD]
May 26 10:20:28.023751 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 PKTS=0 BYTES=0
May 26 10:20:28.023776 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 PKTS=0 BYTES=0 [OFFLOAD]
May 26 10:20:28.025612 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 PKTS=0 BYTES=0
May 26 10:20:28.025768 osdx ulogd[122122]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=44214 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=44214 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.392 ms

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

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2050ms
rtt min/avg/max/mdev = 0.253/0.322/0.406/0.063 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
May 26 10:20:32.293922 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:32.296305 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:32.296356 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:32.303317 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:32.631684 osdx osdx-coredump[122277]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:32.639154 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:33.099762 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:33.213680 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
May 26 10:20:33.289493 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
May 26 10:20:33.414725 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:33.472321 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:33.599739 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:33.674831 osdx INFO[122299]: FRR daemons did not change
May 26 10:20:33.844302 osdx kernel: app-detect: module init
May 26 10:20:33.844348 osdx kernel: app-detect: registered: sysctl net.appdetect
May 26 10:20:33.844358 osdx kernel: app-detect: expression init
May 26 10:20:33.844365 osdx kernel: app-detect: appid cache initialized
May 26 10:20:33.844376 osdx kernel: app-detect: appid cache changes counter initialized
May 26 10:20:33.847125 osdx modulelauncher[122302]: AppDetect: no change in application dictionaries, thus nothing more to do
May 26 10:20:33.872306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:33.964578 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:33.965217 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:20:33.965527 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:33.966628 osdx ulogd[122391]: registering plugin `NFCT'
May 26 10:20:33.966667 osdx ulogd[122391]: registering plugin `IP2STR'
May 26 10:20:33.966702 osdx ulogd[122391]: registering plugin `PRINTFLOW'
May 26 10:20:33.966741 osdx ulogd[122391]: registering plugin `SYSLOG'
May 26 10:20:33.966746 osdx ulogd[122391]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:33.966788 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:33.966789 osdx ulogd[122391]: NFCT plugin working in event mode
May 26 10:20:33.966795 osdx ulogd[122391]: Changing UID / GID
May 26 10:20:33.966857 osdx ulogd[122391]: initialization finished, entering main loop
May 26 10:20:33.998736 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:34.019155 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:34.888087 osdx ulogd[122391]: [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]
May 26 10:20:34.888113 osdx ulogd[122391]: [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]
May 26 10:20:34.972641 osdx ulogd[122391]: [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]
May 26 10:20:34.972666 osdx ulogd[122391]: [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]
May 26 10:20:35.998635 osdx ulogd[122391]: [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]
May 26 10:20:35.998661 osdx ulogd[122391]: [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]
May 26 10:20:35.998677 osdx ulogd[122391]: [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]
May 26 10:20:37.022544 osdx ulogd[122391]: [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]
May 26 10:20:37.022563 osdx ulogd[122391]: [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]
May 26 10:20:37.022575 osdx ulogd[122391]: [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
May 26 10:20:32.293922 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:32.296305 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:32.296356 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:32.303317 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:32.631684 osdx osdx-coredump[122277]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:32.639154 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:33.099762 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:33.213680 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
May 26 10:20:33.289493 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
May 26 10:20:33.414725 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:33.472321 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:33.599739 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:33.674831 osdx INFO[122299]: FRR daemons did not change
May 26 10:20:33.844302 osdx kernel: app-detect: module init
May 26 10:20:33.844348 osdx kernel: app-detect: registered: sysctl net.appdetect
May 26 10:20:33.844358 osdx kernel: app-detect: expression init
May 26 10:20:33.844365 osdx kernel: app-detect: appid cache initialized
May 26 10:20:33.844376 osdx kernel: app-detect: appid cache changes counter initialized
May 26 10:20:33.847125 osdx modulelauncher[122302]: AppDetect: no change in application dictionaries, thus nothing more to do
May 26 10:20:33.872306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:33.964578 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:33.965217 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:20:33.965527 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:33.966628 osdx ulogd[122391]: registering plugin `NFCT'
May 26 10:20:33.966667 osdx ulogd[122391]: registering plugin `IP2STR'
May 26 10:20:33.966702 osdx ulogd[122391]: registering plugin `PRINTFLOW'
May 26 10:20:33.966741 osdx ulogd[122391]: registering plugin `SYSLOG'
May 26 10:20:33.966746 osdx ulogd[122391]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:33.966788 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:33.966789 osdx ulogd[122391]: NFCT plugin working in event mode
May 26 10:20:33.966795 osdx ulogd[122391]: Changing UID / GID
May 26 10:20:33.966857 osdx ulogd[122391]: initialization finished, entering main loop
May 26 10:20:33.998736 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:34.019155 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:34.888087 osdx ulogd[122391]: [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]
May 26 10:20:34.888113 osdx ulogd[122391]: [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]
May 26 10:20:34.972641 osdx ulogd[122391]: [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]
May 26 10:20:34.972666 osdx ulogd[122391]: [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]
May 26 10:20:35.998635 osdx ulogd[122391]: [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]
May 26 10:20:35.998661 osdx ulogd[122391]: [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]
May 26 10:20:35.998677 osdx ulogd[122391]: [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]
May 26 10:20:37.022544 osdx ulogd[122391]: [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]
May 26 10:20:37.022563 osdx ulogd[122391]: [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]
May 26 10:20:37.022575 osdx ulogd[122391]: [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]
May 26 10:20:37.122395 osdx OSDxCLI[114644]: 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
May 26 10:20:32.293922 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:32.296305 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:32.296356 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:32.303317 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:32.631684 osdx osdx-coredump[122277]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:32.639154 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:33.099762 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:33.213680 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
May 26 10:20:33.289493 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
May 26 10:20:33.414725 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:33.472321 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:33.599739 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:33.674831 osdx INFO[122299]: FRR daemons did not change
May 26 10:20:33.844302 osdx kernel: app-detect: module init
May 26 10:20:33.844348 osdx kernel: app-detect: registered: sysctl net.appdetect
May 26 10:20:33.844358 osdx kernel: app-detect: expression init
May 26 10:20:33.844365 osdx kernel: app-detect: appid cache initialized
May 26 10:20:33.844376 osdx kernel: app-detect: appid cache changes counter initialized
May 26 10:20:33.847125 osdx modulelauncher[122302]: AppDetect: no change in application dictionaries, thus nothing more to do
May 26 10:20:33.872306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:33.964578 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:33.965217 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:20:33.965527 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:33.966628 osdx ulogd[122391]: registering plugin `NFCT'
May 26 10:20:33.966667 osdx ulogd[122391]: registering plugin `IP2STR'
May 26 10:20:33.966702 osdx ulogd[122391]: registering plugin `PRINTFLOW'
May 26 10:20:33.966741 osdx ulogd[122391]: registering plugin `SYSLOG'
May 26 10:20:33.966746 osdx ulogd[122391]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:33.966788 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:33.966789 osdx ulogd[122391]: NFCT plugin working in event mode
May 26 10:20:33.966795 osdx ulogd[122391]: Changing UID / GID
May 26 10:20:33.966857 osdx ulogd[122391]: initialization finished, entering main loop
May 26 10:20:33.998736 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:34.019155 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:34.888087 osdx ulogd[122391]: [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]
May 26 10:20:34.888113 osdx ulogd[122391]: [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]
May 26 10:20:34.972641 osdx ulogd[122391]: [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]
May 26 10:20:34.972666 osdx ulogd[122391]: [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]
May 26 10:20:35.998635 osdx ulogd[122391]: [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]
May 26 10:20:35.998661 osdx ulogd[122391]: [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]
May 26 10:20:35.998677 osdx ulogd[122391]: [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]
May 26 10:20:37.022544 osdx ulogd[122391]: [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]
May 26 10:20:37.022563 osdx ulogd[122391]: [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]
May 26 10:20:37.022575 osdx ulogd[122391]: [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]
May 26 10:20:37.122395 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal show | cat'.
May 26 10:20:37.271518 osdx OSDxCLI[114644]: 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.272 ms

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

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

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

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
May 26 10:20:32.293922 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.2M free.
May 26 10:20:32.296305 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:32.296356 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:32.303317 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:32.631684 osdx osdx-coredump[122277]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:32.639154 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:33.099762 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:33.213680 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
May 26 10:20:33.289493 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
May 26 10:20:33.414725 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
May 26 10:20:33.472321 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
May 26 10:20:33.599739 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:33.674831 osdx INFO[122299]: FRR daemons did not change
May 26 10:20:33.844302 osdx kernel: app-detect: module init
May 26 10:20:33.844348 osdx kernel: app-detect: registered: sysctl net.appdetect
May 26 10:20:33.844358 osdx kernel: app-detect: expression init
May 26 10:20:33.844365 osdx kernel: app-detect: appid cache initialized
May 26 10:20:33.844376 osdx kernel: app-detect: appid cache changes counter initialized
May 26 10:20:33.847125 osdx modulelauncher[122302]: AppDetect: no change in application dictionaries, thus nothing more to do
May 26 10:20:33.872306 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0
May 26 10:20:33.964578 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
May 26 10:20:33.965217 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
May 26 10:20:33.965527 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
May 26 10:20:33.966628 osdx ulogd[122391]: registering plugin `NFCT'
May 26 10:20:33.966667 osdx ulogd[122391]: registering plugin `IP2STR'
May 26 10:20:33.966702 osdx ulogd[122391]: registering plugin `PRINTFLOW'
May 26 10:20:33.966741 osdx ulogd[122391]: registering plugin `SYSLOG'
May 26 10:20:33.966746 osdx ulogd[122391]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
May 26 10:20:33.966788 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:33.966789 osdx ulogd[122391]: NFCT plugin working in event mode
May 26 10:20:33.966795 osdx ulogd[122391]: Changing UID / GID
May 26 10:20:33.966857 osdx ulogd[122391]: initialization finished, entering main loop
May 26 10:20:33.998736 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:34.019155 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:34.888087 osdx ulogd[122391]: [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]
May 26 10:20:34.888113 osdx ulogd[122391]: [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]
May 26 10:20:34.972641 osdx ulogd[122391]: [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]
May 26 10:20:34.972666 osdx ulogd[122391]: [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]
May 26 10:20:35.998635 osdx ulogd[122391]: [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]
May 26 10:20:35.998661 osdx ulogd[122391]: [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]
May 26 10:20:35.998677 osdx ulogd[122391]: [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]
May 26 10:20:37.022544 osdx ulogd[122391]: [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]
May 26 10:20:37.022563 osdx ulogd[122391]: [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]
May 26 10:20:37.022575 osdx ulogd[122391]: [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]
May 26 10:20:37.122395 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal show | cat'.
May 26 10:20:37.271518 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal show | cat'.
May 26 10:20:37.388617 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal show | cat'.
May 26 10:20:37.560570 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:37.635820 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
May 26 10:20:37.717647 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
May 26 10:20:37.784810 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show changes'.
May 26 10:20:37.886931 osdx INFO[122444]: FRR daemons did not change
May 26 10:20:37.940306 osdx kernel: app-detect: expression destroy
May 26 10:20:37.976310 osdx kernel: app-detect: expression init
May 26 10:20:37.976371 osdx kernel: app-detect: appid cache initialized
May 26 10:20:37.976389 osdx kernel: app-detect: appid cache changes counter initialized
May 26 10:20:37.982012 osdx modulelauncher[122447]: AppDetect: no change in application dictionaries, thus nothing more to do
May 26 10:20:38.004305 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
May 26 10:20:38.080152 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:38.113478 osdx ulogd[122391]: [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]
May 26 10:20:38.113496 osdx ulogd[122391]: [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]
May 26 10:20:38.114086 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:38.130304 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:38.280069 osdx ulogd[122391]: [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]
May 26 10:20:38.280315 osdx ulogd[122391]: [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]
May 26 10:20:38.281615 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
May 26 10:20:38.413732 osdx file_operation[122552]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
May 26 10:20:38.416274 osdx ulogd[122391]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=41522 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=41522 PKTS=0 BYTES=0 APPDETECT[L4:80]
May 26 10:20:38.416461 osdx ulogd[122391]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=41522 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=41522 PKTS=0 BYTES=0 APPDETECT[L4:80]
May 26 10:20:38.416477 osdx ulogd[122391]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=41522 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=41522 PKTS=0 BYTES=0 APPDETECT[L4:80]
May 26 10:20:38.417350 osdx ulogd[122391]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=41522 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=41522 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
May 26 10:20:38.417470 osdx ulogd[122391]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=41522 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=41522 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
May 26 10:20:38.417486 osdx ulogd[122391]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=41522 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=41522 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
May 26 10:20:38.433982 osdx OSDxCLI[114644]: 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.208 ms

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

Step 3: Run command 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
May 26 10:20:43.302442 osdx systemd-journald[1942]: Runtime Journal (/run/log/journal/88574923f45f44e5afdfd869586bf8bf) is 2.0M, max 15.3M, 13.3M free.
May 26 10:20:43.306437 osdx systemd-journald[1942]: Received client request to rotate journal, rotating.
May 26 10:20:43.306491 osdx systemd-journald[1942]: Vacuuming done, freed 0B of archived journals from /run/log/journal/88574923f45f44e5afdfd869586bf8bf.
May 26 10:20:43.312080 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system journal clear'.
May 26 10:20:43.652441 osdx osdx-coredump[122704]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
May 26 10:20:43.660221 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'system coredump delete all'.
May 26 10:20:44.142146 osdx OSDxCLI[114644]: User 'admin' entered the configuration menu.
May 26 10:20:44.225411 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'.
May 26 10:20:44.309040 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'.
May 26 10:20:44.370387 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'.
May 26 10:20:44.504494 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'.
May 26 10:20:44.576662 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'.
May 26 10:20:44.666178 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'.
May 26 10:20:44.722400 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'.
May 26 10:20:44.843338 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'.
May 26 10:20:44.897938 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
May 26 10:20:44.994406 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
May 26 10:20:45.070259 osdx OSDxCLI[114644]: User 'admin' added a new cfg line: 'show working'.
May 26 10:20:45.214077 osdx INFO[122746]: FRR daemons did not change
May 26 10:20:45.390436 osdx kernel: app-detect: module init
May 26 10:20:45.390484 osdx kernel: app-detect: registered: sysctl net.appdetect
May 26 10:20:45.390498 osdx kernel: app-detect: expression init
May 26 10:20:45.390510 osdx kernel: app-detect: appid cache initialized
May 26 10:20:45.390526 osdx kernel: app-detect: appid cache changes counter initialized
May 26 10:20:45.434470 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1
May 26 10:20:45.695416 osdx cfgd[1647]: [114644]Completed change to active configuration
May 26 10:20:45.726222 osdx OSDxCLI[114644]: User 'admin' committed the configuration.
May 26 10:20:45.743898 osdx OSDxCLI[114644]: User 'admin' left the configuration menu.
May 26 10:20:45.899780 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
May 26 10:20:46.024519 osdx file_operation[122892]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
May 26 10:20:46.030436 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=17635 DF PROTO=TCP SPT=59840 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
May 26 10:20:46.234444 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=17636 DF PROTO=TCP SPT=59840 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
May 26 10:20:46.650487 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=17637 DF PROTO=TCP SPT=59840 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
May 26 10:20:47.482476 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=17638 DF PROTO=TCP SPT=59840 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
May 26 10:20:49.035324 osdx file_operation.py[122892]: Operation aborted by user.
May 26 10:20:49.046437 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=17639 DF PROTO=TCP SPT=59840 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
May 26 10:20:49.051292 osdx OSDxCLI[114644]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.
May 26 10:20:49.114502 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=17640 DF PROTO=TCP SPT=59840 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]