Аномальные обрывы сессий

Установка, настройка, поддержка
Ответить
worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Аномальные обрывы сессий

Сообщение worky » Вт июн 04, 2013 1:20 pm

День добрый!
Использую 0.55b/20121019, PPPoE and Linux NAS. И вот что вижу на НАСе в логах:

Код: Выделить всё

Jun  3 19:50:58 nas05 pppd[19685]: Plugin /etc/ppp/plugins/rp-pppoe.so loaded.
Jun  3 19:50:58 nas05 pppd[19685]: RP-PPPoE plugin version 3.10 compiled against pppd 2.4.5
Jun  3 19:50:58 nas05 pppd[19685]: Plugin /etc/ppp/plugins/rp-pppoe.so loaded.
Jun  3 19:50:58 nas05 pppd[19685]: RP-PPPoE plugin version 3.10 compiled against pppd 2.4.5
Jun  3 19:50:58 nas05 pppd[19685]: Plugin /usr/lib/pppd/2.4.5/radius.so loaded.
Jun  3 19:50:58 nas05 pppd[19685]: RADIUS plugin initialized.
Jun  3 19:50:58 nas05 pppd[19685]: Plugin /usr/lib/pppd/2.4.5/radattr.so loaded.
Jun  3 19:50:58 nas05 pppd[19685]: RADATTR plugin initialized.
Jun  3 19:50:58 nas05 pppd[19685]: pppd 2.4.5 started by root, uid 0
Jun  3 19:50:58 nas05 pppd[19685]: Connected to 50:e5:49:51:b8:10 via interface vlan42
Jun  3 19:50:58 nas05 pppd[19685]: Using interface ppp1885
Jun  3 19:50:58 nas05 pppd[19685]: Connect: ppp1885 <--> vlan42
Jun  3 19:50:58 nas05 pppd[19685]: Couldn't increase MTU to 1500
Jun  3 19:50:58 nas05 pppd[19685]: Couldn't increase MRU to 1500
Jun  3 19:50:59 nas05 pppd[19685]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:50:59 nas05 pppd[19685]: local  IP address 10.200.46.1
Jun  3 19:50:59 nas05 pppd[19685]: remote IP address 213.х.х.х
Jun  3 19:51:36 nas05 pppd[19685]: Unsupported protocol 0xd900 received
Jun  3 20:22:08 nas05 pppd[19685]: Terminating on signal 15
Jun  3 20:22:08 nas05 pppd[19685]: Connect time 31.2 minutes.
Jun  3 20:22:08 nas05 pppd[19685]: Sent 3195324 bytes, received 15429696 bytes.
Jun  3 20:22:08 nas05 pppd[19685]: Couldn't increase MTU to 1500
Jun  3 20:22:08 nas05 pppd[19685]: Couldn't increase MRU to 1500
Jun  3 20:22:14 nas05 pppd[19685]: Connection terminated.
Jun  3 20:22:14 nas05 pppd[19685]: Modem hangup
Jun  3 20:22:14 nas05 pppd[19685]: Exit.
все гут. но вот начали появляться у некоторых юзеров (никакой зависимости не установлено) множественные сессии:

Код: Выделить всё

Jun  3 19:27:14 nas05 pppd[2810]: Plugin /etc/ppp/plugins/rp-pppoe.so loaded.
Jun  3 19:27:14 nas05 pppd[2810]: RP-PPPoE plugin version 3.10 compiled against pppd 2.4.5
Jun  3 19:27:14 nas05 pppd[2810]: Plugin /etc/ppp/plugins/rp-pppoe.so loaded.
Jun  3 19:27:14 nas05 pppd[2810]: RP-PPPoE plugin version 3.10 compiled against pppd 2.4.5
Jun  3 19:27:14 nas05 pppd[2810]: Plugin /usr/lib/pppd/2.4.5/radius.so loaded.
Jun  3 19:27:14 nas05 pppd[2810]: RADIUS plugin initialized.
Jun  3 19:27:14 nas05 pppd[2810]: Plugin /usr/lib/pppd/2.4.5/radattr.so loaded.
Jun  3 19:27:14 nas05 pppd[2810]: RADATTR plugin initialized.
Jun  3 19:27:14 nas05 pppd[2810]: pppd 2.4.5 started by root, uid 0
Jun  3 19:27:14 nas05 pppd[2810]: Connected to 50:e5:49:51:b8:10 via interface vlan42
Jun  3 19:27:14 nas05 pppd[2810]: Using interface ppp1115
Jun  3 19:27:14 nas05 pppd[2810]: Connect: ppp1115 <--> vlan42
Jun  3 19:27:14 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:27:14 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:27:14 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:27:14 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:27:14 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:34:41 nas05 pppd[2810]: Unsupported protocol 0xc336 received
Jun  3 19:34:58 nas05 pppd[2810]: Unsupported protocol 0xe5c8 received
Jun  3 19:35:00 nas05 pppd[2810]: Connect time 7.8 minutes.
Jun  3 19:35:00 nas05 pppd[2810]: Sent 3294016 bytes, received 44283959 bytes.
Jun  3 19:35:00 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:35:00 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:35:00 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:35:00 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:35:00 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:35:06 nas05 pppd[2810]: Unsupported protocol 0xe574 received
Jun  3 19:35:45 nas05 pppd[2810]: Unsupported protocol 0xf811 received
Jun  3 19:36:00 nas05 pppd[2810]: Unsupported protocol 0xf211 received
Jun  3 19:36:04 nas05 pppd[2810]: Unsupported protocol 0xd96d received
Jun  3 19:36:49 nas05 pppd[2810]: Connect time 1.9 minutes.
Jun  3 19:36:49 nas05 pppd[2810]: Sent 1399292 bytes, received 67848078 bytes.
Jun  3 19:36:49 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:36:49 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:36:49 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:36:49 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:36:49 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:36:53 nas05 pppd[2810]: Unsupported protocol 0xdc9c received
Jun  3 19:38:37 nas05 pppd[2810]: Unsupported protocol 0xf930 received
Jun  3 19:38:57 nas05 pppd[2810]: Unsupported protocol 0xd00f received
Jun  3 19:39:33 nas05 pppd[2810]: Unsupported protocol 0xf811 received
Jun  3 19:40:20 nas05 pppd[2810]: Unsupported protocol 0xf211 received
Jun  3 19:40:41 nas05 pppd[2810]: Unsupported protocol 0xf811 received
Jun  3 19:41:23 nas05 pppd[2810]: Connect time 4.6 minutes.
Jun  3 19:41:23 nas05 pppd[2810]: Sent 2215981 bytes, received 74773959 bytes.
Jun  3 19:41:23 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:41:23 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:41:23 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:41:23 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:41:23 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:44:07 nas05 pppd[2810]: Unsupported protocol 0xf211 received
Jun  3 19:46:20 nas05 pppd[2810]: Connect time 5.0 minutes.
Jun  3 19:46:20 nas05 pppd[2810]: Sent 1837083 bytes, received 48523760 bytes.
Jun  3 19:46:20 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:46:20 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:46:20 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:46:20 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:46:20 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:46:25 nas05 pppd[2810]: Unsupported protocol 0xfdf5 received
Jun  3 19:46:39 nas05 pppd[2810]: Connect time 0.4 minutes.
Jun  3 19:46:39 nas05 pppd[2810]: Sent 208872 bytes, received 9937371 bytes.
Jun  3 19:46:39 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:46:39 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:46:39 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:46:39 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:46:39 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:46:45 nas05 pppd[2810]: Unsupported protocol 0xf575 received
Jun  3 19:46:47 nas05 pppd[2810]: Connect time 0.2 minutes.
Jun  3 19:46:47 nas05 pppd[2810]: Sent 107083 bytes, received 5138555 bytes.
Jun  3 19:46:47 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:46:47 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:46:47 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:46:47 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:46:47 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:47:10 nas05 pppd[2810]: Unsupported protocol 0xc600 received
Jun  3 19:50:15 nas05 pppd[2810]: Connect time 3.5 minutes.
Jun  3 19:50:15 nas05 pppd[2810]: Sent 1171890 bytes, received 19408865 bytes.
Jun  3 19:50:15 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:50:15 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:50:15 nas05 pppd[2810]: peer from calling number 50:E5:49:51:B8:10 authorized
Jun  3 19:50:15 nas05 pppd[2810]: local  IP address 10.200.46.1
Jun  3 19:50:15 nas05 pppd[2810]: remote IP address 213.х.х.х
Jun  3 19:50:23 nas05 pppd[2810]: LCP terminated by peer (Failed to authenticate ourselves to peer)
Jun  3 19:50:23 nas05 pppd[2810]: Connect time 0.2 minutes.
Jun  3 19:50:23 nas05 pppd[2810]: Sent 37932 bytes, received 249845 bytes.
Jun  3 19:50:23 nas05 pppd[2810]: Couldn't increase MTU to 1500
Jun  3 19:50:23 nas05 pppd[2810]: Couldn't increase MRU to 1500
Jun  3 19:50:26 nas05 pppd[2810]: Connection terminated.
Jun  3 19:50:26 nas05 pppd[2810]: Modem hangup
Jun  3 19:50:26 nas05 pppd[2810]: Exit.
со стороны биллинга в статистике видно 4 сессии с User-Request,а у юзера разрыв один.
Причем эти обрывы бывают как у юзеров с роутерами, так и с компами. Причем это проявляется не постоянно, а то есть разрывы, то нет. И только на одном НАСе.

