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.484 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.484/0.484/0.484/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.318 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.318/0.318/0.318/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
Feb 03 14:41:34.412569 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:41:34.415835 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:41:34.415965 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:41:34.429354 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:41:34.961284 osdx osdx-coredump[405906]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:41:34.975857 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:41:35.751695 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:41:35.881163 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:41:35.993472 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. Feb 03 14:41:36.146690 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:41:36.242691 osdx INFO[405927]: FRR daemons did not change Feb 03 14:41:36.271868 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:41:36.416478 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:41:36.419513 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:41:36.421977 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:41:36.422557 osdx ulogd[405993]: registering plugin `NFCT' Feb 03 14:41:36.423585 osdx ulogd[405993]: registering plugin `IP2STR' Feb 03 14:41:36.423676 osdx ulogd[405993]: registering plugin `PRINTFLOW' Feb 03 14:41:36.424917 osdx ulogd[405993]: registering plugin `SYSLOG' Feb 03 14:41:36.424926 osdx ulogd[405993]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:41:36.424992 osdx ulogd[405993]: NFCT plugin working in event mode Feb 03 14:41:36.425002 osdx ulogd[405993]: Changing UID / GID Feb 03 14:41:36.425093 osdx ulogd[405993]: initialization finished, entering main loop Feb 03 14:41:36.469342 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:41:36.495416 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:41:37.711076 osdx ulogd[405993]: [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 Feb 03 14:41:37.836934 osdx ulogd[405993]: [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.618 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.618/0.618/0.618/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.356 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.356/0.356/0.356/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
Feb 03 14:41:43.392978 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.3M free. Feb 03 14:41:43.394166 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:41:43.394245 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:41:43.409083 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:41:43.949829 osdx osdx-coredump[406143]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:41:43.961521 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:41:44.719951 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:41:44.866161 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:41:44.999454 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. Feb 03 14:41:45.155585 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:41:45.281869 osdx INFO[406164]: FRR daemons did not change Feb 03 14:41:45.314169 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:41:45.454798 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:41:45.456069 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:41:45.456268 osdx ulogd[406230]: registering plugin `NFCT' Feb 03 14:41:45.456373 osdx ulogd[406230]: registering plugin `IP2STR' Feb 03 14:41:45.456448 osdx ulogd[406230]: registering plugin `PRINTFLOW' Feb 03 14:41:45.456523 osdx ulogd[406230]: registering plugin `SYSLOG' Feb 03 14:41:45.456528 osdx ulogd[406230]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:41:45.456582 osdx ulogd[406230]: NFCT plugin working in event mode Feb 03 14:41:45.456591 osdx ulogd[406230]: Changing UID / GID Feb 03 14:41:45.456682 osdx ulogd[406230]: initialization finished, entering main loop Feb 03 14:41:45.459178 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:41:45.498185 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:41:45.526001 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:41:46.697707 osdx ulogd[406230]: [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 Feb 03 14:41:46.826211 osdx ulogd[406230]: [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.464 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.464/0.464/0.464/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.310 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.355 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.397 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2012ms rtt min/avg/max/mdev = 0.310/0.354/0.397/0.035 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
Feb 03 14:41:53.410641 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.3M free. Feb 03 14:41:53.411452 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:41:53.411517 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:41:53.427716 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:41:54.016234 osdx osdx-coredump[406382]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:41:54.030417 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:41:54.811937 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:41:54.943062 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:41:55.069676 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. Feb 03 14:41:55.247917 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Feb 03 14:41:55.429479 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service ssh'. Feb 03 14:41:55.611311 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:41:55.813635 osdx INFO[406411]: FRR daemons did not change Feb 03 14:41:55.847367 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:41:55.991799 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:41:55.992940 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:41:55.993136 osdx ulogd[406479]: registering plugin `NFCT' Feb 03 14:41:55.993221 osdx ulogd[406479]: registering plugin `IP2STR' Feb 03 14:41:55.993307 osdx ulogd[406479]: registering plugin `PRINTFLOW' Feb 03 14:41:55.993394 osdx ulogd[406479]: registering plugin `SYSLOG' Feb 03 14:41:55.993400 osdx ulogd[406479]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:41:55.993491 osdx ulogd[406479]: NFCT plugin working in event mode Feb 03 14:41:55.993509 osdx ulogd[406479]: Changing UID / GID Feb 03 14:41:55.993633 osdx ulogd[406479]: initialization finished, entering main loop Feb 03 14:41:56.107834 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Feb 03 14:41:56.128455 osdx sshd[406485]: Server listening on 0.0.0.0 port 22. Feb 03 14:41:56.128807 osdx sshd[406485]: Server listening on :: port 22. Feb 03 14:41:56.129012 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Feb 03 14:41:56.165030 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:41:56.202886 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:41:56.234622 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:41:58.723572 osdx ulogd[406479]: [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 Feb 03 14:41:59.723971 osdx ulogd[406479]: [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.495 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.495/0.495/0.495/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.284 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.284/0.284/0.284/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
Feb 03 14:42:08.485672 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:42:08.487739 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:42:08.487853 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:42:08.507602 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:42:09.046323 osdx osdx-coredump[406663]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:42:09.060561 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:42:09.794757 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:42:09.914630 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:42:10.023587 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:42:10.149198 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:42:10.264102 osdx INFO[406684]: FRR daemons did not change Feb 03 14:42:10.291745 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:42:10.432158 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:10.433417 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:42:10.433911 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:10.435099 osdx ulogd[406750]: registering plugin `NFCT' Feb 03 14:42:10.435187 osdx ulogd[406750]: registering plugin `IP2STR' Feb 03 14:42:10.435272 osdx ulogd[406750]: registering plugin `PRINTFLOW' Feb 03 14:42:10.435360 osdx ulogd[406750]: registering plugin `SYSLOG' Feb 03 14:42:10.435366 osdx ulogd[406750]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:10.435440 osdx ulogd[406750]: NFCT plugin working in event mode Feb 03 14:42:10.435453 osdx ulogd[406750]: Changing UID / GID Feb 03 14:42:10.435571 osdx ulogd[406750]: initialization finished, entering main loop Feb 03 14:42:10.435698 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:42:10.472339 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:42:10.498315 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:42:11.832681 osdx ulogd[406750]: [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 Feb 03 14:42:11.832726 osdx ulogd[406750]: [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 Feb 03 14:42:11.949047 osdx ulogd[406750]: [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 Feb 03 14:42:11.949074 osdx ulogd[406750]: [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.527 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.527/0.527/0.527/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.345 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.273 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1019ms rtt min/avg/max/mdev = 0.273/0.309/0.345/0.036 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
Feb 03 14:42:18.408165 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.3M free. Feb 03 14:42:18.410077 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:42:18.410190 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:42:18.426444 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:42:18.979290 osdx osdx-coredump[406900]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:42:18.989699 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:42:19.702376 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:42:19.863249 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Feb 03 14:42:19.954425 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic label TEST'. Feb 03 14:42:20.076960 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. Feb 03 14:42:20.229314 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. Feb 03 14:42:20.374601 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:42:20.482956 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:42:20.621115 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:42:20.783465 osdx INFO[406931]: FRR daemons did not change Feb 03 14:42:20.814042 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:42:20.970547 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:20.972087 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:42:20.973107 osdx ulogd[406997]: registering plugin `NFCT' Feb 03 14:42:20.973208 osdx ulogd[406997]: registering plugin `IP2STR' Feb 03 14:42:20.973289 osdx ulogd[406997]: registering plugin `PRINTFLOW' Feb 03 14:42:20.973375 osdx ulogd[406997]: registering plugin `SYSLOG' Feb 03 14:42:20.973381 osdx ulogd[406997]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:20.973463 osdx ulogd[406997]: NFCT plugin working in event mode Feb 03 14:42:20.973475 osdx ulogd[406997]: Changing UID / GID Feb 03 14:42:20.973590 osdx ulogd[406997]: initialization finished, entering main loop Feb 03 14:42:20.990077 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:21.005779 osdx ulogd[406997]: Terminal signal received, exiting Feb 03 14:42:21.005872 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:21.006653 osdx systemd[1]: ulogd2.service: Deactivated successfully. Feb 03 14:42:21.006926 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:21.008550 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:21.009537 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:42:21.014121 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:21.014565 osdx ulogd[407003]: registering plugin `NFCT' Feb 03 14:42:21.014669 osdx ulogd[407003]: registering plugin `IP2STR' Feb 03 14:42:21.014756 osdx ulogd[407003]: registering plugin `PRINTFLOW' Feb 03 14:42:21.014869 osdx ulogd[407003]: registering plugin `SYSLOG' Feb 03 14:42:21.014876 osdx ulogd[407003]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:21.014950 osdx ulogd[407003]: NFCT plugin working in event mode Feb 03 14:42:21.014962 osdx ulogd[407003]: Changing UID / GID Feb 03 14:42:21.015083 osdx ulogd[407003]: initialization finished, entering main loop Feb 03 14:42:21.203305 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:42:21.242794 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:42:21.279841 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:42:22.498428 osdx ulogd[407003]: [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 Feb 03 14:42:22.498453 osdx ulogd[407003]: [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 Feb 03 14:42:22.623015 osdx ulogd[407003]: [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 Feb 03 14:42:22.623042 osdx ulogd[407003]: [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.430 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.430/0.430/0.430/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.302 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.302/0.302/0.302/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
Feb 03 14:42:30.386677 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.3M free. Feb 03 14:42:30.388902 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:42:30.388972 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:42:30.404206 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:42:30.866050 osdx osdx-coredump[407195]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:42:30.877055 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:42:31.553418 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:42:31.674132 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. Feb 03 14:42:31.791938 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. Feb 03 14:42:31.912162 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system vrf RED'. Feb 03 14:42:32.018788 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:42:32.141740 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:42:32.278983 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:42:32.407258 osdx INFO[407219]: FRR daemons did not change Feb 03 14:42:32.429133 osdx (udev-worker)[407232]: RED: Could not disable auto negotiation, ignoring: Operation not supported Feb 03 14:42:32.429524 osdx (udev-worker)[407232]: Network interface NamePolicy= disabled on kernel command line. Feb 03 14:42:32.460903 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:42:32.568937 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:42:32.721554 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:32.722568 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:32.722896 osdx ulogd[407338]: registering plugin `NFCT' Feb 03 14:42:32.723055 osdx ulogd[407338]: registering plugin `IP2STR' Feb 03 14:42:32.723138 osdx ulogd[407338]: registering plugin `PRINTFLOW' Feb 03 14:42:32.723230 osdx ulogd[407338]: registering plugin `SYSLOG' Feb 03 14:42:32.723240 osdx ulogd[407338]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:32.723937 osdx ulogd[407338]: NFCT plugin working in event mode Feb 03 14:42:32.723952 osdx ulogd[407338]: Changing UID / GID Feb 03 14:42:32.724074 osdx ulogd[407338]: initialization finished, entering main loop Feb 03 14:42:32.724731 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:42:32.762938 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:42:32.805676 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:42:33.953447 osdx ulogd[407338]: [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 Feb 03 14:42:33.953484 osdx ulogd[407338]: [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 Feb 03 14:42:34.074028 osdx ulogd[407338]: [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 Feb 03 14:42:34.074067 osdx ulogd[407338]: [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.314 ms --- 10.215.168.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 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 20273 0 --:--:-- --:--:-- --:--:-- 21500
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.727 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.727/0.727/0.727/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.370 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.370/0.370/0.370/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
Feb 03 14:42:40.386081 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:42:40.388257 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:42:40.388349 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:42:40.403205 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:42:40.878940 osdx osdx-coredump[407548]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:42:40.890484 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:42:41.644297 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:42:41.774190 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Feb 03 14:42:41.906434 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:42:42.049124 osdx INFO[407568]: FRR daemons did not change Feb 03 14:42:42.072344 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Feb 03 14:42:42.175645 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:42:42.222190 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:42:42.281642 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:42:42.527122 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Feb 03 14:42:42.755959 osdx file_operation[407660]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// Feb 03 14:42:42.794720 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. Feb 03 14:42:43.003918 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:42:43.137036 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Feb 03 14:42:43.249485 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. Feb 03 14:42:43.397804 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'. Feb 03 14:42:43.491754 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. Feb 03 14:42:43.602902 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. Feb 03 14:42:43.748043 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. Feb 03 14:42:43.865660 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. Feb 03 14:42:43.997129 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. Feb 03 14:42:44.136737 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. Feb 03 14:42:44.259289 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:42:44.381826 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:42:44.532477 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:42:44.729620 osdx INFO[407707]: FRR daemons did not change Feb 03 14:42:44.760242 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:42:44.928992 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:44.930053 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:44.930150 osdx ulogd[407773]: registering plugin `NFCT' Feb 03 14:42:44.930251 osdx ulogd[407773]: registering plugin `IP2STR' Feb 03 14:42:44.930320 osdx ulogd[407773]: registering plugin `PRINTFLOW' Feb 03 14:42:44.930402 osdx ulogd[407773]: registering plugin `SYSLOG' Feb 03 14:42:44.930408 osdx ulogd[407773]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:44.930490 osdx ulogd[407773]: NFCT plugin working in event mode Feb 03 14:42:44.930502 osdx ulogd[407773]: Changing UID / GID Feb 03 14:42:44.930604 osdx ulogd[407773]: initialization finished, entering main loop Feb 03 14:42:45.143304 osdx systemd[1]: Reloading. Feb 03 14:42:45.352236 osdx systemd-sysv-generator[407807]: stat() failed on /etc/init.d/README, ignoring: No such file or directory Feb 03 14:42:45.545101 osdx systemd[1]: Starting logrotate.service - Rotate log files... Feb 03 14:42:45.552665 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... Feb 03 14:42:45.584682 osdx systemd[1]: logrotate.service: Deactivated successfully. Feb 03 14:42:45.584931 osdx systemd[1]: Finished logrotate.service - Rotate log files. Feb 03 14:42:45.587451 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. Feb 03 14:42:45.989771 osdx INFO[407788]: Rules successfully loaded Feb 03 14:42:46.009375 osdx ulogd[407773]: Terminal signal received, exiting Feb 03 14:42:46.009537 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:46.010035 osdx systemd[1]: ulogd2.service: Deactivated successfully. Feb 03 14:42:46.010214 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:46.044928 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:46.046369 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:46.047377 osdx ulogd[407835]: registering plugin `NFCT' Feb 03 14:42:46.047451 osdx ulogd[407835]: registering plugin `IP2STR' Feb 03 14:42:46.047531 osdx ulogd[407835]: registering plugin `PRINTFLOW' Feb 03 14:42:46.047610 osdx ulogd[407835]: registering plugin `SYSLOG' Feb 03 14:42:46.047616 osdx ulogd[407835]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:46.047670 osdx ulogd[407835]: NFCT plugin working in event mode Feb 03 14:42:46.047679 osdx ulogd[407835]: Changing UID / GID Feb 03 14:42:46.047781 osdx ulogd[407835]: initialization finished, entering main loop Feb 03 14:42:46.048579 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:42:46.089920 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:42:46.124002 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:42:47.339265 osdx ulogd[407835]: [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) Feb 03 14:42:47.339308 osdx ulogd[407835]: [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) Feb 03 14:42:47.465691 osdx ulogd[407835]: [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) Feb 03 14:42:47.465727 osdx ulogd[407835]: [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.426 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.426/0.426/0.426/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.902 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.902/0.902/0.902/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.3 This system includes free software. Contact Teldat for licenses information and source code. Last login: Mon Feb 3 14:41:11 2025 from 10.215.168.64 admin@osdx$
Step 7: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*\[OFFLOAD\]Show output
Feb 03 14:42:57.432602 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:42:57.434063 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:42:57.434141 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:42:57.450203 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:42:57.952018 osdx osdx-coredump[408057]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:42:57.962299 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:42:58.616199 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:42:58.736910 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. Feb 03 14:42:58.848408 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:42:58.971052 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:42:59.094208 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:42:59.218213 osdx INFO[408081]: FRR daemons did not change Feb 03 14:42:59.246045 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Feb 03 14:42:59.362056 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:42:59.518696 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:42:59.519679 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:42:59.520061 osdx ulogd[408197]: registering plugin `NFCT' Feb 03 14:42:59.520208 osdx ulogd[408197]: registering plugin `IP2STR' Feb 03 14:42:59.520355 osdx ulogd[408197]: registering plugin `PRINTFLOW' Feb 03 14:42:59.520481 osdx ulogd[408197]: registering plugin `SYSLOG' Feb 03 14:42:59.520492 osdx ulogd[408197]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:42:59.520575 osdx ulogd[408197]: NFCT plugin working in event mode Feb 03 14:42:59.520587 osdx ulogd[408197]: Changing UID / GID Feb 03 14:42:59.520719 osdx ulogd[408197]: initialization finished, entering main loop Feb 03 14:42:59.522714 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:42:59.561459 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:42:59.589130 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:02.103208 osdx ulogd[408197]: [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 Feb 03 14:43:02.103248 osdx ulogd[408197]: [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 Feb 03 14:43:02.229331 osdx ulogd[408197]: [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 Feb 03 14:43:02.229367 osdx ulogd[408197]: [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 Feb 03 14:43:02.378875 osdx ulogd[408197]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=37528 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=37528 PKTS=0 BYTES=0 Feb 03 14:43:02.379284 osdx ulogd[408197]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=37528 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=37528 PKTS=0 BYTES=0 Feb 03 14:43:02.379352 osdx ulogd[408197]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=37528 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=37528 PKTS=0 BYTES=0 [OFFLOAD] Feb 03 14:43:02.817024 osdx ulogd[408197]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=37528 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=37528 PKTS=0 BYTES=0 Feb 03 14:43:02.818911 osdx ulogd[408197]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=37528 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=37528 PKTS=0 BYTES=0 Feb 03 14:43:02.819133 osdx ulogd[408197]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=37528 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=37528 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.524 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.524/0.524/0.524/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.348 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.445 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.482 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2029ms rtt min/avg/max/mdev = 0.348/0.425/0.482/0.056 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
Feb 03 14:43:09.426742 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:43:09.427595 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:43:09.427660 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:43:09.443675 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:43:09.952733 osdx osdx-coredump[408358]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:43:09.967388 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:43:10.666108 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:43:10.818401 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Feb 03 14:43:10.920962 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Feb 03 14:43:11.075395 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:43:11.164460 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:43:11.328182 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:43:11.432351 osdx INFO[408381]: FRR daemons did not change Feb 03 14:43:11.562914 osdx kernel: app-detect: module init Feb 03 14:43:11.562977 osdx kernel: app-detect: registered: sysctl net.appdetect Feb 03 14:43:11.563001 osdx kernel: app-detect: expression init Feb 03 14:43:11.563027 osdx kernel: app-detect: appid cache initialized Feb 03 14:43:11.563047 osdx kernel: app-detect: appid cache changes counter initialized Feb 03 14:43:11.570521 osdx modulelauncher[408384]: AppDetect: no change in application dictionaries, thus nothing more to do Feb 03 14:43:11.602913 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:43:11.747391 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:43:11.748918 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:43:11.749752 osdx ulogd[408473]: registering plugin `NFCT' Feb 03 14:43:11.749832 osdx ulogd[408473]: registering plugin `IP2STR' Feb 03 14:43:11.749920 osdx ulogd[408473]: registering plugin `PRINTFLOW' Feb 03 14:43:11.750002 osdx ulogd[408473]: registering plugin `SYSLOG' Feb 03 14:43:11.750010 osdx ulogd[408473]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:43:11.750096 osdx ulogd[408473]: NFCT plugin working in event mode Feb 03 14:43:11.750111 osdx ulogd[408473]: Changing UID / GID Feb 03 14:43:11.750246 osdx ulogd[408473]: initialization finished, entering main loop Feb 03 14:43:11.766983 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:43:11.769327 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:43:11.807792 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:43:11.854114 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:13.033728 osdx ulogd[408473]: [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] Feb 03 14:43:13.033772 osdx ulogd[408473]: [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] Feb 03 14:43:13.194358 osdx ulogd[408473]: [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] Feb 03 14:43:13.194399 osdx ulogd[408473]: [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] Feb 03 14:43:14.199161 osdx ulogd[408473]: [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] Feb 03 14:43:14.199204 osdx ulogd[408473]: [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] Feb 03 14:43:14.199231 osdx ulogd[408473]: [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] Feb 03 14:43:15.223226 osdx ulogd[408473]: [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] Feb 03 14:43:15.223293 osdx ulogd[408473]: [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] Feb 03 14:43:15.223318 osdx ulogd[408473]: [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
Feb 03 14:43:09.426742 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:43:09.427595 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:43:09.427660 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:43:09.443675 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:43:09.952733 osdx osdx-coredump[408358]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:43:09.967388 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:43:10.666108 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:43:10.818401 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Feb 03 14:43:10.920962 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Feb 03 14:43:11.075395 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:43:11.164460 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:43:11.328182 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:43:11.432351 osdx INFO[408381]: FRR daemons did not change Feb 03 14:43:11.562914 osdx kernel: app-detect: module init Feb 03 14:43:11.562977 osdx kernel: app-detect: registered: sysctl net.appdetect Feb 03 14:43:11.563001 osdx kernel: app-detect: expression init Feb 03 14:43:11.563027 osdx kernel: app-detect: appid cache initialized Feb 03 14:43:11.563047 osdx kernel: app-detect: appid cache changes counter initialized Feb 03 14:43:11.570521 osdx modulelauncher[408384]: AppDetect: no change in application dictionaries, thus nothing more to do Feb 03 14:43:11.602913 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:43:11.747391 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:43:11.748918 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:43:11.749752 osdx ulogd[408473]: registering plugin `NFCT' Feb 03 14:43:11.749832 osdx ulogd[408473]: registering plugin `IP2STR' Feb 03 14:43:11.749920 osdx ulogd[408473]: registering plugin `PRINTFLOW' Feb 03 14:43:11.750002 osdx ulogd[408473]: registering plugin `SYSLOG' Feb 03 14:43:11.750010 osdx ulogd[408473]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:43:11.750096 osdx ulogd[408473]: NFCT plugin working in event mode Feb 03 14:43:11.750111 osdx ulogd[408473]: Changing UID / GID Feb 03 14:43:11.750246 osdx ulogd[408473]: initialization finished, entering main loop Feb 03 14:43:11.766983 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:43:11.769327 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:43:11.807792 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:43:11.854114 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:13.033728 osdx ulogd[408473]: [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] Feb 03 14:43:13.033772 osdx ulogd[408473]: [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] Feb 03 14:43:13.194358 osdx ulogd[408473]: [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] Feb 03 14:43:13.194399 osdx ulogd[408473]: [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] Feb 03 14:43:14.199161 osdx ulogd[408473]: [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] Feb 03 14:43:14.199204 osdx ulogd[408473]: [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] Feb 03 14:43:14.199231 osdx ulogd[408473]: [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] Feb 03 14:43:15.223226 osdx ulogd[408473]: [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] Feb 03 14:43:15.223293 osdx ulogd[408473]: [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] Feb 03 14:43:15.223318 osdx ulogd[408473]: [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] Feb 03 14:43:15.365872 osdx OSDxCLI[400402]: 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
Feb 03 14:43:09.426742 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:43:09.427595 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:43:09.427660 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:43:09.443675 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:43:09.952733 osdx osdx-coredump[408358]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:43:09.967388 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:43:10.666108 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:43:10.818401 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Feb 03 14:43:10.920962 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Feb 03 14:43:11.075395 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:43:11.164460 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:43:11.328182 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:43:11.432351 osdx INFO[408381]: FRR daemons did not change Feb 03 14:43:11.562914 osdx kernel: app-detect: module init Feb 03 14:43:11.562977 osdx kernel: app-detect: registered: sysctl net.appdetect Feb 03 14:43:11.563001 osdx kernel: app-detect: expression init Feb 03 14:43:11.563027 osdx kernel: app-detect: appid cache initialized Feb 03 14:43:11.563047 osdx kernel: app-detect: appid cache changes counter initialized Feb 03 14:43:11.570521 osdx modulelauncher[408384]: AppDetect: no change in application dictionaries, thus nothing more to do Feb 03 14:43:11.602913 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:43:11.747391 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:43:11.748918 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:43:11.749752 osdx ulogd[408473]: registering plugin `NFCT' Feb 03 14:43:11.749832 osdx ulogd[408473]: registering plugin `IP2STR' Feb 03 14:43:11.749920 osdx ulogd[408473]: registering plugin `PRINTFLOW' Feb 03 14:43:11.750002 osdx ulogd[408473]: registering plugin `SYSLOG' Feb 03 14:43:11.750010 osdx ulogd[408473]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:43:11.750096 osdx ulogd[408473]: NFCT plugin working in event mode Feb 03 14:43:11.750111 osdx ulogd[408473]: Changing UID / GID Feb 03 14:43:11.750246 osdx ulogd[408473]: initialization finished, entering main loop Feb 03 14:43:11.766983 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:43:11.769327 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:43:11.807792 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:43:11.854114 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:13.033728 osdx ulogd[408473]: [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] Feb 03 14:43:13.033772 osdx ulogd[408473]: [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] Feb 03 14:43:13.194358 osdx ulogd[408473]: [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] Feb 03 14:43:13.194399 osdx ulogd[408473]: [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] Feb 03 14:43:14.199161 osdx ulogd[408473]: [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] Feb 03 14:43:14.199204 osdx ulogd[408473]: [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] Feb 03 14:43:14.199231 osdx ulogd[408473]: [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] Feb 03 14:43:15.223226 osdx ulogd[408473]: [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] Feb 03 14:43:15.223293 osdx ulogd[408473]: [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] Feb 03 14:43:15.223318 osdx ulogd[408473]: [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] Feb 03 14:43:15.365872 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal show | cat'. Feb 03 14:43:15.571376 osdx OSDxCLI[400402]: 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.377 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.377/0.377/0.377/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 479k 0 --:--:-- --:--:-- --:--:-- 531k
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
Feb 03 14:43:09.426742 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.2M free. Feb 03 14:43:09.427595 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:43:09.427660 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:43:09.443675 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:43:09.952733 osdx osdx-coredump[408358]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:43:09.967388 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:43:10.666108 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:43:10.818401 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Feb 03 14:43:10.920962 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Feb 03 14:43:11.075395 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Feb 03 14:43:11.164460 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Feb 03 14:43:11.328182 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:43:11.432351 osdx INFO[408381]: FRR daemons did not change Feb 03 14:43:11.562914 osdx kernel: app-detect: module init Feb 03 14:43:11.562977 osdx kernel: app-detect: registered: sysctl net.appdetect Feb 03 14:43:11.563001 osdx kernel: app-detect: expression init Feb 03 14:43:11.563027 osdx kernel: app-detect: appid cache initialized Feb 03 14:43:11.563047 osdx kernel: app-detect: appid cache changes counter initialized Feb 03 14:43:11.570521 osdx modulelauncher[408384]: AppDetect: no change in application dictionaries, thus nothing more to do Feb 03 14:43:11.602913 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Feb 03 14:43:11.747391 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Feb 03 14:43:11.748918 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Feb 03 14:43:11.749752 osdx ulogd[408473]: registering plugin `NFCT' Feb 03 14:43:11.749832 osdx ulogd[408473]: registering plugin `IP2STR' Feb 03 14:43:11.749920 osdx ulogd[408473]: registering plugin `PRINTFLOW' Feb 03 14:43:11.750002 osdx ulogd[408473]: registering plugin `SYSLOG' Feb 03 14:43:11.750010 osdx ulogd[408473]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Feb 03 14:43:11.750096 osdx ulogd[408473]: NFCT plugin working in event mode Feb 03 14:43:11.750111 osdx ulogd[408473]: Changing UID / GID Feb 03 14:43:11.750246 osdx ulogd[408473]: initialization finished, entering main loop Feb 03 14:43:11.766983 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Feb 03 14:43:11.769327 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:43:11.807792 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:43:11.854114 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:13.033728 osdx ulogd[408473]: [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] Feb 03 14:43:13.033772 osdx ulogd[408473]: [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] Feb 03 14:43:13.194358 osdx ulogd[408473]: [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] Feb 03 14:43:13.194399 osdx ulogd[408473]: [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] Feb 03 14:43:14.199161 osdx ulogd[408473]: [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] Feb 03 14:43:14.199204 osdx ulogd[408473]: [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] Feb 03 14:43:14.199231 osdx ulogd[408473]: [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] Feb 03 14:43:15.223226 osdx ulogd[408473]: [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] Feb 03 14:43:15.223293 osdx ulogd[408473]: [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] Feb 03 14:43:15.223318 osdx ulogd[408473]: [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] Feb 03 14:43:15.365872 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal show | cat'. Feb 03 14:43:15.571376 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal show | cat'. Feb 03 14:43:15.784604 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal show | cat'. Feb 03 14:43:16.009401 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:43:16.132062 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Feb 03 14:43:16.220681 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Feb 03 14:43:16.337365 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show changes'. Feb 03 14:43:16.472452 osdx INFO[408523]: FRR daemons did not change Feb 03 14:43:16.506956 osdx kernel: app-detect: expression destroy Feb 03 14:43:16.538968 osdx kernel: app-detect: expression init Feb 03 14:43:16.539043 osdx kernel: app-detect: appid cache initialized Feb 03 14:43:16.539067 osdx kernel: app-detect: appid cache changes counter initialized Feb 03 14:43:16.545708 osdx modulelauncher[408526]: AppDetect: no change in application dictionaries, thus nothing more to do Feb 03 14:43:16.570887 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Feb 03 14:43:16.681163 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:43:16.734065 osdx ulogd[408473]: [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] Feb 03 14:43:16.734097 osdx ulogd[408473]: [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] Feb 03 14:43:16.734962 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:43:16.787297 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:16.971763 osdx ulogd[408473]: [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] Feb 03 14:43:16.972130 osdx ulogd[408473]: [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] Feb 03 14:43:16.974472 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Feb 03 14:43:17.186516 osdx file_operation[408629]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Feb 03 14:43:17.195345 osdx ulogd[408473]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=43782 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=43782 PKTS=0 BYTES=0 APPDETECT[L4:80] Feb 03 14:43:17.195385 osdx ulogd[408473]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=43782 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=43782 PKTS=0 BYTES=0 APPDETECT[L4:80] Feb 03 14:43:17.195412 osdx ulogd[408473]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=43782 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=43782 PKTS=0 BYTES=0 APPDETECT[L4:80] Feb 03 14:43:17.198484 osdx ulogd[408473]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=43782 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=43782 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Feb 03 14:43:17.198818 osdx ulogd[408473]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=43782 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=43782 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Feb 03 14:43:17.198854 osdx ulogd[408473]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=43782 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=43782 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Feb 03 14:43:17.234129 osdx OSDxCLI[400402]: 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.415 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.415/0.415/0.415/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
Feb 03 14:43:24.383162 osdx systemd-journald[1936]: Runtime Journal (/run/log/journal/0b455e05fd8849079cae205af04c9e16) is 2.0M, max 15.3M, 13.3M free. Feb 03 14:43:24.385002 osdx systemd-journald[1936]: Received client request to rotate journal, rotating. Feb 03 14:43:24.385064 osdx systemd-journald[1936]: Vacuuming done, freed 0B of archived journals from /run/log/journal/0b455e05fd8849079cae205af04c9e16. Feb 03 14:43:24.398695 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system journal clear'. Feb 03 14:43:24.896490 osdx osdx-coredump[408787]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Feb 03 14:43:24.906867 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'system coredump delete all'. Feb 03 14:43:25.579727 osdx OSDxCLI[400402]: User 'admin' entered the configuration menu. Feb 03 14:43:25.714469 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. Feb 03 14:43:25.810945 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. Feb 03 14:43:25.908915 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. Feb 03 14:43:26.022449 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. Feb 03 14:43:26.116314 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. Feb 03 14:43:26.216564 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. Feb 03 14:43:26.324510 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. Feb 03 14:43:26.473130 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. Feb 03 14:43:26.557078 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Feb 03 14:43:26.660850 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Feb 03 14:43:26.807513 osdx OSDxCLI[400402]: User 'admin' added a new cfg line: 'show working'. Feb 03 14:43:26.960433 osdx INFO[408828]: FRR daemons did not change Feb 03 14:43:27.093021 osdx kernel: app-detect: module init Feb 03 14:43:27.093086 osdx kernel: app-detect: registered: sysctl net.appdetect Feb 03 14:43:27.093115 osdx kernel: app-detect: expression init Feb 03 14:43:27.093135 osdx kernel: app-detect: appid cache initialized Feb 03 14:43:27.093161 osdx kernel: app-detect: appid cache changes counter initialized Feb 03 14:43:27.153034 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Feb 03 14:43:27.498467 osdx cfgd[1636]: [400402]Completed change to active configuration Feb 03 14:43:27.543847 osdx OSDxCLI[400402]: User 'admin' committed the configuration. Feb 03 14:43:27.592587 osdx OSDxCLI[400402]: User 'admin' left the configuration menu. Feb 03 14:43:27.791406 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Feb 03 14:43:28.003674 osdx file_operation[408971]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Feb 03 14:43:28.012995 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=63017 DF PROTO=TCP SPT=36994 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Feb 03 14:43:28.216992 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=63018 DF PROTO=TCP SPT=36994 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Feb 03 14:43:28.621159 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=63019 DF PROTO=TCP SPT=36994 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Feb 03 14:43:29.453082 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=63020 DF PROTO=TCP SPT=36994 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Feb 03 14:43:30.927519 osdx file_operation.py[408971]: Operation aborted by user. Feb 03 14:43:30.941207 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=63021 DF PROTO=TCP SPT=36994 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Feb 03 14:43:30.949587 osdx OSDxCLI[400402]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'. Feb 03 14:43:31.092999 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=63022 DF PROTO=TCP SPT=36994 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]