Fehler/Bug bei Rückfrage über ISDN-Merkmal

Toggle sidebar Toggle sidebar
Upgrade 3CX to v18 and get it hosted free!
G

generalfiretech

Neuer User
Mitglied seit
14 Nov 2006
Beiträge
6
Punkte für Reaktionen
0
Punkte
0
Hallo Forum,

keine Ahnung, wohin ich mich nun am besten wenden sollte. Daher bin ich erst mal hier.
Meine Konfig:
SUSE 10.1
Bristuff-0.3.0-PRE-1y-d (Tritt aber auch mit allen vorigen Versionen auf, mit und ohne florz-patch)
AMP 2.2

Meine ISDN-Karten (2xNT für interne S0, 1xTE für externen TCOM-ISDN-Mehrgeräte-Anschluss):
Code: 
Span 1: ZTHFC1 "HFC-S PCI A ISDN card 0 [NT] layer 1 ACTIVATED (G3)" AMI/CCS

           1 ZTHFC1/0/1 Clear (In use)
           2 ZTHFC1/0/2 Clear (In use)
           3 ZTHFC1/0/3 HDLCFCS (In use)
Span 2: ZTHFC2 "HFC-S PCI A ISDN card 1 [NT] layer 1 ACTIVATED (G3)" AMI/CCS

           4 ZTHFC2/0/1 Clear (In use)
           5 ZTHFC2/0/2 Clear (In use)
           6 ZTHFC2/0/3 HDLCFCS (In use)
Span 3: ZTHFC3 "HFC-S PCI A ISDN card 2 [TE] layer 1 ACTIVATED (F7)" AMI/CCS

           7 ZTHFC3/0/1 Clear (In use)
           8 ZTHFC3/0/2 Clear (In use)
           9 ZTHFC3/0/3 HDLCFCS (In use)

Folgendes Problem:
Mit dem ISDN ZAP-Telefon nehme ich ein Gespräch an. Jetzt habe ich eine Rückfrage, nutze also entsprechend das ISDN-Merkmal am Telefon. Neue Leitung ist da.
Wenn ich jetzt eine gültige Nummer anrufe, jemand abnimmt und ich mit ihm spreche, dann kann ich wunderbar zwischen beiden Gesprächen makeln. Ich kann sogar auflegen und die beiden Gespräche werden per ECT-Merkmal miteinander verbunden.

Das Problem tritt auf, wenn ich eine falsche Nummer oder gar keine Nummer wähle, oder aber niemand abnimmt.
Denn dann kann man am Telefon so etwas wie "ZURÜCK" drücken.
Dabei wird offenbar gemäß BRI-Debug folgendes vom Telefon gesendet:

Code: 
1 < Protocol Discriminator: Q.931 (8)  len=8
1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
1 < [B][COLOR="Red"]Message type: DISCONNECT (69)[/COLOR][/B]
1 < [08 02 80 9f]er*CLI>
1 < Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: User (0)
1 <                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
1 -- Processing IE 8 (cs0, Cause)
    -- Channel 0/2, span 1 got hangup request
    -- Channel Zap/5-1 removed from hold.
    -- Stopped music on hold on Zap/5-1
    -- Channel Zap/5-1 removed from hold.
    -- Hungup 'Zap/5-1'>
1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Active, peerstate Connect Request
1 > Protocol Discriminator: Q.931 (8)  len=8
1 > Call Ref: len= 1 (reference 12/0xC) (Originator)
1 > Message type: DISCONNECT (69)
1 > [08 02 81 9f]
1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
1 >                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Disconnect Indication, peerstate Disconnect Request
1 > Protocol Discriminator: Q.931 (8)  len=8
1 > Call Ref: len= 1 (reference 129/0x81) (Terminator)
1 > Message type: RELEASE (77)
1 > [08 02 81 9f]
1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
1 >                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
    -- Hungup 'Zap/2-1'
1 < Protocol Discriminator: Q.931 (8)  len=4
1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
1 < Message type: RELEASE COMPLETE (90)
1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
1 NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null
1 < Protocol Discriminator: Q.931 (8)  len=4
1 < Call Ref: len= 1 (reference 140/0x8C) (Terminator)
1 < Message type: RELEASE (77)
1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Release Request
1 > Protocol Discriminator: Q.931 (8)  len=8
1 > Call Ref: len= 1 (reference 12/0xC) (Originator)
1 > Message type: RELEASE COMPLETE (90)
1 > [08 02 81 9f]
1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
1 >                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
1 NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null

Das ist das gleiche Signal, wie wenn man am Telefon auflegt. Offenbar wird dieses Signal dann gesendet, wenn man noch kein neues Gespräch erfolgreich aufgebaut hat, man aber bereits zum gehaltenen Gespräch zurückkehren möchte.

Leider werden aber beide Gespräche beendet, anstatt das das vorige Gespräch wieder am Telefon landet.

