All of lore.kernel.org
 help / color / mirror / Atom feed
* Difficulties with ulog / NFCT
@ 2020-02-15 16:03 Alessandro Vesely
  2020-02-17 14:13 ` Alessandro Vesely
  0 siblings, 1 reply; 6+ messages in thread
From: Alessandro Vesely @ 2020-02-15 16:03 UTC (permalink / raw)
  To: netfilter

Hi,

I've set up logging as follows, to get a history of TCP connections:

# conntrack logging to MariaDB
stack=ct1:NFCT,ip2str1:IP2STR,mysql1:MYSQL

[ct1]
accept_proto_filter=tcp # layer 4 proto of connections
event_mask=0x00000004 # only listen to DESTROY events

[mysql1]
table="ct"
reconnect=4
connect_timeout=60
procedure="INSERT"
db="ulog"
host="localhost"
user="ulog"
pass="*****"
port=3306


It doesn't work well.  For example, I get this:

MariaDB [ulog]> SELECT FROM_UNIXTIME(flow_start_sec) AS start, flow_end_sec - flow_start_sec AS sec,
> orig_ip_saddr_str AS src, orig_l4_sport AS sport, orig_ip_daddr_str, orig_l4_dport AS svc
> FROM ct WHERE orig_ip_saddr_str = '66.110.216.209';
+-------+------+----------------+-------+-------------------+------+
| start | sec  | src            | sport | orig_ip_daddr_str | svc  |
+-------+------+----------------+-------+-------------------+------+
| NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
| NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
+-------+------+----------------+-------+-------------------+------+
2 rows in set (0.00 sec)



flow_start_sec and flow_end_sec are both NULL, after several hours.  They seem to be non-NULL for outgoing connections and for connections coming from the internal network.  Even then, they don't seem to be accurate timings.

The mail log for the IP above IP is as follows (the source port is always 32767):

Feb 15 12:08:07 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[41204]
Feb 15 12:08:16 23 north imapd: Disconnected, ip=[66.110.216.209], port=[41204], time=16
Feb 15 12:08:47 23 north imapd: Connection, ip=[66.110.216.209], port=[45344]
Feb 15 12:08:54 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[45344]
Feb 15 12:09:06 23 north imapd: Disconnected, ip=[66.110.216.209], port=[45344], time=19

Disconnections are likely caused by conntrack -D -s 66.110.216.209.  I'm reporting abusive login attempts at end-of-day, and I've been told to mention my server (target) address and port, 62.94.243.226:143 in this case.  Since the mail log doesn't mention that data, the idea is to find it in the NFCT log based on the time and source IP.

Should I be running conntrackd?
Should I play with socket buffer/ resync timeout/ backlog_oneshot_requests/ ring_buffer_size?
Any other hint?


TIA
Ale
-- 

























^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Difficulties with ulog / NFCT
  2020-02-15 16:03 Difficulties with ulog / NFCT Alessandro Vesely
@ 2020-02-17 14:13 ` Alessandro Vesely
  2020-02-17 14:19   ` Alessandro Vesely
  2020-02-17 15:53   ` Anton Danilov
  0 siblings, 2 replies; 6+ messages in thread
From: Alessandro Vesely @ 2020-02-17 14:13 UTC (permalink / raw)
  To: netfilter

Hi,

Only the start timestamp is NULL, the end one looks fine.  I tried setting
hash_enable=0, it apparently didn't better nor worse the logging.


In /proc/net/nf_conntrack there is no timestamp, but port numbers seem good
(there is no port 32767).


What am I missing?

Best
Ale

