Camp-on feature in FreePBX 2.9 and Asterisk 1.8

Hi Everyone

Would someone be so kind to help please.

I’m trying the camp-on feature in FreePBX 2.9 and Asterisk 1.8.

I’ve tried in two separate servers and environments but keep on getting the same error.

When ext A phone ext B and ext B rejects the call, ext A then dials the camp-on feature code, and ext A can hear a beep… everything is going as planned.

If one the executes in the CLI>cc report status
The desired results are displayed

1 Call completion transactions
Core ID Caller Status

3 SIP/0297 CC accepted by callee
|–>[email protected]
|–>SIP/0298(CCNR)

When ext B completes a call the system does phone ext A back to initiate the call back procedure. But as soon as ext A answers the phone, a hang-up happens and the CALLCOMPLETION is cancelled.
[Sep 5 18:48:50] VERBOSE[3572] pbx.c: – Executing [*[email protected]:4] ExecIf(“SIP/0297-00000002”, "0?CallCompletionCancel():CallCompletionRequest(

This is the Asterisk Log files

[Sep 5 18:48:57] VERBOSE[3575] pbx.c: – Executing [[email protected]:41] Set(“Local/[email protected];2”, “D_OPTIONS=trI”) in new stack
[Sep 5 18:48:57] VERBOSE[3575] pbx.c: – Executing [[email protected]:42] Dial(“Local/[email protected];2”, “SIP/0297,60,trI”) in new stack
[Sep 5 18:48:57] VERBOSE[3575] netsock.c: == Using UDPTL TOS bits 184
[Sep 5 18:48:57] VERBOSE[3575] netsock.c: == Using UDPTL CoS mark 5
[Sep 5 18:48:57] VERBOSE[3575] netsock2.c: == Using SIP RTP TOS bits 184
[Sep 5 18:48:57] VERBOSE[3575] netsock2.c: == Using SIP RTP CoS mark 5
[Sep 5 18:48:57] VERBOSE[3575] app_dial.c: – Called SIP/0297
[Sep 5 18:48:57] VERBOSE[3575] app_dial.c: – Connected line update to Local/[email protected];2 prevented.
[Sep 5 18:48:58] VERBOSE[3575] app_dial.c: – SIP/0297-00000005 is ringing
[Sep 5 18:49:01] WARNING[3278] chan_sip.c: Unsupported SDP media type in offer: audio 0 RTP/AVP 8 101
[Sep 5 18:49:01] WARNING[3278] chan_sip.c: Failing due to no acceptable offer found
[Sep 5 18:49:01] VERBOSE[3575] app_dial.c: – Connected line update to Local/[email protected];2 prevented.
[Sep 5 18:49:01] VERBOSE[3575] app_dial.c: – SIP/0297-00000005 answered Local/[email protected];2
[Sep 5 18:49:01] VERBOSE[3575] pbx.c: – Executing [[email protected]:1] Macro(“Local/[email protected];2”, “hangupcall,”) in new stack
[Sep 5 18:49:01] VERBOSE[3575] pbx.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected];2”, “1?endmixmoncheck”) in new stack

Any help would be much appreciated.

Unsupported SDP media type in offer

What codecs are you using? are any of the non-free ones properly licensed and legitimate?

Hi

Thanks for your reply!

Initially I thought it was a codec issue as well, maybe it is. I’m not forcing any codec but I did try if by forcing both extensions to the same codec, alaw, with the same result.

We do have a VOIP trunk that uses g729 with properly licensed Digium codecs

Any suggestions?

not really, increase your verbosity and debug levels and try again,

core set verbose 99
core set debug 99

