[Freeswitch-users] freetdm-pritap --- Failed to get a free passive PRI call slot

Mon Apr 22 09:34:36 MSD 2013

Dear all

i have configured a freetdm environment to make passive tapping of isdn 
calls.
things finally seems went configured well, but when i started the 
freeswitch application, after a while i start seeing these messages all 
the time

2013-02-08 05:02:27.946997 [DEBUG] ftmod_pritap.c:789 Hangup ack on 
channel w1g1:0:7 with callref 6749
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:622 Ring on channel 
w2g1:0:6 with callref 6750
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:451 crv 6750 was not 
found active in span w2g1
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:497 Garbage collecting 
callref 6749/0x7fbdf8075f90 from span w2g1 in slot 31
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:505 Enabling callref 
slot 31 in span w2g1
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:658 Proceeding on 
channel w1g1:0:6 with callref 6750
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:451 crv 6750 was not 
found active in span w1g1
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:497 Garbage collecting 
callref 6749/0x7fbdf8082260 from span w1g1 in slot 31
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:505 Enabling callref 
slot 31 in span w1g1
2013-02-08 05:02:28.026981 [NOTICE] ftmod_pritap.c:724 [s1c6][1:6] 
Starting new tapped call with callref 6750
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:728 [s1c6][1:6] 
Changed state from DOWN to RING
2013-02-08 05:02:28.026981 [DEBUG] ftdm_state.c:541 [s1c6][1:6] 
Executing state processor for RING
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:288 [s1c6][1:6] 
processing state RING
2013-02-08 05:02:28.026981 [DEBUG] ftmod_pritap.c:295 [s1c6][1:6] 
Completed state change from DOWN to RING in 0 ms
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:2653 got clear channel 
sig [START]
2013-02-08 05:02:28.026981 [DEBUG] ftdm_io.c:3386 [s1c6][1:6] Enabled 
software DTMF detector
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:403 Set codec PCMA 20ms
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:1886 Connect inbound 
channel FreeTDM/1:6/2315229537
2013-02-08 05:02:28.026981 [NOTICE] switch_channel.c:968 New Channel 
FreeTDM/1:6/2315229537 [a57b4d1c-009f-4f22-89f4-8787a08e5935]
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:2084 Call Variable: 
freetdm_pritap_ring_interface = UNKNOWN
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:2089 
(FreeTDM/1:6/2315229537) State Change CS_NEW -> CS_INIT
2013-02-08 05:02:28.026981 [DEBUG] switch_core_session.c:1283 Send 
signal FreeTDM/1:6/2315229537 [BREAK]
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:415 
(FreeTDM/1:6/2315229537) Running State Change CS_INIT
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:454 
(FreeTDM/1:6/2315229537) State INIT
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:430 
(FreeTDM/1:6/2315229537) State Change CS_INIT -> CS_ROUTING
2013-02-08 05:02:28.026981 [DEBUG] switch_core_session.c:1283 Send 
signal FreeTDM/1:6/2315229537 [BREAK]
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:454 
(FreeTDM/1:6/2315229537) State INIT going to sleep
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:415 
(FreeTDM/1:6/2315229537) Running State Change CS_ROUTING
2013-02-08 05:02:28.026981 [DEBUG] switch_channel.c:2003 
(FreeTDM/1:6/2315229537) Callstate Change DOWN -> RINGING
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:470 
(FreeTDM/1:6/2315229537) State ROUTING
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:453 
FreeTDM/1:6/2315229537 CHANNEL ROUTING
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:456 [s1c6][1:6] 
Indicating PROCEED in state RING
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:117 
FreeTDM/1:6/2315229537 Standard ROUTING
2013-02-08 05:02:28.026981 [INFO] mod_dialplan_xml.c:498 Processing 
002347085116551 <002347085116551>->2315229537 in context 001_isdn_analyzerA
Dialplan: FreeTDM/1:6/2315229537 parsing 
[001_isdn_analyzerA->incoming-pri] continue=false
Dialplan: FreeTDM/1:6/2315229537 Regex (PASS) [incoming-pri] 
destination_number(2315229537) =~ /(^.+$)/ break=on-false
Dialplan: FreeTDM/1:6/2315229537 Action wait_for_answer()
Dialplan: FreeTDM/1:6/2315229537 Action record(/tmp/bocata)
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:167 
(FreeTDM/1:6/2315229537) State Change CS_ROUTING -> CS_EXECUTE
2013-02-08 05:02:28.026981 [DEBUG] switch_core_session.c:1283 Send 
signal FreeTDM/1:6/2315229537 [BREAK]
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:470 
(FreeTDM/1:6/2315229537) State ROUTING going to sleep
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:415 
(FreeTDM/1:6/2315229537) Running State Change CS_EXECUTE
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:477 
(FreeTDM/1:6/2315229537) State EXECUTE
2013-02-08 05:02:28.026981 [DEBUG] mod_freetdm.c:473 
FreeTDM/1:6/2315229537 CHANNEL EXECUTE
2013-02-08 05:02:28.026981 [DEBUG] switch_core_state_machine.c:209 
FreeTDM/1:6/2315229537 Standard EXECUTE
EXECUTE FreeTDM/1:6/2315229537 wait_for_answer()
2013-02-08 05:02:28.026981 [DEBUG] mod_dptools.c:1182 Waiting for answer
2013-02-08 05:02:29.046978 [DEBUG] ftmod_pritap.c:796 Ignoring passive 
event Ringing on span w1g1
2013-02-08 05:02:29.487039 [DEBUG] ftmod_pritap.c:622 Ring on channel 
w2g1:0:5 with callref 6751
2013-02-08 05:02:29.487039 [DEBUG] ftmod_pritap.c:451 crv 6751 was not 
found active in span w2g1
2013-02-08 05:02:29.487039 [ERR] ftmod_pritap.c:637 Failed to get a free 
passive PRI call slot for callref 6751, this is a bug!

