Дозвон на сервер + callback. Нужна помощь.

[gray_wings]

Ситуация: строю диал-ап на свою рабочую тачку (FreeBSD 6.3). Входящая линия одна. Перечитав кучу всяццких советов по этому поводу (в том числе и на lissyara.su), дозвон сделал. А вот callback никак не получается. Сервер перезванивает на клиента (винда), тот снимает трубу и тут же идет сброс...
вот, сопссно, лог:

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

Mar  4 16:21:40 info2 ppp[2174]: Phase: Using interface: tun0
Mar  4 16:21:40 info2 ppp[2174]: Phase: deflink: Created in closed state
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: enable pap passwdauth
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: enable proxy
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set ifaddr 192.168.1.3 192.168.1.241-192.168.1.244
Mar  4 16:21:40 info2 ppp[2174]: tun0: IPCP: Selected IP address 192.168.1.241
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: accept dns
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set callback cbcp
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set cbcp
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set log +cbcp
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set redial 5 1
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set device /dev/cuad0
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set speed 57600
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set dial TIMEOUT 10 "" AT OK-AT-OK ATDT\T CONNECT
Mar  4 16:21:40 info2 ppp[2174]: tun0: Command: callback: set timeout 900
Mar  4 16:21:40 info2 ppp[2174]: tun0: Phase: PPP Started (direct mode).
Mar  4 16:21:40 info2 ppp[2174]: tun0: Phase: bundle: Establish
Mar  4 16:21:40 info2 ppp[2174]: tun0: Phase: deflink: closed -> opening
Mar  4 16:21:40 info2 ppp[2174]: tun0: Phase: deflink: Connected!
Mar  4 16:21:40 info2 ppp[2174]: tun0: Phase: deflink: opening -> carrier
Mar  4 16:21:41 info2 ppp[2174]: tun0: Phase: deflink: /dev/cuad0: CD detected
Mar  4 16:21:41 info2 ppp[2174]: tun0: Phase: deflink: carrier -> lcp
Mar  4 16:21:41 info2 ppp[2174]: tun0: LCP: FSM: Using "deflink" as a transport
Mar  4 16:21:41 info2 ppp[2174]: tun0: LCP: deflink: State change Initial --> Closed
Mar  4 16:21:41 info2 ppp[2174]: tun0: LCP: deflink: State change Closed --> Stopped
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP: deflink: LayerStart
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP:  ACFCOMP[2]
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP:  PROTOCOMP[2]
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP:  ACCMAP[6] 0x00000000
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP:  MRU[4] 1500
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP:  MAGICNUM[6] 0x6f34e573
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Mar  4 16:21:42 info2 ppp[2174]: tun0: LCP: deflink: State change Stopped --> Req-Sent
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP: deflink: RecvConfigReq(3) state = Req-Sent
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  ACCMAP[6] 0x000a0000
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  MAGICNUM[6] 0x01a6622e
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  PROTOCOMP[2]
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  ACFCOMP[2]
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  CALLBACK[3] CBCP
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP: deflink: SendConfigAck(3) state = Req-Sent
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  ACCMAP[6] 0x000a0000
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  MAGICNUM[6] 0x01a6622e
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  PROTOCOMP[2]
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  ACFCOMP[2]
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP:  CALLBACK[3] CBCP
Mar  4 16:21:43 info2 ppp[2174]: tun0: LCP: deflink: State change Req-Sent --> Ack-Sent
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP: deflink: SendConfigReq(1) state = Ack-Sent
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  ACFCOMP[2]
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  PROTOCOMP[2]
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  ACCMAP[6] 0x00000000
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  MRU[4] 1500
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  MAGICNUM[6] 0x6f34e573
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP: deflink: RecvConfigAck(1) state = Ack-Sent
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  ACFCOMP[2]
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  PROTOCOMP[2]
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  ACCMAP[6] 0x00000000
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  MRU[4] 1500
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  MAGICNUM[6] 0x6f34e573
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP: deflink: State change Ack-Sent --> Opened
Mar  4 16:21:45 info2 ppp[2174]: tun0: LCP: deflink: LayerUp
Mar  4 16:21:45 info2 ppp[2174]: tun0: Phase: bundle: Authenticate
Mar  4 16:21:45 info2 ppp[2174]: tun0: Phase: deflink: his = none, mine = PAP
Mar  4 16:21:45 info2 ppp[2174]: tun0: Phase: Pap Input: REQUEST (hata1)
Mar  4 16:21:45 info2 ppp[2174]: tun0: Phase: Pap Output: SUCCESS
Mar  4 16:21:45 info2 ppp[2174]: tun0: Phase: deflink: lcp -> cbcp
Mar  4 16:21:45 info2 ppp[2174]: tun0: CBCP: deflink: SendReq(0) state = closed
Mar  4 16:21:45 info2 ppp[2174]: tun0: CBCP:  TYPE Server-spec
Mar  4 16:21:45 info2 ppp[2174]: tun0: CBCP:  DELAY 0
Mar  4 16:21:45 info2 ppp[2174]: tun0: CBCP: deflink: State change closed --> req-sent
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP: deflink: RecvResponse(0) state = req-sent
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP:  TYPE Server-spec
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP:  DELAY 15
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP: deflink: SendAck(0) state = req-sent
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP:  TYPE Server-spec
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP:  DELAY 15
Mar  4 16:21:49 info2 ppp[2174]: tun0: CBCP: deflink: State change req-sent --> ack-sent
Mar  4 16:21:49 info2 ppp[2174]: tun0: LCP: deflink: RecvTerminateReq(4) state = Opened
Mar  4 16:21:49 info2 ppp[2174]: tun0: LCP: deflink: LayerDown
Mar  4 16:21:49 info2 ppp[2174]: tun0: Phase: deflink: CBCP: Will dial back on 7571848
Mar  4 16:21:49 info2 ppp[2174]: tun0: LCP: deflink: SendTerminateAck(4) state = Opened
Mar  4 16:21:49 info2 ppp[2174]: tun0: LCP: deflink: State change Opened --> Stopping
Mar  4 16:21:49 info2 ppp[2174]: tun0: Phase: deflink: cbcp -> lcp
Mar  4 16:21:50 info2 ppp[2174]: tun0: Phase: deflink: Carrier lost
Mar  4 16:21:50 info2 ppp[2174]: tun0: LCP: deflink: State change Stopping --> Starting
Mar  4 16:21:50 info2 ppp[2174]: tun0: LCP: deflink: LayerFinish
Mar  4 16:21:50 info2 ppp[2174]: tun0: LCP: deflink: State change Starting --> Initial
Mar  4 16:21:50 info2 ppp[2174]: tun0: Phase: deflink: Disconnected!
Mar  4 16:21:50 info2 ppp[2174]: tun0: Phase: deflink: Connect time: 10 secs: 225 octets in, 233 octets out
Mar  4 16:21:50 info2 ppp[2174]: tun0: Phase: deflink: 11 packets in, 7 packets out
Mar  4 16:21:50 info2 ppp[2174]: tun0: Phase:  total 45 bytes/sec, peak 76 bytes/sec on Tue Mar  4 16:21:46 2008
Mar  4 16:21:50 info2 ppp[2195]: tun0: Phase: Call peer back on 7571848
Mar  4 16:21:50 info2 ppp[2195]: tun0: CBCP: deflink: State change ack-sent --> closed
Mar  4 16:21:50 info2 ppp[2195]: tun0: Phase: deflink: lcp -> opening
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: deflink: Redial timer expired.
Mar  4 16:22:05 info2 ppp[2195]: tun0: Phase: deflink: Connected!
Mar  4 16:22:05 info2 ppp[2195]: tun0: Phase: deflink: opening -> dial
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Phone: 7571848
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: deflink: Dial attempt 1 of 1
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Send: AT^M
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Expect(10): OK
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Received: AT^M^M
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Received: OK^M
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Send: ATDT7571848^M
Mar  4 16:22:05 info2 ppp[2195]: tun0: Chat: Expect(10): CONNECT
Mar  4 16:22:15 info2 ppp[2195]: tun0: Chat: Expect timeout
Mar  4 16:22:15 info2 ppp[2195]: tun0: Warning: Chat script failed
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: deflink: dial -> hangup
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: deflink: Disconnected!
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: deflink: Connect time: 10 secs: 0 octets in, 0 octets out
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: deflink: 11 packets in, 7 packets out
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase:  total 0 bytes/sec, peak 0 bytes/sec on Tue Mar  4 16:22:05 2008
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: deflink: hangup -> closed
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: bundle: Dead
Mar  4 16:22:15 info2 ppp[2195]: tun0: Phase: PPP Terminated (normal).

