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 1
Show 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.295 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.295/0.295/0.295/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 1
Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.230 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.230/0.230/0.230/0.000 ms

Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[NEW\].*SRC=192.168.100.2
Show output
Jan 10 14:03:52.302842 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 1.9M, max 15.3M, 13.3M free.
Jan 10 14:03:52.304689 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:03:52.304735 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:03:52.315135 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:03:52.649661 osdx osdx-coredump[20521]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:03:52.657233 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:03:53.097242 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:03:53.170878 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:03:53.253863 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events new'.
Jan 10 14:03:53.320075 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:03:53.416386 osdx INFO[20545]: FRR daemons did not change
Jan 10 14:03:53.556932 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:03:53.559620 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:03:53.560795 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:03:53.562675 osdx ulogd[20614]: registering plugin `NFCT'
Jan 10 14:03:53.563661 osdx ulogd[20614]: registering plugin `IP2STR'
Jan 10 14:03:53.563762 osdx ulogd[20614]: registering plugin `PRINTFLOW'
Jan 10 14:03:53.564794 osdx ulogd[20614]: registering plugin `SYSLOG'
Jan 10 14:03:53.564839 osdx ulogd[20614]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:03:53.564906 osdx ulogd[20614]: NFCT plugin working in event mode
Jan 10 14:03:53.564941 osdx ulogd[20614]: Changing UID / GID
Jan 10 14:03:53.565028 osdx ulogd[20614]: initialization finished, entering main loop
Jan 10 14:03:53.592648 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:03:53.608552 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:03:54.458487 osdx ulogd[20614]: [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
Jan 10 14:03:54.532621 osdx ulogd[20614]: [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 1
Show 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.297 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.297/0.297/0.297/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 1
Show 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.214 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.214/0.214/0.214/0.000 ms

Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

ulogd\[.*\]:.*\[UPDATE\].*SRC=192.168.100.2
Show output
Jan 10 14:03:58.293437 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.1M, max 15.3M, 13.2M free.
Jan 10 14:03:58.295996 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:03:58.296055 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:03:58.302604 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:03:58.625302 osdx osdx-coredump[20764]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:03:58.632838 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:03:59.089644 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:03:59.163749 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:03:59.245501 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events update'.
Jan 10 14:03:59.313354 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:03:59.414815 osdx INFO[20788]: FRR daemons did not change
Jan 10 14:03:59.536277 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:03:59.536958 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:03:59.537149 osdx ulogd[20857]: registering plugin `NFCT'
Jan 10 14:03:59.537323 osdx ulogd[20857]: registering plugin `IP2STR'
Jan 10 14:03:59.537386 osdx ulogd[20857]: registering plugin `PRINTFLOW'
Jan 10 14:03:59.537453 osdx ulogd[20857]: registering plugin `SYSLOG'
Jan 10 14:03:59.537480 osdx ulogd[20857]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:03:59.537542 osdx ulogd[20857]: NFCT plugin working in event mode
Jan 10 14:03:59.537579 osdx ulogd[20857]: Changing UID / GID
Jan 10 14:03:59.537666 osdx ulogd[20857]: initialization finished, entering main loop
Jan 10 14:03:59.538346 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:03:59.563943 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:03:59.591625 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:00.402737 osdx ulogd[20857]: [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
Jan 10 14:04:00.481362 osdx ulogd[20857]: [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 1
Show 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.361 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.361/0.361/0.361/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 1
Show 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.196 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.423 ms
64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.246 ms

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2048ms
rtt min/avg/max/mdev = 0.196/0.288/0.423/0.097 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.2
Show output
Jan 10 14:04:04.298006 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:04:04.300034 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:04.300074 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:04.306943 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:04.616836 osdx osdx-coredump[21010]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:04.624329 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:05.067615 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:05.149072 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:05.229614 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events destroy'.
Jan 10 14:04:05.284621 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jan 10 14:04:05.379771 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service ssh'.
Jan 10 14:04:05.451436 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:05.554146 osdx INFO[21042]: FRR daemons did not change
Jan 10 14:04:05.696454 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:05.697638 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:05.698050 osdx ulogd[21113]: registering plugin `NFCT'
Jan 10 14:04:05.698156 osdx ulogd[21113]: registering plugin `IP2STR'
Jan 10 14:04:05.698251 osdx ulogd[21113]: registering plugin `PRINTFLOW'
Jan 10 14:04:05.698362 osdx ulogd[21113]: registering plugin `SYSLOG'
Jan 10 14:04:05.698370 osdx ulogd[21113]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:05.698477 osdx ulogd[21113]: NFCT plugin working in event mode
Jan 10 14:04:05.698495 osdx ulogd[21113]: Changing UID / GID
Jan 10 14:04:05.698671 osdx ulogd[21113]: initialization finished, entering main loop
Jan 10 14:04:05.764923 osdx systemd[1]: Starting ssh.service - OpenBSD Secure Shell server...
Jan 10 14:04:05.775840 osdx sshd[21119]: Server listening on 0.0.0.0 port 22.
Jan 10 14:04:05.776046 osdx sshd[21119]: Server listening on :: port 22.
Jan 10 14:04:05.776151 osdx systemd[1]: Started ssh.service - OpenBSD Secure Shell server.
Jan 10 14:04:05.795937 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:05.821287 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:05.837394 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:07.711272 osdx ulogd[21113]: [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
Jan 10 14:04:08.735031 osdx ulogd[21113]: [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 1
Show 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 1 size 56 timeout 1
Show 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.221 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.221/0.221/0.221/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.2
Show output
Jan 10 14:04:16.300191 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:04:16.302500 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:16.302552 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:16.309303 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:16.620953 osdx osdx-coredump[21294]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:16.628682 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:17.075644 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:17.151210 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:17.233878 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:17.303328 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:17.401419 osdx INFO[21318]: FRR daemons did not change
Jan 10 14:04:17.518806 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:17.520014 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:17.520409 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:17.521287 osdx ulogd[21387]: registering plugin `NFCT'
Jan 10 14:04:17.521332 osdx ulogd[21387]: registering plugin `IP2STR'
Jan 10 14:04:17.521370 osdx ulogd[21387]: registering plugin `PRINTFLOW'
Jan 10 14:04:17.521414 osdx ulogd[21387]: registering plugin `SYSLOG'
Jan 10 14:04:17.521417 osdx ulogd[21387]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:17.521453 osdx ulogd[21387]: NFCT plugin working in event mode
Jan 10 14:04:17.521459 osdx ulogd[21387]: Changing UID / GID
Jan 10 14:04:17.521518 osdx ulogd[21387]: initialization finished, entering main loop
Jan 10 14:04:17.521723 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:17.547345 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:17.565756 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:18.365839 osdx ulogd[21387]: [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
Jan 10 14:04:18.365861 osdx ulogd[21387]: [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
Jan 10 14:04:18.439162 osdx ulogd[21387]: [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
Jan 10 14:04:18.439181 osdx ulogd[21387]: [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 1
Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.302 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.302/0.302/0.302/0.000 ms

Step 4: Ping IP address 192.168.100.1 from DUT1:

admin@DUT1$ ping 192.168.100.1 count 1 size 56 timeout 1
Show output
PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
64 bytes from 192.168.100.1: icmp_seq=1 ttl=64 time=0.241 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.241/0.241/0.241/0.000 ms

Step 5: Run command system journal show | cat at DUT0 and check if output matches the following regular expressions:

OSDx_DUT0\[.*\]:.*\[((NEW)|(UPDATE)|(DESTROY))\].*SRC=192.168.100.2
Show output
Jan 10 14:04:22.288108 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:04:22.292035 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:22.292076 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:22.298205 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:22.601264 osdx osdx-coredump[21537]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:22.608848 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:23.054576 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:23.127274 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:23.215800 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:23.279673 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Jan 10 14:04:23.408224 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:23.473604 osdx INFO[21562]: FRR daemons did not change
Jan 10 14:04:23.596247 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:23.596789 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:23.597326 osdx ulogd[21631]: registering plugin `NFCT'
Jan 10 14:04:23.597367 osdx ulogd[21631]: registering plugin `IP2STR'
Jan 10 14:04:23.597405 osdx ulogd[21631]: registering plugin `PRINTFLOW'
Jan 10 14:04:23.597445 osdx ulogd[21631]: registering plugin `SYSLOG'
Jan 10 14:04:23.597449 osdx ulogd[21631]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:23.597494 osdx ulogd[21631]: NFCT plugin working in event mode
Jan 10 14:04:23.597500 osdx OSDx_DUT0[21631]: Changing UID / GID
Jan 10 14:04:23.597564 osdx OSDx_DUT0[21631]: initialization finished, entering main loop
Jan 10 14:04:23.612107 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:23.613998 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:23.646744 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:23.662361 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:24.499811 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.499834 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.574604 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.574622 osdx OSDx_DUT0[21631]: [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 1
Show 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.229 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.229/0.229/0.229/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.2
Show output
Jan 10 14:04:22.288108 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:04:22.292035 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:22.292076 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:22.298205 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:22.601264 osdx osdx-coredump[21537]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:22.608848 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:23.054576 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:23.127274 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:23.215800 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:23.279673 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging identity OSDx_DUT0'.
Jan 10 14:04:23.408224 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:23.473604 osdx INFO[21562]: FRR daemons did not change
Jan 10 14:04:23.596247 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:23.596789 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:23.597326 osdx ulogd[21631]: registering plugin `NFCT'
Jan 10 14:04:23.597367 osdx ulogd[21631]: registering plugin `IP2STR'
Jan 10 14:04:23.597405 osdx ulogd[21631]: registering plugin `PRINTFLOW'
Jan 10 14:04:23.597445 osdx ulogd[21631]: registering plugin `SYSLOG'
Jan 10 14:04:23.597449 osdx ulogd[21631]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:23.597494 osdx ulogd[21631]: NFCT plugin working in event mode
Jan 10 14:04:23.597500 osdx OSDx_DUT0[21631]: Changing UID / GID
Jan 10 14:04:23.597564 osdx OSDx_DUT0[21631]: initialization finished, entering main loop
Jan 10 14:04:23.612107 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:23.613998 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:23.646744 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:23.662361 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:24.499811 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.499834 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.574604 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.574622 osdx OSDx_DUT0[21631]: [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
Jan 10 14:04:24.693153 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal show | cat'.
Jan 10 14:04:24.848190 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:24.904898 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'delete system conntrack logging identity'.
Jan 10 14:04:25.004488 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show changes'.
Jan 10 14:04:25.063494 osdx INFO[21667]: FRR daemons did not change
Jan 10 14:04:25.073082 osdx OSDx_DUT0[21631]: Terminal signal received, exiting
Jan 10 14:04:25.073106 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:25.073611 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jan 10 14:04:25.073703 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:25.092374 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:25.093149 osdx ulogd[21675]: registering plugin `NFCT'
Jan 10 14:04:25.093166 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:25.093185 osdx ulogd[21675]: registering plugin `IP2STR'
Jan 10 14:04:25.093223 osdx ulogd[21675]: registering plugin `PRINTFLOW'
Jan 10 14:04:25.093271 osdx ulogd[21675]: registering plugin `SYSLOG'
Jan 10 14:04:25.093274 osdx ulogd[21675]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:25.093315 osdx ulogd[21675]: NFCT plugin working in event mode
Jan 10 14:04:25.093322 osdx ulogd[21675]: Changing UID / GID
Jan 10 14:04:25.093392 osdx ulogd[21675]: initialization finished, entering main loop
Jan 10 14:04:25.094367 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:25.095734 osdx ulogd[21675]: [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
Jan 10 14:04:25.095751 osdx ulogd[21675]: [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
Jan 10 14:04:25.096367 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:25.114943 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:25.257058 osdx ulogd[21675]: [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
Jan 10 14:04:25.257077 osdx ulogd[21675]: [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 1
Show 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 4: Ping IP address 192.168.100.1 from DUT1:

admin@DUT1$ ping 192.168.100.1 count 2 size 56 timeout 1
Show 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.303 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.269 ms

--- 192.168.100.1 ping statistics ---
2 packets transmitted, 2 received, 0% packet loss, time 1017ms
rtt min/avg/max/mdev = 0.269/0.286/0.303/0.017 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=TEST
Show output
Jan 10 14:04:29.291505 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:04:29.293527 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:29.293599 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:29.300842 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:29.611551 osdx osdx-coredump[21806]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:29.619166 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:30.061384 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:30.140272 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jan 10 14:04:30.213822 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic label TEST'.
Jan 10 14:04:30.276126 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set connmark 33'.
Jan 10 14:04:30.369000 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 set label TEST'.
Jan 10 14:04:30.423200 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:30.520460 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:30.593592 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:30.698872 osdx INFO[21840]: FRR daemons did not change
Jan 10 14:04:30.821736 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:30.822526 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:30.822696 osdx ulogd[21909]: registering plugin `NFCT'
Jan 10 14:04:30.822858 osdx ulogd[21909]: registering plugin `IP2STR'
Jan 10 14:04:30.823236 osdx ulogd[21909]: registering plugin `PRINTFLOW'
Jan 10 14:04:30.823310 osdx ulogd[21909]: registering plugin `SYSLOG'
Jan 10 14:04:30.823336 osdx ulogd[21909]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:30.823394 osdx ulogd[21909]: NFCT plugin working in event mode
Jan 10 14:04:30.823423 osdx ulogd[21909]: Changing UID / GID
Jan 10 14:04:30.823504 osdx ulogd[21909]: initialization finished, entering main loop
Jan 10 14:04:30.833055 osdx ulogd[21909]: Terminal signal received, exiting
Jan 10 14:04:30.833135 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:30.833383 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jan 10 14:04:30.833495 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:30.834313 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:30.835012 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:30.835507 osdx ulogd[21915]: registering plugin `NFCT'
Jan 10 14:04:30.835546 osdx ulogd[21915]: registering plugin `IP2STR'
Jan 10 14:04:30.835584 osdx ulogd[21915]: registering plugin `PRINTFLOW'
Jan 10 14:04:30.835626 osdx ulogd[21915]: registering plugin `SYSLOG'
Jan 10 14:04:30.835629 osdx ulogd[21915]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:30.835663 osdx ulogd[21915]: NFCT plugin working in event mode
Jan 10 14:04:30.835668 osdx ulogd[21915]: Changing UID / GID
Jan 10 14:04:30.835724 osdx ulogd[21915]: initialization finished, entering main loop
Jan 10 14:04:30.853553 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:31.082297 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:31.108203 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:31.137765 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:31.955462 osdx ulogd[21915]: [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
Jan 10 14:04:31.955481 osdx ulogd[21915]: [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
Jan 10 14:04:32.027845 osdx ulogd[21915]: [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
Jan 10 14:04:32.027864 osdx ulogd[21915]: [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 1
Show 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.276 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.276/0.276/0.276/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 1
Show 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.252 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.252/0.252/0.252/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=RED
Show output
Jan 10 14:04:37.296841 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.2M free.
Jan 10 14:04:37.300065 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:37.300110 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:37.305759 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:37.630672 osdx osdx-coredump[22107]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:37.640363 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:38.085576 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:38.160607 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 vrf RED'.
Jan 10 14:04:38.255003 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set protocols vrf RED static route 0.0.0.0/0 next-hop 192.168.100.2'.
Jan 10 14:04:38.304370 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system vrf RED'.
Jan 10 14:04:38.403829 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:38.459550 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:38.574421 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:38.642591 osdx INFO[22135]: FRR daemons did not change
Jan 10 14:04:38.657755 osdx (udev-worker)[22150]: RED: Could not disable auto negotiation, ignoring: Operation not supported
Jan 10 14:04:38.657784 osdx (udev-worker)[22150]: Network interface NamePolicy= disabled on kernel command line.
Jan 10 14:04:38.848422 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:38.848998 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:38.849119 osdx ulogd[22257]: registering plugin `NFCT'
Jan 10 14:04:38.849159 osdx ulogd[22257]: registering plugin `IP2STR'
Jan 10 14:04:38.849193 osdx ulogd[22257]: registering plugin `PRINTFLOW'
Jan 10 14:04:38.849232 osdx ulogd[22257]: registering plugin `SYSLOG'
Jan 10 14:04:38.849235 osdx ulogd[22257]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:38.849272 osdx ulogd[22257]: NFCT plugin working in event mode
Jan 10 14:04:38.849277 osdx ulogd[22257]: Changing UID / GID
Jan 10 14:04:38.849664 osdx ulogd[22257]: initialization finished, entering main loop
Jan 10 14:04:38.850108 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:38.883862 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:38.900031 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:39.706883 osdx ulogd[22257]: [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
Jan 10 14:04:39.706900 osdx ulogd[22257]: [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
Jan 10 14:04:39.817167 osdx ulogd[22257]: [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
Jan 10 14:04:39.817185 osdx ulogd[22257]: [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 1
Show 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.172 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.172/0.172/0.172/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  27777      0 --:--:-- --:--:-- --:--:-- 32250

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 1
Show 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.436 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.436/0.436/0.436/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 1
Show 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.283 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.283/0.283/0.283/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-bypass
Show output
Jan 10 14:04:43.293143 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.2M free.
Jan 10 14:04:43.294883 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:43.294927 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:43.302147 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:43.624736 osdx osdx-coredump[22467]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:43.632774 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:44.094060 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:44.168834 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jan 10 14:04:44.259419 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:44.325249 osdx INFO[22490]: FRR daemons did not change
Jan 10 14:04:44.419458 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:44.444469 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:44.464812 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:44.617018 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jan 10 14:04:44.738849 osdx file_operation[22585]: using src url: http://10.215.168.1/~robot/test-performance.rules dst url: running://
Jan 10 14:04:44.762464 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/test-performance.rules running:// force'.
Jan 10 14:04:44.895613 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:44.961883 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 traffic policy in POLICY'.
Jan 10 14:04:45.049173 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service firewall FW mode inline queue FW_Q'.
Jan 10 14:04:45.104945 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service firewall FW ruleset file running://test-performance.rules'.
Jan 10 14:04:45.200243 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass'.
Jan 10 14:04:45.255993 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mark 129834765'.
Jan 10 14:04:45.352538 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass mask 129834765'.
Jan 10 14:04:45.407669 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set service firewall FW stream bypass set-connmark'.
Jan 10 14:04:45.507363 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic queue FW_Q elements 1'.
Jan 10 14:04:45.567508 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic policy POLICY rule 1 action enqueue FW_Q'.
Jan 10 14:04:45.674050 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:45.725317 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:45.843921 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:45.954776 osdx INFO[22634]: FRR daemons did not change
Jan 10 14:04:46.079140 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:46.079744 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:46.080091 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:46.082267 osdx ulogd[22703]: registering plugin `NFCT'
Jan 10 14:04:46.082319 osdx ulogd[22703]: registering plugin `IP2STR'
Jan 10 14:04:46.082370 osdx ulogd[22703]: registering plugin `PRINTFLOW'
Jan 10 14:04:46.082416 osdx ulogd[22703]: registering plugin `SYSLOG'
Jan 10 14:04:46.082420 osdx ulogd[22703]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:46.082469 osdx ulogd[22703]: NFCT plugin working in event mode
Jan 10 14:04:46.082476 osdx ulogd[22703]: Changing UID / GID
Jan 10 14:04:46.082550 osdx ulogd[22703]: initialization finished, entering main loop
Jan 10 14:04:46.395816 osdx systemd[1]: Reloading.
Jan 10 14:04:46.494889 osdx systemd-sysv-generator[22740]: stat() failed on /etc/init.d/README, ignoring: No such file or directory
Jan 10 14:04:46.615298 osdx systemd[1]: Starting logrotate.service - Rotate log files...
Jan 10 14:04:46.620125 osdx systemd[1]: Created slice system-suricata.slice - Slice /system/suricata.
Jan 10 14:04:46.621186 osdx systemd[1]: Starting suricata@FW.service - Suricata client "FW" service...
Jan 10 14:04:46.639348 osdx systemd[1]: logrotate.service: Deactivated successfully.
Jan 10 14:04:46.639487 osdx systemd[1]: Finished logrotate.service - Rotate log files.
Jan 10 14:04:46.890204 osdx systemd[1]: Started suricata@FW.service - Suricata client "FW" service.
Jan 10 14:04:47.292170 osdx INFO[22722]: Rules successfully loaded
Jan 10 14:04:47.304588 osdx ulogd[22703]: Terminal signal received, exiting
Jan 10 14:04:47.304624 osdx systemd[1]: Stopping ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:47.305007 osdx systemd[1]: ulogd2.service: Deactivated successfully.
Jan 10 14:04:47.305097 osdx systemd[1]: Stopped ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:47.335225 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:47.336072 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:47.336748 osdx ulogd[22768]: registering plugin `NFCT'
Jan 10 14:04:47.336804 osdx ulogd[22768]: registering plugin `IP2STR'
Jan 10 14:04:47.336852 osdx ulogd[22768]: registering plugin `PRINTFLOW'
Jan 10 14:04:47.336902 osdx ulogd[22768]: registering plugin `SYSLOG'
Jan 10 14:04:47.336906 osdx ulogd[22768]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:47.336956 osdx ulogd[22768]: NFCT plugin working in event mode
Jan 10 14:04:47.336963 osdx ulogd[22768]: Changing UID / GID
Jan 10 14:04:47.337040 osdx ulogd[22768]: initialization finished, entering main loop
Jan 10 14:04:47.358951 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:47.360766 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:47.399317 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:47.421564 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:48.217585 osdx ulogd[22768]: [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)
Jan 10 14:04:48.217607 osdx ulogd[22768]: [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)
Jan 10 14:04:48.293253 osdx ulogd[22768]: [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)
Jan 10 14:04:48.293276 osdx ulogd[22768]: [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 1
Show 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.519 ms

--- 192.168.100.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.519/0.519/0.519/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 1
Show 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.313 ms

--- 192.168.200.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.313/0.313/0.313/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/null
Show 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.2.1

This system includes free software.
Contact Teldat for licenses information and source code.

Last login: Fri Jan 10 12:18:36 2025 from 40.0.0.2
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
Jan 10 14:04:55.306445 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:04:55.309571 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:04:55.309610 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:04:55.316214 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:04:55.622113 osdx osdx-coredump[22990]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:04:55.629711 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:04:56.084698 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:04:56.158546 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 192.168.200.1/24'.
Jan 10 14:04:56.247559 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:04:56.310411 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:04:56.427375 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:04:56.501139 osdx INFO[23017]: FRR daemons did not change
Jan 10 14:04:56.701842 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:04:56.702397 osdx systemd[1]: ulogd2.service: Failed to parse PID from file /run/ulog/ulogd.pid: Invalid argument
Jan 10 14:04:56.702745 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:04:56.703714 osdx ulogd[23139]: registering plugin `NFCT'
Jan 10 14:04:56.703896 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:04:56.703908 osdx ulogd[23139]: registering plugin `IP2STR'
Jan 10 14:04:56.703948 osdx ulogd[23139]: registering plugin `PRINTFLOW'
Jan 10 14:04:56.703995 osdx ulogd[23139]: registering plugin `SYSLOG'
Jan 10 14:04:56.703999 osdx ulogd[23139]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:04:56.704050 osdx ulogd[23139]: NFCT plugin working in event mode
Jan 10 14:04:56.704058 osdx ulogd[23139]: Changing UID / GID
Jan 10 14:04:56.704134 osdx ulogd[23139]: initialization finished, entering main loop
Jan 10 14:04:56.730197 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:04:56.754388 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:04:58.415472 osdx ulogd[23139]: [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
Jan 10 14:04:58.415490 osdx ulogd[23139]: [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
Jan 10 14:04:58.499699 osdx ulogd[23139]: [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
Jan 10 14:04:58.499717 osdx ulogd[23139]: [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
Jan 10 14:04:58.583867 osdx ulogd[23139]: [NEW] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 PKTS=0 BYTES=0
Jan 10 14:04:58.583989 osdx ulogd[23139]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 PKTS=0 BYTES=0
Jan 10 14:04:58.584115 osdx ulogd[23139]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 PKTS=0 BYTES=0 [OFFLOAD]
Jan 10 14:04:58.878202 osdx ulogd[23139]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 PKTS=0 BYTES=0
Jan 10 14:04:58.878219 osdx ulogd[23139]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 PKTS=0 BYTES=0 [OFFLOAD]
Jan 10 14:04:58.879384 osdx ulogd[23139]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 PKTS=0 BYTES=0
Jan 10 14:04:58.879525 osdx ulogd[23139]: [UPDATE] ORIG: SRC=192.168.100.2 DST=192.168.200.2 PROTO=TCP SPT=55506 DPT=22 PKTS=0 BYTES=0 , REPLY: SRC=192.168.200.2 DST=192.168.100.2 PROTO=TCP SPT=22 DPT=55506 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 1
Show 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 1
Show 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.232 ms
64 bytes from 192.168.100.1: icmp_seq=2 ttl=64 time=0.232 ms
64 bytes from 192.168.100.1: icmp_seq=3 ttl=64 time=0.404 ms

--- 192.168.100.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2025ms
rtt min/avg/max/mdev = 0.232/0.289/0.404/0.081 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
Jan 10 14:05:03.298081 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.2M free.
Jan 10 14:05:03.300541 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:05:03.300592 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:05:03.307170 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:05:03.614714 osdx osdx-coredump[23300]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:05:03.621946 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:05:04.096751 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:05:04.156225 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jan 10 14:05:04.258689 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jan 10 14:05:04.373410 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:05:04.426754 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:05:04.538879 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:05:04.606021 osdx INFO[23326]: FRR daemons did not change
Jan 10 14:05:04.780546 osdx kernel: app-detect: module init
Jan 10 14:05:04.780597 osdx kernel: app-detect: registered: sysctl net.appdetect
Jan 10 14:05:04.780607 osdx kernel: app-detect: expression init
Jan 10 14:05:04.780615 osdx kernel: app-detect: appid cache initialized
Jan 10 14:05:04.780623 osdx kernel: app-detect: appid cache changes counter initialized
Jan 10 14:05:04.784967 osdx modulelauncher[23329]: AppDetect: no change in application dictionaries, thus nothing more to do
Jan 10 14:05:04.924870 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:05:04.925758 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:05:04.925853 osdx ulogd[23418]: registering plugin `NFCT'
Jan 10 14:05:04.925891 osdx ulogd[23418]: registering plugin `IP2STR'
Jan 10 14:05:04.925924 osdx ulogd[23418]: registering plugin `PRINTFLOW'
Jan 10 14:05:04.925963 osdx ulogd[23418]: registering plugin `SYSLOG'
Jan 10 14:05:04.925966 osdx ulogd[23418]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:05:04.926001 osdx ulogd[23418]: NFCT plugin working in event mode
Jan 10 14:05:04.926007 osdx ulogd[23418]: Changing UID / GID
Jan 10 14:05:04.926069 osdx ulogd[23418]: initialization finished, entering main loop
Jan 10 14:05:04.927054 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:05:04.952788 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:05:04.978094 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:05:05.785644 osdx ulogd[23418]: [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]
Jan 10 14:05:05.785660 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862392 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862412 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863537 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863556 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863568 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887747 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887790 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887814 osdx ulogd[23418]: [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
Jan 10 14:05:03.298081 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.2M free.
Jan 10 14:05:03.300541 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:05:03.300592 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:05:03.307170 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:05:03.614714 osdx osdx-coredump[23300]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:05:03.621946 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:05:04.096751 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:05:04.156225 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jan 10 14:05:04.258689 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jan 10 14:05:04.373410 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:05:04.426754 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:05:04.538879 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:05:04.606021 osdx INFO[23326]: FRR daemons did not change
Jan 10 14:05:04.780546 osdx kernel: app-detect: module init
Jan 10 14:05:04.780597 osdx kernel: app-detect: registered: sysctl net.appdetect
Jan 10 14:05:04.780607 osdx kernel: app-detect: expression init
Jan 10 14:05:04.780615 osdx kernel: app-detect: appid cache initialized
Jan 10 14:05:04.780623 osdx kernel: app-detect: appid cache changes counter initialized
Jan 10 14:05:04.784967 osdx modulelauncher[23329]: AppDetect: no change in application dictionaries, thus nothing more to do
Jan 10 14:05:04.924870 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:05:04.925758 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:05:04.925853 osdx ulogd[23418]: registering plugin `NFCT'
Jan 10 14:05:04.925891 osdx ulogd[23418]: registering plugin `IP2STR'
Jan 10 14:05:04.925924 osdx ulogd[23418]: registering plugin `PRINTFLOW'
Jan 10 14:05:04.925963 osdx ulogd[23418]: registering plugin `SYSLOG'
Jan 10 14:05:04.925966 osdx ulogd[23418]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:05:04.926001 osdx ulogd[23418]: NFCT plugin working in event mode
Jan 10 14:05:04.926007 osdx ulogd[23418]: Changing UID / GID
Jan 10 14:05:04.926069 osdx ulogd[23418]: initialization finished, entering main loop
Jan 10 14:05:04.927054 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:05:04.952788 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:05:04.978094 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:05:05.785644 osdx ulogd[23418]: [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]
Jan 10 14:05:05.785660 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862392 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862412 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863537 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863556 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863568 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887747 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887790 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887814 osdx ulogd[23418]: [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]
Jan 10 14:05:07.980386 osdx OSDxCLI[16822]: 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
Jan 10 14:05:03.298081 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.2M free.
Jan 10 14:05:03.300541 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:05:03.300592 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:05:03.307170 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:05:03.614714 osdx osdx-coredump[23300]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:05:03.621946 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:05:04.096751 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:05:04.156225 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jan 10 14:05:04.258689 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jan 10 14:05:04.373410 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:05:04.426754 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:05:04.538879 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:05:04.606021 osdx INFO[23326]: FRR daemons did not change
Jan 10 14:05:04.780546 osdx kernel: app-detect: module init
Jan 10 14:05:04.780597 osdx kernel: app-detect: registered: sysctl net.appdetect
Jan 10 14:05:04.780607 osdx kernel: app-detect: expression init
Jan 10 14:05:04.780615 osdx kernel: app-detect: appid cache initialized
Jan 10 14:05:04.780623 osdx kernel: app-detect: appid cache changes counter initialized
Jan 10 14:05:04.784967 osdx modulelauncher[23329]: AppDetect: no change in application dictionaries, thus nothing more to do
Jan 10 14:05:04.924870 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:05:04.925758 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:05:04.925853 osdx ulogd[23418]: registering plugin `NFCT'
Jan 10 14:05:04.925891 osdx ulogd[23418]: registering plugin `IP2STR'
Jan 10 14:05:04.925924 osdx ulogd[23418]: registering plugin `PRINTFLOW'
Jan 10 14:05:04.925963 osdx ulogd[23418]: registering plugin `SYSLOG'
Jan 10 14:05:04.925966 osdx ulogd[23418]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:05:04.926001 osdx ulogd[23418]: NFCT plugin working in event mode
Jan 10 14:05:04.926007 osdx ulogd[23418]: Changing UID / GID
Jan 10 14:05:04.926069 osdx ulogd[23418]: initialization finished, entering main loop
Jan 10 14:05:04.927054 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:05:04.952788 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:05:04.978094 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:05:05.785644 osdx ulogd[23418]: [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]
Jan 10 14:05:05.785660 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862392 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862412 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863537 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863556 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863568 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887747 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887790 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887814 osdx ulogd[23418]: [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]
Jan 10 14:05:07.980386 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal show | cat'.
Jan 10 14:05:08.077173 osdx OSDxCLI[16822]: 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 1
Show 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.221 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.221/0.221/0.221/0.000 ms

Step 10: Run command file copy http://10.215.168.1/~robot/ running://index.html at DUT0 and expect this output:

Show output
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  4352    0  4352    0     0   914k      0 --:--:-- --:--:-- --:--:-- 1062k

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
Jan 10 14:05:03.298081 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.2M free.
Jan 10 14:05:03.300541 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:05:03.300592 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:05:03.307170 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:05:03.614714 osdx osdx-coredump[23300]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:05:03.621946 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:05:04.096751 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:05:04.156225 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect'.
Jan 10 14:05:04.258689 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack timeout icmp 1'.
Jan 10 14:05:04.373410 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth0 address 192.168.100.1/24'.
Jan 10 14:05:04.426754 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack logging events all'.
Jan 10 14:05:04.538879 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:05:04.606021 osdx INFO[23326]: FRR daemons did not change
Jan 10 14:05:04.780546 osdx kernel: app-detect: module init
Jan 10 14:05:04.780597 osdx kernel: app-detect: registered: sysctl net.appdetect
Jan 10 14:05:04.780607 osdx kernel: app-detect: expression init
Jan 10 14:05:04.780615 osdx kernel: app-detect: appid cache initialized
Jan 10 14:05:04.780623 osdx kernel: app-detect: appid cache changes counter initialized
Jan 10 14:05:04.784967 osdx modulelauncher[23329]: AppDetect: no change in application dictionaries, thus nothing more to do
Jan 10 14:05:04.924870 osdx systemd[1]: Starting ulogd2.service - Netfilter Userspace Logging Daemon...
Jan 10 14:05:04.925758 osdx systemd[1]: Started ulogd2.service - Netfilter Userspace Logging Daemon.
Jan 10 14:05:04.925853 osdx ulogd[23418]: registering plugin `NFCT'
Jan 10 14:05:04.925891 osdx ulogd[23418]: registering plugin `IP2STR'
Jan 10 14:05:04.925924 osdx ulogd[23418]: registering plugin `PRINTFLOW'
Jan 10 14:05:04.925963 osdx ulogd[23418]: registering plugin `SYSLOG'
Jan 10 14:05:04.925966 osdx ulogd[23418]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,print1:PRINTFLOW,sys1:SYSLOG'
Jan 10 14:05:04.926001 osdx ulogd[23418]: NFCT plugin working in event mode
Jan 10 14:05:04.926007 osdx ulogd[23418]: Changing UID / GID
Jan 10 14:05:04.926069 osdx ulogd[23418]: initialization finished, entering main loop
Jan 10 14:05:04.927054 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:05:04.952788 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:05:04.978094 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:05:05.785644 osdx ulogd[23418]: [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]
Jan 10 14:05:05.785660 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862392 osdx ulogd[23418]: [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]
Jan 10 14:05:05.862412 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863537 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863556 osdx ulogd[23418]: [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]
Jan 10 14:05:06.863568 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887747 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887790 osdx ulogd[23418]: [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]
Jan 10 14:05:07.887814 osdx ulogd[23418]: [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]
Jan 10 14:05:07.980386 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal show | cat'.
Jan 10 14:05:08.077173 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal show | cat'.
Jan 10 14:05:08.174204 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal show | cat'.
Jan 10 14:05:08.328744 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:05:08.400828 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jan 10 14:05:08.483729 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Jan 10 14:05:08.545103 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show changes'.
Jan 10 14:05:08.654384 osdx INFO[23471]: FRR daemons did not change
Jan 10 14:05:08.688545 osdx kernel: app-detect: expression destroy
Jan 10 14:05:08.712543 osdx kernel: app-detect: expression init
Jan 10 14:05:08.712576 osdx kernel: app-detect: appid cache initialized
Jan 10 14:05:08.712585 osdx kernel: app-detect: appid cache changes counter initialized
Jan 10 14:05:08.716267 osdx modulelauncher[23474]: AppDetect: no change in application dictionaries, thus nothing more to do
Jan 10 14:05:08.798055 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:05:08.821828 osdx ulogd[23418]: [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]
Jan 10 14:05:08.821844 osdx ulogd[23418]: [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]
Jan 10 14:05:08.822408 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:05:08.837807 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:05:08.981081 osdx ulogd[23418]: [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]
Jan 10 14:05:08.981264 osdx ulogd[23418]: [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]
Jan 10 14:05:08.982635 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jan 10 14:05:09.104402 osdx file_operation[23579]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Jan 10 14:05:09.108959 osdx ulogd[23418]: [NEW] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=47652 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=47652 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jan 10 14:05:09.109170 osdx ulogd[23418]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=47652 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=47652 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jan 10 14:05:09.109195 osdx ulogd[23418]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=47652 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=47652 PKTS=0 BYTES=0 APPDETECT[L4:80]
Jan 10 14:05:09.110806 osdx ulogd[23418]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=47652 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=47652 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jan 10 14:05:09.110901 osdx ulogd[23418]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=47652 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=47652 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jan 10 14:05:09.110916 osdx ulogd[23418]: [UPDATE] ORIG: SRC=10.215.168.64 DST=10.215.168.1 PROTO=TCP SPT=47652 DPT=80 PKTS=0 BYTES=0 , REPLY: SRC=10.215.168.1 DST=10.215.168.64 PROTO=TCP SPT=80 DPT=47652 PKTS=0 BYTES=0 APPDETECT[L4:80 http-host:10.215.168.1]
Jan 10 14:05:09.127850 osdx OSDxCLI[16822]: 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 1
Show output
PING 10.215.168.1 (10.215.168.1) 56(84) bytes of data.
64 bytes from 10.215.168.1: icmp_seq=1 ttl=64 time=0.214 ms

--- 10.215.168.1 ping statistics ---
1 packets transmitted, 1 received, 0% packet loss, time 0ms
rtt min/avg/max/mdev = 0.214/0.214/0.214/0.000 ms

Step 3: Run command 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
Jan 10 14:05:13.299436 osdx systemd-journald[1663]: Runtime Journal (/run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558) is 2.0M, max 15.3M, 13.3M free.
Jan 10 14:05:13.300542 osdx systemd-journald[1663]: Received client request to rotate journal, rotating.
Jan 10 14:05:13.300583 osdx systemd-journald[1663]: Vacuuming done, freed 0B of archived journals from /run/log/journal/b02b6f729b7f4d8fa7abd9f8efa86558.
Jan 10 14:05:13.310694 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system journal clear'.
Jan 10 14:05:13.616205 osdx osdx-coredump[23736]: Deleting all coredumps in /opt/vyatta/etc/config/coredump...
Jan 10 14:05:13.623936 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'system coredump delete all'.
Jan 10 14:05:14.082772 osdx OSDxCLI[16822]: User 'admin' entered the configuration menu.
Jan 10 14:05:14.153059 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect dictionary 130 custom app-id 155 fqdn 10.215.168.1'.
Jan 10 14:05:14.256453 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect enable_dict_match_priv_ip'.
Jan 10 14:05:14.319281 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-url'.
Jan 10 14:05:14.419198 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic selector APPID rule 1 app-id custom 155'.
Jan 10 14:05:14.481022 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 selector APPID'.
Jan 10 14:05:14.598516 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 action drop'.
Jan 10 14:05:14.696757 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set traffic policy DROP rule 1 log app-id'.
Jan 10 14:05:14.785257 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 traffic policy out DROP'.
Jan 10 14:05:14.860230 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set interfaces ethernet eth1 address 10.215.168.64/24'.
Jan 10 14:05:14.916120 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'set system conntrack app-detect http-host'.
Jan 10 14:05:15.031904 osdx OSDxCLI[16822]: User 'admin' added a new cfg line: 'show working'.
Jan 10 14:05:15.146457 osdx INFO[23784]: FRR daemons did not change
Jan 10 14:05:15.304557 osdx kernel: app-detect: module init
Jan 10 14:05:15.304649 osdx kernel: app-detect: registered: sysctl net.appdetect
Jan 10 14:05:15.304674 osdx kernel: app-detect: expression init
Jan 10 14:05:15.304694 osdx kernel: app-detect: appid cache initialized
Jan 10 14:05:15.304723 osdx kernel: app-detect: appid cache changes counter initialized
Jan 10 14:05:15.857523 osdx cfgd[1450]: [16822]Completed change to active configuration
Jan 10 14:05:15.883032 osdx OSDxCLI[16822]: User 'admin' committed the configuration.
Jan 10 14:05:15.904132 osdx OSDxCLI[16822]: User 'admin' left the configuration menu.
Jan 10 14:05:16.050332 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'ping 10.215.168.1 count 1 size 56 timeout 1'.
Jan 10 14:05:16.185329 osdx file_operation[23936]: using src url: http://10.215.168.1/~robot/ dst url: running://index.html
Jan 10 14:05:16.192566 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=20875 DF PROTO=TCP SPT=37970 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jan 10 14:05:16.396564 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=20876 DF PROTO=TCP SPT=37970 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jan 10 14:05:16.808578 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=20877 DF PROTO=TCP SPT=37970 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jan 10 14:05:17.640577 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=20878 DF PROTO=TCP SPT=37970 DPT=80 WINDOW=502 RES=0x00 ACK PSH URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jan 10 14:05:19.211772 osdx file_operation.py[23936]: Operation aborted by user.
Jan 10 14:05:19.220534 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=20879 DF PROTO=TCP SPT=37970 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]
Jan 10 14:05:19.227015 osdx OSDxCLI[16822]: User 'admin' executed a new command: 'file copy http://10.215.168.1/~robot/ running://index.html'.
Jan 10 14:05:19.272588 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=20880 DF PROTO=TCP SPT=37970 DPT=80 WINDOW=502 RES=0x00 ACK PSH FIN URGP=0 APPDETECT[U:155 http-url:/~robot/ http-host:10.215.168.1]