Iptables rules with module string give strange counter results

Discussion:

Vladimir Budnev

2012-11-15 13:50:17 UTC

Hello everyone.

This is the first time I'm using matching string module for iptables
and faced with some strange behaviour I can't overcome.

In short, it looks like iptables passes "trimmed" packets to module,
so module can not parse whole packet for string. I cant find any
information about such behaviour on net. All examples and tutors
should work like a charm, but they dont.

Now in details.

OS: debian testing, kernel 3.2.0-3-686-pae
IPTABLES: iptables v1.4.14
OTHER:
tcpdump version 4.3.0,
libpcap version 1.3.0

# lsmod|grep ipt
ipt_LOG 12533 0
iptable_nat 12800 0
nf_nat 17924 1 iptable_nat
nf_conntrack_ipv4 13726 3 nf_nat,iptable_nat
nf_conntrack 43121 3 nf_conntrack_ipv4,nf_nat,iptable_nat
iptable_filter 12488 0
ip_tables 17079 2 iptable_filter,iptable_nat
x_tables 18121 6
ip_tables,iptable_filter,iptable_nat,xt_string,xt_tcpudp,ipt_LOG

I'v reseted all rules to default(nat,mangle,filter tables) and added
only two rules in following order:
iptables -t filter -A OUTPUT --protocol tcp --dport 80 --match string
--algo bm --from 0 --to 1500 --string "/index.php" --jump LOG
--log-prefix "matched :"
iptables -t filter -A OUTPUT --protocol tcp --dport 80 --jump LOG
--log-prefix "OUT : "

The example idea is obvious - match requests to any ip to port 80
containing string "/index.php" and signal matched to log, and also log
all the data passed to 80 port.

So the iptables -L -xvn :

Chain INPUT (policy ACCEPT 3 packets, 693 bytes)
pkts bytes target prot opt in out source
destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source
destination

Chain OUTPUT (policy ACCEPT 3 packets, 184 bytes)
pkts bytes target prot opt in out source
destination
0 0 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 STRING match "/index.php" ALGO
name bm TO 1500 LOG flags 0 level 4 prefix "matched :"
0 0 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 LOG flags 0 level 4 prefix "OUT : "

Counters for rules are zeroed.

Ok, now browser goes to www.gentoo.org/index.php. This is the only
request url in browser.
And I get the following for iptables -L -xvn:

Chain INPUT (policy ACCEPT 61 packets, 16657 bytes)
pkts bytes target prot opt in out source
destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source
destination

Chain OUTPUT (policy ACCEPT 63 packets, 4394 bytes)
pkts bytes target prot opt in out source
destination
1 380 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 STRING match "/index.php" ALGO
name bm TO 1500 LOG flags 0 level 4 prefix "matched :"
13 1392 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 LOG flags 0 level 4 prefix "OUT : "

So we have only ONE match for 1st rule. But that is wrong. Here is
tcpdump for output for connection.
First ip request 89.16.167.134:

<handshake omitted>
16:56:38.440308 IP 192.168.66.106.54704 > 89.16.167.134.80: Flags
[P.], seq 1:373, ack 1, win 913,
options [nop,nop,TS val 85359 ecr 3026115253], length 372
<...>
0x0030: b45e dab5 4745 5420 2f69 6e64 6578 2e70 .^..GET./index.p
0x0040: 6870 2048 5454 502f 312e 310d 0a48 6f73 hp.HTTP/1.1..Hos
0x0050: 743a 2077 7777 2e67 656e 746f 6f2e 6f72 t:.www.gentoo.or
0x0060: 670d 0a55 7365 722d 4167 656e 743a 204d g..User-Agent:.M
0x0070: 6f7a 696c 6c61 2f35 2e30 2028 5831 313b ozilla/5.0.(X11;

Here we see string in HTTP GET, but iptables did not match it (ill
explain below)!
Ok some packets later we have request for some more content to ip
140.211.166.176:

16:56:38.772432 IP 192.168.66.106.59766 > 140.211.166.176.80: Flags
[P.], seq 1:329, ack 1, win 913,
options [nop,nop,TS val 85442 ecr 110101513], length 328
<...>
0x0030: 0690 0409 4745 5420 2f20 4854 5450 2f31 ....GET./.HTTP/1
<...>
0x0130: 6566 6c61 7465 0d0a 436f 6e6e 6563 7469 eflate..Connecti
0x0140: 6f6e 3a20 6b65 6570 2d61 6c69 7665 0d0a on:.keep-alive..
0x0150: 5265 6665 7265 723a 2068 7474 703a 2f2f Referer:.http://
0x0160: 7777 772e 6765 6e74 6f6f 2e6f 7267 2f69 www.gentoo.org/i
0x0170: 6e64 6578 2e70 6870 0d0a 0d0a ndex.php....

Here we see "/index.php" again.

And LOG rule gives the following info:

kernel: [ 641.386182] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=60
kernel: [ 641.435946] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.436226] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=424
kernel: [ 641.512594] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.512762] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.512819] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.567496] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=60
kernel: [ 641.767707] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.768328] matched :IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=380 <--
kernel: [ 641.768352] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=380
kernel: [ 641.990287] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.990455] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.990507] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.990559] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52