Ist natürlich ziemlich ungeschickt, wenn ich jemanden per Rückfrage weiterleiten möchte, dort niemanden erreiche und dann meinen ursprünglichen Gesprächspartner ins Nirvana schicke...

Sinnvoll wäre doch, dass nur das neu aufzubauende Gespräch (Noch im Status "Setup") abgebrochen wird und ich beim Erst-Gespräch wieder lande.

Ließ sich mit mehreren unterschiedlichen Telefonen reproduzieren.

Habe ich irgendwas falsch konfiguriert, oder weiß irgend jemand einen Weg für Abhilfe? Wenn das ein Bug ist, wo am Besten absetzen?

Das wars schon.
Danke im voraus für Kommentare/Anregungen/Lösungen.

R.Oldenburg
 
Ich sehe, dass auf Dein DISCONNECT auch noch ein DISCONNECT von draussen reinkommt. Das ist seltsam.

Damit wir mal die CRs (Callreferenzen) zusammenbekommen: Kannst Du mal die _komplette_ Sequenz aufzeichnen? SETUP 1, HOLD, SETUP 2, DISCONNECT...etc.

Grüsse
 
OK, hier also ein Mitschnitt.
Habe mit einem SIP-Phone das ISDN-Phone angerufen, das Gespräch dann auf dem ISDN-Phone on HOLD gelegt und kein neues Gespräch aufgebaut, sondern wieder auf "ZURÜCK" gedrückt.

Mitschnitt beginnt bei dem Drücken der "Rückfrage" auf den ISDN-Phone. Endet nach dem ungewollten Trennen aller Gespräche.
Habe den FreePBX-eigenen Mysql-Kram, usw. so gut es ging rausgefiltert.

