[Freeswitch-users] OpenZAP parse error [-3012] [Q931E_INVALID_CRV]
Peter P GMX
Prometheus001 at gmx.net
Thu Jan 15 12:12:41 PST 2009
I did some more tests. When I sequentially setup calls (only one
simultaneous call at a time), it works for hundreds of calls.
As soon as I setup 2 calls in parallel ist fails aber a number of calls.
Please find another debug ouput (now with Q.921 debug also).
The log starts with the latest hangup of a successfull call. After this
one I receive a
"2009-01-15 20:26:46 [CRIT] ozmod_isdn.c:446 zap_isdn_931_34() Received
Release with no matching channel 0"
and later
"2009-01-15 20:26:46 [DEBUG] ozmod_isdn.c:781 zap_isdn_921_23() 931
parse error [-3012] [Q931E_INVALID_CRV]"
Is there anyone to fix it? May I donate some money for fixing that?
Best regards
Peter
Debug:
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() Sending frame
----------------- Q.921 Packet [Outgoing] ---------------
SAPI: 0, TEI: 0, C/R: Command (0)
Type: S Frame, SV: RR (Receive Ready)
P/F: 0, N(R): 81 [V(A): 80, V(R): 81, V(S): 80]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:813 state_advance() 2:3 STATE
[TERMINATING]
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:1121 state_advance()
Terminating: Direction Inbound
2009-01-15 20:26:44 [DEBUG] mod_openzap.c:1418 on_clear_channel_signal()
got clear channel sig [STOP]
2009-01-15 20:26:44 [NOTICE] mod_openzap.c:1437
on_clear_channel_signal() Hangup OpenZAP/2:3/21658519 [CS_EXECUTE]
[NORMAL_CLEARING]
2009-01-15 20:26:44 [DEBUG] switch_channel.c:1513
switch_channel_perform_hangup() Send signal OpenZAP/2:3/21658519 [KILL]
2009-01-15 20:26:44 [DEBUG] switch_core_session.c:807
switch_core_session_signal_state_change() Send signal
OpenZAP/2:3/21658519 [BREAK]
2009-01-15 20:26:44 [DEBUG] Span:0 Q.931() Receiving message from Layer4
(size: 184, type: 77)
2009-01-15 20:26:44 [DEBUG] Span:0 Q.931() Sending message to Q.921
(size: 184)
2009-01-15 20:26:44 [DEBUG] Span:0 Q.931() Creating Q.931 Message Header:
ProtDisc 8 (0x8), CRV 126 (0x7e), CRVflag: 1 (0x1), MesType: 77 (0x4d)
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:1529 q931_rx_32() WRITE 5
--------------------------------------------------------------------------------
[08 02 80 7e 4d]
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() Got frame from Q.931, type:
4, tei: 0, size: 9
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() Enqueueing I frame for TEI 0 [0]
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() Sending frame
----------------- Q.921 Packet [Outgoing] ---------------
SAPI: 0, TEI: 0, C/R: Command (0)
Type: I Frame
P/F: 0, N(S): 80, N(R): 81 [V(A): 80, V(R): 81, V(S): 80]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() T200 (timeout: 1000 msecs)
started for TEI 0
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() T203 stopped for TEI 0
2009-01-15 20:26:44 [DEBUG] Span:0 Q.931() Q931Rx43 return code: 1
2009-01-15 20:26:44 [DEBUG] mod_event_socket.c:1922 listener_run()
Session complete, waiting for children
2009-01-15 20:26:44 [DEBUG] mod_event_socket.c:1946 listener_run()
Connection Closed
2009-01-15 20:26:44 [DEBUG] switch_ivr_play_say.c:1222
switch_ivr_play_file() done playing file
2009-01-15 20:26:44 [DEBUG] switch_core_state_machine.c:454
switch_core_session_run() (OpenZAP/2:3/21658519) State EXECUTE going to
sleep
2009-01-15 20:26:44 [DEBUG] switch_core_state_machine.c:379
switch_core_session_run() (OpenZAP/2:3/21658519) Running State Change
CS_HANGUP
2009-01-15 20:26:44 [DEBUG] switch_core_state_machine.c:410
switch_core_session_run() (OpenZAP/2:3/21658519) State HANGUP
2009-01-15 20:26:44 [DEBUG] mod_openzap.c:472 channel_on_hangup()
OpenZAP/2:3/21658519 CHANNEL HANGUP
2009-01-15 20:26:44 [DEBUG] switch_core_state_machine.c:46
switch_core_standard_on_hangup() OpenZAP/2:3/21658519 Standard HANGUP,
cause: NORMAL_CLEARING
2009-01-15 20:26:44 [DEBUG] switch_core_state_machine.c:410
switch_core_session_run() (OpenZAP/2:3/21658519) State HANGUP going to sleep
2009-01-15 20:26:44 [DEBUG] switch_core_session.c:939
switch_core_session_thread() Session 251 (OpenZAP/2:3/21658519) Locked,
Waiting on external entities
2009-01-15 20:26:44 [NOTICE] switch_core_session.c:957
switch_core_session_thread() Session 251 (OpenZAP/2:3/21658519) Ended
2009-01-15 20:26:44 [NOTICE] switch_core_session.c:959
switch_core_session_thread() Close Channel OpenZAP/2:3/21658519 [CS_HANGUP]
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() New packet received (4 bytes)
----------------- Q.921 Packet [Incoming] ---------------
SAPI: 0, TEI: 0, C/R: Response (0)
Type: S Frame, SV: RR (Receive Ready)
P/F: 0, N(R): 81 [V(A): 80, V(R): 81, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() T200 stopped for TEI 0
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() T203 (timeout: 10000 msecs)
restarted for TEI 0
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() New packet received (9 bytes)
----------------- Q.921 Packet [Incoming] ---------------
SAPI: 0, TEI: 0, C/R: Command (1)
Type: I Frame
P/F: 0, N(S): 81, N(R): 81 [V(A): 81, V(R): 81, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:777 zap_isdn_921_23() READ 5
--------------------------------------------------------------------------------
[08 02 00 7e 5a]
2009-01-15 20:26:44 [DEBUG] Span:0 Q.931() Received message from Q.921
(ind 4, tei 0, size 9)
MesType: 90, CRVFlag 0 (Originator), CRV 126 (Dialect: 0)
2009-01-15 20:26:44 [DEBUG] Span:0 Q.931() Sending message to Layer4
(size: 103)
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:320 zap_isdn_931_34() Yay I got
an event! Type:[5a] Size:[103] CRV: 126 (0x7e, CTX: Originator)
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:352 zap_isdn_931_34() zchan
e0020270 (2:3) source isdn_data->channels_remote_crv[0x7e]
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:418 zap_isdn_931_34() Changing
state on 2:3 from TERMINATING to DOWN
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() Sending frame
----------------- Q.921 Packet [Outgoing] ---------------
SAPI: 0, TEI: 0, C/R: Response (1)
Type: S Frame, SV: RR (Receive Ready)
P/F: 0, N(R): 82 [V(A): 81, V(R): 82, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() T200 stopped for TEI 0
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() T203 (timeout: 10000 msecs)
restarted for TEI 0
2009-01-15 20:26:44 [DEBUG] Span:0 Q.921() Sending frame
----------------- Q.921 Packet [Outgoing] ---------------
SAPI: 0, TEI: 0, C/R: Command (0)
Type: S Frame, SV: RR (Receive Ready)
P/F: 0, N(R): 82 [V(A): 81, V(R): 82, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:44 [DEBUG] ozmod_isdn.c:813 state_advance() 2:3 STATE
[DOWN]
2009-01-15 20:26:44 [DEBUG] zap_io.c:1125 zap_channel_done() channel
done 2:3
2009-01-15 20:26:46 [DEBUG] Span:0 Q.921() New packet received (16 bytes)
----------------- Q.921 Packet [Incoming] ---------------
SAPI: 0, TEI: 0, C/R: Command (1)
Type: I Frame
P/F: 0, N(S): 82, N(R): 81 [V(A): 81, V(R): 82, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:46 [DEBUG] ozmod_isdn.c:777 zap_isdn_921_23() READ 12
--------------------------------------------------------------------------------
[08 02 00 7d 4d 08 05 82 e6 33 30 33]
2009-01-15 20:26:46 [DEBUG] Span:0 Q.931() Received message from Q.921
(ind 4, tei 0, size 16)
MesType: 77, CRVFlag 0 (Originator), CRV 125 (Dialect: 0)
2009-01-15 20:26:46 [DEBUG] Span:0 Q.931() Sending message to Layer4
(size: 110)
2009-01-15 20:26:46 [DEBUG] ozmod_isdn.c:320 zap_isdn_931_34() Yay I got
an event! Type:[4d] Size:[110] CRV: 125 (0x7d, CTX: Originator)
2009-01-15 20:26:46 [DEBUG] ozmod_isdn.c:352 zap_isdn_931_34() zchan 0
(-1:-1) source isdn_data->channels_remote_crv[0x7d]
2009-01-15 20:26:46 [CRIT] ozmod_isdn.c:446 zap_isdn_931_34() Received
Release with no matching channel 0
2009-01-15 20:26:46 [DEBUG] Span:0 Q.931() Sending message to Q.921
(size: 110)
2009-01-15 20:26:46 [DEBUG] Span:0 Q.931() Creating Q.931 Message Header:
ProtDisc 8 (0x8), CRV 125 (0x7d), CRVflag: 1 (0x1), MesType: 90 (0x5a)
2009-01-15 20:26:46 [DEBUG] ozmod_isdn.c:781 zap_isdn_921_23() 931 parse
error [-3012] [Q931E_INVALID_CRV]
2009-01-15 20:26:46 [DEBUG] Span:0 Q.921() Sending frame
----------------- Q.921 Packet [Outgoing] ---------------
SAPI: 0, TEI: 0, C/R: Response (1)
Type: S Frame, SV: RR (Receive Ready)
P/F: 0, N(R): 83 [V(A): 81, V(R): 83, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
2009-01-15 20:26:46 [DEBUG] Span:0 Q.921() T200 stopped for TEI 0
2009-01-15 20:26:46 [DEBUG] Span:0 Q.921() T203 (timeout: 10000 msecs)
restarted for TEI 0
2009-01-15 20:26:46 [DEBUG] Span:0 Q.921() Sending frame
----------------- Q.921 Packet [Outgoing] ---------------
SAPI: 0, TEI: 0, C/R: Command (0)
Type: S Frame, SV: RR (Receive Ready)
P/F: 0, N(R): 83 [V(A): 81, V(R): 83, V(S): 81]
Q.921 state: "Multiple Frame Mode Established" (7) [flags: ----]
----------------------------------------------
Peter P GMX schrieb:
> Thanks Helmut,
>
> I cross-checked with our provider. They use national numbering plan for
> our lines. So this didn't solve our problem.
> I also ensured that the local language is DE and ZAP timing is dedicated
> to span 1.
>
> I changed the configs to debug mode for OpenZAP, so I hopefully will get
> some more info on the next failure.
>
> Best regards
> Peter
>
> Helmut Kuper schrieb:
>
>> Hi Peter,
>>
>> it was simply a change in our TDM Voice Switch. It used a different
>> numbering plan and we changed it to "national" to get it work with FS
>> and openzap in Q921/Q931 mode.
>>
>> What I still search is a way to configure the numberplan in FS.
>>
>> To make it clear: In my case it didn't work from the second FS starts
>> up. So this differs from your problem.
>>
>>
>> To get an idea what's going on on the TDM link I used a TDM D-Channel
>> monitoring device and traced the d-channel messages exchanged between FS
>> and TDM. That should make it easier to see what's wrong when the
>> problems occur.
>> But you can also increase FS debug level to debug and trace the Q921
>> and Q931 messages in FS console via fs_cli during runtime. You have to
>> set this in openzap.conf.xml:
>>
>> <param name="q921loglevel" value="debug"/>
>> <param name="q931loglevel" value="debug"/>
>>
>> Unfortunately FS doesn't decode the whole Q931 messages, but it shows a
>> hex representation of the message, so you can manually decode it with
>> this documents:
>>
>> Q.931: http://www.itu.int/rec/T-REC-Q.931-199805-I/en
>> Q.921: http://www.itu.int/rec/T-REC-Q.921-199709-I/en
>>
>>
>> I think for numberingplan issues you only have to track the Q.931
>> messages.
>>
>>
>> The last idea I have to get some light into your problem and to avoid
>> manually decoding, try to convert FS's q931 hexdump into wiresharks pcap
>> format. Wireshark should be able to decode it :)
>> http://wiki.wireshark.org/Q.931
>>
>> Maybe it's a good idea to implement a wireshark export for those
>> messages in FS. This will make debugging easy and cheap.
>>
>>
>>
>> Hope it helps a bit.
>>
>>
>> regards
>> helmut
>>
>> Am 15.01.2009 12:06, schrieb Peter P GMX:
>>
>>> Helmut,
>>>
>>> can you give me a hint, how you worked around this?
>>>
>>> Best regards
>>> Peter
>>>
>>> Helmut Kuper schrieb:
>>>
>>>> Hi Michael,
>>>>
>>>> it must not be the case here, but I had the same error, when incomming
>>>> calles used a wrong numbering plan resp not the one, FS expected.
>>>>
>>>> Just a hint.
>>>>
>>>> regards
>>>> Helmut
>>>>
>>>>
>>>> Am 15.01.2009 09:20, schrieb Peter P GMX:
>>>>
>>>>> Hello Michael,
>>>>> how much $$ are we talking about? I need this issue to be solved
>>>>>
>> quickly
>>
>>>>> and it's worth to spend some money.
>>>>> I've read the following post:
>>>>>
>> http://www.mail-archive.com/freeswitch-users@lists.freeswitch.org/msg05792.html
>>
>>>>> and have the same symptom with "after hundreds of calls I start to
>>>>>
>> get b
>>
>>>>> channels that are stuck in states like "TERMINATING" or "HANGUP""
>>>>> Best regards
>>>>> Peter
>>>>> Michael Collins schrieb:
>>>>>
>>>>>>> I believe these are all symptoms of something that Stefan is working
>>>>>>> on: better Q931 timers. It's been on the todo list for some time but
>>>>>>> we've had absolutely NOBODY willing to pony up serious $$ to support
>>>>>>> OpenZAP development which means it is progressing at the speed of
>>>>>>> developers' free time.
>>>>>>>
>>>>>>> -MC
>>>>>>>
>>> _______________________________________________
>>> 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
>>>
>>
>>
>>> _______________________________________________
>>> 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
>>>
>>
>
> _______________________________________________
> 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
>
>
>
> _______________________________________________
> 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
>
>
More information about the FreeSWITCH-users
mailing list