Ошибка "mlibnetlink: RTNETLINK answers: File exists"

Questions related to general functionality
Post Reply
eklmno
Posts: 10
Joined: 05 Dec 2020, 16:56

Ошибка "mlibnetlink: RTNETLINK answers: File exists"

Post by eklmno » 18 Aug 2021, 14:11

Доброго дня.
Есть связка ACCEL+LanBilling, при которой dhcp discovery от клиентов, летят через NAS на lanbiiling (dhcp server)уже как unicast +авторизация через radius.

Все работает, но с некоторыми клиентами возникают вопросы.
Обычно проходит по схеме:
1. от клиента должен приходить бродкаст Discover
2. Этот Discover релеется юникастом NASом на dhcp сервер на биллинге
3. DHCP сервер отправляет offer, который летит на NAS
4. NAS, в свою очередь, пересылает offer клиенту
5. клиент отправляет Request на NAS на получение IP адреса
6. NAS пересылает request на сервер dhcp
7. NAS получает от dhcp сервера ACK
8. NAS пересылает ACK клиенту
9. на NAS активируется IP сессия (в логах сообщение activate session)
10. NAS отправляет Radius авторизацию на биллинг
11. биллинг принимает решение о включении сессии и отправляет ответ Accept или Reject.

Но в некоторых случаях возникает такая ситуация :
1. на NAS прилетает discover от клиента
2. NAS отправляет радиус авторизацию
3. NAS получает radius-accept и успешно авторизует сессию (но у этой сессии еще нет IP адреса!!!)
4. Этот Discover релеется юникастом NASом на dhcp сервер на биллинге
5. DHCP сервер отправляет offer, который летит на NAS
6. NAS, в свою очередь, пересылает offer клиенту
7. клиент отправляет Request на NAS на получение IP адреса
8. NAS пересылает request на сервер dhcp
9. NAS получает от dhcp сервера ACK
10. NAS пересылает ACK клиенту
11. на NAS активируется IP сессия (в логах сообщение activate session)
Лог:
Спойлер
^[[1;32m[2021-08-18 11:14:13]: info: enp4s0f0.1102: ^[[0;39mrecv [DHCPv4 Discover xid=5991171 chaddr=d8:47:32:0f:ea:73 <Message-Type Discover> <Max-Message-Size 1024> <Client-ID 01d847320fea73> <Host-Name Archer_C5> <Vendor-Class 54502d4c696e6b> <Request-List Subnet,Router,DNS,
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39mcreate interface ipoe164 parent enp4s0f0.1102
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39msend [RADIUS(1) Access-Request id=1 <User-Name "d8:47:32:0f:ea:73"> <NAS-Identifier "accel-ppp-bras"> <NAS-IP-Address 109.95.80.19> <NAS-Port 817405> <NAS-Port-Id "ipoe164"> <NAS-Port-Type Ethernet> <Calling-Station-Id "d8:4
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39mrecv [RADIUS(1) Access-Accept id=1 <Class 0x3c313632393237343435332c203331372c20446e35457835384c314c4e3e> <Service-Type Framed-User> <Acct-Interim-Interval 300> <Filter-Id "307200/307200"> <Message-Authenticator 0x0f7d5485b0
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39md8:47:32:0f:ea:73: authentication succeeded
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39msend [DHCPv4 relay Discover xid=5991171 giaddr=10.48.0.1 chaddr=d8:47:32:0f:ea:73 <Message-Type Discover> <Max-Message-Size 1024> <Client-ID 01d847320fea73> <Host-Name Archer_C5> <Vendor-Class 54502d4c696e6b> <Request-List S
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39mrecv [DHCPv4 relay Offer xid=5991171 yiaddr=10.50.7.234 giaddr=10.48.0.1 chaddr=d8:47:32:0f:ea:73 <Subnet 255.255.252.0> <Router 10.50.4.1> <DNS 8.8.8.8> <Domain-Name company.ru> <Lease-Time 600> <Message-Type Offer> <Server
^[[1;32m[2021-08-18 11:14:13]: info: ipoe164: ^[[0;39msend [DHCPv4 Offer xid=5991171 yiaddr=10.50.7.234 chaddr=d8:47:32:0f:ea:73 <Message-Type Offer> <Server-ID 10.50.4.1> <Lease-Time 600> <T1 100> <T2 175> <Router 10.50.4.1> <Subnet 255.255.252.0> <DNS 8.8.8.8> <Domain-Name co
^[[1;32m[2021-08-18 11:14:14]: info: ipoe164: ^[[0;39mrecv [DHCPv4 Request xid=5991171 chaddr=d8:47:32:0f:ea:73 <Message-Type Request> <Max-Message-Size 1024> <Client-ID 01d847320fea73> <Host-Name Archer_C5> <Vendor-Class 54502d4c696e6b> <Request-IP 10.50.7.234> <Server-ID 10.5
^[[1;32m[2021-08-18 11:14:14]: info: ipoe164: ^[[0;39msend [DHCPv4 relay Request xid=5991171 giaddr=10.48.0.1 chaddr=d8:47:32:0f:ea:73 <Message-Type Request> <Max-Message-Size 1024> <Client-ID 01d847320fea73> <Host-Name Archer_C5> <Vendor-Class 54502d4c696e6b> <Request-IP 10.50
^[[1;32m[2021-08-18 11:14:14]: info: ipoe164: ^[[0;39mrecv [DHCPv4 relay Ack xid=5991171 yiaddr=10.50.7.234 giaddr=10.48.0.1 chaddr=d8:47:32:0f:ea:73 <Subnet 255.255.252.0> <Router 10.50.4.1> <DNS 8.8.8.8> <Domain-Name company.ru> <Lease-Time 600> <Message-Type Ack> <Server-ID
^[[1;34m[2021-08-18 11:14:14]: debug: ipoe164: ^[[0;39mipoe: activate session
^[[1;34m[2021-08-18 11:14:14]: debug: ^[[0;39mlibnetlink: RTNETLINK answers: File exists
^[[1;31m[2021-08-18 11:14:14]: error: ipoe164: ^[[0;39mipoe: nl_modify: File exists
^[[1;34m[2021-08-18 11:14:14]: debug: ipoe164: ^[[0;39mterminate
^[[1;32m[2021-08-18 11:14:14]: info: ipoe164: ^[[0;39mipoe: session finished

При закрытии сессии NAS формирует DHCP release:
^[[1;32m[2021-08-18 11:14:33]: info: ipoe164: ^[[0;39msend [DHCPv4 relay Release xid=1c1b07be ciaddr=10.50.7.234 giaddr=10.48.0.1 chaddr=d8:47:32:0f:ea:73 <Message-Type Release> <Relay-Agent {Agent-Circuit-ID _044e001301090a} {Agent-Remote-ID _984562300dc8} {Option-9 _00000cf81

и так по кругу.
Надо понимание по ошибке и как устранить данную ситуацию.

dimka88
Posts: 784
Joined: 13 Oct 2014, 05:51
Contact:

Re: Ошибка "mlibnetlink: RTNETLINK answers: File exists"

Post by dimka88 » 03 Sep 2021, 23:25

Доброго времени суток, действительно очень интересная ситуация получается.
Т.е. необходимо как то релеить Discover перед авторизацией. Есть у вас возможность опубликовать accel-ppp.conf (замаскировав частную информацию)

eklmno
Posts: 10
Joined: 05 Dec 2020, 16:56

Re: Ошибка "mlibnetlink: RTNETLINK answers: File exists"

Post by eklmno » 25 Sep 2021, 08:11

День добрый,
Вначале полагали, что именно такой сценарий оптимальный, Discover, Offer, Request, Ack и тд и после этого авторизация.
Позже пришли к тому, что может быть и так как работает по умолчанию - Discover , Авторизация, релей и всё остальное, однако Release летит именно от NASa. Этот Release формируется после неудачной попытки активации сессии
^[[1;34m[2021-08-18 11:14:14]: debug: ipoe164: ^[[0;39mipoe: activate session
^[[1;34m[2021-08-18 11:14:14]: debug: ^[[0;39mlibnetlink: RTNETLINK answers: File exists
^[[1;31m[2021-08-18 11:14:14]: error: ipoe164: ^[[0;39mipoe: nl_modify: File exists
и как следствие, последующей терминации ipoe сессии
^[[1;34m[2021-08-18 11:14:14]: debug: ipoe164: ^[[0;39mterminate
^[[1;32m[2021-08-18 11:14:14]: info: ipoe164: ^[[0;39mipoe: session finished

Предверием такого поведения была достаточно долгая потеря связанности между биллингом, где расположен DHCP сервер и NASом. Проводились технические работы на ланбиллинге и процедура затянулась минут на 30-40. Время обновления DHCP аренды у клиентов стоит 10 минут и получалось так, что сессии на NASе рвались по таймауту. После поднятия DHCP многие клиенты не могли получить адреса и в логах появлялись ошибки, которые привел выше.


Похоже отсутствует обработка ошибки в файле accel-ppp-code/drivers/ipoe/ipoe.c :

1) При создании интерфейса
static int ipoe_nl_cmd_create(struct sk_buff *skb, struct genl_info *info)
{
struct sk_buff *msg;
void *hdr;
__be32 peer_addr = 0, addr = 0, gw = 0;
int ifindex = 0;
int ret = 0;
__u8 hwaddr[ETH_ALEN];
struct ipoe_session *ses;
//struct net *net = genl_info_net(info);

if (info->attrs[IPOE_ATTR_PEER_ADDR]) {
peer_addr = nla_get_be32(info->attrs[IPOE_ATTR_PEER_ADDR]);
if (peer_addr) {
ses = ipoe_lookup(peer_addr);
if (ses) {
atomic_dec(&ses->refs);
------------->>> return -EEXIST;
}
}
}


или 2) при изменении интерфейса:

static int ipoe_nl_cmd_modify(struct sk_buff *skb, struct genl_info *info)
{
int ret = -EINVAL, r = 0;
struct net_device *dev, *link_dev, *old_dev;
struct in_device *in_dev;
struct ipoe_session *ses, *ses1;
int ifindex;
__be32 peer_addr;

if (!info->attrs[IPOE_ATTR_IFINDEX])
return -EINVAL;

down(&ipoe_wlock);

ifindex = nla_get_u32(info->attrs[IPOE_ATTR_IFINDEX]);

rcu_read_lock();
dev = dev_get_by_index_rcu(&init_net, ifindex);
if (!dev || dev->header_ops != &ipoe_hard_header_ops)
r = 1;
rcu_read_unlock();

if (r)
goto out_unlock;

ses = netdev_priv(dev);

if (info->attrs[IPOE_ATTR_PEER_ADDR]) {
peer_addr = nla_get_be32(info->attrs[IPOE_ATTR_PEER_ADDR]);
if (peer_addr) {
ses1 = ipoe_lookup(peer_addr);
if (ses1) {
atomic_dec(&ses1->refs);
if (ses1 != ses) {
--------------------->>> ret = -EEXIST;
// if (ses==NULL) ret= -EINVAL ; //
goto out_unlock;
}

во втором случае сравниваются структуры, ссылающиеся на области памяти старой и новой сессии.
Менять что либо не стали, поскольку много зависимостей и нужно было понимать всю логику целиком.

т.е. вопрос оказался скорее не по релизу от наса, а по проверке актуальности ipoe сессии и дальнейшим принятием решения АкселемЪ.
Стоит упомянуть, что эту проблему обошли жесткой привязкой IP адреса клиенту со стороны биллинга (DHCP сервера). Т.е. при условии, когда клиенту назначен статический IP адрес, сессия на NASe не терминируется, поднимается корректно и работает.

Post Reply

Who is online

Users browsing this forum: No registered users and 1 guest