netgraph mkpeer and connect failures with ng_ipfw and ng_nat
Erik Klavon
erikk at berkeley.edu
Fri Jan 15 17:22:01 UTC 2010
On Thu, Jan 14, 2010 at 02:46:35PM -0800, Erik Klavon wrote:
> I have several dual processor, single core amd64 machines running
> 8.0p1. These machines use netgraph to implement one to one NAT with
> one ng_nat(4) node for each network client behind them. ipfw(8) rules
> direct traffic to netgraph nodes as needed based on table entries
> using an ng_ipfw(4) node. As clients join and leave the network,
> scripts dynamically create and delete NAT sessions by making calls to
> ipfw(8), ngctl(8) and arp(8) to create and delete ng_nat(4) nodes,
> ipfw(8) table and published ARP entries. This scheme has worked well
> so far in all places we're using it except one.
>
> In the problematic case, immediately following boot up, creation and
> deletion of sessions work consistently. After a couple of hours, long
> enough for roughly 100 session creations and deletions, creation and
> deletion of sessions will occasionally fail during calls to
> ngctl(8). In all other cases, creation and deletion of sessions work
> consistently. The rate of session change appears to be greater in the
> problematic case, though the total number of active sessions when
> session creation and deletion start to fail is below the total number
> of sessions we see in non problematic cases. I have swapped out the
> machine in the problematic case with another machine with an identical
> configuration. This did not result in a change in behavior.
>
> Here are the calls to ngctl(8) we use to create a one to one NAT
> session, with the first two octets in the globally routable IPv4
> addresses replaced with an "x".
>
> ngctl mkpeer ipfw: nat 202182094 out
> ngctl name ipfw:202182094 WirelessNAT2182094
> ngctl connect ipfw: WirelessNAT2182094: 102182094 in
> ngctl msg WirelessNAT2182094: setaliasaddr x.x.182.94
> ngctl msg WirelessNAT2182094: redirectaddr \
> '{'"local_addr=10.10.115.242" "alias_addr=x.x.182.94" \
> 'description="Static NAT"' '}'
>
> For the identifiers above, we represent the globally routable IPv4
> address by an integer such as 2182094. The first digit of this integer
> represents the first two octets in the address (all addresses used
> have the same first two octets). The remaining digits are the third
> and forth octets with padded leading zeros as needed. We generate the
> hook names by prepending a two digit int representing the direction
> (20 out, 10 in) to the integer representing the globally routable IPv4
> address. This guarantees unique identifiers for all hooks and ng_nat(4)
> node names. We use multiple checks in the script that calls ngctl(8) to
> ensure that each globally routable address is used in exactly one
> session. We use a lock around the above calls prevent two session
> creation attempts from interleaving their ngctl(8) calls.
>
> Here is the call to ngctl(8) we use to delete a one to one NAT
> session. The lock around this call is the same used for creating a
> session.
>
> ngctl shutdown ipfw:202182094
>
> The first error leading to a session creation or deletion failure
> after booting I've observed is in the mkpeer call. Here is an example
> from yesterday, after booting the machine at roughly 0500.
>
> Jan 13 08:44:42 nac[11721]: ngctl: send msg: File exists
> Jan 13 08:44:42 nac[11722]: warning: Unsuccessful execution: /usr/sbin/ngctl mkpeer ipfw: nat 202182094 out
>
> This mkpeer call is the first time since boot that the globally
> routable IP address x.x.182.94 was used and the first attempt to
> create a hook named 202182094. Output from vmstat(8) -z captured every
> minute shows no incrementing of the allocation failure
> counters from well before 0844 to 0848. Reducing the number of
> netgraph threads (from 2 to 1) via the sysctl net.graph.threads has
> not had an effect on this problem. I can not think of any obvious
> reasons why this mkpeer call might have failed. 102 mkpeer calls prior
> to it did not.
>
> When a mkpeer call succeeds, the subsequent connect call in the above
> session creation sequence will fail, also with a "File exists"
> error. The next failure after the above example from yesterday is an
> example of this problem.
>
> Jan 13 08:51:45 nac[51209]: ngctl: send msg: File exists
> Jan 13 08:51:45 nac[51212]: warning: Unsuccessful execution: /usr/sbin/ngctl connect ipfw: WirelessNAT2175205: 102175205 in
>
> Also in this case, this is the first time since boot that the globally
> routable IP address x.x.175.205 was used and the first attempt to
> create a hook named 102175205. Output from vmstat(8) -z captured every
> minute shows no incrementing of the allocation failure
> counters from 0849 to 0900. There is an increment of the allocation
> failure counter for the 128 Bucket in vmstat(8) -z between 0848 and 0849;
> I assume that this is too far away in time from the two above events
> to be related. Also, the "File exists" error results from a check
> I don't think is related to memory allocation (see below).
>
> This morning prior to a reboot I modified the ngctl(8) calls to include
> the -d flag and obtained the following additional information.
>
> Jan 14 08:35:08 nac[3234]: ngctl: sendto(ipfw:): File exists
> Jan 14 08:35:08 nac[3234]: ngctl: send msg: File exists
> Jan 14 08:35:08 nac[3235]: warning: Unsuccessful execution: /usr/sbin/ngctl -d mkpeer ipfw: nat 202183148 out
>
> Jan 14 08:47:50 nac[94270]: ngctl: sendto(ipfw:): File exists
> Jan 14 08:47:50 nac[94270]: ngctl: send msg: File exists
> Jan 14 08:47:50 nac[94271]: warning: Unsuccessful execution: /usr/sbin/ngctl -d connect ipfw: WirelessNAT2175111: 102175111 in
>
> This points to ng_ipfw(4) as the source of these errors. I took a very
> quick look at the code to come up with the following interpretations;
> please let me know if you see any mistakes in the following. It looks
> to me like the error string "File exists" is displayed by ngctl(8) when
> the EEXIST constant is returned from ng_ipfw(4) when processing the
> command issued via ngctl(8). There is one place in ng_ipfw(4) where EEXIST
> is returned. This section of code appears to be used only when the
> single ipfw(8) node is first created, so I don't think it should be the
> source of the problem in this case. This leaves the parts of ng_base
> used to handle generic operations. EEXIST is returned by ng_base.c in
> the following functions.
>
> ng_newtype (called when a new netgraph type is installed)
> ng_add_hook (add an unconnected hook to a node)
> ng_con_nodes (connect this node with another node)
> ng_con_part2 (make the connection in the opposite direction of ng_con_nodes)
>
> ng_newtype probably isn't the source of the problem in this case,
> since we're not working with a new type. The other three functions are
> possible candidates for each of the above two error examples as in
> both cases hooks are created and connected. Here are the conditional
> statements that check for an EEXIST condition.
>
> ng_add_hook if (ng_findhook(node, name) != NULL) {
> ng_con_nodes if (ng_findhook(node2, name2) != NULL) {
> ng_con_part2 if (ng_findhook(node, NG_HOOK_NAME(hook)) != NULL) {
>
> In each of these cases, it appears that the code is checking to see if
> a hook with the argument name exists before creating a hook with that
> name. Given the conditions in the above two example errors that the
> hook names are unique and no hooks with these same names were
> previously created, I can't explain why the above calls to ng_findhook
> are returning references to hooks.
Each ng_ipfw(4) hook has associated with it a u_int16_t variable rulenum
as part of the ng_ipfw_hook_priv struct. When a hook is created, in
ng_ipfw_newhook rulenum is set to a value obtained from the hook name
via the following conversion.
/* Convert it to integer */
rulenum = (u_int16_t)strtol(name, &endptr, 10);
ng_ipfw(4)'s implementation of ng_findhook, ng_ipfw_findhook, uses this
conversion to supply a u_int16_t to ng_ipfw_findhook1, which performs
a direct binary comparison between the argument value and the rulenum
associated with each hook in place of the call to strcmp in ng_ipfw's
implementation of ng_findhook. I used the following program with data
taken from one of the examples in my last followup to Julian (which I
duplicate at the end of this message) to test this logic.
#include <sys/param.h>
#include <sys/lock.h>
#include <sys/mbuf.h>
#include <sys/malloc.h>
#include <sys/ctype.h>
#include <sys/errno.h>
#include <sys/rwlock.h>
#include <sys/socket.h>
#include <sys/syslog.h>
#include <net/if.h>
#include <netinet/in.h>
#include <netinet/in_systm.h>
#include <netinet/ip_fw.h>
#include <netinet/ip.h>
#include <netinet/ip_var.h>
#include <netgraph/ng_message.h>
#include <netgraph/ng_parse.h>
#include <netgraph/ng_ipfw.h>
#include <stdio.h>
int main() {
int tablesize = 118;
int i = 0;
char *table[tablesize];
char *name, *endptr;
u_int16_t n, t;
table[0] = "102175162";
table[1] = "202175162";
table[2] = "102182226";
table[3] = "202182226";
table[4] = "102182009";
table[5] = "202182009";
table[6] = "202174135";
table[7] = "102173144";
table[8] = "202173144";
table[9] = "102183171";
table[10] = "202183171";
table[11] = "102172040";
table[12] = "202172040";
table[13] = "102173235";
table[14] = "202173235";
table[15] = "102174107";
table[16] = "202174107";
table[17] = "102173033";
table[18] = "202173033";
table[19] = "102183226";
table[20] = "202183226";
table[21] = "102172216";
table[22] = "202172216";
table[23] = "102182129";
table[24] = "202182129";
table[25] = "102173201";
table[26] = "202173201";
table[27] = "102132178";
table[28] = "202132178";
table[29] = "102183212";
table[30] = "202183212";
table[31] = "102173179";
table[32] = "202173179";
table[33] = "102172132";
table[34] = "202172132";
table[35] = "102175045";
table[36] = "202175045";
table[37] = "102175215";
table[38] = "202175215";
table[39] = "102183173";
table[40] = "202183173";
table[41] = "102173180";
table[42] = "202173180";
table[43] = "102173171";
table[44] = "202173171";
table[45] = "102173025";
table[46] = "202173025";
table[47] = "102175064";
table[48] = "202175064";
table[49] = "102172038";
table[50] = "202172038";
table[51] = "102175035";
table[52] = "202175035";
table[53] = "102182254";
table[54] = "202182254";
table[55] = "102183083";
table[56] = "202183083";
table[57] = "102132088";
table[58] = "202132088";
table[59] = "102183201";
table[60] = "202183201";
table[61] = "102182255";
table[62] = "202182255";
table[63] = "102172085";
table[64] = "202172085";
table[65] = "102183127";
table[66] = "202183127";
table[67] = "102173146";
table[68] = "202173146";
table[69] = "102182071";
table[70] = "202182071";
table[71] = "102172073";
table[72] = "202172073";
table[73] = "102173186";
table[74] = "202173186";
table[75] = "102175067";
table[76] = "202175067";
table[77] = "102173061";
table[78] = "202173061";
table[79] = "102183115";
table[80] = "202183115";
table[81] = "102132147";
table[82] = "202132147";
table[83] = "102182233";
table[84] = "202182233";
table[85] = "102183051";
table[86] = "202183051";
table[87] = "102183102";
table[88] = "202183102";
table[89] = "102172157";
table[90] = "202172157";
table[91] = "102174083";
table[92] = "202174083";
table[93] = "102132017";
table[94] = "202132017";
table[95] = "102172065";
table[96] = "202172065";
table[97] = "102132142";
table[98] = "202132142";
table[99] = "102183163";
table[100] = "202183163";
table[101] = "102173094";
table[102] = "202173094";
table[103] = "102172147";
table[104] = "202172147";
table[105] = "102173066";
table[106] = "202173066";
table[107] = "102132098";
table[108] = "202132098";
table[109] = "102173166";
table[110] = "202173166";
table[111] = "102132096";
table[112] = "202132096";
table[113] = "102183229";
table[114] = "202183229";
table[115] = "102173220";
table[116] = "202173220";
table[117] = "1";
table[118] = "2";
name = "102174135";
n = (u_int16_t)strtol(name, &endptr, 10);
for (i = 0; i <= tablesize; i++) {
t = (u_int16_t)strtol(table[i], &endptr, 10);
if (n == t) {
printf("%s matches %s\n", name, table[i]);
}
}
}
saving this as test.c in sys/netgraph/, compiling and
running it on the machine that produced the data under test via the
following commands I get the following output.
sudo gcc test.c -o test
./test
102174135 matches 202182071
Based on this result, I am able to reproduce the problem on a test
system as follows:
sudo ngctl list
There are 3 total nodes:
Name: UnauthNat Type: nat ID: 00000004 Num hooks: 2
Name: ipfw Type: ipfw ID: 00000001 Num hooks: 2
Name: ngctl2605 Type: socket ID: 00000008 Num hooks: 0
sudo ngctl -d mkpeer ipfw: nat 202182071 out
sudo ngctl -d mkpeer ipfw: nat 102174135 out
ngctl: sendto(ipfw:): File exists
ngctl: send msg: File exists
sudo ngctl list
There are 4 total nodes:
Name: <unnamed> Type: nat ID: 0000000a Num hooks: 1
Name: UnauthNat Type: nat ID: 00000004 Num hooks: 2
Name: ipfw Type: ipfw ID: 00000001 Num hooks: 3
Name: ngctl2612 Type: socket ID: 0000000d Num hooks: 0
The use of a u_int16_t representation of the hook name is limited to
ng_ipfw_findhook1. ng_ipfw_findhook1 is called directly from
ng_ipfw_findhook and also ng_ipfw_input where it takes its u_int16_t
argument from the cookie field of the tag associated with the packet
(an ip_fw_args struct). This field, as defined in sys/netinet/ip_fw.h,
has type uint32_t. So this problem easily fixed by using a u_int32_t
instead of a u_int16_t. Here is a patch.
--- ng_ipfw.c.orig 2010-01-15 08:20:37.000000000 -0800
+++ ng_ipfw.c 2010-01-15 08:21:49.000000000 -0800
@@ -61,7 +61,7 @@
static ng_rcvdata_t ng_ipfw_rcvdata;
static ng_disconnect_t ng_ipfw_disconnect;
-static hook_p ng_ipfw_findhook1(node_p, u_int16_t );
+static hook_p ng_ipfw_findhook1(node_p, u_int32_t );
static int ng_ipfw_input(struct mbuf **, int, struct ip_fw_args *,
int);
@@ -87,7 +87,7 @@
/* Information we store for each hook */
struct ng_ipfw_hook_priv {
hook_p hook;
- u_int16_t rulenum;
+ u_int32_t rulenum;
};
typedef struct ng_ipfw_hook_priv *hpriv_p;
@@ -145,7 +145,7 @@
ng_ipfw_newhook(node_p node, hook_p hook, const char *name)
{
hpriv_p hpriv;
- u_int16_t rulenum;
+ u_int32_t rulenum;
const char *cp;
char *endptr;
@@ -159,7 +159,7 @@
return (EINVAL);
/* Convert it to integer */
- rulenum = (u_int16_t)strtol(name, &endptr, 10);
+ rulenum = (u_int32_t)strtol(name, &endptr, 10);
if (*endptr != '\0')
return (EINVAL);
@@ -191,10 +191,10 @@
hook_p
ng_ipfw_findhook(node_p node, const char *name)
{
- u_int16_t n; /* numeric representation of hook */
+ u_int32_t n; /* numeric representation of hook */
char *endptr;
- n = (u_int16_t)strtol(name, &endptr, 10);
+ n = (u_int32_t)strtol(name, &endptr, 10);
if (*endptr != '\0')
return NULL;
return ng_ipfw_findhook1(node, n);
@@ -202,7 +202,7 @@
/* Look up hook by rule number */
static hook_p
-ng_ipfw_findhook1(node_p node, u_int16_t rulenum)
+ng_ipfw_findhook1(node_p node, u_int32_t rulenum)
{
hook_p hook;
hpriv_p hpriv;
After applying this patch and rebooting with the new ng_ipfw(4) kernel
module, I am no longer able to reproduce the problem.
sudo ngctl list
There are 3 total nodes:
Name: UnauthNat Type: nat ID: 00000004 Num hooks: 2
Name: ipfw Type: ipfw ID: 00000001 Num hooks: 2
Name: ngctl2600 Type: socket ID: 00000008 Num hooks: 0
sudo ngctl -d mkpeer ipfw: nat 202182071 out
sudo ngctl -d mkpeer ipfw: nat 102174135 out
sudo ngctl list
There are 5 total nodes:
Name: <unnamed> Type: nat ID: 0000000c Num hooks: 1
Name: <unnamed> Type: nat ID: 0000000a Num hooks: 1
Name: UnauthNat Type: nat ID: 00000004 Num hooks: 2
Name: ipfw Type: ipfw ID: 00000001 Num hooks: 4
Name: ngctl2607 Type: socket ID: 0000000d Num hooks: 0
I will install the patched ng_ipfw(4) kernel module on the machine
where I first noticed these problems tomorrow to see if it works in
production.
Here is the failure I used as my test case. I took the hook name
102174135 from the error message and populated the table with the
values in the Local hook column from the output of ngctl show ipfw.
Jan 14 08:28:08 nac[70382]: /usr/sbin/ngctl -d mkpeer ipfw: nat 202174135 out
Jan 14 08:28:08 nac[70388]: /usr/sbin/ngctl -d name ipfw:202174135 WirelessNAT2174135
Jan 14 08:28:08 nac[70394]: /usr/sbin/ngctl -d connect ipfw: WirelessNAT2174135: 102174135 in
Jan 14 08:28:08 nac[70399]: ngctl: sendto(ipfw:): File exists
Jan 14 08:28:08 nac[70399]: ngctl: send msg: File exists
Thu Jan 14 08:29:01 PST 2010
/usr/sbin/ngctl show ipfw:
Name: ipfw Type: ipfw ID: 00000001 Num hooks: 119
Local hook Peer name Peer type Peer ID Peer hook
---------- --------- --------- ------- ---------
102175162 WirelessNAT2175162 nat 00000315 in
202175162 WirelessNAT2175162 nat 00000315 out
102182226 WirelessNAT2182226 nat 0000030f in
202182226 WirelessNAT2182226 nat 0000030f out
102182009 WirelessNAT2182009 nat 00000309 in
202182009 WirelessNAT2182009 nat 00000309 out
202174135 WirelessNAT2174135 nat 00000305 out
102173144 WirelessNAT2173144 nat 000002fd in
202173144 WirelessNAT2173144 nat 000002fd out
102183171 WirelessNAT2183171 nat 000002f7 in
202183171 WirelessNAT2183171 nat 000002f7 out
102172040 WirelessNAT2172040 nat 000002ef in
202172040 WirelessNAT2172040 nat 000002ef out
102173235 WirelessNAT2173235 nat 000002e9 in
202173235 WirelessNAT2173235 nat 000002e9 out
102174107 WirelessNAT2174107 nat 000002e3 in
202174107 WirelessNAT2174107 nat 000002e3 out
102173033 WirelessNAT2173033 nat 000002db in
202173033 WirelessNAT2173033 nat 000002db out
102183226 WirelessNAT2183226 nat 000002d5 in
202183226 WirelessNAT2183226 nat 000002d5 out
102172216 WirelessNAT2172216 nat 000002cf in
202172216 WirelessNAT2172216 nat 000002cf out
102182129 WirelessNAT2182129 nat 000002c8 in
202182129 WirelessNAT2182129 nat 000002c8 out
102173201 WirelessNAT2173201 nat 000002c0 in
202173201 WirelessNAT2173201 nat 000002c0 out
102132178 WirelessNAT2132178 nat 000002b8 in
202132178 WirelessNAT2132178 nat 000002b8 out
102183212 WirelessNAT2183212 nat 000002b0 in
202183212 WirelessNAT2183212 nat 000002b0 out
102173179 WirelessNAT2173179 nat 000002a8 in
202173179 WirelessNAT2173179 nat 000002a8 out
102172132 WirelessNAT2172132 nat 0000029f in
202172132 WirelessNAT2172132 nat 0000029f out
102175045 WirelessNAT2175045 nat 00000297 in
202175045 WirelessNAT2175045 nat 00000297 out
102175215 WirelessNAT2175215 nat 0000028f in
202175215 WirelessNAT2175215 nat 0000028f out
102183173 WirelessNAT2183173 nat 00000287 in
202183173 WirelessNAT2183173 nat 00000287 out
102173180 WirelessNAT2173180 nat 0000027f in
202173180 WirelessNAT2173180 nat 0000027f out
102173171 WirelessNAT2173171 nat 00000279 in
202173171 WirelessNAT2173171 nat 00000279 out
102173025 WirelessNAT2173025 nat 00000271 in
202173025 WirelessNAT2173025 nat 00000271 out
102175064 WirelessNAT2175064 nat 00000269 in
202175064 WirelessNAT2175064 nat 00000269 out
102172038 WirelessNAT2172038 nat 00000263 in
202172038 WirelessNAT2172038 nat 00000263 out
102175035 WirelessNAT2175035 nat 0000025b in
202175035 WirelessNAT2175035 nat 0000025b out
102182254 WirelessNAT2182254 nat 00000255 in
202182254 WirelessNAT2182254 nat 00000255 out
102183083 WirelessNAT2183083 nat 0000024f in
202183083 WirelessNAT2183083 nat 0000024f out
102132088 WirelessNAT2132088 nat 00000245 in
202132088 WirelessNAT2132088 nat 00000245 out
102183201 WirelessNAT2183201 nat 0000023f in
202183201 WirelessNAT2183201 nat 0000023f out
102182255 WirelessNAT2182255 nat 00000237 in
202182255 WirelessNAT2182255 nat 00000237 out
102172085 WirelessNAT2172085 nat 00000231 in
202172085 WirelessNAT2172085 nat 00000231 out
102183127 WirelessNAT2183127 nat 00000228 in
202183127 WirelessNAT2183127 nat 00000228 out
102173146 WirelessNAT2173146 nat 0000021c in
202173146 WirelessNAT2173146 nat 0000021c out
102182071 WirelessNAT2182071 nat 0000020e in
202182071 WirelessNAT2182071 nat 0000020e out
102172073 WirelessNAT2172073 nat 00000208 in
202172073 WirelessNAT2172073 nat 00000208 out
102173186 WirelessNAT2173186 nat 00000200 in
202173186 WirelessNAT2173186 nat 00000200 out
102175067 WirelessNAT2175067 nat 000001f8 in
202175067 WirelessNAT2175067 nat 000001f8 out
102173061 WirelessNAT2173061 nat 000001f2 in
202173061 WirelessNAT2173061 nat 000001f2 out
102183115 WirelessNAT2183115 nat 000001ec in
202183115 WirelessNAT2183115 nat 000001ec out
102132147 WirelessNAT2132147 nat 000001e6 in
202132147 WirelessNAT2132147 nat 000001e6 out
102182233 WirelessNAT2182233 nat 000001d8 in
202182233 WirelessNAT2182233 nat 000001d8 out
102183051 WirelessNAT2183051 nat 000001d0 in
202183051 WirelessNAT2183051 nat 000001d0 out
102183102 WirelessNAT2183102 nat 000001c6 in
202183102 WirelessNAT2183102 nat 000001c6 out
102172157 WirelessNAT2172157 nat 000001c0 in
202172157 WirelessNAT2172157 nat 000001c0 out
102174083 WirelessNAT2174083 nat 000001ba in
202174083 WirelessNAT2174083 nat 000001ba out
102132017 WirelessNAT2132017 nat 000001b2 in
202132017 WirelessNAT2132017 nat 000001b2 out
102172065 WirelessNAT2172065 nat 000001a8 in
202172065 WirelessNAT2172065 nat 000001a8 out
102132142 WirelessNAT2132142 nat 0000019e in
202132142 WirelessNAT2132142 nat 0000019e out
102183163 WirelessNAT2183163 nat 00000198 in
202183163 WirelessNAT2183163 nat 00000198 out
102173094 WirelessNAT2173094 nat 00000190 in
202173094 WirelessNAT2173094 nat 00000190 out
102172147 WirelessNAT2172147 nat 00000188 in
202172147 WirelessNAT2172147 nat 00000188 out
102173066 WirelessNAT2173066 nat 00000174 in
202173066 WirelessNAT2173066 nat 00000174 out
102132098 WirelessNAT2132098 nat 0000016c in
202132098 WirelessNAT2132098 nat 0000016c out
102173166 WirelessNAT2173166 nat 00000154 in
202173166 WirelessNAT2173166 nat 00000154 out
102132096 WirelessNAT2132096 nat 00000134 in
202132096 WirelessNAT2132096 nat 00000134 out
102183229 WirelessNAT2183229 nat 00000126 in
202183229 WirelessNAT2183229 nat 00000126 out
102173220 WirelessNAT2173220 nat 00000010 in
202173220 WirelessNAT2173220 nat 00000010 out
1 UnauthNat nat 00000004 in
2 UnauthNat nat 00000004 out
Erik
More information about the freebsd-net
mailing list