[Sep 6 05:58:19] DEBUG[3278] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
[Sep 6 05:58:19] DEBUG[3278] netsock2.c: Splitting ‘172.32.1.207:62332’ into…
[Sep 6 05:58:19] DEBUG[3278] netsock2.c: …host ‘172.32.1.207’ and port ‘62332’.
[Sep 6 05:58:19] DEBUG[3278] chan_sip.c: build_route: Retaining previous route: sip:[email protected]:62332
[Sep 6 05:58:19] DEBUG[3278] chan_sip.c: Trying to put ‘SIP/2.0 404’ onto UDP socket destined for 172.32.1.207:62332
[Sep 6 05:58:19] DEBUG[3278] chan_sip.c: Destroying SIP dialog MTZjOGE5MDUwMDM3MjliMTA4MWJhOTNjOWU5N2E1YmY.
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: = Looking for Call ID: [email protected]:5060 (Checking To) --From tag as09c7d38d --To-tag 745fcc29
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Acked pending invite 102
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: SIP response 200 to standard invite
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED.
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Processing session-level SDP o=- 1 2 IN IP4 172.32.1.25… UNSUPPORTED.
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Processing session-level SDP s=CounterPath eyeBeam 1.5… UNSUPPORTED.
[Sep 6 05:58:20] DEBUG[3278] netsock2.c: Splitting ‘172.32.1.25’ into…
[Sep 6 05:58:20] DEBUG[3278] netsock2.c: …host ‘172.32.1.25’ and port ‘’.
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Processing session-level SDP c=IN IP4 172.32.1.25… OK.
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED.
[Sep 6 05:58:20] WARNING[3278] chan_sip.c: Unsupported SDP media type in offer: audio 0 RTP/AVP 8 101
[Sep 6 05:58:20] WARNING[3278] chan_sip.c: Failing due to no acceptable offer found
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Updating call counter for outgoing call
[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: build_route: Contact hop: sip:[email protected]:15736;rinstance=ceea05e7d4e35e6e
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for SIP - 0297
[Sep 6 05:58:20] DEBUG[3216] chan_sip.c: Checking device state for peer 0297
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for SIP/0297 - state 2 (In use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘SIP/0297’ state ‘2’
[Sep 6 05:58:20] DEBUG[3278] netsock2.c: Splitting ‘172.32.1.117:15736’ into…
[Sep 6 05:58:20] DEBUG[3278] netsock2.c: …host ‘172.32.1.117’ and port ‘15736’.
[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: ChannelUpdate
Privilege: system,all
Channel: SIP/0297-0000001d
Channeltype: SIP
Uniqueid: 1346903897.39
SIPcallid: [email protected]:5060
SIPfullcontact: sip:[email protected]:15736;rinstance=ceea05e7d4e35e6e
Peername: 0297

[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Trying to put ‘ACK sip:029’ onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:20] DEBUG[3278] channel.c: Soft-Hanging up channel ‘SIP/0297-0000001d’
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: ChannelUpdate
Privilege: system,all
Channel: SIP/0297-0000001d
Channeltype: SIP
Uniqueid: 1346903897.39
SIPcallid: [email protected]:5060
SIPfullcontact: sip:[email protected]:15736;rinstance=ceea05e7d4e35e6e
Peername: 0297

[Sep 6 05:58:20] DEBUG[3278] netsock2.c: Splitting ‘172.32.1.117:15736’ into…
[Sep 6 05:58:20] DEBUG[3278] netsock2.c: …host ‘172.32.1.117’ and port ‘15736’.
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: ChannelUpdate
Privilege: system,all
Channel: SIP/0297-0000001d
Channeltype: SIP
Uniqueid: 1346903897.39
SIPcallid: [email protected]:5060
SIPfullcontact: sip:[email protected]:15736;rinstance=ceea05e7d4e35e6e
Peername: 0297

[Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Trying to put ‘BYE sip:029’ onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:20] DEBUG[3217] app_queue.c: Extension ‘[email protected]’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘SIP/0297’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 0297
Context: ext-local
Hint: SIP/0297
Status: 1

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 0297
Context: ext-local
Hint: SIP/0297
Status: 1

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 0297
Context: ext-local
Hint: SIP/0297
Status: 1

[Sep 6 05:58:20] VERBOSE[871] app_dial.c: – Connected line update to Local/[email protected];2 prevented.
[Sep 6 05:58:20] VERBOSE[871] app_dial.c: – SIP/0297-0000001d answered Local/[email protected];2
[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/0297-0000001d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0297
CallerIDName: device
ConnectedLineNum: 0298
ConnectedLineName: QTest2
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/0297-0000001d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0297
CallerIDName: device
ConnectedLineNum: 0298
ConnectedLineName: QTest2
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for SIP - 0297
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3216] chan_sip.c: Checking device state for peer 0297
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: SIP/0297-0000001d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0297
CallerIDName: device
ConnectedLineNum: 0298
ConnectedLineName: QTest2
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for SIP/0297 - state 2 (In use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘SIP/0297’ state ‘2’
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘SIP/0297’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[871] channel.c: Set channel SIP/0297-0000001d to write format slin
[Sep 6 05:58:20] DEBUG[871] channel.c: Set channel SIP/0297-0000001d to read format slin
[Sep 6 05:58:20] DEBUG[871] features.c: bridge answer set, chan answer set
[Sep 6 05:58:20] DEBUG[871] features.c: Removing dialed interfaces datastore on SIP/0297-0000001d since we’re bridging
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALEDPEERNAME
Value: SIP/0297-0000001d
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALEDPEERNUMBER
Value: 0297
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: BRIDGEPEER
Value: SIP/0297-0000001d
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for Local - [email protected]
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: BRIDGEPEER
Value: Local/[email protected];2
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALEDPEERNAME
Value: SIP/0297-0000001d
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/[email protected];2
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0298
CallerIDName: QTest2
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3216] chan_local.c: Checking if extension [email protected] exists (devicestate)
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: NewAccountCode
Privilege: call,all
Channel: SIP/0297-0000001d
Uniqueid: 1346903897.39
AccountCode:
OldAccountCode:

[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for Local/[email protected] - state 2 (In use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘Local/[email protected]’ state ‘2’
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/[email protected];1
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0297
CallerIDName: QTest1
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for Local - [email protected]
[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/[email protected];2
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0298
CallerIDName: QTest2
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CC_INTERFACES
Value: SIP/0298
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CC_EXTEN
Value: 0298
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ANSWEREDTIME
Value: 0
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CC_CONTEXT
Value: from-internal
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: NewAccountCode
Privilege: call,all
Channel: SIP/0297-0000001d
Uniqueid: 1346903897.39
AccountCode:
OldAccountCode:

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALEDTIME
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/[email protected];1
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0297
CallerIDName: QTest1
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_EXTEN
Value: 0298
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALEDPEERNUMBER
Value: 0297
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3216] chan_local.c: Checking if extension [email protected] exists (devicestate)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for Local/[email protected] - state 2 (In use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘Local/[email protected]’ state ‘2’
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: BRIDGEPEER
Value: SIP/0297-0000001d
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: BRIDGEPEER
Value: Local/[email protected];2
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/[email protected];2
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0298
CallerIDName: QTest2
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: NewAccountCode
Privilege: call,all
Channel: SIP/0297-0000001d
Uniqueid: 1346903897.39
AccountCode:
OldAccountCode:

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newstate
Privilege: call,all
Channel: Local/[email protected];1
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 0297
CallerIDName: QTest1
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CC_INTERFACES
Value: SIP/0298
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CC_EXTEN
Value: 0298
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ANSWEREDTIME
Value: 0
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CC_CONTEXT
Value: from-internal
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALEDTIME
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_EXTEN
Value: 0298
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘Macro’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:1] Macro(“Local/[email protected];2”, “hangupcall,”) in new stack
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected];2”, “1?endmixmoncheck”) in new stack
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,9)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘NoOp’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:9] NoOp(“Local/[email protected];2”, “End of MIXMON check”) in new stack
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: Noop
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘MEETME_RECORDINGFILE’ is NULL
[Sep 6 05:58:20] DEBUG[870] pbx.c: Result of ‘AMPUSER’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:10] GotoIf(“Local/[email protected];2”, “1?nomeetmemon”) in new stack
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-dial-one
Extension: h
Priority: 1
Application: Macro
AppData: hangupcall,
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_IN_HANGUP
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[870] db.c: Unable to find key ‘/ccss/cc_announce_monitor’ in family ‘AMPUSER’
[Sep 6 05:58:20] DEBUG[870] func_db.c: DB: AMPUSER//ccss/cc_announce_monitor not found in database.
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Expression result is ‘0’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[870] pbx.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected];1”, “0?siprm”) in new stack
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-dial-one
Extension: h
Priority: 1
Application: Macro
AppData: hangupcall,
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_IN_HANGUP
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_EXTEN
Value: h
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_CONTEXT
Value: macro-dial-one
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_PRIORITY
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_CONTEXT
Value: from-internal
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_PRIORITY
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG1
Value:
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 1
Application: GotoIf
AppData: 1?endmixmoncheck
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 9
Application: NoOp
AppData: End of MIXMON check
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 10
Application: GotoIf
AppData: 1?nomeetmemon
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];1
Context: macro-ccss-default
Extension: s
Priority: 1
Application: GotoIf
AppData: 0?siprm
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘Local/[email protected]’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘Local/[email protected]’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_EXTEN
Value: h
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_CONTEXT
Value: macro-dial-one
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_PRIORITY
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_CONTEXT
Value: from-internal
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_PRIORITY
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG1
Value:
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected]rnal-f049;2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 1
Application: GotoIf
AppData: 1?endmixmoncheck
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 9
Application: NoOp
AppData: End of MIXMON check
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 10
Application: GotoIf
AppData: 1?nomeetmemon
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];1
Context: macro-ccss-default
Extension: s
Priority: 1
Application: GotoIf
AppData: 0?siprm
Uniqueid: 1346903897.37

