[RRAS][long] comment configurer le contre-appel?

[ Publication croisée dans microsoft.public.fr.windows.server.reseau et
  fr.comp.os.ms-windows.serveurs, suivis vers ce dernier groupe. ]

Bonjour,

J'ai installé le service d'accès distant, et j'ai réussi à faire fonctionner
tout ce dont j'ai besoin sauf _une_ chose : le contre-appel (callback,
rappel) à initiative de l'appelant (set-by-caller).

Contexte : Serveur 2003 (SBS espagnol si cela a une quelconque importance),
sans IAS; carte RNIS Eicon Diva (BRI2M).
Configuration du serveur RRAS : tout est activé, sauf les protocoles trop
faibles (CHAP, SPAP, PAP).
Au niveau des ports, la carte RNIS est autorisée pour routage et accès
distant, son numéro est bien indiqué.
Au niveau des directives, j'ai essayé sans directive (j'ai très peu
d'utilisateurs), ou avec ; sans différence appréciable.

Ce qui marche : VPN avec PPTP, connexion RAS sans contre-appel (fiche «Appel
entrant», option «Pas de rappel»), et connexion RAS avec rappel d'un numéro
figé dans l'AD (option «Toujours rappeler»).
Ce qui ne marche pas avec 2003 : l'option du milieu, «Défini par l'appelant
(service de routage et d'accès distant uniquement)», avec le même numéro.

J'ai tout revérifier les éléments détaillés dans
http://www.microsoft.com/france/technet/produits/win2003/rrascnfg.mspx (bon
résumé du sujet), mais rien n'y fait. Le même service fonctionnait
auparavant avec un serveur NT4 et la même carte RNIS, donc le problème doit
être purement logiciel. De même, j'ai les mêmes résultats quels que soient
les client utilisés, 98SE ou 2000 ou XP; j'ai aussi essayé plusieurs modems
différents, et aussi plusieurs numéros rappelés, pas de différence.


Voilà. Si quelqu'un a des pistes, je suis preneur !


Antoine

____________
P.S. : Pour les techniciens qui nous lisent, j'ai rajouté les traces (et si
cela ne vous intéresse pas particulièrement, vous pouvez coupez le reste du
message à ce niveau).

Dans la trace, je vois bien le dialogue sur le numéro à rappeler, donc pour
moi tout va bien jusque là. De fait, la conversation PPP
(%windir%/tracing/PPP.LOG) dans le cas des rappels se termine invariablement
par

[5428] 03-03 14:19:23:220: Notifying server to callback at XXXXXXX, delay =
12
[5428] 03-03 14:19:23:220: NotifyCaller(hPort=1, dwMsgId=15)
[5192] 03-03 14:19:23:642: PPPEMSG_LineDown recvd, hPort=1

[5428] 03-03 14:19:23:642: Line down event occurred on port 1
[5428] 03-03 14:19:23:642: FsmDown event received for protocol c021 on port
1
[5428] 03-03 14:19:23:642: RemoveFromTimerQ [...]
[7776] 03-03 14:19:23:642: Stopping Accounting for port 1
[5428] 03-03 14:19:23:642: LcpEnd
[5428] 03-03 14:19:25:642: Post line down event occurred on port 1

