I thought Sangoma had fixed this but possibly not. Please put all this information into a new ticket on jira.freeswitch.org. -MC On Thu, Apr 18, 2013 at 5:12 AM, Dmitriy Shumaev <pm_zefman_r@mail.ru>wrote:
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.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Michael S Collins Twitter: @mercutioviz http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org