[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,15)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘MEETME_RECORDINGFILE’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘NoOp’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:15] NoOp(“Local/[email protected];2”, “MEETME_RECORDINGFILE=”) in new stack
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: Noop
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘TOUCH_MONITOR_OUTPUT’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:16] GotoIf(“Local/[email protected];2”, “1?noautomon”) in new stack
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,18)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘TOUCH_MONITOR_OUTPUT’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘NoOp’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:18] NoOp(“Local/[email protected];2”, “TOUCH_MONITOR_OUTPUT=”) in new stack
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: Noop
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘MONITOR_FILENAME’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:19] GotoIf(“Local/[email protected];2”, “1?noautomon2”) in new stack
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,25)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘MONITOR_FILENAME’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘NoOp’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:25] NoOp(“Local/[email protected];2”, “MONITOR_FILENAME=”) in new stack
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: Noop
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘USE_CONFIRMATION’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘RINGGROUP_INDEX’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘CHANNEL’ is ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘UNIQCHAN’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:26] GotoIf(“Local/[email protected];2”, “1?skiprg”) in new stack
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,29)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘BLKVM_BASE’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘BLKVM_BASE’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘CHANNEL’ is ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘BLKVM_OVERRIDE’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:29] GotoIf(“Local/[email protected];2”, “1?skipblkvm”) in new stack
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,32)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘FMGRP’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘FMUNIQUE’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘CHANNEL’ is ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Result of ‘FMUNIQUE’ is NULL
[Sep 6 05:58:20] DEBUG[871] pbx.c: Expression result is ‘1’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘GotoIf’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:32] GotoIf(“Local/[email protected];2”, “1?theend”) in new stack
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Goto (macro-hangupcall,s,34)
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[871] pbx.c: Launching ‘Hangup’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: – Executing [[email protected]:34] Hangup(“Local/[email protected];2”, “”) in new stack
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Spawn extension (macro-hangupcall,s,34) exited non-zero on ‘Local/[email protected];2’ in macro ‘hangupcall’
[Sep 6 05:58:20] VERBOSE[871] app_macro.c: == Spawn extension (macro-hangupcall, s, 34) exited non-zero on ‘Local/[email protected];2’ in macro ‘hangupcall’
[Sep 6 05:58:20] DEBUG[871] features.c: Spawn extension (macro-dial-one,h,1) exited non-zero on ‘Local/[email protected];2’
[Sep 6 05:58:20] VERBOSE[871] features.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Not taking any branch
[Sep 6 05:58:20] DEBUG[870] app_macro.c: Executed application: GotoIf
[Sep 6 05:58:20] DEBUG[870] pbx.c: Launching ‘Playback’
[Sep 6 05:58:20] VERBOSE[870] pbx.c: – Executing [[email protected]:2] Playback(“Local/[email protected];1”, “beep&calling&extension”) in new stack
[Sep 6 05:58:20] DEBUG[870] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Sep 6 05:58:20] VERBOSE[870] file.c: – <Local/[email protected];1> Playing ‘beep.slin’ (language ‘en’)
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 15
Application: NoOp
AppData: MEETME_RECORDINGFILE=
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 16
Application: GotoIf
AppData: 1?noautomon
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 18
Application: NoOp
AppData: TOUCH_MONITOR_OUTPUT=
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 19
Application: GotoIf
AppData: 1?noautomon2
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 25
Application: NoOp
AppData: MONITOR_FILENAME=
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 26
Application: GotoIf
AppData: 1?skiprg
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 29
Application: GotoIf
AppData: 1?skipblkvm
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 32
Application: GotoIf
AppData: 1?theend
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 34
Application: Hangup
AppData:
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 2
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG1
Value: 60
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_EXTEN
Value: s
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_CONTEXT
Value: macro-exten-vm
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_PRIORITY
Value: 7
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];1
Context: macro-ccss-default
Extension: s
Priority: 2
Application: Playback
AppData: beep&calling&extension
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 15
Application: NoOp
AppData: MEETME_RECORDINGFILE=
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 16
Application: GotoIf
AppData: 1?noautomon
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 18
Application: NoOp
AppData: TOUCH_MONITOR_OUTPUT=
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 19
Application: GotoIf
AppData: 1?noautomon2
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 25
Application: NoOp
AppData: MONITOR_FILENAME=
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 26
Application: GotoIf
AppData: 1?skiprg
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 29
Application: GotoIf
AppData: 1?skipblkvm
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 32
Application: GotoIf
AppData: 1?theend
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 3
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];2
Context: macro-hangupcall
Extension: s
Priority: 34
Application: Hangup
AppData:
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 2
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG1
Value: 60
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_EXTEN
Value: s
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_CONTEXT
Value: macro-exten-vm
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_PRIORITY
Value: 7
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Newexten
Privilege: dialplan,all
Channel: Local/[email protected];1
Context: macro-ccss-default
Extension: s
Priority: 2
Application: Playback
AppData: beep&calling&extension
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[871] cdr_mysql.c: Inserting a CDR record.
[Sep 6 05:58:20] DEBUG[871] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid) VALUES (‘2012-09-06 05:58:17’,’“QTest2” <0298>’,‘0298’,‘0297’,‘from-internal’,‘Local/[email protected];2’,‘SIP/0297-0000001d’,‘Dial’,‘SIP/0297,60,trI’,‘3’,‘0’,‘ANSWERED’,‘3’,‘1346903897.38’)
[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Cdr
Privilege: cdr,all
AccountCode:
Source: 0298
Destination: 0297
DestinationContext: from-internal
CallerID: “QTest2” <0298>
Channel: Local/[email protected];2
DestinationChannel: SIP/0297-0000001d
LastApplication: Dial
LastData: SIP/0297,60,trI
StartTime: 2012-09-06 05:58:17
AnswerTime: 2012-09-06 05:58:20
EndTime: 2012-09-06 05:58:20
Duration: 3
BillableSeconds: 0
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1346903897.38
UserField:

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Cdr
Privilege: cdr,all
AccountCode:
Source: 0298
Destination: 0297
DestinationContext: from-internal
CallerID: “QTest2” <0298>
Channel: Local/[email protected];2
DestinationChannel: SIP/0297-0000001d
LastApplication: Dial
LastData: SIP/0297,60,trI
StartTime: 2012-09-06 05:58:17
AnswerTime: 2012-09-06 05:58:20
EndTime: 2012-09-06 05:58:20
Duration: 3
BillableSeconds: 0
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1346903897.38
UserField:

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Cdr
Privilege: cdr,all
AccountCode:
Source: 0298
Destination: 0297
DestinationContext: from-internal
CallerID: “QTest2” <0298>
Channel: Local/[email protected];2
DestinationChannel: SIP/0297-0000001d
LastApplication: Dial
LastData: SIP/0297,60,trI
StartTime: 2012-09-06 05:58:17
AnswerTime: 2012-09-06 05:58:20
EndTime: 2012-09-06 05:58:20
Duration: 3
BillableSeconds: 0
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1346903897.38
UserField:

[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘2012-09-06 05:58:17’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘“QTest2” <0298>’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘from-internal’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘SIP/0297-0000001d’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘Dial’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘SIP/0297,60,trI’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘3’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘0’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘ANSWERED’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘DOCUMENTATION’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘1346903897.38’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘0298’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Function result is ‘0297’
[Sep 6 05:58:20] DEBUG[871] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test,src,dst) VALUES (‘2012-09-06 05:58:17’,’“QTest2” <0298>’,‘from-internal’,‘Local/[email protected];2’,‘SIP/0297-0000001d’,‘Dial’,‘SIP/0297,60,trI’,‘3’,‘0’,‘ANSWERED’,‘DOCUMENTATION’,’’,‘1346903897.38’,’’,’’,‘0298’,‘0297’)
[Sep 6 05:58:20] DEBUG[871] channel.c: Hanging up channel ‘SIP/0297-0000001d’
[Sep 6 05:58:20] DEBUG[871] chan_sip.c: Hanging up zombie call. Be scared.
[Sep 6 05:58:20] DEBUG[871] chan_sip.c: Updating call counter for outgoing call
[Sep 6 05:58:20] DEBUG[871] res_rtp_asterisk.c: Setting RTCP address on RTP instance ‘0x1bec78c8’
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for SIP - 0297
[Sep 6 05:58:20] DEBUG[3216] chan_sip.c: Checking device state for peer 0297
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for SIP/0297 - state 1 (Not in use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘SIP/0297’ state ‘1’
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOS
Value: ssrc=887232367;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOS
Value: ssrc=887232367;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[871] netsock2.c: Splitting ‘172.32.1.117:15736’ into…
[Sep 6 05:58:20] DEBUG[871] netsock2.c: …host ‘172.32.1.117’ and port ‘15736’.
[Sep 6 05:58:20] DEBUG[871] chan_sip.c: Trying to put ‘BYE sip:029’ onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:20] DEBUG[871] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Spawn extension (macro-dial-one,s,42) exited non-zero on ‘Local/[email protected];2’ in macro ‘dial-one’
[Sep 6 05:58:20] DEBUG[3217] app_queue.c: Extension ‘[email protected]’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] VERBOSE[871] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘Local/[email protected];2’ in macro ‘dial-one’
[Sep 6 05:58:20] DEBUG[871] app_macro.c: Spawn extension (macro-exten-vm,s,7) exited non-zero on ‘Local/[email protected];2’ in macro ‘exten-vm’
[Sep 6 05:58:20] VERBOSE[871] app_macro.c: == Spawn extension (macro-exten-vm, s, 7) exited non-zero on ‘Local/[email protected];2’ in macro ‘exten-vm’
[Sep 6 05:58:20] DEBUG[871] pbx.c: Spawn extension (from-internal,0297,2) exited non-zero on ‘Local/[email protected];2’
[Sep 6 05:58:20] VERBOSE[871] pbx.c: == Spawn extension (from-internal, 0297, 2) exited non-zero on ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[871] channel.c: Soft-Hanging up channel ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[871] channel.c: Hanging up channel ‘Local/[email protected];2’
[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: SIP/0297-0000001d
Uniqueid: 1346903897.39
CallerIDNum: 0297
CallerIDName: device
ConnectedLineNum: 0298
ConnectedLineName: QTest2
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Dial
Privilege: call,all
SubEvent: End
Channel: Local/[email protected];2
UniqueID: 1346903897.38
DialStatus: ANSWER

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 0297
Context: ext-local
Hint: SIP/0297
Status: 0

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: Local/[email protected];2
Uniqueid: 1346903897.38
CallerIDNum: 0298
CallerIDName: QTest2
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘SIP/0297’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOS
Value: ssrc=887232367;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: SIP/0297-0000001d
Uniqueid: 1346903897.39
CallerIDNum: 0297
CallerIDName: device
ConnectedLineNum: 0298
ConnectedLineName: QTest2
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Dial
Privilege: call,all
SubEvent: End
Channel: Local/[email protected];2
UniqueID: 1346903897.38
DialStatus: ANSWER

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 0297
Context: ext-local
Hint: SIP/0297
Status: 0

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG1
Value: novm
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG2
Value: 0297
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG3
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_EXTEN
Value: 0297
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_CONTEXT
Value: from-internal
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_PRIORITY
Value: 2
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 0
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CHANLOCALSTATUS
Value: ANSWER
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: Local/[email protected];2
Uniqueid: 1346903897.38
CallerIDNum: 0298
CallerIDName: QTest2
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for SIP - 0297
[Sep 6 05:58:20] DEBUG[3216] chan_sip.c: Checking device state for peer 0297
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for SIP/0297 - state 1 (Not in use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘SIP/0297’ state ‘1’
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for Local - [email protected]
[Sep 6 05:58:20] DEBUG[3216] chan_local.c: Checking if extension [email protected] exists (devicestate)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: Changing state for Local/[email protected] - state 2 (In use)
[Sep 6 05:58:20] DEBUG[3216] devicestate.c: device ‘Local/[email protected]’ state ‘2’
[Sep 6 05:58:20] DEBUG[870] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Sep 6 05:58:20] DEBUG[870] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Sep 6 05:58:20] DEBUG[870] app_macro.c: Spawn extension (macro-ccss-default,s,2) exited non-zero on ‘Local/[email protected];1’ in macro ‘ccss-default’
[Sep 6 05:58:20] VERBOSE[870] app_macro.c: == Spawn extension (macro-ccss-default, s, 2) exited non-zero on ‘Local/[email protected];1’ in macro ‘ccss-default’
[Sep 6 05:58:20] DEBUG[870] channel.c: Hanging up channel ‘Local/[email protected];1’
[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: Local/[email protected];1
Uniqueid: 1346903897.37
CallerIDNum: 0297
CallerIDName: QTest1
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: PLAYBACKSTATUS
Value: SUCCESS
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 0
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: Local/[email protected];1
Uniqueid: 1346903897.37
CallerIDNum: 0297
CallerIDName: QTest1
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[870] cdr_mysql.c: Inserting a CDR record.
[Sep 6 05:58:20] DEBUG[870] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid) VALUES (‘2012-09-06 05:58:17’,’“QTest1” <0297>’,‘0297’,‘0297_0298’,‘from-ccss-internal’,‘Local/[email protected];1’,‘Playback’,‘beep&calling&extension’,‘3’,‘0’,‘ANSWERED’,‘3’,‘1346903897.37’)
[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘SIP/0297’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3478] app_queue.c: Device ‘Local/[email protected]’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: SIP/0297-0000001d
Variable: RTPAUDIOQOS
Value: ssrc=887232367;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1346903897.39

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: SIP/0297-0000001d
Uniqueid: 1346903897.39
CallerIDNum: 0297
CallerIDName: device
ConnectedLineNum: 0298
ConnectedLineName: QTest2
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: DIALSTATUS
Value: ANSWER
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Dial
Privilege: call,all
SubEvent: End
Channel: Local/[email protected];2
UniqueID: 1346903897.38
DialStatus: ANSWER

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: ExtensionStatus
Privilege: call,all
Exten: 0297
Context: ext-local
Hint: SIP/0297
Status: 0

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG1
Value: novm
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG2
Value: 0297
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: ARG3
Value: 1
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_EXTEN
Value: 0297
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_CONTEXT
Value: from-internal
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_PRIORITY
Value: 2
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];2
Variable: MACRO_DEPTH
Value: 0
Uniqueid: 1346903897.38

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: CHANLOCALSTATUS
Value: ANSWER
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: Local/[email protected];2
Uniqueid: 1346903897.38
CallerIDNum: 0298
CallerIDName: QTest2
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: PLAYBACKSTATUS
Value: SUCCESS
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: VarSet
Privilege: dialplan,all
Channel: Local/[email protected];1
Variable: MACRO_DEPTH
Value: 0
Uniqueid: 1346903897.37

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Hangup
Privilege: call,all
Channel: Local/[email protected];1
Uniqueid: 1346903897.37
CallerIDNum: 0297
CallerIDName: QTest1
ConnectedLineNum: 0297
ConnectedLineName: QTest1
Cause: 16
Cause-txt: Normal Clearing

