<HTML><BODY>Core 2 Duo E8400 @3.00Ghz 2GB RAM<br>Sangoma A101<br>Git-1.7.11-preview20120710<br>FreeSWITCH Version 1.5.1b+git~20130417T225111Z~54d47599e9<br>wanpipe_6_0_46_0<br>libsng_isdn-7.6.2<br><br><span class="hps">mod_freetdm </span><span class="hps">is loaded</span> <span class="hps">successfully</span> (look at full log forwards).<br>But as a reaction on incoming calls FS console shows the next warning message:<br>> 2013-04-18 15:43:33.046875 [WARNING] ftmod_sangoma_isdn_stack_rcv.c:862 [SNGISDN Q931] s1: Internal: Unknown Event Code(5): Invalid PCB state(265).<br><span style="overflow: auto;" dir="ltr" id="tinymce" class="mceContentBody " contenteditable="true">Although the</span> <span class="hps">analyzer</span>(linkbit) <span class="hps">shows transmission</span> of SETUP, RR, RR, 10sec delay, SETUP, RR, RR from PBX to FS(sangoma).<br><br>What it could be?<br><span class="hps">Grateful</span> <span class="hps">for any answers</span>.<br><br><br>Full log:<br>freeswitch@telegraf-4a8f3c> load mod_freetdm<br>2013-04-18 15:03:35.765625 [INFO] mod_enum.c:872 ENUM Reloaded<br>2013-04-18 15:03:35.765625 [INFO] switch_time.c:1173 Timezone reloaded 530 definitions<br>2013-04-18 15:03:35.796875 [NOTICE] ftdm_sched.c:185 Launching main schedule thread<br>2013-04-18 15:03:35.796875 [NOTICE] ftdm_io.c:6330 Modules configured: 1<br>2013-04-18 15:03:35.812500 [INFO] ftdm_io.c:5499 Loading IO from C:/FS_GIT/Win32/Release/mod\ftmod_wanpipe.dll [wanpipe]<br><br>2013-04-18 15:03:35.812500 [ERR] ftdm_io.c:5445 Cannot open wanpipe.conf<br>2013-04-18 15:03:35.812500 [INFO] ftdm_io.c:860 Auto-loaded I/O module 'wanpipe'<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c1][1:1] Configured wanpipe device FD: 3620, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c2][1:2] Configured wanpipe device FD: 4936, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c3][1:3] Configured wanpipe device FD: 4948, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c4][1:4] Configured wanpipe device FD: 4956, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c5][1:5] Configured wanpipe device FD: 4964, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c6][1:6] Configured wanpipe device FD: 4972, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c7][1:7] Configured wanpipe device FD: 4980, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c8][1:8] Configured wanpipe device FD: 4988, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c9][1:9] Configured wanpipe device FD: 4996, DTMF: software, HW<br>EC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c10][1:10] Configured wanpipe device FD: 5004, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c11][1:11] Configured wanpipe device FD: 5012, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c12][1:12] Configured wanpipe device FD: 5020, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c13][1:13] Configured wanpipe device FD: 5028, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c14][1:14] Configured wanpipe device FD: 5036, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c15][1:15] Configured wanpipe device FD: 5044, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c16][1:17] Configured wanpipe device FD: 5052, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c17][1:18] Configured wanpipe device FD: 5060, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c18][1:19] Configured wanpipe device FD: 5068, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c19][1:20] Configured wanpipe device FD: 5076, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c20][1:21] Configured wanpipe device FD: 5084, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c21][1:22] Configured wanpipe device FD: 5092, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c22][1:23] Configured wanpipe device FD: 5100, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c23][1:24] Configured wanpipe device FD: 5108, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c24][1:25] Configured wanpipe device FD: 5116, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c25][1:26] Configured wanpipe device FD: 5124, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c26][1:27] Configured wanpipe device FD: 5132, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c27][1:28] Configured wanpipe device FD: 5140, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c28][1:29] Configured wanpipe device FD: 5148, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c29][1:30] Configured wanpipe device FD: 5156, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c30][1:31] Configured wanpipe device FD: 5164, DTMF: software,<br>HWEC: unavailable, HWEC_IDLE: enabled<br>2013-04-18 15:03:35.812500 [INFO] ftmod_wanpipe.c:420 [s1c31][1:16] Configured wanpipe device FD: 5168, DTMF: none, HWEC<br>: none, HWEC_IDLE: none<br>2013-04-18 15:03:35.843750 [INFO] ftdm_io.c:5421 Configured 31 channel(s)<br>2013-04-18 15:03:35.937500 [INFO] ftdm_io.c:5499 Loading IO from C:/FS_GIT/Win32/Release/mod\ftmod_sangoma_isdn.dll [san<br>goma_isdn]<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn.c:1338 Loading ftmod_sangoma_isdn...<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1102 sng_isdn-><br><br>===========================================<br>= Sangoma FreeTDM ISDN Library =<br>= Version:7.6.2 =<br>===========================================<br><br><br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully registered Stack Manager<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully started a task for Stack Ma<br>nager<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully attached Stack Manager to i<br>t's task<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully registered Call Control<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully started a task for Call Con<br>trol<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully attached Call Control to it<br>'s task<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully registered Q.930/Q.931<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully started a task for Q.930/Q.<br>931<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully attached Q.930/Q.931 to it'<br>s task<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully registered LAPD<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully started a task for LAPD<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully attached LAPD to it's task<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully registered Physical Layer<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully started a task for Physical<br> Layer<br>2013-04-18 15:03:35.937500 [INFO] ftmod_sangoma_isdn_stack_rcv.c:1098 sng_isdn->Successfully attached Physical Layer to<br>it's task<br>2013-04-18 15:03:36.437500 [INFO] ftmod_sangoma_isdn_stack_cfg.c:89 General stack configuration done<br>2013-04-18 15:03:36.437500 [INFO] ftdm_io.c:5511 Loading SIG from C:/FS_GIT/Win32/Release/mod\ftmod_sangoma_isdn.dll<br>2013-04-18 15:03:36.437500 [INFO] ftdm_io.c:5735 auto-loaded 'sangoma_isdn'<br>2013-04-18 15:03:36.437500 [INFO] ftmod_sangoma_isdn.c:1184 Configuring ftmod_sangoma_isdn span = wp1<br>2013-04-18 15:03:36.453125 [INFO] ftmod_sangoma_isdn_stack_cfg.c:159 wp1:stack configuration done<br>2013-04-18 15:03:36.453125 [INFO] ftmod_sangoma_isdn.c:1331 Finished configuring ftmod_sangoma_isdn span = wp1<br>2013-04-18 15:03:36.453125 [INFO] ftmod_sangoma_isdn.c:1089 Starting span wp1:1.<br>2013-04-18 15:03:37.265625 [INFO] ftmod_sangoma_isdn_stack_cntrl.c:88 wp1:Stack activated<br>2013-04-18 15:03:37.265625 [INFO] ftmod_sangoma_isdn.c:447 ftmod_sangoma_isdn monitor thread for span=1 started.<br>2013-04-18 15:03:37.265625 [CONSOLE] switch_loadable_module.c:1350 Successfully Loaded [mod_freetdm]<br>2013-04-18 15:03:37.265625 [INFO] ftmod_sangoma_isdn_stack_rcv.c:825 [SNGISDN Q931] s1: Interface: UP(260): Dchan(285)<br>2013-04-18 15:03:37.265625 [NOTICE] switch_loadable_module.c:146 Adding Endpoint 'freetdm'<br>2013-04-18 15:03:37.265625 [NOTICE] switch_loadable_module.c:254 Adding Application 'disable_ec'<br>2013-04-18 15:03:37.265625 [NOTICE] switch_loadable_module.c:254 Adding Application 'disable_dtmf'<br>2013-04-18 15:03:37.265625 [NOTICE] switch_loadable_module.c:254 Adding Application 'enable_dtmf'<br>2013-04-18 15:03:37.265625 [NOTICE] switch_loadable_module.c:298 Adding API Function 'ftdm'<br>2013-04-18 15:03:37.265625 [NOTICE] switch_loadable_module.c:298 Adding API Function 'ftdm_usage'<br><br>+OK Reloading XML<br>+OK<br><br>2013-04-18 15:03:37.281250 [INFO] ftmod_sangoma_isdn_stack_rcv.c:675 Received RESTART CFM (dChan:1 ces:0 type:0)<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:1 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:2 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:3 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:4 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:5 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:6 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:7 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:8 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:9 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:10 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:11 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:12 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:13 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:14 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:15 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:16 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:17 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:18 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:19 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:20 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:21 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:22 signalling changed to :UP<br>2013-04-18 15:03:37.281250 [INFO] mod_freetdm.c:2733 1:23 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:24 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:25 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:26 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:27 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:28 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:29 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:30 signalling changed to :UP<br>2013-04-18 15:03:37.296875 [INFO] mod_freetdm.c:2733 1:31 signalling changed to :UP<br><br>freeswitch@telegraf-4a8f3c><br><br>freeswitch@telegraf-4a8f3c><br><br>freeswitch@telegraf-4a8f3c> ftdm list<br><br>+OK<br>span: 1 (wp1)<br>type: Sangoma (ISDN)<br>physical_status: ok<br>signaling_status: UP<br>chan_count: 31<br>dialplan: XML<br>context: default<br>dial_regex:<br>fail_dial_regex:<br>hold_music:<br>analog_options: none<br><br><br>freeswitch@telegraf-4a8f3c> ftdm sangoma_isdn trace q931 wp1<br>2013-04-18 15:04:38.484375 [INFO] ftmod_sangoma_isdn_stack_cntrl.c:271 s1 Enabling q931 trace<br><br>Command executed OK<br><br><br>freeswitch@telegraf-4a8f3c> ftdm sangoma_isdn trace q921 wp1<br>2013-04-18 15:04:42.015625 [INFO] ftmod_sangoma_isdn_stack_cntrl.c:261 wp1:Enabling q921 trace<br><br>Command executed OK<br><br><br>freeswitch@telegraf-4a8f3c> 2013-04-18 15:06:44.843750 [WARNING] ftmod_sangoma_isdn_stack_rcv.c:862 [SNGISDN Q931] s1: I<br>nternal: Unknown Event Code(5): Invalid PCB state(265)<br>2013-04-18 15:06:54.843750 [WARNING] ftmod_sangoma_isdn_stack_rcv.c:862 [SNGISDN Q931] s1: Internal: Unknown Event Code(<br>5): Invalid PCB state(265)<br>2013-04-18 15:07:30.375000 [WARNING] ftmod_sangoma_isdn_stack_rcv.c:862 [SNGISDN Q931] s1: Internal: Unknown Event Code(<br>5): Invalid PCB state(265)<br>2013-04-18 15:07:40.359375 [WARNING] ftmod_sangoma_isdn_stack_rcv.c:862 [SNGISDN Q931] s1: Internal: Unknown Event Code(<br>5): Invalid PCB state(265)<br>...<br>...<br>...<br><br>With best regards, Shumaev DA, KBR Ltd.<br></BODY></HTML>