.... sauf que, si le numéro est fourni par négociation, après cela plus rien
ne se passe à ce niveau :-(.
Tandis que si j'ai figé le numéro à rappeler dans l'AD (un peu avant, on
voit passer " Auth Attribute Forced callback to XXXXXX"), le serveur
rappelle bien :
[1388] 03-03 10:10:24:196: Stopping Accounting for port 1
[5428] 03-03 10:10:24:196: LcpEnd
[5428] 03-03 10:10:26:196: Post line down event occurred on port 1
[5668] 03-03 10:10:59:805: PPPEMSG_DdmCallbackDone recvd

[5428] 03-03 10:10:59:805: Line up event occurred on port 1
[5428] 03-03 10:10:59:805: Starting PPP on link with
IfType=0x0,IPIf=0x0,IPXIf=0x0
 etc.


La suite se passe au niveau TAPI ; dans %windir%/tracing/RASTAPI.LOG, après
une attente de 14 secondes, cela bavarde: lorsque cela va bien, cela donne
[5192] 03-03 10:10:24:196: PortTestSignalState: DisconnectReason = 2
[5192] 03-03 10:10:24:196: PortDisconnect: ISDN8-0
[5192] 03-03 10:10:24:196:
[5668] 03-03 10:10:38:055: DeviceConnect: calling lineMakeCall for ISDN8-0,
address=XXXXXX
[5668] 03-03 10:10:38:055: DeviceConnect: Changing state for ISDN8-0 from
1 -> 4
[5264] 03-03 10:10:38:055: RasTapicallback: msg=12 , param1=66392l ,
param2=0l
[5264] 03-03 10:10:38:055: LINE_REPLY. param1=0x10358
[5264] 03-03 10:10:38:055: RasTapicallback: msg=2 , param1=16l , param2=0l
[5264] 03-03 10:10:38:055: RasTapicallback: linecallstate=0x10
[5264] 03-03 10:10:38:336: RasTapicallback: msg=2 , param1=512l , param2=0l
[5264] 03-03 10:10:38:336: RasTapicallback: linecallstate=0x200
[5264] 03-03 10:10:59:805: RasTapicallback: msg=1 , param1=8l , param2=0l
[5264] 03-03 10:10:59:805: RasTapicallback: msg=2 , param1=256l , param2=0l
[5264] 03-03 10:10:59:805: RasTapicallback: linecallstate=0x100
[5264] 03-03 10:10:59:805: DwGetConnectInfo
[5264] 03-03 10:10:59:805: DwGetIDInformation
[5264] 03-03 10:10:59:805: DwGetIDInformation. 0
 etc., la suite est sans intérêt àmha.

On peut aussi regarder %windir%/tracing/RASMAN.LOG au même moment:
[5668] 03-03 10:10:38:055: d:\nt\net\rras\ras\rasman\rasman\util.c: 2538:
port 1 state chg: prev=4, new=0
[5668] 03-03 10:10:38:055: d:\nt\net\rras\ras\rasman\rasman\util.c: 2583:
port 1 async reqtype chg: prev=0, new=15
[5668] 03-03 10:10:38:055: Adding timeout of 120 for listen
[5192] 03-03 10:10:38:055: OVEVT_RASMAN_ADJUST_TIMER
[5668] 03-03 10:10:38:055: Connect request on port: ISDN8-0, error code 600
 et c'est tout, rien d'autre à voir ici.


Lorsque cela ne marche pas, on obtient dans RASTAPI.LOG
[5192] 03-03 14:19:23:642: PortDisconnect: ISDN8-0
[5192] 03-03 14:19:23:642:
[5468] 03-03 14:19:37:533: DeviceConnect: calling lineMakeCall for ISDN8-0,
address=XXXXXXX
[5468] 03-03 14:19:37:533: DeviceConnect: Changing state for ISDN8-0 from
1 -> 4
[5264] 03-03 14:19:37:533: RasTapicallback: msg=12 , param1=65692l ,
param2=0l
[5264] 03-03 14:19:37:533: LINE_REPLY. param1=0x1009c
[5264] 03-03 14:19:37:533: RasTapicallback: msg=2 , param1=16l , param2=0l
[5264] 03-03 14:19:37:533: RasTapicallback: linecallstate=0x10
[5264] 03-03 14:19:37:720: RasTapicallback: msg=2 , param1=512l , param2=0l
[5264] 03-03 14:19:37:720: RasTapicallback: linecallstate=0x200
[5264] 03-03 14:19:37:830: RasTapicallback: msg=2 , param1=16384l ,
param2=1l
[5264] 03-03 14:19:37:830: RasTapicallback: linecallstate=0x4000
[5264] 03-03 14:19:37:830: RasTapiCallback: LINECALLSTATE_DISCONNECTED for
port ISDN8-0. AsyncErr = 651, param2=0x1
[5192] 03-03 14:19:37:830: DeviceWork: ISDN8-0. State = 4
[5264] 03-03 14:19:37:830: RasTapicallback: msg=2 , param1=1l , param2=0l
[5264] 03-03 14:19:37:830: RasTapicallback: linecallstate=0x1
[5468] 03-03 14:19:37:830: PortDisconnect: ISDN8-0
[5468] 03-03 14:19:37:830: InitiatePortDisconnection: ISDN8-0
[5468] 03-03 14:19:37:830: InitiatePortDisconnection: Changing state for
ISDN8-0 from 4 -> 5, id=0x10127
[5468] 03-03 14:19:37:830:
[5468] 03-03 14:19:37:830:
[5264] 03-03 14:19:37:939: RasTapicallback: msg=12 , param1=65831l ,
param2=0l
[5264] 03-03 14:19:37:939: LINE_REPLY. param1=0x10127
[5264] 03-03 14:19:37:939: RasTapiCallback: lineDropped. port ISDN8-0,
id=0xffffffff
[5264] 03-03 14:19:37:939: RasTapiCallback: Idle Received for port ISDN8-0
[5264] 03-03 14:19:37:939: RasTapiCallback: changing state of ISDN8-0. 5 ->
1
[5264] 03-03 14:19:37:939: RasTapiCallback: lineDeallocateCall for
ISDN8-0,hcall = 0x10105
[5192] 03-03 14:19:37:939: PortTestSignalState: DeviceState = 0
[5468] 03-03 14:19:37:939: DeviceListen: Changing State for ISDN8-0 from
1 -> 2
[5468] 03-03 14:19:37:939: DeviceListen: Changing Listen State for ISDN8-0
from 4 -> 2
[5468] 03-03 14:19:37:939:

Fin des émissions (et réception d'un évenement erreur 20089 de RemoteAccess
dans le journal système, info complémentaire: 28b hexa, soit 651).
Pour info, l'erreur 651 signifie « votre modem a donné une erreur »...

Je vois bien que cela déraille au moment où l'état passe à 0x4000, mais cela
ne m'éclaire pas.

Nettement plus de bavardages dans RASMAN.LOG dans ce cas-là:
[5468] 03-03 14:19:37:533: d:\nt\net\rras\ras\rasman\rasman\util.c: 2538:
port 1 state chg: prev=4, new=0
[5468] 03-03 14:19:37:533: d:\nt\net\rras\ras\rasman\rasman\util.c: 2583:
port 1 async reqtype chg: prev=0, new=15
[5468] 03-03 14:19:37:533: Adding timeout of 120 for listen
[5468] 03-03 14:19:37:533: Connect request on port: ISDN8-0, error code 600
[5192] 03-03 14:19:37:533: OVEVT_RASMAN_ADJUST_TIMER
[5192] 03-03 14:19:37:830: WorkerThread: Async work event signaled on port:
ISDN8-0
[5192] 03-03 14:19:37:830: OVEVT_DEV_ASYNCOP. pOverlapped = 0x31ce000
[5192] 03-03 14:19:37:830: d:\nt\net\rras\ras\rasman\rasman\worker.c: 2356:
port 1 async reqtype chg: prev=15, new=0
[5192] 03-03 14:19:37:830: ServiceWorkRequest: Async op event 15 for port
ISDN8-0 returned 651
[5468] 03-03 14:19:37:830: PortDisconnectRequest on ISDN8-0 Connection=0x0
,RasmanReceiveFlags=0x0
[5468] 03-03 14:19:37:830: PortDisconnectRequest: Disconnecting ISDN8-0
[5468] 03-03 14:19:37:830: Disconnecting Port 0xISDN8-0, reason 0
[5468] 03-03 14:19:37:830: link handle for ISDN8-0 = INVALID_HANDLE_VALUE
[5468] 03-03 14:19:37:830: d:\nt\net\rras\ras\rasman\rasman\util.c 1997:
Disconnected Port 1, reason 0. rc=0x258
[5468] 03-03 14:19:37:830: d:\nt\net\rras\ras\rasman\rasman\util.c: 2218:
port 1 state chg: prev=0, new=3
[5468] 03-03 14:19:37:830: d:\nt\net\rras\ras\rasman\rasman\util.c: 2288:
port 1 async reqtype chg: prev=0, new=9
[5468] 03-03 14:19:37:830: Disconnect request on port: ISDN8-0
[5192] 03-03 14:19:37:830: OVEVT_RASMAN_ADJUST_TIMER
[5192] 03-03 14:19:37:830: OVEVT_RASMAN_ADJUST_TIMER
[5192] 03-03 14:19:37:939: WorkerThread: Disconnect event signaled on port:
ISDN8-0
[5192] 03-03 14:19:37:939: OVEVT_DEV_STATECHANGE. pOverlapped = 0x31ce040
[5192] 03-03 14:19:37:939: d:\nt\net\rras\ras\rasman\rasman\request.c: 4723:
port 1 state chg: prev=3, new=4
[5192] 03-03 14:19:37:939: d:\nt\net\rras\ras\rasman\rasman\request.c: 4734:
port 1 async reqtype chg: prev=9, new=0
[5192] 03-03 14:19:37:939: CompleteDisconnectRequest: signalling 0x258c for
ISDN8-0
[5192] 03-03 14:19:37:939: Disconnect completed on port: ISDN8-0
[5468] 03-03 14:19:37:939: DeviceListenRequest: Clearing Autoclose flag on
port ISDN8-0
[5468] 03-03 14:19:37:939: d:\nt\net\rras\ras\rasman\rasman\util.c: 2552:
port 1 state chg: prev=4, new=1
[5468] 03-03 14:19:37:939: d:\nt\net\rras\ras\rasman\rasman\util.c: 2583:
port 1 async reqtype chg: prev=0, new=27
[5468] 03-03 14:19:37:939: Listen posted on port: ISDN8-0, error code 600

.... sauf que pour moi, cela ne signifie rien.