Hello, i tried to call a phone with the latest snapshot.
The called phone rings for about 3 seconds and is unable to answer the call.
Here's the debug log from asterisk:
vISDN q.931 debugging enabled
q931 visdn2:TEI[98]: DLC autorelease timer fired
q931 visdn2:TEI[98]: DL-RELEASE-CONFIRM
q931 Releasing message
q931 visdn2:TEI[98]: DL-ESTABLISH-INDICATION
q931 visdn2:TEI[98]: DLC autorelease timer stopped
q931 visdn2:TEI[98]: DLC autorelease timer started
q931 Releasing message
q931 visdn2:TEI[99]: DLC autorelease timer fired
q931 visdn2:TEI[99]: DL-RELEASE-CONFIRM
q931 Releasing message
q931 visdn2:TEI[99]: DL-ESTABLISH-INDICATION
q931 visdn2:TEI[99]: DLC autorelease timer stopped
q931 visdn2:TEI[99]: DLC autorelease timer started
q931 Releasing message
q931 visdn2:TEI[98]: Received message:
q931 <- call reference = 1.I (len 1)
q931 <- message_type = SETUP (5)
q931 visdn2:TEI[98]: DLC autorelease timer stopped
q931 visdn2:CALL[1.I]: call.c:277 GET (1 => 2)
q931 visdn2:CALL[1.I]: Got SETUP
q931 <- VL IE 1 ===> 4 (Bearer Capability) length=(3)
q931 <- Coding Standard = CCITT (0)
q931 <- Information Transfer Capability = Speech (0)
q931 <- Transfer mode = Circuit (0)
q931 <- Information Transfer Rate = 64 kbps (16)
q931 <- User information layer 1 protocol = g.711 a-law (3)
q931 <- VL IE 2 ===> 24 (Channel Identification) length=(1)
q931 <- Interface id = Implicit (0)
q931 <- Interface type = Basic (0)
q931 <- Pref/Excl = Preferred (0)
q931 <- D channel ident = Is not D channel (0)
q931 <- Coding standard = CCITT (0)
q931 <- Channels = B1
q931 <- VL IE 3 ===> 108 (Calling Party Number) length=(8)
q931 <- Type of number = Unknown (0)
q931 <- Numbering plan = ISDN Telephony (1)
q931 <- Presentation indicator = Presentation allowed (0)
q931 <- Screening indicator = User provided, not screened (0)
q931 <- Number = 11
q931 <- VL IE 4 ===> 112 (Called Party Number) length=(8)
q931 <- Type of number = Unknown (0)
q931 <- Numbering plan = ISDN Telephony (1)
q931 <- Number = 12
q931 <- VL IE 5 ===> 125 (High Layer Compatibility) length=(2)
q931 <- Coding standard = CCITT (0)
q931 <- Characteristics identification = Telephony (1)
q931 visdn2:CALL[1.I]: Requested channel B1 available
q931 visdn2[B1]: changed state from AVAILABLE to SELECTED
q931 visdn2:CALL[1.I]: N0_NULL_STATE ==to==> N1_CALL_INITIATED
q931 visdn2:CALL[1.I]: chan_visdn.c:372 GET (2 => 3)
q931
q931 visdn2:CALL[1.I]: input.c:1210 PUT (3 => 2)
q931 visdn2:TEI[98]: Releasing message
q931 visdn2:CALL[1.I]: chan_visdn.c:3229 GET (2 => 3)
q931 visdn2:CALL[1.I]: chan_visdn.c:338 GET (3 => 4)
q931 visdn2:CALL[1.I]: chan_visdn.c:4331 PUT (4 => 3)
q931 visdn2:CALL[1.I]: MORE-INFO-REQ
q931 visdn2:CALL[1.I]: call.c:393 GET (3 => 4)
q931 visdn2:CALL[1.I]: call.c:1375 Timer T302 started
q931 visdn2:CALL[1.I]: Sending message:
q931 -> message type: SETUP ACKNOWLEDGE (13)
q931 -> VL IE 0 ===> 24 (Channel Identification) -- length 1
q931 -> Interface id = Implicit (0)
q931 -> Interface type = Basic (0)
q931 -> Pref/Excl = Exclusive (1)
q931 -> D channel ident = Is not D channel (0)
q931 -> Coding standard = CCITT (0)
q931 -> Channels = B1
q931 -> VL IE 1 ===> 30 (Progress Indicator) -- length 2
q931 -> Coding standard = CCITT (0)
q931 -> Location = Private network serving local user (1)
q931 -> Description = In-band information or appropriate pattern now
available (8)
q931
q931 visdn2:TEI[98]: Releasing message
q931 visdn2[B1]: changed state from SELECTED to CONNECTED
q931 visdn2:CALL[1.I]: N1_CALL_INITIATED ==to==> N2_OVERLAP_SENDING
q931 visdn2:CALL[1.I]: chan_visdn.c:2234 PUT (4 => 3)
-- Executing VISDNOverlapDial("VISDN/visdn2/1.I", "") in new stack
q931 visdn2:TEI[99]: DLC autorelease timer fired
q931 visdn2:TEI[99]: DL-RELEASE-CONFIRM
q931 visdn2:CALL[1.I]: input.c:119 GET (3 => 4)
q931 visdn2:CALL[1.I]: input.c:131 PUT (4 => 3)
q931 Releasing message
q931 visdn2:TEI[99]: DL-ESTABLISH-INDICATION
q931 visdn2:TEI[99]: DLC autorelease timer stopped
q931 visdn2:TEI[99]: DLC autorelease timer started
q931 visdn2:CALL[1.I]: input.c:92 GET (3 => 4)
q931 visdn2:CALL[1.I]: input.c:104 PUT (4 => 3)
q931 Releasing message
q931 visdn2:CALL[1.I]: T302 fired
q931 visdn2:CALL[1.I]: chan_visdn.c:372 GET (3 => 4)
q931 visdn2:CALL[1.I]: call.c:2701 PUT (4 => 3)
q931 visdn2:CALL[1.I]: chan_visdn.c:338 GET (3 => 4)
q931 visdn2:CALL[1.I]: chan_visdn.c:4331 PUT (4 => 3)
q931 visdn2:CALL[1.I]: PROCEEDING-REQ
q931 visdn2:CALL[1.I]: call.c:1524 Timer T302 stopped
q931 visdn2:CALL[1.I]: Sending message:
q931 -> message type: CALL PROCEEDING (2)
q931
q931 visdn2:TEI[98]: Releasing message
q931 visdn2:CALL[1.I]: N2_OVERLAP_SENDING ==to==>
N3_OUTGOING_CALL_PROCEEDING
q931 visdn2:CALL[1.I]: chan_visdn.c:2234 PUT (3 => 2)
-- Executing Dial("VISDN/visdn2/1.I", "VISDN/visdn2/12") in new stack
q931 visdn2:CALL[116.O]: call.c:311 GET (1 => 2)
q931 visdn2:CALL[116.O]: chan_visdn.c:803 GET (2 => 3)
q931 visdn2:CALL[116.O]: chan_visdn.c:338 GET (3 => 4)
q931 visdn2:CALL[116.O]: chan_visdn.c:938 PUT (4 => 3)
-- Called visdn2/12
q931 visdn2:CALL[116.O]: SETUP-REQ
q931 visdn2[B2]: changed state from AVAILABLE to SELECTED
q931 visdn2:CALL[116.O]: call.c:393 GET (3 => 4)
q931 visdn2:CALL[116.O]: call.c:1838 Timer T303 started
q931 visdn2:CALL[116.O]: call.c:393 GET (4 => 5)
q931 visdn2:CALL[116.O]: call.c:1867 Timer T312 started
q931 visdn2:CALL[116.O]: Sending message:
q931 visdn2:CALL[116.O]: -> message type: SETUP (5)
q931 -> VL IE 0 ===> 4 (Bearer Capability) -- length 3
q931 -> Coding Standard = CCITT (0)
q931 -> Information Transfer Capability = Speech (0)
q931 -> Transfer mode = Circuit (0)
q931 -> Information Transfer Rate = 64 kbps (16)
q931 -> User information layer 1 protocol = g.711 a-law (3)
q931 -> VL IE 1 ===> 24 (Channel Identification) -- length 1
q931 -> Interface id = Implicit (0)
q931 -> Interface type = Basic (0)
q931 -> Pref/Excl = Exclusive (1)
q931 -> D channel ident = Is not D channel (0)
q931 -> Coding standard = CCITT (0)
q931 -> Channels = B2
q931 -> VL IE 2 ===> 41 (Date Time) -- length 6
q931 -> DateTime = Thu Mar 30 15:51:26 2006
q931 -> VL IE 3 ===> 108 (Calling Party Number) -- length 8
q931 -> Type of number = Unknown (0)
q931 -> Numbering plan = Unknown (0)
q931 -> Presentation indicator = Presentation allowed (0)
q931 -> Screening indicator = User provided, verified and passed (1)
q931 -> Number = 11
q931 -> VL IE 4 ===> 112 (Called Party Number) -- length 8
q931 -> Type of number = Unknown (0)
q931 -> Numbering plan = Unknown (0)
q931 -> Number = 12
q931 -> VL IE 5 ===> 125 (High Layer Compatibility) -- length 2
q931 -> Coding standard = CCITT (0)
q931 -> Characteristics identification = Telephony (1)
q931 -> SO IE 6 ===> 161 (Sending Complete)
q931 visdn2:CALL[116.O]: N0_NULL_STATE ==to==> N6_CALL_PRESENT
q931 visdn2:CALL[116.O]: chan_visdn.c:2234 PUT (5 => 4)
q931 visdn2:TEI[99]: Protocol discriminator 0 not supported, ignoring
message
q931 visdn2:TEI[99]: Releasing message
q931 visdn2:TEI[99]: Protocol discriminator 0 not supported, ignoring
message
q931 visdn2:TEI[99]: Releasing message
q931 visdn2:CALL[116.O]: T303 fired
q931 visdn2:CALL[116.O]: Sending message:
q931 visdn2:CALL[116.O]: -> message type: SETUP (5)
q931 -> VL IE 0 ===> 4 (Bearer Capability) -- length 3
q931 -> Coding Standard = CCITT (0)
q931 -> Information Transfer Capability = Speech (0)
q931 -> Transfer mode = Circuit (0)
q931 -> Information Transfer Rate = 64 kbps (16)
q931 -> User information layer 1 protocol = g.711 a-law (3)
q931 -> VL IE 1 ===> 24 (Channel Identification) -- length 1
q931 -> Interface id = Implicit (0)
q931 -> Interface type = Basic (0)
q931 -> Pref/Excl = Exclusive (1)
q931 -> D channel ident = Is not D channel (0)
q931 -> Coding standard = CCITT (0)
q931 -> Channels = B2
q931 -> VL IE 2 ===> 41 (Date Time) -- length 6
q931 -> DateTime = Thu Mar 30 15:51:26 2006
q931 -> VL IE 3 ===> 108 (Calling Party Number) -- length 8
q931 -> Type of number = Unknown (0)
q931 -> Numbering plan = Unknown (0)
q931 -> Presentation indicator = Presentation allowed (0)
q931 -> Screening indicator = User provided, verified and passed (1)
q931 -> Number = 11
q931 -> VL IE 4 ===> 112 (Called Party Number) -- length 8
q931 -> Type of number = Unknown (0)
q931 -> Numbering plan = Unknown (0)
q931 -> Number = 12
q931 -> VL IE 5 ===> 125 (High Layer Compatibility) -- length 2
q931 -> Coding standard = CCITT (0)
q931 -> Characteristics identification = Telephony (1)
q931 -> SO IE 6 ===> 161 (Sending Complete)
q931 visdn2:CALL[116.O]: call.c:393 GET (4 => 5)
q931 visdn2:CALL[116.O]: call.c:2727 Timer T303 started
q931 visdn2:CALL[116.O]: call.c:2728 Timer T312 restarted
q931 visdn2:CALL[116.O]: call.c:2811 PUT (5 => 4)
q931 visdn2:TEI[99]: DLC autorelease timer fired
q931 visdn2:TEI[99]: DL-RELEASE-CONFIRM
q931 visdn2:CALL[1.I]: input.c:119 GET (2 => 3)
q931 visdn2:CALL[1.I]: input.c:131 PUT (3 => 2)
q931 visdn2:CALL[116.O]: input.c:119 GET (4 => 5)
q931 visdn2:CALL[116.O]: input.c:131 PUT (5 => 4)
q931 Releasing message
q931 visdn2:TEI[99]: DL-ESTABLISH-INDICATION
q931 visdn2:TEI[99]: DLC autorelease timer stopped
q931 visdn2:TEI[99]: DLC autorelease timer started
q931 visdn2:CALL[1.I]: input.c:92 GET (2 => 3)
q931 visdn2:CALL[1.I]: input.c:104 PUT (3 => 2)
q931 visdn2:CALL[116.O]: input.c:92 GET (4 => 5)
q931 visdn2:CALL[116.O]: input.c:104 PUT (5 => 4)
q931 Releasing message
q931 visdn2:CALL[116.O]: T303 fired
q931 visdn2[B2]: changed state from SELECTED to AVAILABLE
q931 visdn2:CALL[116.O]: N6_CALL_PRESENT ==to==> N22_CALL_ABORT
q931 visdn2:CALL[116.O]: chan_visdn.c:372 GET (4 => 5)
q931 visdn2:CALL[116.O]: call.c:2811 PUT (5 => 4)
q931 visdn2:CALL[116.O]: chan_visdn.c:4331 PUT (4 => 3)
q931 visdn2:CALL[116.O]: chan_visdn.c:1852 PUT (3 => 2)
== Everyone is busy/congested at this time (1:0/0/1)
-- Executing Hangup("VISDN/visdn2/1.I", "") in new stack
== Spawn extension (visdn_pbx_in, 12, 2) exited non-zero on
'VISDN/visdn2/1.I'
-- Executing Congestion("VISDN/visdn2/1.I", "") in new stack
q931 visdn2:CALL[1.I]: chan_visdn.c:338 GET (2 => 3)
q931 visdn2:CALL[1.I]: DISCONNECT-REQ
q931 visdn2:CALL[1.I]: Sending message:
q931 -> message type: DISCONNECT (69)
q931 -> VL IE 0 ===> 8 (Cause) -- length 2
q931 -> Coding standard = CCITT (0)
q931 -> Location = Private network serving local user (1)
q931 -> Cause value = Normal call clearing (16)
q931 -> VL IE 1 ===> 30 (Progress Indicator) -- length 2
q931 -> Coding standard = CCITT (0)
q931 -> Location = Private network serving local user (1)
q931 -> Description = In-band information or appropriate pattern now
available (8)
q931
q931 visdn2:TEI[98]: Releasing message
q931 visdn2:CALL[1.I]: call.c:393 GET (3 => 4)
q931 visdn2:CALL[1.I]: call.c:1021 Timer T306 started
q931 visdn2:CALL[1.I]: N3_OUTGOING_CALL_PROCEEDING ==to==>
N12_DISCONNECT_INDICATION
q931 visdn2:CALL[1.I]: chan_visdn.c:2234 PUT (4 => 3)
Mar 30 15:51:34 WARNING[10343]: channel.c:2250 ast_write: Thread -1212884048
Blocking 'VISDN/visdn2/1.I', already blocked by thread -1220346960 in
procedure ast_waitfor_nandfds
q931 visdn2:CALL[116.O]: T312 fired
q931 visdn2:CALL[116.O]: N22_CALL_ABORT ==to==> N0_NULL_STATE
q931 visdn2:CALL[116.O]: call.c:373 PUT (2 => 1)
q931 visdn2:CALL[116.O]: call.c:3257 PUT (1 => 0)
q931 visdn2:CALL[116.O]: Freeing call
q931 visdn2:TEI[98]: Received message:
q931 <- call reference = 1.I (len 1)
q931 <- message_type = RELEASE (77)
q931 visdn2:CALL[1.I]: call.c:421 GET (3 => 4)
q931 visdn2:CALL[1.I]: Got RELEASE
q931 visdn2:CALL[1.I]: call.c:4939 Timer T305 stopped
q931 visdn2:CALL[1.I]: call.c:405 PUT (4 => 3)
q931 visdn2:CALL[1.I]: call.c:4940 Timer T306 stopped
q931 visdn2[B1]: changed state from CONNECTED to AVAILABLE
q931 visdn2:CALL[1.I]: Sending message:
q931 -> message type: RELEASE COMPLETE (90)
q931
q931 visdn2:TEI[98]: Releasing message
q931 visdn2:CALL[1.I]: N12_DISCONNECT_INDICATION ==to==> N0_NULL_STATE
q931 visdn2:CALL[1.I]: call.c:373 PUT (3 => 2)
q931 visdn2:CALL[1.I]: chan_visdn.c:372 GET (2 => 3)
q931
q931 visdn2:CALL[1.I]: input.c:1210 PUT (3 => 2)
q931 visdn2:TEI[98]: Releasing message
q931 visdn2:CALL[1.I]: chan_visdn.c:4331 PUT (2 => 1)
== Spawn extension (visdn_pbx_in, h, 1) exited non-zero on
'VISDN/visdn2/1.I'
q931 visdn2:CALL[1.I]: chan_visdn.c:1852 PUT (1 => 0)
q931 visdn2:CALL[1.I]: Freeing call
Heres the asterisk extension section:
exten => 12,1,Dial(VISDN/visdn2/12)
exten => 12,2,Hangup()
exten => s,1,VISDNOverlapDial()
exten => h,1,Congestion()
bye,
Philipp
_______________________________________________
Visdn-hackers mailing list
[email protected]
https://mailman.uli.it/mailman/listinfo/visdn-hackers
