STM32 lwIP PPPoS, STM32 lwIP PPPoS Опции

[eisufu]

Не знаю, существуют ли русскоязычные гуру в PPP, но рискну.
На STM32F407 крутится FreeRTOS с lwIP. Пытаюсь установить PPP-соединение, но оно не устанавливается до конца. Собрал с выводом диагностической информации (лог - ниже), но интерпретировать не могу. Видел в интернете, что у людей возникают схожие проблемы, но решений и у них нет. Помогите пожалуйста найти решение проблемы.
Пакеты фрагментируются, та как приходится перенаправлять траффик с USB-модема, подключённого к компьютеру, на устройство и обратно. Скрипт в режиме поллинга с периодом 0.1 секунды читает и пишет из виртуального COM-порта USB-модема в COM-порт, к которому подключено устройство, и наоборот. Думаю пакеты из байтов должны нормально собираться. sio_read не бесконечно блокирующая, стоит таймаут 1.5 секунды. Иначе вообще ничего не получается.

CODE

send: 'ATZ0 E0 V0'
recv:
0
send: 'ATS0=0'
recv:
0
send: 'AT+CGDCONT=1,"IP","internet.mts.ru"'
recv:
0
send: 'ATDT*99#'
recv:
1
lcp_init: xmit_accm=0 0 0 0
upap_init: 0
pppOverSerialOpen: unit 0: Connecting
pppStart: unit 0
ppp_set_xaccm[0]: outACCM=0 0 0 0
ppp_send_config[0]: outACCM=FF FF FF FF
ppp_recv_config[0]: inACCM=0 0 0 0
lcp_lowerup: asyncmap=0 0 0 0
LCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
auth_reset: 0
lcp_addci: L opt=2 0
lcp_addci: L opt=5 52181044
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=47
fsm_sdata(LCP): Sent code 1,1,20.
LCP: sending Configure-Request, id 1
LCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppStart: finished
pppInProc[0]: got 154 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,224,25
fsm 0
lcp_addci: L opt=5 33CF11CE
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=46
fsm_sdata(LCP): Sent code 1,2,20.
LCP: sending Configure-Request, id 2
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=53
fsm_sdata(LCP): Sent code 2,225,25.
pppInput[0]: packet processed
pppInProc[0]: got 153 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,226,25
fs2 0
lcp_addci: L opt=5 F7BDAD33
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=44
fsm_sdata(LCP): Sent code 1,3,20.
LCP: sending Configure-Request, id 3
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,227,25.
pppInput[0]: packet processed
pppInProc[0]: got 151 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,228,25
fsm 0
lcp_addci: L opt=5 246375C
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=45
fsm_sdata(LCP): Sent code 1,4,20.
LCP: sending Configure-Request, id 4
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,229,25.
pppInput[0]: packet processed
pppInProc[0]: got 153 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,230,25
fs2 0
lcp_addci: L opt=5 E236C5DD
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=44
fsm_sdata(LCP): Sent code 1,5,20.
LCP: sending Configure-Request, id 5
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,231,25.
pppInput[0]: packet processed
pppInProc[0]: got 152 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,232,25
fsm 0
lcp_addci: L opt=5 8E005B91
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=46
fsm_sdata(LCP): Sent code 1,6,20.
LCP: sending Configure-Request, id 6
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,233,25.
pppInput[0]: packet processed
pppInProc[0]: got 153 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,234,25
fs2 0
lcp_addci: L opt=5 37DA08AA
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=45
fsm_sdata(LCP): Sent code 1,7,20.
LCP: sending Configure-Request, id 7
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,235,25.
pppInput[0]: packet processed
pppInProc[0]: got 152 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,236,25
fsm 0
lcp_addci: L opt=5 7D452883
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=46
fsm_sdata(LCP): Sent code 1,8,20.
LCP: sending Configure-Request, id 8
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,237,25.
pppInput[0]: packet processed
pppInProc[0]: got 154 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,238,25
fs2 0
lcp_addci: L opt=5 BB77512B
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=44
fsm_sdata(LCP): Sent code 1,9,20.
LCP: sending Configure-Request, id 9
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=53
fsm_sdata(LCP): Sent code 2,239,25.
pppInput[0]: packet processed
pppInProc[0]: got 151 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,240,25
fsm 0
lcp_addci: L opt=5 320709B8
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=47
fsm_sdata(LCP): Sent code 1,10,20.
LCP: sending Configure-Request, id 10
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,241,25.
pppInput[0]: packet processed
pppInProc[0]: got 154 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,242,25
fst=2 0
lcp_addci: L opt=5 874F608F
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=44
fsm_sdata(LCP): Sent code 1,11,20.
LCP: sending Configure-Request, id 11
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (19972D3) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=52
fsm_sdata(LCP): Sent code 2,243,25.
pppInput[0]: packet processed
pppInProc[0]: got 2 bytes
LCP: timeout resending Config-Request state=8 (LS_ACKSENT)
lcp_addci: L opt=2 0
lcp_addci: L opt=5 874F608F
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=45
fsm_sdata(LCP): Sent code 1,11,20.
LCP: sending Configure-Request, id 11
pppClose() called
pppClose: unit 0 kill_link -> pppStop
pppStop: unit 0
pppWrite[0]: len=29
fsm_sdata(LCP): Sent code 5,12,16.
LCP: close reason=User request state 8 (LS_ACKSENT) -> 4 (LS_CLOSING)
pppRecvWakeup: unit 0
LCP: timeout resending Terminate-Requests state=4 (LS_CLOSING)
pppWrite[0]: len=29
fsm_sdata(LCP): Sent code 5,13,16.
LCP: timeout sending Terminate-Request state=4 (LS_CLOSING)
link_terminated: 0
Connection terminated.
pppLinkTerminated: unit 0
pppRecvWakeup: unit 0
pppLinkTerminated: unit 0: linkStatusCB=0x800de11 errCode=-5
pppLinkTerminated: finished.

