[Freeswitch-users] OpenZAP parse error [-3012] [Q931E_INVALID_CRV]
Michael Collins
msc at freeswitch.org
Mon Jan 19 10:21:39 PST 2009
Peter,
I believe we are in a bit of a holding pattern right now with OpenZAP
PRI stuff. We have a super user, Stefan, who is working on some Q931
timers and such but he is working on it in spare time and there's no
hard date. If you know someone with serious PRI and C programming
skillz who can assist then we'd definitely be willing to have some
help. "Patches welcome" as it were. :)
Thanks,
MC
On Thu, Jan 15, 2009 at 12:12 PM, Peter P GMX <Prometheus001 at gmx.net> wrote:
> 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
>>
>>
>
> _______________________________________________
> 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