Erratic trixbox behaviour on incoming SIP (voipcheap) trunk from external POTS

gferguson
Posts: 1
Member Since:
2007-12-12

Hi, I wonder if anyone has the time to review an unusual issue that I have with my trixbox incoming SIP trunk. It took me a while to get it to receive a call on the incoming SIP trunk, but now that I have, it works very occasionally, but it mostly does not.

I'm running FreePBX Framework v2.3.1.1 with Core v2.3.1.2. If any other info is required then please let me know.

Please note that I am a real trixbox newbie, so I'm still in learning mode.

I'm using voipcheap as my SIP provider.
I can make outgoing calls over the SIP trunk - no problem.
Receiving incoming calls over the SIP trunk, big headache.

Here is a step by step diary of my symptoms this evening. Grab a cup of coffee or some tea, this is a weird one.

Note that my first attempt detailed is my first call into the trixbox box since a fresh reboot.

[Attempt 01]
Dialling from a POTS line to the SIP trunk.
I hear ringing on the POTS line handset, sounds good.
No call registered on the x-lite softphone (extension 101).
Call rings out at POTS end.
No detail of incoming call on the ssh console.
I hangup and shrug my shoulders.

I try again.

[Attempt 02]
Dialling from a POTS line to the SIP trunk.
I receive a message tone which infers that the number is not in use.
I hangup.

I check the 'sip show registry' via the Asterisk CLI module. Looks ok.

ion
Host Username Refresh State
sip.voipcheap.co.uk:5060 105 Registered
Verbosity is at least 4

I run an 'amportal restart' and fire up the verbose logging on the ssh console.

[Attempt 03]
Dialling from a POTS line to the SIP trunk.
I hear ringing on the POTS line, sounds good.
Incoming call registers on softphone client ok.
Answer call on softphone and call status is normal- wayhey, success.
Hang up on softphone and call is closed as normal.

Here is my log.