On Sat 15/Feb/2020 17:03:19 +0100 Alessandro Vesely wrote:
> I've set up logging as follows, to get a history of TCP connections:
> 
> # conntrack logging to MariaDB
> stack=ct1:NFCT,ip2str1:IP2STR,mysql1:MYSQL
> 
> [ct1]
> accept_proto_filter=tcp # layer 4 proto of connections
> event_mask=0x00000004 # only listen to DESTROY events
> 
> [mysql1]
> table="ct"
> reconnect=4
> connect_timeout=60
> procedure="INSERT"
> db="ulog"
> host="localhost"
> user="ulog"
> pass="*****"
> port=3306
> 
> 
> It doesn't work well.  For example, I get this:
> 
> MariaDB [ulog]> SELECT FROM_UNIXTIME(flow_start_sec) AS start, flow_end_sec - flow_start_sec AS sec,
>> orig_ip_saddr_str AS src, orig_l4_sport AS sport, orig_ip_daddr_str, orig_l4_dport AS svc
>> FROM ct WHERE orig_ip_saddr_str = '66.110.216.209';
> +-------+------+----------------+-------+-------------------+------+
> | start | sec  | src            | sport | orig_ip_daddr_str | svc  |
> +-------+------+----------------+-------+-------------------+------+
> | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
> | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
> +-------+------+----------------+-------+-------------------+------+
> 2 rows in set (0.00 sec)
> 
> 
> 
> flow_start_sec and flow_end_sec are both NULL, after several hours.  They seem to be non-NULL for outgoing connections and for connections coming from the internal network.  Even then, they don't seem to be accurate timings.
> 
> The mail log for the IP above IP is as follows (the source port is always 32767):
> 
> Feb 15 12:08:07 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[41204]
> Feb 15 12:08:16 23 north imapd: Disconnected, ip=[66.110.216.209], port=[41204], time=16
> Feb 15 12:08:47 23 north imapd: Connection, ip=[66.110.216.209], port=[45344]
> Feb 15 12:08:54 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[45344]
> Feb 15 12:09:06 23 north imapd: Disconnected, ip=[66.110.216.209], port=[45344], time=19
> 
> Disconnections are likely caused by conntrack -D -s 66.110.216.209.  I'm reporting abusive login attempts at end-of-day, and I've been told to mention my server (target) address and port, 62.94.243.226:143 in this case.  Since the mail log doesn't mention that data, the idea is to find it in the NFCT log based on the time and source IP.
> 
> Should I be running conntrackd?
> Should I play with socket buffer/ resync timeout/ backlog_oneshot_requests/ ring_buffer_size?
> Any other hint?
> 
> 
> TIA
> Ale
> 

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Difficulties with ulog / NFCT
  2020-02-17 14:13 ` Alessandro Vesely
@ 2020-02-17 14:19   ` Alessandro Vesely
  2020-02-17 15:53   ` Anton Danilov
  1 sibling, 0 replies; 6+ messages in thread
From: Alessandro Vesely @ 2020-02-17 14:19 UTC (permalink / raw)
  To: netfilter

Hi again,

BTW, is there any chance to add the process command/ executable/ whatever (a la
netstat -p)?


TIA
Ale


On Mon 17/Feb/2020 15:13:52 +0100 Alessandro Vesely wrote:
> Hi,
> 
> Only the start timestamp is NULL, the end one looks fine.  I tried setting
> hash_enable=0, it apparently didn't better nor worse the logging.
> 
> 
> In /proc/net/nf_conntrack there is no timestamp, but port numbers seem good
> (there is no port 32767).
> 
> 
> What am I missing?
> 
> Best
> Ale
> 
> On Sat 15/Feb/2020 17:03:19 +0100 Alessandro Vesely wrote:
>> I've set up logging as follows, to get a history of TCP connections:
>> 
>> # conntrack logging to MariaDB
>> stack=ct1:NFCT,ip2str1:IP2STR,mysql1:MYSQL
>> 
>> [ct1]
>> accept_proto_filter=tcp # layer 4 proto of connections
>> event_mask=0x00000004 # only listen to DESTROY events
>> 
>> [mysql1]
>> table="ct"
>> reconnect=4
>> connect_timeout=60
>> procedure="INSERT"
>> db="ulog"
>> host="localhost"
>> user="ulog"
>> pass="*****"
>> port=3306
>> 
>> 
>> It doesn't work well.  For example, I get this:
>> 
>> MariaDB [ulog]> SELECT FROM_UNIXTIME(flow_start_sec) AS start, flow_end_sec - flow_start_sec AS sec,
>>> orig_ip_saddr_str AS src, orig_l4_sport AS sport, orig_ip_daddr_str, orig_l4_dport AS svc
>>> FROM ct WHERE orig_ip_saddr_str = '66.110.216.209';
>> +-------+------+----------------+-------+-------------------+------+
>> | start | sec  | src            | sport | orig_ip_daddr_str | svc  |
>> +-------+------+----------------+-------+-------------------+------+
>> | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
>> | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
>> +-------+------+----------------+-------+-------------------+------+
>> 2 rows in set (0.00 sec)
>> 
>> 
>> 
>> flow_start_sec and flow_end_sec are both NULL, after several hours.  They seem to be non-NULL for outgoing connections and for connections coming from the internal network.  Even then, they don't seem to be accurate timings.
>> 
>> The mail log for the IP above IP is as follows (the source port is always 32767):
>> 
>> Feb 15 12:08:07 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[41204]
>> Feb 15 12:08:16 23 north imapd: Disconnected, ip=[66.110.216.209], port=[41204], time=16
>> Feb 15 12:08:47 23 north imapd: Connection, ip=[66.110.216.209], port=[45344]
>> Feb 15 12:08:54 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[45344]
>> Feb 15 12:09:06 23 north imapd: Disconnected, ip=[66.110.216.209], port=[45344], time=19
>> 
>> Disconnections are likely caused by conntrack -D -s 66.110.216.209.  I'm reporting abusive login attempts at end-of-day, and I've been told to mention my server (target) address and port, 62.94.243.226:143 in this case.  Since the mail log doesn't mention that data, the idea is to find it in the NFCT log based on the time and source IP.
>> 
>> Should I be running conntrackd?
>> Should I play with socket buffer/ resync timeout/ backlog_oneshot_requests/ ring_buffer_size?
>> Any other hint?
>> 
>> 
>> TIA
>> Ale
>> 
> 

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Difficulties with ulog / NFCT
  2020-02-17 14:13 ` Alessandro Vesely
  2020-02-17 14:19   ` Alessandro Vesely
@ 2020-02-17 15:53   ` Anton Danilov
  2020-02-17 18:01     ` Alessandro Vesely
  1 sibling, 1 reply; 6+ messages in thread
From: Anton Danilov @ 2020-02-17 15:53 UTC (permalink / raw)
  To: Alessandro Vesely; +Cc: netfilter

Have you enabled the conntrack accounting and conntrack timestamps via sysctl?

On Mon, 17 Feb 2020 at 18:13, Alessandro Vesely <vesely@tana.it> wrote:
>
> Hi,
>
> Only the start timestamp is NULL, the end one looks fine.  I tried setting
> hash_enable=0, it apparently didn't better nor worse the logging.
>
>
> In /proc/net/nf_conntrack there is no timestamp, but port numbers seem good
> (there is no port 32767).
>
>
> What am I missing?
>
> Best
> Ale
>
> On Sat 15/Feb/2020 17:03:19 +0100 Alessandro Vesely wrote:
> > I've set up logging as follows, to get a history of TCP connections:
> >
> > # conntrack logging to MariaDB
> > stack=ct1:NFCT,ip2str1:IP2STR,mysql1:MYSQL
> >
> > [ct1]
> > accept_proto_filter=tcp # layer 4 proto of connections
> > event_mask=0x00000004 # only listen to DESTROY events
> >
> > [mysql1]
> > table="ct"
> > reconnect=4
> > connect_timeout=60
> > procedure="INSERT"
> > db="ulog"
> > host="localhost"
> > user="ulog"
> > pass="*****"
> > port=3306
> >
> >
> > It doesn't work well.  For example, I get this:
> >
> > MariaDB [ulog]> SELECT FROM_UNIXTIME(flow_start_sec) AS start, flow_end_sec - flow_start_sec AS sec,
> >> orig_ip_saddr_str AS src, orig_l4_sport AS sport, orig_ip_daddr_str, orig_l4_dport AS svc
> >> FROM ct WHERE orig_ip_saddr_str = '66.110.216.209';
> > +-------+------+----------------+-------+-------------------+------+
> > | start | sec  | src            | sport | orig_ip_daddr_str | svc  |
> > +-------+------+----------------+-------+-------------------+------+
> > | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
> > | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
> > +-------+------+----------------+-------+-------------------+------+
> > 2 rows in set (0.00 sec)
> >
> >
> >
> > flow_start_sec and flow_end_sec are both NULL, after several hours.  They seem to be non-NULL for outgoing connections and for connections coming from the internal network.  Even then, they don't seem to be accurate timings.
> >
> > The mail log for the IP above IP is as follows (the source port is always 32767):
> >
> > Feb 15 12:08:07 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[41204]
> > Feb 15 12:08:16 23 north imapd: Disconnected, ip=[66.110.216.209], port=[41204], time=16
> > Feb 15 12:08:47 23 north imapd: Connection, ip=[66.110.216.209], port=[45344]
> > Feb 15 12:08:54 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[45344]
> > Feb 15 12:09:06 23 north imapd: Disconnected, ip=[66.110.216.209], port=[45344], time=19
> >
> > Disconnections are likely caused by conntrack -D -s 66.110.216.209.  I'm reporting abusive login attempts at end-of-day, and I've been told to mention my server (target) address and port, 62.94.243.226:143 in this case.  Since the mail log doesn't mention that data, the idea is to find it in the NFCT log based on the time and source IP.
> >
> > Should I be running conntrackd?
> > Should I play with socket buffer/ resync timeout/ backlog_oneshot_requests/ ring_buffer_size?
> > Any other hint?
> >
> >
> > TIA
> > Ale
> >



-- 
Anton Danilov.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Difficulties with ulog / NFCT
  2020-02-17 15:53   ` Anton Danilov