Code: 
Mar 29 08:27:40 DEBUG[28549] chan_sip.c: update_call_counter(33) - decrement call limit counter
Mar 29 08:27:40 DEBUG[25713] chan_sip.c: Stopping retransmission on 'a5783457af358800M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.' of Response 2: Match Not Found
Mar 29 08:27:40 DEBUG[25713] chan_sip.c: Auto destroying call '[email protected]'
Mar 29 08:27:47 DEBUG[25713] chan_sip.c: Auto destroying call '262e9b110013fe09M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.'
Mar 29 08:27:48 DEBUG[25713] chan_sip.c: Setting NAT on RTP to 0
Mar 29 08:27:48 DEBUG[25713] chan_sip.c: Stopping retransmission on '9410bd7df854fa16M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.' of Response 1: Match Found
Mar 29 08:27:48 DEBUG[25713] chan_sip.c: Setting NAT on RTP to 0
Mar 29 08:27:48 DEBUG[25713] chan_sip.c: Checking SIP call limits for device 33
Mar 29 08:27:48 DEBUG[25713] chan_sip.c: build_route: Contact hop: <sip:[email protected]:59140>
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Macro("SIP/33-081fbd58", "exten-vm|novm|10") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Macro("SIP/33-081fbd58", "user-callerid") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing GotoIf("SIP/33-081fbd58", "0?report") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing GotoIf("SIP/33-081fbd58", "0?start") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "REALCALLERIDNUM=33") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing NoOp("SIP/33-081fbd58", "REALCALLERIDNUM is 33") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "AMPUSER=33") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "AMPUSERCIDNAME=Roland SIP") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing GotoIf("SIP/33-081fbd58", "0?report") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "CALLERID(all)=Roland SIP <33>") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "REALCALLERIDNUM=33") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing NoOp("SIP/33-081fbd58", "Using CallerID "Roland SIP" <33>") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "FROMCONTEXT=exten-vm") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "VMBOX=novm") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "EXTTOCALL=10") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "CFUEXT=") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Set("SIP/33-081fbd58", "RT=") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing Macro("SIP/33-081fbd58", "record-enable|10|IN") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing GotoIf("SIP/33-081fbd58", "0 > 0?2:4") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Goto (macro-record-enable,s,4)
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Executing DeadAGI("SIP/33-081fbd58", "recordingcheck|20070329-082748|asterisk-25688-1175149668.118") in new stack
Mar 29 08:27:48 VERBOSE[28558] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Mar 29 08:27:49 VERBOSE[28558] logger.c:   recordingcheck|20070329-082748|asterisk-25688-1175149668.118: Inbound recording not enabled
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- AGI Script recordingcheck completed, returning 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Executing NoOp("SIP/33-081fbd58", "No recording needed") in new stack
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Executing GotoIf("SIP/33-081fbd58", "0?dolocaldial|1") in new stack
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Executing Macro("SIP/33-081fbd58", "dial||Ttb|10") in new stack
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Executing DeadAGI("SIP/33-081fbd58", "dialparties.agi") in new stack
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Mar 29 08:27:49 VERBOSE[28558] logger.c:   dialparties.agi: Starting New Dialparties.agi
Mar 29 08:27:49 VERBOSE[28558] logger.c:     --  dialparties.agi: priority is 1
Mar 29 08:27:49 VERBOSE[28558] logger.c:   dialparties.agi: Caller ID name is 'Roland SIP' number is '33'
Mar 29 08:27:49 VERBOSE[28558] logger.c:   dialparties.agi: Methodology of ring is  'none'
Mar 29 08:27:49 VERBOSE[28558] logger.c:     --  dialparties.agi: Added extension 10 to extension map
Mar 29 08:27:49 VERBOSE[28558] logger.c:     --  dialparties.agi: Extension 10 cf is disabled
Mar 29 08:27:49 VERBOSE[28558] logger.c:     --  dialparties.agi: Extension 10 do not disturb is disabled
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: extnum: 10
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: exthascw: 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: exthascfb: 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: extcfb: 
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: exthascfu: 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: extcfu: 
Mar 29 08:27:49 VERBOSE[28562] logger.c:   == Manager 'admin' logged on from 127.0.0.1
Mar 29 08:27:49 VERBOSE[28562] logger.c:   == Manager 'admin' logged off from 127.0.0.1
Mar 29 08:27:49 VERBOSE[28558] logger.c:        >  dialparties.agi: ExtensionState: 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:   dialparties.agi: Extension 10 has ExtensionState: 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:     --  dialparties.agi: Checking CW and CFB status for extension 10
Mar 29 08:27:49 VERBOSE[28558] logger.c:     --  dialparties.agi: DbSet CALLTRACE/10 to 33
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- AGI Script dialparties.agi completed, returning 0
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Executing Dial("SIP/33-081fbd58", "ZAP/g1/10||Ttb") in new stack
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 -- Making new call for cr 146
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Requested transfer capability: 0x00 - SPEECH
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=39
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Call Ref: len= 1 (reference 18/0x12) (Originator)
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Message type: SETUP (5)
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > [04 03 80 90 a3]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Bearer Capability (len= 5) [ Ext: 1  Q.931 Std: 0  Info transfer capability: Speech (0)
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 >                              Ext: 1  Trans mode/rate: 64kbps, circuit-mode (16)
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 >                              Ext: 1  User information layer 1: A-Law (35)
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > [18 01 89]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Channel ID (len= 3) [ Ext: 1  IntID: Implicit, Other Spare: 0, Exclusive Dchan: 0
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 >                        ChanSel: B1 channel
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1                          ]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > [28 0a 52 6f 6c 61 6e 64 20 53 49 50]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Display (len=10) [ Roland SIP ]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > [6c 04 00 80 33 33]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Calling Number (len= 6) [ Ext: 0  TON: Unknown Number Type (0)  NPI: Unknown Number Plan (0)
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 >                           Presentation: Presentation permitted, user number not screened (0) '33' ]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > [70 03 80 31 30]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > Called Number (len= 5) [ Ext: 1  TON: Unknown Number Type (0)  NPI: Unknown Number Plan (0) '10' ]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > [7d 02 91 81]
Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > High-layer compatibilty (len= 4) [ Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > High-layer compatibilty (len= 4) [ 1 0x91 Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > High-layer compatibilty (len= 4) [ 1 0x91 1 0x81 Mar 29 08:27:49 VERBOSE[28558] logger.c: 1 > High-layer compatibilty (len= 4) [ 1 0x91 1 0x81 1  ]
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Called g1/10
Mar 29 08:27:49 DEBUG[25692] channel.c: Avoiding initial deadlock for 'Zap/1-1'
Mar 29 08:27:49 VERBOSE[25704] logger.c:   == Primary D-Channel on span 1 up for TEI 64
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 146/0x92) (Terminator)
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Message type: ALERTING (1)
Mar 29 08:27:49 VERBOSE[28558] logger.c:     -- Zap/1-1 is ringing
Mar 29 08:27:49 VERBOSE[25704] logger.c:   == Primary D-Channel on span 1 up for TEI 65
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=8
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 146/0x92) (Terminator)
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Message type: RELEASE COMPLETE (90)
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < [08 02 80 92]
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 < Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: User (0)
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 <                  Ext: 1  Cause: No user responding (18), class = Normal Event (1) ]
Mar 29 08:27:49 VERBOSE[25704] logger.c: 1 -- Processing IE 8 (cs0, Cause)
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=10
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 146/0x92) (Terminator)
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 < Message type: CONNECT (7)
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 < [4c 04 01 80 31 30]
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 < COLP (len= 6) [ Ext: 0  TON: Unknown Number Type (0)  NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1)
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 <                           Presentation: Presentation permitted, user number not screened (0) '10' ]
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 -- Processing IE 76 (cs0, Connect Line ID Presentation)
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=4
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 18/0x12) (Originator)
Mar 29 08:27:51 VERBOSE[25704] logger.c: 1 > Message type: CONNECT ACKNOWLEDGE (15)
Mar 29 08:27:51 DEBUG[25704] chan_zap.c: Enabled echo cancellation on channel 1
Mar 29 08:27:51 DEBUG[25704] chan_zap.c: No echo training requested
Mar 29 08:27:51 VERBOSE[28558] logger.c:     -- Zap/1-1 answered SIP/33-081fbd58
Mar 29 08:27:51 DEBUG[25713] chan_sip.c: Stopping retransmission on '9410bd7df854fa16M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.' of Response 2: Match Found
Mar 29 08:27:56 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 08:27:56 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 146/0x92) (Terminator)
Mar 29 08:27:56 VERBOSE[25704] logger.c: 1 < Message type: HOLD (36)
Mar 29 08:27:56 DEBUG[25704] channel.c: Planning to masquerade channel SIP/33-081fbd58 into the structure of Onhold/SIP/33-081fbd58
Mar 29 08:27:56 DEBUG[25704] channel.c: Done planning to masquerade channel SIP/33-081fbd58 into the structure of Onhold/SIP/33-081fbd58
Mar 29 08:27:56 DEBUG[25704] channel.c: Got clone lock for masquerade on 'SIP/33-081fbd58' at 0x8198c24
Mar 29 08:27:56 DEBUG[25704] channel.c: Putting channel SIP/33-081fbd58 in 64/64 formats
Mar 29 08:27:56 DEBUG[25704] channel.c: Released clone lock on 'Onhold/SIP/33-081fbd58<ZOMBIE>'
Mar 29 08:27:56 DEBUG[25704] channel.c: Done Masquerading SIP/33-081fbd58 (6)
Mar 29 08:27:56 VERBOSE[25704] logger.c:     -- Started music on hold, class 'default', on channel 'SIP/33-081fbd58'
Mar 29 08:27:56 DEBUG[25704] channel.c: Scheduling timer at 160 sample intervals
Mar 29 08:27:56 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=4
Mar 29 08:27:56 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 18/0x12) (Originator)
Mar 29 08:27:56 VERBOSE[25704] logger.c: 1 > Message type: HOLD ACKNOWLEDGE (40)
Mar 29 08:27:56 DEBUG[28558] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=Onhold/SIP/33-081fbd58<ZOMBIE>, c1=Zap/1-1, flags: Yes,Yes,No,No
Mar 29 08:27:56 DEBUG[28558] channel.c: Bridge stops bridging channels Onhold/SIP/33-081fbd58<ZOMBIE> and Zap/1-1
Mar 29 08:27:56 DEBUG[28558] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
Mar 29 08:27:57 DEBUG[28558] chan_zap.c: Hangup: channel: 1 index = 0, normal = 16, callwait = -1, thirdcall = -1
Mar 29 08:27:57 DEBUG[28558] chan_zap.c: disabled echo cancellation on channel 1
Mar 29 08:27:57 DEBUG[28558] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Mar 29 08:27:57 DEBUG[28558] chan_zap.c: Updated conferencing on 1, with 0 conference users
Mar 29 08:27:57 DEBUG[28558] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
Mar 29 08:27:57 DEBUG[28558] chan_zap.c: disabled echo cancellation on channel 1
Mar 29 08:27:57 VERBOSE[28558] logger.c:     -- Hungup 'Zap/1-1'
Mar 29 08:27:57 DEBUG[28558] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Mar 29 08:27:57 VERBOSE[28558] logger.c:   == Spawn extension (macro-dial, s, 10) exited non-zero on 'Onhold/SIP/33-081fbd58<ZOMBIE>' in macro 'dial'
Mar 29 08:27:57 VERBOSE[28558] logger.c:   == Spawn extension (macro-dial, s, 10) exited non-zero on 'Onhold/SIP/33-081fbd58<ZOMBIE>' in macro 'exten-vm'
Mar 29 08:27:57 VERBOSE[28558] logger.c:   == Spawn extension (macro-dial, s, 10) exited non-zero on 'Onhold/SIP/33-081fbd58<ZOMBIE>'
Mar 29 08:27:57 DEBUG[25698] channel.c: Generator got voice, switching to phase locked mode
Mar 29 08:27:57 DEBUG[25698] channel.c: Scheduling timer at 0 sample intervals
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=19
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < Message type: SETUP (5)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < [04 03 80 90 a3]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < Bearer Capability (len= 5) [ Ext: 1  Q.931 Std: 0  Info transfer capability: Speech (0)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 <                              Ext: 1  Trans mode/rate: 64kbps, circuit-mode (16)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 <                              Ext: 1  User information layer 1: A-Law (35)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < [6c 04 01 80 31 30]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < Calling Number (len= 6) [ Ext: 0  TON: Unknown Number Type (0)  NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 <                           Presentation: Presentation permitted, user number not screened (0) '10' ]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < [7d 02 91 81]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ 1 0x91 Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ 1 0x91 1 0x81 Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ 1 0x91 1 0x81 1  ]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 -- Making new call for cr 1
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 -- Processing Q.931 Call Setup
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 -- Processing IE 4 (cs0, Bearer Capability)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 -- Processing IE 108 (cs0, Calling Party Number)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 -- Processing IE 125 (cs0, High-layer Compatibility)
Mar 29 08:27:57 DEBUG[25704] chan_zap.c: Found empty available channel 0/2
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=11
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 129/0x81) (Terminator)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > Message type: SETUP ACKNOWLEDGE (13)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > [18 01 8a]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > Channel ID (len= 3) [ Ext: 1  IntID: Implicit, Other Spare: 0, Exclusive Dchan: 0
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 >                        ChanSel: B2 channel
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1                          ]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > [1e 02 81 88]
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 > Progress Indicator (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 08:27:57 VERBOSE[25704] logger.c: 1 >                               Ext: 1  Progress Description: Inband information or appropriate pattern now available. (8) ]
Mar 29 08:27:57 DEBUG[25704] chan_zap.c: Enabled echo cancellation on channel 2
Mar 29 08:27:57 VERBOSE[25704] logger.c:     -- Accepting overlap voice call from '10' to '<unspecified>' on channel 0/2, span 1
Mar 29 08:27:57 VERBOSE[28570] logger.c:     -- Starting simple switch on 'Zap/2-1'
Mar 29 08:27:59 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=8
Mar 29 08:27:59 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
Mar 29 08:27:59 VERBOSE[25704] logger.c: 1 < Message type: DISCONNECT (69)
Mar 29 08:27:59 VERBOSE[25704] logger.c: 1 < [08 02 80 9f]
Mar 29 08:27:59 VERBOSE[25704] logger.c: 1 < Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: User (0)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 <                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 -- Processing IE 8 (cs0, Cause)
Mar 29 08:28:00 VERBOSE[25704] logger.c:     -- Channel 0/2, span 1 got hangup request
Mar 29 08:28:00 NOTICE[25704] chan_zap.c: killing channel asterisk-25688-1175149668.118 
Mar 29 08:28:00 VERBOSE[25704] logger.c:     -- Channel SIP/33-081fbd58 removed from hold.
Mar 29 08:28:00 VERBOSE[25704] logger.c:     -- Stopped music on hold on SIP/33-081fbd58
Mar 29 08:28:00 DEBUG[25704] channel.c: Scheduling timer at 0 sample intervals
Mar 29 08:28:00 VERBOSE[25704] logger.c:     -- Channel SIP/33-081fbd58 removed from hold.
Mar 29 08:28:00 DEBUG[25704] chan_sip.c: update_call_counter(33) - decrement call limit counter
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Active, peerstate Connect Request
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=8
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 18/0x12) (Originator)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Message type: DISCONNECT (69)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > [08 02 81 9f]
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 >                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: waitfordigit returned < 0...
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: Hangup: channel: 2 index = 0, normal = 17, callwait = -1, thirdcall = -1
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Disconnect Indication, peerstate Disconnect Request
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=8
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 > Call Ref: len= 1 (reference 129/0x81) (Terminator)
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 > Message type: RELEASE (77)
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 > [08 02 81 9f]
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 08:28:00 VERBOSE[28570] logger.c: 1 >                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: disabled echo cancellation on channel 2
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: Updated conferencing on 2, with 0 conference users
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
Mar 29 08:28:00 DEBUG[28570] chan_zap.c: disabled echo cancellation on channel 2
Mar 29 08:28:00 VERBOSE[28570] logger.c:     -- Hungup 'Zap/2-1'
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 < Message type: RELEASE COMPLETE (90)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null
Mar 29 08:28:00 DEBUG[25713] chan_sip.c: Stopping retransmission on '9410bd7df854fa16M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.' of Request 102: Match Found
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 146/0x92) (Terminator)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 < Message type: RELEASE (77)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Release Request
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=8
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 18/0x12) (Originator)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Message type: RELEASE COMPLETE (90)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > [08 02 81 9f]
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 >                  Ext: 1  Cause: Normal, unspecified (31), class = Normal Event (1) ]
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
Mar 29 08:28:00 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null