Сообщение отредактировал IgorKossak - Jul 9 2012, 18:48

Причина редактирования: [codebox] для длинных простыней!!!

[kan35]

как я понимаю нужно оставить что то одно или CHAP или PAP, оставьте PAP и дайте лог.

[eisufu]

как я понимаю нужно оставить что то одно или CHAP или PAP, оставьте PAP и дайте лог.

вот лог

CODE

lcp_init: xmit_accm=0 0 0 0
upap_init: 0
tx dump (11/11):
41 54 20 5A 30 20 45 30 20 56 30 AT.Z0.E0.V0
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (7/7):
41 54 20 53 30 3D 30 AT.S0=0
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (36/36):
41 54 20 2B 43 47 44 43 4F 4E 54 3D 31 2C 22 49 AT.+CGDCONT=1,"I
50 22 2C 22 69 6E 74 65 72 6E 65 74 2E 6D 74 73 P","internet.mts
2E 72 75 22 .ru"
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (9/9):
41 54 20 44 54 2A 39 39 23 AT.DT*99#
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
31 0D 1.
pppOverSerialOpen: unit 0: Connecting
pppStart: unit 0
ppp_set_xaccm[0]: outACCM=0 0 0 0
ppp_send_config[0]: outACCM=FF FF FF FF
ppp_recv_config[0]: inACCM=0 0 0 0
lcp_lowerup: asyncmap=0 0 0 0
LCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
auth_reset: 0
lcp_addci: L opt=2 0
lcp_addci: L opt=5 34DE8CCF
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=45
tx dump (45/45):
7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 34 7D 22 ~.}#.!}!}!}.}4}"
7D 26 7D 20 7D 20 7D 20 7D 20 7D 25 7D 26 34 DE }&}.}.}.}.}%}&4.
8C CF 7D 27 7D 22 7D 28 7D 22 57 8D 7E ..}'}"}(}"W.~
fsm_sdata(LCP): Sent code 1,1,20.
LCP: sending Configure-Request, id 1
LCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppStart: finished
rx dump (98/1504):
7E FF 7D 23 C0 21 7D 21 66 7D 20 7D 39 7D 22 7D ~.}#.!}!f}.}9}"}
26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 7D &}.}.}.}.}#}%.#}
25 7D 25 7D 26 7D 34 56 A8 81 7D 27 7D 22 7D 28 %}%}&}4V..}'}"}(
7D 22 21 CA 7E 7E FF 7D 23 C0 21 7D 22 7D 21 7D }"!.~~.}#.!}"}!}
20 7D 34 7D 22 7D 26 7D 20 7D 20 7D 20 7D 20 7D .}4}"}&}.}.}.}.}
25 7D 26 34 DE 8C CF 7D 27 7D 22 7D 28 7D 22 BC %}&4...}'}"}(}".
E4 7E .~
pppInProc[0]: got 98 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,102,25
fsm_rconfreq(LCP): Rcvd id 102 state=6 (LS_REQSENT)
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (1456A881) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=53
tx dump (53/53):
7E FF 7D 23 C0 21 7D 22 66 7D 20 7D 39 7D 22 7D ~.}#.!}"f}.}9}"}
26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 7D &}.}.}.}.}#}%.#}
25 7D 25 7D 26 7D 34 56 A8 81 7D 27 7D 22 7D 28 %}%}&}4V..}'}"}(
7D 22 AC C6 7E }"..~
fsm_sdata(LCP): Sent code 2,102,25.
pppInput[0]: packet processed
pppInput[0]: LCP len=20
fsm_input(LCP):2,1,20
fsm_rconfack(LCP): Rcvd id 1 state=8 (LS_ACKSENT)
lcp_acki: Ack
ppp_send_config[0]: outACCM=0 0 0 0
ppp_recv_config[0]: inACCM=0 0 0 0
link_established: unit 0; Lowering up all protocols...
upap_lowerup: init 0 clientstate s=0
IPCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
pppWrite[0]: len=29
tx dump (29/29):
FF 03 80 21 01 01 00 16 03 06 00 00 00 00 81 06 ...!............
00 00 00 00 83 06 00 00 00 00 6E DB 7E ..........n.~
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppInput[0]: packet processed
rx dump (65/1504):
7E FF 7D 23 C0 21 7D 2B 67 7D 20 7D 28 7D 34 56 ~.}#.!}+g}.}(}4V
A8 81 80 7D 36 7E 7E C2 23 01 01 00 23 10 94 F8 ...}6~~.#...#...
71 E7 40 33 77 EB 84 27 C6 DE 5E BD 4C A3 55 4D q.@3w..'..^.L.UM
54 53 5F 43 48 41 50 5F 53 52 56 52 B8 EF 7E 33 TS_CHAP_SRVR..~3
0D .
pppInProc[0]: got 65 bytes
pppInput[0]: LCP len=8
fsm_input(LCP):11,103,8
fsm_input(LCP): default:
pppInput[0]: packet processed
pppInput[0]: rejecting unsupported proto 0xc223 len=35
pppWrite[0]: len=49
tx dump (49/49):
7E FF 03 C0 21 08 02 00 29 C2 23 01 01 00 23 10 ~...!...).#...#.
94 F8 71 E7 40 33 77 EB 84 27 C6 DE 5E BD 4C A3 ..q.@3w..'..^.L.
55 4D 54 53 5F 43 48 41 50 5F 53 52 56 52 59 69 UMTS_CHAP_SRVRYi
7E ~
fsm_sdata(LCP): Sent code 8,2,41.
rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
tx dump (30/30):
7E FF 03 80 21 01 01 00 16 03 06 00 00 00 00 81 ~...!...........
06 00 00 00 00 83 06 00 00 00 00 6E DB 7E ...........n.~
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):
это 200 мс таймауты в sio_read

