POWER_CYCLE
IIIIPOWER_CYCLE

RDY

+CFUN: 1

+CPIN: READY

Call Ready
ATE0
ATE0

OK
AT+CSQ

+CSQ: 0,0

OK
AT+CSQ

+CSQ: 13,0

OK
AT+COPS?

+COPS: 0,0,"MTS-RUS"

OK
AT+CGATT=1

OK
AT+IFC=2,2

OK
AT+CGDCONT=1,"IP","internet.mts.ru"

OK
ATD*99***1#

CONNECT
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
sio_read:7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 2E 7D 22 7D 26 7D 20 7D 2A 7D 20 7D 20 7D 23 7D 24 C0 23 F3 4D 7E 7E FF 7D 23 C0 21 7D
24 7D 21 7D 20 7D 2E 7D 25 7D 26 52 7D 38 7D 30 44 7D 27 7D 22 7D 28 7D 22 97 8D 7E
pppInProc[0]: got 70 bytes
tcpip_thread: CALLBACK 0x200032c0
pppInput[0]: LCP len=14
fsm_input(LCP):1,1,14
fsm_rconfreq(LCP): Rcvd id 1 state=6 (LS_REQSENT)
lcp_reqci: ASYNCMAP=A0000 PAP (C023)
lcp_reqci: returning CONFACK.
pppWrite[0]: len=34
fsm_sdata(LCP): Sent code 2,1,14.
pppInput[0]: packet processed
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=14
fsm_input(LCP):4,1,14
fsm_rconfnakrej(LCP): Rcvd id 1 state=8 (LS_ACKSENT)
lcp_rejci: long opt 5 rejected
lcp_rejci: void opt 7 rejected
lcp_rejci: void opt 8 rejected
lcp_addci: L opt=2 0
pppWrite[0]: len=28
fsm_sdata(LCP): Sent code 1,2,10.
LCP: sending Configure-Request, id 2
pppInput[0]: packet processed
sio_read:7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 2E 7D 22 7D 26 7D 20 7D 2A 7D 20 7D 20 7D 23 7D 24 C0 23 F3 4D 7E
pppInProc[0]: got 35 bytes
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=14
sio_read:7E FF 7D 23 C0 21 7D 22 7D 22 7D 20 7D 2A 7D 22 7D 26 7D 20 7D 20 7D 20 7D 20 36 D9 7E
fsm_input(LCP):1,1,14
pppInProc[0]: got 29 bytes
fsm_rconfreq(LCP): Rcvd id 1 state=8 (LS_ACKSENT)
lcp_reqci: ASYNCMAP=A0000 PAP (C023)
lcp_reqci: returning CONFACK.
pppWrite[0]: len=35
fsm_sdata(LCP): Sent code 2,1,14.
pppInput[0]: packet processed
tcpip_thread: CALLBACK 0x200032c0
pppInput[0]: LCP len=10
fsm_input(LCP):2,2,10
fsm_rconfack(LCP): Rcvd id 2 state=8 (LS_ACKSENT)
lcp_acki: Ack
ppp_send_config[0]: outACCM=0 0 A 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)
upap_authwithpeer: 0 user=mts password=mts s=1
pppWrite[0]: len=19
pap_sauth: Sent id 1
pppInput[0]: packet processed
upap_timeout: 0 timeout 6 expired s=3
pppWrite[0]: len=20
pap_sauth: Sent id 2
upap_timeout: 0 timeout 6 expired s=3
pppWrite[0]: len=20
pap_sauth: Sent id 3
upap_timeout: 0 timeout 6 expired s=3
pppWrite[0]: len=20
pap_sauth: Sent id 4
sio_read:7E FF 7D 23 C0 21 7D 25 7D 22 7D 20 7D 3B 41 75 74 68 65 6E 74 69 63 61 74 69 6F 6E 20 66 61 69 6C 65 64 2C 20 FE 9C 7E
pppInProc[0]: got 40 bytes
tcpip_thread: CALLBACK 0x200032c0
pppInput[0]: LCP len=27
fsm_input(LCP):5,2,27
fsm_rtermreq(LCP): Rcvd id 2 state=9 (LS_OPENED)
LCP terminated by peer (0x2000584e)
link_down: 0
upap_lowerdown: 0 s=3
IPCP: lowerdown state 2 (LS_CLOSED) -> 0 (LS_INITIAL)
IPCP: close reason=LCP down state 0 (LS_INITIAL) -> 0 (LS_INITIAL)
pppLinkDown: unit 0
pppRecvWakeup: unit 0
ppp_send_config[0]: outACCM=FF FF FF FF
ppp_recv_config[0]: inACCM=0 0 0 0
sio_read:
pppWrite[0]: len=18
fsm_sdata(LCP): Sent code 6,2,4.
pppInput[0]: packet processed
sio_read:7E FF 7D 23 C0 21 7D 25 7D 23 7D 20 7D 3B 41 75 74 68 65 6E 74 69 63 61 74 69 6F 6E 20 66 61 69 6C 65 64 2C 20 AE 51 7E
pppInProc[0]: got 40 bytes
sio_read:0D 0A 4E 4F 20 43 41 52 52 49 45 52 0D 0A
pppInProc[0]: got 14 bytes
tcpip_thread: CALLBACK 0x200032c0
pppInput[0]: LCP len=27
fsm_input(LCP):5,3,27
fsm_rtermreq(LCP): Rcvd id 3 state=5 (LS_STOPPING)
pppWrite[0]: len=17
fsm_sdata(LCP): Sent code 6,3,4.
pppInput[0]: packet processed
LCP: timeout sending Terminate-Request state=5 (LS_STOPPING)
link_terminated: 0
Connection terminated.
pppLinkTerminated: unit 0
pppRecvWakeup: unit 0
pppLinkTerminated: unit 0: linkStatusCB=0x80018ad errCode=0