ПРобовал делать дампы - и вот неполный дамп с фреймами от юзера:

Код: Выделить всё

11:39:56.031182 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 55, length 10
11:40:01.035591 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 56, length 10
11:40:06.040583 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 57, length 10
11:40:11.043534 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 58, length 10
11:40:16.047154 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 59, length 10
11:40:21.051194 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 60, length 10
11:40:26.055768 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 61, length 10
11:40:31.059592 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 62, length 10
11:40:36.062122 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 63, length 10
11:40:41.063483 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 64, length 10
11:40:46.067406 PPPoE  [ses 0xd2d] LCP, Echo-Reply (0x0a), id 65, length 10
11:40:51.931777 PPPoE  [ses 0xd2d] LCP, Term-Request (0x05), id 100, length 12
11:40:59.733845 PPPoE  [ses 0xc93] LCP, Conf-Request (0x01), id 101, length 16
11:41:00.369649 PPPoE  [ses 0xc93] LCP, Conf-Ack (0x02), id 1, length 21
11:41:00.369968 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 0, length 10
11:41:05.371997 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 1, length 10
11:41:10.376021 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 2, length 10
11:41:15.376936 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 3, length 10
11:41:20.379936 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 4, length 10
11:41:25.382826 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 5, length 10
11:41:30.383841 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 6, length 10
11:41:35.388866 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 7, length 10
11:41:40.393489 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 8, length 10
11:41:45.395838 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 9, length 10
11:41:50.396270 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 10, length 10
11:41:55.399847 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 11, length 10
11:42:00.403834 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 12, length 10
11:42:05.407848 PPPoE  [ses 0xc93] LCP, Echo-Reply (0x0a), id 13, length 10
В какой стороне искать - со стороны биллинга или НАСа?

зы скоро получу полный дамп от юзера - будет больше пищи для размышления

~AsmodeuS~
Site Admin
Сообщения: 5707
Зарегистрирован: Пт янв 28, 2005 3:11 pm
Контактная информация:

Re: Аномальные обрывы сессий

Сообщение ~AsmodeuS~ » Вт июн 04, 2013 2:07 pm

думаю рвёт это

Jun 3 19:50:23 nas05 pppd[2810]: LCP terminated by peer (Failed to authenticate ourselves to peer)

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Вт июн 04, 2013 2:13 pm

А что это значит?
В инете смотрел - типа неправильно введено логин\пароль. Но ведь ничего не меняется!!
Со стороны юзера это выглядит просто внезапным разрывом и пересоединением, юзер даже ничего не вводит руками - все на автомате.

И опять же - это в конце было сессии и это вызвало разрыв у юзера, но ведь в логе видно несколько повторов одних и тех же строк (которых нет в нормальном первом логе), а в биллинге - несколько сессий за это время - время одной сессии. Как это понять?

Код: Выделить всё

Пользователь Sort 	Начало Sort 	Длительность Sort 	Тарифный план Sort 	Отправлено Sort 	Получено Sort 	CID Sort 	NAS Sort 	IP Sort 	Сумма Sort 	- 	-
vpn*	2013-06-03 19:46:47	00:03:28	41	18.51 MB	1.12 MB	50:E5:49:51:B8:10	10	213.x	0.000000	D	Удалить
vpn*	2013-06-03 19:46:20	00:00:19	41	9.48 MB	203.98 Kb	50:E5:49:51:B8:10	10	213.x	0.000000	D	Удалить
vpn*	2013-06-03 19:41:23	00:04:57	41	46.28 MB	1.75 MB	50:E5:49:51:B8:10	10	213.x	0.000000	D	Удалить
vpn*	2013-06-03 19:36:49	00:04:34	41	71.31 MB	2.11 MB	50:E5:49:51:B8:10	10	213.x	0.000000	D	Удалить
vpn*	2013-06-03 19:35:00	00:01:49	41	64.70 MB	1.33 MB	50:E5:49:51:B8:10	10	213.x	0.000000	D	Удалить
vpn*	2013-06-03 19:27:14	00:07:46	41	42.23 MB	3.14 MB	50:E5:49:51:B8:10	10	213.x	0.000000	D	Удалить

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Ср июн 05, 2013 7:22 am

вот что видно от юзера, когда по биллингу разрыв сессии.
Видно, что НАС запрашивает переконфигурацию соединения и происходит заново авторизация пользователя.
Почему это происходит?
Вложения
pppoed_session.png
pppoed_session.png (190.58 КБ) 7257 просмотров