в чем тут может быть заморочка?
заранее благодарен за ответы!)))

[Хостинг HostFood.ru]

Тарифы на хостинг в России, от 12 рублей: https://www.host-food.ru/tariffs/hosting/
Тарифы на виртуальные сервера (VPS/VDS/KVM) в РФ, от 189 руб.: https://www.host-food.ru/tariffs/virtualny-server-vps/
Выделенные сервера, Россия, Москва, от 2000 рублей (HP Proliant G5, Intel Xeon E5430 (2.66GHz, Quad-Core, 12Mb), 8Gb RAM, 2x300Gb SAS HDD, P400i, 512Mb, BBU):
https://www.host-food.ru/tariffs/vydelennyi-server-ds/
Недорогие домены в популярных зонах: https://www.host-food.ru/domains/

[_kirill_]

Mar 4 16:22:05 info2 ppp[2195]: tun0: Chat: Expect(10): CONNECT
Mar 4 16:22:15 info2 ppp[2195]: tun0: Chat: Expect timeout
Mar 4 16:22:15 info2 ppp[2195]: tun0: Warning: Chat script failed

я думаю сдесь ))))

[gray_wings]

))))))))) я тоже думаю что здесь. но как это поправить? )))

[_kirill_]

cat /etc/ppp/* в студию

[gray_wings]

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

/etc/ppp/ppp.conf
default:
 set log Phase Chat LCP IPCP CCP tun command

callback:
 enable pap passwdauth
 enable proxy
 set ifaddr 192.168.1.3 192.168.1.241-192.168.1.244
 accept dns
 set callback cbcp
 set cbcp
 set log +cbcp
 set redial 5 1
 set device /dev/cuad0
 set speed 57600
###дальше я заморачивался с разными скриптами
 set dial "TIMEOUT 10 \"\" AT OK-AT-OK ATDT\\T CONNECT"
 #set dial "ABORT BUSY ABORT NO\\sCARRIER TIMEOUT 2 \"\" ATE1Q0M0 OK-AT-OK\\dATDT\\T TIMEOUT 40 CONNECT"
 #set dial "TIMEOUT 10 "" AT OK-AT-OK ATDT\T TIMEOUT 10 CONNECT"
 set timeout 900 

/etc/ppp/ppp.secret

# Authname Authkey      Peer's IP address        Label   Callback
user1       passw	 192.168.1.251		 *	1234567
user	    passw2	 192.168.1.252		*	*

[_kirill_]

а мопед какой?

[gray_wings]

момед GVC 33600 SF-1133 V/R16

со строкой на клиенте AT S0=1

[gray_wings]

грабли найдены и обезврежены
а стояли они здесь:

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

/etc/ppp/ppp.conf
set dial "TIMEOUT 10 \"\" AT OK-AT-OK ATDT\\T CONNECT"

при таком раскладе не успевал обрабатываться скрипт и связь рвалась.
правим скриптик и получаем:

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

/etc/ppp/ppp.conf
set dial "TIMEOUT 10 \"\" AT OK-AT-OK ATDT\\T TIMEOUT 60 CONNECT"

[OT]и жили они долго и счастливо пока не расконнектил их провайдер[/OT]

думаю, можно закрывать тему...)))

[dendroid]

Вот у меня такая же ситуация сложилась, и твой рецепт не помог.
- Win2000-клиент дозванивается до FreeBSD - связь нормально проходит, потом авторизация
- сервер перезванивает на Win2000-клиента
- далее модем пишит и отваливается по таймауту 60 сек

Вот мой ppp.conf^

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

default:
 set log Phase Chat LCP IPCP CCP tun command

callback:
 enable pap passwdauth
 enable pap
 enable proxy
 set ifaddr 192.168.100.1 192.168.100.30-192.168.100.40
 accept dns
 set callback cbcp
 set cbcp
 set log +cbcp
 set redial 5 1
 set device /dev/ttyd0
 set speed 19200
 set dial "TIMEOUT 10 \"\" AT OK-AT-OK ATDT\\T TIMEOUT 60 CONNECT"
 set timeout 900

Может на Win2000 клиенте нужно какие-нибудь там скрипты входа писать, или ничего не нужно ?
Требуется ли настройка Win2000 клиента ?

[gray_wings]

а без коллбэка нормально дозванивается?
и что в логе? почему отбивает?

[dendroid]

Дозвон Win2000 клиента на FREEBSD сервер проходит нормально.
Вот лог входящего звонка от mgetty:

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

05/29 12:20:54 yd0  mgetty: interim release 1.1.34-Nov30
05/29 12:20:54 yd0  check for lockfiles
05/29 12:20:54 yd0  locking the line
05/29 12:20:55 yd0  lowering DTR to reset Modem
05/29 12:20:55 yd0  send: ATS0=0Q0&D3&C1[0d]
05/29 12:20:55 yd0  waiting for ``OK'' ** found **
05/29 12:20:55 yd0  mdm_send: 'ATI'
05/29 12:20:56 yd0  non-numeric ID string: '5608A'
05/29 12:20:56 yd0  mdm_send: 'AT+FCLASS=2.0' -> OK
05/29 12:20:56 yd0  mdm_send: 'AT+FAA=1;+FCR=1' -> OK
05/29 12:20:56 yd0  mdm_send: 'AT+FBO=1' -> OK
05/29 12:20:56 yd0  mdm_send: 'AT+FNR=1,1,1,0' -> OK
05/29 12:20:56 yd0  mdm_send: 'AT+FLI="00 00 000000"' -> OK
05/29 12:20:56 yd0  mdm_send: 'AT+FCC=1,5,0,2,0,0,0,0' -> OK
05/29 12:20:56 yd0  waiting...
05/29 12:21:24 yd0  wfr: waiting for ``RING''
05/29 12:21:25 yd0  send: ATA[0d]
05/29 12:21:25 yd0  waiting for ``CONNECT'' ** found **
05/29 12:21:38 yd0  send:
05/29 12:21:38 yd0  waiting for ``_'' ** found **
05/29 12:21:40 ##### data dev=ttyd0, pid=1143, caller='none', conn='33600/ARQ/V34/LAPM/V42BIS', name='', cmd='/etc/ppp/ppplogin.sh', user='/AutoPPP/'

Далее mgetty вызывает ppplogin.sh

Содержимое ppplogin.sh:
#!/bin/sh
exec /usr/sbin/ppp -direct callback

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

Содержимое ppp.conf:
default:
 set log Phase Chat LCP IPCP CCP tun command

callback:
 enable pap passwdauth
 enable pap
 enable proxy
 set ifaddr 192.168.100.1 192.168.100.30-192.168.100.40
 accept dns
 set callback cbcp
 set cbcp
 set log +cbcp
 set redial 5 1
 set device /dev/ttyd0
 set speed 9600
 set dial "TIMEOUT 10 \"\" AT OK-AT-OK ATDP\\T TIMEOUT 120 CONNECT"
 set timeout 900

Вот содержимое ppp.log, после того, как mgetty обработала входящий звонок и передала управление ppp:

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

May 29 14:26:47 nsk ppp[2314]: Phase: Using interface: tun0
May 29 14:26:47 nsk ppp[2314]: Phase: deflink: Created in closed state
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: enable pap passwdauth
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: enable pap
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: enable proxy
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set ifaddr 192.168.100.1 192.168.100.30-192.168.100.40
May 29 14:26:47 nsk ppp[2314]: tun0: IPCP: Selected IP address 192.168.100.40
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: accept dns
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set callback cbcp
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set cbcp
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set log +cbcp
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set redial 5 1
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set device /dev/ttyd0
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set speed 9600
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set dial TIMEOUT 10 "" AT OK-AT-OK ATDP\T TIMEOUT 120 CONNECT
May 29 14:26:47 nsk ppp[2314]: tun0: Command: callback: set timeout 900
May 29 14:26:47 nsk ppp[2314]: tun0: Phase: PPP Started (direct mode).
May 29 14:26:47 nsk ppp[2314]: tun0: Phase: bundle: Establish
May 29 14:26:47 nsk ppp[2314]: tun0: Phase: deflink: closed -> opening
May 29 14:26:47 nsk ppp[2314]: tun0: Phase: deflink: Connected!
May 29 14:26:47 nsk ppp[2314]: tun0: Phase: deflink: opening -> carrier
May 29 14:26:48 nsk ppp[2314]: tun0: Phase: deflink: /dev/ttyd0: CD detected
May 29 14:26:48 nsk ppp[2314]: tun0: Phase: deflink: carrier -> lcp
May 29 14:26:48 nsk ppp[2314]: tun0: LCP: FSM: Using "deflink" as a transport
May 29 14:26:48 nsk ppp[2314]: tun0: LCP: deflink: State change Initial --> Closed
May 29 14:26:48 nsk ppp[2314]: tun0: LCP: deflink: State change Closed --> Stopped
May 29 14:26:49 nsk ppp[2314]: tun0: LCP: deflink: LayerStart
May 29 14:26:49 nsk ppp[2314]: tun0: LCP: deflink: SendConfigReq(1) state = Stopped
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  ACFCOMP[2]
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  PROTOCOMP[2]
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  ACCMAP[6] 0x00000000
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  MRU[4] 1500
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  MAGICNUM[6] 0x8b283117
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
May 29 14:26:49 nsk ppp[2314]: tun0: LCP: deflink: State change Stopped --> Req-Sent
May 29 14:26:49 nsk ppp[2314]: tun0: LCP: deflink: RecvConfigAck(1) state = Req-Sent
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  ACFCOMP[2]
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  PROTOCOMP[2]
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  ACCMAP[6] 0x00000000
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  MRU[4] 1500
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  MAGICNUM[6] 0x8b283117
May 29 14:26:49 nsk ppp[2314]: tun0: LCP:  AUTHPROTO[4] 0xc023 (PAP)
May 29 14:26:49 nsk ppp[2314]: tun0: LCP: deflink: State change Req-Sent --> Ack-Rcvd
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: RecvConfigReq(2) state = Ack-Rcvd
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ACCMAP[6] 0x00000000
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  MAGICNUM[6] 0x31e524c1
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  PROTOCOMP[2]
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ACFCOMP[2]
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  CALLBACK[3] CBCP
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  MRRU[4] 1614
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ENDDISC[23] Local Addr: Kp?№$вIbзё?s%т@?
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: SendConfigRej(2) state = Ack-Rcvd
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  MRRU[4] 1614
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: RecvConfigReq(3) state = Ack-Rcvd
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ACCMAP[6] 0x00000000
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  MAGICNUM[6] 0x31e524c1
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  PROTOCOMP[2]
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ACFCOMP[2]
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  CALLBACK[3] CBCP
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ENDDISC[23] Local Addr: Kp?№$вIbзё?s%т@?
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: SendConfigAck(3) state = Ack-Rcvd
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ACCMAP[6] 0x00000000
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  MAGICNUM[6] 0x31e524c1
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  PROTOCOMP[2]
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ACFCOMP[2]
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  CALLBACK[3] CBCP
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  ENDDISC[23] Local Addr: Kp?№$вIbзё?s%т@?
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: State change Ack-Rcvd --> Opened
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: LayerUp
May 29 14:26:50 nsk ppp[2314]: tun0: Phase: bundle: Authenticate
May 29 14:26:50 nsk ppp[2314]: tun0: Phase: deflink: his = none, mine = PAP
May 29 14:26:50 nsk ppp[2314]: tun0: LCP: deflink: RecvIdent(4) state = Opened
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  MAGICNUM 31e524c1
May 29 14:26:50 nsk ppp[2314]: tun0: LCP:  TEXT MSRA
May 29 14:26:51 nsk ppp[2314]: tun0: LCP: deflink: RecvIdent(5) state = Opened
May 29 14:26:51 nsk ppp[2314]: tun0: LCP:  MAGICNUM 31e524c1
May 29 14:26:51 nsk ppp[2314]: tun0: LCP:  TEXT MSRAS-1-I
May 29 14:26:51 nsk ppp[2314]: tun0: Phase: Pap Input: REQUEST (pppuser)
May 29 14:26:51 nsk ppp[2314]: tun0: Phase: Pap Output: SUCCESS
May 29 14:26:51 nsk ppp[2314]: tun0: Phase: deflink: lcp -> cbcp
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP: deflink: SendReq(0) state = closed
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP:  TYPE Server-spec
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP:  DELAY 0
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP: deflink: State change closed --> req-sent
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP: deflink: RecvResponse(0) state = req-sent
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP:  TYPE Server-spec
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP:  DELAY 12
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP: deflink: SendAck(0) state = req-sent
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP:  TYPE Server-spec
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP:  DELAY 12
May 29 14:26:51 nsk ppp[2314]: tun0: CBCP: deflink: State change req-sent --> ack-sent
May 29 14:26:51 nsk ppp[2314]: tun0: LCP: deflink: RecvTerminateReq(6) state = Opened
May 29 14:26:51 nsk ppp[2314]: tun0: LCP: deflink: LayerDown
May 29 14:26:51 nsk ppp[2314]: tun0: Phase: deflink: CBCP: Will dial back on p50722
May 29 14:26:51 nsk ppp[2314]: tun0: LCP: deflink: SendTerminateAck(6) state = Opened
May 29 14:26:51 nsk ppp[2314]: tun0: LCP: deflink: State change Opened --> Stopping
May 29 14:26:51 nsk ppp[2314]: tun0: Phase: deflink: cbcp -> lcp
May 29 14:26:52 nsk ppp[2314]: tun0: Phase: deflink: Carrier lost
May 29 14:26:52 nsk ppp[2314]: tun0: LCP: deflink: State change Stopping --> Starting
May 29 14:26:52 nsk ppp[2314]: tun0: LCP: deflink: LayerFinish
May 29 14:26:52 nsk ppp[2314]: tun0: LCP: deflink: State change Starting --> Initial
May 29 14:26:52 nsk ppp[2314]: tun0: Phase: deflink: Disconnected!
May 29 14:26:52 nsk ppp[2314]: tun0: Phase: deflink: Connect time: 5 secs: 462 octets in, 229 octets out
May 29 14:26:52 nsk ppp[2314]: tun0: Phase: deflink: 24 packets in, 7 packets out
May 29 14:26:52 nsk ppp[2314]: tun0: Phase:  total 138 bytes/sec, peak 137 bytes/sec on Thu May 29 14:26:52 2008
May 29 14:26:52 nsk ppp[2320]: tun0: Phase: Call peer back on p50722
May 29 14:26:52 nsk ppp[2320]: tun0: CBCP: deflink: State change ack-sent --> closed
May 29 14:26:52 nsk ppp[2320]: tun0: Phase: deflink: lcp -> opening
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: deflink: Redial timer expired.
May 29 14:27:04 nsk ppp[2320]: tun0: Phase: deflink: Connected!
May 29 14:27:04 nsk ppp[2320]: tun0: Phase: deflink: opening -> dial
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: Phone: p50722
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: deflink: Dial attempt 1 of 1
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: Send: AT^M
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: Expect(10): OK
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Received: AT^M^M
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Received: OK^M
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Send: ATDPp50722^M
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Expect(120): CONNECT
May 29 14:27:21 nsk ppp[2320]: tun0: Chat: Received: ATDPp50722^M^M
May 29 14:27:21 nsk ppp[2320]: tun0: Chat: Received: RINGING^M
May 29 14:28:00 nsk ppp[2320]: tun0: Chat: Received: Hh
May 29 14:29:05 nsk ppp[2320]: tun0: Chat: Expect timeout
May 29 14:29:05 nsk ppp[2320]: tun0: Warning: Chat script failed
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: dial -> hangup
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: Disconnected!
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: Connect time: 121 secs: 0 octets in, 0 octets out
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: 24 packets in, 7 packets out
May 29 14:29:05 nsk ppp[2320]: tun0: Phase:  total 0 bytes/sec, peak 0 bytes/sec on Thu May 29 14:27:04 2008
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: hangup -> closed
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: bundle: Dead
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: PPP Terminated (normal).

Здесь видно, что дозвон на сервер происходит нормально и после идентификации пользователя ppp:
- ложит трубку и перезванивает на клиента.

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

May 29 14:27:04 nsk ppp[2320]: tun0: Phase: deflink: Connected!
May 29 14:27:04 nsk ppp[2320]: tun0: Phase: deflink: opening -> dial
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: Phone: p50722
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: deflink: Dial attempt 1 of 1
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: Send: AT^M
May 29 14:27:04 nsk ppp[2320]: tun0: Chat: Expect(10): OK
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Received: AT^M^M
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Received: OK^M
May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Send: ATDPp50722^M

- здесь клиентская машина Win2000 получает входящий звонок, снимает трубку. Далее ppp ждёт сообщение от модема CONNECT ... а его нет

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

May 29 14:27:05 nsk ppp[2320]: tun0: Chat: Expect(120): CONNECT
May 29 14:27:21 nsk ppp[2320]: tun0: Chat: Received: ATDPp50722^M^M
May 29 14:27:21 nsk ppp[2320]: tun0: Chat: Received: RINGING^M
May 29 14:28:00 nsk ppp[2320]: tun0: Chat: Received: Hh
May 29 14:29:05 nsk ppp[2320]: tun0: Chat: Expect timeout
May 29 14:29:05 nsk ppp[2320]: tun0: Warning: Chat script failed
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: dial -> hangup
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: Disconnected!
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: Connect time: 121 secs: 0 octets in, 0 octets out
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: 24 packets in, 7 packets out
May 29 14:29:05 nsk ppp[2320]: tun0: Phase:  total 0 bytes/sec, peak 0 bytes/sec on Thu May 29 14:27:04 2008
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: deflink: hangup -> closed
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: bundle: Dead
May 29 14:29:05 nsk ppp[2320]: tun0: Phase: PPP Terminated (normal).

- и после таймаута (120), ppp ложит трубку на сервере и завершает свою работу

Модемы почему-то не связываются на этапе перезвона сервера на клиента.
Вот не пойму в чём дело. Что не так. Клиент снимает трубку, некоторое время модемы пищат (но не так, как при дозвоне на сервер, а однотонный писк, без смены частот), и CONNECT так и не наступает.

Не могу разобраться, что может быть.
Помогите, плз. Где рыть?

З.Ы. Вот я и говорил, что увеличив таймаут (аш до 120), как в рецепте к данной теме, CONNECT так и не наступает.

[gray_wings]

Клиент снимает трубку, некоторое время модемы пищат (но не так, как при дозвоне на сервер, а однотонный писк, без смены частот), и CONNECT так и не наступает.

во-во! та же самая ерунда была! такой дурацкий писк.

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

May 29 14:28:00 nsk ppp[2320]: tun0: Chat: Received: Hh
May 29 14:29:05 nsk ppp[2320]: tun0: Chat: Expect timeout
May 29 14:29:05 nsk ppp[2320]: tun0: Warning: Chat script failed

та же ерунда что и у меня была... проблемка с обработкой скрипта. попробуй поиграться таймаутами.
что в mgetty.config?

а что за момед (со стороны винды)? может ему в строке прописать

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

AT S0=1

, чтоб трубу с первого звонка брал.
з.ы. позасовывай логи и конфиги в *

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

*. здесь за это шибко ругают!)))))))

[dendroid]

Вот содержимое mgetty.config^

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

port ttyd0
debug 4
fax-id 00 00 000000
speed 38400
direct NO
blocking NO
port-owner uucp
port-group uucp
port-mode 0660
toggle-dtr YES
toggle-dtr-waittime 500
data-only NO
fax-only NO
modem-type auto
init-chat "" ATS0=0Q0&D3&C1 OK
modem-check-time 3600
rings 1
answer-chat "" ATA CONNECT \c \r
answer-chat-timeout 80
autobauding NO
ringback NO
ringback-time 30
ignore-carrier false
issue-file /etc/issue
prompt-waittime 500
login-prompt @!login:
login-time 240
diskspace 1024
notify faxadmin
fax-owner uucp
fax-group modem
fax-mode 0660

Со стороны Win2000 и сервера одно и тоже - 3COM Courier
Пробовали модем со стороны Win2000 менять на другой - тоже самое
Я вот тоже думаю, что chat-скрипт дозвона ppp здесь при делах, ведь mgetty обрабатывает входящее подключение нормально ...

Что скажете ?

[gray_wings]

1. меня можно на ты. я один))))))))
2. 252429938 так удобнее общаться