Tja...
Ich bin ja gespannt. Danke schonmal fürs Interesse.

Grüße,
R. Oldenburg

P.S.: Habe beim google'n festgestellt, dass es in diesem Bereich scheinbar besonders mit Siemens und Telekom(auch oft verkapptes Siemens) ISDN-Geräten Probleme beim Makeln mit ZAP gibt.
 
Total verrückt...
Habe gerade mal ein T Europa 10 ausprobiert. (Diesmal also kein Siemens!)
Und tadaa. Makeln beginnen und schnell wieder beenden funzt!

Hier der Mitschnitt des gleichen Szenarios wie oben mit dem Europa-Phone.

Code: 
Mar 29 09:07:44 VERBOSE[25704] logger.c: 1 < COLP (len= 6) [ Ext: 0  TON: Unknown Number Type (0)  NPI: Unknown Number Plan (0)
Mar 29 09:07:44 VERBOSE[25704] logger.c: 1 <                           Presentation: Presentation permitted, user number not screened (0) '11' ]
Mar 29 09:07:44 VERBOSE[25704] logger.c: 1 -- Processing IE 76 (cs0, Connect Line ID Presentation)
Mar 29 09:07:44 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=4
Mar 29 09:07:44 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 21/0x15) (Originator)
Mar 29 09:07:44 VERBOSE[25704] logger.c: 1 > Message type: CONNECT ACKNOWLEDGE (15)
Mar 29 09:07:44 DEBUG[25704] chan_zap.c: Enabled echo cancellation on channel 1
Mar 29 09:07:44 DEBUG[25704] chan_zap.c: No echo training requested
Mar 29 09:07:44 VERBOSE[31110] logger.c:     -- Zap/1-1 answered SIP/33-08200ae0
Mar 29 09:07:44 DEBUG[25713] chan_sip.c: Stopping retransmission on '6e2da40ee2758126M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.' of Response 2: Match Found
Mar 29 09:07:54 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 09:07:54 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 149/0x95) (Terminator)
Mar 29 09:07:54 VERBOSE[25704] logger.c: 1 < Message type: HOLD (36)
Mar 29 09:07:54 DEBUG[25704] channel.c: Planning to masquerade channel SIP/33-08200ae0 into the structure of Onhold/SIP/33-08200ae0
Mar 29 09:07:54 DEBUG[25704] channel.c: Done planning to masquerade channel SIP/33-08200ae0 into the structure of Onhold/SIP/33-08200ae0
Mar 29 09:07:54 DEBUG[25704] channel.c: Got clone lock for masquerade on 'SIP/33-08200ae0' at 0x815243c
Mar 29 09:07:54 DEBUG[25704] channel.c: Putting channel SIP/33-08200ae0 in 64/64 formats
Mar 29 09:07:54 DEBUG[25704] channel.c: Released clone lock on 'Onhold/SIP/33-08200ae0<ZOMBIE>'
Mar 29 09:07:54 DEBUG[25704] channel.c: Done Masquerading SIP/33-08200ae0 (6)
Mar 29 09:07:54 VERBOSE[25704] logger.c:     -- Started music on hold, class 'default', on channel 'SIP/33-08200ae0'
Mar 29 09:07:54 DEBUG[25704] channel.c: Scheduling timer at 160 sample intervals
Mar 29 09:07:54 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=4
Mar 29 09:07:54 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 21/0x15) (Originator)
Mar 29 09:07:54 VERBOSE[25704] logger.c: 1 > Message type: HOLD ACKNOWLEDGE (40)
Mar 29 09:07:54 DEBUG[31110] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=Onhold/SIP/33-08200ae0<ZOMBIE>, c1=Zap/1-1, flags: Yes,Yes,No,No
Mar 29 09:07:54 DEBUG[31110] channel.c: Bridge stops bridging channels Onhold/SIP/33-08200ae0<ZOMBIE> and Zap/1-1
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: Hangup: channel: 1 index = 0, normal = 16, callwait = -1, thirdcall = -1
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: disabled echo cancellation on channel 1
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: Updated conferencing on 1, with 0 conference users
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
Mar 29 09:07:54 DEBUG[31110] chan_zap.c: disabled echo cancellation on channel 1
Mar 29 09:07:54 VERBOSE[31110] logger.c:     -- Hungup 'Zap/1-1'
Mar 29 09:07:54 DEBUG[31110] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Mar 29 09:07:54 VERBOSE[31110] logger.c:   == Spawn extension (macro-dial, s, 10) exited non-zero on 'Onhold/SIP/33-08200ae0<ZOMBIE>' in macro 'dial'
Mar 29 09:07:54 VERBOSE[31110] logger.c:   == Spawn extension (macro-dial, s, 10) exited non-zero on 'Onhold/SIP/33-08200ae0<ZOMBIE>' in macro 'exten-vm'
Mar 29 09:07:54 VERBOSE[31110] logger.c:   == Spawn extension (macro-dial, s, 10) exited non-zero on 'Onhold/SIP/33-08200ae0<ZOMBIE>'
Mar 29 09:07:54 DEBUG[25698] channel.c: Generator got voice, switching to phase locked mode
Mar 29 09:07:54 DEBUG[25698] channel.c: Scheduling timer at 0 sample intervals
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=19
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < Message type: SETUP (5)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < [04 03 80 90 a3]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < Bearer Capability (len= 5) [ Ext: 1  Q.931 Std: 0  Info transfer capability: Speech (0)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 <                              Ext: 1  Trans mode/rate: 64kbps, circuit-mode (16)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 <                              Ext: 1  User information layer 1: A-Law (35)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < [6c 04 00 80 31 31]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < Calling Number (len= 6) [ Ext: 0  TON: Unknown Number Type (0)  NPI: Unknown Number Plan (0)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 <                           Presentation: Presentation permitted, user number not screened (0) '11' ]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < [7d 02 91 81]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ 1 0x91 Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ 1 0x91 1 0x81 Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 < High-layer compatibilty (len= 4) [ 1 0x91 1 0x81 1  ]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 -- Making new call for cr 1
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 -- Processing Q.931 Call Setup
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 -- Processing IE 4 (cs0, Bearer Capability)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 -- Processing IE 108 (cs0, Calling Party Number)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 -- Processing IE 125 (cs0, High-layer Compatibility)
Mar 29 09:07:55 DEBUG[25704] chan_zap.c: Found empty available channel 0/2
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=11
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 129/0x81) (Terminator)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > Message type: SETUP ACKNOWLEDGE (13)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > [18 01 8a]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > Channel ID (len= 3) [ Ext: 1  IntID: Implicit, Other Spare: 0, Exclusive Dchan: 0
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 >                        ChanSel: B2 channel
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1                          ]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > [1e 02 81 88]
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 > Progress Indicator (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 09:07:55 VERBOSE[25704] logger.c: 1 >                               Ext: 1  Progress Description: Inband information or appropriate pattern now available. (8) ]
Mar 29 09:07:55 DEBUG[25704] chan_zap.c: Enabled echo cancellation on channel 2
Mar 29 09:07:55 VERBOSE[25704] logger.c:     -- Accepting overlap voice call from '11' to '<unspecified>' on channel 0/2, span 1
Mar 29 09:07:55 VERBOSE[31123] logger.c:     -- Starting simple switch on 'Zap/2-1'
Mar 29 09:07:57 DEBUG[25713] chan_sip.c: Auto destroying call '[email protected]'
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=8
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Message type: DISCONNECT (69)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < [08 02 80 90]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: User (0)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 <                  Ext: 1  Cause: Normal Clearing (16), class = Normal Event (1) ]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 -- Processing IE 8 (cs0, Cause)
Mar 29 09:07:58 VERBOSE[25704] logger.c:     -- Channel 0/2, span 1 got hangup request
Mar 29 09:07:58 NOTICE[25704] chan_zap.c: killing channel asterisk-25688-1175152061.135 
Mar 29 09:07:58 VERBOSE[25704] logger.c:     -- Channel SIP/33-08200ae0 removed from hold.
Mar 29 09:07:58 VERBOSE[25704] logger.c:     -- Stopped music on hold on SIP/33-08200ae0
Mar 29 09:07:58 DEBUG[25704] channel.c: Scheduling timer at 0 sample intervals
Mar 29 09:07:58 VERBOSE[25704] logger.c:     -- Channel SIP/33-08200ae0 removed from hold.
Mar 29 09:07:58 DEBUG[25704] chan_sip.c: update_call_counter(33) - decrement call limit counter
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Active, peerstate Connect Request
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=23
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 21/0x15) (Originator)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Message type: DISCONNECT (69)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > [08 02 81 90]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 >                  Ext: 1  Cause: Normal Clearing (16), class = Normal Event (1) ]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > [1c 0d 91 a1 0a 02 01 02 02 01 24 30 02 81 00]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Facility (len=15, codeset=0) [ Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Facility (len=15, codeset=0) [ 1 0x91, 0xa1, 0x0a, 0x02, 0x01, 0x02, 0x02, 0x01, 0x24, '0', 0x02, 0x81, 0x00Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Facility (len=15, codeset=0) [ 1 0x91, 0xa1, 0x0a, 0x02, 0x01, 0x02, 0x02, 0x01, 0x24, '0', 0x02, 0x81, 0x001  ]
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: waitfordigit returned < 0...
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: Hangup: channel: 2 index = 0, normal = 17, callwait = -1, thirdcall = -1
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: Not yet hungup...  Calling hangup once with icause, and clearing call
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Disconnect Indication, peerstate Disconnect Request
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=8
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 > Call Ref: len= 1 (reference 129/0x81) (Terminator)
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 > Message type: RELEASE (77)
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 > [08 02 81 90]
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 09:07:58 VERBOSE[31123] logger.c: 1 >                  Ext: 1  Cause: Normal Clearing (16), class = Normal Event (1) ]
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: disabled echo cancellation on channel 2
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/2-1
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: Updated conferencing on 2, with 0 conference users
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
Mar 29 09:07:58 DEBUG[31123] chan_zap.c: disabled echo cancellation on channel 2
Mar 29 09:07:58 VERBOSE[31123] logger.c:     -- Hungup 'Zap/2-1'
Mar 29 09:07:58 DEBUG[25713] chan_sip.c: Stopping retransmission on '6e2da40ee2758126M2Y4ZjU1MmNjMmQ4ZTgzYzIyYWQyMTNlYTBlMmFlNGY.' of Request 102: Match Found
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 1/0x1) (Originator)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Message type: RELEASE COMPLETE (90)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Protocol Discriminator: Q.931 (8)  len=4
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Call Ref: len= 1 (reference 149/0x95) (Terminator)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 < Message type: RELEASE (77)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Release Request
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Protocol Discriminator: Q.931 (8)  len=8
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Call Ref: len= 1 (reference 21/0x15) (Originator)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Message type: RELEASE COMPLETE (90)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > [08 02 81 90]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 > Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0) 0: 0   Location: Private network serving the local user (1)
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 >                  Ext: 1  Cause: Normal Clearing (16), class = Normal Event (1) ]
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
Mar 29 09:07:58 VERBOSE[25704] logger.c: 1 NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null