~AsmodeuS~
Site Admin
Сообщения: 5707
Зарегистрирован: Пт янв 28, 2005 3:11 pm
Контактная информация:

Re: Аномальные обрывы сессий

Сообщение ~AsmodeuS~ » Ср июн 05, 2013 8:26 am

покажите радиус пары авторизации

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Ср июн 05, 2013 8:37 am

~AsmodeuS~ писал(а):покажите радиус пары авторизации
а где глянуть их?

~AsmodeuS~
Site Admin
Сообщения: 5707
Зарегистрирован: Пт янв 28, 2005 3:11 pm
Контактная информация:

Re: Аномальные обрывы сессий

Сообщение ~AsmodeuS~ » Ср июн 05, 2013 8:53 am

radiusd -X

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Ср июн 05, 2013 9:01 am

Код: Выделить всё

Sending Accounting-Response of id 243 to х.х.х.17 port 58492
Finished request 1.
Cleaning up request 1 ID 243 with timestamp +0
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host х.х.х.16 port 38784, id=244, length=163
        Acct-Session-Id = "51ACCCD27CE200"
        User-Name = "vpnvikalex"
        Acct-Status-Type = Interim-Update
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Acct-Authentic = RADIUS
        Acct-Session-Time = 143492
        Acct-Output-Octets = 2978911860
        Acct-Input-Octets = 122788405
        Acct-Output-Gigawords = 1
        Acct-Input-Gigawords = 0
        Acct-Output-Packets = 5036583
        Acct-Input-Packets = 2633878
        Calling-Station-Id = "90:F6:52:77:38:0F"
        NAS-Port-Type = Async
        Framed-IP-Address = 10.200.29.45
        NAS-IP-Address = х.х.х.16
        NAS-Port = 312
        Acct-Delay-Time = 0
# Executing section preacct from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group preacct {...}
++[preprocess] returns ok
# Executing section accounting from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group accounting {...}
rlm_perl: Added pair NAS-Port-Type = Async
rlm_perl: Added pair Acct-Input-Octets = 122788405
rlm_perl: Added pair Acct-Session-Id = 51ACCCD27CE200
rlm_perl: Added pair Acct-Output-Gigawords = 1
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Acct-Authentic = RADIUS
rlm_perl: Added pair Acct-Status-Type = Interim-Update
rlm_perl: Added pair Acct-Output-Packets = 5036583
rlm_perl: Added pair NAS-IP-Address = х.х.х.16
rlm_perl: Added pair Acct-Output-Octets = 2978911860
rlm_perl: Added pair Acct-Session-Time = 143492
rlm_perl: Added pair Calling-Station-Id = 90:F6:52:77:38:0F
rlm_perl: Added pair Framed-Protocol = PPP
rlm_perl: Added pair User-Name = vpnvikalex
rlm_perl: Added pair Acct-Input-Gigawords = 0
rlm_perl: Added pair Acct-Input-Packets = 2633878
rlm_perl: Added pair Framed-IP-Address = 10.200.29.45
rlm_perl: Added pair NAS-Port = 312
rlm_perl: Added pair Acct-Delay-Time = 0
++[perl] returns ok
Sending Accounting-Response of id 244 to х.х.х.16 port 38784
Finished request 2.
Cleaning up request 2 ID 244 with timestamp +0
Going to the next request

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Ср июн 05, 2013 9:09 am

Код: Выделить всё

rad_recv: Accounting-Request packet from host х.х.х.17 port 36200, id=79, length=119
        Acct-Session-Id = "51AEFD616FB100"
        User-Name = "vpnFedan"
        Acct-Status-Type = Start
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Calling-Station-Id = "00:E0:4D:52:B2:E5"
        Acct-Authentic = RADIUS
        NAS-Port-Type = Async
        Framed-IP-Address = 10.200.238.4
        NAS-IP-Address = х.х.х.17
        NAS-Port = 1579
        Acct-Delay-Time = 0
# Executing section preacct from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group preacct {...}
++[preprocess] returns ok
# Executing section accounting from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group accounting {...}
rlm_perl: Added pair NAS-Port-Type = Async
rlm_perl: Added pair Acct-Session-Id = 51AEFD616FB100
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Calling-Station-Id = 00:E0:4D:52:B2:E5
rlm_perl: Added pair Framed-Protocol = PPP
rlm_perl: Added pair User-Name = vpnFedan
rlm_perl: Added pair Acct-Authentic = RADIUS
rlm_perl: Added pair Acct-Status-Type = Start
rlm_perl: Added pair Framed-IP-Address = 10.200.238.4
rlm_perl: Added pair NAS-Port = 1579
rlm_perl: Added pair NAS-IP-Address = х.х.х.17
rlm_perl: Added pair Acct-Delay-Time = 0
++[perl] returns ok
Sending Accounting-Response of id 79 to х.х.х.17 port 36200
Finished request 26.
Cleaning up request 26 ID 79 with timestamp +1
Going to the next request


worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Ср июн 05, 2013 9:42 am

А вот конец сессии, из за которой и началась эта тема. При этом фактического разрыва сессии у юзера и не было:

Код: Выделить всё

rad_recv: Accounting-Request packet from host х.х.х.16 port 58952, id=229, length=167
        Acct-Session-Id = "51AEEA3D50DA06"
        User-Name = "vpnwakil"
        Acct-Status-Type = Stop
        Service-Type = Framed-User
        Framed-Protocol = PPP
        Acct-Authentic = RADIUS
        Acct-Session-Time = 4888
        Acct-Output-Octets = 21703015
        Acct-Input-Octets = 29622335
        Acct-Output-Gigawords = 0
        Acct-Input-Gigawords = 0
        Acct-Output-Packets = 139236
        Acct-Input-Packets = 215592
        Calling-Station-Id = "44:87:FC:56:D4:C2"
        NAS-Port-Type = Async
        Acct-Terminate-Cause = User-Request
        Framed-IP-Address = 10.200.181.98
        NAS-IP-Address = х.х.х.16
        NAS-Port = 119
        Acct-Delay-Time = 0
