Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

T6362: Create conntrack logger daemon #3804

Merged
merged 1 commit into from
Jul 29, 2024
Merged

Conversation

HollyGurza
Copy link
Contributor

@HollyGurza HollyGurza commented Jul 9, 2024

Change Summary

Created conntrack logger daemon based on pyroute2

The current format log is similar to the command contract -E, also added cta_id and ability to add flow-based timestamp extension

log example:

Jul 16 12:54:54 vyos-conntrack-logger[9387]: [NEW]     1411737613 udp      17 30 src=192.168.122.1 dst=192.168.122.255 sport=17500 dport=17500 [UNREPLIED] src=192.168.122.255 dst=192.168.122.1 sport=17500 dport=17500
Jul 16 12:55:12 vyos-conntrack-logger[9387]: [NEW]     2800357913 tcp      6 120 SYN_SENT src=192.168.122.1 dst=192.168.122.166 sport=38854 dport=5201 [UNREPLIED] src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=38854
Jul 16 12:55:12 vyos-conntrack-logger[9387]: [DESTROY] 2800357913 tcp      6 120 CLOSE src=192.168.122.1 dst=192.168.122.166 sport=38854 dport=5201 [UNREPLIED] src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=38854 start=1721134512551045816 stop=1721134512551109629 delta=6.4e-05
Jul 16 12:55:24 vyos-conntrack-logger[9387]: [DESTROY] 1411737613 udp      17 src=192.168.122.1 dst=192.168.122.255 sport=17500 dport=17500 [UNREPLIED] src=192.168.122.255 dst=192.168.122.1 sport=17500 dport=17500 start=1721134494073916335 stop=1721134524073621287 delta=29.999705
Jul 16 12:55:24 vyos-conntrack-logger[9387]: [NEW]     1411737613 udp      17 30 src=192.168.122.1 dst=192.168.122.255 sport=17500 dport=17500 [UNREPLIED] src=192.168.122.255 dst=192.168.122.1 sport=17500 dport=17500
Jul 16 12:55:25 vyos-conntrack-logger[9387]: [NEW]     3137757669 tcp      6 120 SYN_SENT src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 [UNREPLIED] src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990
Jul 16 12:55:25 vyos-conntrack-logger[9387]: [UPDATE]  3137757669 tcp      6 60 SYN_RECV src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990
Jul 16 12:55:25 vyos-conntrack-logger[9387]: [UPDATE]  3137757669 tcp      6 432000 ESTABLISHED src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990  [ASSURED]
Jul 16 12:55:25 vyos-conntrack-logger[9387]: [NEW]     1036296743 tcp      6 120 SYN_SENT src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 [UNREPLIED] src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996
Jul 16 12:55:25 vyos-conntrack-logger[9387]: [UPDATE]  1036296743 tcp      6 60 SYN_RECV src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996
Jul 16 12:55:25 vyos-conntrack-logger[9387]: [UPDATE]  1036296743 tcp      6 300 ESTABLISHED src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996  [ASSURED]
Jul 16 12:55:30 vyos-conntrack-logger[9387]: [UPDATE]  1036296743 tcp      6 120 FIN_WAIT src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996  [ASSURED]
Jul 16 12:55:30 vyos-conntrack-logger[9387]: [UPDATE]  1036296743 tcp      6 60 CLOSE_WAIT src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996  [ASSURED]
Jul 16 12:55:30 vyos-conntrack-logger[9387]: [UPDATE]  3137757669 tcp      6 120 FIN_WAIT src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990  [ASSURED]
Jul 16 12:55:30 vyos-conntrack-logger[9387]: [UPDATE]  3137757669 tcp      6 60 CLOSE_WAIT src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990  [ASSURED]
Jul 16 12:55:31 vyos-conntrack-logger[9387]: [UPDATE]  1036296743 tcp      6 30 LAST_ACK src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996  [ASSURED]
Jul 16 12:55:31 vyos-conntrack-logger[9387]: [UPDATE]  3137757669 tcp      6 30 LAST_ACK src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990  [ASSURED]
Jul 16 12:55:31 vyos-conntrack-logger[9387]: [UPDATE]  1036296743 tcp      6 120 TIME_WAIT src=192.168.122.1 dst=192.168.122.166 sport=41996 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41996  [ASSURED]
Jul 16 12:55:31 vyos-conntrack-logger[9387]: [UPDATE]  3137757669 tcp      6 120 TIME_WAIT src=192.168.122.1 dst=192.168.122.166 sport=41990 dport=5201 src=192.168.122.166 dst=192.168.122.1 sport=5201 dport=41990  [ASSURED]

Types of changes

  • Bug fix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Code style update (formatting, renaming)
  • Refactoring (no functional changes)
  • Migration from an old Vyatta component to vyos-1x, please link to related PR inside obsoleted component
  • Other (please describe):

Related Task(s)

Related PR(s)

Component(s) name

Proposed changes

# set system conntrack log 
Possible completions:
 > event                Filter by event type and protocol
   queue-size           Internal queue size for nf messages
   timestamp            Log connection tracking events include flow-based timestamp