i tried changing some parameters on the wanpipe.conf of the 
/usr/local/freeswitch/conf about the queu length but it's the same.
when i start the FSW it start to record the calls normally but after 
some minutes and capturing about 20 calls, it starts to show the sames 
messages

2013-02-08 05:02:29.487039 [DEBUG] ftmod_pritap.c:622 Ring on channel 
w2g1:0:5 with callref 6751
2013-02-08 05:02:29.487039 [DEBUG] ftmod_pritap.c:451 crv 6751 was not 
found active in span w2g1
2013-02-08 05:02:29.487039 [ERR] ftmod_pritap.c:637 Failed to get a free 
passive PRI call slot for callref 6751, this is a bug!

and seems it cannot do the garbage recollect the callref to a slot

a problem seem to start when some calls get the hangup ignored, and the 
call is not destroyed.
2013-02-22 04:36:37.692467 [DEBUG] ftmod_pritap.c:796 Ignoring passive 
event Hangup on span w2g1
2013-02-22 04:36:37.712506 [DEBUG] ftmod_pritap.c:109 NEW_HANGUP DEBUG: 
NOT Destroying the call 16230 (0x7f6c800970c0), ourstate Null, peerstate 
Null with magic 0
that causes after sometime another call attempting same channel fails to 
use it, and i guess that causes in some time to fail tapping any call.
seeing the program, seems like the sangoma was not seeing the event 
PRI_EVENT_HANGUP_REQ.
i tried to change the wanpipe configuration setting HDLC_STREAMING=YES 
and the IGNORE_FRONT_END = NO, but seems the same.

this doesnt happen in all calls, they use to work and process the 
messages normally after booting the FSW till we start to see the issue 
some time after that.

here you have the wanpipe conf and hwprobe too

root at ss7mon2 <mailto:root at ss7mon2>:/usr/local/freeswitch/bin# cat 
/etc/wanpipe/wanpipe1.conf
[devices]
wanpipe1 = WAN_AFT_TE1, Comment

[interfaces]
w1g1 = wanpipe1, , TDM_VOICE_API, Comment

[wanpipe1]
CARD_TYPE = AFT
S514CPU = A
CommPort = PRI
AUTO_PCISLOT = NO
PCISLOT = 4
PCIBUS = 5
FE_MEDIA = E1
FE_LCODE = HDB3
FE_FRAME = NCRC4

FE_LINE = 1
TE_CLOCK = NORMAL
TE_REF_CLOCK = 0
TE_SIG_MODE = CCS
TE_HIGHIMPEDANCE = YES
LBO = 75OH

FE_TXTRISTATE = NO
MTU = 1500
UDPPORT = 9000
TTL = 255
IGNORE_FRONT_END = NO
TDMV_SPAN = 1
TDMV_DCHAN = 16
TDMV_HW_DTMF = NO
#TDMV_HW_FAX_DETECT = NO

[w1g1]
ACTIVE_CH = ALL
HDLC_STREAMING = YES
#HDLC_REPEAT = YES
#MTP1_FILTER = YES
#TDMV_HWEC = NO
#MTU = 80
root at ss7mon2 <mailto:root at ss7mon2>:/usr/local/freeswitch/bin# wanrouter 
hwprobe

-------------------------------
| Wanpipe Hardware Probe Info |
-------------------------------
1 . AFT-A104-SH : SLOT=4 : BUS=5 : IRQ=16 : CPU=A : PORT=1 : HWEC=0 : V=43
2 . AFT-A104-SH : SLOT=4 : BUS=5 : IRQ=16 : CPU=A : PORT=2 : HWEC=0 : V=43
3 . AFT-A104-SH : SLOT=4 : BUS=5 : IRQ=16 : CPU=A : PORT=3 : HWEC=0 : V=43
4 . AFT-A104-SH : SLOT=4 : BUS=5 : IRQ=16 : CPU=A : PORT=4 : HWEC=0 : V=43

Card Cnt: A104=1

could you please take a look and help me understanding where i have the 
missconfiguration (or some kind of memory issue¿?)?

thanks a lot and regards
david escartin
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130422/2ad73363/attachment-0001.html 