[Freeswitch-users] Sangoma Unknown Event Code(5) Invalid PCB state(265)
Michael Collins
msc at freeswitch.org
Fri Apr 19 03:03:35 MSD 2013
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 at 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 at 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 at telegraf-4a8f3c>
>
> freeswitch at telegraf-4a8f3c>
>
> freeswitch at 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 at 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 at 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 at 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 at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130418/466384ae/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users
mailing list