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 1Show 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 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.226 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.226/0.226/0.226/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[NEW\].*SRC=192.168.100.2Show output
Nov 25 12:52:49.352382 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:52:49.355669 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:52:49.355722 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:52:49.363893 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:52:49.602076 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:52:49.915210 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:52:49.993024 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:52:50.081928 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. Nov 25 12:52:50.154643 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:52:50.254870 osdx ubnt-cfgd[480817]: inactive Nov 25 12:52:50.275022 osdx INFO[480825]: FRR daemons did not change Nov 25 12:52:50.299698 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:52:50.387969 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:52:50.390566 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:52:50.393290 osdx ulogd[480916]: registering plugin `NFCT' Nov 25 12:52:50.394291 osdx ulogd[480916]: registering plugin `IP2STR' Nov 25 12:52:50.394383 osdx ulogd[480916]: registering plugin `PRINTFLOW' Nov 25 12:52:50.395429 osdx ulogd[480916]: registering plugin `SYSLOG' Nov 25 12:52:50.395463 osdx ulogd[480916]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:52:50.395529 osdx ulogd[480916]: NFCT plugin working in event mode Nov 25 12:52:50.395561 osdx ulogd[480916]: Changing UID / GID Nov 25 12:52:50.395648 osdx ulogd[480916]: initialization finished, entering main loop Nov 25 12:52:50.407718 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:52:50.409272 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:52:50.421228 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:52:50.442638 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:52:51.357588 osdx ulogd[480916]: [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 Nov 25 12:52:51.432943 osdx ulogd[480916]: [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 1Show 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.333 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.333/0.333/0.333/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 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.226 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.226/0.226/0.226/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[UPDATE\].*SRC=192.168.100.2Show output
Nov 25 12:52:55.297918 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:52:55.300468 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:52:55.300523 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:52:55.308094 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:52:55.510835 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:52:55.731300 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:52:55.807062 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:52:55.891044 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. Nov 25 12:52:55.956339 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:52:56.052461 osdx ubnt-cfgd[481099]: inactive Nov 25 12:52:56.074485 osdx INFO[481107]: FRR daemons did not change Nov 25 12:52:56.096523 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:52:56.188822 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:52:56.189826 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:52:56.190363 osdx ulogd[481198]: registering plugin `NFCT' Nov 25 12:52:56.190556 osdx ulogd[481198]: registering plugin `IP2STR' Nov 25 12:52:56.190623 osdx ulogd[481198]: registering plugin `PRINTFLOW' Nov 25 12:52:56.190688 osdx ulogd[481198]: registering plugin `SYSLOG' Nov 25 12:52:56.190714 osdx ulogd[481198]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:52:56.190779 osdx ulogd[481198]: NFCT plugin working in event mode Nov 25 12:52:56.190809 osdx ulogd[481198]: Changing UID / GID Nov 25 12:52:56.190902 osdx ulogd[481198]: initialization finished, entering main loop Nov 25 12:52:56.196493 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:52:56.197645 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:52:56.208514 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:52:56.224442 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:52:57.062884 osdx ulogd[481198]: [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 Nov 25 12:52:57.153575 osdx ulogd[481198]: [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 1Show 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.322 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.322/0.322/0.322/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 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.235 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.266 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.243 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2036ms rtt min/avg/max/mdev = 0.235/0.248/0.266/0.013 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.2Show output
Nov 25 12:53:01.328126 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:01.329127 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:01.329180 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:01.340395 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:01.561842 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:01.798546 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:01.912290 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:02.011316 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. Nov 25 12:53:02.091875 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Nov 25 12:53:02.180390 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service ssh'. Nov 25 12:53:02.250402 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:02.351846 osdx ubnt-cfgd[481384]: inactive Nov 25 12:53:02.378796 osdx INFO[481398]: FRR daemons did not change Nov 25 12:53:02.409125 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:02.489456 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:02.490386 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:02.490723 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:02.491761 osdx ulogd[481491]: registering plugin `NFCT' Nov 25 12:53:02.492003 osdx ulogd[481491]: registering plugin `IP2STR' Nov 25 12:53:02.492923 osdx ulogd[481491]: registering plugin `PRINTFLOW' Nov 25 12:53:02.493074 osdx ulogd[481491]: registering plugin `SYSLOG' Nov 25 12:53:02.493127 osdx ulogd[481491]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:02.493220 osdx ulogd[481491]: NFCT plugin working in event mode Nov 25 12:53:02.493263 osdx ulogd[481491]: Changing UID / GID Nov 25 12:53:02.493403 osdx ulogd[481491]: initialization finished, entering main loop Nov 25 12:53:02.545930 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Nov 25 12:53:02.558242 osdx sshd[481497]: Server listening on 0.0.0.0 port 22. Nov 25 12:53:02.558461 osdx sshd[481497]: Server listening on :: port 22. Nov 25 12:53:02.558665 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Nov 25 12:53:02.584221 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:02.598765 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:02.631407 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:04.631544 osdx ulogd[481491]: [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 Nov 25 12:53:05.129215 osdx ulogd[481491]: [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 Nov 25 12:53:05.655453 osdx ulogd[481491]: [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 1Show 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.293 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.293/0.293/0.293/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 1Show 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)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Nov 25 12:53:13.429227 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:13.432884 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:13.432947 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:13.440878 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:13.665148 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:13.894489 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:13.980400 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:14.088777 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:14.169729 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:14.267839 osdx ubnt-cfgd[481704]: inactive Nov 25 12:53:14.287274 osdx INFO[481712]: FRR daemons did not change Nov 25 12:53:14.308885 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:14.401198 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:14.402252 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:14.404915 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:14.405156 osdx ulogd[481803]: registering plugin `NFCT' Nov 25 12:53:14.405369 osdx ulogd[481803]: registering plugin `IP2STR' Nov 25 12:53:14.405446 osdx ulogd[481803]: registering plugin `PRINTFLOW' Nov 25 12:53:14.405511 osdx ulogd[481803]: registering plugin `SYSLOG' Nov 25 12:53:14.405532 osdx ulogd[481803]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:14.405598 osdx ulogd[481803]: NFCT plugin working in event mode Nov 25 12:53:14.405627 osdx ulogd[481803]: Changing UID / GID Nov 25 12:53:14.405712 osdx ulogd[481803]: initialization finished, entering main loop Nov 25 12:53:14.407253 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:14.421337 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:14.444243 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:15.281846 osdx ulogd[481803]: [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 Nov 25 12:53:15.281878 osdx ulogd[481803]: [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 Nov 25 12:53:15.369694 osdx ulogd[481803]: [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 Nov 25 12:53:15.369711 osdx ulogd[481803]: [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 1Show 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 1Show 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.270 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.270/0.270/0.270/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.2Show output
Nov 25 12:53:19.000174 osdx systemd-timedated[479355]: Changed local time to Tue 2025-11-25 12:53:19 UTC Nov 25 12:53:19.001483 osdx systemd-journald[1857]: Time jumped backwards, rotating. Nov 25 12:53:19.002241 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'set date 2025-11-25 12:53:19'. Nov 25 12:53:19.345031 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:19.345467 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:19.345504 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:19.355177 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:19.587634 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:19.894533 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:19.989407 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:20.093889 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:20.164081 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. Nov 25 12:53:20.275945 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:20.339338 osdx ubnt-cfgd[481986]: inactive Nov 25 12:53:20.358857 osdx INFO[481994]: FRR daemons did not change Nov 25 12:53:20.381510 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:20.469759 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:20.470663 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:20.471207 osdx ulogd[482085]: registering plugin `NFCT' Nov 25 12:53:20.471393 osdx ulogd[482085]: registering plugin `IP2STR' Nov 25 12:53:20.471463 osdx ulogd[482085]: registering plugin `PRINTFLOW' Nov 25 12:53:20.471533 osdx ulogd[482085]: registering plugin `SYSLOG' Nov 25 12:53:20.471561 osdx ulogd[482085]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:20.471627 osdx ulogd[482085]: NFCT plugin working in event mode Nov 25 12:53:20.471661 osdx OSDx_DUT0[482085]: Changing UID / GID Nov 25 12:53:20.471749 osdx OSDx_DUT0[482085]: initialization finished, entering main loop Nov 25 12:53:20.477504 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:20.478818 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:20.490676 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:20.507150 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:21.339143 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.339164 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.422399 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.422421 osdx OSDx_DUT0[482085]: [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 1Show 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 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.2Show output
Nov 25 12:53:19.000174 osdx systemd-timedated[479355]: Changed local time to Tue 2025-11-25 12:53:19 UTC Nov 25 12:53:19.001483 osdx systemd-journald[1857]: Time jumped backwards, rotating. Nov 25 12:53:19.002241 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'set date 2025-11-25 12:53:19'. Nov 25 12:53:19.345031 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:19.345467 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:19.345504 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:19.355177 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:19.587634 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:19.894533 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:19.989407 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:20.093889 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:20.164081 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. Nov 25 12:53:20.275945 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:20.339338 osdx ubnt-cfgd[481986]: inactive Nov 25 12:53:20.358857 osdx INFO[481994]: FRR daemons did not change Nov 25 12:53:20.381510 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:20.469759 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:20.470663 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:20.471207 osdx ulogd[482085]: registering plugin `NFCT' Nov 25 12:53:20.471393 osdx ulogd[482085]: registering plugin `IP2STR' Nov 25 12:53:20.471463 osdx ulogd[482085]: registering plugin `PRINTFLOW' Nov 25 12:53:20.471533 osdx ulogd[482085]: registering plugin `SYSLOG' Nov 25 12:53:20.471561 osdx ulogd[482085]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:20.471627 osdx ulogd[482085]: NFCT plugin working in event mode Nov 25 12:53:20.471661 osdx OSDx_DUT0[482085]: Changing UID / GID Nov 25 12:53:20.471749 osdx OSDx_DUT0[482085]: initialization finished, entering main loop Nov 25 12:53:20.477504 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:20.478818 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:20.490676 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:20.507150 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:21.339143 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.339164 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.422399 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.422421 osdx OSDx_DUT0[482085]: [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 Nov 25 12:53:21.591207 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal show | cat'. Nov 25 12:53:21.743094 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:21.809140 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'. Nov 25 12:53:21.903127 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show changes'. Nov 25 12:53:21.965979 osdx ubnt-cfgd[482121]: inactive Nov 25 12:53:21.982435 osdx INFO[482127]: FRR daemons did not change Nov 25 12:53:21.992097 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:21.992247 osdx OSDx_DUT0[482085]: Terminal signal received, exiting Nov 25 12:53:21.992531 osdx systemd[1]: ulogd2.service: Deactivated successfully. Nov 25 12:53:21.992619 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:22.017832 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:22.018518 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:22.019248 osdx ulogd[482136]: registering plugin `NFCT' Nov 25 12:53:22.019293 osdx ulogd[482136]: registering plugin `IP2STR' Nov 25 12:53:22.019338 osdx ulogd[482136]: registering plugin `PRINTFLOW' Nov 25 12:53:22.019389 osdx ulogd[482136]: registering plugin `SYSLOG' Nov 25 12:53:22.019393 osdx ulogd[482136]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:22.019442 osdx ulogd[482136]: NFCT plugin working in event mode Nov 25 12:53:22.019450 osdx ulogd[482136]: Changing UID / GID Nov 25 12:53:22.019536 osdx ulogd[482136]: initialization finished, entering main loop Nov 25 12:53:22.020041 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:22.021286 osdx ulogd[482136]: [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 Nov 25 12:53:22.021334 osdx ulogd[482136]: [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 Nov 25 12:53:22.021848 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:22.042115 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:22.189980 osdx ulogd[482136]: [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 Nov 25 12:53:22.190003 osdx ulogd[482136]: [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 1Show 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.325 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.325/0.325/0.325/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 1Show 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.224 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.247 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1021ms rtt min/avg/max/mdev = 0.224/0.235/0.247/0.011 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=TESTShow output
Nov 25 12:53:26.306822 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:26.310637 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:26.310696 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:26.317399 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:26.585338 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:26.908600 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:26.997979 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Nov 25 12:53:27.090342 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic label TEST'. Nov 25 12:53:27.154523 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. Nov 25 12:53:27.290614 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. Nov 25 12:53:27.407393 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:27.498657 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:27.576266 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:27.721280 osdx ubnt-cfgd[482297]: inactive Nov 25 12:53:27.754663 osdx INFO[482311]: FRR daemons did not change Nov 25 12:53:27.778663 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:27.874971 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:27.876029 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:27.876547 osdx ulogd[482402]: registering plugin `NFCT' Nov 25 12:53:27.876740 osdx ulogd[482402]: registering plugin `IP2STR' Nov 25 12:53:27.876813 osdx ulogd[482402]: registering plugin `PRINTFLOW' Nov 25 12:53:27.876882 osdx ulogd[482402]: registering plugin `SYSLOG' Nov 25 12:53:27.876911 osdx ulogd[482402]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:27.876975 osdx ulogd[482402]: NFCT plugin working in event mode Nov 25 12:53:27.877003 osdx ulogd[482402]: Changing UID / GID Nov 25 12:53:27.877097 osdx ulogd[482402]: initialization finished, entering main loop Nov 25 12:53:27.890686 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:27.901107 osdx ulogd[482402]: Terminal signal received, exiting Nov 25 12:53:27.901163 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:27.901663 osdx systemd[1]: ulogd2.service: Deactivated successfully. Nov 25 12:53:27.901759 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:27.902662 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:27.903522 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:27.904061 osdx ulogd[482408]: registering plugin `NFCT' Nov 25 12:53:27.904239 osdx ulogd[482408]: registering plugin `IP2STR' Nov 25 12:53:27.904304 osdx ulogd[482408]: registering plugin `PRINTFLOW' Nov 25 12:53:27.904374 osdx ulogd[482408]: registering plugin `SYSLOG' Nov 25 12:53:27.904399 osdx ulogd[482408]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:27.904463 osdx ulogd[482408]: NFCT plugin working in event mode Nov 25 12:53:27.904491 osdx ulogd[482408]: Changing UID / GID Nov 25 12:53:27.904571 osdx ulogd[482408]: initialization finished, entering main loop Nov 25 12:53:27.918735 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:28.111531 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:28.123315 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:28.143109 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:28.954280 osdx ulogd[482408]: [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 Nov 25 12:53:28.954301 osdx ulogd[482408]: [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 Nov 25 12:53:29.035516 osdx ulogd[482408]: [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 Nov 25 12:53:29.035533 osdx ulogd[482408]: [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 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.342 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.342/0.342/0.342/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show 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.240 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.240/0.240/0.240/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=REDShow output
Nov 25 12:53:35.354060 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.9M, max 13.8M, 11.8M free. Nov 25 12:53:35.355080 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:35.355121 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:35.364436 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:35.574403 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:35.801530 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:35.885537 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. Nov 25 12:53:35.978670 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. Nov 25 12:53:36.032106 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system vrf RED'. Nov 25 12:53:36.134752 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:36.199168 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:36.299784 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:36.363935 osdx ubnt-cfgd[482634]: inactive Nov 25 12:53:36.387160 osdx INFO[482642]: FRR daemons did not change Nov 25 12:53:36.397321 osdx (udev-worker)[482653]: RED: Could not disable auto negotiation, ignoring: Operation not supported Nov 25 12:53:36.397564 osdx (udev-worker)[482653]: Network interface NamePolicy= disabled on kernel command line. Nov 25 12:53:36.423087 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:36.471091 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:36.555408 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:36.556270 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:36.556470 osdx ulogd[482808]: registering plugin `NFCT' Nov 25 12:53:36.556698 osdx ulogd[482808]: registering plugin `IP2STR' Nov 25 12:53:36.556788 osdx ulogd[482808]: registering plugin `PRINTFLOW' Nov 25 12:53:36.556870 osdx ulogd[482808]: registering plugin `SYSLOG' Nov 25 12:53:36.556903 osdx ulogd[482808]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:36.556986 osdx ulogd[482808]: NFCT plugin working in event mode Nov 25 12:53:36.557024 osdx ulogd[482808]: Changing UID / GID Nov 25 12:53:36.557133 osdx ulogd[482808]: initialization finished, entering main loop Nov 25 12:53:36.557531 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:36.568338 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:36.616130 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:37.477509 osdx ulogd[482808]: [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 Nov 25 12:53:37.477532 osdx ulogd[482808]: [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 Nov 25 12:53:37.553567 osdx ulogd[482808]: [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 Nov 25 12:53:37.553587 osdx ulogd[482808]: [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 1Show 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.273 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.273/0.273/0.273/0.000 ms
Step 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 7054 0 --:--:-- --:--:-- --:--:-- 7166
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 1Show 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.405 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.405/0.405/0.405/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 1Show 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 8: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*Sc: not-bypassShow output
Nov 25 12:53:42.383285 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:42.387048 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:42.387104 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:42.394876 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:42.639420 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:42.878588 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:43.015663 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Nov 25 12:53:43.107838 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:43.200100 osdx ubnt-cfgd[483070]: inactive Nov 25 12:53:43.223748 osdx INFO[483078]: FRR daemons did not change Nov 25 12:53:43.247058 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Nov 25 12:53:43.294100 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:43.305113 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:43.322273 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:43.507479 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Nov 25 12:53:43.702449 osdx file_operation[483195]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// Nov 25 12:53:43.745419 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. Nov 25 12:53:43.914001 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:43.997826 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Nov 25 12:53:44.092236 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. Nov 25 12:53:44.150700 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'. Nov 25 12:53:44.247990 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. Nov 25 12:53:44.319077 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. Nov 25 12:53:44.377468 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. Nov 25 12:53:44.478770 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. Nov 25 12:53:44.537492 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. Nov 25 12:53:44.654801 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. Nov 25 12:53:44.729773 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:44.817583 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:44.909725 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:45.022897 osdx ubnt-cfgd[483229]: inactive Nov 25 12:53:45.059012 osdx INFO[483246]: FRR daemons did not change Nov 25 12:53:45.083053 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:45.163367 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:45.164110 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:45.164317 osdx ulogd[483337]: registering plugin `NFCT' Nov 25 12:53:45.164507 osdx ulogd[483337]: registering plugin `IP2STR' Nov 25 12:53:45.164572 osdx ulogd[483337]: registering plugin `PRINTFLOW' Nov 25 12:53:45.164640 osdx ulogd[483337]: registering plugin `SYSLOG' Nov 25 12:53:45.164678 osdx ulogd[483337]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:45.164746 osdx ulogd[483337]: NFCT plugin working in event mode Nov 25 12:53:45.164778 osdx ulogd[483337]: Changing UID / GID Nov 25 12:53:45.165740 osdx ulogd[483337]: initialization finished, entering main loop Nov 25 12:53:45.349309 osdx systemd[1]: Reloading. Nov 25 12:53:45.403049 osdx systemd-sysv-generator[483370]: stat() failed on /etc/init.d/README, ignoring: No such file or directory Nov 25 12:53:45.547508 osdx systemd[1]: Starting logrotate.service - Rotate log files... Nov 25 12:53:45.551183 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... Nov 25 12:53:45.571005 osdx systemd[1]: logrotate.service: Deactivated successfully. Nov 25 12:53:45.571122 osdx systemd[1]: Finished logrotate.service - Rotate log files. Nov 25 12:53:45.572834 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. Nov 25 12:53:45.906625 osdx INFO[483352]: Rules successfully loaded Nov 25 12:53:45.922884 osdx ulogd[483337]: Terminal signal received, exiting Nov 25 12:53:45.923125 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:45.923575 osdx systemd[1]: ulogd2.service: Deactivated successfully. Nov 25 12:53:45.923710 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:45.951500 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:45.952255 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:45.952492 osdx ulogd[483397]: registering plugin `NFCT' Nov 25 12:53:45.952698 osdx ulogd[483397]: registering plugin `IP2STR' Nov 25 12:53:45.952777 osdx ulogd[483397]: registering plugin `PRINTFLOW' Nov 25 12:53:45.952855 osdx ulogd[483397]: registering plugin `SYSLOG' Nov 25 12:53:45.952884 osdx ulogd[483397]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:45.952950 osdx ulogd[483397]: NFCT plugin working in event mode Nov 25 12:53:45.952981 osdx ulogd[483397]: Changing UID / GID Nov 25 12:53:45.953091 osdx ulogd[483397]: initialization finished, entering main loop Nov 25 12:53:45.953975 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:45.968498 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:45.991398 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:46.787081 osdx ulogd[483397]: [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) Nov 25 12:53:46.787098 osdx ulogd[483397]: [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) Nov 25 12:53:46.863322 osdx ulogd[483397]: [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) Nov 25 12:53:46.863344 osdx ulogd[483397]: [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 1Show 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.295 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.295/0.295/0.295/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 1Show 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.346 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.346/0.346/0.346/0.000 ms
Step 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/nullShow output
Warning: Permanently added '192.168.200.2' (ECDSA) to the list of known hosts. admin@192.168.200.2's password: Welcome to Teldat OSDx v4.2.4.8 This system includes free software. Contact Teldat for licenses information and source code. Last login: Tue Nov 25 12:52:24 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
Nov 25 12:53:53.326255 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:53:53.326848 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:53:53.326890 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:53:53.339453 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:53:53.575843 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:53:53.880401 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:53:53.994143 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. Nov 25 12:53:54.079818 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:53:54.136378 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:53:54.246334 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:53:54.308129 osdx ubnt-cfgd[483673]: inactive Nov 25 12:53:54.332221 osdx INFO[483683]: FRR daemons did not change Nov 25 12:53:54.354692 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Nov 25 12:53:54.418688 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:53:54.519053 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:53:54.519637 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:53:54.520130 osdx ulogd[483849]: registering plugin `NFCT' Nov 25 12:53:54.520168 osdx ulogd[483849]: registering plugin `IP2STR' Nov 25 12:53:54.520205 osdx ulogd[483849]: registering plugin `PRINTFLOW' Nov 25 12:53:54.520248 osdx ulogd[483849]: registering plugin `SYSLOG' Nov 25 12:53:54.520251 osdx ulogd[483849]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:53:54.520290 osdx ulogd[483849]: NFCT plugin working in event mode Nov 25 12:53:54.520296 osdx ulogd[483849]: Changing UID / GID Nov 25 12:53:54.520361 osdx ulogd[483849]: initialization finished, entering main loop Nov 25 12:53:54.534723 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:53:54.535944 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:53:54.546935 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:53:54.601065 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:53:56.216917 osdx ulogd[483849]: [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 Nov 25 12:53:56.216933 osdx ulogd[483849]: [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 Nov 25 12:53:56.303348 osdx ulogd[483849]: [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 Nov 25 12:53:56.303368 osdx ulogd[483849]: [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 Nov 25 12:53:56.376760 osdx ulogd[483849]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 PKTS=0 BYTES=0 Nov 25 12:53:56.376938 osdx ulogd[483849]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 PKTS=0 BYTES=0 Nov 25 12:53:56.377094 osdx ulogd[483849]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 PKTS=0 BYTES=0 [OFFLOAD] Nov 25 12:53:56.645581 osdx ulogd[483849]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 PKTS=0 BYTES=0 Nov 25 12:53:56.645604 osdx ulogd[483849]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 PKTS=0 BYTES=0 [OFFLOAD] Nov 25 12:53:56.647179 osdx ulogd[483849]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 PKTS=0 BYTES=0 Nov 25 12:53:56.647337 osdx ulogd[483849]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=41682 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=41682 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 1Show 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 3 size 56 timeout 1Show 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.266 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.311 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.302 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2037ms rtt min/avg/max/mdev = 0.266/0.293/0.311/0.019 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[NEW\].*APPDETECT\[L3:1\]Show output
Nov 25 12:54:01.308272 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:54:01.310912 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:54:01.310961 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:54:01.317815 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:54:01.536854 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:54:01.810772 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:01.871010 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Nov 25 12:54:02.023441 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Nov 25 12:54:02.096278 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:54:02.206360 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:54:02.312182 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:54:02.403491 osdx ubnt-cfgd[484065]: inactive Nov 25 12:54:02.423791 osdx INFO[484073]: FRR daemons did not change Nov 25 12:54:02.578917 osdx kernel: app-detect: module init Nov 25 12:54:02.578966 osdx kernel: app-detect: registered: sysctl net.appdetect Nov 25 12:54:02.578976 osdx kernel: app-detect: expression init Nov 25 12:54:02.578988 osdx kernel: app-detect: appid cache initialized Nov 25 12:54:02.578996 osdx kernel: app-detect: appid cache changes counter initialized Nov 25 12:54:02.581968 osdx modulelauncher[484076]: AppDetect: no change in application dictionaries, thus nothing more to do Nov 25 12:54:02.606919 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:54:02.695255 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:54:02.696096 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:54:02.696191 osdx ulogd[484187]: registering plugin `NFCT' Nov 25 12:54:02.696232 osdx ulogd[484187]: registering plugin `IP2STR' Nov 25 12:54:02.696265 osdx ulogd[484187]: registering plugin `PRINTFLOW' Nov 25 12:54:02.696307 osdx ulogd[484187]: registering plugin `SYSLOG' Nov 25 12:54:02.696310 osdx ulogd[484187]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:54:02.696352 osdx ulogd[484187]: NFCT plugin working in event mode Nov 25 12:54:02.696358 osdx ulogd[484187]: Changing UID / GID Nov 25 12:54:02.696422 osdx ulogd[484187]: initialization finished, entering main loop Nov 25 12:54:02.697690 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:02.712473 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:02.729729 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:03.574699 osdx ulogd[484187]: [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] Nov 25 12:54:03.574716 osdx ulogd[484187]: [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] Nov 25 12:54:03.723830 osdx ulogd[484187]: [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] Nov 25 12:54:03.723853 osdx ulogd[484187]: [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] Nov 25 12:54:04.737359 osdx ulogd[484187]: [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] Nov 25 12:54:04.737381 osdx ulogd[484187]: [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] Nov 25 12:54:04.737397 osdx ulogd[484187]: [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] Nov 25 12:54:05.761332 osdx ulogd[484187]: [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] Nov 25 12:54:05.761348 osdx ulogd[484187]: [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] Nov 25 12:54:05.761360 osdx ulogd[484187]: [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
Nov 25 12:54:01.308272 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:54:01.310912 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:54:01.310961 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:54:01.317815 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:54:01.536854 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:54:01.810772 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:01.871010 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Nov 25 12:54:02.023441 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Nov 25 12:54:02.096278 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:54:02.206360 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:54:02.312182 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:54:02.403491 osdx ubnt-cfgd[484065]: inactive Nov 25 12:54:02.423791 osdx INFO[484073]: FRR daemons did not change Nov 25 12:54:02.578917 osdx kernel: app-detect: module init Nov 25 12:54:02.578966 osdx kernel: app-detect: registered: sysctl net.appdetect Nov 25 12:54:02.578976 osdx kernel: app-detect: expression init Nov 25 12:54:02.578988 osdx kernel: app-detect: appid cache initialized Nov 25 12:54:02.578996 osdx kernel: app-detect: appid cache changes counter initialized Nov 25 12:54:02.581968 osdx modulelauncher[484076]: AppDetect: no change in application dictionaries, thus nothing more to do Nov 25 12:54:02.606919 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:54:02.695255 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:54:02.696096 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:54:02.696191 osdx ulogd[484187]: registering plugin `NFCT' Nov 25 12:54:02.696232 osdx ulogd[484187]: registering plugin `IP2STR' Nov 25 12:54:02.696265 osdx ulogd[484187]: registering plugin `PRINTFLOW' Nov 25 12:54:02.696307 osdx ulogd[484187]: registering plugin `SYSLOG' Nov 25 12:54:02.696310 osdx ulogd[484187]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:54:02.696352 osdx ulogd[484187]: NFCT plugin working in event mode Nov 25 12:54:02.696358 osdx ulogd[484187]: Changing UID / GID Nov 25 12:54:02.696422 osdx ulogd[484187]: initialization finished, entering main loop Nov 25 12:54:02.697690 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:02.712473 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:02.729729 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:03.574699 osdx ulogd[484187]: [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] Nov 25 12:54:03.574716 osdx ulogd[484187]: [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] Nov 25 12:54:03.723830 osdx ulogd[484187]: [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] Nov 25 12:54:03.723853 osdx ulogd[484187]: [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] Nov 25 12:54:04.737359 osdx ulogd[484187]: [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] Nov 25 12:54:04.737381 osdx ulogd[484187]: [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] Nov 25 12:54:04.737397 osdx ulogd[484187]: [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] Nov 25 12:54:05.761332 osdx ulogd[484187]: [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] Nov 25 12:54:05.761348 osdx ulogd[484187]: [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] Nov 25 12:54:05.761360 osdx ulogd[484187]: [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] Nov 25 12:54:05.853397 osdx OSDxCLI[311836]: 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
Nov 25 12:54:01.308272 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:54:01.310912 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:54:01.310961 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:54:01.317815 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:54:01.536854 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:54:01.810772 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:01.871010 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Nov 25 12:54:02.023441 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Nov 25 12:54:02.096278 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:54:02.206360 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:54:02.312182 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:54:02.403491 osdx ubnt-cfgd[484065]: inactive Nov 25 12:54:02.423791 osdx INFO[484073]: FRR daemons did not change Nov 25 12:54:02.578917 osdx kernel: app-detect: module init Nov 25 12:54:02.578966 osdx kernel: app-detect: registered: sysctl net.appdetect Nov 25 12:54:02.578976 osdx kernel: app-detect: expression init Nov 25 12:54:02.578988 osdx kernel: app-detect: appid cache initialized Nov 25 12:54:02.578996 osdx kernel: app-detect: appid cache changes counter initialized Nov 25 12:54:02.581968 osdx modulelauncher[484076]: AppDetect: no change in application dictionaries, thus nothing more to do Nov 25 12:54:02.606919 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:54:02.695255 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:54:02.696096 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:54:02.696191 osdx ulogd[484187]: registering plugin `NFCT' Nov 25 12:54:02.696232 osdx ulogd[484187]: registering plugin `IP2STR' Nov 25 12:54:02.696265 osdx ulogd[484187]: registering plugin `PRINTFLOW' Nov 25 12:54:02.696307 osdx ulogd[484187]: registering plugin `SYSLOG' Nov 25 12:54:02.696310 osdx ulogd[484187]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:54:02.696352 osdx ulogd[484187]: NFCT plugin working in event mode Nov 25 12:54:02.696358 osdx ulogd[484187]: Changing UID / GID Nov 25 12:54:02.696422 osdx ulogd[484187]: initialization finished, entering main loop Nov 25 12:54:02.697690 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:02.712473 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:02.729729 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:03.574699 osdx ulogd[484187]: [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] Nov 25 12:54:03.574716 osdx ulogd[484187]: [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] Nov 25 12:54:03.723830 osdx ulogd[484187]: [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] Nov 25 12:54:03.723853 osdx ulogd[484187]: [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] Nov 25 12:54:04.737359 osdx ulogd[484187]: [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] Nov 25 12:54:04.737381 osdx ulogd[484187]: [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] Nov 25 12:54:04.737397 osdx ulogd[484187]: [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] Nov 25 12:54:05.761332 osdx ulogd[484187]: [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] Nov 25 12:54:05.761348 osdx ulogd[484187]: [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] Nov 25 12:54:05.761360 osdx ulogd[484187]: [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] Nov 25 12:54:05.853397 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal show | cat'. Nov 25 12:54:05.959984 osdx OSDxCLI[311836]: 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 1Show 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.237 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.237/0.237/0.237/0.000 ms
Step 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 4352 0 4352 0 0 122k 0 --:--:-- --:--:-- --:--:-- 125k
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
Nov 25 12:54:01.308272 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:54:01.310912 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:54:01.310961 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:54:01.317815 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:54:01.536854 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:54:01.810772 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:01.871010 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Nov 25 12:54:02.023441 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Nov 25 12:54:02.096278 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:54:02.206360 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:54:02.312182 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:54:02.403491 osdx ubnt-cfgd[484065]: inactive Nov 25 12:54:02.423791 osdx INFO[484073]: FRR daemons did not change Nov 25 12:54:02.578917 osdx kernel: app-detect: module init Nov 25 12:54:02.578966 osdx kernel: app-detect: registered: sysctl net.appdetect Nov 25 12:54:02.578976 osdx kernel: app-detect: expression init Nov 25 12:54:02.578988 osdx kernel: app-detect: appid cache initialized Nov 25 12:54:02.578996 osdx kernel: app-detect: appid cache changes counter initialized Nov 25 12:54:02.581968 osdx modulelauncher[484076]: AppDetect: no change in application dictionaries, thus nothing more to do Nov 25 12:54:02.606919 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:54:02.695255 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:54:02.696096 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:54:02.696191 osdx ulogd[484187]: registering plugin `NFCT' Nov 25 12:54:02.696232 osdx ulogd[484187]: registering plugin `IP2STR' Nov 25 12:54:02.696265 osdx ulogd[484187]: registering plugin `PRINTFLOW' Nov 25 12:54:02.696307 osdx ulogd[484187]: registering plugin `SYSLOG' Nov 25 12:54:02.696310 osdx ulogd[484187]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:54:02.696352 osdx ulogd[484187]: NFCT plugin working in event mode Nov 25 12:54:02.696358 osdx ulogd[484187]: Changing UID / GID Nov 25 12:54:02.696422 osdx ulogd[484187]: initialization finished, entering main loop Nov 25 12:54:02.697690 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:02.712473 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:02.729729 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:03.574699 osdx ulogd[484187]: [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] Nov 25 12:54:03.574716 osdx ulogd[484187]: [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] Nov 25 12:54:03.723830 osdx ulogd[484187]: [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] Nov 25 12:54:03.723853 osdx ulogd[484187]: [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] Nov 25 12:54:04.737359 osdx ulogd[484187]: [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] Nov 25 12:54:04.737381 osdx ulogd[484187]: [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] Nov 25 12:54:04.737397 osdx ulogd[484187]: [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] Nov 25 12:54:05.761332 osdx ulogd[484187]: [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] Nov 25 12:54:05.761348 osdx ulogd[484187]: [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] Nov 25 12:54:05.761360 osdx ulogd[484187]: [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] Nov 25 12:54:05.853397 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal show | cat'. Nov 25 12:54:05.959984 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal show | cat'. Nov 25 12:54:06.066927 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal show | cat'. Nov 25 12:54:06.223438 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:06.299640 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Nov 25 12:54:06.383973 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Nov 25 12:54:06.446863 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show changes'. Nov 25 12:54:06.549267 osdx ubnt-cfgd[484238]: inactive Nov 25 12:54:06.576680 osdx INFO[484246]: FRR daemons did not change Nov 25 12:54:06.630922 osdx kernel: app-detect: expression destroy Nov 25 12:54:06.638915 osdx kernel: app-detect: expression init Nov 25 12:54:06.638956 osdx kernel: app-detect: appid cache initialized Nov 25 12:54:06.638966 osdx kernel: app-detect: appid cache changes counter initialized Nov 25 12:54:06.643409 osdx modulelauncher[484249]: AppDetect: no change in application dictionaries, thus nothing more to do Nov 25 12:54:06.666919 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Nov 25 12:54:06.719961 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:06.730366 osdx ulogd[484187]: [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] Nov 25 12:54:06.730380 osdx ulogd[484187]: [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] Nov 25 12:54:06.731020 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:06.747564 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:06.918508 osdx ulogd[484187]: [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] Nov 25 12:54:06.918909 osdx ulogd[484187]: [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] Nov 25 12:54:06.920530 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Nov 25 12:54:07.058412 osdx file_operation[484376]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Nov 25 12:54:07.061148 osdx ulogd[484187]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=34228 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=34228 PKTS=0 BYTES=0 APPDETECT[L4:80] Nov 25 12:54:07.061386 osdx ulogd[484187]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=34228 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=34228 PKTS=0 BYTES=0 APPDETECT[L4:80] Nov 25 12:54:07.061416 osdx ulogd[484187]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=34228 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=34228 PKTS=0 BYTES=0 APPDETECT[L4:80] Nov 25 12:54:07.094351 osdx ulogd[484187]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=34228 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=34228 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Nov 25 12:54:07.094532 osdx ulogd[484187]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=34228 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=34228 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Nov 25 12:54:07.094557 osdx ulogd[484187]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=34228 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=34228 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Nov 25 12:54:07.114491 osdx OSDxCLI[311836]: 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 1Show 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.249 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.249/0.249/0.249/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
Nov 25 12:54:12.317755 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:54:12.321598 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:54:12.321660 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:54:12.328689 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:54:12.540720 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:54:12.778934 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:12.850610 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. Nov 25 12:54:12.945285 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. Nov 25 12:54:13.005513 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. Nov 25 12:54:13.102149 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. Nov 25 12:54:13.159252 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. Nov 25 12:54:13.257830 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. Nov 25 12:54:13.318245 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. Nov 25 12:54:13.439566 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. Nov 25 12:54:13.493811 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Nov 25 12:54:13.605611 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Nov 25 12:54:13.701124 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:54:13.813729 osdx ubnt-cfgd[484594]: inactive Nov 25 12:54:13.856225 osdx INFO[484616]: FRR daemons did not change Nov 25 12:54:14.025610 osdx kernel: app-detect: module init Nov 25 12:54:14.025672 osdx kernel: app-detect: registered: sysctl net.appdetect Nov 25 12:54:14.025686 osdx kernel: app-detect: expression init Nov 25 12:54:14.025698 osdx kernel: app-detect: appid cache initialized Nov 25 12:54:14.025710 osdx kernel: app-detect: appid cache changes counter initialized Nov 25 12:54:14.065615 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Nov 25 12:54:14.310869 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:14.324669 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:14.341224 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:14.493680 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Nov 25 12:54:14.643931 osdx file_operation[484784]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Nov 25 12:54:14.649602 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=62253 DF PROTO=TCP SPT=33422 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Nov 25 12:54:14.857605 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=62254 DF PROTO=TCP SPT=33422 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Nov 25 12:54:15.269676 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=62255 DF PROTO=TCP SPT=33422 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Nov 25 12:54:16.101655 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=62256 DF PROTO=TCP SPT=33422 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Nov 25 12:54:17.618071 osdx file_operation.py[484784]: Operation aborted by user. Nov 25 12:54:17.629759 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=62257 DF PROTO=TCP SPT=33422 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Nov 25 12:54:17.634378 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.
Identity Values
Description
Conntrack identity is able to contain any printed character but not spaces
Scenario
Step 1: Run command configure at DUT0 and expect this output:
Step 2: Run command set system conntrack logging identity "he||o w@rld!" at DUT0 and check if output contains the following tokens:
Identity name must be 92 characters or less and must contain printable characters except those defined as part of the space character classShow output
Identity name must be 92 characters or less and must contain printable characters except those defined as part of the space character class Value validation failed CLI Error: Command error
Step 3: 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 'he||o-w@rld!' set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 4: 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 5: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.378 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.378/0.378/0.378/0.000 ms
Step 6: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show 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.267 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.267/0.267/0.267/0.000 ms
Step 7: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
he||o-w@rld!\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Nov 25 12:54:22.325761 osdx systemd-journald[1857]: Runtime Journal (/run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32) is 1.8M, max 13.8M, 11.9M free. Nov 25 12:54:22.326372 osdx systemd-journald[1857]: Received client request to rotate journal, rotating. Nov 25 12:54:22.326415 osdx systemd-journald[1857]: Vacuuming done, freed 0B of archived journals from /run/log/journal/3dabd6c33b8e497d9fdbc41689ab0c32. Nov 25 12:54:22.339114 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system journal clear'. Nov 25 12:54:22.594813 osdx OSDxCLI[311836]: User 'admin' executed a new command: 'system coredump delete all'. Nov 25 12:54:22.853435 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:22.973707 osdx cfgd[1655]: [311836]Command output: Identity name must be 92 characters or less and must contain printable characters except those defined as part of the space character class Value validation failed Nov 25 12:54:22.974406 osdx OSDxCLI[311836]: User 'admin' entered an invalid command: 'set system conntrack logging identity "he||o w@rld!"'. Nov 25 12:54:23.041779 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:23.220548 osdx OSDxCLI[311836]: User 'admin' entered the configuration menu. Nov 25 12:54:23.303240 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Nov 25 12:54:23.378712 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Nov 25 12:54:23.439100 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'set system conntrack logging identity he||o-w@rld!'. Nov 25 12:54:23.568256 osdx OSDxCLI[311836]: User 'admin' added a new cfg line: 'show working'. Nov 25 12:54:23.629494 osdx ubnt-cfgd[484975]: inactive Nov 25 12:54:23.652467 osdx INFO[484983]: FRR daemons did not change Nov 25 12:54:23.674342 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Nov 25 12:54:23.762708 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Nov 25 12:54:23.763546 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Nov 25 12:54:23.763880 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Nov 25 12:54:23.763907 osdx ulogd[485074]: registering plugin `NFCT' Nov 25 12:54:23.763943 osdx ulogd[485074]: registering plugin `IP2STR' Nov 25 12:54:23.763978 osdx ulogd[485074]: registering plugin `PRINTFLOW' Nov 25 12:54:23.764014 osdx ulogd[485074]: registering plugin `SYSLOG' Nov 25 12:54:23.764018 osdx ulogd[485074]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Nov 25 12:54:23.764057 osdx ulogd[485074]: NFCT plugin working in event mode Nov 25 12:54:23.764063 osdx he||o-w@rld![485074]: Changing UID / GID Nov 25 12:54:23.764128 osdx he||o-w@rld![485074]: initialization finished, entering main loop Nov 25 12:54:23.765324 osdx cfgd[1655]: [311836]Completed change to active configuration Nov 25 12:54:23.776201 osdx OSDxCLI[311836]: User 'admin' committed the configuration. Nov 25 12:54:23.799091 osdx OSDxCLI[311836]: User 'admin' left the configuration menu. Nov 25 12:54:24.630534 osdx he||o-w@rld![485074]: [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 Nov 25 12:54:24.630552 osdx he||o-w@rld![485074]: [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 Nov 25 12:54:24.708347 osdx he||o-w@rld![485074]: [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 Nov 25 12:54:24.708368 osdx he||o-w@rld![485074]: [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