@ 2020-02-17 18:01     ` Alessandro Vesely
  2020-06-14 11:33       ` Alessandro Vesely
  0 siblings, 1 reply; 6+ messages in thread
From: Alessandro Vesely @ 2020-02-17 18:01 UTC (permalink / raw)
  To: Anton Danilov; +Cc: netfilter

On Mon 17/Feb/2020 16:53:23 +0100 Anton Danilov wrote:
> Have you enabled the conntrack accounting and conntrack timestamps via sysctl?


Nope.  I don't need accounting, and I didn't know about timestamps.

Now I set nf_conntrack_timestamp=1 and I'm starting to get some non-NULL
timestamps.  Great!

In /proc/net/nf_conntrack I have delta-time=n, presumably secs.


Thank you
Ale

> On Mon, 17 Feb 2020 at 18:13, Alessandro Vesely <vesely@tana.it> wrote:
>>
>> Hi,
>>
>> Only the start timestamp is NULL, the end one looks fine.  I tried setting
>> hash_enable=0, it apparently didn't better nor worse the logging.
>>
>>
>> In /proc/net/nf_conntrack there is no timestamp, but port numbers seem good
>> (there is no port 32767).
>>
>>
>> What am I missing?
>>
>> Best
>> Ale
>>
>> On Sat 15/Feb/2020 17:03:19 +0100 Alessandro Vesely wrote:
>> > I've set up logging as follows, to get a history of TCP connections:
>> >
>> > # conntrack logging to MariaDB
>> > stack=ct1:NFCT,ip2str1:IP2STR,mysql1:MYSQL
>> >
>> > [ct1]
>> > accept_proto_filter=tcp # layer 4 proto of connections
>> > event_mask=0x00000004 # only listen to DESTROY events
>> >
>> > [mysql1]
>> > table="ct"
>> > reconnect=4
>> > connect_timeout=60
>> > procedure="INSERT"
>> > db="ulog"
>> > host="localhost"
>> > user="ulog"
>> > pass="*****"
>> > port=3306
>> >
>> >
>> > It doesn't work well.  For example, I get this:
>> >
>> > MariaDB [ulog]> SELECT FROM_UNIXTIME(flow_start_sec) AS start, flow_end_sec - flow_start_sec AS sec,
>> >> orig_ip_saddr_str AS src, orig_l4_sport AS sport, orig_ip_daddr_str, orig_l4_dport AS svc
>> >> FROM ct WHERE orig_ip_saddr_str = '66.110.216.209';
>> > +-------+------+----------------+-------+-------------------+------+
>> > | start | sec  | src            | sport | orig_ip_daddr_str | svc  |
>> > +-------+------+----------------+-------+-------------------+------+
>> > | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
>> > | NULL  | NULL | 66.110.216.209 | 32767 | 62.94.243.226     |  143 |
>> > +-------+------+----------------+-------+-------------------+------+
>> > 2 rows in set (0.00 sec)
>> >
>> >
>> >
>> > flow_start_sec and flow_end_sec are both NULL, after several hours.  They seem to be non-NULL for outgoing connections and for connections coming from the internal network.  Even then, they don't seem to be accurate timings.
>> >
>> > The mail log for the IP above IP is as follows (the source port is always 32767):
>> >
>> > Feb 15 12:08:07 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[41204]
>> > Feb 15 12:08:16 23 north imapd: Disconnected, ip=[66.110.216.209], port=[41204], time=16
>> > Feb 15 12:08:47 23 north imapd: Connection, ip=[66.110.216.209], port=[45344]
>> > Feb 15 12:08:54 22 north imapd: LOGIN FAILED, user=sungjtrio@fragoline.it, ip=[66.110.216.209], port=[45344]
>> > Feb 15 12:09:06 23 north imapd: Disconnected, ip=[66.110.216.209], port=[45344], time=19
>> >
>> > Disconnections are likely caused by conntrack -D -s 66.110.216.209.  I'm reporting abusive login attempts at end-of-day, and I've been told to mention my server (target) address and port, 62.94.243.226:143 in this case.  Since the mail log doesn't mention that data, the idea is to find it in the NFCT log based on the time and source IP.
>> >
>> > Should I be running conntrackd?
>> > Should I play with socket buffer/ resync timeout/ backlog_oneshot_requests/ ring_buffer_size?
>> > Any other hint?
>> >
>> >
>> > TIA
>> > Ale
>> >
> 
> 
> 

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Difficulties with ulog / NFCT
  2020-02-17 18:01     ` Alessandro Vesely
@ 2020-06-14 11:33       ` Alessandro Vesely
  0 siblings, 0 replies; 6+ messages in thread
