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.339 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.339/0.339/0.339/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.205 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.205/0.205/0.205/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[NEW\].*SRC=192.168.100.2Show output
Oct 30 13:27:11.000349 osdx systemd-timedated[355713]: Changed local time to Wed 2024-10-30 13:27:11 UTC Oct 30 13:27:11.001863 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'set date 2024-10-30 13:27:11'. Oct 30 13:27:11.003241 osdx systemd-journald[1923]: Time jumped backwards, rotating. Oct 30 13:27:11.323257 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.2M free. Oct 30 13:27:11.327233 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:11.327293 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:11.332794 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:11.669791 osdx osdx-coredump[355730]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:11.677546 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:12.009529 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:12.161602 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:12.232948 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:27:12.326025 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. Oct 30 13:27:12.401034 osdx ERROR[355738]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:12.401915 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:12.535243 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:12.643478 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:12.646722 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:27:12.647033 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:12.648114 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:12.650995 osdx ulogd[355815]: registering plugin `NFCT' Oct 30 13:27:12.652025 osdx ulogd[355815]: registering plugin `IP2STR' Oct 30 13:27:12.652135 osdx ulogd[355815]: registering plugin `PRINTFLOW' Oct 30 13:27:12.653232 osdx ulogd[355815]: registering plugin `SYSLOG' Oct 30 13:27:12.653295 osdx ulogd[355815]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:12.653378 osdx ulogd[355815]: NFCT plugin working in event mode Oct 30 13:27:12.653412 osdx ulogd[355815]: Changing UID / GID Oct 30 13:27:12.653591 osdx ulogd[355815]: initialization finished, entering main loop Oct 30 13:27:12.681259 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:12.704185 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:13.488614 osdx ulogd[355815]: [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 Oct 30 13:27:13.576141 osdx ulogd[355815]: [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.406 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.406/0.406/0.406/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.254 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.254/0.254/0.254/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
Oct 30 13:27:18.308201 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.1M, max 15.3M, 13.1M free. Oct 30 13:27:18.310193 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:18.310243 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:18.318226 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:18.639029 osdx osdx-coredump[355962]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:18.648108 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:19.122405 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:19.191477 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:27:19.277172 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. Oct 30 13:27:19.346419 osdx ERROR[355970]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:19.347085 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:19.482201 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:19.582561 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:19.583135 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:19.583253 osdx ulogd[356047]: registering plugin `NFCT' Oct 30 13:27:19.583290 osdx ulogd[356047]: registering plugin `IP2STR' Oct 30 13:27:19.583325 osdx ulogd[356047]: registering plugin `PRINTFLOW' Oct 30 13:27:19.583363 osdx ulogd[356047]: registering plugin `SYSLOG' Oct 30 13:27:19.583366 osdx ulogd[356047]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:19.583402 osdx ulogd[356047]: NFCT plugin working in event mode Oct 30 13:27:19.583408 osdx ulogd[356047]: Changing UID / GID Oct 30 13:27:19.583473 osdx ulogd[356047]: initialization finished, entering main loop Oct 30 13:27:19.585750 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:19.607518 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:19.614927 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:19.631233 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:20.433607 osdx ulogd[356047]: [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 Oct 30 13:27:20.511300 osdx ulogd[356047]: [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.268 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.268/0.268/0.268/0.000 ms
Step 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.177 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.249 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.271 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2030ms rtt min/avg/max/mdev = 0.177/0.232/0.271/0.040 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
Oct 30 13:27:24.313178 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.1M, max 15.3M, 13.2M free. Oct 30 13:27:24.316834 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:24.316898 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:24.322693 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:24.634086 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:24.634154 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:24.649808 osdx osdx-coredump[356194]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:24.658418 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:25.155742 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:25.274220 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:27:25.326227 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. Oct 30 13:27:25.421570 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 30 13:27:25.475426 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service ssh'. Oct 30 13:27:25.585403 osdx ERROR[356204]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:25.588823 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:25.684800 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:25.801081 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:25.801689 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:27:25.802035 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:25.802896 osdx ulogd[356289]: registering plugin `NFCT' Oct 30 13:27:25.803075 osdx ulogd[356289]: registering plugin `IP2STR' Oct 30 13:27:25.803143 osdx ulogd[356289]: registering plugin `PRINTFLOW' Oct 30 13:27:25.803208 osdx ulogd[356289]: registering plugin `SYSLOG' Oct 30 13:27:25.803229 osdx ulogd[356289]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:25.803283 osdx ulogd[356289]: NFCT plugin working in event mode Oct 30 13:27:25.803310 osdx ulogd[356289]: Changing UID / GID Oct 30 13:27:25.803389 osdx ulogd[356289]: initialization finished, entering main loop Oct 30 13:27:25.845312 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Oct 30 13:27:25.857859 osdx sshd[356295]: Server listening on 0.0.0.0 port 22. Oct 30 13:27:25.857883 osdx sshd[356295]: Server listening on :: port 22. Oct 30 13:27:25.857989 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Oct 30 13:27:25.877992 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:25.907039 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:25.922919 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:27.091158 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:27.834618 osdx ulogd[356289]: [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 Oct 30 13:27:28.858689 osdx ulogd[356289]: [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 Oct 30 13:27:30.920065 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:31.148997 osdx ulogd[356289]: [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 Oct 30 13:27:31.149019 osdx ulogd[356289]: [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.324 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.324/0.324/0.324/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:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Oct 30 13:27:36.298689 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.3M free. Oct 30 13:27:36.302087 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:36.302157 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:36.307884 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:36.613905 osdx osdx-coredump[356467]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:36.621763 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:37.065736 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:37.139705 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:27:37.221483 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:27:37.288718 osdx ERROR[356475]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:37.291691 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:37.406098 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:37.518810 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:37.520863 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:37.521270 osdx ulogd[356554]: registering plugin `NFCT' Oct 30 13:27:37.521401 osdx ulogd[356554]: registering plugin `IP2STR' Oct 30 13:27:37.521531 osdx ulogd[356554]: registering plugin `PRINTFLOW' Oct 30 13:27:37.521668 osdx ulogd[356554]: registering plugin `SYSLOG' Oct 30 13:27:37.521679 osdx ulogd[356554]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:37.522529 osdx ulogd[356554]: NFCT plugin working in event mode Oct 30 13:27:37.522566 osdx ulogd[356554]: Changing UID / GID Oct 30 13:27:37.522780 osdx ulogd[356554]: initialization finished, entering main loop Oct 30 13:27:37.524045 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:37.565545 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:37.583806 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:38.374736 osdx ulogd[356554]: [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 Oct 30 13:27:38.374758 osdx ulogd[356554]: [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 Oct 30 13:27:38.464446 osdx ulogd[356554]: [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 Oct 30 13:27:38.464465 osdx ulogd[356554]: [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.317 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.317/0.317/0.317/0.000 ms
Step 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.219 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.234 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1012ms rtt min/avg/max/mdev = 0.219/0.226/0.234/0.007 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*MARK=33.*LABELS=TESTShow output
Oct 30 13:27:43.319536 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.2M free. Oct 30 13:27:43.320308 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:43.320372 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:43.329408 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:43.696110 osdx osdx-coredump[356701]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:43.704420 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:44.160312 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:44.246127 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Oct 30 13:27:44.328931 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic label TEST'. Oct 30 13:27:44.388529 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. Oct 30 13:27:44.488491 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. Oct 30 13:27:44.543980 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:27:44.640408 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:27:44.722869 osdx ERROR[356713]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:44.723871 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:44.868320 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:44.976671 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:44.977588 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:44.978017 osdx ulogd[356796]: registering plugin `NFCT' Oct 30 13:27:44.978082 osdx ulogd[356796]: registering plugin `IP2STR' Oct 30 13:27:44.978131 osdx ulogd[356796]: registering plugin `PRINTFLOW' Oct 30 13:27:44.978179 osdx ulogd[356796]: registering plugin `SYSLOG' Oct 30 13:27:44.978184 osdx ulogd[356796]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:44.978234 osdx ulogd[356796]: NFCT plugin working in event mode Oct 30 13:27:44.978242 osdx ulogd[356796]: Changing UID / GID Oct 30 13:27:44.978326 osdx ulogd[356796]: initialization finished, entering main loop Oct 30 13:27:44.989648 osdx ulogd[356796]: Terminal signal received, exiting Oct 30 13:27:44.989772 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:44.990059 osdx systemd[1]: ulogd2.service: Deactivated successfully. Oct 30 13:27:44.990187 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:44.991407 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:44.992345 osdx ulogd[356802]: registering plugin `NFCT' Oct 30 13:27:44.992384 osdx ulogd[356802]: registering plugin `IP2STR' Oct 30 13:27:44.992421 osdx ulogd[356802]: registering plugin `PRINTFLOW' Oct 30 13:27:44.992466 osdx ulogd[356802]: registering plugin `SYSLOG' Oct 30 13:27:44.992469 osdx ulogd[356802]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:44.992505 osdx ulogd[356802]: NFCT plugin working in event mode Oct 30 13:27:44.992510 osdx ulogd[356802]: Changing UID / GID Oct 30 13:27:44.992567 osdx ulogd[356802]: initialization finished, entering main loop Oct 30 13:27:44.992801 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:45.193311 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:45.222215 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:45.238006 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:46.022516 osdx ulogd[356802]: [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 Oct 30 13:27:46.022537 osdx ulogd[356802]: [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 Oct 30 13:27:46.094284 osdx ulogd[356802]: [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 Oct 30 13:27:46.094300 osdx ulogd[356802]: [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 Oct 30 13:27:46.471620 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:27:46.471632 osdx ulogd[356802]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=58249 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=58249 PKTS=0 BYTES=0 Oct 30 13:27:46.471646 osdx ulogd[356802]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=50646 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=50646 PKTS=0 BYTES=0
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.352 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.352/0.352/0.352/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.259 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.259/0.259/0.259/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*VRF=REDShow output
Oct 30 13:27:51.299870 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.3M free. Oct 30 13:27:51.303472 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:51.303517 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:51.310132 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:51.619067 osdx osdx-coredump[356991]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:51.626226 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:52.143577 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:52.270588 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. Oct 30 13:27:52.342367 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. Oct 30 13:27:52.431450 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system vrf RED'. Oct 30 13:27:52.490590 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:27:52.584495 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:27:52.653295 osdx ERROR[357002]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:52.661065 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:52.775146 osdx (udev-worker)[357026]: RED: Could not disable auto negotiation, ignoring: Operation not supported Oct 30 13:27:52.775170 osdx (udev-worker)[357026]: Network interface NamePolicy= disabled on kernel command line. Oct 30 13:27:52.795475 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:52.859479 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:27:52.943930 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:27:52.945188 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:27:52.945599 osdx ulogd[357109]: registering plugin `NFCT' Oct 30 13:27:52.945719 osdx ulogd[357109]: registering plugin `IP2STR' Oct 30 13:27:52.945837 osdx ulogd[357109]: registering plugin `PRINTFLOW' Oct 30 13:27:52.945935 osdx ulogd[357109]: registering plugin `SYSLOG' Oct 30 13:27:52.945943 osdx ulogd[357109]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:27:52.946048 osdx ulogd[357109]: NFCT plugin working in event mode Oct 30 13:27:52.946065 osdx ulogd[357109]: Changing UID / GID Oct 30 13:27:52.946224 osdx ulogd[357109]: initialization finished, entering main loop Oct 30 13:27:52.948516 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:52.987826 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:53.003522 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:53.821381 osdx ulogd[357109]: [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 Oct 30 13:27:53.821400 osdx ulogd[357109]: [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 Oct 30 13:27:53.897727 osdx ulogd[357109]: [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 Oct 30 13:27:53.897748 osdx ulogd[357109]: [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.224 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.224/0.224/0.224/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 53997 0 --:--:-- --:--:-- --:--:-- 64500
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.488 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.488/0.488/0.488/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.335 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.335/0.335/0.335/0.000 ms
Step 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
Oct 30 13:27:58.303840 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.2M free. Oct 30 13:27:58.307005 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:27:58.307070 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:27:58.316619 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:27:58.665218 osdx osdx-coredump[357293]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:27:58.672775 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:27:59.150507 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:27:59.220096 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Oct 30 13:27:59.336463 osdx ERROR[357300]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:27:59.339427 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:27:59.427004 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 30 13:27:59.498051 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:27:59.524164 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:27:59.543864 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:27:59.696599 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Oct 30 13:27:59.828310 osdx file_operation[357403]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// Oct 30 13:27:59.851879 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. Oct 30 13:27:59.991742 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:00.069849 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Oct 30 13:28:00.176072 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. Oct 30 13:28:00.252399 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file 'running://test-performance.rules''. Oct 30 13:28:00.361635 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. Oct 30 13:28:00.437807 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. Oct 30 13:28:00.561497 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. Oct 30 13:28:00.640220 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. Oct 30 13:28:00.743751 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. Oct 30 13:28:00.805538 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. Oct 30 13:28:00.899685 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:28:00.951966 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:28:01.078571 osdx ERROR[357428]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:01.084275 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:01.215007 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:28:01.290282 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:01.323337 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:01.324098 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:28:01.327031 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:01.327331 osdx ulogd[357514]: registering plugin `NFCT' Oct 30 13:28:01.327371 osdx ulogd[357514]: registering plugin `IP2STR' Oct 30 13:28:01.327409 osdx ulogd[357514]: registering plugin `PRINTFLOW' Oct 30 13:28:01.327449 osdx ulogd[357514]: registering plugin `SYSLOG' Oct 30 13:28:01.327452 osdx ulogd[357514]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:01.327489 osdx ulogd[357514]: NFCT plugin working in event mode Oct 30 13:28:01.327496 osdx ulogd[357514]: Changing UID / GID Oct 30 13:28:01.327562 osdx ulogd[357514]: initialization finished, entering main loop Oct 30 13:28:01.500767 osdx systemd[1]: Reloading. Oct 30 13:28:01.607023 osdx systemd-sysv-generator[357547]: stat() failed on /etc/init.d/README, ignoring: No such file or directory Oct 30 13:28:01.739526 osdx systemd[1]: Starting logrotate.service - Rotate log files... Oct 30 13:28:01.743414 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... Oct 30 13:28:01.768736 osdx systemd[1]: logrotate.service: Deactivated successfully. Oct 30 13:28:01.768882 osdx systemd[1]: Finished logrotate.service - Rotate log files. Oct 30 13:28:01.769779 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. Oct 30 13:28:01.798612 osdx INFO[357529]: Rules successfully loaded Oct 30 13:28:01.813757 osdx ulogd[357514]: Terminal signal received, exiting Oct 30 13:28:01.813841 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:01.814073 osdx systemd[1]: ulogd2.service: Deactivated successfully. Oct 30 13:28:01.814176 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:01.835393 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:01.836095 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:01.837086 osdx ulogd[357576]: registering plugin `NFCT' Oct 30 13:28:01.837140 osdx ulogd[357576]: registering plugin `IP2STR' Oct 30 13:28:01.837191 osdx ulogd[357576]: registering plugin `PRINTFLOW' Oct 30 13:28:01.837240 osdx ulogd[357576]: registering plugin `SYSLOG' Oct 30 13:28:01.837245 osdx ulogd[357576]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:01.837297 osdx ulogd[357576]: NFCT plugin working in event mode Oct 30 13:28:01.837306 osdx ulogd[357576]: Changing UID / GID Oct 30 13:28:01.837393 osdx ulogd[357576]: initialization finished, entering main loop Oct 30 13:28:01.838223 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:01.875226 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:01.895799 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:02.714701 osdx ulogd[357576]: [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) Oct 30 13:28:02.714719 osdx ulogd[357576]: [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) Oct 30 13:28:02.798671 osdx ulogd[357576]: [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) Oct 30 13:28:02.798689 osdx ulogd[357576]: [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.366 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.366/0.366/0.366/0.000 ms
Step 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.353 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.353/0.353/0.353/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.1.1 This system includes free software. Contact Teldat for licenses information and source code. Last login: Wed Oct 30 13:26:01 2024 from 10.215.168.64 admin@osdx$
Step 7: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*\[OFFLOAD\]Show output
Oct 30 13:28:09.316850 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.2M free. Oct 30 13:28:09.317284 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:28:09.317328 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:28:09.327735 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:28:09.644537 osdx osdx-coredump[357797]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:28:09.651899 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:28:10.119520 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:10.119568 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:10.178582 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:10.262301 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. Oct 30 13:28:10.347243 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:28:10.403824 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:28:10.516676 osdx ERROR[357806]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:10.520213 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:10.617270 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 30 13:28:10.689268 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:28:10.793476 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:10.793995 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:28:10.794513 osdx ulogd[357935]: registering plugin `NFCT' Oct 30 13:28:10.794549 osdx ulogd[357935]: registering plugin `IP2STR' Oct 30 13:28:10.794591 osdx ulogd[357935]: registering plugin `PRINTFLOW' Oct 30 13:28:10.794629 osdx ulogd[357935]: registering plugin `SYSLOG' Oct 30 13:28:10.794632 osdx ulogd[357935]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:10.794670 osdx ulogd[357935]: NFCT plugin working in event mode Oct 30 13:28:10.794676 osdx ulogd[357935]: Changing UID / GID Oct 30 13:28:10.794748 osdx ulogd[357935]: initialization finished, entering main loop Oct 30 13:28:10.809292 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:10.810482 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:10.842201 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:10.861971 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:12.577562 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:12.577613 osdx ulogd[357935]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=47760 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=47760 PKTS=0 BYTES=0 Oct 30 13:28:12.577631 osdx ulogd[357935]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=58435 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=58435 PKTS=0 BYTES=0 Oct 30 13:28:12.630508 osdx ulogd[357935]: [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 Oct 30 13:28:12.630528 osdx ulogd[357935]: [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 Oct 30 13:28:12.712817 osdx ulogd[357935]: [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 Oct 30 13:28:12.712836 osdx ulogd[357935]: [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 Oct 30 13:28:12.795787 osdx ulogd[357935]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 PKTS=0 BYTES=0 Oct 30 13:28:12.795927 osdx ulogd[357935]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 PKTS=0 BYTES=0 Oct 30 13:28:12.796038 osdx ulogd[357935]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 PKTS=0 BYTES=0 [OFFLOAD] Oct 30 13:28:13.064976 osdx ulogd[357935]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 PKTS=0 BYTES=0 Oct 30 13:28:13.064996 osdx ulogd[357935]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 PKTS=0 BYTES=0 [OFFLOAD] Oct 30 13:28:13.066278 osdx ulogd[357935]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 PKTS=0 BYTES=0 Oct 30 13:28:13.066378 osdx ulogd[357935]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=42068 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=42068 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.338 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.338/0.338/0.338/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.329 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.255 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.423 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2040ms rtt min/avg/max/mdev = 0.255/0.335/0.423/0.068 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
Oct 30 13:28:17.303752 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.3M, max 15.3M, 12.9M free. Oct 30 13:28:17.304721 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:28:17.304760 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:28:17.313774 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:28:17.625728 osdx osdx-coredump[358090]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:28:17.633253 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:28:18.082142 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:18.142598 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 30 13:28:18.243107 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 30 13:28:18.311659 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:28:18.410093 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:28:18.499314 osdx ERROR[358100]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:18.502454 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:18.760717 osdx kernel: app-detect: module init Oct 30 13:28:18.760778 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 30 13:28:18.760793 osdx kernel: app-detect: expression init Oct 30 13:28:18.760805 osdx kernel: app-detect: appid cache initialized Oct 30 13:28:18.760817 osdx kernel: app-detect: appid cache changes counter initialized Oct 30 13:28:18.764839 osdx modulelauncher[358114]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 30 13:28:18.788718 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:28:18.917038 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:18.917845 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:28:18.918174 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:18.919305 osdx ulogd[358200]: registering plugin `NFCT' Oct 30 13:28:18.919354 osdx ulogd[358200]: registering plugin `IP2STR' Oct 30 13:28:18.919401 osdx ulogd[358200]: registering plugin `PRINTFLOW' Oct 30 13:28:18.919450 osdx ulogd[358200]: registering plugin `SYSLOG' Oct 30 13:28:18.919454 osdx ulogd[358200]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:18.919472 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:18.919503 osdx ulogd[358200]: NFCT plugin working in event mode Oct 30 13:28:18.919512 osdx ulogd[358200]: Changing UID / GID Oct 30 13:28:18.919597 osdx ulogd[358200]: initialization finished, entering main loop Oct 30 13:28:18.954348 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:18.972198 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:19.529109 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:19.529113 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=45229 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=45229 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.529127 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=33709 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=33709 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.833760 osdx ulogd[358200]: [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] Oct 30 13:28:19.833785 osdx ulogd[358200]: [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] Oct 30 13:28:19.918204 osdx ulogd[358200]: [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] Oct 30 13:28:19.918224 osdx ulogd[358200]: [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] Oct 30 13:28:20.934578 osdx ulogd[358200]: [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] Oct 30 13:28:20.934599 osdx ulogd[358200]: [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] Oct 30 13:28:20.934611 osdx ulogd[358200]: [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] Oct 30 13:28:21.958663 osdx ulogd[358200]: [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] Oct 30 13:28:21.958700 osdx ulogd[358200]: [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] Oct 30 13:28:21.958713 osdx ulogd[358200]: [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
Oct 30 13:28:17.303752 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.3M, max 15.3M, 12.9M free. Oct 30 13:28:17.304721 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:28:17.304760 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:28:17.313774 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:28:17.625728 osdx osdx-coredump[358090]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:28:17.633253 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:28:18.082142 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:18.142598 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 30 13:28:18.243107 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 30 13:28:18.311659 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:28:18.410093 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:28:18.499314 osdx ERROR[358100]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:18.502454 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:18.760717 osdx kernel: app-detect: module init Oct 30 13:28:18.760778 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 30 13:28:18.760793 osdx kernel: app-detect: expression init Oct 30 13:28:18.760805 osdx kernel: app-detect: appid cache initialized Oct 30 13:28:18.760817 osdx kernel: app-detect: appid cache changes counter initialized Oct 30 13:28:18.764839 osdx modulelauncher[358114]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 30 13:28:18.788718 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:28:18.917038 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:18.917845 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:28:18.918174 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:18.919305 osdx ulogd[358200]: registering plugin `NFCT' Oct 30 13:28:18.919354 osdx ulogd[358200]: registering plugin `IP2STR' Oct 30 13:28:18.919401 osdx ulogd[358200]: registering plugin `PRINTFLOW' Oct 30 13:28:18.919450 osdx ulogd[358200]: registering plugin `SYSLOG' Oct 30 13:28:18.919454 osdx ulogd[358200]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:18.919472 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:18.919503 osdx ulogd[358200]: NFCT plugin working in event mode Oct 30 13:28:18.919512 osdx ulogd[358200]: Changing UID / GID Oct 30 13:28:18.919597 osdx ulogd[358200]: initialization finished, entering main loop Oct 30 13:28:18.954348 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:18.972198 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:19.529109 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:19.529113 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=45229 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=45229 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.529127 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=33709 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=33709 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.833760 osdx ulogd[358200]: [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] Oct 30 13:28:19.833785 osdx ulogd[358200]: [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] Oct 30 13:28:19.918204 osdx ulogd[358200]: [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] Oct 30 13:28:19.918224 osdx ulogd[358200]: [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] Oct 30 13:28:20.934578 osdx ulogd[358200]: [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] Oct 30 13:28:20.934599 osdx ulogd[358200]: [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] Oct 30 13:28:20.934611 osdx ulogd[358200]: [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] Oct 30 13:28:21.958663 osdx ulogd[358200]: [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] Oct 30 13:28:21.958700 osdx ulogd[358200]: [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] Oct 30 13:28:21.958713 osdx ulogd[358200]: [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] Oct 30 13:28:22.056338 osdx OSDxCLI[352274]: 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
Oct 30 13:28:17.303752 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.3M, max 15.3M, 12.9M free. Oct 30 13:28:17.304721 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:28:17.304760 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:28:17.313774 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:28:17.625728 osdx osdx-coredump[358090]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:28:17.633253 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:28:18.082142 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:18.142598 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 30 13:28:18.243107 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 30 13:28:18.311659 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:28:18.410093 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:28:18.499314 osdx ERROR[358100]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:18.502454 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:18.760717 osdx kernel: app-detect: module init Oct 30 13:28:18.760778 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 30 13:28:18.760793 osdx kernel: app-detect: expression init Oct 30 13:28:18.760805 osdx kernel: app-detect: appid cache initialized Oct 30 13:28:18.760817 osdx kernel: app-detect: appid cache changes counter initialized Oct 30 13:28:18.764839 osdx modulelauncher[358114]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 30 13:28:18.788718 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:28:18.917038 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:18.917845 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:28:18.918174 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:18.919305 osdx ulogd[358200]: registering plugin `NFCT' Oct 30 13:28:18.919354 osdx ulogd[358200]: registering plugin `IP2STR' Oct 30 13:28:18.919401 osdx ulogd[358200]: registering plugin `PRINTFLOW' Oct 30 13:28:18.919450 osdx ulogd[358200]: registering plugin `SYSLOG' Oct 30 13:28:18.919454 osdx ulogd[358200]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:18.919472 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:18.919503 osdx ulogd[358200]: NFCT plugin working in event mode Oct 30 13:28:18.919512 osdx ulogd[358200]: Changing UID / GID Oct 30 13:28:18.919597 osdx ulogd[358200]: initialization finished, entering main loop Oct 30 13:28:18.954348 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:18.972198 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:19.529109 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:19.529113 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=45229 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=45229 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.529127 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=33709 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=33709 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.833760 osdx ulogd[358200]: [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] Oct 30 13:28:19.833785 osdx ulogd[358200]: [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] Oct 30 13:28:19.918204 osdx ulogd[358200]: [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] Oct 30 13:28:19.918224 osdx ulogd[358200]: [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] Oct 30 13:28:20.934578 osdx ulogd[358200]: [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] Oct 30 13:28:20.934599 osdx ulogd[358200]: [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] Oct 30 13:28:20.934611 osdx ulogd[358200]: [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] Oct 30 13:28:21.958663 osdx ulogd[358200]: [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] Oct 30 13:28:21.958700 osdx ulogd[358200]: [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] Oct 30 13:28:21.958713 osdx ulogd[358200]: [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] Oct 30 13:28:22.056338 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal show | cat'. Oct 30 13:28:22.179295 osdx OSDxCLI[352274]: 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.213 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.213/0.213/0.213/0.000 ms
Step 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 4352 0 4352 0 0 1287k 0 --:--:-- --:--:-- --:--:-- 1416k
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
Oct 30 13:28:17.303752 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.3M, max 15.3M, 12.9M free. Oct 30 13:28:17.304721 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:28:17.304760 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:28:17.313774 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:28:17.625728 osdx osdx-coredump[358090]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:28:17.633253 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:28:18.082142 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:18.142598 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 30 13:28:18.243107 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 30 13:28:18.311659 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 30 13:28:18.410093 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 30 13:28:18.499314 osdx ERROR[358100]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:18.502454 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:18.760717 osdx kernel: app-detect: module init Oct 30 13:28:18.760778 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 30 13:28:18.760793 osdx kernel: app-detect: expression init Oct 30 13:28:18.760805 osdx kernel: app-detect: appid cache initialized Oct 30 13:28:18.760817 osdx kernel: app-detect: appid cache changes counter initialized Oct 30 13:28:18.764839 osdx modulelauncher[358114]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 30 13:28:18.788718 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 30 13:28:18.917038 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 30 13:28:18.917845 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 30 13:28:18.918174 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 30 13:28:18.919305 osdx ulogd[358200]: registering plugin `NFCT' Oct 30 13:28:18.919354 osdx ulogd[358200]: registering plugin `IP2STR' Oct 30 13:28:18.919401 osdx ulogd[358200]: registering plugin `PRINTFLOW' Oct 30 13:28:18.919450 osdx ulogd[358200]: registering plugin `SYSLOG' Oct 30 13:28:18.919454 osdx ulogd[358200]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 30 13:28:18.919472 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:18.919503 osdx ulogd[358200]: NFCT plugin working in event mode Oct 30 13:28:18.919512 osdx ulogd[358200]: Changing UID / GID Oct 30 13:28:18.919597 osdx ulogd[358200]: initialization finished, entering main loop Oct 30 13:28:18.954348 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:18.972198 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:19.529109 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:19.529113 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=45229 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=45229 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.529127 osdx ulogd[358200]: [NEW] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=33709 DPT=53 PKTS=0 BYTES=0 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=33709 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:19.833760 osdx ulogd[358200]: [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] Oct 30 13:28:19.833785 osdx ulogd[358200]: [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] Oct 30 13:28:19.918204 osdx ulogd[358200]: [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] Oct 30 13:28:19.918224 osdx ulogd[358200]: [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] Oct 30 13:28:20.934578 osdx ulogd[358200]: [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] Oct 30 13:28:20.934599 osdx ulogd[358200]: [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] Oct 30 13:28:20.934611 osdx ulogd[358200]: [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] Oct 30 13:28:21.958663 osdx ulogd[358200]: [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] Oct 30 13:28:21.958700 osdx ulogd[358200]: [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] Oct 30 13:28:21.958713 osdx ulogd[358200]: [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] Oct 30 13:28:22.056338 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal show | cat'. Oct 30 13:28:22.179295 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal show | cat'. Oct 30 13:28:22.294991 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal show | cat'. Oct 30 13:28:22.444901 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:22.515066 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Oct 30 13:28:22.602574 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Oct 30 13:28:22.663601 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show changes'. Oct 30 13:28:22.820718 osdx kernel: app-detect: expression destroy Oct 30 13:28:22.844716 osdx kernel: app-detect: expression init Oct 30 13:28:22.844757 osdx kernel: app-detect: appid cache initialized Oct 30 13:28:22.844773 osdx kernel: app-detect: appid cache changes counter initialized Oct 30 13:28:22.848677 osdx modulelauncher[358252]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 30 13:28:22.864712 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 30 13:28:22.930116 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:22.963339 osdx ulogd[358200]: [DESTROY] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=33709 DPT=53 PKTS=1 BYTES=62 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=33709 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:22.963358 osdx ulogd[358200]: [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] Oct 30 13:28:22.963370 osdx ulogd[358200]: [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] Oct 30 13:28:22.963381 osdx ulogd[358200]: [DESTROY] ORIG: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=45229 DPT=53 PKTS=1 BYTES=62 , REPLY: SRC=127.0.0.1 DST=127.0.0.1 PROTO=UDP SPT=53 DPT=45229 PKTS=0 BYTES=0 APPDETECT[L4:53] Oct 30 13:28:22.964391 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:22.981275 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:23.112419 osdx ulogd[358200]: [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] Oct 30 13:28:23.112579 osdx ulogd[358200]: [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] Oct 30 13:28:23.114327 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Oct 30 13:28:23.246074 osdx file_operation[358354]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Oct 30 13:28:23.249207 osdx ulogd[358200]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=39264 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=39264 PKTS=0 BYTES=0 APPDETECT[L4:80] Oct 30 13:28:23.249428 osdx ulogd[358200]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=39264 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=39264 PKTS=0 BYTES=0 APPDETECT[L4:80] Oct 30 13:28:23.249448 osdx ulogd[358200]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=39264 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=39264 PKTS=0 BYTES=0 APPDETECT[L4:80] Oct 30 13:28:23.250680 osdx ulogd[358200]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=39264 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=39264 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Oct 30 13:28:23.250787 osdx ulogd[358200]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=39264 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=39264 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Oct 30 13:28:23.250807 osdx ulogd[358200]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=39264 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=39264 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Oct 30 13:28:23.269709 osdx OSDxCLI[352274]: 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.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 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
Oct 30 13:28:27.000202 osdx systemd-timedated[355713]: Changed local time to Wed 2024-10-30 13:28:27 UTC Oct 30 13:28:27.001773 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'set date 2024-10-30 13:28:27'. Oct 30 13:28:27.003747 osdx systemd-journald[1923]: Time jumped backwards, rotating. Oct 30 13:28:27.299671 osdx systemd-journald[1923]: Runtime Journal (/run/log/journal/877522c656344df9b9ad28416f5f036f) is 2.0M, max 15.3M, 13.2M free. Oct 30 13:28:27.300105 osdx systemd-journald[1923]: Received client request to rotate journal, rotating. Oct 30 13:28:27.300135 osdx systemd-journald[1923]: Vacuuming done, freed 0B of archived journals from /run/log/journal/877522c656344df9b9ad28416f5f036f. Oct 30 13:28:27.309189 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system journal clear'. Oct 30 13:28:27.643055 osdx osdx-coredump[358510]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 30 13:28:27.651518 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'system coredump delete all'. Oct 30 13:28:28.142102 osdx OSDxCLI[352274]: User 'admin' entered the configuration menu. Oct 30 13:28:28.253212 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. Oct 30 13:28:28.305267 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. Oct 30 13:28:28.403593 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. Oct 30 13:28:28.470347 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. Oct 30 13:28:28.561292 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. Oct 30 13:28:28.617765 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. Oct 30 13:28:28.730995 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. Oct 30 13:28:28.802002 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. Oct 30 13:28:28.884611 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Oct 30 13:28:28.939991 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Oct 30 13:28:29.055191 osdx ERROR[358526]: unexpected Traceback (most recent call last): File "osdx/bin/op/fan_control.py", line 23, in _send_fan_control_cmd FileNotFoundError: [Errno 2] No such file or directory Oct 30 13:28:29.056636 osdx OSDxCLI[352274]: User 'admin' added a new cfg line: 'show working'. Oct 30 13:28:29.315883 osdx kernel: app-detect: module init Oct 30 13:28:29.316000 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 30 13:28:29.316029 osdx kernel: app-detect: expression init Oct 30 13:28:29.316066 osdx kernel: app-detect: appid cache initialized Oct 30 13:28:29.316091 osdx kernel: app-detect: appid cache changes counter initialized Oct 30 13:28:29.387760 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 30 13:28:29.688571 osdx cfgd[1636]: [352274]Completed change to active configuration Oct 30 13:28:29.716973 osdx OSDxCLI[352274]: User 'admin' committed the configuration. Oct 30 13:28:29.742820 osdx OSDxCLI[352274]: User 'admin' left the configuration menu. Oct 30 13:28:29.896709 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Oct 30 13:28:30.033058 osdx file_operation[358692]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Oct 30 13:28:30.035748 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=49260 DF PROTO=TCP SPT=46458 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 30 13:28:30.243758 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=49261 DF PROTO=TCP SPT=46458 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 30 13:28:30.651799 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=49262 DF PROTO=TCP SPT=46458 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 30 13:28:30.744118 osdx zebra[1601]: [RZ3YY-GPH41][EC 100663310] snmp[warning]: Warning: Failed to connect to the agentx master agent ([NIL]): Oct 30 13:28:31.483821 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=49263 DF PROTO=TCP SPT=46458 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 30 13:28:33.034304 osdx file_operation.py[358692]: Operation aborted by user. Oct 30 13:28:33.047768 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=49264 DF PROTO=TCP SPT=46458 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 30 13:28:33.051629 osdx OSDxCLI[352274]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'. Oct 30 13:28:33.115824 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=49265 DF PROTO=TCP SPT=46458 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]