Ich kann da nix mehr erkennen...
RO
 
Also vom Trace her zeigen beide ein identisches Verhalten. Und in beiden Fällen verhält sich das Gerät, welches als NT agiert (Asterisk?) m.M.n. falsch.

Hier mal die Analyse des ersten Traces (wie gesagt, der zweite ist an der entscheidenden Stelle genauso falsch)

Ich sehe zwei Devices als TE, eine operiert an TEI 64, die andere an TEI 65

Code: 
NT                                TE1                             TE2
SETUP CR 12
                                  ALERTING CR 12
                                                                  REL_COMP CR 12
                                  CONNECT CR 12
CONNECT_ACK CR 12
                                  HOLD CR 12
HOLD_ACK CR 12
                                  SETUP CR 1 (B2)
SETUP_ACK CR 1
                                  DISCONNECT CR 1
[B]DISCONNECT CR 12[/B]       
RELEASE CR 1
                                  RELEASE_COMPL CR 1
                                  RELEASE CR 12
RELEASE_COMPL CR 12

Das RELEASE_COMPL von der zweiten TE ist m.E.n. OK. Das Gerät sagt einfach, dass es damit nichts zu tun hat.

Der Problembär ist das DISCONNECT CR 12, welches auf den Rückfall vom NT gesandt wird. Meiner Meinung nach MUSS der NT hier die Füsse still halten und auf das RESUME CR 12 von TE 1 warten, mit der der HOLD CR 12 aufgelöst werden würde.