//    pppSetAuth(PPPAUTHTYPE_NONE, "mts", "mts");
//    pppSetAuth(PPPAUTHTYPE_PAP, "mts", "mts");
    pppSetAuth(PPPAUTHTYPE_ANY, "mts", "mts");

#ifndef __LWIPOPTS_H__
#define __LWIPOPTS_H__
#include "DebugUART.h"
// ??? !!! #define MEMP_MEM_MALLOC 0
#define MEM_SIZE 16000
#define LWIP_RAW 0
//#define TCP_SND_BUF (12 * TCP_MSS)
//#define TCP_WND (10 * TCP_MSS)

#define TCPIP_THREAD_STACKSIZE (configMINIMAL_STACK_SIZE+1024)
#define TCPIP_THREAD_PRIO (tskIDLE_PRIORITY+2)
#define TCPIP_MBOX_SIZE 5
#define SLIPIF_THREAD_STACKSIZE configMINIMAL_STACK_SIZE
#define SLIPIF_THREAD_PRIO (tskIDLE_PRIORITY+2)/*configMAX_PRIORITIES*/
#define PPP_THREAD_STACKSIZE (configMINIMAL_STACK_SIZE + 1024)
#define PPP_THREAD_PRIO (TCPIP_THREAD_PRIO)
#define DEFAULT_THREAD_STACKSIZE (TCPIP_THREAD_STACKSIZE)
#define DEFAULT_THREAD_PRIO (TCPIP_THREAD_PRIO)
#define DEFAULT_RAW_RECVMBOX_SIZE 10
#define DEFAULT_UDP_RECVMBOX_SIZE 0
#define DEFAULT_TCP_RECVMBOX_SIZE 2000
#define DEFAULT_ACCEPTMBOX_SIZE 2000
#define LWIP_NETCONN 1
#define LWIP_SOCKET 0
#define LWIP_ICMP 1
#define PPP_SUPPORT 1
#define NUM_PPP 1
#define PAP_SUPPORT 1
#define CHAP_SUPPORT 1
#define VJ_SUPPORT 0
#define MD5_SUPPORT 1
#define PPPOE_SUPPORT 0
#define LWIP_ARP 0
#define ARP_TABLE_SIZE 10
#define ARP_QUEUEING 0
#define IP_OPTIONS 1
#define ICMP_TTL 255

#define IP_REASS_MAXAGE 10
#define FSM_DEFTIMEOUT 6
#define LWIP_DHCP_AUTOIP_COOP_TRIES 90

#define LWIP_DEBUG LWIP_DBG_ON