отвергает CHAP, а сервер ничего не отвечает

Код

FF 03 80 21 01 01 00 16  03 06 00 00 00 00 81 06  ...!............
00 00 00 00 83 06 00 00  00 00 6E DB 7E           ..........n.~

фрейминг нарушен, я правильно понимаю?

CODE

lcp_init: xmit_accm=0 0 0 0
tx dump (11/11):
41 54 20 5A 30 20 45 30 20 56 30 AT.Z0.E0.V0
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (7/7):
41 54 20 53 30 3D 30 AT.S0=0
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (36/36):
41 54 20 2B 43 47 44 43 4F 4E 54 3D 31 2C 22 49 AT.+CGDCONT=1,"I
50 22 2C 22 69 6E 74 65 72 6E 65 74 2E 6D 74 73 P","internet.mts
2E 72 75 22 .ru"
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (9/9):
41 54 20 44 54 2A 39 39 23 AT.DT*99#
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
31 0D 1.
pppOverSerialOpen: unit 0: Connecting
pppStart: unit 0
ppp_set_xaccm[0]: outACCM=0 0 0 0
ppp_send_config[0]: outACCM=FF FF FF FF
ppp_recv_config[0]: inACCM=0 0 0 0
lcp_lowerup: asyncmap=0 0 0 0
LCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
auth_reset: 0
lcp_addci: L opt=2 0
lcp_addci: L opt=5 52181044
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=47
tx dump (47/47):
7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 34 7D 22 ~.}#.!}!}!}.}4}"
7D 26 7D 20 7D 20 7D 20 7D 20 7D 25 7D 26 52 7D }&}.}.}.}.}%}&R}
38 7D 30 44 7D 27 7D 22 7D 28 7D 22 6E E1 7E 8}0D}'}"}(}"n.~
fsm_sdata(LCP): Sent code 1,1,20.
LCP: sending Configure-Request, id 1
LCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppStart: finished
rx dump (100/1504):
7E FF 7D 23 C0 21 7D 21 6C 7D 20 7D 39 7D 22 7D ~.}#.!}!l}.}9}"}
26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 7D &}.}.}.}.}#}%.#}
25 7D 25 7D 26 7D 34 6B 31 77 7D 27 7D 22 7D 28 %}%}&}4k1w}'}"}(
7D 22 F1 88 7E 7E FF 7D 23 C0 21 7D 22 7D 21 7D }"..~~.}#.!}"}!}
20 7D 34 7D 22 7D 26 7D 20 7D 20 7D 20 7D 20 7D .}4}"}&}.}.}.}.}
25 7D 26 52 7D 38 7D 30 44 7D 27 7D 22 7D 28 7D %}&R}8}0D}'}"}(}
22 85 88 7E "..~
pppInProc[0]: got 100 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,108,25
fsm_rconfreq(LCP): Rcvd id 108 state=6 (LS_REQSENT)
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (146B3177) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=53
tx dump (53/53):
7E FF 7D 23 C0 21 7D 22 6C 7D 20 7D 39 7D 22 7D ~.}#.!}"l}.}9}"}
26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 7D &}.}.}.}.}#}%.#}
25 7D 25 7D 26 7D 34 6B 31 77 7D 27 7D 22 7D 28 %}%}&}4k1w}'}"}(
7D 22 7C 84 7E }"|.~
fsm_sdata(LCP): Sent code 2,108,25.
pppInput[0]: packet processed
pppInput[0]: LCP len=20
fsm_input(LCP):2,1,20
fsm_rconfack(LCP): Rcvd id 1 state=8 (LS_ACKSENT)
lcp_acki: Ack
ppp_send_config[0]: outACCM=0 0 0 0
ppp_recv_config[0]: inACCM=0 0 0 0
link_established: unit 0; Lowering up all protocols...
IPCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
pppInput[0]: packet processed
rx dump (62/1504):
7E FF 7D 23 C0 21 7D 2B 6D 7D 20 7D 28 7D 34 6B ~.}#.!}+m}.}(}4k
31 77 FA DA 7E 7E C2 23 01 01 00 23 10 D0 A0 01 1w..~~.#...#....
97 22 05 E5 EB 2C 74 B4 08 2A F9 36 7F 55 4D 54 ."...,t..*.6.UMT
53 5F 43 48 41 50 5F 53 52 56 52 EB 09 7E S_CHAP_SRVR..~
pppInProc[0]: got 62 bytes
pppInput[0]: LCP len=8
fsm_input(LCP):11,109,8
fsm_input(LCP): default:
pppInput[0]: packet processed
pppInput[0]: CHAP len=35
ChapReceiveChallenge: Rcvd id 1.
ChapReceiveChallenge: received name field 'UMTS_CHAP_SRVR'
pppWrite[0]: len=32
tx dump (32/32):
7E FF 03 C2 23 02 01 00 18 10 A3 DA 18 42 B8 5C ~...#........B.\
BA B5 A1 E6 A8 C6 FA 14 1E EA 6D 74 73 2F 9D 7E ..........mts/.~
pppInput[0]: packet processed
rx dump (10/1504):
7E C2 23 03 01 00 04 C2 BC 7E ~.#......~
pppInProc[0]: got 10 bytes
pppInput[0]: CHAP len=4
ChapReceiveSuccess: Rcvd id 1.
auth_withpeer_success: 0 proto=C223
pppWrite[0]: len=30
tx dump (30/30):
7E FF 03 80 21 01 01 00 16 03 06 00 00 00 00 81 ~...!...........
06 00 00 00 00 83 06 00 00 00 00 6E DB 7E ...........n.~
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppInput[0]: packet processed
rx dump (2/1504):
33 0D 3.
pppInProc[0]: got 2 bytes
rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
tx dump (30/30):
7E FF 03 80 21 01 01 00 16 03 06 00 00 00 00 81 ~...!...........
06 00 00 00 00 83 06 00 00 00 00 6E DB 7E ...........n.~
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