Das Fehlverhalten ist auch im zweiten Trace zu erkennen.

Ich hoffe, ich habe nicht allzu falsch interpretiert. Meine ISDN Zeit liegt jetzt auch schon wieder 7 Jahre zurück....

PS: Bis auf das unerwartete DISCONNECT CR 12 ist alles andere absolut korrekt und protokollkonform.
Grüsse
 
Zuletzt bearbeitet:
Du hast recht... Jetzt wo ich es noch ein paar mal probiert hab, löppt das mit keinem Tel. mehr. Merkwürding. Vorhin, meine ich, hat es gefunzt.

Frage: Was jetzt?
Offenbar verhält sich ZapHFC im NT Modus nicht vollkommen Protokoll-Konform...

Wohin mit dieser Meldung?
Wo ist das entsprechende Bugtracking-Tool zu finden? Kann ich da einfach rein und einen Bug hinterlegen? Gibt es den vielleicht schon?
Und vielleicht kannst Du mir bei der konkreten technischen Formulierung helfen?

Grüße,
RO
 
Ja, ich weiss leider auch nicht, wohin Du Dich mit Deiner Fehlermeldung wenden kannst, denn ich nutze das nicht.

Für die korrekte technische Formulierung: Einfach den ersten Trace einschicken, kurz die "externen Handlungen" schildern und behaupten, dass das DISCONNECT auf Callreferenz 0x12 AUF KEINEN FALL an dieser Stelle vom NT (von dem besagten Programm) geschickt werden darf. Vielmehr MUSS die CR 0x12 weiterhin im Status HOLD verbleiben, bis das die TE die Verbindung mittels RESUME wieder aufnimmt oder selbst per DISCONNECT terminiert.