From: Alessandro Vesely @ 2020-06-14 11:33 UTC (permalink / raw)
  To: Anton Danilov; +Cc: netfilter

On Mon 17/Feb/2020 19:01:00 +0100 Alessandro Vesely wrote:
> On Mon 17/Feb/2020 16:53:23 +0100 Anton Danilov wrote:
>> Have you enabled the conntrack accounting and conntrack timestamps via sysctl?
> 
> 
> Nope.  [...]
> 
> Now I set nf_conntrack_timestamp=1 and I'm starting to get some non-NULL
> timestamps.  Great!


At the time, I also wrote a file:

# ls -labt /etc/sysctl.d/timestamps*
-rw-r--r-- 1 root root 65 Feb 17 18:27 /etc/sysctl.d/timestamps_in_nfct_ulog.conf

# cat !$
cat /etc/sysctl.d/timestamps*
# start timestamp in ulog
net.netfilter.nf_conntrack_timestamp=1

Yet, upon reboot, I found:
net.netfilter.nf_conntrack_timestamp = 0

The only (cryptic) message I found in the logs was:
[  168.919868] nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead.

Any idea what went wrong?


For a second warning to people on this path, the LSB headers in my ulog2 init script missed the following:
# Should-Start:      mysql
# Should-Stop:       mysql