# Executing section preacct from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group preacct {...}
++[preprocess] returns ok
# Executing section accounting from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group accounting {...}
rlm_perl: Added pair NAS-Port-Type = Async
rlm_perl: Added pair Acct-Input-Octets = 29622335
rlm_perl: Added pair Acct-Session-Id = 51AEEA3D50DA06
rlm_perl: Added pair Acct-Output-Gigawords = 0
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Acct-Authentic = RADIUS
rlm_perl: Added pair Acct-Status-Type = Stop
rlm_perl: Added pair Acct-Output-Packets = 139236
rlm_perl: Added pair NAS-IP-Address = х.х.х.16
rlm_perl: Added pair Acct-Output-Octets = 21703015
rlm_perl: Added pair Acct-Terminate-Cause = User-Request
rlm_perl: Added pair Acct-Session-Time = 4888
rlm_perl: Added pair Calling-Station-Id = 44:87:FC:56:D4:C2
rlm_perl: Added pair Framed-Protocol = PPP
rlm_perl: Added pair User-Name = vpnwakil
rlm_perl: Added pair Acct-Input-Gigawords = 0
rlm_perl: Added pair Framed-IP-Address = 10.200.181.98
rlm_perl: Added pair Acct-Input-Packets = 215592
rlm_perl: Added pair NAS-Port = 119
rlm_perl: Added pair Acct-Delay-Time = 0
++[perl] returns ok
Sending Accounting-Response of id 229 to х.х.х.16 port 58952
Finished request 440.
Cleaning up request 440 ID 229 with timestamp +9
Going to the next request
***************************************************************
rad_recv: Access-Request packet from host 195.225.145.16 port 41528, id=111, length=113
        Service-Type = Framed-User
        Framed-Protocol = PPP
        User-Name = "vpnwakil"
        CHAP-Challenge = 0xfcd4fd3ca03cd6d141c1410242b744cf3853c0
        CHAP-Password = 0x4c643aaf01597a734af12696889eb09122
        Calling-Station-Id = "44:87:FC:56:D4:C2"
        NAS-IP-Address = 195.225.145.16
        NAS-Port = 119
# Executing section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
+- entering group authorize {...}
++[preprocess] returns ok
++[mschap] returns noop
[files] users: Matched entry DEFAULT at line 38
++[files] returns ok
rlm_perl: Added pair CHAP-Password = 0x4c643aaf01597a734af12696889eb09122
rlm_perl: Added pair Service-Type = Framed-User
rlm_perl: Added pair Calling-Station-Id = 44:87:FC:56:D4:C2
rlm_perl: Added pair Framed-Protocol = PPP
rlm_perl: Added pair User-Name = vpnwakil
rlm_perl: Added pair CHAP-Challenge = 0xfcd4fd3ca03cd6d141c1410242b744cf3853c0
rlm_perl: Added pair NAS-IP-Address = 195.225.145.16
rlm_perl: Added pair NAS-Port = 119
rlm_perl: Added pair Acct-Interim-Interval = 300
rlm_perl: Added pair User-Name = vpnwakil
rlm_perl: Added pair PPPD-Upstream-Speed-Limit = 102400
rlm_perl: Added pair Framed-IP-Address = 10.200.181.98
rlm_perl: Added pair Session-Octets-Limit = 0
rlm_perl: Added pair Framed-IP-Netmask = 255.255.255.255
rlm_perl: Added pair PPPD-Downstream-Speed-Limit = 102400
rlm_perl: Added pair Auth-Type = Accept
++[perl] returns ok
Found Auth-Type = Accept
Auth-Type = Accept, accepting the user
Login OK: [vpnwakil/<CHAP-Password>] (from client nas05 port 119 cli 44:87:FC:56:D4:C2)
  WARNING: Empty post-auth section.  Using default return values.
# Executing section post-auth from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
Sending Access-Accept of id 111 to 195.225.145.16 port 41528
        Acct-Interim-Interval = 300
        User-Name = "vpnwakil"
        PPPD-Upstream-Speed-Limit = 102400
        Framed-IP-Address = 10.200.181.98
        Session-Octets-Limit = 0
        Framed-IP-Netmask = 255.255.255.255
        PPPD-Downstream-Speed-Limit = 102400
Finished request 442.

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Ср июн 05, 2013 12:45 pm

Login OK: [vpnwakil/<CHAP-Password>] (from client nas05 port 119 cli 44:87:FC:56:D4:C2)
WARNING: Empty post-auth section. Using default return values.
# Executing section post-auth from file /usr/local/freeradius/etc/raddb/sites-enabled/abills_default
это нормально?

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Пт июн 07, 2013 7:17 am

Так что это может быть - где искать то?

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Пн июн 10, 2013 10:11 am

вот подробный лог пппд сессии:

Код: Выделить всё