Grüsse
 
Da es sich anscheinend um einen Fehler im bristuff handelt, wäre wohl eine Fehlermeldung an Junghanns sinnvoll, am besten mit den Logs von oben und evtl. der Analyse von spongebob.
 
Danke nochmal euch allen.
Habe den Fehler an Junghanns gemeldet.

Bin gespannt.
Übrigens: Man hat mir bei denen am Telefon gesagt, dass es bald ein online zugängliches Bugtracking-Tool geben soll.

Man merke sich: http://bristuff.org/

RO
 
Um antworten zu können musst du eingeloggt sein.
Kostenlos!
Jetzt holen

Neueste Beiträge

Kategorien

Wissenswertes

Zurzeit aktive Besucher

Gesamt: 670 (Mitglieder: 31, Gäste: 639)

Statistik des Forums

Themen
248,350
Beiträge
2,288,984
Mitglieder
377,668
Neuestes Mitglied
buckdiefliege

3CX jetzt einen Monat kostenlos testen

Die Verbindung, Zusammenarbeit und Kommunikation mit Ihrem Team und Ihren Kunden war noch nie so einfach. Nutzen Sie unsere kostenlose 30-Tage-Testversion und entdecken Sie die richtige Lösung für Ihr Unternehmen.

3CX start your free trial guy
Für diese E-Mail-Adresse besteht bereits ein 3CX-Konto. Sie werden zum Kundenportal weitergeleitet, wo Sie sich anmelden oder Ihr Passwort zurücksetzen können, falls Sie dieses vergessen haben.
| Style by ThemeHouse
XenPorta 2 PRO © Jason Axelrod of 8WAYRUN
Oben Unten