[Freeswitch-users] Sangoma Unknown Event Code(5) Invalid PCB state(265)

Dmitriy Shumaev pm_zefman_r at mail.ru
Thu Apr 18 16:12:25 MSD 2013


 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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130418/9acbd36c/attachment-0001.html 


Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users mailing list