So we have match on only one packet, going to 140.211.166.176. But
where is the first match?
The more strange for me is that on other machine with ubuntu, it gives
different counters, like 6 matches for string.

Mb there is some kind of options to tune module data passing or am I
completly don't understand string matching idea?

Tnx in advance.

Vladimir Budnev

2012-11-15 14:01:08 UTC

Permalink

Hello al.

This is the first time I'm using matching string module for iptables
and met some strange behaviour I can't overcome.

In short, it looks like iptables passes "trimmed" packets to module,
so module can not parse whole packet for string.
I cant find any information about such behaviour on net. All examples
and tutors should work like a charm, but they dont.

Now in details.

OS: debian testing, kernel 3.2.0-3-686-pae
IPTABLES: iptables v1.4.14
OTHER:

tcpdump version 4.3.0,
libpcap version 1.3.0

# lsmod|grep ipt
ipt_LOG 12533 0
iptable_nat 12800 0
nf_nat 17924 1 iptable_nat
nf_conntrack_ipv4 13726 3 nf_nat,iptable_nat
nf_conntrack 43121 3 nf_conntrack_ipv4,nf_nat,iptable_nat
iptable_filter 12488 0
ip_tables 17079 2 iptable_filter,iptable_nat
x_tables 18121 6
ip_tables,iptable_filter,iptable_nat,xt_string,xt_tcpudp,ipt_LOG

I'v reseted all rules to default and added only two rules in following order:
iptables -t filter -A OUTPUT --protocol tcp --dport 80 --match string
--algo bm --from 0 --to 1500 --string "/index.php" --jump LOG
--log-prefix "matched :"
iptables -t filter -A OUTPUT --protocol tcp --dport 80 --jump LOG
--log-prefix "OUT : "

The idea is obious - match requests to any ip to port 80 containing
string /index.php and print them to log, and also log all the data
passed to 80 port.

So the iptables -L -xvn :

Chain INPUT (policy ACCEPT 3 packets, 693 bytes)
pkts bytes target prot opt in out source
destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source
destination

Chain OUTPUT (policy ACCEPT 3 packets, 184 bytes)
pkts bytes target prot opt in out source
destination
0 0 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 STRING match "/index.php" ALGO
name bm TO 1500 LOG flags 0 level 4 prefix "matched :"
0 0 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 LOG flags 0 level 4 prefix "OUT : "

Counters for rules are zeroed.

Ok, now browser goes to www.gentoo.org/index.php. This is the only
request url in browser.
And I get the following for iptables -t filter -L -xvn:

Chain INPUT (policy ACCEPT 61 packets, 16657 bytes)
pkts bytes target prot opt in out source
destination

Chain FORWARD (policy ACCEPT 0 packets, 0 bytes)
pkts bytes target prot opt in out source
destination

Chain OUTPUT (policy ACCEPT 63 packets, 4394 bytes)
pkts bytes target prot opt in out source
destination
1 380 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 STRING match "/index.php" ALGO
name bm TO 1500 LOG flags 0 level 4 prefix "matched :"
13 1392 LOG tcp -- * * 0.0.0.0/0
0.0.0.0/0 tcp dpt:80 LOG flags 0 level 4 prefix "OUT : "

So we have only ONE match for 1st rule. But that is wrong. Here is
tcpdump for output for connection.
First ip request 89.16.167.134:

