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.362 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.362/0.362/0.362/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.230 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.230/0.230/0.230/0.000 ms
Step 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 13 14:59:27.343751 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 14:59:27.344228 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 14:59:27.344270 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 14:59:27.353140 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 14:59:27.718311 osdx osdx-coredump[156159]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 14:59:27.726870 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 14:59:28.227282 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 14:59:28.352960 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 14:59:28.423762 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. May 13 14:59:28.490498 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 14:59:28.586997 osdx ubnt-cfgd[156177]: inactive May 13 14:59:28.610868 osdx INFO[156185]: FRR daemons did not change May 13 14:59:28.636242 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 14:59:28.740858 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 14:59:28.744180 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 14:59:28.745823 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 14:59:28.748139 osdx ulogd[156276]: registering plugin `NFCT' May 13 14:59:28.749530 osdx ulogd[156276]: registering plugin `IP2STR' May 13 14:59:28.749704 osdx ulogd[156276]: registering plugin `PRINTFLOW' May 13 14:59:28.751148 osdx ulogd[156276]: registering plugin `SYSLOG' May 13 14:59:28.751228 osdx ulogd[156276]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 14:59:28.751331 osdx ulogd[156276]: NFCT plugin working in event mode May 13 14:59:28.751381 osdx ulogd[156276]: Changing UID / GID May 13 14:59:28.751523 osdx ulogd[156276]: initialization finished, entering main loop May 13 14:59:28.760516 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 14:59:28.778108 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 14:59:29.645296 osdx ulogd[156276]: [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 13 14:59:29.728729 osdx ulogd[156276]: [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.344 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.344/0.344/0.344/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.241 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.241/0.241/0.241/0.000 ms
Step 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 13 14:59:34.318613 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 14:59:34.319834 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 14:59:34.319893 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 14:59:34.330117 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 14:59:34.685141 osdx osdx-coredump[156451]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 14:59:34.693368 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 14:59:35.208400 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 14:59:35.306608 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 14:59:35.401265 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. May 13 14:59:35.487645 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 14:59:35.591924 osdx ubnt-cfgd[156469]: inactive May 13 14:59:35.610280 osdx INFO[156477]: FRR daemons did not change May 13 14:59:35.635831 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 14:59:35.720089 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 14:59:35.721284 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 14:59:35.721751 osdx ulogd[156568]: registering plugin `NFCT' May 13 14:59:35.721992 osdx ulogd[156568]: registering plugin `IP2STR' May 13 14:59:35.722084 osdx ulogd[156568]: registering plugin `PRINTFLOW' May 13 14:59:35.722173 osdx ulogd[156568]: registering plugin `SYSLOG' May 13 14:59:35.722208 osdx ulogd[156568]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 14:59:35.722289 osdx ulogd[156568]: NFCT plugin working in event mode May 13 14:59:35.722330 osdx ulogd[156568]: Changing UID / GID May 13 14:59:35.722438 osdx ulogd[156568]: initialization finished, entering main loop May 13 14:59:35.724052 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 14:59:35.736410 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 14:59:35.752891 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 14:59:36.615229 osdx ulogd[156568]: [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 13 14:59:36.694730 osdx ulogd[156568]: [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.328 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.328/0.328/0.328/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.246 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.229 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.279 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2047ms rtt min/avg/max/mdev = 0.229/0.251/0.279/0.020 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 13 14:59:41.347529 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.3M free. May 13 14:59:41.348669 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 14:59:41.348728 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 14:59:41.359585 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 14:59:41.744474 osdx osdx-coredump[156745]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 14:59:41.753030 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 14:59:42.289464 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 14:59:42.371440 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 14:59:42.459926 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. May 13 14:59:42.525346 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 13 14:59:42.638452 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service ssh'. May 13 14:59:42.737939 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 14:59:42.859929 osdx ubnt-cfgd[156765]: inactive May 13 14:59:42.888090 osdx INFO[156779]: FRR daemons did not change May 13 14:59:42.920655 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 14:59:43.025003 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 14:59:43.026123 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 14:59:43.026290 osdx ulogd[156872]: registering plugin `NFCT' May 13 14:59:43.026526 osdx ulogd[156872]: registering plugin `IP2STR' May 13 14:59:43.026611 osdx ulogd[156872]: registering plugin `PRINTFLOW' May 13 14:59:43.026694 osdx ulogd[156872]: registering plugin `SYSLOG' May 13 14:59:43.026728 osdx ulogd[156872]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 14:59:43.026804 osdx ulogd[156872]: NFCT plugin working in event mode May 13 14:59:43.026844 osdx ulogd[156872]: Changing UID / GID May 13 14:59:43.026946 osdx ulogd[156872]: initialization finished, entering main loop May 13 14:59:43.076364 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... May 13 14:59:43.088028 osdx sshd[156878]: Server listening on 0.0.0.0 port 22. May 13 14:59:43.088216 osdx sshd[156878]: Server listening on :: port 22. May 13 14:59:43.088330 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. May 13 14:59:43.107986 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 14:59:43.120276 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 14:59:43.150862 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 14:59:45.110751 osdx ulogd[156872]: [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 13 14:59:46.134774 osdx ulogd[156872]: [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.468 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.468/0.468/0.468/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.251 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.251/0.251/0.251/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
May 13 14:59:54.307390 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.3M free. May 13 14:59:54.310999 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 14:59:54.311054 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 14:59:54.318555 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 14:59:54.657252 osdx osdx-coredump[157078]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 14:59:54.665211 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 14:59:55.184122 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 14:59:55.285070 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 14:59:55.396482 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 14:59:55.527146 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 14:59:55.625390 osdx ubnt-cfgd[157096]: inactive May 13 14:59:55.645307 osdx INFO[157104]: FRR daemons did not change May 13 14:59:55.671005 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 14:59:55.751290 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 14:59:55.752253 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 13 14:59:55.752704 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 14:59:55.753825 osdx ulogd[157195]: registering plugin `NFCT' May 13 14:59:55.754048 osdx ulogd[157195]: registering plugin `IP2STR' May 13 14:59:55.754133 osdx ulogd[157195]: registering plugin `PRINTFLOW' May 13 14:59:55.754206 osdx ulogd[157195]: registering plugin `SYSLOG' May 13 14:59:55.754232 osdx ulogd[157195]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 14:59:55.754300 osdx ulogd[157195]: NFCT plugin working in event mode May 13 14:59:55.754310 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 14:59:55.754450 osdx ulogd[157195]: Changing UID / GID May 13 14:59:55.754558 osdx ulogd[157195]: initialization finished, entering main loop May 13 14:59:55.769268 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 14:59:55.813467 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 14:59:56.842223 osdx ulogd[157195]: [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 13 14:59:56.842241 osdx ulogd[157195]: [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 13 14:59:57.100717 osdx ulogd[157195]: [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 13 14:59:57.100741 osdx ulogd[157195]: [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.336 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.336/0.336/0.336/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 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.249 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.249/0.249/0.249/0.000 ms
Step 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 13 15:00:01.340592 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.3M free. May 13 15:00:01.342623 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:01.342668 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:01.350499 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:01.695640 osdx osdx-coredump[157372]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:01.703361 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:02.197369 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:02.278473 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:02.359165 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:02.431378 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. May 13 15:00:02.504886 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:02.602249 osdx ubnt-cfgd[157396]: inactive May 13 15:00:02.621998 osdx INFO[157404]: FRR daemons did not change May 13 15:00:02.646616 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:02.727064 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:02.728136 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:02.728367 osdx ulogd[157495]: registering plugin `NFCT' May 13 15:00:02.728423 osdx ulogd[157495]: registering plugin `IP2STR' May 13 15:00:02.728473 osdx ulogd[157495]: registering plugin `PRINTFLOW' May 13 15:00:02.728533 osdx ulogd[157495]: registering plugin `SYSLOG' May 13 15:00:02.728537 osdx ulogd[157495]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:02.728594 osdx ulogd[157495]: NFCT plugin working in event mode May 13 15:00:02.728602 osdx OSDx_DUT0[157495]: Changing UID / GID May 13 15:00:02.728689 osdx OSDx_DUT0[157495]: initialization finished, entering main loop May 13 15:00:02.729566 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:02.741150 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:02.757593 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:03.634748 osdx OSDx_DUT0[157495]: [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 13 15:00:03.634768 osdx OSDx_DUT0[157495]: [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 13 15:00:03.730091 osdx OSDx_DUT0[157495]: [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 13 15:00:03.730108 osdx OSDx_DUT0[157495]: [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.245 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.245/0.245/0.245/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 13 15:00:01.340592 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.3M free. May 13 15:00:01.342623 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:01.342668 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:01.350499 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:01.695640 osdx osdx-coredump[157372]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:01.703361 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:02.197369 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:02.278473 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:02.359165 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:02.431378 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. May 13 15:00:02.504886 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:02.602249 osdx ubnt-cfgd[157396]: inactive May 13 15:00:02.621998 osdx INFO[157404]: FRR daemons did not change May 13 15:00:02.646616 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:02.727064 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:02.728136 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:02.728367 osdx ulogd[157495]: registering plugin `NFCT' May 13 15:00:02.728423 osdx ulogd[157495]: registering plugin `IP2STR' May 13 15:00:02.728473 osdx ulogd[157495]: registering plugin `PRINTFLOW' May 13 15:00:02.728533 osdx ulogd[157495]: registering plugin `SYSLOG' May 13 15:00:02.728537 osdx ulogd[157495]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:02.728594 osdx ulogd[157495]: NFCT plugin working in event mode May 13 15:00:02.728602 osdx OSDx_DUT0[157495]: Changing UID / GID May 13 15:00:02.728689 osdx OSDx_DUT0[157495]: initialization finished, entering main loop May 13 15:00:02.729566 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:02.741150 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:02.757593 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:03.634748 osdx OSDx_DUT0[157495]: [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 13 15:00:03.634768 osdx OSDx_DUT0[157495]: [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 13 15:00:03.730091 osdx OSDx_DUT0[157495]: [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 13 15:00:03.730108 osdx OSDx_DUT0[157495]: [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 13 15:00:03.821695 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal show | cat'. May 13 15:00:03.964769 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:04.024544 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'. May 13 15:00:04.141793 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show changes'. May 13 15:00:04.224651 osdx ubnt-cfgd[157531]: inactive May 13 15:00:04.244444 osdx INFO[157537]: FRR daemons did not change May 13 15:00:04.256616 osdx OSDx_DUT0[157495]: Terminal signal received, exiting May 13 15:00:04.256624 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:04.257077 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 13 15:00:04.257169 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:04.294949 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:04.296047 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:04.296207 osdx ulogd[157546]: registering plugin `NFCT' May 13 15:00:04.296421 osdx ulogd[157546]: registering plugin `IP2STR' May 13 15:00:04.296502 osdx ulogd[157546]: registering plugin `PRINTFLOW' May 13 15:00:04.296594 osdx ulogd[157546]: registering plugin `SYSLOG' May 13 15:00:04.296628 osdx ulogd[157546]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:04.296706 osdx ulogd[157546]: NFCT plugin working in event mode May 13 15:00:04.296743 osdx ulogd[157546]: Changing UID / GID May 13 15:00:04.296845 osdx ulogd[157546]: initialization finished, entering main loop May 13 15:00:04.297525 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:04.298823 osdx ulogd[157546]: [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 13 15:00:04.298905 osdx ulogd[157546]: [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 13 15:00:04.299489 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:04.323480 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:04.485682 osdx ulogd[157546]: [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 13 15:00:04.485837 osdx ulogd[157546]: [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.345 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.345/0.345/0.345/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 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.213 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.215 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1012ms rtt min/avg/max/mdev = 0.213/0.214/0.215/0.001 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 13 15:00:09.320334 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.3M free. May 13 15:00:09.323205 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:09.323252 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:09.330435 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:09.654762 osdx osdx-coredump[157697]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:09.662878 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:10.136295 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:10.221879 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. May 13 15:00:10.294840 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic label TEST'. May 13 15:00:10.359367 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. May 13 15:00:10.458548 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. May 13 15:00:10.514200 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:10.659902 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:10.733430 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:10.838072 osdx ubnt-cfgd[157719]: inactive May 13 15:00:10.866758 osdx INFO[157733]: FRR daemons did not change May 13 15:00:10.895221 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:10.991667 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:10.992608 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:10.993115 osdx ulogd[157824]: registering plugin `NFCT' May 13 15:00:10.993349 osdx ulogd[157824]: registering plugin `IP2STR' May 13 15:00:10.993436 osdx ulogd[157824]: registering plugin `PRINTFLOW' May 13 15:00:10.993523 osdx ulogd[157824]: registering plugin `SYSLOG' May 13 15:00:10.993558 osdx ulogd[157824]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:10.993642 osdx ulogd[157824]: NFCT plugin working in event mode May 13 15:00:10.993681 osdx ulogd[157824]: Changing UID / GID May 13 15:00:10.993796 osdx ulogd[157824]: initialization finished, entering main loop May 13 15:00:11.006567 osdx ulogd[157824]: Terminal signal received, exiting May 13 15:00:11.006649 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:11.006839 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 13 15:00:11.006936 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:11.007818 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:11.008808 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:11.009150 osdx ulogd[157830]: registering plugin `NFCT' May 13 15:00:11.009369 osdx ulogd[157830]: registering plugin `IP2STR' May 13 15:00:11.009451 osdx ulogd[157830]: registering plugin `PRINTFLOW' May 13 15:00:11.009527 osdx ulogd[157830]: registering plugin `SYSLOG' May 13 15:00:11.009556 osdx ulogd[157830]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:11.009640 osdx ulogd[157830]: NFCT plugin working in event mode May 13 15:00:11.009676 osdx ulogd[157830]: Changing UID / GID May 13 15:00:11.009776 osdx ulogd[157830]: initialization finished, entering main loop May 13 15:00:11.244447 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:11.255417 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:11.285144 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:12.057757 osdx ulogd[157830]: [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 13 15:00:12.057779 osdx ulogd[157830]: [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 13 15:00:12.136916 osdx ulogd[157830]: [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 13 15:00:12.136935 osdx ulogd[157830]: [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.307 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.307/0.307/0.307/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.242 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.242/0.242/0.242/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 13 15:00:17.326910 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:17.328581 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:17.328650 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:17.337982 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:17.760139 osdx osdx-coredump[158047]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:17.768563 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:18.304311 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:18.454731 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. May 13 15:00:18.510724 osdx OSDxCLI[2678]: 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 13 15:00:18.603284 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system vrf RED'. May 13 15:00:18.661720 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:18.762277 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:18.839646 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:18.957620 osdx ubnt-cfgd[158068]: inactive May 13 15:00:18.977649 osdx INFO[158076]: FRR daemons did not change May 13 15:00:18.986791 osdx (udev-worker)[158084]: RED: Could not disable auto negotiation, ignoring: Operation not supported May 13 15:00:18.987000 osdx (udev-worker)[158084]: Network interface NamePolicy= disabled on kernel command line. May 13 15:00:19.016424 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:19.064430 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:19.180736 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:19.181538 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument May 13 15:00:19.182026 osdx ulogd[158242]: registering plugin `NFCT' May 13 15:00:19.182272 osdx ulogd[158242]: registering plugin `IP2STR' May 13 15:00:19.182368 osdx ulogd[158242]: registering plugin `PRINTFLOW' May 13 15:00:19.182466 osdx ulogd[158242]: registering plugin `SYSLOG' May 13 15:00:19.182505 osdx ulogd[158242]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:19.182601 osdx ulogd[158242]: NFCT plugin working in event mode May 13 15:00:19.182647 osdx ulogd[158242]: Changing UID / GID May 13 15:00:19.182773 osdx ulogd[158242]: initialization finished, entering main loop May 13 15:00:19.204464 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:19.205926 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:19.234861 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:19.261287 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:20.104805 osdx ulogd[158242]: [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 13 15:00:20.104828 osdx ulogd[158242]: [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 13 15:00:20.189682 osdx ulogd[158242]: [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 13 15:00:20.189701 osdx ulogd[158242]: [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.214 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.214/0.214/0.214/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 3330 0 --:--:-- --:--:-- --:--:-- 3394
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.452 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.452/0.452/0.452/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.341 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.341/0.341/0.341/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 13 15:00:25.379487 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:25.382173 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:25.382262 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:25.390301 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:25.801878 osdx osdx-coredump[158499]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:25.812401 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:26.354252 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:26.431481 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 13 15:00:26.540765 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:26.602749 osdx ubnt-cfgd[158516]: inactive May 13 15:00:26.625610 osdx INFO[158524]: FRR daemons did not change May 13 15:00:26.650169 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 May 13 15:00:26.702625 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:26.713363 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:26.736218 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:26.902345 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 13 15:00:27.040422 osdx file_operation[158641]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// May 13 15:00:27.101893 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. May 13 15:00:27.241971 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:27.314210 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. May 13 15:00:27.410988 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. May 13 15:00:27.467389 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'. May 13 15:00:27.566421 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. May 13 15:00:27.628665 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. May 13 15:00:27.727939 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. May 13 15:00:27.785627 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. May 13 15:00:27.921473 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. May 13 15:00:27.991965 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. May 13 15:00:28.104103 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:28.174730 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:28.259990 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:28.345832 osdx ubnt-cfgd[158675]: inactive May 13 15:00:28.384969 osdx INFO[158692]: FRR daemons did not change May 13 15:00:28.410175 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:28.514527 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:28.515407 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:28.515612 osdx ulogd[158783]: registering plugin `NFCT' May 13 15:00:28.515843 osdx ulogd[158783]: registering plugin `IP2STR' May 13 15:00:28.515942 osdx ulogd[158783]: registering plugin `PRINTFLOW' May 13 15:00:28.516050 osdx ulogd[158783]: registering plugin `SYSLOG' May 13 15:00:28.516089 osdx ulogd[158783]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:28.516179 osdx ulogd[158783]: NFCT plugin working in event mode May 13 15:00:28.516224 osdx ulogd[158783]: Changing UID / GID May 13 15:00:28.516343 osdx ulogd[158783]: initialization finished, entering main loop May 13 15:00:28.796732 osdx systemd[1]: Reloading. May 13 15:00:28.874194 osdx systemd-sysv-generator[158821]: stat() failed on /etc/init.d/README, ignoring: No such file or directory May 13 15:00:29.042687 osdx systemd[1]: Starting logrotate.service - Rotate log files... May 13 15:00:29.048856 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata. May 13 15:00:29.050198 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... May 13 15:00:29.066534 osdx systemd[1]: logrotate.service: Deactivated successfully. May 13 15:00:29.066774 osdx systemd[1]: Finished logrotate.service - Rotate log files. May 13 15:00:29.342262 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. May 13 15:00:29.837493 osdx INFO[158802]: Rules successfully loaded May 13 15:00:29.852655 osdx ulogd[158783]: Terminal signal received, exiting May 13 15:00:29.852781 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:29.853106 osdx systemd[1]: ulogd2.service: Deactivated successfully. May 13 15:00:29.853227 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:29.898870 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:29.899682 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:29.899772 osdx ulogd[158849]: registering plugin `NFCT' May 13 15:00:29.900038 osdx ulogd[158849]: registering plugin `IP2STR' May 13 15:00:29.900139 osdx ulogd[158849]: registering plugin `PRINTFLOW' May 13 15:00:29.900236 osdx ulogd[158849]: registering plugin `SYSLOG' May 13 15:00:29.900274 osdx ulogd[158849]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:29.900358 osdx ulogd[158849]: NFCT plugin working in event mode May 13 15:00:29.900397 osdx ulogd[158849]: Changing UID / GID May 13 15:00:29.900512 osdx ulogd[158849]: initialization finished, entering main loop May 13 15:00:29.902043 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:29.913672 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:29.935707 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:30.813933 osdx ulogd[158849]: [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 13 15:00:30.813948 osdx ulogd[158849]: [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 13 15:00:30.922042 osdx ulogd[158849]: [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 13 15:00:30.922067 osdx ulogd[158849]: [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.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 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.336 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.336/0.336/0.336/0.000 ms
Step 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.5.0 This system includes free software. Contact Teldat for licenses information and source code. Last login: Tue May 13 13:36:45 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 13 15:00:38.309555 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:38.311629 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:38.311697 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:38.319066 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:38.662424 osdx osdx-coredump[159118]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:38.672662 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:39.142503 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:39.225775 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. May 13 15:00:39.303798 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:39.359657 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:39.469098 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:39.535105 osdx ubnt-cfgd[159137]: inactive May 13 15:00:39.565842 osdx INFO[159147]: FRR daemons did not change May 13 15:00:39.591630 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 May 13 15:00:39.655630 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:39.744003 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:39.745266 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:39.745685 osdx ulogd[159313]: registering plugin `NFCT' May 13 15:00:39.745892 osdx ulogd[159313]: registering plugin `IP2STR' May 13 15:00:39.745965 osdx ulogd[159313]: registering plugin `PRINTFLOW' May 13 15:00:39.746037 osdx ulogd[159313]: registering plugin `SYSLOG' May 13 15:00:39.746075 osdx ulogd[159313]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:39.746146 osdx ulogd[159313]: NFCT plugin working in event mode May 13 15:00:39.746179 osdx ulogd[159313]: Changing UID / GID May 13 15:00:39.746276 osdx ulogd[159313]: initialization finished, entering main loop May 13 15:00:39.746662 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:39.760733 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:39.777816 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:41.482576 osdx ulogd[159313]: [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 13 15:00:41.482605 osdx ulogd[159313]: [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 13 15:00:41.576373 osdx ulogd[159313]: [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 13 15:00:41.576395 osdx ulogd[159313]: [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 13 15:00:41.699737 osdx ulogd[159313]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 PKTS=0 BYTES=0 May 13 15:00:41.699941 osdx ulogd[159313]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 PKTS=0 BYTES=0 May 13 15:00:41.700053 osdx ulogd[159313]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 PKTS=0 BYTES=0 [OFFLOAD] May 13 15:00:42.000226 osdx ulogd[159313]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 PKTS=0 BYTES=0 May 13 15:00:42.000249 osdx ulogd[159313]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 PKTS=0 BYTES=0 [OFFLOAD] May 13 15:00:42.002400 osdx ulogd[159313]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 PKTS=0 BYTES=0 May 13 15:00:42.002587 osdx ulogd[159313]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42064 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42064 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.379 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.379/0.379/0.379/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.255 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.289 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.282 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2043ms rtt min/avg/max/mdev = 0.255/0.275/0.289/0.014 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 13 15:00:46.374524 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:46.378272 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:46.378327 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:46.384283 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:46.739736 osdx osdx-coredump[159518]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:46.747764 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:47.277122 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:47.335547 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 13 15:00:47.454395 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 13 15:00:47.566462 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:47.620028 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:47.736470 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:47.802293 osdx ubnt-cfgd[159538]: inactive May 13 15:00:47.822551 osdx INFO[159546]: FRR daemons did not change May 13 15:00:48.026266 osdx kernel: app-detect: module init May 13 15:00:48.026353 osdx kernel: app-detect: registered: sysctl net.appdetect May 13 15:00:48.026372 osdx kernel: app-detect: expression init May 13 15:00:48.026386 osdx kernel: app-detect: appid cache initialized May 13 15:00:48.026401 osdx kernel: app-detect: appid cache changes counter initialized May 13 15:00:48.031753 osdx modulelauncher[159549]: AppDetect: no change in application dictionaries, thus nothing more to do May 13 15:00:48.058263 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:48.138571 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:48.139418 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:48.139574 osdx ulogd[159659]: registering plugin `NFCT' May 13 15:00:48.139744 osdx ulogd[159659]: registering plugin `IP2STR' May 13 15:00:48.139812 osdx ulogd[159659]: registering plugin `PRINTFLOW' May 13 15:00:48.139875 osdx ulogd[159659]: registering plugin `SYSLOG' May 13 15:00:48.139900 osdx ulogd[159659]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:48.139965 osdx ulogd[159659]: NFCT plugin working in event mode May 13 15:00:48.139993 osdx ulogd[159659]: Changing UID / GID May 13 15:00:48.140084 osdx ulogd[159659]: initialization finished, entering main loop May 13 15:00:48.140458 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:48.151382 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:48.170064 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:49.073690 osdx ulogd[159659]: [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 13 15:00:49.073706 osdx ulogd[159659]: [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 13 15:00:49.165130 osdx ulogd[159659]: [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 13 15:00:49.165150 osdx ulogd[159659]: [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 13 15:00:50.184383 osdx ulogd[159659]: [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 13 15:00:50.184404 osdx ulogd[159659]: [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 13 15:00:50.184418 osdx ulogd[159659]: [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 13 15:00:51.208372 osdx ulogd[159659]: [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 13 15:00:51.208391 osdx ulogd[159659]: [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 13 15:00:51.208402 osdx ulogd[159659]: [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 13 15:00:46.374524 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:46.378272 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:46.378327 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:46.384283 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:46.739736 osdx osdx-coredump[159518]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:46.747764 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:47.277122 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:47.335547 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 13 15:00:47.454395 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 13 15:00:47.566462 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:47.620028 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:47.736470 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:47.802293 osdx ubnt-cfgd[159538]: inactive May 13 15:00:47.822551 osdx INFO[159546]: FRR daemons did not change May 13 15:00:48.026266 osdx kernel: app-detect: module init May 13 15:00:48.026353 osdx kernel: app-detect: registered: sysctl net.appdetect May 13 15:00:48.026372 osdx kernel: app-detect: expression init May 13 15:00:48.026386 osdx kernel: app-detect: appid cache initialized May 13 15:00:48.026401 osdx kernel: app-detect: appid cache changes counter initialized May 13 15:00:48.031753 osdx modulelauncher[159549]: AppDetect: no change in application dictionaries, thus nothing more to do May 13 15:00:48.058263 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:48.138571 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:48.139418 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:48.139574 osdx ulogd[159659]: registering plugin `NFCT' May 13 15:00:48.139744 osdx ulogd[159659]: registering plugin `IP2STR' May 13 15:00:48.139812 osdx ulogd[159659]: registering plugin `PRINTFLOW' May 13 15:00:48.139875 osdx ulogd[159659]: registering plugin `SYSLOG' May 13 15:00:48.139900 osdx ulogd[159659]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:48.139965 osdx ulogd[159659]: NFCT plugin working in event mode May 13 15:00:48.139993 osdx ulogd[159659]: Changing UID / GID May 13 15:00:48.140084 osdx ulogd[159659]: initialization finished, entering main loop May 13 15:00:48.140458 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:48.151382 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:48.170064 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:49.073690 osdx ulogd[159659]: [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 13 15:00:49.073706 osdx ulogd[159659]: [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 13 15:00:49.165130 osdx ulogd[159659]: [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 13 15:00:49.165150 osdx ulogd[159659]: [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 13 15:00:50.184383 osdx ulogd[159659]: [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 13 15:00:50.184404 osdx ulogd[159659]: [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 13 15:00:50.184418 osdx ulogd[159659]: [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 13 15:00:51.208372 osdx ulogd[159659]: [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 13 15:00:51.208391 osdx ulogd[159659]: [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 13 15:00:51.208402 osdx ulogd[159659]: [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 13 15:00:51.303912 osdx OSDxCLI[2678]: 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 13 15:00:46.374524 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:46.378272 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:46.378327 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:46.384283 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:46.739736 osdx osdx-coredump[159518]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:46.747764 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:47.277122 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:47.335547 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 13 15:00:47.454395 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 13 15:00:47.566462 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:47.620028 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:47.736470 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:47.802293 osdx ubnt-cfgd[159538]: inactive May 13 15:00:47.822551 osdx INFO[159546]: FRR daemons did not change May 13 15:00:48.026266 osdx kernel: app-detect: module init May 13 15:00:48.026353 osdx kernel: app-detect: registered: sysctl net.appdetect May 13 15:00:48.026372 osdx kernel: app-detect: expression init May 13 15:00:48.026386 osdx kernel: app-detect: appid cache initialized May 13 15:00:48.026401 osdx kernel: app-detect: appid cache changes counter initialized May 13 15:00:48.031753 osdx modulelauncher[159549]: AppDetect: no change in application dictionaries, thus nothing more to do May 13 15:00:48.058263 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:48.138571 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:48.139418 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:48.139574 osdx ulogd[159659]: registering plugin `NFCT' May 13 15:00:48.139744 osdx ulogd[159659]: registering plugin `IP2STR' May 13 15:00:48.139812 osdx ulogd[159659]: registering plugin `PRINTFLOW' May 13 15:00:48.139875 osdx ulogd[159659]: registering plugin `SYSLOG' May 13 15:00:48.139900 osdx ulogd[159659]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:48.139965 osdx ulogd[159659]: NFCT plugin working in event mode May 13 15:00:48.139993 osdx ulogd[159659]: Changing UID / GID May 13 15:00:48.140084 osdx ulogd[159659]: initialization finished, entering main loop May 13 15:00:48.140458 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:48.151382 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:48.170064 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:49.073690 osdx ulogd[159659]: [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 13 15:00:49.073706 osdx ulogd[159659]: [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 13 15:00:49.165130 osdx ulogd[159659]: [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 13 15:00:49.165150 osdx ulogd[159659]: [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 13 15:00:50.184383 osdx ulogd[159659]: [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 13 15:00:50.184404 osdx ulogd[159659]: [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 13 15:00:50.184418 osdx ulogd[159659]: [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 13 15:00:51.208372 osdx ulogd[159659]: [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 13 15:00:51.208391 osdx ulogd[159659]: [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 13 15:00:51.208402 osdx ulogd[159659]: [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 13 15:00:51.303912 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal show | cat'. May 13 15:00:51.405540 osdx OSDxCLI[2678]: 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.190 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.190/0.190/0.190/0.000 ms
Step 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 1086 0 1086 0 0 29579 0 --:--:-- --:--:-- --:--:-- 30166
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 13 15:00:46.374524 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.2M free. May 13 15:00:46.378272 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:46.378327 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:46.384283 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:46.739736 osdx osdx-coredump[159518]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:46.747764 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:47.277122 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:47.335547 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. May 13 15:00:47.454395 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. May 13 15:00:47.566462 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. May 13 15:00:47.620028 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. May 13 15:00:47.736470 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:00:47.802293 osdx ubnt-cfgd[159538]: inactive May 13 15:00:47.822551 osdx INFO[159546]: FRR daemons did not change May 13 15:00:48.026266 osdx kernel: app-detect: module init May 13 15:00:48.026353 osdx kernel: app-detect: registered: sysctl net.appdetect May 13 15:00:48.026372 osdx kernel: app-detect: expression init May 13 15:00:48.026386 osdx kernel: app-detect: appid cache initialized May 13 15:00:48.026401 osdx kernel: app-detect: appid cache changes counter initialized May 13 15:00:48.031753 osdx modulelauncher[159549]: AppDetect: no change in application dictionaries, thus nothing more to do May 13 15:00:48.058263 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 May 13 15:00:48.138571 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... May 13 15:00:48.139418 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. May 13 15:00:48.139574 osdx ulogd[159659]: registering plugin `NFCT' May 13 15:00:48.139744 osdx ulogd[159659]: registering plugin `IP2STR' May 13 15:00:48.139812 osdx ulogd[159659]: registering plugin `PRINTFLOW' May 13 15:00:48.139875 osdx ulogd[159659]: registering plugin `SYSLOG' May 13 15:00:48.139900 osdx ulogd[159659]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' May 13 15:00:48.139965 osdx ulogd[159659]: NFCT plugin working in event mode May 13 15:00:48.139993 osdx ulogd[159659]: Changing UID / GID May 13 15:00:48.140084 osdx ulogd[159659]: initialization finished, entering main loop May 13 15:00:48.140458 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:48.151382 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:48.170064 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:49.073690 osdx ulogd[159659]: [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 13 15:00:49.073706 osdx ulogd[159659]: [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 13 15:00:49.165130 osdx ulogd[159659]: [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 13 15:00:49.165150 osdx ulogd[159659]: [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 13 15:00:50.184383 osdx ulogd[159659]: [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 13 15:00:50.184404 osdx ulogd[159659]: [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 13 15:00:50.184418 osdx ulogd[159659]: [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 13 15:00:51.208372 osdx ulogd[159659]: [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 13 15:00:51.208391 osdx ulogd[159659]: [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 13 15:00:51.208402 osdx ulogd[159659]: [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 13 15:00:51.303912 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal show | cat'. May 13 15:00:51.405540 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal show | cat'. May 13 15:00:51.508565 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal show | cat'. May 13 15:00:51.657726 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:51.765574 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 13 15:00:51.819968 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. May 13 15:00:51.914213 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show changes'. May 13 15:00:51.980750 osdx ubnt-cfgd[159710]: inactive May 13 15:00:52.004758 osdx INFO[159718]: FRR daemons did not change May 13 15:00:52.042263 osdx kernel: app-detect: expression destroy May 13 15:00:52.050293 osdx kernel: app-detect: expression init May 13 15:00:52.050340 osdx kernel: app-detect: appid cache initialized May 13 15:00:52.050349 osdx kernel: app-detect: appid cache changes counter initialized May 13 15:00:52.053993 osdx modulelauncher[159721]: AppDetect: no change in application dictionaries, thus nothing more to do May 13 15:00:52.074263 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 May 13 15:00:52.125968 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:00:52.136094 osdx ulogd[159659]: [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 13 15:00:52.136113 osdx ulogd[159659]: [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 13 15:00:52.136822 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:00:52.154742 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:00:52.305826 osdx ulogd[159659]: [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 13 15:00:52.306149 osdx ulogd[159659]: [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 13 15:00:52.307194 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 13 15:00:52.454410 osdx file_operation[159848]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html May 13 15:00:52.458774 osdx ulogd[159659]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=50894 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=50894 PKTS=0 BYTES=0 APPDETECT[L4:80] May 13 15:00:52.458895 osdx ulogd[159659]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=50894 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=50894 PKTS=0 BYTES=0 APPDETECT[L4:80] May 13 15:00:52.458911 osdx ulogd[159659]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=50894 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=50894 PKTS=0 BYTES=0 APPDETECT[L4:80] May 13 15:00:52.493037 osdx ulogd[159659]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=50894 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=50894 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] May 13 15:00:52.493064 osdx ulogd[159659]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=50894 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=50894 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] May 13 15:00:52.493078 osdx ulogd[159659]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=50894 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=50894 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] May 13 15:00:52.512570 osdx OSDxCLI[2678]: 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 13 15:00:58.302767 osdx systemd-journald[1688]: Runtime Journal (/run/log/journal/78d6c860b8a549a191d002c20b18506e) is 2.0M, max 15.3M, 13.3M free. May 13 15:00:58.305141 osdx systemd-journald[1688]: Received client request to rotate journal, rotating. May 13 15:00:58.305193 osdx systemd-journald[1688]: Vacuuming done, freed 0B of archived journals from /run/log/journal/78d6c860b8a549a191d002c20b18506e. May 13 15:00:58.314450 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system journal clear'. May 13 15:00:58.673601 osdx osdx-coredump[160052]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... May 13 15:00:58.684443 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'system coredump delete all'. May 13 15:00:59.180812 osdx OSDxCLI[2678]: User 'admin' entered the configuration menu. May 13 15:00:59.247786 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. May 13 15:00:59.355726 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. May 13 15:00:59.455459 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. May 13 15:00:59.528827 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. May 13 15:00:59.637875 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. May 13 15:00:59.717355 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. May 13 15:00:59.830372 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. May 13 15:00:59.908182 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. May 13 15:00:59.988471 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. May 13 15:01:00.047996 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. May 13 15:01:00.190642 osdx OSDxCLI[2678]: User 'admin' added a new cfg line: 'show working'. May 13 15:01:00.262898 osdx ubnt-cfgd[160078]: inactive May 13 15:01:00.304443 osdx INFO[160100]: FRR daemons did not change May 13 15:01:00.469146 osdx kernel: app-detect: module init May 13 15:01:00.469213 osdx kernel: app-detect: registered: sysctl net.appdetect May 13 15:01:00.469226 osdx kernel: app-detect: expression init May 13 15:01:00.469238 osdx kernel: app-detect: appid cache initialized May 13 15:01:00.469250 osdx kernel: app-detect: appid cache changes counter initialized May 13 15:01:00.517145 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 May 13 15:01:00.774409 osdx cfgd[1466]: [2678]Completed change to active configuration May 13 15:01:00.786703 osdx OSDxCLI[2678]: User 'admin' committed the configuration. May 13 15:01:00.814399 osdx OSDxCLI[2678]: User 'admin' left the configuration menu. May 13 15:01:00.970354 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. May 13 15:01:01.124270 osdx file_operation[160267]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html May 13 15:01:01.133141 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=50997 DF PROTO=TCP SPT=45132 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 13 15:01:01.337162 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=50998 DF PROTO=TCP SPT=45132 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 13 15:01:01.741153 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=50999 DF PROTO=TCP SPT=45132 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 13 15:01:02.573150 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=51000 DF PROTO=TCP SPT=45132 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 13 15:01:04.123018 osdx file_operation.py[160267]: Operation aborted by user. May 13 15:01:04.133142 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=51001 DF PROTO=TCP SPT=45132 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] May 13 15:01:04.137486 osdx OSDxCLI[2678]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'. May 13 15:01:04.201187 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=51002 DF PROTO=TCP SPT=45132 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]