#define ETHARP_DEBUG LWIP_DBG_ON
#define NETIF_DEBUG LWIP_DBG_ON
//#define PBUF_DEBUG LWIP_DBG_ON
#define API_LIB_DEBUG LWIP_DBG_ON
#define API_MSG_DEBUG LWIP_DBG_ON
#define SOCKETS_DEBUG LWIP_DBG_ON
#define ICMP_DEBUG LWIP_DBG_ON
#define IGMP_DEBUG LWIP_DBG_ON
#define INET_DEBUG LWIP_DBG_ON
#define IP_DEBUG LWIP_DBG_ON
#define IP_REASS_DEBUG LWIP_DBG_ON
#define RAW_DEBUG LWIP_DBG_ON
#define MEM_DEBUG LWIP_DBG_ON
#define MEMP_DEBUG LWIP_DBG_ON
#define SYS_DEBUG LWIP_DBG_ON
//#define TIMERS_DEBUG LWIP_DBG_ON
#define TCP_DEBUG LWIP_DBG_ON
#define TCP_INPUT_DEBUG LWIP_DBG_ON
#define TCP_FR_DEBUG LWIP_DBG_ON
#define TCP_RTO_DEBUG LWIP_DBG_ON
#define TCP_CWND_DEBUG LWIP_DBG_ON
#define TCP_WND_DEBUG LWIP_DBG_ON
#define TCP_OUTPUT_DEBUG LWIP_DBG_ON
#define TCP_RST_DEBUG LWIP_DBG_ON
#define TCP_QLEN_DEBUG LWIP_DBG_ON
#define UDP_DEBUG LWIP_DBG_ON
#define TCPIP_DEBUG LWIP_DBG_ON
#define PPP_DEBUG LWIP_DBG_ON
#define SLIP_DEBUG LWIP_DBG_ON
#define DHCP_DEBUG LWIP_DBG_ON
#define AUTOIP_DEBUG LWIP_DBG_ON
#define SNMP_MSG_DEBUG LWIP_DBG_ON
#define SNMP_MIB_DEBUG LWIP_DBG_ON
#define DNS_DEBUG LWIP_DBG_ON
#define LWIP_PLATFORM_DIAG(message) DebugLog message
#endif /* __LWIPOPTS_H__ */

lcp_init: xmit_accm=0 0 0 0
upap_init: 0
POWER_CYCLE

RDY

+CFUN: 1

+CPIN: READY

Call Ready
ATE0
ATE0
ATE0

OK
AT+CSQ

+CSQ: 0,0

OK
AT+CSQ

+CSQ: 13,0

OK
AT+COPS?

+COPS: 0,0,"MTS-RUS"

OK
AT+CGATT=1

OK
AT+IFC=2,2

OK
AT+CGDCONT=1,"IP","internet.mts.ru"

OK
ATD*99***1#

