[FUGSPBR] Problemas com LCP Requests no PPP

:: Patrick Tracanelli :: eeviac em fatectq.com.br
Seg Jul 23 18:50:57 BRT 2001


Ola Pessoas;
Bom Dia!

Há 4 dias vem acontecendo um problema muito estranho com meu PPP. Esse 
mesmo problema ja acontecia algumas vezes quando eu usava FreeBSD 
4.1-STABLE. Recentemente eu tava com um -CURRENT de alguns meses atraz, mas 
fiquei muito puto quando esse problema voltou a ocorrer que eu resolvi 
instalar o ultimo snapshot do FreeBSD, portanto meu FreeBSD hj é 
5.0-20010618-CURRENT.

Quando ainda era 4.1 o Briam Somers tentou me ajudar, disse pra eu por 'set 
openmode active 10' pra esperar pra iniciar a negociacao... coloquei ate 30 
segundos e nunca resolveu...

Acontece o seguinte, eu disco normalmente pro meu provedor, ele atende, faz 
todo o 'handshake' e fica em silencio... ai rola o que ta no log ai em 
baixo... mas o console do ppp nao fica nem Ppp ou seja, os 3 'P' se mantem 
minusculos... de acordo com a man page isso quer dizer que a negociacao nao 
foi iniciada...
Analizando os logs percebe-se que o ppp fica enviando requisicoes LCP ao 
atendedor, na outra ponta (que nesse caso eh um USR Total Control) e entao 
ele desiste e 'hanga' a transação.