<handshake omitted>
16:56:38.440308 IP 192.168.66.106.54704 > 89.16.167.134.80: Flags
[P.], seq 1:373, ack 1, win 913,
options [nop,nop,TS val 85359 ecr 3026115253], length 372
<...>
0x0030: b45e dab5 4745 5420 2f69 6e64 6578 2e70 .^..GET./index.p
0x0040: 6870 2048 5454 502f 312e 310d 0a48 6f73 hp.HTTP/1.1..Hos
0x0050: 743a 2077 7777 2e67 656e 746f 6f2e 6f72 t:.www.gentoo.or
0x0060: 670d 0a55 7365 722d 4167 656e 743a 204d g..User-Agent:.M
0x0070: 6f7a 696c 6c61 2f35 2e30 2028 5831 313b ozilla/5.0.(X11;

Here we see one match in HTTP GET. Ok some packets later we have
request for some more content to ip 140.211.166.176:
16:56:38.772432 IP 192.168.66.106.59766 > 140.211.166.176.80: Flags
[P.], seq 1:329, ack 1, win 913,
options [nop,nop,TS val 85442 ecr 110101513], length 328
<...>
0x0030: 0690 0409 4745 5420 2f20 4854 5450 2f31 ....GET./.HTTP/1
<...>
0x0130: 6566 6c61 7465 0d0a 436f 6e6e 6563 7469 eflate..Connecti
0x0140: 6f6e 3a20 6b65 6570 2d61 6c69 7665 0d0a on:.keep-alive..
0x0150: 5265 6665 7265 723a 2068 7474 703a 2f2f Referer:.http://
0x0160: 7777 772e 6765 6e74 6f6f 2e6f 7267 2f69 www.gentoo.org/i
0x0170: 6e64 6578 2e70 6870 0d0a 0d0a ndex.php....

Here we see "/index.php" again.

But LOG rule gives the following info:

kernel: [ 641.386182] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=60
kernel: [ 641.435946] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.436226] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=424
kernel: [ 641.512594] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.512762] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.512819] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=89.16.167.134 LEN=52
kernel: [ 641.567496] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=60
kernel: [ 641.767707] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.768328] matched :IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=380 <--
kernel: [ 641.768352] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=380
kernel: [ 641.990287] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.990455] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.990507] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52
kernel: [ 641.990559] OUT : IN= OUT=eth0 SRC=192.168.66.106
DST=140.211.166.176 LEN=52

So we have match on only one packet, going to 140.211.166.176. But
where is the first match?
The more strange for me is that on ither machine with ubuntu, it gives
different counters, like 6 matches for string.

Mb there is some kind of options to tune module data passing or smth?

Tnx in advance.
--
To unsubscribe from this list: send the line "unsubscribe netfilter" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

Stephan Balmer

2012-11-16 16:30:43 UTC

Permalink

Post by Vladimir Budnev
OS: debian testing, kernel 3.2.0-3-686-pae
iptables -t filter -A OUTPUT --protocol tcp --dport 80 --match string
--algo bm --from 0 --to 1500 --string "/index.php" --jump LOG
--log-prefix "matched :"

Works for me on Debian stock kernel 3.2.0-3-amd64.

Tnx for test.
You mean you get correct counters with 2 matches for both packets?

I only tested the part that didn't work for you:

iptables -t filter -A OUTPUT --protocol tcp --dport 80 --match string --algo bm --from 0 --to 1500 --string /index.php --jump LOG
echo -n "GET /index.php HTTP/1.1\r\nHost: www.gentoo.org\r\n\r\n" | nc 89.16.167.134 80

Can you list your iptables version ?

iptables v1.4.14
It shoudn't make a difference.

Vladimir Budnev

2012-11-19 09:10:10 UTC

Permalink

Perhaps your log daemon is squashing duplicate entries?

To be honest i dont care much about log messages, I do care about rule
counters:) The thing that scares me is my missunderstanding of "what
is going on?"

But I found when counters get incremented. Bulmer test with nc hinted
me to play a bit with tcp packet payload.

First run:
echo -n "GET /index.php HTTP/1.1\r\nHost: www.gentoo.org\r\n\r\n" | nc
89.16.167.134 80

gives no counters change. I get the page, but counters still unchanged. Okey...

Doing request like:
echo -n "GET BUBA-BUBA /index.php HTTP/1.1\r\nHost:
www.gentoo.org\r\n\r\n" | nc 89.16.167.134 80

I get "400 Bad request" and counters still unchaged. Okey....

!!! BUT !!!!
if I do something like
echo -n "GET BUBA-BUBA-BUBA-BUBAaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
/index.php HTTP/1.1\r\nHost: www.gentoo.org\r\n\r\n| nc 89.16.167.134
80

I get the same "400 Bad request", BUT now counters got incremented.

Seems like module start matching from the wrong position thus even
--from 0 (ommiting --from 0 for default does not change result) simply
does not work.

Ehm...
--
To unsubscribe from this list: send the line "unsubscribe netfilter" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html