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