Pra tentar descobrir de forma heuristica o que acontece, eu ja tentei com 
meu modem interno (USR 56k) e pra outro provedor (da facul, onde o 
atendedor eh PathRas -cyclades-) normalmente meu modem eh um USR Sportster 
externo...
Em todos os casos o problema sempre foi o mesmo :( igualzinho... algumas 
vezes funcionava sem ninguem mudar nada, outras nao... mas agora parece que 
resolveu nao funcionar de vez...

Pra ter certeza que a questao nao eh com o PPP especificamente, o Genoc me 
mando um script pra conectar usando o pppd diretamente... o pppd funcionou 
igual ao ppp, e parou no mesmo momento com o mesmo problema: LCP

Bom, nao sei mais que informacao eu posso dar pra ajudar voces me 
ajudarem... qq q achar interessante saber deem o toque.

Segue abaixo o LOG de como a transacao para sem se completar:

---------- LOG PPP -----------------
Jul 23 02:31:32  ppp[305]: Phase: Using interface: tun0
Jul 23 02:31:32  ppp[305]: Phase: deflink: Created in closed state
Jul 23 02:31:32  ppp[305]: tun0: Command: default: set openmode active 10
Jul 23 02:31:32  ppp[305]: tun0: Command: default: set speed 115200
Jul 23 02:31:32  ppp[305]: tun0: Command: default: set dial ABORT BUSY 
ABORT NO\sCARRIER TIMEOUT 15 "" AT OK-AT-OK ATE1Q0 OK \dATDT\T TIMEOUT 180 
CONNECT
Jul 23 02:31:32  ppp[305]: tun0: Command: default: set ifaddr 10.0.0.1/0 
10.0.0.2/0 255.255.255.0 0.0.0.0
Jul 23 02:31:32  ppp[305]: tun0: Command: default: add default HISADDR
Jul 23 02:31:32  ppp[305]: tun0: Command: default: enable dns
Jul 23 02:31:32  ppp[305]: tun0: Phase: PPP Started (interactive mode).
Jul 23 02:31:36  ppp[305]: tun0: Command: /dev/ttyv0: dial mdbrasil
Jul 23 02:31:36  ppp[305]: tun0: Command: mdbrasil: set phone 33445000
Jul 23 02:31:36  ppp[305]: tun0: Command: mdbrasil: set authname artstudio
Jul 23 02:31:36  ppp[305]: tun0: Command: mdbrasil: set authkey ********
Jul 23 02:31:36  ppp[305]: tun0: Phase: bundle: Establish
Jul 23 02:31:36  ppp[305]: tun0: Phase: deflink: closed -> opening
Jul 23 02:31:36  ppp[305]: tun0: Phase: deflink: Connected!
Jul 23 02:31:36  ppp[305]: tun0: Phase: deflink: opening -> dial
Jul 23 02:31:36  ppp[305]: tun0: Chat: Phone: 33445000
Jul 23 02:31:36  ppp[305]: tun0: Chat: deflink: Dial attempt 1 of 1
Jul 23 02:31:36  ppp[305]: tun0: Chat: Send: AT
Jul 23 02:31:36  ppp[305]: tun0: Chat: Expect(15): OK
Jul 23 02:31:36  ppp[305]: tun0: Chat: Received: AT
Jul 23 02:31:36  ppp[305]: tun0: Chat: Received: OK
Jul 23 02:31:36  ppp[305]: tun0: Chat: Send: ATE1Q0
Jul 23 02:31:36  ppp[305]: tun0: Chat: Expect(15): OK
Jul 23 02:31:36  ppp[305]: tun0: Chat: Received: ATE1Q0
Jul 23 02:31:36  ppp[305]: tun0: Chat: Received: OK
Jul 23 02:31:36  ppp[305]: tun0: Chat: Send: ATDT33445000
Jul 23 02:31:38  ppp[305]: tun0: Chat: Expect(180): CONNECT
Jul 23 02:32:11  ppp[305]: tun0: Chat: Received: ATDT33445000
Jul 23 02:32:11  ppp[305]: tun0: Chat: Received: CONNECT 45333/ARQ
Jul 23 02:32:11  ppp[305]: tun0: Phase: deflink: dial -> carrier
Jul 23 02:32:12  ppp[305]: tun0: Phase: deflink: /dev/cuaa1: CD detected
Jul 23 02:32:12  ppp[305]: tun0: Phase: deflink: carrier -> login
Jul 23 02:32:12  ppp[305]: tun0: Phase: deflink: login -> lcp
Jul 23 02:32:12  ppp[305]: tun0: LCP: FSM: Using "deflink" as a transport
Jul 23 02:32:12  ppp[305]: tun0: LCP: deflink: State change Initial --> Closed
Jul 23 02:32:12  ppp[305]: tun0: Phase: deflink: Entering STOPPED state for 
10 seconds
Jul 23 02:32:12  ppp[305]: tun0: LCP: deflink: State change Closed --> Stopped
Jul 23 02:32:22  ppp[305]: tun0: LCP: deflink: LayerStart
Jul 23 02:32:22  ppp[305]: tun0: LCP: deflink: SendConfigReq(1) state = 
Stopped
Jul 23 02:32:22  ppp[305]: tun0: LCP:  ACFCOMP[2]
Jul 23 02:32:22  ppp[305]: tun0: LCP:  PROTOCOMP[2]
Jul 23 02:32:22  ppp[305]: tun0: LCP:  ACCMAP[6] 0x00000000
Jul 23 02:32:22  ppp[305]: tun0: LCP:  MRU[4] 1500
Jul 23 02:32:22  ppp[305]: tun0: LCP:  MAGICNUM[6] 0x3a98820e
Jul 23 02:32:22  ppp[305]: tun0: LCP: deflink: State change Stopped --> 
Req-Sent
Jul 23 02:32:25  ppp[305]: tun0: LCP: deflink: SendConfigReq(1) state = 
Req-Sent
Jul 23 02:32:25  ppp[305]: tun0: LCP:  ACFCOMP[2]
Jul 23 02:32:25  ppp[305]: tun0: LCP:  PROTOCOMP[2]
Jul 23 02:32:25  ppp[305]: tun0: LCP:  ACCMAP[6] 0x00000000
Jul 23 02:32:25  ppp[305]: tun0: LCP:  MRU[4] 1500
Jul 23 02:32:25  ppp[305]: tun0: LCP:  MAGICNUM[6] 0x3a98820e
Jul 23 02:32:28  ppp[305]: tun0: LCP: deflink: SendConfigReq(1) state = 
Req-Sent
Jul 23 02:32:28  ppp[305]: tun0: LCP:  ACFCOMP[2]
Jul 23 02:32:28  ppp[305]: tun0: LCP:  PROTOCOMP[2]
Jul 23 02:32:28  ppp[305]: tun0: LCP:  ACCMAP[6] 0x00000000
Jul 23 02:32:28  ppp[305]: tun0: LCP:  MRU[4] 1500
Jul 23 02:32:28  ppp[305]: tun0: LCP:  MAGICNUM[6] 0x3a98820e
Jul 23 02:32:31  ppp[305]: tun0: LCP: deflink: SendConfigReq(1) state = 
Req-Sent
Jul 23 02:32:31  ppp[305]: tun0: LCP:  ACFCOMP[2]
Jul 23 02:32:31  ppp[305]: tun0: LCP:  PROTOCOMP[2]
Jul 23 02:32:31  ppp[305]: tun0: LCP:  ACCMAP[6] 0x00000000
Jul 23 02:32:31  ppp[305]: tun0: LCP:  MRU[4] 1500
Jul 23 02:32:31  ppp[305]: tun0: LCP:  MAGICNUM[6] 0x3a98820e
Jul 23 02:32:34  ppp[305]: tun0: LCP: deflink: SendConfigReq(1) state = 
Req-Sent
Jul 23 02:32:34  ppp[305]: tun0: LCP:  ACFCOMP[2]
Jul 23 02:32:34  ppp[305]: tun0: LCP:  PROTOCOMP[2]
Jul 23 02:32:34  ppp[305]: tun0: LCP:  ACCMAP[6] 0x00000000
Jul 23 02:32:34  ppp[305]: tun0: LCP:  MRU[4] 1500
Jul 23 02:32:34  ppp[305]: tun0: LCP:  MAGICNUM[6] 0x3a98820e
Jul 23 02:32:37  ppp[305]: tun0: LCP: deflink: LayerFinish
Jul 23 02:32:37  ppp[305]: tun0: LCP: deflink: State change Req-Sent --> 
Stopped
Jul 23 02:32:37  ppp[305]: tun0: LCP: deflink: State change Stopped --> Closed
Jul 23 02:32:37  ppp[305]: tun0: LCP: deflink: State change Closed --> Initial
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: Disconnected!
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: lcp -> logout
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: logout -> hangup
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: Disconnected!
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: Connect time: 61 secs: 308 
octets in, 270 octets out
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: : 9 packets in, 5 packets out
Jul 23 02:32:37  ppp[305]: tun0: Phase:  total 9 bytes/sec, peak 54 
bytes/sec on Mon Jul 23 02:32:37 2001
Jul 23 02:32:37  ppp[305]: tun0: Phase: deflink: hangup -> closed
Jul 23 02:32:37  ppp[305]: tun0: Phase: bundle: Dead



Segue agora o LOG do script de pppd+chat, sem o ppp
----------------LOG PPPD-----------------------------

Jul 23 02:32:51  pppd[307]: pppd 2.3.5 started by root, uid 0
Jul 23 02:33:29  pppd[307]: Connect: ppp0 <--> /dev/cuaa1
Jul 23 02:33:29  pppd[307]: Warning - secret file /etc/ppp/pap-secrets has 
world and/or group access
Jul 23 02:34:00  pppd[307]: LCP: timeout sending Config-Requests
Jul 23 02:34:00  pppd[307]: Connection terminated, connected for 1 minutes

--------------Meu ppp.conf usual----------------

default:
  set device /dev/cuaa1

  set log Phase Chat LCP IPCP CCP tun command
  set openmode active 10
  set speed 115200
  set dial "ABORT BUSY ABORT NO\\sCARRIER TIMEOUT 15 \"\" AT OK-AT-OK 
ATE1Q0 OK \\dATDT\\T TIMEOUT 180 CONNECT"

# set timeout 0
# set ifaddr 255.255.255.0 0.0.0.0
  set ifaddr 10.0.0.1/0 10.0.0.2/0 255.255.255.0 0.0.0.0
  add default HISADDR
  enable dns
# disable pred1 deflate dflate24 protocomp acfcomp shortseg vj
# deny pred1 deflate deflate24 protocomp acfcomp shortseg vj
# papchap:

  #
  # edit the next three lines and replace the items in caps with
  # the values which have been assigned by your ISP.
  #
facul:
  set phone 01632527005
  set authname eksffa
  set authkey xsxsxsxxsxsx

mdbrasil:
  set phone 33445000
  set authname eksffa
  set authkey sxssxsxsx




----------Meu ppp.conf de outras tentativas-------------------
default:
  set device /dev/cuaa1
  set speed 115200
  set dial "ABORT BUSY ABORT NO\\sCARRIER TIMEOUT 5 \"\" AT \
            OK-AT-OK ATE1Q0 OK \\dATDT\\T TIMEOUT 50 CONNECT"
mdbr:
  set phone "33445000"
  set reconnect 3 20
  set redial 2 20
  set timeout 260
  set login
  set authname eksffa
  set authkey sxsxsxsxsx
  set ifaddr 10.0.1.2/0 10.0.1.1/0 255.255.255.0 0.0.0.0
  add default HISADDR
  enable dns



Espero que algum ser iluminado dessa lista possa ter boas ideias do que 
esteja acontecendo :(

Paz Profunda;
[]'z Patrick

----
Para sair da lista envie um e-mail para majordomo em fugspbr.org
com as palavras "unsubscribe fugspbr" no corpo da mensagem.



Mais detalhes sobre a lista de discussão freebsd