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.322 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.322/0.322/0.322/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.218 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.218/0.218/0.218/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
Apr 10 17:00:35.000211 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:00:35 UTC Apr 10 17:00:35.001418 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:00:35.001651 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:00:35'. Apr 10 17:00:35.285488 osdx sudo[150698]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:35.288711 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.0M, max 15.3M, 13.2M free. Apr 10 17:00:35.289415 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:00:35.289457 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:00:35.292966 osdx sudo[150697]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:35.299372 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:00:35.486495 osdx sudo[150705]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:35.569650 osdx sudo[150710]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:35.617474 osdx osdx-coredump[150712]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:00:35.625391 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:00:36.110167 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:00:36.209064 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:00:36.261956 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events new'. Apr 10 17:00:36.390173 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:00:36.505676 osdx ubnt-cfgd[150732]: inactive Apr 10 17:00:36.562257 osdx INFO[150740]: FRR daemons did not change Apr 10 17:00:36.585528 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:00:36.585537 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7850, pid=2547650158 Apr 10 17:00:36.585541 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:00:36.585544 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7851, pid=2547650158 Apr 10 17:00:36.585562 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:00:36.585566 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:00:36.589429 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:00:36.658837 osdx sudo[150828]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:36.685715 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:00:36.688475 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:00:36.689815 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:00:36.692750 osdx ulogd[150831]: registering plugin `NFCT' Apr 10 17:00:36.694093 osdx ulogd[150831]: registering plugin `IP2STR' Apr 10 17:00:36.694228 osdx ulogd[150831]: registering plugin `PRINTFLOW' Apr 10 17:00:36.695607 osdx ulogd[150831]: registering plugin `SYSLOG' Apr 10 17:00:36.695664 osdx ulogd[150831]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:00:36.695757 osdx ulogd[150831]: NFCT plugin working in event mode Apr 10 17:00:36.695814 osdx ulogd[150831]: Changing UID / GID Apr 10 17:00:36.695935 osdx ulogd[150831]: initialization finished, entering main loop Apr 10 17:00:36.700862 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:00:36.718380 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:00:37.686568 osdx ulogd[150831]: [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 Apr 10 17:00:37.771565 osdx ulogd[150831]: [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.335 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.335/0.335/0.335/0.000 ms
Step 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.211 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.211/0.211/0.211/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
Apr 10 17:00:42.000190 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:00:42 UTC Apr 10 17:00:42.001729 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:00:42'. Apr 10 17:00:42.002188 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:00:42.297033 osdx sudo[150991]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:42.300188 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.2M free. Apr 10 17:00:42.302189 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:00:42.302236 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:00:42.304179 osdx sudo[150990]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:42.311329 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:00:42.516848 osdx sudo[150998]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:42.607940 osdx sudo[151003]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:42.657851 osdx osdx-coredump[151005]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:00:42.665657 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:00:43.157683 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:00:43.245826 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:00:43.329119 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events update'. Apr 10 17:00:43.404516 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:00:43.491187 osdx ubnt-cfgd[151023]: inactive Apr 10 17:00:43.539321 osdx INFO[151031]: FRR daemons did not change Apr 10 17:00:43.566756 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:00:43.566767 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7866, pid=2547650158 Apr 10 17:00:43.566773 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:00:43.566777 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7867, pid=2547650158 Apr 10 17:00:43.566815 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:00:43.566821 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:00:43.570215 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:00:43.632501 osdx sudo[151119]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:43.658462 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:00:43.659359 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:00:43.659724 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:00:43.660696 osdx ulogd[151122]: registering plugin `NFCT' Apr 10 17:00:43.660875 osdx ulogd[151122]: registering plugin `IP2STR' Apr 10 17:00:43.660944 osdx ulogd[151122]: registering plugin `PRINTFLOW' Apr 10 17:00:43.661015 osdx ulogd[151122]: registering plugin `SYSLOG' Apr 10 17:00:43.661038 osdx ulogd[151122]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:00:43.661071 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:00:43.661094 osdx ulogd[151122]: NFCT plugin working in event mode Apr 10 17:00:43.661100 osdx ulogd[151122]: Changing UID / GID Apr 10 17:00:43.661162 osdx ulogd[151122]: initialization finished, entering main loop Apr 10 17:00:43.671927 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:00:43.695588 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:00:44.568601 osdx ulogd[151122]: [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 Apr 10 17:00:44.647368 osdx ulogd[151122]: [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.337 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.337/0.337/0.337/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.210 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.215 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.307 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2047ms rtt min/avg/max/mdev = 0.210/0.244/0.307/0.044 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
Apr 10 17:00:49.308907 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.1M free. Apr 10 17:00:49.311024 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:00:49.311069 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:00:49.312996 osdx sudo[151280]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:49.319790 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:00:49.523359 osdx sudo[151288]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:49.610466 osdx sudo[151293]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:49.662650 osdx osdx-coredump[151295]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:00:49.670507 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:00:50.187270 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:00:50.314222 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:00:50.369547 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'. Apr 10 17:00:50.459955 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Apr 10 17:00:50.524221 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service ssh'. Apr 10 17:00:50.645481 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:00:50.710249 osdx ubnt-cfgd[151315]: inactive Apr 10 17:00:50.808938 osdx INFO[151329]: FRR daemons did not change Apr 10 17:00:50.837327 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:00:50.837337 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7882, pid=2547650158 Apr 10 17:00:50.837342 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:00:50.837346 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7883, pid=2547650158 Apr 10 17:00:50.837370 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:00:50.837374 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:00:50.839030 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:00:50.902927 osdx sudo[151419]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:00:50.963436 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:00:50.964319 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:00:50.965036 osdx ulogd[151422]: registering plugin `NFCT' Apr 10 17:00:50.965259 osdx ulogd[151422]: registering plugin `IP2STR' Apr 10 17:00:50.965350 osdx ulogd[151422]: registering plugin `PRINTFLOW' Apr 10 17:00:50.965448 osdx ulogd[151422]: registering plugin `SYSLOG' Apr 10 17:00:50.965484 osdx ulogd[151422]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:00:50.965567 osdx ulogd[151422]: NFCT plugin working in event mode Apr 10 17:00:50.965611 osdx ulogd[151422]: Changing UID / GID Apr 10 17:00:50.965725 osdx ulogd[151422]: initialization finished, entering main loop Apr 10 17:00:50.971067 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:00:51.035316 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server... Apr 10 17:00:51.046589 osdx sshd[151428]: Server listening on 0.0.0.0 port 22. Apr 10 17:00:51.046775 osdx sshd[151428]: Server listening on :: port 22. Apr 10 17:00:51.046896 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server. Apr 10 17:00:51.066817 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:00:51.081735 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:00:51.112297 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:00:53.204461 osdx ulogd[151422]: [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 Apr 10 17:00:54.228521 osdx ulogd[151422]: [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.379 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.379/0.379/0.379/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 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.258 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.258/0.258/0.258/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
Apr 10 17:01:02.343838 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.2M free. Apr 10 17:01:02.345397 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:02.345452 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:02.349520 osdx sudo[151614]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:02.356977 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:02.542786 osdx sudo[151622]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:02.635434 osdx sudo[151627]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:02.699576 osdx osdx-coredump[151629]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:02.709094 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:03.248425 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:03.369330 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:03.423736 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:03.537957 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:03.614761 osdx ubnt-cfgd[151647]: inactive Apr 10 17:01:03.710601 osdx INFO[151655]: FRR daemons did not change Apr 10 17:01:03.734524 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:03.734535 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7898, pid=2547650158 Apr 10 17:01:03.734540 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:03.734544 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7899, pid=2547650158 Apr 10 17:01:03.734904 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:01:03.734910 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:01:03.737401 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:03.797169 osdx sudo[151743]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:03.837704 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:03.838532 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:03.838848 osdx ulogd[151746]: registering plugin `NFCT' Apr 10 17:01:03.839037 osdx ulogd[151746]: registering plugin `IP2STR' Apr 10 17:01:03.839105 osdx ulogd[151746]: registering plugin `PRINTFLOW' Apr 10 17:01:03.839169 osdx ulogd[151746]: registering plugin `SYSLOG' Apr 10 17:01:03.839199 osdx ulogd[151746]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:03.839270 osdx ulogd[151746]: NFCT plugin working in event mode Apr 10 17:01:03.839307 osdx ulogd[151746]: Changing UID / GID Apr 10 17:01:03.839422 osdx ulogd[151746]: initialization finished, entering main loop Apr 10 17:01:03.839640 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:03.851546 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:03.873544 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:04.809913 osdx ulogd[151746]: [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 Apr 10 17:01:04.809939 osdx ulogd[151746]: [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 Apr 10 17:01:04.892179 osdx ulogd[151746]: [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 Apr 10 17:01:04.892204 osdx ulogd[151746]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
Identity logging
Description
Set a simple configuration with identity OSDx_DUT0 for logs entries, send a ping command from one device to other
and check that the identity has changed when running system journal show.
Scenario
Step 1: Set the following configuration in DUT0 :
set interfaces ethernet eth0 address 192.168.100.1/24 set system conntrack logging events all set system conntrack logging identity OSDx_DUT0 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 2: Set the following configuration in DUT1 :
set interfaces ethernet eth0 address 192.168.100.2/24 set protocols static route 0.0.0.0/0 next-hop 192.168.100.1 set system login user admin authentication encrypted-password '$6$GSjsCj8gHLv$/VcqU6FLi6CT2Oxn0MJQ2C2tqnRDrYKNF8HIYWJp68nvXvPdFccDsT04.WtigUONbKYrgKg8d6rEs8PjljMkH0'
Step 3: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.330 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.330/0.330/0.330/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.280 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.280/0.280/0.280/0.000 ms
Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
OSDx_DUT0\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Apr 10 17:01:09.000201 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:09 UTC Apr 10 17:01:09.000843 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:09.002016 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:09'. Apr 10 17:01:09.306006 osdx sudo[151907]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.309908 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 3.1M, max 15.3M, 12.2M free. Apr 10 17:01:09.312842 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:09.312893 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:09.314324 osdx sudo[151906]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.320074 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:09.545939 osdx sudo[151914]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.634141 osdx sudo[151919]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.681977 osdx osdx-coredump[151921]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:09.690334 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:10.238041 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:10.315715 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:10.440164 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:10.510010 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. Apr 10 17:01:10.647839 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:10.715731 osdx ubnt-cfgd[151940]: inactive Apr 10 17:01:10.782488 osdx INFO[151948]: FRR daemons did not change Apr 10 17:01:10.805445 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:10.805455 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7914, pid=2547650158 Apr 10 17:01:10.805459 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:10.805461 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7915, pid=2547650158 Apr 10 17:01:10.805491 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:01:10.805497 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:01:10.808843 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:10.867223 osdx sudo[152036]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:10.889210 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:10.890032 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:10.893075 osdx ulogd[152039]: registering plugin `NFCT' Apr 10 17:01:10.893271 osdx ulogd[152039]: registering plugin `IP2STR' Apr 10 17:01:10.893339 osdx ulogd[152039]: registering plugin `PRINTFLOW' Apr 10 17:01:10.893402 osdx ulogd[152039]: registering plugin `SYSLOG' Apr 10 17:01:10.893430 osdx ulogd[152039]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:10.893498 osdx ulogd[152039]: NFCT plugin working in event mode Apr 10 17:01:10.893527 osdx OSDx_DUT0[152039]: Changing UID / GID Apr 10 17:01:10.893615 osdx OSDx_DUT0[152039]: initialization finished, entering main loop Apr 10 17:01:10.900940 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:10.902286 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:10.913497 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:10.932071 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:11.801257 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.801278 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.884422 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.884441 osdx OSDx_DUT0[152039]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.100.1 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0 , REPLY: SRC=192.168.100.1 DST=192.168.100.2 PROTO=ICMP TYPE=0 CODE=8 PKTS=0 BYTES=0
Note
If the identity is not provided, “ulogd” will be used by default.
Step 6: Modify the following configuration lines in DUT0 :
delete system conntrack logging identity
Step 7: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data. 64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.241 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.241/0.241/0.241/0.000 ms
Step 8: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:
ulogd\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2Show output
Apr 10 17:01:09.000201 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:09 UTC Apr 10 17:01:09.000843 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:09.002016 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:09'. Apr 10 17:01:09.306006 osdx sudo[151907]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.309908 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 3.1M, max 15.3M, 12.2M free. Apr 10 17:01:09.312842 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:09.312893 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:09.314324 osdx sudo[151906]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.320074 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:09.545939 osdx sudo[151914]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.634141 osdx sudo[151919]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:09.681977 osdx osdx-coredump[151921]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:09.690334 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:10.238041 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:10.315715 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:10.440164 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:10.510010 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'. Apr 10 17:01:10.647839 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:10.715731 osdx ubnt-cfgd[151940]: inactive Apr 10 17:01:10.782488 osdx INFO[151948]: FRR daemons did not change Apr 10 17:01:10.805445 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:10.805455 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7914, pid=2547650158 Apr 10 17:01:10.805459 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:10.805461 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7915, pid=2547650158 Apr 10 17:01:10.805491 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:01:10.805497 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:01:10.808843 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:10.867223 osdx sudo[152036]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:10.889210 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:10.890032 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:10.893075 osdx ulogd[152039]: registering plugin `NFCT' Apr 10 17:01:10.893271 osdx ulogd[152039]: registering plugin `IP2STR' Apr 10 17:01:10.893339 osdx ulogd[152039]: registering plugin `PRINTFLOW' Apr 10 17:01:10.893402 osdx ulogd[152039]: registering plugin `SYSLOG' Apr 10 17:01:10.893430 osdx ulogd[152039]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:10.893498 osdx ulogd[152039]: NFCT plugin working in event mode Apr 10 17:01:10.893527 osdx OSDx_DUT0[152039]: Changing UID / GID Apr 10 17:01:10.893615 osdx OSDx_DUT0[152039]: initialization finished, entering main loop Apr 10 17:01:10.900940 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:10.902286 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:10.913497 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:10.932071 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:11.801257 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.801278 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.884422 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.884441 osdx OSDx_DUT0[152039]: [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 Apr 10 17:01:11.986506 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal show | cat'. Apr 10 17:01:12.162180 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:12.242739 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'. Apr 10 17:01:12.364321 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show changes'. Apr 10 17:01:12.449162 osdx ubnt-cfgd[152075]: inactive Apr 10 17:01:12.546718 osdx INFO[152081]: FRR daemons did not change Apr 10 17:01:12.567268 osdx sudo[152086]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:12.574880 osdx OSDx_DUT0[152039]: Terminal signal received, exiting Apr 10 17:01:12.575094 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:12.575652 osdx systemd[1]: ulogd2.service: Deactivated successfully. Apr 10 17:01:12.575838 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:12.597175 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:12.598120 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:12.598571 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:12.599378 osdx ulogd[152089]: registering plugin `NFCT' Apr 10 17:01:12.599744 osdx ulogd[152089]: registering plugin `IP2STR' Apr 10 17:01:12.600122 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:12.600442 osdx ulogd[152089]: registering plugin `PRINTFLOW' Apr 10 17:01:12.600550 osdx ulogd[152089]: registering plugin `SYSLOG' Apr 10 17:01:12.600591 osdx ulogd[152089]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:12.600691 osdx ulogd[152089]: NFCT plugin working in event mode Apr 10 17:01:12.600743 osdx ulogd[152089]: Changing UID / GID Apr 10 17:01:12.600875 osdx ulogd[152089]: initialization finished, entering main loop Apr 10 17:01:12.601585 osdx ulogd[152089]: [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 Apr 10 17:01:12.601674 osdx ulogd[152089]: [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 Apr 10 17:01:12.602162 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:12.626957 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:12.787529 osdx ulogd[152089]: [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 Apr 10 17:01:12.787558 osdx ulogd[152089]: [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.325 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.325/0.325/0.325/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.285 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.259 ms --- 192.168.100.1 ping statistics --- 2 packets transmitted, 2 received, 0% packet loss, time 1032ms rtt min/avg/max/mdev = 0.259/0.272/0.285/0.013 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
Apr 10 17:01:17.000178 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:17 UTC Apr 10 17:01:17.001421 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:17'. Apr 10 17:01:17.002823 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:17.306840 osdx sudo[152226]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:17.310016 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.2M free. Apr 10 17:01:17.310829 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:17.310869 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:17.314156 osdx sudo[152225]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:17.320645 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:17.509999 osdx sudo[152233]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:17.593448 osdx sudo[152238]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:17.649961 osdx osdx-coredump[152240]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:17.658388 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:18.151850 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:18.236124 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Apr 10 17:01:18.328760 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic label TEST'. Apr 10 17:01:18.390146 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'. Apr 10 17:01:18.487136 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'. Apr 10 17:01:18.544131 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:18.643541 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:18.721114 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:18.813636 osdx ubnt-cfgd[152262]: inactive Apr 10 17:01:18.895471 osdx INFO[152276]: FRR daemons did not change Apr 10 17:01:18.920944 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:18.920955 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7930, pid=2547650158 Apr 10 17:01:18.920960 osdx zebra[11813]: [HSYZM-HV7HF] Extended Error: Nexthop has invalid gateway Apr 10 17:01:18.920963 osdx zebra[11813]: [WVJCK-PPMGD][EC 4043309093] netlink-dp (NS 0) error: Network is unreachable, type=RTM_NEWNEXTHOP(104), seq=7931, pid=2547650158 Apr 10 17:01:18.920993 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1639[10.215.200.100 if 2 vrfid 0]) into the kernel Apr 10 17:01:18.920998 osdx zebra[11813]: [X5XE1-RS0SW][EC 4043309074] Failed to install Nexthop (1640[10.215.200.200 if 2 vrfid 0]) into the kernel Apr 10 17:01:18.922833 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:18.994193 osdx sudo[152364]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:19.035170 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:19.036108 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:19.036360 osdx ulogd[152367]: registering plugin `NFCT' Apr 10 17:01:19.036598 osdx ulogd[152367]: registering plugin `IP2STR' Apr 10 17:01:19.036692 osdx ulogd[152367]: registering plugin `PRINTFLOW' Apr 10 17:01:19.036778 osdx ulogd[152367]: registering plugin `SYSLOG' Apr 10 17:01:19.036820 osdx ulogd[152367]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:19.036920 osdx ulogd[152367]: NFCT plugin working in event mode Apr 10 17:01:19.036966 osdx ulogd[152367]: Changing UID / GID Apr 10 17:01:19.037088 osdx ulogd[152367]: initialization finished, entering main loop Apr 10 17:01:19.043423 osdx sudo[152370]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:19.047009 osdx ulogd[152367]: Terminal signal received, exiting Apr 10 17:01:19.047083 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:19.047366 osdx systemd[1]: ulogd2.service: Deactivated successfully. Apr 10 17:01:19.047460 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:19.048380 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:19.049259 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:19.049459 osdx ulogd[152373]: registering plugin `NFCT' Apr 10 17:01:19.049677 osdx ulogd[152373]: registering plugin `IP2STR' Apr 10 17:01:19.049764 osdx ulogd[152373]: registering plugin `PRINTFLOW' Apr 10 17:01:19.049872 osdx ulogd[152373]: registering plugin `SYSLOG' Apr 10 17:01:19.049905 osdx ulogd[152373]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:19.049996 osdx ulogd[152373]: NFCT plugin working in event mode Apr 10 17:01:19.050037 osdx ulogd[152373]: Changing UID / GID Apr 10 17:01:19.050139 osdx ulogd[152373]: initialization finished, entering main loop Apr 10 17:01:19.223978 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:19.235865 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:19.266759 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:20.221471 osdx ulogd[152373]: [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 Apr 10 17:01:20.221488 osdx ulogd[152373]: [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 Apr 10 17:01:20.307917 osdx ulogd[152373]: [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 Apr 10 17:01:20.307937 osdx ulogd[152373]: [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.420 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.420/0.420/0.420/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.223 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.223/0.223/0.223/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
Apr 10 17:01:26.000193 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:26 UTC Apr 10 17:01:26.001570 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:26'. Apr 10 17:01:26.001701 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:26.348971 osdx sudo[152575]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:26.352196 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.2M free. Apr 10 17:01:26.353701 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:26.353749 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:26.357168 osdx sudo[152574]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:26.364934 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:26.577143 osdx sudo[152582]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:26.665174 osdx sudo[152587]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:26.727796 osdx osdx-coredump[152589]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:26.735515 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:27.288101 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:27.416303 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'. Apr 10 17:01:27.487650 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'. Apr 10 17:01:27.593293 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system vrf RED'. Apr 10 17:01:27.689836 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:27.799375 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:27.888839 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:27.977625 osdx ubnt-cfgd[152610]: inactive Apr 10 17:01:28.071230 osdx INFO[152618]: FRR daemons did not change Apr 10 17:01:28.076755 osdx sudo[152623]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:28.085460 osdx (udev-worker)[152632]: RED: Could not disable auto negotiation, ignoring: Operation not supported Apr 10 17:01:28.085659 osdx (udev-worker)[152632]: Network interface NamePolicy= disabled on kernel command line. Apr 10 17:01:28.113701 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:28.177701 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:28.239658 osdx sudo[152781]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:28.278037 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:28.278843 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:28.279456 osdx ulogd[152784]: registering plugin `NFCT' Apr 10 17:01:28.279642 osdx ulogd[152784]: registering plugin `IP2STR' Apr 10 17:01:28.279724 osdx ulogd[152784]: registering plugin `PRINTFLOW' Apr 10 17:01:28.279794 osdx ulogd[152784]: registering plugin `SYSLOG' Apr 10 17:01:28.279825 osdx ulogd[152784]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:28.279898 osdx ulogd[152784]: NFCT plugin working in event mode Apr 10 17:01:28.279935 osdx ulogd[152784]: Changing UID / GID Apr 10 17:01:28.280039 osdx ulogd[152784]: initialization finished, entering main loop Apr 10 17:01:28.285720 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:28.287253 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:28.299109 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:28.316658 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:29.267391 osdx ulogd[152784]: [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 Apr 10 17:01:29.267416 osdx ulogd[152784]: [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 Apr 10 17:01:29.344668 osdx ulogd[152784]: [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 Apr 10 17:01:29.344691 osdx ulogd[152784]: [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.184 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.184/0.184/0.184/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 21582 0 --:--:-- --:--:-- --:--:-- 25800
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.412 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.412/0.412/0.412/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.273 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.273/0.273/0.273/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
Apr 10 17:01:34.303068 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.1M free. Apr 10 17:01:34.306487 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:34.306541 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:34.307325 osdx sudo[153024]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:34.313717 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:34.498304 osdx sudo[153032]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:34.581027 osdx sudo[153037]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:34.628935 osdx osdx-coredump[153039]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:34.637644 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:35.168267 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:35.309104 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Apr 10 17:01:35.373947 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:35.473003 osdx ubnt-cfgd[153056]: inactive Apr 10 17:01:35.523320 osdx INFO[153064]: FRR daemons did not change Apr 10 17:01:35.542495 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Apr 10 17:01:35.595913 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:35.609388 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:35.631473 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:35.799103 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Apr 10 17:01:35.868323 osdx sudo[153178]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:35.931443 osdx file_operation[153181]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running:// Apr 10 17:01:35.957149 osdx sudo[153188]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:35.959871 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'. Apr 10 17:01:36.096531 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:36.164064 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'. Apr 10 17:01:36.263046 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'. Apr 10 17:01:36.316233 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'. Apr 10 17:01:36.415379 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'. Apr 10 17:01:36.472770 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'. Apr 10 17:01:36.571509 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'. Apr 10 17:01:36.629948 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'. Apr 10 17:01:36.730336 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'. Apr 10 17:01:36.790424 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'. Apr 10 17:01:36.903410 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:36.957065 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:37.076571 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:37.150406 osdx ubnt-cfgd[153215]: inactive Apr 10 17:01:37.261938 osdx INFO[153232]: FRR daemons did not change Apr 10 17:01:37.290502 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:37.356640 osdx sudo[153320]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:37.382793 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:37.383798 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:37.384348 osdx ulogd[153323]: registering plugin `NFCT' Apr 10 17:01:37.384385 osdx ulogd[153323]: registering plugin `IP2STR' Apr 10 17:01:37.384421 osdx ulogd[153323]: registering plugin `PRINTFLOW' Apr 10 17:01:37.384459 osdx ulogd[153323]: registering plugin `SYSLOG' Apr 10 17:01:37.384463 osdx ulogd[153323]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:37.384502 osdx ulogd[153323]: NFCT plugin working in event mode Apr 10 17:01:37.384508 osdx ulogd[153323]: Changing UID / GID Apr 10 17:01:37.384577 osdx ulogd[153323]: initialization finished, entering main loop Apr 10 17:01:37.398566 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:37.711675 osdx systemd[1]: Reloading. Apr 10 17:01:37.830478 osdx systemd-sysv-generator[153360]: stat() failed on /etc/init.d/README, ignoring: No such file or directory Apr 10 17:01:37.967294 osdx systemd[1]: Starting logrotate.service - Rotate log files... Apr 10 17:01:37.972941 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata. Apr 10 17:01:37.973853 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service... Apr 10 17:01:37.990942 osdx systemd[1]: logrotate.service: Deactivated successfully. Apr 10 17:01:37.991053 osdx systemd[1]: Finished logrotate.service - Rotate log files. Apr 10 17:01:38.259643 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service. Apr 10 17:01:38.454157 osdx INFO[153342]: Rules successfully loaded Apr 10 17:01:38.463508 osdx sudo[153385]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:38.467054 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:38.467060 osdx ulogd[153323]: Terminal signal received, exiting Apr 10 17:01:38.467455 osdx systemd[1]: ulogd2.service: Deactivated successfully. Apr 10 17:01:38.467554 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:38.490796 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:38.491480 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:38.491718 osdx ulogd[153389]: registering plugin `NFCT' Apr 10 17:01:38.491914 osdx ulogd[153389]: registering plugin `IP2STR' Apr 10 17:01:38.491977 osdx ulogd[153389]: registering plugin `PRINTFLOW' Apr 10 17:01:38.492044 osdx ulogd[153389]: registering plugin `SYSLOG' Apr 10 17:01:38.492067 osdx ulogd[153389]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:38.492129 osdx ulogd[153389]: NFCT plugin working in event mode Apr 10 17:01:38.492154 osdx ulogd[153389]: Changing UID / GID Apr 10 17:01:38.492237 osdx ulogd[153389]: initialization finished, entering main loop Apr 10 17:01:38.494099 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:38.508810 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:38.529226 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:39.413392 osdx ulogd[153389]: [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) Apr 10 17:01:39.413411 osdx ulogd[153389]: [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) Apr 10 17:01:39.493615 osdx ulogd[153389]: [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) Apr 10 17:01:39.493642 osdx ulogd[153389]: [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.411 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.411/0.411/0.411/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.316 ms --- 192.168.200.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.316/0.316/0.316/0.000 ms
Step 6: Init an SSH connection from DUT1 to IP address 192.168.200.2 with the user admin:
admin@DUT1$ ssh admin@192.168.200.2 option StrictHostKeyChecking=no option UserKnownHostsFile=/dev/nullShow output
Warning: Permanently added '192.168.200.2' (ECDSA) to the list of known hosts. admin@192.168.200.2's password: Welcome to Teldat OSDx v4.2.4.2 This system includes free software. Contact Teldat for licenses information and source code. Last login: Thu Apr 10 17:00:18 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
Apr 10 17:01:46.000196 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:46 UTC Apr 10 17:01:46.001924 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:46'. Apr 10 17:01:46.003726 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:46.336292 osdx sudo[153643]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:46.339492 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.0M, max 15.3M, 13.2M free. Apr 10 17:01:46.339910 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:46.339945 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:46.343678 osdx sudo[153642]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:46.351479 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:46.539077 osdx sudo[153650]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:46.628838 osdx sudo[153655]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:46.695489 osdx osdx-coredump[153657]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:46.705858 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:47.220271 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:47.336316 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'. Apr 10 17:01:47.393597 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:47.491078 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:47.565676 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:47.687995 osdx ubnt-cfgd[153676]: inactive Apr 10 17:01:47.782556 osdx INFO[153686]: FRR daemons did not change Apr 10 17:01:47.807732 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Apr 10 17:01:47.883728 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:47.953801 osdx sudo[153849]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:47.976040 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:47.976814 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:47.977163 osdx ulogd[153852]: registering plugin `NFCT' Apr 10 17:01:47.977347 osdx ulogd[153852]: registering plugin `IP2STR' Apr 10 17:01:47.977416 osdx ulogd[153852]: registering plugin `PRINTFLOW' Apr 10 17:01:47.977492 osdx ulogd[153852]: registering plugin `SYSLOG' Apr 10 17:01:47.977522 osdx ulogd[153852]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:47.977592 osdx ulogd[153852]: NFCT plugin working in event mode Apr 10 17:01:47.977627 osdx ulogd[153852]: Changing UID / GID Apr 10 17:01:47.977732 osdx ulogd[153852]: initialization finished, entering main loop Apr 10 17:01:47.977997 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:47.990074 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:48.023907 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:49.937369 osdx ulogd[153852]: [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 Apr 10 17:01:49.937390 osdx ulogd[153852]: [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 Apr 10 17:01:50.041554 osdx ulogd[153852]: [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 Apr 10 17:01:50.041570 osdx ulogd[153852]: [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 Apr 10 17:01:50.130556 osdx ulogd[153852]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 PKTS=0 BYTES=0 Apr 10 17:01:50.130767 osdx ulogd[153852]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 PKTS=0 BYTES=0 Apr 10 17:01:50.130779 osdx ulogd[153852]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 PKTS=0 BYTES=0 [OFFLOAD] Apr 10 17:01:50.394976 osdx ulogd[153852]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 PKTS=0 BYTES=0 Apr 10 17:01:50.395003 osdx ulogd[153852]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 PKTS=0 BYTES=0 [OFFLOAD] Apr 10 17:01:50.396383 osdx ulogd[153852]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 PKTS=0 BYTES=0 Apr 10 17:01:50.396497 osdx ulogd[153852]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=53666 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=53666 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.400 ms --- 192.168.100.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.400/0.400/0.400/0.000 ms
Step 4: Ping IP address 192.168.100.1 from DUT1:
admin@DUT1$ ping 192.168.100.1 count 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.253 ms 64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.301 ms 64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.259 ms --- 192.168.100.1 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2025ms rtt min/avg/max/mdev = 0.253/0.271/0.301/0.021 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
Apr 10 17:01:55.000186 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:55 UTC Apr 10 17:01:55.000832 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:55.001394 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:55'. Apr 10 17:01:55.292478 osdx sudo[154042]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.296280 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 3.0M, max 15.3M, 12.3M free. Apr 10 17:01:55.296876 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:55.296926 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:55.301632 osdx sudo[154041]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.310351 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:55.499855 osdx sudo[154049]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.596872 osdx sudo[154054]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.645658 osdx osdx-coredump[154056]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:55.653406 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:56.167956 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:56.271282 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Apr 10 17:01:56.331876 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Apr 10 17:01:56.446829 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:56.499643 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:56.606851 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:56.674195 osdx ubnt-cfgd[154076]: inactive Apr 10 17:01:56.763338 osdx INFO[154084]: FRR daemons did not change Apr 10 17:01:56.904470 osdx kernel: app-detect: module init Apr 10 17:01:56.904513 osdx kernel: app-detect: registered: sysctl net.appdetect Apr 10 17:01:56.904522 osdx kernel: app-detect: expression init Apr 10 17:01:56.904530 osdx kernel: app-detect: appid cache initialized Apr 10 17:01:56.904538 osdx kernel: app-detect: appid cache changes counter initialized Apr 10 17:01:56.907673 osdx modulelauncher[154087]: AppDetect: no change in application dictionaries, thus nothing more to do Apr 10 17:01:56.932470 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:56.995962 osdx sudo[154195]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:57.028873 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:57.029761 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:57.030521 osdx ulogd[154198]: registering plugin `NFCT' Apr 10 17:01:57.030578 osdx ulogd[154198]: registering plugin `IP2STR' Apr 10 17:01:57.030626 osdx ulogd[154198]: registering plugin `PRINTFLOW' Apr 10 17:01:57.030687 osdx ulogd[154198]: registering plugin `SYSLOG' Apr 10 17:01:57.030695 osdx ulogd[154198]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:57.030755 osdx ulogd[154198]: NFCT plugin working in event mode Apr 10 17:01:57.030766 osdx ulogd[154198]: Changing UID / GID Apr 10 17:01:57.030854 osdx ulogd[154198]: initialization finished, entering main loop Apr 10 17:01:57.052525 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:57.054084 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:57.068248 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:57.092429 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:57.957680 osdx ulogd[154198]: [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] Apr 10 17:01:57.957705 osdx ulogd[154198]: [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] Apr 10 17:01:58.049034 osdx ulogd[154198]: [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] Apr 10 17:01:58.049051 osdx ulogd[154198]: [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] Apr 10 17:01:59.049991 osdx ulogd[154198]: [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] Apr 10 17:01:59.050010 osdx ulogd[154198]: [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] Apr 10 17:01:59.050023 osdx ulogd[154198]: [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] Apr 10 17:02:00.073934 osdx ulogd[154198]: [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] Apr 10 17:02:00.073955 osdx ulogd[154198]: [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] Apr 10 17:02:00.073969 osdx ulogd[154198]: [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
Apr 10 17:01:55.000186 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:55 UTC Apr 10 17:01:55.000832 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:55.001394 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:55'. Apr 10 17:01:55.292478 osdx sudo[154042]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.296280 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 3.0M, max 15.3M, 12.3M free. Apr 10 17:01:55.296876 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:55.296926 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:55.301632 osdx sudo[154041]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.310351 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:55.499855 osdx sudo[154049]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.596872 osdx sudo[154054]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.645658 osdx osdx-coredump[154056]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:55.653406 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:56.167956 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:56.271282 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Apr 10 17:01:56.331876 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Apr 10 17:01:56.446829 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:56.499643 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:56.606851 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:56.674195 osdx ubnt-cfgd[154076]: inactive Apr 10 17:01:56.763338 osdx INFO[154084]: FRR daemons did not change Apr 10 17:01:56.904470 osdx kernel: app-detect: module init Apr 10 17:01:56.904513 osdx kernel: app-detect: registered: sysctl net.appdetect Apr 10 17:01:56.904522 osdx kernel: app-detect: expression init Apr 10 17:01:56.904530 osdx kernel: app-detect: appid cache initialized Apr 10 17:01:56.904538 osdx kernel: app-detect: appid cache changes counter initialized Apr 10 17:01:56.907673 osdx modulelauncher[154087]: AppDetect: no change in application dictionaries, thus nothing more to do Apr 10 17:01:56.932470 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:56.995962 osdx sudo[154195]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:57.028873 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:57.029761 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:57.030521 osdx ulogd[154198]: registering plugin `NFCT' Apr 10 17:01:57.030578 osdx ulogd[154198]: registering plugin `IP2STR' Apr 10 17:01:57.030626 osdx ulogd[154198]: registering plugin `PRINTFLOW' Apr 10 17:01:57.030687 osdx ulogd[154198]: registering plugin `SYSLOG' Apr 10 17:01:57.030695 osdx ulogd[154198]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:57.030755 osdx ulogd[154198]: NFCT plugin working in event mode Apr 10 17:01:57.030766 osdx ulogd[154198]: Changing UID / GID Apr 10 17:01:57.030854 osdx ulogd[154198]: initialization finished, entering main loop Apr 10 17:01:57.052525 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:57.054084 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:57.068248 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:57.092429 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:57.957680 osdx ulogd[154198]: [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] Apr 10 17:01:57.957705 osdx ulogd[154198]: [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] Apr 10 17:01:58.049034 osdx ulogd[154198]: [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] Apr 10 17:01:58.049051 osdx ulogd[154198]: [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] Apr 10 17:01:59.049991 osdx ulogd[154198]: [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] Apr 10 17:01:59.050010 osdx ulogd[154198]: [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] Apr 10 17:01:59.050023 osdx ulogd[154198]: [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] Apr 10 17:02:00.073934 osdx ulogd[154198]: [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] Apr 10 17:02:00.073955 osdx ulogd[154198]: [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] Apr 10 17:02:00.073969 osdx ulogd[154198]: [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] Apr 10 17:02:00.172804 osdx OSDxCLI[143320]: 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
Apr 10 17:01:55.000186 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:55 UTC Apr 10 17:01:55.000832 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:55.001394 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:55'. Apr 10 17:01:55.292478 osdx sudo[154042]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.296280 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 3.0M, max 15.3M, 12.3M free. Apr 10 17:01:55.296876 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:55.296926 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:55.301632 osdx sudo[154041]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.310351 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:55.499855 osdx sudo[154049]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.596872 osdx sudo[154054]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.645658 osdx osdx-coredump[154056]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:55.653406 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:56.167956 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:56.271282 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Apr 10 17:01:56.331876 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Apr 10 17:01:56.446829 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:56.499643 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:56.606851 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:56.674195 osdx ubnt-cfgd[154076]: inactive Apr 10 17:01:56.763338 osdx INFO[154084]: FRR daemons did not change Apr 10 17:01:56.904470 osdx kernel: app-detect: module init Apr 10 17:01:56.904513 osdx kernel: app-detect: registered: sysctl net.appdetect Apr 10 17:01:56.904522 osdx kernel: app-detect: expression init Apr 10 17:01:56.904530 osdx kernel: app-detect: appid cache initialized Apr 10 17:01:56.904538 osdx kernel: app-detect: appid cache changes counter initialized Apr 10 17:01:56.907673 osdx modulelauncher[154087]: AppDetect: no change in application dictionaries, thus nothing more to do Apr 10 17:01:56.932470 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:56.995962 osdx sudo[154195]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:57.028873 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:57.029761 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:57.030521 osdx ulogd[154198]: registering plugin `NFCT' Apr 10 17:01:57.030578 osdx ulogd[154198]: registering plugin `IP2STR' Apr 10 17:01:57.030626 osdx ulogd[154198]: registering plugin `PRINTFLOW' Apr 10 17:01:57.030687 osdx ulogd[154198]: registering plugin `SYSLOG' Apr 10 17:01:57.030695 osdx ulogd[154198]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:57.030755 osdx ulogd[154198]: NFCT plugin working in event mode Apr 10 17:01:57.030766 osdx ulogd[154198]: Changing UID / GID Apr 10 17:01:57.030854 osdx ulogd[154198]: initialization finished, entering main loop Apr 10 17:01:57.052525 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:57.054084 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:57.068248 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:57.092429 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:57.957680 osdx ulogd[154198]: [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] Apr 10 17:01:57.957705 osdx ulogd[154198]: [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] Apr 10 17:01:58.049034 osdx ulogd[154198]: [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] Apr 10 17:01:58.049051 osdx ulogd[154198]: [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] Apr 10 17:01:59.049991 osdx ulogd[154198]: [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] Apr 10 17:01:59.050010 osdx ulogd[154198]: [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] Apr 10 17:01:59.050023 osdx ulogd[154198]: [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] Apr 10 17:02:00.073934 osdx ulogd[154198]: [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] Apr 10 17:02:00.073955 osdx ulogd[154198]: [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] Apr 10 17:02:00.073969 osdx ulogd[154198]: [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] Apr 10 17:02:00.172804 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal show | cat'. Apr 10 17:02:00.294148 osdx OSDxCLI[143320]: 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.233 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.233/0.233/0.233/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 291k 0 --:--:-- --:--:-- --:--:-- 316k
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
Apr 10 17:01:55.000186 osdx systemd-timedated[147586]: Changed local time to Thu 2025-04-10 17:01:55 UTC Apr 10 17:01:55.000832 osdx systemd-journald[1983]: Time jumped backwards, rotating. Apr 10 17:01:55.001394 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'set date 2025-04-10 17:01:55'. Apr 10 17:01:55.292478 osdx sudo[154042]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.296280 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 3.0M, max 15.3M, 12.3M free. Apr 10 17:01:55.296876 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:01:55.296926 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:01:55.301632 osdx sudo[154041]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.310351 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:01:55.499855 osdx sudo[154049]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.596872 osdx sudo[154054]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:55.645658 osdx osdx-coredump[154056]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:01:55.653406 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:01:56.167956 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:01:56.271282 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect'. Apr 10 17:01:56.331876 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'. Apr 10 17:01:56.446829 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'. Apr 10 17:01:56.499643 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack logging events all'. Apr 10 17:01:56.606851 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:01:56.674195 osdx ubnt-cfgd[154076]: inactive Apr 10 17:01:56.763338 osdx INFO[154084]: FRR daemons did not change Apr 10 17:01:56.904470 osdx kernel: app-detect: module init Apr 10 17:01:56.904513 osdx kernel: app-detect: registered: sysctl net.appdetect Apr 10 17:01:56.904522 osdx kernel: app-detect: expression init Apr 10 17:01:56.904530 osdx kernel: app-detect: appid cache initialized Apr 10 17:01:56.904538 osdx kernel: app-detect: appid cache changes counter initialized Apr 10 17:01:56.907673 osdx modulelauncher[154087]: AppDetect: no change in application dictionaries, thus nothing more to do Apr 10 17:01:56.932470 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth0 Apr 10 17:01:56.995962 osdx sudo[154195]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:01:57.028873 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon... Apr 10 17:01:57.029761 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument Apr 10 17:01:57.030521 osdx ulogd[154198]: registering plugin `NFCT' Apr 10 17:01:57.030578 osdx ulogd[154198]: registering plugin `IP2STR' Apr 10 17:01:57.030626 osdx ulogd[154198]: registering plugin `PRINTFLOW' Apr 10 17:01:57.030687 osdx ulogd[154198]: registering plugin `SYSLOG' Apr 10 17:01:57.030695 osdx ulogd[154198]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG' Apr 10 17:01:57.030755 osdx ulogd[154198]: NFCT plugin working in event mode Apr 10 17:01:57.030766 osdx ulogd[154198]: Changing UID / GID Apr 10 17:01:57.030854 osdx ulogd[154198]: initialization finished, entering main loop Apr 10 17:01:57.052525 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon. Apr 10 17:01:57.054084 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:01:57.068248 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:01:57.092429 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:01:57.957680 osdx ulogd[154198]: [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] Apr 10 17:01:57.957705 osdx ulogd[154198]: [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] Apr 10 17:01:58.049034 osdx ulogd[154198]: [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] Apr 10 17:01:58.049051 osdx ulogd[154198]: [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] Apr 10 17:01:59.049991 osdx ulogd[154198]: [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] Apr 10 17:01:59.050010 osdx ulogd[154198]: [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] Apr 10 17:01:59.050023 osdx ulogd[154198]: [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] Apr 10 17:02:00.073934 osdx ulogd[154198]: [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] Apr 10 17:02:00.073955 osdx ulogd[154198]: [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] Apr 10 17:02:00.073969 osdx ulogd[154198]: [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] Apr 10 17:02:00.172804 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal show | cat'. Apr 10 17:02:00.294148 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal show | cat'. Apr 10 17:02:00.409634 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal show | cat'. Apr 10 17:02:00.532305 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:02:00.650302 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Apr 10 17:02:00.752966 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Apr 10 17:02:00.832584 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show changes'. Apr 10 17:02:00.950578 osdx ubnt-cfgd[154251]: inactive Apr 10 17:02:01.003856 osdx INFO[154259]: FRR daemons did not change Apr 10 17:02:01.036477 osdx kernel: app-detect: expression destroy Apr 10 17:02:01.044485 osdx kernel: app-detect: expression init Apr 10 17:02:01.044535 osdx kernel: app-detect: appid cache initialized Apr 10 17:02:01.044544 osdx kernel: app-detect: appid cache changes counter initialized Apr 10 17:02:01.049343 osdx modulelauncher[154262]: AppDetect: no change in application dictionaries, thus nothing more to do Apr 10 17:02:01.068472 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Apr 10 17:02:01.133059 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:02:01.144962 osdx ulogd[154198]: [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] Apr 10 17:02:01.144979 osdx ulogd[154198]: [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] Apr 10 17:02:01.145776 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:02:01.168327 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:02:01.316804 osdx ulogd[154198]: [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] Apr 10 17:02:01.316986 osdx ulogd[154198]: [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] Apr 10 17:02:01.318503 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Apr 10 17:02:01.383865 osdx sudo[154386]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:01.452963 osdx file_operation[154389]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Apr 10 17:02:01.456363 osdx ulogd[154198]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40466 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40466 PKTS=0 BYTES=0 APPDETECT[L4:80] Apr 10 17:02:01.456503 osdx ulogd[154198]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40466 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40466 PKTS=0 BYTES=0 APPDETECT[L4:80] Apr 10 17:02:01.456519 osdx ulogd[154198]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40466 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40466 PKTS=0 BYTES=0 APPDETECT[L4:80] Apr 10 17:02:01.457992 osdx ulogd[154198]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40466 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40466 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Apr 10 17:02:01.458032 osdx ulogd[154198]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40466 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40466 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Apr 10 17:02:01.458047 osdx ulogd[154198]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=40466 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=40466 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1] Apr 10 17:02:01.473592 osdx sudo[154396]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:01.475177 osdx OSDxCLI[143320]: 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.220 ms --- 10.215.168.1 ping statistics --- 1 packets transmitted, 1 received, 0% packet loss, time 0ms rtt min/avg/max/mdev = 0.220/0.220/0.220/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
Apr 10 17:02:07.301615 osdx systemd-journald[1983]: Runtime Journal (/run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42) is 2.1M, max 15.3M, 13.1M free. Apr 10 17:02:07.304655 osdx systemd-journald[1983]: Received client request to rotate journal, rotating. Apr 10 17:02:07.304709 osdx systemd-journald[1983]: Vacuuming done, freed 0B of archived journals from /run/log/journal/1b38a2acfb83465bb2abfbc9ee1b5d42. Apr 10 17:02:07.305932 osdx sudo[154580]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:07.312865 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system journal clear'. Apr 10 17:02:07.537317 osdx sudo[154588]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:07.638351 osdx sudo[154593]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:07.688185 osdx osdx-coredump[154595]: Deleting all coredumps in /opt/vyatta/etc/config/coredump... Apr 10 17:02:07.698267 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'system coredump delete all'. Apr 10 17:02:08.215109 osdx OSDxCLI[143320]: User 'admin' entered the configuration menu. Apr 10 17:02:08.290308 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'. Apr 10 17:02:08.409326 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'. Apr 10 17:02:08.507579 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'. Apr 10 17:02:08.571453 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'. Apr 10 17:02:08.708421 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'. Apr 10 17:02:08.805907 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'. Apr 10 17:02:08.930467 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'. Apr 10 17:02:09.038882 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'. Apr 10 17:02:09.093542 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'. Apr 10 17:02:09.193454 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'. Apr 10 17:02:09.273275 osdx OSDxCLI[143320]: User 'admin' added a new cfg line: 'show working'. Apr 10 17:02:09.366220 osdx ubnt-cfgd[154621]: inactive Apr 10 17:02:09.465635 osdx INFO[154643]: FRR daemons did not change Apr 10 17:02:09.628653 osdx kernel: app-detect: module init Apr 10 17:02:09.628698 osdx kernel: app-detect: registered: sysctl net.appdetect Apr 10 17:02:09.628708 osdx kernel: app-detect: expression init Apr 10 17:02:09.628720 osdx kernel: app-detect: appid cache initialized Apr 10 17:02:09.628728 osdx kernel: app-detect: appid cache changes counter initialized Apr 10 17:02:09.645378 osdx sudo[154672]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:09.672668 osdx kernel: 8021q: adding VLAN 0 to HW filter on device eth1 Apr 10 17:02:09.913774 osdx cfgd[1673]: [143320]Completed change to active configuration Apr 10 17:02:09.925697 osdx OSDxCLI[143320]: User 'admin' committed the configuration. Apr 10 17:02:09.943374 osdx OSDxCLI[143320]: User 'admin' left the configuration menu. Apr 10 17:02:10.120659 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'. Apr 10 17:02:10.183186 osdx sudo[154808]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:10.256228 osdx file_operation[154811]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html Apr 10 17:02:10.260655 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=32966 DF PROTO=TCP SPT=51118 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Apr 10 17:02:10.464666 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=32967 DF PROTO=TCP SPT=51118 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Apr 10 17:02:10.868708 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=32968 DF PROTO=TCP SPT=51118 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Apr 10 17:02:11.700697 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=32969 DF PROTO=TCP SPT=51118 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Apr 10 17:02:13.249432 osdx file_operation.py[154811]: Operation aborted by user. Apr 10 17:02:13.260689 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=32970 DF PROTO=TCP SPT=51118 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1] Apr 10 17:02:13.264626 osdx sudo[154816]: pam_limits(sudo:session): invalid line '@200:215 hard maxlogins ' - skipped Apr 10 17:02:13.266635 osdx OSDxCLI[143320]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'. Apr 10 17:02:13.336652 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=32971 DF PROTO=TCP SPT=51118 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]