CONNECT
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
sio_read:7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 2E 7D 22 7D 26 7D 20 7D 2A 7D 20 7D 20 7D 23
7D 24 C0 23 F3 4D 7E 7E FF 7D 23 C0 21 7D 24 7D 21 7D 20 7D 2E 7D 25 7D 26 52 7D 38 7D 30 44 7D 27 7D 22 7D 28 7D 22 97 8D 7E
pppInProc[0]: got 70 bytes
tcpip_thread: CALLBACK 0x200032c0
pppInput[0]: LCP len=14
fsm_input(LCP):1,1,14
fsm_rconfreq(LCP): Rcvd id 1 state=6 (LS_REQSENT)
lcp_reqci: ASYNCMAP=A0000 PAP (C023)
lcp_reqci: returning CONFACK.
pppWrite[0]: len=34
fsm_sdata(LCP): Sent code 2,1,14.
pppInput[0]: packet processed
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=14
fsm_input(LCP):4,1,14
fsm_rconfnakrej(LCP): Rcvd id 1 state=8 (LS_ACKSENT)
lcp_rejci: long opt 5 rejected
lcp_rejci: void opt 7 rejected
lcp_rejci: void opt 8 rejected
lcp_addci: L opt=2 0
pppWrite[0]: len=28
fsm_sdata(LCP): Sent code 1,2,10.
LCP: sending Configure-Request, id 2
pppInput[0]: packet processed
sio_read:7E FF 7D 23 C0 21 7D 22 7D 22 7D 20 7D 2A 7D 22 7D 26 7D 20 7D 20 7D 20 7D 20 36 D9 7E 24
C0 23 F3 4D 7E 7E FF 7D 23 C0 21 7D 24 7D 21 7D 20 7D 2E 7D 25 7D 26 52 7D 38 7D 30 44 7D 27 7D 22 7D
pppInProc[0]: got 64 bytes
pppInProc[0]: Dropping bad fcs 0x650e proto=0x24c0
pppDrop: pbuf len=11, addr 0x20005832
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=10
fsm_input(LCP):2,2,10
fsm_rconfack(LCP): Rcvd id 2 state=8 (LS_ACKSENT)
lcp_acki: Ack
ppp_send_config[0]: outACCM=0 0 A 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)
upap_authwithpeer: 0 user=mts password=mts s=1
pppWrite[0]: len=20
pap_sauth: Sent id 1
pppInput[0]: packet processed
sio_read:7E FF 7D 23 C0 21 7D 21 7D 21 7D 20 7D 2E 7D 22 7D 26 7D 20 7D 2A 7D 20 7D 20 7D 23 7D 24 C0 23 F3 4D 7E
pppInProc[0]: got 35 bytes
pppInProc[0]: Dropping bad fcs 0x6de8 proto=0xc021
pppDrop: pbuf len=20, addr 0x20005832
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=14
fsm_input(LCP):1,1,14
fsm_rconfreq(LCP): Rcvd id 1 state=9 (LS_OPENED)
link_down: 0
upap_lowerdown: 0 s=3
IPCP: lowerdown state 2 (LS_CLOSED) -> 0 (LS_INITIAL)
IPCP: close reason=LCP down state 0 (LS_INITIAL) -> 0 (LS_INITIAL)
pppLinkDown: unit 0
pppRecvWakeup: unit 0
ppp_send_config[0]: outACCM=FF FF FF FF
sio_read:
ppp_recv_config[0]: inACCM=0 0 0 0
auth_reset: 0
lcp_addci: L opt=2 0
lcp_addci: L opt=5 F06AFFF
lcp_addci: opt=7
lcp_addci: opt=8
pppWrite[0]: len=47
fsm_sdata(LCP): Sent code 1,3,20.
LCP: sending Configure-Request, id 3
lcp_reqci: ASYNCMAP=A0000 PAP (C023)
lcp_reqci: returning CONFACK.
pppWrite[0]: len=34
fsm_sdata(LCP): Sent code 2,1,14.
pppInput[0]: packet processed
sio_read:7E FF 7D 23 C0 21 7D 24 7D 23 7D 20 7D 2E 7D 25 7D 26 7D 2F 7D 26 AF FF 7D 27 7D 22 7D 28 7D 22 E2 D7 7E
pppInProc[0]: got 35 bytes
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=14
fsm_input(LCP):4,3,14
fsm_rconfnakrej(LCP): Rcvd id 3 state=8 (LS_ACKSENT)
lcp_rejci: long opt 5 rejected
lcp_rejci: void opt 7 rejected
lcp_rejci: void opt 8 rejected
lcp_addci: L opt=2 0
pppWrite[0]: len=29
fsm_sdata(LCP): Sent code 1,4,10.
LCP: sending Configure-Request, id 4
pppInput[0]: packet processed
sio_read:7E FF 7D 23 C0 21 7D 22 7D 24 7D 20 7D 2A 7D 22 7D 26 7D 20 7D 20 7D 20 7D 20 29 7D 5D 7E
pppInProc[0]: got 30 bytes
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: LCP len=10
fsm_input(LCP):2,4,10
fsm_rconfack(LCP): Rcvd id 4 state=8 (LS_ACKSENT)
lcp_acki: Ack
ppp_send_config[0]: outACCM=0 0 A 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)
upap_authwithpeer: 0 user=mts password=mts s=1
pppWrite[0]: len=19
pap_sauth: Sent id 2
pppInput[0]: packet processed
sio_read:7E FF 03 C0 23 02 02 00 0D 08 4C 6F 67 69 6E 20 4F 4B 89 5B 7E
pppInProc[0]: got 21 bytes
tcpip_thread: CALLBACK 0x200032ac
pppInput[0]: PAP len=13
pap_rauthack: Rcvd id 2 s=3
Remote message: Login OK
auth_withpeer_success: 0 proto=C023
pppWrite[0]: len=29
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
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30
fsm_sdata(IPCP): Sent code 1,1,22.
IPCP: sending Configure-Request, id 1
IPCP: timeout resending Config-Request state=6 (LS_REQSENT)
pppWrite[0]: len=30

u32_t sio_read(sio_fd_t fd, u8_t *data, u32_t len){
    tReceivedMessage_st rec_mess;
    TickType_t delay=portMAX_DELAY;
    u32_t cnt=len,length;
    for(;cnt;){
        length=MRecFIFO_get(data,cnt);
        if(length){
            cnt-=length;
            delay=20;//MAXREC_TOUT_MS;
            if(!cnt)break;
        }
        else if(delay==20/*MAXREC_TOUT_MS*/)break;
        if(xQueueReceive(link_bundle_st->modem_queue,&rec_mess,delay)==pdTRUE){
            switch(rec_mess.mode){
            case RxMSG_ABORT:
#if LWIP_DEBUG==LWIP_DBG_ON
                print_sio_read(data,len-cnt);
#endif
                return len-cnt;
                break;
            }
        }
    }
#if LWIP_DEBUG==LWIP_DBG_ON
    print_sio_read(data,len-cnt);
#endif
    return len-cnt;
}