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.408 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.408/0.408/0.408/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.205 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.205/0.205/0.205/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
May 14 08:44:39.000191 osdx systemd-timedated[18678]: Changed local time to Wed 2025-05-14 08:44:39 UTC May 14 08:44:39.001396 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'set date 2025-05-14 08:44:39'. May 14 08:44:39.002678 osdx systemd-journald[1882]: Time jumped backwards, rotating. May 14 08:44:39.304945 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:44:39.306686 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:44:39.306749 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:44:39.314380 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:44:39.669287 osdx osdx-coredump[26042]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:44:39.679484 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:44:40.181969 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:44:40.305298 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:44:40.371867 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. May 14 08:44:40.496864 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:44:40.561700 osdx ubnt-cfgd[26062]: inactive May 14 08:44:40.584822 osdx INFO[26070]: FRR daemons did not change May 14 08:44:40.722963 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:44:40.726867 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:44:40.728257 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:44:40.730463 osdx ulogd[26161]: registering plugin `NFCT' May 14 08:44:40.731756 osdx ulogd[26161]: registering plugin `IP2STR' May 14 08:44:40.731895 osdx ulogd[26161]: registering plugin `PRINTFLOW' May 14 08:44:40.733269 osdx ulogd[26161]: registering plugin `SYSLOG' May 14 08:44:40.733319 osdx ulogd[26161]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:44:40.733414 osdx ulogd[26161]: NFCT plugin working in event mode May 14 08:44:40.733457 osdx ulogd[26161]: Changing UID / GID May 14 08:44:40.733578 osdx ulogd[26161]: initialization finished, entering main loop May 14 08:44:40.739015 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:44:40.756284 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:44:41.616522 osdx ulogd[26161]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:44:41.694084 osdx ulogd[26161]: [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.400 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.400/0.400/0.400/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.395 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.395/0.395/0.395/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
May 14 08:44:46.306336 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.1M, max 15.3M, 13.1M free. May 14 08:44:46.309671 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:44:46.309727 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:44:46.316282 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:44:46.658905 osdx osdx-coredump[26336]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:44:46.667123 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:44:47.179514 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:44:47.264669 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:44:47.349108 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. May 14 08:44:47.419783 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:44:47.527829 osdx ubnt-cfgd[26354]: inactive May 14 08:44:47.549072 osdx INFO[26362]: FRR daemons did not change May 14 08:44:47.686016 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:44:47.686796 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:44:47.686898 osdx ulogd[26453]: registering plugin `NFCT' May 14 08:44:47.687126 osdx ulogd[26453]: registering plugin `IP2STR' May 14 08:44:47.687224 osdx ulogd[26453]: registering plugin `PRINTFLOW' May 14 08:44:47.687307 osdx ulogd[26453]: registering plugin `SYSLOG' May 14 08:44:47.687349 osdx ulogd[26453]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:44:47.687427 osdx ulogd[26453]: NFCT plugin working in event mode May 14 08:44:47.687466 osdx ulogd[26453]: Changing UID / GID May 14 08:44:47.687937 osdx ulogd[26453]: initialization finished, entering main loop May 14 08:44:47.688322 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:44:47.701334 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:44:47.718852 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:44:48.535069 osdx ulogd[26453]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:44:48.621755 osdx ulogd[26453]: [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.369 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.369/0.369/0.369/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.231 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.248 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.451 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2050ms rtt min/avg/max/mdev = 0.231/0.310/0.451/0.099 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
May 14 08:44:53.333291 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.1M, max 15.3M, 13.2M free. May 14 08:44:53.336343 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:44:53.336405 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:44:53.343027 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:44:53.711125 osdx osdx-coredump[26627]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:44:53.721547 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:44:54.247545 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:44:54.351003 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:44:54.439894 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. May 14 08:44:54.526181 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 14 08:44:54.607282 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service ssh'. May 14 08:44:54.724436 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:44:54.799374 osdx ubnt-cfgd[26647]: inactive May 14 08:44:54.830832 osdx INFO[26661]: FRR daemons did not change May 14 08:44:54.968667 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:44:54.969420 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:44:54.969481 osdx ulogd[26754]: registering plugin `NFCT' May 14 08:44:54.969521 osdx ulogd[26754]: registering plugin `IP2STR' May 14 08:44:54.969556 osdx ulogd[26754]: registering plugin `PRINTFLOW' May 14 08:44:54.969594 osdx ulogd[26754]: registering plugin `SYSLOG' May 14 08:44:54.969597 osdx ulogd[26754]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:44:54.969636 osdx ulogd[26754]: NFCT plugin working in event mode May 14 08:44:54.969642 osdx ulogd[26754]: Changing UID / GID May 14 08:44:54.969704 osdx ulogd[26754]: initialization finished, entering main loop May 14 08:44:55.032725 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... May 14 08:44:55.046423 osdx sshd[26760]: Server listening on 0.0.0.0 port 22. May 14 08:44:55.046629 osdx sshd[26760]: Server listening on :: port 22. May 14 08:44:55.046738 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. May 14 08:44:55.067970 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:44:55.082909 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:44:55.100945 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:44:57.098608 osdx ulogd[26754]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 May 14 08:44:58.122773 osdx ulogd[26754]: [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.329 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.329/0.329/0.329/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.236 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.236/0.236/0.236/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
May 14 08:45:06.317977 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.3M free. May 14 08:45:06.320869 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:06.320925 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:06.328422 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:06.674441 osdx osdx-coredump[26961]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:06.682190 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:07.141045 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:07.232488 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:07.313703 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:07.388264 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:07.473199 osdx ubnt-cfgd[26979]: inactive May 14 08:45:07.497562 osdx INFO[26987]: FRR daemons did not change May 14 08:45:07.625176 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:07.625903 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:07.626457 osdx ulogd[27078]: registering plugin `NFCT' May 14 08:45:07.626624 osdx ulogd[27078]: registering plugin `IP2STR' May 14 08:45:07.626687 osdx ulogd[27078]: registering plugin `PRINTFLOW' May 14 08:45:07.626748 osdx ulogd[27078]: registering plugin `SYSLOG' May 14 08:45:07.626776 osdx ulogd[27078]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:07.626837 osdx ulogd[27078]: NFCT plugin working in event mode May 14 08:45:07.626876 osdx ulogd[27078]: Changing UID / GID May 14 08:45:07.626959 osdx ulogd[27078]: initialization finished, entering main loop May 14 08:45:07.632839 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:07.634038 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:07.645347 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:07.676069 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:08.626621 osdx ulogd[27078]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:08.626639 osdx ulogd[27078]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:08.707084 osdx ulogd[27078]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:08.707101 osdx ulogd[27078]: [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.406 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.406/0.406/0.406/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.268 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.268/0.268/0.268/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
May 14 08:45:13.561021 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.3M free. May 14 08:45:13.562806 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:13.562873 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:13.571079 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:13.929389 osdx osdx-coredump[27251]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:13.937379 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:14.409335 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:14.544636 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:14.597421 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:14.717129 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. May 14 08:45:14.831476 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:14.902575 osdx ubnt-cfgd[27270]: inactive May 14 08:45:14.925002 osdx INFO[27278]: FRR daemons did not change May 14 08:45:15.059120 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:15.059999 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:15.060581 osdx ulogd[27369]: registering plugin `NFCT' May 14 08:45:15.060788 osdx ulogd[27369]: registering plugin `IP2STR' May 14 08:45:15.060862 osdx ulogd[27369]: registering plugin `PRINTFLOW' May 14 08:45:15.060934 osdx ulogd[27369]: registering plugin `SYSLOG' May 14 08:45:15.060959 osdx ulogd[27369]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:15.061036 osdx ulogd[27369]: NFCT plugin working in event mode May 14 08:45:15.061067 osdx OSDx_DUT0[27369]: Changing UID / GID May 14 08:45:15.061159 osdx OSDx_DUT0[27369]: initialization finished, entering main loop May 14 08:45:15.078891 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:15.080427 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:15.093486 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:15.121475 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:15.978513 osdx OSDx_DUT0[27369]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:15.978535 osdx OSDx_DUT0[27369]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:16.093576 osdx OSDx_DUT0[27369]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:16.093598 osdx OSDx_DUT0[27369]: [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.272 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.272/0.272/0.272/0.000 ms
Step 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
May 14 08:45:13.561021 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.3M free. May 14 08:45:13.562806 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:13.562873 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:13.571079 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:13.929389 osdx osdx-coredump[27251]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:13.937379 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:14.409335 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:14.544636 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:14.597421 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:14.717129 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. May 14 08:45:14.831476 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:14.902575 osdx ubnt-cfgd[27270]: inactive May 14 08:45:14.925002 osdx INFO[27278]: FRR daemons did not change May 14 08:45:15.059120 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:15.059999 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:15.060581 osdx ulogd[27369]: registering plugin `NFCT' May 14 08:45:15.060788 osdx ulogd[27369]: registering plugin `IP2STR' May 14 08:45:15.060862 osdx ulogd[27369]: registering plugin `PRINTFLOW' May 14 08:45:15.060934 osdx ulogd[27369]: registering plugin `SYSLOG' May 14 08:45:15.060959 osdx ulogd[27369]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:15.061036 osdx ulogd[27369]: NFCT plugin working in event mode May 14 08:45:15.061067 osdx OSDx_DUT0[27369]: Changing UID / GID May 14 08:45:15.061159 osdx OSDx_DUT0[27369]: initialization finished, entering main loop May 14 08:45:15.078891 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:15.080427 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:15.093486 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:15.121475 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:15.978513 osdx OSDx_DUT0[27369]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:15.978535 osdx OSDx_DUT0[27369]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:16.093576 osdx OSDx_DUT0[27369]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:16.093598 osdx OSDx_DUT0[27369]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:16.238008 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal show | cat'. May 14 08:45:16.468897 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:16.536639 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'. May 14 08:45:16.649005 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show changes'. May 14 08:45:16.715647 osdx ubnt-cfgd[27405]: inactive May 14 08:45:16.731674 osdx INFO[27411]: FRR daemons did not change May 14 08:45:16.740567 osdx OSDx_DUT0[27369]: Terminal signal received, exiting May 14 08:45:16.740593 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:16.740983 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 14 08:45:16.741078 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:16.763230 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:16.764109 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:16.764941 osdx ulogd[27419]: registering plugin `NFCT' May 14 08:45:16.765219 osdx ulogd[27419]: registering plugin `IP2STR' May 14 08:45:16.765322 osdx ulogd[27419]: registering plugin `PRINTFLOW' May 14 08:45:16.765416 osdx ulogd[27419]: registering plugin `SYSLOG' May 14 08:45:16.765461 osdx ulogd[27419]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:16.765557 osdx ulogd[27419]: NFCT plugin working in event mode May 14 08:45:16.765602 osdx ulogd[27419]: Changing UID / GID May 14 08:45:16.765724 osdx ulogd[27419]: initialization finished, entering main loop May 14 08:45:16.782828 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:16.784262 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:16.785935 osdx ulogd[27419]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 May 14 08:45:16.785995 osdx ulogd[27419]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 May 14 08:45:16.786616 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:16.828240 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:16.988112 osdx ulogd[27419]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:16.988135 osdx ulogd[27419]: [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.366 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.366/0.366/0.366/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.248 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.294 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1016ms rtt min/avg/max/mdev = 0.248/0.271/0.294/0.023 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
May 14 08:45:21.339493 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.3M free. May 14 08:45:21.341514 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:21.341559 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:21.348698 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:21.687362 osdx osdx-coredump[27568]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:21.695355 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:22.203969 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:22.297791 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. May 14 08:45:22.399288 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic label TEST'. May 14 08:45:22.510711 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. May 14 08:45:22.614439 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. May 14 08:45:22.694326 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:22.803258 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:22.893115 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:22.994716 osdx ubnt-cfgd[27590]: inactive May 14 08:45:23.026404 osdx INFO[27604]: FRR daemons did not change May 14 08:45:23.145747 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:23.146897 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:23.147412 osdx ulogd[27695]: registering plugin `NFCT' May 14 08:45:23.147591 osdx ulogd[27695]: registering plugin `IP2STR' May 14 08:45:23.147657 osdx ulogd[27695]: registering plugin `PRINTFLOW' May 14 08:45:23.147725 osdx ulogd[27695]: registering plugin `SYSLOG' May 14 08:45:23.147750 osdx ulogd[27695]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:23.147811 osdx ulogd[27695]: NFCT plugin working in event mode May 14 08:45:23.147841 osdx ulogd[27695]: Changing UID / GID May 14 08:45:23.147922 osdx ulogd[27695]: initialization finished, entering main loop May 14 08:45:23.161556 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:23.172989 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:23.173100 osdx ulogd[27695]: Terminal signal received, exiting May 14 08:45:23.173378 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 14 08:45:23.173471 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:23.174329 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:23.174985 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:23.175516 osdx ulogd[27701]: registering plugin `NFCT' May 14 08:45:23.175567 osdx ulogd[27701]: registering plugin `IP2STR' May 14 08:45:23.175605 osdx ulogd[27701]: registering plugin `PRINTFLOW' May 14 08:45:23.175650 osdx ulogd[27701]: registering plugin `SYSLOG' May 14 08:45:23.175653 osdx ulogd[27701]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:23.175690 osdx ulogd[27701]: NFCT plugin working in event mode May 14 08:45:23.175700 osdx ulogd[27701]: Changing UID / GID May 14 08:45:23.175759 osdx ulogd[27701]: initialization finished, entering main loop May 14 08:45:23.189533 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:23.394592 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:23.405522 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:23.443985 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:24.262680 osdx ulogd[27701]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 LABELS=TEST May 14 08:45:24.262705 osdx ulogd[27701]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 May 14 08:45:24.351463 osdx ulogd[27701]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33 LABELS=TEST May 14 08:45:24.351486 osdx ulogd[27701]: [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.363 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.363/0.363/0.363/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.285 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.285/0.285/0.285/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
May 14 08:45:30.411914 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:30.414172 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:30.414251 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:30.421813 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:30.743567 osdx osdx-coredump[27916]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:30.751495 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:31.239049 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:31.315630 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. May 14 08:45:31.407924 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. May 14 08:45:31.459775 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system vrf RED'. May 14 08:45:31.560574 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:31.619325 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:31.724000 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:31.786550 osdx ubnt-cfgd[27937]: inactive May 14 08:45:31.809195 osdx INFO[27945]: FRR daemons did not change May 14 08:45:31.824583 osdx (udev-worker)[27958]: RED: Could not disable auto negotiation, ignoring: Operation not supported May 14 08:45:31.824862 osdx (udev-worker)[27958]: Network interface NamePolicy= disabled on kernel command line. May 14 08:45:31.986450 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:31.987197 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 14 08:45:31.987744 osdx ulogd[28111]: registering plugin `NFCT' May 14 08:45:31.987925 osdx ulogd[28111]: registering plugin `IP2STR' May 14 08:45:31.987987 osdx ulogd[28111]: registering plugin `PRINTFLOW' May 14 08:45:31.988056 osdx ulogd[28111]: registering plugin `SYSLOG' May 14 08:45:31.988080 osdx ulogd[28111]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:31.988141 osdx ulogd[28111]: NFCT plugin working in event mode May 14 08:45:31.988168 osdx ulogd[28111]: Changing UID / GID May 14 08:45:31.988255 osdx ulogd[28111]: initialization finished, entering main loop May 14 08:45:32.002223 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:32.003731 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:32.014936 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:32.031929 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:32.960032 osdx ulogd[28111]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:32.960055 osdx ulogd[28111]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:33.043553 osdx ulogd[28111]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 VRF=RED PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:33.043573 osdx ulogd[28111]: [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.195 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.195/0.195/0.195/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 17753 0 --:--:-- --:--:-- --:--:-- 18428
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.410 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.410/0.410/0.410/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.339 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.339/0.339/0.339/0.000 ms
Step 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
May 14 08:45:37.343954 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:37.347020 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:37.347081 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:37.354423 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:37.737656 osdx osdx-coredump[28366]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:37.745443 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:38.235597 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:38.352113 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 14 08:45:38.416523 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:38.535427 osdx ubnt-cfgd[28383]: inactive May 14 08:45:38.555643 osdx INFO[28391]: FRR daemons did not change May 14 08:45:38.634444 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:38.647514 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:38.664555 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:38.833434 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 14 08:45:39.005908 osdx file_operation[28508]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// May 14 08:45:39.033164 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. May 14 08:45:39.203298 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:39.285804 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. May 14 08:45:39.370704 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. May 14 08:45:39.424424 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'. May 14 08:45:39.535408 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. May 14 08:45:39.657596 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. May 14 08:45:39.754637 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. May 14 08:45:39.810254 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. May 14 08:45:39.925778 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. May 14 08:45:40.018357 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. May 14 08:45:40.086754 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:40.174533 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:40.266375 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:40.349882 osdx ubnt-cfgd[28542]: inactive May 14 08:45:40.408922 osdx INFO[28559]: FRR daemons did not change May 14 08:45:40.527305 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:40.528101 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:40.528338 osdx ulogd[28650]: registering plugin `NFCT' May 14 08:45:40.528573 osdx ulogd[28650]: registering plugin `IP2STR' May 14 08:45:40.528663 osdx ulogd[28650]: registering plugin `PRINTFLOW' May 14 08:45:40.528747 osdx ulogd[28650]: registering plugin `SYSLOG' May 14 08:45:40.528785 osdx ulogd[28650]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:40.528869 osdx ulogd[28650]: NFCT plugin working in event mode May 14 08:45:40.528911 osdx ulogd[28650]: Changing UID / GID May 14 08:45:40.529026 osdx ulogd[28650]: initialization finished, entering main loop May 14 08:45:40.800368 osdx systemd[1]: Reloading. May 14 08:45:40.915083 osdx systemd-sysv-generator[28687]: stat() failed on /etc/init.d/README, ignoring: No such file or directory May 14 08:45:41.035665 osdx systemd[1]: Starting logrotate.service - Rotate log files... May 14 08:45:41.049247 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata. May 14 08:45:41.052502 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... May 14 08:45:41.097114 osdx systemd[1]: logrotate.service: Deactivated successfully. May 14 08:45:41.097326 osdx systemd[1]: Finished logrotate.service - Rotate log files. May 14 08:45:41.362633 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. May 14 08:45:41.703158 osdx INFO[28670]: Rules successfully loaded May 14 08:45:41.715526 osdx ulogd[28650]: Terminal signal received, exiting May 14 08:45:41.715621 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:41.716149 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 14 08:45:41.716278 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:41.727520 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:41.728338 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:41.728524 osdx ulogd[28716]: registering plugin `NFCT' May 14 08:45:41.728726 osdx ulogd[28716]: registering plugin `IP2STR' May 14 08:45:41.728788 osdx ulogd[28716]: registering plugin `PRINTFLOW' May 14 08:45:41.728853 osdx ulogd[28716]: registering plugin `SYSLOG' May 14 08:45:41.728878 osdx ulogd[28716]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:41.728940 osdx ulogd[28716]: NFCT plugin working in event mode May 14 08:45:41.728967 osdx ulogd[28716]: Changing UID / GID May 14 08:45:41.729303 osdx ulogd[28716]: initialization finished, entering main loop May 14 08:45:41.730022 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:41.741266 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:41.759880 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:42.660412 osdx ulogd[28716]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass) May 14 08:45:42.660431 osdx ulogd[28716]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass) May 14 08:45:42.741968 osdx ulogd[28716]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 (Sc: not-bypass) May 14 08:45:42.741992 osdx ulogd[28716]: [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.375 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.375/0.375/0.375/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.317 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.317/0.317/0.317/0.000 ms
Step 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.3 This system includes free software. Contact Teldat for licenses information and source code. Last login: Wed May 14 08:23:05 2025 admin@osdx$
Step 7: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*\[OFFLOAD\]Show output
May 14 08:45:50.317412 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:50.318089 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:50.318126 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:50.326629 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:50.703711 osdx osdx-coredump[28983]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:50.712645 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:45:51.198924 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:45:51.280785 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. May 14 08:45:51.406404 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:45:51.464258 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:45:51.569548 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:45:51.637842 osdx ubnt-cfgd[29002]: inactive May 14 08:45:51.670658 osdx INFO[29012]: FRR daemons did not change May 14 08:45:51.866441 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:45:51.867784 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:45:51.868778 osdx ulogd[29178]: registering plugin `NFCT' May 14 08:45:51.868981 osdx ulogd[29178]: registering plugin `IP2STR' May 14 08:45:51.869047 osdx ulogd[29178]: registering plugin `PRINTFLOW' May 14 08:45:51.869127 osdx ulogd[29178]: registering plugin `SYSLOG' May 14 08:45:51.869160 osdx ulogd[29178]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:45:51.869221 osdx ulogd[29178]: NFCT plugin working in event mode May 14 08:45:51.869245 osdx ulogd[29178]: Changing UID / GID May 14 08:45:51.869315 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:45:51.869338 osdx ulogd[29178]: initialization finished, entering main loop May 14 08:45:51.880617 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:45:51.897494 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:45:53.622380 osdx ulogd[29178]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:53.622396 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:53.726486 osdx ulogd[29178]: [NEW] ORIG: SRC=192.168.200.2 DST=192.168.200.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.1 DST=192.168.200.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:53.726504 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.200.2 DST=192.168.200.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.1 DST=192.168.200.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 May 14 08:45:53.832398 osdx ulogd[29178]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 PKTS=0 BYTES=0 May 14 08:45:53.832554 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 PKTS=0 BYTES=0 May 14 08:45:53.832653 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 PKTS=0 BYTES=0 [OFFLOAD] May 14 08:45:54.112691 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 PKTS=0 BYTES=0 May 14 08:45:54.112708 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 PKTS=0 BYTES=0 [OFFLOAD] May 14 08:45:54.113967 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 PKTS=0 BYTES=0 May 14 08:45:54.114112 osdx ulogd[29178]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=33186 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=33186 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.329 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.329/0.329/0.329/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.270 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.332 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.263 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2052ms rtt min/avg/max/mdev = 0.263/0.288/0.332/0.031 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[NEW\].*APPDETECT\[L3:1\]Show output
May 14 08:45:59.298887 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:59.300611 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:59.300685 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:59.308123 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:59.635061 osdx osdx-coredump[29381]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:59.643395 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:46:00.122704 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:46:00.181763 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 14 08:46:00.296824 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 14 08:46:00.413569 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:46:00.465876 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:46:00.576809 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:46:00.644908 osdx ubnt-cfgd[29401]: inactive May 14 08:46:00.664273 osdx INFO[29409]: FRR daemons did not change May 14 08:46:00.832662 osdx kernel: app-detect: module init May 14 08:46:00.832714 osdx kernel: app-detect: registered: sysctl net.appdetect May 14 08:46:00.832727 osdx kernel: app-detect: expression init May 14 08:46:00.832739 osdx kernel: app-detect: appid cache initialized May 14 08:46:00.832750 osdx kernel: app-detect: appid cache changes counter initialized May 14 08:46:00.838948 osdx modulelauncher[29412]: AppDetect: no change in application dictionaries, thus nothing more to do May 14 08:46:00.968872 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:46:00.969802 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:46:00.970495 osdx ulogd[29523]: registering plugin `NFCT' May 14 08:46:00.970694 osdx ulogd[29523]: registering plugin `IP2STR' May 14 08:46:00.970763 osdx ulogd[29523]: registering plugin `PRINTFLOW' May 14 08:46:00.970835 osdx ulogd[29523]: registering plugin `SYSLOG' May 14 08:46:00.970864 osdx ulogd[29523]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:46:00.970914 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:46:00.970925 osdx ulogd[29523]: NFCT plugin working in event mode May 14 08:46:00.970932 osdx ulogd[29523]: Changing UID / GID May 14 08:46:00.970998 osdx ulogd[29523]: initialization finished, entering main loop May 14 08:46:00.981554 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:46:01.024176 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:46:01.957104 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:01.957123 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038423 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038440 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066890 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:03.066911 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066925 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090857 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:04.090874 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090886 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1]
Step 6: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[UPDATE\].*APPDETECT\[L3:1\]Show output
May 14 08:45:59.298887 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:59.300611 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:59.300685 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:59.308123 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:59.635061 osdx osdx-coredump[29381]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:59.643395 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:46:00.122704 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:46:00.181763 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 14 08:46:00.296824 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 14 08:46:00.413569 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:46:00.465876 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:46:00.576809 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:46:00.644908 osdx ubnt-cfgd[29401]: inactive May 14 08:46:00.664273 osdx INFO[29409]: FRR daemons did not change May 14 08:46:00.832662 osdx kernel: app-detect: module init May 14 08:46:00.832714 osdx kernel: app-detect: registered: sysctl net.appdetect May 14 08:46:00.832727 osdx kernel: app-detect: expression init May 14 08:46:00.832739 osdx kernel: app-detect: appid cache initialized May 14 08:46:00.832750 osdx kernel: app-detect: appid cache changes counter initialized May 14 08:46:00.838948 osdx modulelauncher[29412]: AppDetect: no change in application dictionaries, thus nothing more to do May 14 08:46:00.968872 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:46:00.969802 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:46:00.970495 osdx ulogd[29523]: registering plugin `NFCT' May 14 08:46:00.970694 osdx ulogd[29523]: registering plugin `IP2STR' May 14 08:46:00.970763 osdx ulogd[29523]: registering plugin `PRINTFLOW' May 14 08:46:00.970835 osdx ulogd[29523]: registering plugin `SYSLOG' May 14 08:46:00.970864 osdx ulogd[29523]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:46:00.970914 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:46:00.970925 osdx ulogd[29523]: NFCT plugin working in event mode May 14 08:46:00.970932 osdx ulogd[29523]: Changing UID / GID May 14 08:46:00.970998 osdx ulogd[29523]: initialization finished, entering main loop May 14 08:46:00.981554 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:46:01.024176 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:46:01.957104 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:01.957123 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038423 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038440 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066890 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:03.066911 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066925 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090857 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:04.090874 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090886 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.180333 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal show | cat'.
Step 7: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[DESTROY\].*APPDETECT\[L3:1\]Show output
May 14 08:45:59.298887 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:59.300611 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:59.300685 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:59.308123 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:59.635061 osdx osdx-coredump[29381]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:59.643395 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:46:00.122704 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:46:00.181763 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 14 08:46:00.296824 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 14 08:46:00.413569 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:46:00.465876 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:46:00.576809 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:46:00.644908 osdx ubnt-cfgd[29401]: inactive May 14 08:46:00.664273 osdx INFO[29409]: FRR daemons did not change May 14 08:46:00.832662 osdx kernel: app-detect: module init May 14 08:46:00.832714 osdx kernel: app-detect: registered: sysctl net.appdetect May 14 08:46:00.832727 osdx kernel: app-detect: expression init May 14 08:46:00.832739 osdx kernel: app-detect: appid cache initialized May 14 08:46:00.832750 osdx kernel: app-detect: appid cache changes counter initialized May 14 08:46:00.838948 osdx modulelauncher[29412]: AppDetect: no change in application dictionaries, thus nothing more to do May 14 08:46:00.968872 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:46:00.969802 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:46:00.970495 osdx ulogd[29523]: registering plugin `NFCT' May 14 08:46:00.970694 osdx ulogd[29523]: registering plugin `IP2STR' May 14 08:46:00.970763 osdx ulogd[29523]: registering plugin `PRINTFLOW' May 14 08:46:00.970835 osdx ulogd[29523]: registering plugin `SYSLOG' May 14 08:46:00.970864 osdx ulogd[29523]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:46:00.970914 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:46:00.970925 osdx ulogd[29523]: NFCT plugin working in event mode May 14 08:46:00.970932 osdx ulogd[29523]: Changing UID / GID May 14 08:46:00.970998 osdx ulogd[29523]: initialization finished, entering main loop May 14 08:46:00.981554 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:46:01.024176 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:46:01.957104 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:01.957123 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038423 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038440 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066890 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:03.066911 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066925 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090857 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:04.090874 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090886 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.180333 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal show | cat'. May 14 08:46:04.278681 osdx OSDxCLI[13216]: 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.210 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.210/0.210/0.210/0.000 ms
Step 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 972 0 972 0 0 31082 0 --:--:-- --:--:-- --:--:-- 31354
Step 11: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*APPDETECT\[L4:80 http-host:10.215.168.1\]Show output
May 14 08:45:59.298887 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.2M free. May 14 08:45:59.300611 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:45:59.300685 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:45:59.308123 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:45:59.635061 osdx osdx-coredump[29381]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:45:59.643395 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:46:00.122704 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:46:00.181763 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 14 08:46:00.296824 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 14 08:46:00.413569 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 14 08:46:00.465876 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 14 08:46:00.576809 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:46:00.644908 osdx ubnt-cfgd[29401]: inactive May 14 08:46:00.664273 osdx INFO[29409]: FRR daemons did not change May 14 08:46:00.832662 osdx kernel: app-detect: module init May 14 08:46:00.832714 osdx kernel: app-detect: registered: sysctl net.appdetect May 14 08:46:00.832727 osdx kernel: app-detect: expression init May 14 08:46:00.832739 osdx kernel: app-detect: appid cache initialized May 14 08:46:00.832750 osdx kernel: app-detect: appid cache changes counter initialized May 14 08:46:00.838948 osdx modulelauncher[29412]: AppDetect: no change in application dictionaries, thus nothing more to do May 14 08:46:00.968872 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 14 08:46:00.969802 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 14 08:46:00.970495 osdx ulogd[29523]: registering plugin `NFCT' May 14 08:46:00.970694 osdx ulogd[29523]: registering plugin `IP2STR' May 14 08:46:00.970763 osdx ulogd[29523]: registering plugin `PRINTFLOW' May 14 08:46:00.970835 osdx ulogd[29523]: registering plugin `SYSLOG' May 14 08:46:00.970864 osdx ulogd[29523]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 14 08:46:00.970914 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:46:00.970925 osdx ulogd[29523]: NFCT plugin working in event mode May 14 08:46:00.970932 osdx ulogd[29523]: Changing UID / GID May 14 08:46:00.970998 osdx ulogd[29523]: initialization finished, entering main loop May 14 08:46:00.981554 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:46:01.024176 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:46:01.957104 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:01.957123 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038423 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:02.038440 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066890 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:03.066911 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:03.066925 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090857 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:04.090874 osdx ulogd[29523]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.090886 osdx ulogd[29523]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:04.180333 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal show | cat'. May 14 08:46:04.278681 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal show | cat'. May 14 08:46:04.378997 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal show | cat'. May 14 08:46:04.532222 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:46:04.605895 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 14 08:46:04.688038 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. May 14 08:46:04.753363 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show changes'. May 14 08:46:04.858544 osdx ubnt-cfgd[29577]: inactive May 14 08:46:04.883965 osdx INFO[29585]: FRR daemons did not change May 14 08:46:04.920609 osdx kernel: app-detect: expression destroy May 14 08:46:04.928605 osdx kernel: app-detect: expression init May 14 08:46:04.928646 osdx kernel: app-detect: appid cache initialized May 14 08:46:04.928659 osdx kernel: app-detect: appid cache changes counter initialized May 14 08:46:04.932112 osdx modulelauncher[29588]: AppDetect: no change in application dictionaries, thus nothing more to do May 14 08:46:05.007713 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:46:05.018013 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:05.018035 osdx ulogd[29523]: [DESTROY] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=1 BYTES=84 APPDETECT[L3:1] May 14 08:46:05.018722 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:46:05.035453 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:46:05.182535 osdx ulogd[29523]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:05.182744 osdx ulogd[29523]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 APPDETECT[L3:1] May 14 08:46:05.184199 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 14 08:46:05.321630 osdx file_operation[29715]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html May 14 08:46:05.326585 osdx ulogd[29523]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=49834 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=49834 PKTS=0 BYTES=0 APPDETECT[L4:80] May 14 08:46:05.326829 osdx ulogd[29523]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=49834 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=49834 PKTS=0 BYTES=0 APPDETECT[L4:80] May 14 08:46:05.326841 osdx ulogd[29523]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=49834 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=49834 PKTS=0 BYTES=0 APPDETECT[L4:80] May 14 08:46:05.354963 osdx ulogd[29523]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=49834 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=49834 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] May 14 08:46:05.355107 osdx ulogd[29523]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=49834 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=49834 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] May 14 08:46:05.355119 osdx ulogd[29523]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=49834 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=49834 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] May 14 08:46:05.373016 osdx OSDxCLI[13216]: 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.195 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.195/0.195/0.195/0.000 ms
Step 3: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
osdx kernel:.*APPDETECT\[U:155 http-url:/~robot/ http-host:10.215.168.1\]Show output
May 14 08:46:10.346388 osdx systemd-journald[1882]: Runtime Journal (/run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac) is 2.0M, max 15.3M, 13.3M free. May 14 08:46:10.346968 osdx systemd-journald[1882]: Received client request to rotate journal, rotating. May 14 08:46:10.347009 osdx systemd-journald[1882]: Vacuuming done, freed 0B of archived journals from /run/log/journal/d54fa6ddd60f4e688f2f72800dcfecac. May 14 08:46:10.357442 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system journal clear'. May 14 08:46:10.741325 osdx osdx-coredump[29919]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 14 08:46:10.750609 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'system coredump delete all'. May 14 08:46:11.308840 osdx OSDxCLI[13216]: User 'admin' entered the configuration menu. May 14 08:46:11.440248 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. May 14 08:46:11.502364 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. May 14 08:46:11.624049 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. May 14 08:46:11.694824 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. May 14 08:46:11.809477 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. May 14 08:46:11.867100 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. May 14 08:46:11.971371 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. May 14 08:46:12.053596 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. May 14 08:46:12.143065 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 14 08:46:12.244312 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. May 14 08:46:12.357853 osdx OSDxCLI[13216]: User 'admin' added a new cfg line: 'show working'. May 14 08:46:12.444862 osdx ubnt-cfgd[29945]: inactive May 14 08:46:12.488208 osdx INFO[29967]: FRR daemons did not change May 14 08:46:12.666955 osdx kernel: app-detect: module init May 14 08:46:12.667016 osdx kernel: app-detect: registered: sysctl net.appdetect May 14 08:46:12.667029 osdx kernel: app-detect: expression init May 14 08:46:12.667040 osdx kernel: app-detect: appid cache initialized May 14 08:46:12.667051 osdx kernel: app-detect: appid cache changes counter initialized May 14 08:46:13.132287 osdx cfgd[1680]: [13216]Completed change to active configuration May 14 08:46:13.144895 osdx OSDxCLI[13216]: User 'admin' committed the configuration. May 14 08:46:13.181205 osdx OSDxCLI[13216]: User 'admin' left the configuration menu. May 14 08:46:13.368238 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 14 08:46:13.523920 osdx file_operation[30141]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html May 14 08:46:13.530971 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=27506 DF PROTO=TCP SPT=54106 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 14 08:46:13.734955 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=27507 DF PROTO=TCP SPT=54106 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 14 08:46:14.163003 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=27508 DF PROTO=TCP SPT=54106 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 14 08:46:14.995005 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=27509 DF PROTO=TCP SPT=54106 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 14 08:46:16.498393 osdx file_operation.py[30141]: Operation aborted by user. May 14 08:46:16.510958 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=27510 DF PROTO=TCP SPT=54106 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 14 08:46:16.513423 osdx OSDxCLI[13216]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.