Jun 10 08:37:17 nas05 pppd[8321]: rcvd [CHAP Response id=0xcd <4da5c03b38f92848135e01c64bfa0d50>, name = "vpnsobaka"]
Jun 10 09:07:43 nas05 pppoe-server[28481]: Session 1563 created for client 90:f6:52:57:ad:01 (10.67.21.27) on vlan90 using Service-Name ''
Jun 10 09:07:43 nas05 pppd[28481]: Plugin /etc/ppp/plugins/rp-pppoe.so loaded.
Jun 10 09:07:43 nas05 pppd[28481]: RP-PPPoE plugin version 3.10 compiled against pppd 2.4.5
Jun 10 09:07:43 nas05 pppd[28481]: Plugin /etc/ppp/plugins/rp-pppoe.so loaded.
Jun 10 09:07:43 nas05 pppd[28481]: RP-PPPoE plugin version 3.10 compiled against pppd 2.4.5
Jun 10 09:07:43 nas05 pppd[28481]: Plugin /usr/lib/pppd/2.4.5/radius.so loaded.
Jun 10 09:07:43 nas05 pppd[28481]: RADIUS plugin initialized.
Jun 10 09:07:43 nas05 pppd[28481]: Plugin /usr/lib/pppd/2.4.5/radattr.so loaded.
Jun 10 09:07:43 nas05 pppd[28481]: RADATTR plugin initialized.
Jun 10 09:07:43 nas05 pppd[28481]: pppd 2.4.5 started by root, uid 0
Jun 10 09:07:43 nas05 pppd[28481]: Connected to 90:f6:52:57:ad:01 via interface vlan90
Jun 10 09:07:43 nas05 pppd[28481]: using channel 178434
Jun 10 09:07:44 nas05 pppd[28481]: Using interface ppp1054
Jun 10 09:07:44 nas05 pppd[28481]: Connect: ppp1054 <--> vlan90
Jun 10 09:07:44 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 09:07:44 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 09:07:44 nas05 pppd[28481]: sent [LCP ConfReq id=0x1 <mru 1472> <auth chap MD5> <magic 0xb7d71317>]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x1 <mru 1480> <magic 0xd947ddea>]
Jun 10 09:07:44 nas05 pppd[28481]: sent [LCP ConfAck id=0x1 <mru 1480> <magic 0xd947ddea>]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x1 <mru 1472> <auth chap MD5> <magic 0xb7d71317>]
Jun 10 09:07:44 nas05 pppd[28481]: sent [LCP EchoReq id=0x0 magic=0xb7d71317]
Jun 10 09:07:44 nas05 pppd[28481]: sent [CHAP Challenge id=0x55 <2219a18e40df3b8466640ec0144d0e6243251d>, name = "nas05"]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [LCP EchoRep id=0x0 magic=0xd947ddea]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [CHAP Response id=0x55 <bd39bdf54165984a07ae252eba21e8c2>, name = "vpn51012"]
Jun 10 09:07:44 nas05 pppd[28481]: RADATTR plugin wrote 7 line(s) to file /var/run/radattr.ppp1054.
Jun 10 09:07:44 nas05 pppd[28481]: sent [CHAP Success id=0x55 ""]
Jun 10 09:07:44 nas05 pppd[28481]: peer from calling number 90:F6:52:57:AD:01 authorized
Jun 10 09:07:44 nas05 pppd[28481]: sent [IPCP ConfReq id=0x1 <addr 10.200.46.1>]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 10 09:07:44 nas05 pppd[28481]: sent [IPCP ConfNak id=0x1 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [IPCP ConfAck id=0x1 <addr 10.200.46.1>]
Jun 10 09:07:44 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x2 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 09:07:44 nas05 pppd[28481]: sent [IPCP ConfAck id=0x2 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 09:07:44 nas05 pppd[28481]: Cannot determine ethernet address for proxy ARP
Jun 10 09:07:44 nas05 pppd[28481]: local  IP address 10.200.46.1
Jun 10 09:07:44 nas05 pppd[28481]: remote IP address 10.200.203.149
Jun 10 09:07:44 nas05 pppd[28481]: Script /etc/ppp/ip-up started (pid 28513)
Jun 10 09:07:44 nas05 pppd[28481]: Script /etc/ppp/ip-up finished (pid 28513), status = 0x0
Jun 10 09:15:08 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x10 <mru 1472> <auth chap MD5> <magic 0x77a76e4b>] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5e f5 79 fb 38 04 05 f1 3c 1e 6e ...
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [LCP TermAck id=0x2] 46 61 69 6c 65 64 20 74 6f 20 61 75 74 68 65 6e 74 69 63 61 74 65 20 6f 75 72 73 65 6c 76 65 73 ...
Jun 10 09:26:16 nas05 pppd[28481]: Connect time 18.6 minutes.
Jun 10 09:26:16 nas05 pppd[28481]: Sent 122000620 bytes, received 20413463 bytes.
Jun 10 09:26:16 nas05 pppd[28481]: Script /etc/ppp/ip-down started (pid 7016)
Jun 10 09:26:16 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 09:26:16 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 09:26:16 nas05 pppd[28481]: sent [LCP ConfReq id=0x2 <mru 1472> <auth chap MD5> <magic 0xe5108161>]
Jun 10 09:26:16 nas05 pppd[28481]: Script /etc/ppp/ip-down finished (pid 7016), status = 0x0
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x2 <mru 1480> <magic 0xdca7d4ca>]
Jun 10 09:26:16 nas05 pppd[28481]: sent [LCP ConfAck id=0x2 <mru 1480> <magic 0xdca7d4ca>]
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x2 <mru 1472> <auth chap MD5> <magic 0xe5108161>]
Jun 10 09:26:16 nas05 pppd[28481]: sent [CHAP Challenge id=0x2b <aa77e429499185cf266c439661d26455dd>, name = "nas05"]
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [CHAP Response id=0x2b <0211646eb54fdc051994174fd6312129>, name = "vpn51012"]
Jun 10 09:26:16 nas05 pppd[28481]: sent [CHAP Success id=0x2b ""]
Jun 10 09:26:16 nas05 pppd[28481]: peer from calling number 90:F6:52:57:AD:01 authorized
Jun 10 09:26:16 nas05 pppd[28481]: sent [IPCP ConfReq id=0x2 <addr 10.200.46.1>]
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x3 <addr 10.200.203.149> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 10 09:26:16 nas05 pppd[28481]: sent [IPCP ConfNak id=0x3 <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [IPCP ConfAck id=0x2 <addr 10.200.46.1>]
Jun 10 09:26:16 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x4 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 09:26:16 nas05 pppd[28481]: sent [IPCP ConfAck id=0x4 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 09:26:16 nas05 pppd[28481]: Cannot determine ethernet address for proxy ARP
Jun 10 09:26:16 nas05 pppd[28481]: local  IP address 10.200.46.1
Jun 10 09:26:16 nas05 pppd[28481]: remote IP address 10.200.203.149
Jun 10 09:26:16 nas05 pppd[28481]: Script /etc/ppp/ip-up started (pid 7031)
Jun 10 09:26:16 nas05 pppd[28481]: Script /etc/ppp/ip-up finished (pid 7031), status = 0x0
Jun 10 11:21:42 nas05 pppd[28481]: rcvd [CHAP Response id=0xf5 <e6d9354b7b0465ef0d09e3f57d3009be>, name = "vpnshvecov"] 00 00 00 00 00 00 00 00 00 06 3f 05 0a d1 09 b8 b8 d1 09 df e0 00 00 6f 74 6f 63 6f 6c 00 00 00 ...
Jun 10 12:20:10 nas05 pppd[28481]: rcvd [proto=0xd932] 00 00 68 1b 00 00 68 1b 00 00 00 00 00 00 91 10 5f 1d d5 f0 fa 22 c1 a2 00 44 53 26 60 00 00 00 ...
Jun 10 12:20:10 nas05 pppd[28481]: Unsupported protocol 0xd932 received
Jun 10 12:20:10 nas05 pppd[28481]: sent [LCP ProtRej id=0x3 d9 32 00 00 68 1b 00 00 68 1b 00 00 00 00 00 00 91 10 5f 1d d5 f0 fa 22 c1 a2 00 44 53 26 60 00 ...]
Jun 10 12:20:10 nas05 pppd[28481]: rcvd [proto=0xd932] 00 00 68 1b 00 00 68 1b 00 00 00 00 00 00 91 10 5f 1d d5 f0 fa 22 c1 a2 00 44 53 26 60 00 00 00 ...
Jun 10 12:20:10 nas05 pppd[28481]: Unsupported protocol 0xd932 received
Jun 10 12:20:10 nas05 pppd[28481]: sent [LCP ProtRej id=0x4 d9 32 00 00 68 1b 00 00 68 1b 00 00 00 00 00 00 91 10 5f 1d d5 f0 fa 22 c1 a2 00 44 53 26 60 00 ...]
Jun 10 12:27:43 nas05 pppd[28481]: rcvd [CHAP Response id=0x48 <fb2e5341526b0bf8dc68f956397c1d89>, name = "vpnshago"] 10 80 79 a7 e0 80 4d 6a 20 00 00 00 00 b7 99 20 01 00 00 9d 38 6a b8 3c 44 36 6b 3c 1e 6e ef 01 ...
Jun 10 12:28:38 nas05 pppd[28481]: rcvd [proto=0xfa2e] 52 c1 30 f1 26 c2 ef e8 e8 e1 06 06 00 00 00 02 07 06 00 00 00 01 01 10 76 70 6e 6b 6f 6e 64 72 ...
Jun 10 12:28:38 nas05 pppd[28481]: Unsupported protocol 0xfa2e received
Jun 10 12:28:38 nas05 pppd[28481]: sent [LCP ProtRej id=0x5 fa 2e 52 c1 30 f1 26 c2 ef e8 e8 e1 06 06 00 00 00 02 07 06 00 00 00 01 01 10 76 70 6e 6b 6f 6e ...]
Jun 10 12:28:52 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x1 <mru 1472> <auth chap MD5> <magic 0xe152844d>] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 01 95 3c 3c 47 32 84 3c 1e 6e ...
Jun 10 12:29:55 nas05 pppd[28481]: rcvd [proto=0xf811] 14 ff 5f 6a c4 ae c3 e1 91 10 45 32 50 ad 00 26 21 a9 41 02 dc cc b1 16 38 44 7f ff ff ff 00 00 ...
Jun 10 12:29:55 nas05 pppd[28481]: Unsupported protocol 0xf811 received
Jun 10 12:29:55 nas05 pppd[28481]: sent [LCP ProtRej id=0x6 f8 11 14 ff 5f 6a c4 ae c3 e1 91 10 45 32 50 ad 00 26 21 a9 41 02 dc cc b1 16 38 44 7f ff ff ff ...]
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [LCP TermAck id=0x6] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ...
Jun 10 12:30:41 nas05 pppd[28481]: Connect time 184.5 minutes.
Jun 10 12:30:41 nas05 pppd[28481]: Sent 2146000933 bytes, received 144716243 bytes.
Jun 10 12:30:41 nas05 pppd[28481]: Script /etc/ppp/ip-down started (pid 5081)
Jun 10 12:30:41 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 12:30:41 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 12:30:41 nas05 pppd[28481]: sent [LCP ConfReq id=0x7 <mru 1472> <auth chap MD5> <magic 0xa178f209>]
Jun 10 12:30:41 nas05 pppd[28481]: Script /etc/ppp/ip-down finished (pid 5081), status = 0x0
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x3 <mru 1480> <magic 0xa3b6e33>]
Jun 10 12:30:41 nas05 pppd[28481]: sent [LCP ConfAck id=0x3 <mru 1480> <magic 0xa3b6e33>]
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x7 <mru 1472> <auth chap MD5> <magic 0xa178f209>]
Jun 10 12:30:41 nas05 pppd[28481]: sent [CHAP Challenge id=0x67 <e50e57d527cab22a85a390839da5b599304c7217396f9b>, name = "nas05"]
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [CHAP Response id=0x67 <1ea56be57f407764ea6a81b9488220b6>, name = "vpn51012"]
Jun 10 12:30:41 nas05 pppd[28481]: sent [CHAP Success id=0x67 ""]
Jun 10 12:30:41 nas05 pppd[28481]: peer from calling number 90:F6:52:57:AD:01 authorized
Jun 10 12:30:41 nas05 pppd[28481]: sent [IPCP ConfReq id=0x3 <addr 10.200.46.1>]
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x5 <addr 10.200.203.149> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 10 12:30:41 nas05 pppd[28481]: sent [IPCP ConfNak id=0x5 <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [IPCP ConfAck id=0x3 <addr 10.200.46.1>]
Jun 10 12:30:41 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x6 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:30:41 nas05 pppd[28481]: sent [IPCP ConfAck id=0x6 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:30:41 nas05 pppd[28481]: Cannot determine ethernet address for proxy ARP
Jun 10 12:30:41 nas05 pppd[28481]: local  IP address 10.200.46.1
Jun 10 12:30:41 nas05 pppd[28481]: remote IP address 10.200.203.149
Jun 10 12:30:41 nas05 pppd[28481]: Script /etc/ppp/ip-up started (pid 5089)
Jun 10 12:30:41 nas05 pppd[28481]: Script /etc/ppp/ip-up finished (pid 5089), status = 0x0
Jun 10 12:31:58 nas05 pppd[28481]: rcvd [proto=0xc84a] 14 22 86 2f 0c 06 50 0a 7b 99 2c 10 35 31 42 35 38 32 31 41 33 38 38 34 30 30 01 08 76 70 6e 76 ...
Jun 10 12:31:58 nas05 pppd[28481]: Unsupported protocol 0xc84a received
Jun 10 12:31:58 nas05 pppd[28481]: sent [LCP ProtRej id=0x8 c8 4a 14 22 86 2f 0c 06 50 0a 7b 99 2c 10 35 31 42 35 38 32 31 41 33 38 38 34 30 30 01 08 76 70 ...]
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x1 <mru 1480> <magic 0x6e4b1d34>] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5e f5 79 fd 0c 65 ...
Jun 10 12:32:01 nas05 pppd[28481]: Connect time 1.4 minutes.
Jun 10 12:32:01 nas05 pppd[28481]: Sent 12704989 bytes, received 14348256 bytes.
Jun 10 12:32:01 nas05 pppd[28481]: Script /etc/ppp/ip-down started (pid 5605)
Jun 10 12:32:01 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 12:32:01 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 12:32:01 nas05 pppd[28481]: sent [LCP ConfReq id=0x9 <mru 1472> <auth chap MD5> <magic 0x47320252>]
Jun 10 12:32:01 nas05 pppd[28481]: sent [LCP ConfAck id=0x1 <mru 1480> <magic 0x6e4b1d34>]
Jun 10 12:32:01 nas05 pppd[28481]: Script /etc/ppp/ip-down finished (pid 5605), status = 0x0
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x4 <mru 1480> <magic 0xd63729de>]
Jun 10 12:32:01 nas05 pppd[28481]: sent [LCP ConfAck id=0x4 <mru 1480> <magic 0xd63729de>]
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x9 <mru 1472> <auth chap MD5> <magic 0x47320252>]
Jun 10 12:32:01 nas05 pppd[28481]: sent [CHAP Challenge id=0x8 <018f3013b92a8f8a79831b9f6cf99518b9>, name = "nas05"]
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [CHAP Response id=0x8 <10426ba18805508654abd06eb1a5fdc4>, name = "vpn51012"]
Jun 10 12:32:01 nas05 pppd[28481]: sent [CHAP Success id=0x8 ""]
Jun 10 12:32:01 nas05 pppd[28481]: peer from calling number 90:F6:52:57:AD:01 authorized
Jun 10 12:32:01 nas05 pppd[28481]: sent [IPCP ConfReq id=0x4 <addr 10.200.46.1>]
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x7 <addr 10.200.203.149> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 10 12:32:01 nas05 pppd[28481]: sent [IPCP ConfNak id=0x7 <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [IPCP ConfAck id=0x4 <addr 10.200.46.1>]
Jun 10 12:32:01 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x8 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:32:01 nas05 pppd[28481]: sent [IPCP ConfAck id=0x8 <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:32:01 nas05 pppd[28481]: Cannot determine ethernet address for proxy ARP
Jun 10 12:32:01 nas05 pppd[28481]: local  IP address 10.200.46.1
Jun 10 12:32:01 nas05 pppd[28481]: remote IP address 10.200.203.149
Jun 10 12:32:01 nas05 pppd[28481]: Script /etc/ppp/ip-up started (pid 5616)
Jun 10 12:32:01 nas05 pppd[28481]: Script /etc/ppp/ip-up finished (pid 5616), status = 0x0
Jun 10 12:32:40 nas05 pppd[28481]: rcvd [proto=0xe2cf] 65 01 4d 5f a8 53 7a e3 64 df 2c 10 35 31 42 35 37 35 35 46 33 30 35 39 30 31 01 0b 76 70 6e 62 ...
Jun 10 12:32:40 nas05 pppd[28481]: Unsupported protocol 0xe2cf received
Jun 10 12:32:40 nas05 pppd[28481]: sent [LCP ProtRej id=0xa e2 cf 65 01 4d 5f a8 53 7a e3 64 df 2c 10 35 31 42 35 37 35 35 46 33 30 35 39 30 31 01 0b 76 70 ...]
Jun 10 12:33:22 nas05 pppd[28481]: rcvd [CHAP Response id=0xee <3f492e214ba68a963ae46edc25169896>, name = "vpniverson"] 00 00 00 00 00 00 00 00 00 42 43 05 0a 98 4d d9 62 98 4d f5 5a 20 01 00 00 9d 38 95 3c 00 4f 0f ...
Jun 10 12:39:41 nas05 pppd[28481]: rcvd [proto=0xda79] 16 cb 14 86 cb d9 e3 e8 c9 db 2c 10 35 31 42 35 38 36 34 31 32 46 32 37 30 31 01 0d 76 70 6e 79 ...
Jun 10 12:39:41 nas05 pppd[28481]: Unsupported protocol 0xda79 received
Jun 10 12:39:41 nas05 pppd[28481]: sent [LCP ProtRej id=0xb da 79 16 cb 14 86 cb d9 e3 e8 c9 db 2c 10 35 31 42 35 38 36 34 31 32 46 32 37 30 31 01 0d 76 70 ...]
Jun 10 12:50:30 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x5 <mru 1472> <auth chap MD5> <magic 0xe1e6fd4c>] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 11 fe a6 fc cc 2b 5a 8f 6d 5a 18 65 e9 ...
Jun 10 12:50:43 nas05 pppd[28481]: rcvd [proto=0xf811] b9 97 d5 a7 c2 69 c3 e1 91 10 43 41 8a 07 00 26 64 8a 41 02 bd 23 fb 54 e7 a2 7f ff ff ff 00 00 ...
Jun 10 12:50:43 nas05 pppd[28481]: Unsupported protocol 0xf811 received
Jun 10 12:50:43 nas05 pppd[28481]: sent [LCP ProtRej id=0xc f8 11 b9 97 d5 a7 c2 69 c3 e1 91 10 43 41 8a 07 00 26 64 8a 41 02 bd 23 fb 54 e7 a2 7f ff ff ff ...]
Jun 10 12:51:42 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x6 <mru 1400> <magic 0xca750862>] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ff ff 00 00 f0 00 48 30 ...
Jun 10 12:51:42 nas05 pppd[28481]: Connect time 19.7 minutes.
Jun 10 12:51:42 nas05 pppd[28481]: Sent 436517738 bytes, received 80521238 bytes.
Jun 10 12:51:42 nas05 pppd[28481]: Script /etc/ppp/ip-down started (pid 15315)
Jun 10 12:51:42 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 12:51:42 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 12:51:42 nas05 pppd[28481]: sent [LCP ConfReq id=0xd <mru 1472> <auth chap MD5> <magic 0x8c4694c0>]
Jun 10 12:51:42 nas05 pppd[28481]: sent [LCP ConfAck id=0x6 <mru 1400> <magic 0xca750862>]
Jun 10 12:51:42 nas05 pppd[28481]: Script /etc/ppp/ip-down finished (pid 15315), status = 0x0
Jun 10 12:51:42 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x5 <mru 1480> <magic 0x1e060bde>]
Jun 10 12:51:42 nas05 pppd[28481]: sent [LCP ConfAck id=0x5 <mru 1480> <magic 0x1e060bde>]
Jun 10 12:51:42 nas05 pppd[28481]: rcvd [LCP ConfAck id=0xd <mru 1472> <auth chap MD5> <magic 0x8c4694c0>]
Jun 10 12:51:42 nas05 pppd[28481]: sent [CHAP Challenge id=0xe5 <4bc3a3deb63af7638d1d52ef4a37559c>, name = "nas05"]
Jun 10 12:51:42 nas05 pppd[28481]: rcvd [CHAP Response id=0xe5 <1dadcd85e2e6115296a852c45614c3ad>, name = "vpn51012"]
Jun 10 12:51:43 nas05 pppd[28481]: sent [CHAP Success id=0xe5 ""]
Jun 10 12:51:43 nas05 pppd[28481]: peer from calling number 90:F6:52:57:AD:01 authorized
Jun 10 12:51:43 nas05 pppd[28481]: sent [IPCP ConfReq id=0x5 <addr 10.200.46.1>]
Jun 10 12:51:43 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0x9 <addr 10.200.203.149> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 10 12:51:43 nas05 pppd[28481]: sent [IPCP ConfNak id=0x9 <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:51:43 nas05 pppd[28481]: rcvd [IPCP ConfAck id=0x5 <addr 10.200.46.1>]
Jun 10 12:51:43 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0xa <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:51:43 nas05 pppd[28481]: sent [IPCP ConfAck id=0xa <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:51:43 nas05 pppd[28481]: Cannot determine ethernet address for proxy ARP
Jun 10 12:51:43 nas05 pppd[28481]: local  IP address 10.200.46.1
Jun 10 12:51:43 nas05 pppd[28481]: remote IP address 10.200.203.149
Jun 10 12:51:43 nas05 pppd[28481]: Script /etc/ppp/ip-up started (pid 15322)
Jun 10 12:51:43 nas05 pppd[28481]: Script /etc/ppp/ip-up finished (pid 15322), status = 0x0
Jun 10 12:54:03 nas05 pppd[28481]: rcvd [proto=0xff53] 83 06 c5 74 78 78 a8 67 c3 85 2c 10 35 31 42 35 36 34 31 41 30 44 34 44 30 30 01 0b 76 70 6e 6b ...
Jun 10 12:54:03 nas05 pppd[28481]: Unsupported protocol 0xff53 received
Jun 10 12:54:03 nas05 pppd[28481]: sent [LCP ProtRej id=0xe ff 53 83 06 c5 74 78 78 a8 67 c3 85 2c 10 35 31 42 35 36 34 31 41 30 44 34 44 30 30 01 0b 76 70 ...]
Jun 10 12:55:41 nas05 pppd[28481]: rcvd [proto=0xf811] c9 39 5f 6a d1 82 c3 e1 91 10 1a e1 1a e2 00 1c 96 63 41 00 c6 98 18 40 a9 f8 00 00 00 00 00 00 ...
Jun 10 12:55:41 nas05 pppd[28481]: Unsupported protocol 0xf811 received
Jun 10 12:55:41 nas05 pppd[28481]: sent [LCP ProtRej id=0xf f8 11 c9 39 5f 6a d1 82 c3 e1 91 10 1a e1 1a e2 00 1c 96 63 41 00 c6 98 18 40 a9 f8 00 00 00 00 ...]
Jun 10 12:55:45 nas05 pppd[28481]: rcvd [CHAP Response id=0xac <38943462510badf4da90df66e94a2b31>, name = "vpnandred21"] 00 00 00 00 00 00 00 00 01 01 08 0a 14 d5 65 32 2d 23 12 e7 20 01 00 00 5e f5 79 fd 00 30 1f ce ...
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x3 <mru 1480> <magic 0x1370fae0>] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0f fe 00 00 ea 83 24 38 ...
Jun 10 12:55:59 nas05 pppd[28481]: Connect time 4.3 minutes.
Jun 10 12:55:59 nas05 pppd[28481]: Sent 71450686 bytes, received 65824530 bytes.
Jun 10 12:55:59 nas05 pppd[28481]: Script /etc/ppp/ip-down started (pid 17380)
Jun 10 12:55:59 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 12:55:59 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 12:55:59 nas05 pppd[28481]: sent [LCP ConfReq id=0x10 <mru 1472> <auth chap MD5> <magic 0xffc2b84c>]
Jun 10 12:55:59 nas05 pppd[28481]: sent [LCP ConfAck id=0x3 <mru 1480> <magic 0x1370fae0>]
Jun 10 12:55:59 nas05 pppd[28481]: Script /etc/ppp/ip-down finished (pid 17380), status = 0x0
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [LCP ConfReq id=0x6 <mru 1480> <magic 0x2ccb1dd8>]
Jun 10 12:55:59 nas05 pppd[28481]: sent [LCP ConfAck id=0x6 <mru 1480> <magic 0x2ccb1dd8>]
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [LCP ConfAck id=0x10 <mru 1472> <auth chap MD5> <magic 0xffc2b84c>]
Jun 10 12:55:59 nas05 pppd[28481]: sent [CHAP Challenge id=0xe2 <6a21969cb18465543262077bff84bd6614fb>, name = "nas05"]
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [CHAP Response id=0xe2 <f4267f6010a2b521e1259e7c63fbdc90>, name = "vpn51012"]
Jun 10 12:55:59 nas05 pppd[28481]: sent [CHAP Success id=0xe2 ""]
Jun 10 12:55:59 nas05 pppd[28481]: peer from calling number 90:F6:52:57:AD:01 authorized
Jun 10 12:55:59 nas05 pppd[28481]: sent [IPCP ConfReq id=0x6 <addr 10.200.46.1>]
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0xb <addr 10.200.203.149> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Jun 10 12:55:59 nas05 pppd[28481]: sent [IPCP ConfNak id=0xb <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [IPCP ConfAck id=0x6 <addr 10.200.46.1>]
Jun 10 12:55:59 nas05 pppd[28481]: rcvd [IPCP ConfReq id=0xc <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:55:59 nas05 pppd[28481]: sent [IPCP ConfAck id=0xc <addr 10.200.203.149> <ms-dns1 195.225.145.2> <ms-dns2 195.225.145.8>]
Jun 10 12:55:59 nas05 pppd[28481]: Cannot determine ethernet address for proxy ARP
Jun 10 12:55:59 nas05 pppd[28481]: local  IP address 10.200.46.1
Jun 10 12:55:59 nas05 pppd[28481]: remote IP address 10.200.203.149
Jun 10 12:55:59 nas05 pppd[28481]: Script /etc/ppp/ip-up started (pid 17388)
Jun 10 12:55:59 nas05 pppd[28481]: Script /etc/ppp/ip-up finished (pid 17388), status = 0x0
Jun 10 12:56:27 nas05 pppd[28481]: rcvd [proto=0xd617] 00 00 66 00 00 00 66 00 00 00 00 00 00 00 93 27 2e b6 56 25 fc 28 00 50 a9 4f fb b5 5e 6b 66 90 ...
Jun 10 12:56:27 nas05 pppd[28481]: Unsupported protocol 0xd617 received
Jun 10 12:56:27 nas05 pppd[28481]: sent [LCP ProtRej id=0x11 d6 17 00 00 66 00 00 00 66 00 00 00 00 00 00 00 93 27 2e b6 56 25 fc 28 00 50 a9 4f fb b5 5e 6b ...]
Jun 10 12:56:30 nas05 pppd[28481]: rcvd [proto=0xf811] f1 3b 6d 7e ff 38 c3 e1 91 10 f2 86 e7 7f 00 3c 05 87 60 00 00 00 00 00 3b 15 20 01 00 00 9d 38 ...
Jun 10 12:56:30 nas05 pppd[28481]: Unsupported protocol 0xf811 received
Jun 10 12:56:30 nas05 pppd[28481]: sent [LCP ProtRej id=0x12 f8 11 f1 3b 6d 7e ff 38 c3 e1 91 10 f2 86 e7 7f 00 3c 05 87 60 00 00 00 00 00 3b 15 20 01 00 00 ...]
Jun 10 12:56:40 nas05 pppd[28481]: rcvd [LCP TermReq id=0x76 "Failed to authenticate ourselves to peer"] 0c 8f 6d 78 00 04 7f 00 00 00 55 00 50 86 b6 bc 08 21 e8 d6 7a 52 b2 50 07 6e 59 4e 19 3f bd 94 ...
Jun 10 12:56:40 nas05 pppd[28481]: LCP terminated by peer (Failed to authenticate ourselves to peer)
Jun 10 12:56:40 nas05 pppd[28481]: Connect time 0.7 minutes.
Jun 10 12:56:40 nas05 pppd[28481]: Sent 4648023 bytes, received 31723540 bytes.
Jun 10 12:56:40 nas05 pppd[28481]: Script /etc/ppp/ip-down started (pid 17820)
Jun 10 12:56:40 nas05 pppd[28481]: Couldn't increase MTU to 1500
Jun 10 12:56:40 nas05 pppd[28481]: Couldn't increase MRU to 1500
Jun 10 12:56:40 nas05 pppd[28481]: sent [LCP TermAck id=0x76]
Jun 10 12:56:40 nas05 pppd[28481]: rcvd [LCP TermAck id=0x2] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 d9 d5 ...
Jun 10 12:56:40 nas05 pppd[28481]: Connection terminated.
Jun 10 12:56:40 nas05 pppd[28481]: Waiting for 1 child processes...
Jun 10 12:56:40 nas05 pppd[28481]:   script /etc/ppp/ip-down, pid 17820
Jun 10 12:56:40 nas05 pppd[28481]: Script /etc/ppp/ip-down finished (pid 17820), status = 0x1
Jun 10 12:56:40 nas05 pppd[28481]: RADATTR plugin removed file /var/run/radattr.ppp1054.
Jun 10 12:56:40 nas05 pppd[28481]: Exit.

worky
Сообщения: 67
Зарегистрирован: Пт мар 13, 2009 6:41 pm

Re: Аномальные обрывы сессий

Сообщение worky » Чт июн 13, 2013 2:29 pm

походу эти фантомные фреймы гнались на пппд из дров или сетевки.
вернулись на старую сетевку - все ок стало.
тема закрыта

Ответить