— это лог с MD5_SUPPORT=1 PAP_SUPPORT=0 CHAP_SUPPORT=1

33 0D - это уже модем в командном режиме отвечает NO CARRIER

извиняюсь, но лог для PAP был снят с pppSetAuth(PPPAUTHTYPE_CHAP, PPP_AUTH_USERNAME, PPP_AUTH_PASSWORD); исправил на pppSetAuth(PPPAUTHTYPE_ANY, PPP_AUTH_USERNAME, PPP_AUTH_PASSWORD); вот он:

CODE

lcp_init: xmit_accm=0 0 0 0
upap_init: 0
tx dump (11/11):
41 54 20 5A 30 20 45 30 20 56 30 AT.Z0.E0.V0
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (7/7):
41 54 20 53 30 3D 30 AT.S0=0
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (36/36):
41 54 20 2B 43 47 44 43 4F 4E 54 3D 31 2C 22 49 AT.+CGDCONT=1,"I
50 22 2C 22 69 6E 74 65 72 6E 65 74 2E 6D 74 73 P","internet.mts
2E 72 75 22 .ru"
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
30 0D 0.
tx dump (9/9):
41 54 20 44 54 2A 39 39 23 AT.DT*99#
rx dump (0/256):

tx dump (2/2):
0D 0A ..
rx dump (2/256):
31 0D 1.
pppOverSerialOpen: unit 0: Connecting
pppStart: unit 0
ppp_set_xaccm[0]: outACCM=0 0 0 0
ppp_send_config[0]: outACCM=FF FF FF FF
ppp_recv_config[0]: inACCM=0 0 0 0
lcp_lowerup: asyncmap=0 0 0 0
LCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
auth_reset: 0
lcp_addci: L opt=2 0
lcp_addci: L opt=5 52181044
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=47
tx dump (47/47):
7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 34 7D 22 ~.}#.!}!}!}.}4}"
7D 26 7D 20 7D 20 7D 20 7D 20 7D 25 7D 26 52 7D }&}.}.}.}.}%}&R}
38 7D 30 44 7D 27 7D 22 7D 28 7D 22 6E E1 7E 8}0D}'}"}(}"n.~
fsm_sdata(LCP): Sent code 1,1,20.
LCP: sending Configure-Request, id 1
LCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppStart: finished
rx dump (102/1504):
7E FF 7D 23 C0 21 7D 21 72 7D 20 7D 39 7D 22 7D ~.}#.!}!r}.}9}"}
26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 7D &}.}.}.}.}#}%.#}
25 7D 25 7D 26 7D 34 81 E6 87 7D 27 7D 22 7D 28 %}%}&}4...}'}"}(
7D 22 7D 34 7D 20 7E 7E FF 7D 23 C0 21 7D 22 7D }"}4}.~~.}#.!}"}
21 7D 20 7D 34 7D 22 7D 26 7D 20 7D 20 7D 20 7D !}.}4}"}&}.}.}.}
20 7D 25 7D 26 52 7D 38 7D 30 44 7D 27 7D 22 7D .}%}&R}8}0D}'}"}
28 7D 22 85 88 7E (}"..~
pppInProc[0]: got 102 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,114,25
fsm_rconfreq(LCP): Rcvd id 114 state=6 (LS_REQSENT)
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (1481E687) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=54
tx dump (54/54):
7E FF 7D 23 C0 21 7D 22 72 7D 20 7D 39 7D 22 7D ~.}#.!}"r}.}9}"}
26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 7D &}.}.}.}.}#}%.#}
25 7D 25 7D 26 7D 34 81 E6 87 7D 27 7D 22 7D 28 %}%}&}4...}'}"}(
7D 22 99 7D 2C 7E }".},~
fsm_sdata(LCP): Sent code 2,114,25.
pppInput[0]: packet processed
pppInput[0]: LCP len=20
fsm_input(LCP):2,1,20
fsm_rconfack(LCP): Rcvd id 1 state=8 (LS_ACKSENT)
lcp_acki: Ack
ppp_send_config[0]: outACCM=0 0 0 0
ppp_recv_config[0]: inACCM=0 0 0 0
link_established: unit 0; Lowering up all protocols...
upap_lowerup: init 0 clientstate s=0
IPCP: lowerup state 0 (LS_INITIAL) -> 2 (LS_CLOSED)
pppWrite[0]: len=29
tx dump (29/29):
FF 03 80 21 01 01 00 16 03 06 00 00 00 00 81 06 ...!............
00 00 00 00 83 06 00 00 00 00 6E DB 7E ..........n.~
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: open state 2 (LS_CLOSED) -> 6 (LS_REQSENT)
pppInput[0]: packet processed
rx dump (64/1504):
7E FF 7D 23 C0 21 7D 2B 73 7D 20 7D 28 7D 34 81 ~.}#.!}+s}.}(}4.
E6 87 75 76 7E 7E C2 23 01 01 00 23 10 BC 8C 6A ..uv~~.#...#...j
58 FC B7 3D BB 6C 61 FA D0 A2 64 12 E6 55 4D 54 X..=.la...d..UMT
53 5F 43 48 41 50 5F 53 52 56 52 A0 F4 7E 33 0D S_CHAP_SRVR..~3.
pppInProc[0]: got 64 bytes
pppInput[0]: LCP len=8
fsm_input(LCP):11,115,8
fsm_input(LCP): default:
pppInput[0]: packet processed
pppInput[0]: rejecting unsupported proto 0xc223 len=35
pppWrite[0]: len=49
tx dump (49/49):
7E FF 03 C0 21 08 02 00 29 C2 23 01 01 00 23 10 ~...!...).#...#.
BC 8C 6A 58 FC B7 3D BB 6C 61 FA D0 A2 64 12 E6 ..jX..=.la...d..
55 4D 54 53 5F 43 48 41 50 5F 53 52 56 52 41 72 UMTS_CHAP_SRVRAr
7E ~
fsm_sdata(LCP): Sent code 8,2,41.
rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
tx dump (30/30):
7E FF 03 80 21 01 01 00 16 03 06 00 00 00 00 81 ~...!...........
06 00 00 00 00 83 06 00 00 00 00 6E DB 7E ...........n.~
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

rx dump (0/1504):

хотя сервер себя повёл точно так же

может ему MS CHAP v2 нужен?

нет. сервер отверг возвращённый хэш, по-видимому