[root@trixbox01 asterisk]# asterisk -rvvvv
== Parsing '/etc/asterisk/asterisk.conf': Found
== Parsing '/etc/asterisk/extconfig.conf': Found
Asterisk 1.2.24 svn rev 79171, Copyright (C) 1999 - 2007 Digium, Inc. and others.
Created by Mark Spencer
Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type 'show license' for details.
=========================================================================
Connected to Asterisk 1.2.24 svn rev 79171 currently running on trixbox01 (pid = 3946)
Verbosity was 1 and is now 4
-- Executing GotoIf("SIP/5060-08d0eae0", "1?from-trunk||1") in new stack
-- Goto (from-trunk,s,1)
-- Executing Set("SIP/5060-08d0eae0", "__FROM_DID=s") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0 ?cidok") in new stack
-- Executing Set("SIP/5060-08d0eae0", "CALLERID(name)=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d0eae0", "CallerID is "00441112223333" ") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d0eae0", "none") in new stack
-- Executing Set("SIP/5060-08d0eae0", "__MOHCLASS=none") in new stack
-- Executing Ringing("SIP/5060-08d0eae0", "") in new stack
-- Executing Goto("SIP/5060-08d0eae0", "from-did-direct|101|1") in new stack
-- Goto (from-did-direct,101,1)
-- Executing Set("SIP/5060-08d0eae0", "__RINGTIMER=10") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "exten-vm|novm|101") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "user-callerid") in new stack
-- Executing NoOp("SIP/5060-08d0eae0", "user-callerid: 00441112223333 00441112223333") in new stack
-- Executing Set("SIP/5060-08d0eae0", "AMPUSER=00441112223333") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?report") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?start") in new stack
-- Executing Set("SIP/5060-08d0eae0", "REALCALLERIDNUM=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d0eae0", "REALCALLERIDNUM is 00441112223333") in new stack
-- Executing Set("SIP/5060-08d0eae0", "AMPUSER=") in new stack
-- Executing Set("SIP/5060-08d0eae0", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing NoOp("SIP/5060-08d0eae0", "TTL: ARG1: novm") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?continue") in new stack
-- Executing Set("SIP/5060-08d0eae0", "__TTL=64") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing NoOp("SIP/5060-08d0eae0", "Using CallerID "00441112223333" ") in new stack
-- Executing Set("SIP/5060-08d0eae0", "FROMCONTEXT=exten-vm") in new stack
-- Executing Set("SIP/5060-08d0eae0", "VMBOX=novm") in new stack
-- Executing Set("SIP/5060-08d0eae0", "EXTTOCALL=101") in new stack
-- Executing Set("SIP/5060-08d0eae0", "CFUEXT=") in new stack
-- Executing Set("SIP/5060-08d0eae0", "CFBEXT=") in new stack
-- Executing Set("SIP/5060-08d0eae0", "RT=") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "record-enable|101|IN") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("SIP/5060-08d0eae0", "recordingcheck|20071212-234737|1197503257.2") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
-- Executing GotoIf("SIP/5060-08d0eae0", "1?from-trunk||1") in new stack
-- Goto (from-trunk,s,1)
-- Executing Set("SIP/5060-08d0eae0", "__FROM_DID=s") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0 ?cidok") in new stack
-- Executing Set("SIP/5060-08d0eae0", "CALLERID(name)=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d0eae0", "CallerID is "00441112223333" ") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d0eae0", "none") in new stack
-- Executing Set("SIP/5060-08d0eae0", "__MOHCLASS=none") in new stack
-- Executing Ringing("SIP/5060-08d0eae0", "") in new stack
-- Executing Goto("SIP/5060-08d0eae0", "from-did-direct|101|1") in new stack
-- Goto (from-did-direct,101,1)
-- Executing Set("SIP/5060-08d0eae0", "__RINGTIMER=10") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "exten-vm|novm|101") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "user-callerid") in new stack
-- Executing NoOp("SIP/5060-08d0eae0", "user-callerid: 00441112223333 00441112223333") in new stack
-- Executing Set("SIP/5060-08d0eae0", "AMPUSER=00441112223333") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?report") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?start") in new stack
-- Executing Set("SIP/5060-08d0eae0", "REALCALLERIDNUM=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d0eae0", "REALCALLERIDNUM is 00441112223333") in new stack
-- Executing Set("SIP/5060-08d0eae0", "AMPUSER=") in new stack
-- Executing Set("SIP/5060-08d0eae0", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing NoOp("SIP/5060-08d0eae0", "TTL: ARG1: novm") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?continue") in new stack
-- Executing Set("SIP/5060-08d0eae0", "__TTL=64") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing NoOp("SIP/5060-08d0eae0", "Using CallerID "00441112223333" ") in new stack
-- Executing Set("SIP/5060-08d0eae0", "FROMCONTEXT=exten-vm") in new stack
-- Executing Set("SIP/5060-08d0eae0", "VMBOX=novm") in new stack
-- Executing Set("SIP/5060-08d0eae0", "EXTTOCALL=101") in new stack
-- Executing Set("SIP/5060-08d0eae0", "CFUEXT=") in new stack
-- Executing Set("SIP/5060-08d0eae0", "CFBEXT=") in new stack
-- Executing Set("SIP/5060-08d0eae0", "RT=") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "record-enable|101|IN") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("SIP/5060-08d0eae0", "recordingcheck|20071212-234737|1197503257.2") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20071212-234737|1197503257.2: Inbound recording not enabled
recordingcheck|20071212-234737|1197503257.2: Inbound recording not enabled
-- AGI Script recordingcheck completed, returning 0
-- Executing NoOp("SIP/5060-08d0eae0", "No recording needed") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "dial||tr|101") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?dial") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d0eae0", "none") in new stack
-- Executing AGI("SIP/5060-08d0eae0", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
-- AGI Script recordingcheck completed, returning 0
-- Executing NoOp("SIP/5060-08d0eae0", "No recording needed") in new stack
-- Executing Macro("SIP/5060-08d0eae0", "dial||tr|101") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "0?dial") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d0eae0", "none") in new stack
-- Executing AGI("SIP/5060-08d0eae0", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Starting New Dialparties.agi
== Parsing '/etc/asterisk/manager.conf': Found
== Parsing '/etc/asterisk/manager_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
== Parsing '/etc/asterisk/manager.conf': Found
== Parsing '/etc/asterisk/manager_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
dialparties.agi: Caller ID name is '00441112223333' number is '00441112223333'
dialparties.agi: Caller ID name is '00441112223333' number is '00441112223333'
dialparties.agi: Methodology of ring is 'none'
dialparties.agi: Methodology of ring is 'none'
-- dialparties.agi: Added extension 101 to extension map
-- dialparties.agi: Added extension 101 to extension map
-- dialparties.agi: Extension 101 cf is disabled
-- dialparties.agi: Extension 101 cf is disabled
-- dialparties.agi: Extension 101 do not disturb is disabled
-- dialparties.agi: Extension 101 do not disturb is disabled
> dialparties.agi: extnum 101 has: cw: 1; hascfb: 0 [] hascfu: 0 []
> dialparties.agi: extnum 101 has: cw: 1; hascfb: 0 [] hascfu: 0 []
> dialparties.agi: ExtensionState: 0
> dialparties.agi: ExtensionState: 0
-- dialparties.agi: dbset CALLTRACE/101 to 00441112223333
-- dialparties.agi: dbset CALLTRACE/101 to 00441112223333
== Manager 'admin' logged off from 127.0.0.1
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("SIP/5060-08d0eae0", "SIP/101||tr") in new stack
-- Called 101
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("SIP/5060-08d0eae0", "SIP/101||tr") in new stack
-- Called 101
-- SIP/101-08d63178 is ringing
-- SIP/101-08d63178 is ringing
-- SIP/101-08d63178 answered SIP/5060-08d0eae0
-- SIP/101-08d63178 answered SIP/5060-08d0eae0
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d0eae0' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d0eae0' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d0eae0'
-- Executing Macro("SIP/5060-08d0eae0", "hangupcall") in new stack
-- Executing ResetCDR("SIP/5060-08d0eae0", "w") in new stack
-- Executing NoCDR("SIP/5060-08d0eae0", "") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("SIP/5060-08d0eae0", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("SIP/5060-08d0eae0", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("SIP/5060-08d0eae0", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d0eae0' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d0eae0'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d0eae0' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d0eae0' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d0eae0'
-- Executing Macro("SIP/5060-08d0eae0", "hangupcall") in new stack
-- Executing ResetCDR("SIP/5060-08d0eae0", "w") in new stack
-- Executing NoCDR("SIP/5060-08d0eae0", "") in new stack
-- Executing GotoIf("SIP/5060-08d0eae0", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("SIP/5060-08d0eae0", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("SIP/5060-08d0eae0", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("SIP/5060-08d0eae0", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d0eae0' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d0eae0'
trixbox01*CLI>

Ok, I'm really happy that I have successfully made a call into my trixbox via SIP, so I give it another go.

[Attempt 04]
Make another call from POTS line to SIP trunk number.
Incoming call registers on softphone client ok.
Answer call on softphone but the call pickup does not register at the POTS end.
Ringing stopped on softphone but the ringing continues at POTS end.
Softphone appears to think that it has an active call.
Hangup call on softphone and the call termination is noted at the POTS end.
The status changes on softphone, the call is closed.

Here is my log for this one...

-- Executing GotoIf("SIP/5060-08d63178", "1?from-trunk||1") in new stack
-- Goto (from-trunk,s,1)
-- Executing Set("SIP/5060-08d63178", "__FROM_DID=s") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0 ?cidok") in new stack
-- Executing Set("SIP/5060-08d63178", "CALLERID(name)=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d63178", "CallerID is "00441112223333" ") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d63178", "none") in new stack
-- Executing Set("SIP/5060-08d63178", "__MOHCLASS=none") in new stack
-- Executing Ringing("SIP/5060-08d63178", "") in new stack
-- Executing Goto("SIP/5060-08d63178", "from-did-direct|101|1") in new stack
-- Goto (from-did-direct,101,1)
-- Executing Set("SIP/5060-08d63178", "__RINGTIMER=10") in new stack
-- Executing Macro("SIP/5060-08d63178", "exten-vm|novm|101") in new stack
-- Executing Macro("SIP/5060-08d63178", "user-callerid") in new stack
-- Executing NoOp("SIP/5060-08d63178", "user-callerid: 00441112223333 00441112223333") in new stack
-- Executing Set("SIP/5060-08d63178", "AMPUSER=00441112223333") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?report") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?start") in new stack
-- Executing Set("SIP/5060-08d63178", "REALCALLERIDNUM=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d63178", "REALCALLERIDNUM is 00441112223333") in new stack
-- Executing Set("SIP/5060-08d63178", "AMPUSER=") in new stack
-- Executing Set("SIP/5060-08d63178", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing NoOp("SIP/5060-08d63178", "TTL: ARG1: novm") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?continue") in new stack
-- Executing Set("SIP/5060-08d63178", "__TTL=64") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing NoOp("SIP/5060-08d63178", "Using CallerID "00441112223333" ") in new stack
-- Executing Set("SIP/5060-08d63178", "FROMCONTEXT=exten-vm") in new stack
-- Executing Set("SIP/5060-08d63178", "VMBOX=novm") in new stack
-- Executing Set("SIP/5060-08d63178", "EXTTOCALL=101") in new stack
-- Executing Set("SIP/5060-08d63178", "CFUEXT=") in new stack
-- Executing Set("SIP/5060-08d63178", "CFBEXT=") in new stack
-- Executing Set("SIP/5060-08d63178", "RT=") in new stack
-- Executing Macro("SIP/5060-08d63178", "record-enable|101|IN") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("SIP/5060-08d63178", "recordingcheck|20071212-235908|1197503948.12") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
-- Executing GotoIf("SIP/5060-08d63178", "1?from-trunk||1") in new stack
-- Goto (from-trunk,s,1)
-- Executing Set("SIP/5060-08d63178", "__FROM_DID=s") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0 ?cidok") in new stack
-- Executing Set("SIP/5060-08d63178", "CALLERID(name)=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d63178", "CallerID is "00441112223333" ") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d63178", "none") in new stack
-- Executing Set("SIP/5060-08d63178", "__MOHCLASS=none") in new stack
-- Executing Ringing("SIP/5060-08d63178", "") in new stack
-- Executing Goto("SIP/5060-08d63178", "from-did-direct|101|1") in new stack
-- Goto (from-did-direct,101,1)
-- Executing Set("SIP/5060-08d63178", "__RINGTIMER=10") in new stack
-- Executing Macro("SIP/5060-08d63178", "exten-vm|novm|101") in new stack
-- Executing Macro("SIP/5060-08d63178", "user-callerid") in new stack
-- Executing NoOp("SIP/5060-08d63178", "user-callerid: 00441112223333 00441112223333") in new stack
-- Executing Set("SIP/5060-08d63178", "AMPUSER=00441112223333") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?report") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?start") in new stack
-- Executing Set("SIP/5060-08d63178", "REALCALLERIDNUM=00441112223333") in new stack
-- Executing NoOp("SIP/5060-08d63178", "REALCALLERIDNUM is 00441112223333") in new stack
-- Executing Set("SIP/5060-08d63178", "AMPUSER=") in new stack
-- Executing Set("SIP/5060-08d63178", "AMPUSERCIDNAME=") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "1?report") in new stack
-- Goto (macro-user-callerid,s,13)
-- Executing NoOp("SIP/5060-08d63178", "TTL: ARG1: novm") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?continue") in new stack
-- Executing Set("SIP/5060-08d63178", "__TTL=64") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "1?continue") in new stack
-- Goto (macro-user-callerid,s,23)
-- Executing NoOp("SIP/5060-08d63178", "Using CallerID "00441112223333" ") in new stack
-- Executing Set("SIP/5060-08d63178", "FROMCONTEXT=exten-vm") in new stack
-- Executing Set("SIP/5060-08d63178", "VMBOX=novm") in new stack
-- Executing Set("SIP/5060-08d63178", "EXTTOCALL=101") in new stack
-- Executing Set("SIP/5060-08d63178", "CFUEXT=") in new stack
-- Executing Set("SIP/5060-08d63178", "CFBEXT=") in new stack
-- Executing Set("SIP/5060-08d63178", "RT=") in new stack
-- Executing Macro("SIP/5060-08d63178", "record-enable|101|IN") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?2:4") in new stack
-- Goto (macro-record-enable,s,4)
-- Executing AGI("SIP/5060-08d63178", "recordingcheck|20071212-235908|1197503948.12") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20071212-235908|1197503948.12: Inbound recording not enabled
recordingcheck|20071212-235908|1197503948.12: Inbound recording not enabled
-- AGI Script recordingcheck completed, returning 0
-- Executing NoOp("SIP/5060-08d63178", "No recording needed") in new stack
-- Executing Macro("SIP/5060-08d63178", "dial||tr|101") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?dial") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d63178", "none") in new stack
-- Executing AGI("SIP/5060-08d63178", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
-- AGI Script recordingcheck completed, returning 0
-- Executing NoOp("SIP/5060-08d63178", "No recording needed") in new stack
-- Executing Macro("SIP/5060-08d63178", "dial||tr|101") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "0?dial") in new stack
-- Executing SetMusicOnHold("SIP/5060-08d63178", "none") in new stack
-- Executing AGI("SIP/5060-08d63178", "dialparties.agi") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
dialparties.agi: Starting New Dialparties.agi
== Parsing '/etc/asterisk/manager.conf': Found
== Parsing '/etc/asterisk/manager_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
== Parsing '/etc/asterisk/manager.conf': Found
== Parsing '/etc/asterisk/manager_custom.conf': Found
== Manager 'admin' logged on from 127.0.0.1
dialparties.agi: Caller ID name is '00441112223333' number is '00441112223333'
dialparties.agi: Caller ID name is '00441112223333' number is '00441112223333'
dialparties.agi: Methodology of ring is 'none'
dialparties.agi: Methodology of ring is 'none'
-- dialparties.agi: Added extension 101 to extension map
-- dialparties.agi: Added extension 101 to extension map
-- dialparties.agi: Extension 101 cf is disabled
-- dialparties.agi: Extension 101 cf is disabled
-- dialparties.agi: Extension 101 do not disturb is disabled
-- dialparties.agi: Extension 101 do not disturb is disabled
> dialparties.agi: extnum 101 has: cw: 1; hascfb: 0 [] hascfu: 0 []
> dialparties.agi: extnum 101 has: cw: 1; hascfb: 0 [] hascfu: 0 []
> dialparties.agi: ExtensionState: 0
> dialparties.agi: ExtensionState: 0
-- dialparties.agi: dbset CALLTRACE/101 to 00441112223333
-- dialparties.agi: dbset CALLTRACE/101 to 00441112223333
== Manager 'admin' logged off from 127.0.0.1
== Manager 'admin' logged off from 127.0.0.1
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("SIP/5060-08d63178", "SIP/101||tr") in new stack
-- Called 101
-- AGI Script dialparties.agi completed, returning 0
-- Executing Dial("SIP/5060-08d63178", "SIP/101||tr") in new stack
-- Called 101
-- SIP/101-08d65d98 is ringing
-- SIP/101-08d65d98 is ringing
-- SIP/101-08d65d98 answered SIP/5060-08d63178
-- SIP/101-08d65d98 answered SIP/5060-08d63178
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d63178' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d63178' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d63178'
-- Executing Macro("SIP/5060-08d63178", "hangupcall") in new stack
-- Executing ResetCDR("SIP/5060-08d63178", "w") in new stack
-- Executing NoCDR("SIP/5060-08d63178", "") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("SIP/5060-08d63178", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("SIP/5060-08d63178", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("SIP/5060-08d63178", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d63178' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d63178'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d63178' in macro 'dial'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d63178' in macro 'exten-vm'
== Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/5060-08d63178'
-- Executing Macro("SIP/5060-08d63178", "hangupcall") in new stack
-- Executing ResetCDR("SIP/5060-08d63178", "w") in new stack
-- Executing NoCDR("SIP/5060-08d63178", "") in new stack
-- Executing GotoIf("SIP/5060-08d63178", "1?skiprg") in new stack
-- Goto (macro-hangupcall,s,6)
-- Executing GotoIf("SIP/5060-08d63178", "1?skipblkvm") in new stack
-- Goto (macro-hangupcall,s,9)
-- Executing GotoIf("SIP/5060-08d63178", "1?theend") in new stack
-- Goto (macro-hangupcall,s,11)
-- Executing Hangup("SIP/5060-08d63178", "") in new stack
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d63178' in macro 'hangupcall'
== Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/5060-08d63178'

[Attempt 05]
So I try again, but get the exact same error as in Attempt 04.

[Attempt 06]
And I try again, this time I get the same error is in Attempt 02.

The inconsistency might suggest that there are several irregularities at play here.
The fact that I can receive a call means that I should be able to do it consistently if I get the settings correct.
The fact that the behaviour is erratic would suggest the sip registration is perhaps failing, although when I do my check it appears to be fine.
I'm not sure where to start looking. I'm hoping that an expert will be able to point me in the right direction here. I'm rather confused by this issue.

Many thanks for your time in reviewing this.
G