[Sep 6 05:58:20] DEBUG[3416] manager.c: Examining event:
Event: Cdr
Privilege: cdr,all
AccountCode:
Source: 0297
Destination: 0297_0298
DestinationContext: from-ccss-internal
CallerID: “QTest1” <0297>
Channel: Local/[email protected];1
DestinationChannel:
LastApplication: Playback
LastData: beep&calling&extension
StartTime: 2012-09-06 05:58:17
AnswerTime: 2012-09-06 05:58:20
EndTime: 2012-09-06 05:58:20
Duration: 3
BillableSeconds: 0
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1346903897.37
UserField:

[Sep 6 05:58:20] DEBUG[3435] manager.c: Examining event:
Event: Cdr
Privilege: cdr,all
AccountCode:
Source: 0297
Destination: 0297_0298
DestinationContext: from-ccss-internal
CallerID: “QTest1” <0297>
Channel: Local/[email protected];1
DestinationChannel:
LastApplication: Playback
LastData: beep&calling&extension
StartTime: 2012-09-06 05:58:17
AnswerTime: 2012-09-06 05:58:20
EndTime: 2012-09-06 05:58:20
Duration: 3
BillableSeconds: 0
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1346903897.37
UserField:

[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: Cdr
Privilege: cdr,all
AccountCode:
Source: 0297
Destination: 0297_0298
DestinationContext: from-ccss-internal
CallerID: “QTest1” <0297>
Channel: Local/[email protected];1
DestinationChannel:
LastApplication: Playback
LastData: beep&calling&extension
StartTime: 2012-09-06 05:58:17
AnswerTime: 2012-09-06 05:58:20
EndTime: 2012-09-06 05:58:20
Duration: 3
BillableSeconds: 0
Disposition: ANSWERED
AMAFlags: DOCUMENTATION
UniqueID: 1346903897.37
UserField:

[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘2012-09-06 05:58:17’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘“QTest1” <0297>’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘from-ccss-internal’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘Local/[email protected];1’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘Playback’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘beep&calling&extension’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘3’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘0’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘ANSWERED’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘DOCUMENTATION’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘1346903897.37’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘(null)’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘0297’
[Sep 6 05:58:20] DEBUG[870] pbx.c: Function result is ‘0297_0298’
[Sep 6 05:58:20] DEBUG[870] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test,src,dst) VALUES (‘2012-09-06 05:58:17’,’“QTest1” <0297>’,‘from-ccss-internal’,‘Local/[email protected];1’,’’,‘Playback’,‘beep&calling&extension’,‘3’,‘0’,‘ANSWERED’,‘DOCUMENTATION’,’’,‘1346903897.37’,’’,’’,‘0297’,‘0297_0298’)
[Sep 6 05:58:21] DEBUG[3216] devicestate.c: No provider found, checking channel drivers for Local - [email protected]
[Sep 6 05:58:21] DEBUG[3216] chan_local.c: Checking if extension [email protected] exists (devicestate)
[Sep 6 05:58:21] DEBUG[3216] devicestate.c: Changing state for Local/[email protected] - state 1 (Not in use)
[Sep 6 05:58:21] DEBUG[3216] devicestate.c: device ‘Local/[email protected]’ state ‘1’
[Sep 6 05:58:21] DEBUG[3478] app_queue.c: Device ‘Local/[email protected]’ changed to state ‘1’ (Not in use) but we don’t care because they’re not a member of any queue.
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 548 ms (t1 274 ms (Retrans id #169020))
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: Trying to put ‘BYE sip:029’ onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 548 ms (t1 274 ms (Retrans id #169023))
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: Trying to put ‘BYE sip:029’ onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: = Looking for Call ID: [email protected]:5060 (Checking To) --From tag as09c7d38d --To-tag 745fcc29
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: Stopping retransmission on ‘[email protected]:5060’ of Request 103: Match Found
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: = Looking for Call ID: [email protected]:5060 (Checking To) --From tag as09c7d38d --To-tag 745fcc29
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: Stopping retransmission on ‘[email protected]:5060’ of Request 103: Match Not Found
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 1096 ms (t1 274 ms (Retrans id #169023))
[Sep 6 05:58:21] DEBUG[3278] chan_sip.c: Trying to put ‘BYE sip:029’ onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:22] DEBUG[3278] chan_sip.c: = Looking for Call ID: [email protected]:5060 (Checking To) --From tag as09c7d38d --To-tag 745fcc29
[Sep 6 05:58:22] DEBUG[3278] chan_sip.c: Stopping retransmission on ‘[email protected]:5060’ of Request 104: Match Found
[Sep 6 05:58:22] DEBUG[3278] chan_sip.c: Destroying SIP dialog [email protected]:5060
[Sep 6 05:58:22] DEBUG[3278] rtp_engine.c: Destroyed RTP instance ‘0x1bec78c8’
[Sep 6 05:58:27] DEBUG[3278] chan_sip.c: = Looking for Call ID: 3c2db59e80e6-ja1y1hhl72jn (Checking From) --From tag wqz70df41l --To-tag as24114dda
[Sep 6 05:58:27] DEBUG[3278] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
[Sep 6 05:58:27] DEBUG[3278] chan_sip.c: Trying to put ‘SIP/2.0 401’ onto UDP socket destined for 172.16.0.5:1024
[Sep 6 05:58:27] DEBUG[3278] chan_sip.c: = Looking for Call ID: 3c2db59e80e6-ja1y1hhl72jn (Checking From) --From tag wqz70df41l --To-tag as24114dda
[Sep 6 05:58:27] DEBUG[3278] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE
[Sep 6 05:58:27] DEBUG[3278] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 172.16.0.5:1024
[Sep 6 05:58:27] DEBUG[3278] netsock2.c: Splitting ‘172.16.0.5:1024’ into…

It’s clearly a CODEC issue, is .117 the IP address of the peer that is disconnecting?

Sep 6 05:58:20] DEBUG[3278] chan_sip.c: Trying to put 'ACK sip:029' onto UDP socket destined for 172.32.1.117:15736
[Sep 6 05:58:20] DEBUG[3278] channel.c: Soft-Hanging up channel 'SIP/0297-0000001d'
[Sep 6 05:58:20] DEBUG[3569] manager.c: Examining event:
Event: ChannelUpdate
Privilege: system,all

Please use pastebin.ca for long logs

Please use the [code]code[/code] tags for all logs posted in forum so they are easier to read.

Thanks for the help and advise on log logs, I do apologise.

Both testing soft phones are on IP 172.32.1.63

That is your problem right there. You can’t run two softphones from one IP address.

I knew I smelled a NAT issues and I was close.

Thank you so much, will test and let you know.

Kind regards
Quentin