here
timestamp - turns on flow-based timestamp extension
https://patchwork.ozlabs.org/project/netdev/patch/[email protected]/
queue-size - allows to configure of internal queue message size to avoid queue overload in high load.
event - configure events available for logging, by default all protocols in selected events will be logged
also each event type can be filtered by protocols e.g.:

# set system conntrack log event new 
Possible completions:
   icmp                 Log connection tracking events for ICMP
   other                Log connection tracking events for all protocols other than TCP,
                        UDP and ICMP
   tcp                  Log connection tracking events for TCP
   udp                  Log connection tracking events for UDP

How to test

set system conntrack log event destroy
set system conntrack log event new
set system conntrack log event update
commit

run monitor log

Smoketest result

vyos@vyos:~$ python3 /usr/libexec/vyos/tests/smoke/cli/test_system_conntrack.py 
test_conntrack_hash_size (__main__.TestSystemConntrack.test_conntrack_hash_size) ... ok
test_conntrack_ignore (__main__.TestSystemConntrack.test_conntrack_ignore) ... 
WARNING: It is prefered to define ipv4 conntrack ignore rules in
<firewall ipv4 prerouting raw> section


WARNING: It is prefered to define ipv6 conntrack ignore rules in
<firewall ipv6 prerouting raw> section

ok
test_conntrack_log (__main__.TestSystemConntrack.test_conntrack_log) ... ok
test_conntrack_module_enable (__main__.TestSystemConntrack.test_conntrack_module_enable) ... ok
test_conntrack_options (__main__.TestSystemConntrack.test_conntrack_options) ... ok
test_conntrack_timeout_custom (__main__.TestSystemConntrack.test_conntrack_timeout_custom) ... ok

----------------------------------------------------------------------
Ran 6 tests in 37.699s

OK

Checklist:

  • I have read the CONTRIBUTING document
  • I have linked this PR to one or more Phabricator Task(s)
  • I have run the components SMOKETESTS if applicable
  • My commit headlines contain a valid Task id
  • My change requires a change to the documentation
  • I have updated the documentation accordingly

@HollyGurza HollyGurza requested a review from a team as a code owner July 9, 2024 10:52
@HollyGurza HollyGurza marked this pull request as draft July 9, 2024 10:53
Copy link

github-actions bot commented Jul 9, 2024

👍
No issues in PR Title / Commit Title

Copy link

github-actions bot commented Jul 9, 2024

👍
No issues in unused-imports

Comment on lines 352 to 362
try:
while True:
logger.debug('Enter main loop...')
if shutdown:
break
for msg in ct.get():
parsed_event = parse_conntrack_event(msg, conf_proto)

if parsed_event:
message = format_event_message(parsed_event)
logger.info(message)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we need to use queues with threads here to keep control over the daemon in high loads and utilize all available CPU cores for processing.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

done.
One thread receives socket messages and puts them into the queue, several processes (one per CPU) get messages from the queue and parse them, write log.

NOTE: In the current implementation, the order of messages in the log may be disrupted because messages are parsed asynchronously

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NOTE: In the current implementation, the order of messages in the log may be disrupted because messages are parsed asynchronously

This is a problem. A common use case for this feature is to detect a connection's start and end times.

Copy link
Member

@dmbaturin dmbaturin left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems mostly good, I left some comments about possible improvements and clarifications.

interface-definitions/system_conntrack.xml.in Outdated Show resolved Hide resolved
interface-definitions/system_conntrack.xml.in Outdated Show resolved Hide resolved
interface-definitions/system_conntrack.xml.in Show resolved Hide resolved
src/systemd/vyos-conntrack-logger.service Outdated Show resolved Hide resolved
src/systemd/vyos-conntrack-logger.service Show resolved Hide resolved
src/services/vyos-conntrack-logger Outdated Show resolved Hide resolved
src/services/vyos-conntrack-logger Outdated Show resolved Hide resolved

while not shutdown_event.is_set():
if not ct.pthread.is_alive():
if ct.buffer_queue.qsize()/ct.async_qsize < 0.9:
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm confused by this part, to be fair. Could you clarify?

  • Why is the queue fullness check needed here?
  • How was the threshold of 90% chosen?
  • Why the listener thread should not be restarted if it's dead and the queue is >90% full?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Restarting the thread right away seems like a bad idea to me, because it will probably crash again almost immediately because the queue will still be nearly full or full.
To avoid wasting resources on restarting a thread that is obviously not working, it is better to wait until the queue is a little unloaded.
The threshold of 90% is taken as one of the options for waiting for free space in the queue, so as not to lose too many messages and not to spam with a new thread too often, we can set any threshold or even just empty the queue upon restart

Copy link

CI integration ❌ failed!

Details

CI logs

  • CLI Smoketests ❌ failed
  • Config tests 👍 passed
  • RAID1 tests 👍 passed

Copy link
Member

@dmbaturin dmbaturin left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's get it in, then we can refine it.

@dmbaturin dmbaturin merged commit 7724a5f into vyos:current Jul 29, 2024
13 of 14 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

Successfully merging this pull request may close these issues.

4 participants