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.307 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.307/0.307/0.307/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.210 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.210/0.210/0.210/0.000 ms
Step 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 07 11:17:14.000371 osdx systemd-timedated[183956]: Changed local time to Mon 2024-10-07 11:17:14 UTC Oct 07 11:17:14.002090 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'set date 2024-10-07 11:17:14'. Oct 07 11:17:14.003632 osdx systemd-journald[115269]: Time jumped backwards, rotating. Oct 07 11:17:14.377291 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.7M, max 15.3M, 12.5M free. Oct 07 11:17:14.383074 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:17:14.383162 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:17:14.415516 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:17:14.812425 osdx osdx-coredump[183973]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:17:14.820421 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:17:15.329139 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:17:15.423877 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:17:15.521014 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. Oct 07 11:17:15.594715 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:17:15.723648 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:15.815948 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:15.819648 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 07 11:17:15.822386 osdx ulogd[184054]: registering plugin `NFCT' Oct 07 11:17:15.823261 osdx ulogd[184054]: registering plugin `IP2STR' Oct 07 11:17:15.823320 osdx ulogd[184054]: registering plugin `PRINTFLOW' Oct 07 11:17:15.824320 osdx ulogd[184054]: registering plugin `SYSLOG' Oct 07 11:17:15.824326 osdx ulogd[184054]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:15.824367 osdx ulogd[184054]: NFCT plugin working in event mode Oct 07 11:17:15.824374 osdx ulogd[184054]: Changing UID / GID Oct 07 11:17:15.824441 osdx ulogd[184054]: initialization finished, entering main loop Oct 07 11:17:15.835726 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:15.838126 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:17:15.840546 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:17:15.866160 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:17:16.832812 osdx ulogd[184054]: [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 07 11:17:16.909211 osdx ulogd[184054]: [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.362 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.362/0.362/0.362/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.286 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.286/0.286/0.286/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 07 11:17:21.345841 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.8M, max 15.3M, 12.4M free. Oct 07 11:17:21.348208 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:17:21.348285 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:17:21.360164 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:17:21.765299 osdx osdx-coredump[184194]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:17:21.772982 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:17:22.261626 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:17:22.359445 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:17:22.452379 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. Oct 07 11:17:22.534149 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:17:22.644241 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:22.708557 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:22.709222 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:22.709427 osdx ulogd[184275]: registering plugin `NFCT' Oct 07 11:17:22.709465 osdx ulogd[184275]: registering plugin `IP2STR' Oct 07 11:17:22.709553 osdx ulogd[184275]: registering plugin `PRINTFLOW' Oct 07 11:17:22.709591 osdx ulogd[184275]: registering plugin `SYSLOG' Oct 07 11:17:22.709594 osdx ulogd[184275]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:22.709634 osdx ulogd[184275]: NFCT plugin working in event mode Oct 07 11:17:22.709640 osdx ulogd[184275]: Changing UID / GID Oct 07 11:17:22.709710 osdx ulogd[184275]: initialization finished, entering main loop Oct 07 11:17:22.711050 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:17:22.713169 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:17:22.728591 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:17:23.577244 osdx ulogd[184275]: [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 07 11:17:23.662115 osdx ulogd[184275]: [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.315 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.315/0.315/0.315/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 3 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.235 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.236 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.272 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2025ms rtt min/avg/max/mdev = 0.235/0.247/0.272/0.017 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 07 11:17:28.316550 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.1M, max 15.3M, 13.2M free. Oct 07 11:17:28.317455 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:17:28.317509 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:17:28.326542 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:17:28.661297 osdx osdx-coredump[184414]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:17:28.668776 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:17:29.200604 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:17:29.281608 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:17:29.397268 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. Oct 07 11:17:29.472486 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 07 11:17:29.621390 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service ssh'. Oct 07 11:17:29.692206 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:17:29.837466 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:29.909779 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:29.910886 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:29.911411 osdx ulogd[184505]: registering plugin `NFCT' Oct 07 11:17:29.911669 osdx ulogd[184505]: registering plugin `IP2STR' Oct 07 11:17:29.911758 osdx ulogd[184505]: registering plugin `PRINTFLOW' Oct 07 11:17:29.911848 osdx ulogd[184505]: registering plugin `SYSLOG' Oct 07 11:17:29.911885 osdx ulogd[184505]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:29.911972 osdx ulogd[184505]: NFCT plugin working in event mode Oct 07 11:17:29.912014 osdx ulogd[184505]: Changing UID / GID Oct 07 11:17:29.912142 osdx ulogd[184505]: initialization finished, entering main loop Oct 07 11:17:29.997812 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Oct 07 11:17:30.010896 osdx sshd[184511]: Server listening on 0.0.0.0 port 22. Oct 07 11:17:30.010919 osdx sshd[184511]: Server listening on :: port 22. Oct 07 11:17:30.011013 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Oct 07 11:17:30.032545 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:17:30.034705 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:17:30.055189 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:17:31.940898 osdx ulogd[184505]: [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 07 11:17:32.964932 osdx ulogd[184505]: [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.538 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.538/0.538/0.538/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.339 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.339/0.339/0.339/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Oct 07 11:17:40.334667 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.3M free. Oct 07 11:17:40.335534 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:17:40.335600 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:17:40.345746 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:17:40.701760 osdx osdx-coredump[184677]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:17:40.710458 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:17:41.215382 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:17:41.338286 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:17:41.422031 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:17:41.535751 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:17:41.627533 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:41.703774 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:41.704636 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 07 11:17:41.707564 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:41.707974 osdx ulogd[184758]: registering plugin `NFCT' Oct 07 11:17:41.708012 osdx ulogd[184758]: registering plugin `IP2STR' Oct 07 11:17:41.708047 osdx ulogd[184758]: registering plugin `PRINTFLOW' Oct 07 11:17:41.708085 osdx ulogd[184758]: registering plugin `SYSLOG' Oct 07 11:17:41.708088 osdx ulogd[184758]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:41.708124 osdx ulogd[184758]: NFCT plugin working in event mode Oct 07 11:17:41.708130 osdx ulogd[184758]: Changing UID / GID Oct 07 11:17:41.708199 osdx ulogd[184758]: initialization finished, entering main loop Oct 07 11:17:41.708997 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:17:41.711030 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:17:41.738481 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:17:42.598954 osdx ulogd[184758]: [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 07 11:17:42.598983 osdx ulogd[184758]: [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 07 11:17:42.682929 osdx ulogd[184758]: [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 07 11:17:42.682955 osdx ulogd[184758]: [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.320 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.320/0.320/0.320/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 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.263 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.217 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1012ms rtt min/avg/max/mdev = 0.217/0.240/0.263/0.023 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*MARK=33.*LABELS=TESTShow output
Oct 07 11:17:47.449747 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.3M free. Oct 07 11:17:47.450466 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:17:47.450516 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:17:47.462655 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:17:47.867588 osdx osdx-coredump[184897]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:17:47.877282 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:17:48.473360 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:17:48.606603 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Oct 07 11:17:48.667374 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic label TEST'. Oct 07 11:17:48.815606 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. Oct 07 11:17:48.923563 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. Oct 07 11:17:49.004617 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:17:49.110404 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:17:49.194666 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:17:49.346467 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:49.442783 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:49.443787 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 07 11:17:49.444153 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:49.445013 osdx ulogd[184988]: registering plugin `NFCT' Oct 07 11:17:49.445054 osdx ulogd[184988]: registering plugin `IP2STR' Oct 07 11:17:49.445092 osdx ulogd[184988]: registering plugin `PRINTFLOW' Oct 07 11:17:49.445131 osdx ulogd[184988]: registering plugin `SYSLOG' Oct 07 11:17:49.445134 osdx ulogd[184988]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:49.445173 osdx ulogd[184988]: NFCT plugin working in event mode Oct 07 11:17:49.445179 osdx ulogd[184988]: Changing UID / GID Oct 07 11:17:49.445245 osdx ulogd[184988]: initialization finished, entering main loop Oct 07 11:17:49.457023 osdx ulogd[184988]: Terminal signal received, exiting Oct 07 11:17:49.457097 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:49.457545 osdx systemd[1]: ulogd2.service: Deactivated successfully. Oct 07 11:17:49.457663 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:49.458704 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:49.459835 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 07 11:17:49.460478 osdx ulogd[184994]: registering plugin `NFCT' Oct 07 11:17:49.460529 osdx ulogd[184994]: registering plugin `IP2STR' Oct 07 11:17:49.460573 osdx ulogd[184994]: registering plugin `PRINTFLOW' Oct 07 11:17:49.460628 osdx ulogd[184994]: registering plugin `SYSLOG' Oct 07 11:17:49.460632 osdx ulogd[184994]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:49.460679 osdx ulogd[184994]: NFCT plugin working in event mode Oct 07 11:17:49.460686 osdx ulogd[184994]: Changing UID / GID Oct 07 11:17:49.460756 osdx ulogd[184994]: initialization finished, entering main loop Oct 07 11:17:49.474643 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:49.675863 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:17:49.678110 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:17:49.696601 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:17:50.710547 osdx ulogd[184994]: [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 07 11:17:50.710571 osdx ulogd[184994]: [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 07 11:17:50.794177 osdx ulogd[184994]: [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 07 11:17:50.794200 osdx ulogd[184994]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 MARK=33
VRF logging
Description
Set a simple configuration with a vrf,
send a ping command from one device to other
and check that default and vrf fields appear when running system journal show.
Scenario
Step 1: Set the following configuration in DUT0:
set interfaces ethernet eth0 address 192.168.100.1/24 set interfaces ethernet eth0 vrf RED set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2 set system conntrack logging events all set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0' set system vrf RED
Step 2: Set the following configuration in DUT1:
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.314 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.314/0.314/0.314/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.244 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.244/0.244/0.244/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 07 11:17:57.350656 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.3M free. Oct 07 11:17:57.352780 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:17:57.352841 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:17:57.362460 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:17:57.733670 osdx osdx-coredump[185176]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:17:57.741229 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:17:58.245215 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:17:58.358725 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. Oct 07 11:17:58.434346 osdx OSDxCLI[173468]: 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 07 11:17:58.525016 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system vrf RED'. Oct 07 11:17:58.582614 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:17:58.680922 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:17:58.752099 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:17:58.869159 osdx (udev-worker)[185212]: RED: Could not disable auto negotiation, ignoring: Operation not supported Oct 07 11:17:58.869385 osdx (udev-worker)[185212]: Network interface NamePolicy= disabled on kernel command line. Oct 07 11:17:58.892782 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:58.928791 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:17:59.028996 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:17:59.029843 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:17:59.030163 osdx ulogd[185290]: registering plugin `NFCT' Oct 07 11:17:59.030329 osdx ulogd[185290]: registering plugin `IP2STR' Oct 07 11:17:59.030385 osdx ulogd[185290]: registering plugin `PRINTFLOW' Oct 07 11:17:59.030441 osdx ulogd[185290]: registering plugin `SYSLOG' Oct 07 11:17:59.030462 osdx ulogd[185290]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:17:59.030517 osdx ulogd[185290]: NFCT plugin working in event mode Oct 07 11:17:59.030540 osdx ulogd[185290]: Changing UID / GID Oct 07 11:17:59.030625 osdx ulogd[185290]: initialization finished, entering main loop Oct 07 11:17:59.031773 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:17:59.064413 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:17:59.079743 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:17:59.894639 osdx ulogd[185290]: [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 07 11:17:59.894662 osdx ulogd[185290]: [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 07 11:18:00.015610 osdx ulogd[185290]: [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 07 11:18:00.015639 osdx ulogd[185290]: [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.181 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.181/0.181/0.181/0.000 ms
Step 3: Run command file copy http://10.215.168.1/~robot/test-performance.rules running:// force at DUT0 and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 129 100 129 0 0 4404 0 --:--:-- --:--:-- --:--:-- 4448
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.489 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.489/0.489/0.489/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.397 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.397/0.397/0.397/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 07 11:18:07.333277 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.2M free. Oct 07 11:18:07.336332 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:07.336410 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:07.345296 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:07.734588 osdx osdx-coredump[185475]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:07.743185 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:08.217028 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:08.296665 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Oct 07 11:18:08.404584 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:08.504308 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 07 11:18:08.541479 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:08.543647 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:08.563910 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:08.729396 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Oct 07 11:18:08.860998 osdx file_operation[185579]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// Oct 07 11:18:08.909208 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. Oct 07 11:18:09.057057 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:09.127117 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Oct 07 11:18:09.214917 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. Oct 07 11:18:09.271378 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file 'running://test-performance.rules''. Oct 07 11:18:09.370386 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. Oct 07 11:18:09.430673 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. Oct 07 11:18:09.530542 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. Oct 07 11:18:09.617555 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. Oct 07 11:18:09.717003 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. Oct 07 11:18:09.807112 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. Oct 07 11:18:09.871400 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:18:09.975786 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:18:10.070830 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:10.228307 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:18:10.284623 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:10.285401 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 07 11:18:10.285818 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:10.286764 osdx ulogd[185686]: registering plugin `NFCT' Oct 07 11:18:10.286805 osdx ulogd[185686]: registering plugin `IP2STR' Oct 07 11:18:10.286842 osdx ulogd[185686]: registering plugin `PRINTFLOW' Oct 07 11:18:10.286881 osdx ulogd[185686]: registering plugin `SYSLOG' Oct 07 11:18:10.286885 osdx ulogd[185686]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:10.286926 osdx ulogd[185686]: NFCT plugin working in event mode Oct 07 11:18:10.286933 osdx ulogd[185686]: Changing UID / GID Oct 07 11:18:10.286997 osdx ulogd[185686]: initialization finished, entering main loop Oct 07 11:18:10.539378 osdx systemd[1]: Reloading. Oct 07 11:18:10.660324 osdx systemd-sysv-generator[185724]: stat() failed on /etc/init.d/README, ignoring: No such file or directory Oct 07 11:18:10.800951 osdx systemd[1]: Starting logrotate.service - Rotate log files... Oct 07 11:18:10.806914 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata. Oct 07 11:18:10.808303 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... Oct 07 11:18:10.826996 osdx systemd[1]: logrotate.service: Deactivated successfully. Oct 07 11:18:10.827140 osdx systemd[1]: Finished logrotate.service - Rotate log files. Oct 07 11:18:11.117860 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. Oct 07 11:18:11.566025 osdx INFO[185705]: Rules successfully loaded Oct 07 11:18:11.580083 osdx ulogd[185686]: Terminal signal received, exiting Oct 07 11:18:11.580087 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:11.580606 osdx systemd[1]: ulogd2.service: Deactivated successfully. Oct 07 11:18:11.580698 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:11.612673 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:11.613533 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Oct 07 11:18:11.614101 osdx ulogd[185752]: registering plugin `NFCT' Oct 07 11:18:11.614139 osdx ulogd[185752]: registering plugin `IP2STR' Oct 07 11:18:11.614176 osdx ulogd[185752]: registering plugin `PRINTFLOW' Oct 07 11:18:11.614217 osdx ulogd[185752]: registering plugin `SYSLOG' Oct 07 11:18:11.614220 osdx ulogd[185752]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:11.614258 osdx ulogd[185752]: NFCT plugin working in event mode Oct 07 11:18:11.614265 osdx ulogd[185752]: Changing UID / GID Oct 07 11:18:11.614328 osdx ulogd[185752]: initialization finished, entering main loop Oct 07 11:18:11.628359 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:11.631161 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:11.633213 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:11.652922 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:12.561638 osdx ulogd[185752]: [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 07 11:18:12.561654 osdx ulogd[185752]: [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 07 11:18:12.663709 osdx ulogd[185752]: [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 07 11:18:12.663730 osdx ulogd[185752]: [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.351 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.351/0.351/0.351/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.403 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.403/0.403/0.403/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.0 This system includes free software. Contact Teldat for licenses information and source code. Last login: Mon Oct 7 11:06:46 2024 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 07 11:18:20.315797 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.3M free. Oct 07 11:18:20.319716 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:20.319774 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:20.327585 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:20.692771 osdx osdx-coredump[185959]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:20.701834 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:21.183015 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:21.267726 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. Oct 07 11:18:21.368954 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:18:21.433931 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:18:21.552584 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:21.663737 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 07 11:18:21.707730 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:18:21.788102 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:21.788989 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:21.789201 osdx ulogd[186089]: registering plugin `NFCT' Oct 07 11:18:21.789259 osdx ulogd[186089]: registering plugin `IP2STR' Oct 07 11:18:21.789315 osdx ulogd[186089]: registering plugin `PRINTFLOW' Oct 07 11:18:21.789378 osdx ulogd[186089]: registering plugin `SYSLOG' Oct 07 11:18:21.789385 osdx ulogd[186089]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:21.789437 osdx ulogd[186089]: NFCT plugin working in event mode Oct 07 11:18:21.789445 osdx ulogd[186089]: Changing UID / GID Oct 07 11:18:21.789530 osdx ulogd[186089]: initialization finished, entering main loop Oct 07 11:18:21.791574 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:21.793723 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:21.816425 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:23.594766 osdx ulogd[186089]: [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 07 11:18:23.594789 osdx ulogd[186089]: [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 07 11:18:23.683142 osdx ulogd[186089]: [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 07 11:18:23.683169 osdx ulogd[186089]: [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 07 11:18:23.757818 osdx ulogd[186089]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=54914 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=54914 PKTS=0 BYTES=0 Oct 07 11:18:23.758013 osdx ulogd[186089]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=54914 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=54914 PKTS=0 BYTES=0 Oct 07 11:18:23.758150 osdx ulogd[186089]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=54914 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=54914 PKTS=0 BYTES=0 [OFFLOAD] Oct 07 11:18:24.039519 osdx ulogd[186089]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=54914 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=54914 PKTS=0 BYTES=0 Oct 07 11:18:24.040665 osdx ulogd[186089]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=54914 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=54914 PKTS=0 BYTES=0 Oct 07 11:18:24.040782 osdx ulogd[186089]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=54914 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=54914 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.371 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.371/0.371/0.371/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.268 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.289 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.384 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2053ms rtt min/avg/max/mdev = 0.268/0.313/0.384/0.050 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 07 11:18:28.338418 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.2M free. Oct 07 11:18:28.341807 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:28.341890 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:28.349977 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:28.728877 osdx osdx-coredump[186232]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:28.736104 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:29.189656 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:29.248435 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 07 11:18:29.345786 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 07 11:18:29.431754 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:18:29.530084 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:18:29.622801 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:29.877810 osdx kernel: app-detect: module init Oct 07 11:18:29.877854 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 07 11:18:29.877869 osdx kernel: app-detect: expression init Oct 07 11:18:29.877881 osdx kernel: app-detect: appid cache initialized Oct 07 11:18:29.877889 osdx kernel: app-detect: appid cache changes counter initialized Oct 07 11:18:29.885043 osdx modulelauncher[186256]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 07 11:18:29.909811 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:18:29.998140 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:29.999434 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:30.000517 osdx ulogd[186338]: registering plugin `NFCT' Oct 07 11:18:30.000556 osdx ulogd[186338]: registering plugin `IP2STR' Oct 07 11:18:30.000882 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:30.001643 osdx ulogd[186338]: registering plugin `PRINTFLOW' Oct 07 11:18:30.001688 osdx ulogd[186338]: registering plugin `SYSLOG' Oct 07 11:18:30.001691 osdx ulogd[186338]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:30.001731 osdx ulogd[186338]: NFCT plugin working in event mode Oct 07 11:18:30.001737 osdx ulogd[186338]: Changing UID / GID Oct 07 11:18:30.001820 osdx ulogd[186338]: initialization finished, entering main loop Oct 07 11:18:30.003004 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:30.025054 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:30.843514 osdx ulogd[186338]: [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 07 11:18:30.843538 osdx ulogd[186338]: [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 07 11:18:30.932658 osdx ulogd[186338]: [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 07 11:18:30.932684 osdx ulogd[186338]: [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 07 11:18:31.961220 osdx ulogd[186338]: [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 07 11:18:31.961239 osdx ulogd[186338]: [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 07 11:18:31.961251 osdx ulogd[186338]: [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 07 11:18:32.985291 osdx ulogd[186338]: [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 07 11:18:32.985314 osdx ulogd[186338]: [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 07 11:18:32.985328 osdx ulogd[186338]: [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 07 11:18:28.338418 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.2M free. Oct 07 11:18:28.341807 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:28.341890 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:28.349977 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:28.728877 osdx osdx-coredump[186232]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:28.736104 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:29.189656 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:29.248435 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 07 11:18:29.345786 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 07 11:18:29.431754 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:18:29.530084 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:18:29.622801 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:29.877810 osdx kernel: app-detect: module init Oct 07 11:18:29.877854 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 07 11:18:29.877869 osdx kernel: app-detect: expression init Oct 07 11:18:29.877881 osdx kernel: app-detect: appid cache initialized Oct 07 11:18:29.877889 osdx kernel: app-detect: appid cache changes counter initialized Oct 07 11:18:29.885043 osdx modulelauncher[186256]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 07 11:18:29.909811 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:18:29.998140 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:29.999434 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:30.000517 osdx ulogd[186338]: registering plugin `NFCT' Oct 07 11:18:30.000556 osdx ulogd[186338]: registering plugin `IP2STR' Oct 07 11:18:30.000882 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:30.001643 osdx ulogd[186338]: registering plugin `PRINTFLOW' Oct 07 11:18:30.001688 osdx ulogd[186338]: registering plugin `SYSLOG' Oct 07 11:18:30.001691 osdx ulogd[186338]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:30.001731 osdx ulogd[186338]: NFCT plugin working in event mode Oct 07 11:18:30.001737 osdx ulogd[186338]: Changing UID / GID Oct 07 11:18:30.001820 osdx ulogd[186338]: initialization finished, entering main loop Oct 07 11:18:30.003004 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:30.025054 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:30.843514 osdx ulogd[186338]: [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 07 11:18:30.843538 osdx ulogd[186338]: [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 07 11:18:30.932658 osdx ulogd[186338]: [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 07 11:18:30.932684 osdx ulogd[186338]: [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 07 11:18:31.961220 osdx ulogd[186338]: [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 07 11:18:31.961239 osdx ulogd[186338]: [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 07 11:18:31.961251 osdx ulogd[186338]: [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 07 11:18:32.985291 osdx ulogd[186338]: [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 07 11:18:32.985314 osdx ulogd[186338]: [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 07 11:18:32.985328 osdx ulogd[186338]: [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 07 11:18:33.099653 osdx OSDxCLI[173468]: 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 07 11:18:28.338418 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.2M free. Oct 07 11:18:28.341807 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:28.341890 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:28.349977 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:28.728877 osdx osdx-coredump[186232]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:28.736104 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:29.189656 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:29.248435 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 07 11:18:29.345786 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 07 11:18:29.431754 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:18:29.530084 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:18:29.622801 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:29.877810 osdx kernel: app-detect: module init Oct 07 11:18:29.877854 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 07 11:18:29.877869 osdx kernel: app-detect: expression init Oct 07 11:18:29.877881 osdx kernel: app-detect: appid cache initialized Oct 07 11:18:29.877889 osdx kernel: app-detect: appid cache changes counter initialized Oct 07 11:18:29.885043 osdx modulelauncher[186256]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 07 11:18:29.909811 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:18:29.998140 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:29.999434 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:30.000517 osdx ulogd[186338]: registering plugin `NFCT' Oct 07 11:18:30.000556 osdx ulogd[186338]: registering plugin `IP2STR' Oct 07 11:18:30.000882 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:30.001643 osdx ulogd[186338]: registering plugin `PRINTFLOW' Oct 07 11:18:30.001688 osdx ulogd[186338]: registering plugin `SYSLOG' Oct 07 11:18:30.001691 osdx ulogd[186338]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:30.001731 osdx ulogd[186338]: NFCT plugin working in event mode Oct 07 11:18:30.001737 osdx ulogd[186338]: Changing UID / GID Oct 07 11:18:30.001820 osdx ulogd[186338]: initialization finished, entering main loop Oct 07 11:18:30.003004 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:30.025054 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:30.843514 osdx ulogd[186338]: [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 07 11:18:30.843538 osdx ulogd[186338]: [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 07 11:18:30.932658 osdx ulogd[186338]: [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 07 11:18:30.932684 osdx ulogd[186338]: [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 07 11:18:31.961220 osdx ulogd[186338]: [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 07 11:18:31.961239 osdx ulogd[186338]: [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 07 11:18:31.961251 osdx ulogd[186338]: [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 07 11:18:32.985291 osdx ulogd[186338]: [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 07 11:18:32.985314 osdx ulogd[186338]: [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 07 11:18:32.985328 osdx ulogd[186338]: [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 07 11:18:33.099653 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal show | cat'. Oct 07 11:18:33.232265 osdx OSDxCLI[173468]: 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.259 ms --- 10.215.168.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 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:
Show output
% Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 100 972 0 972 0 0 29897 0 --:--:-- --:--:-- --:--:-- 30375
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 07 11:18:28.338418 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.2M free. Oct 07 11:18:28.341807 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:28.341890 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:28.349977 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:28.728877 osdx osdx-coredump[186232]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:28.736104 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:29.189656 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:29.248435 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Oct 07 11:18:29.345786 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Oct 07 11:18:29.431754 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Oct 07 11:18:29.530084 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Oct 07 11:18:29.622801 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:29.877810 osdx kernel: app-detect: module init Oct 07 11:18:29.877854 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 07 11:18:29.877869 osdx kernel: app-detect: expression init Oct 07 11:18:29.877881 osdx kernel: app-detect: appid cache initialized Oct 07 11:18:29.877889 osdx kernel: app-detect: appid cache changes counter initialized Oct 07 11:18:29.885043 osdx modulelauncher[186256]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 07 11:18:29.909811 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Oct 07 11:18:29.998140 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Oct 07 11:18:29.999434 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Oct 07 11:18:30.000517 osdx ulogd[186338]: registering plugin `NFCT' Oct 07 11:18:30.000556 osdx ulogd[186338]: registering plugin `IP2STR' Oct 07 11:18:30.000882 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:30.001643 osdx ulogd[186338]: registering plugin `PRINTFLOW' Oct 07 11:18:30.001688 osdx ulogd[186338]: registering plugin `SYSLOG' Oct 07 11:18:30.001691 osdx ulogd[186338]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Oct 07 11:18:30.001731 osdx ulogd[186338]: NFCT plugin working in event mode Oct 07 11:18:30.001737 osdx ulogd[186338]: Changing UID / GID Oct 07 11:18:30.001820 osdx ulogd[186338]: initialization finished, entering main loop Oct 07 11:18:30.003004 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:30.025054 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:30.843514 osdx ulogd[186338]: [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 07 11:18:30.843538 osdx ulogd[186338]: [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 07 11:18:30.932658 osdx ulogd[186338]: [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 07 11:18:30.932684 osdx ulogd[186338]: [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 07 11:18:31.961220 osdx ulogd[186338]: [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 07 11:18:31.961239 osdx ulogd[186338]: [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 07 11:18:31.961251 osdx ulogd[186338]: [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 07 11:18:32.985291 osdx ulogd[186338]: [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 07 11:18:32.985314 osdx ulogd[186338]: [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 07 11:18:32.985328 osdx ulogd[186338]: [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 07 11:18:33.099653 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal show | cat'. Oct 07 11:18:33.232265 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal show | cat'. Oct 07 11:18:33.380379 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal show | cat'. Oct 07 11:18:33.631705 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:33.766341 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Oct 07 11:18:33.862671 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Oct 07 11:18:33.971389 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show changes'. Oct 07 11:18:34.089818 osdx kernel: app-detect: expression destroy Oct 07 11:18:34.121818 osdx kernel: app-detect: expression init Oct 07 11:18:34.121882 osdx kernel: app-detect: appid cache initialized Oct 07 11:18:34.121896 osdx kernel: app-detect: appid cache changes counter initialized Oct 07 11:18:34.128538 osdx modulelauncher[186388]: AppDetect: no change in application dictionaries, thus nothing more to do Oct 07 11:18:34.153807 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 07 11:18:34.189146 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:34.190733 osdx ulogd[186338]: [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 07 11:18:34.190753 osdx ulogd[186338]: [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 07 11:18:34.191558 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:34.214041 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:34.361925 osdx ulogd[186338]: [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 07 11:18:34.362127 osdx ulogd[186338]: [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 07 11:18:34.363923 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Oct 07 11:18:34.500674 osdx file_operation[186484]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Oct 07 11:18:34.503400 osdx ulogd[186338]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=56136 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=56136 PKTS=0 BYTES=0 APPDETECT[L4:80] Oct 07 11:18:34.503520 osdx ulogd[186338]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=56136 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=56136 PKTS=0 BYTES=0 APPDETECT[L4:80] Oct 07 11:18:34.503540 osdx ulogd[186338]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=56136 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=56136 PKTS=0 BYTES=0 APPDETECT[L4:80] Oct 07 11:18:34.534415 osdx ulogd[186338]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=56136 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=56136 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Oct 07 11:18:34.534438 osdx ulogd[186338]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=56136 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=56136 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Oct 07 11:18:34.534452 osdx ulogd[186338]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=56136 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=56136 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Oct 07 11:18:34.551834 osdx OSDxCLI[173468]: 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.228 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.228/0.228/0.228/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 07 11:18:40.353028 osdx systemd-journald[115269]: Runtime Journal (/run/log/journal/ea320b11e8924984abe0660bdd8d3fcc) is 2.0M, max 15.3M, 13.3M free. Oct 07 11:18:40.354639 osdx systemd-journald[115269]: Received client request to rotate journal, rotating. Oct 07 11:18:40.354710 osdx systemd-journald[115269]: Vacuuming done, freed 0B of archived journals from /run/log/journal/ea320b11e8924984abe0660bdd8d3fcc. Oct 07 11:18:40.363043 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system journal clear'. Oct 07 11:18:40.783160 osdx osdx-coredump[186630]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Oct 07 11:18:40.792982 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'system coredump delete all'. Oct 07 11:18:41.376648 osdx OSDxCLI[173468]: User 'admin' entered the configuration menu. Oct 07 11:18:41.461260 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. Oct 07 11:18:41.563486 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. Oct 07 11:18:41.665305 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. Oct 07 11:18:41.743587 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. Oct 07 11:18:41.857216 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. Oct 07 11:18:41.939653 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. Oct 07 11:18:42.033907 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. Oct 07 11:18:42.192079 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. Oct 07 11:18:42.274052 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Oct 07 11:18:42.347124 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Oct 07 11:18:42.444037 osdx OSDxCLI[173468]: User 'admin' added a new cfg line: 'show working'. Oct 07 11:18:42.722633 osdx kernel: app-detect: module init Oct 07 11:18:42.722690 osdx kernel: app-detect: registered: sysctl net.appdetect Oct 07 11:18:42.722706 osdx kernel: app-detect: expression init Oct 07 11:18:42.722718 osdx kernel: app-detect: appid cache initialized Oct 07 11:18:42.722730 osdx kernel: app-detect: appid cache changes counter initialized Oct 07 11:18:42.762664 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Oct 07 11:18:42.983680 osdx cfgd[1439]: [173468]Completed change to active configuration Oct 07 11:18:42.985692 osdx OSDxCLI[173468]: User 'admin' committed the configuration. Oct 07 11:18:43.007752 osdx OSDxCLI[173468]: User 'admin' left the configuration menu. Oct 07 11:18:43.144463 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Oct 07 11:18:43.316153 osdx file_operation[186806]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Oct 07 11:18:43.322640 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=28531 DF PROTO=TCP SPT=55244 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 07 11:18:43.526689 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=28532 DF PROTO=TCP SPT=55244 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 07 11:18:43.938697 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=28533 DF PROTO=TCP SPT=55244 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 07 11:18:44.770690 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=28534 DF PROTO=TCP SPT=55244 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 07 11:18:46.270472 osdx file_operation.py[186806]: Operation aborted by user. Oct 07 11:18:46.282643 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=28535 DF PROTO=TCP SPT=55244 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Oct 07 11:18:46.285925 osdx OSDxCLI[173468]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.