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] для длинных простыней!!!

[eisufu]

вот.

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 (13/13):
41 54 20 44 54 2A 39 39 2A 2A 2A 31 23 AT.DT*99***1#
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 (99/1504):
7E FF 7D 23 C0 21 7D 21 7D 20 7D 20 7D 39 7D 22 ~.}#.!}!}.}.}9}"
7D 26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 }&}.}.}.}.}#}%.#
7D 25 7D 25 7D 26 7D 34 C4 E9 83 7D 27 7D 22 7D }%}%}&}4...}'}"}
28 7D 22 F8 5D 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 }.}4}"}&}.}.}.}.
7D 25 7D 26 34 DE 8C CF 7D 27 7D 22 7D 28 7D 22 }%}&4...}'}"}(}"
BC E4 7E ..~
pppInProc[0]: got 99 bytes
pppInput[0]: LCP len=25
fsm_input(LCP):1,0,25
fsm_rconfreq(LCP): Rcvd id 0 state=6 (LS_REQSENT)
lcp_reqci: rcvd ASYNCMAP=0 CHAP C223,5 MAGICNUMBER (14C4E983) PCOMPRESSION
lcp_reqci: ACCOMPRESSION
lcp_reqci: returning CONFACK.
pppWrite[0]: len=54
tx dump (54/54):
7E FF 7D 23 C0 21 7D 22 7D 20 7D 20 7D 39 7D 22 ~.}#.!}"}.}.}9}"
7D 26 7D 20 7D 20 7D 20 7D 20 7D 23 7D 25 C2 23 }&}.}.}.}.}#}%.#
7D 25 7D 25 7D 26 7D 34 C4 E9 83 7D 27 7D 22 7D }%}%}&}4...}'}"}
28 7D 22 75 51 7E (}"uQ~
fsm_sdata(LCP): Sent code 2,0,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 7D 21 7D 20 7D 28 7D 34 ~.}#.!}+}!}.}(}4
C4 E9 83 A5 AA 7E 7E C2 23 01 01 00 23 10 AA 1C .....~~.#...#...
69 BC 88 3D D9 98 1C FA 56 DE 4E B6 3E 20 55 4D i..=....V.N.>.UM
54 53 5F 43 48 41 50 5F 53 52 56 52 74 EA 7E 33 TS_CHAP_SRVRt.~3
0D .
pppInProc[0]: got 65 bytes
pppInput[0]: LCP len=8
fsm_input(LCP):11,1,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 ~...!...).#...#.
AA 1C 69 BC 88 3D D9 98 1C FA 56 DE 4E B6 3E 20 ..i..=....V.N.>.
55 4D 54 53 5F 43 48 41 50 5F 53 52 56 52 95 6C UMTS_CHAP_SRVR.l
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):

сейчас попробую всё учесть, что вы посоветовали

не опасаюсь за загрузку процессора. хорошо представляю как задачи в FreeRTOS работают

с очередями