I wrote an amended LSB in /etc/insserv/overrides/ulog2

Before doing so, ulogd erred out:
Jun 12 08:47:59 29 north ulogd[5681]: building new pluginstance stack: 'log1:NFLOG,base1:BASE,ifi1:IFINDEX,ip2str1:IP2STR,print1:PRINTPKT,emu1:LOGEMU'
Jun 12 08:47:59 27 north ulogd[5681]: can't find requested plugin PRINTPKT
Jun 12 08:47:59 29 north ulogd[5681]: building new pluginstance stack: 'ct1:NFCT,ip2str1:IP2STR,mysql1:MYSQL'
Jun 12 08:47:59 29 north ulogd[5681]: (re)configuring
Jun 12 08:47:59 27 north ulogd[5681]: can't connect to db: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2 "No such file or directory")
Jun 12 08:47:59 27 north ulogd[5681]: error in open_db
Jun 12 08:47:59 27 north ulogd[5681]: error during configure of plugin MYSQL
Jun 12 08:47:59 26 north ulogd[5681]: not even a single working plugin stack

I restarted it by /etc/init.d/ulogd2 start.  Could that error have cleared nf_conntrack_timestamp??


Best
Ale
-- 


























^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2020-06-14 11:33 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-02-15 16:03 Difficulties with ulog / NFCT Alessandro Vesely
2020-02-17 14:13 ` Alessandro Vesely
2020-02-17 14:19   ` Alessandro Vesely
2020-02-17 15:53   ` Anton Danilov
2020-02-17 18:01     ` Alessandro Vesely
2020-06-14 11:33       ` Alessandro Vesely

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.