[Home]

Summary:ASTERISK-17369: CALLCOMPLETION(cc_monitor_policy) has no affect after the call attempt ends
Reporter:Philippe Lindheimer (p_lindheimer)Labels:
Date Opened:2011-02-08 15:44:20.000-0600Date Closed:
Priority:MajorRegression?No
Status:Open/NewComponents:Core/CallCompletionSupplementaryServices
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:In my scenario, my goal is to not set any CallCompletion settings in sip.conf (or other channel specific files). Instead, I am using CALLCOMPLETION() function to set all the settings on call setup based on information in AstDB for both the Agent (caller) and the Monitor (target extension(s) I am calling.

I am finding that the setting appears to take based on the debug messages but as soon as I hangup the call (in a scenario where the target extension is NOANSWER) the settings get forgotten and everything gets dumped thus I can never campon the call. As soon as I set the cc_monitor_policy against the target device I am calling in sip.conf, everything works. However, this should not be necessary.

EXPECTED BEHAVIOR:

any cc_monitor_* setting that is set with CALLCOMPLETION() function should 'stick' to any devices that you attempt to call at least for the purpose of any subsequent call back attempts that are to be made to that target extension such that no channel specific settings are needed. (This is important for scenarios like hot-desking where it may change depending on who is logged onto a device).

I have added a call trace without cc_monitor_policy set in sip.conf and then with it set to show the difference.

****** ADDITIONAL INFORMATION ******

No settings in sip.conf, note the success after the dial of:

[Feb  8 13:30:46] CC[12136]: ccss.c:1793 cc_extension_monitor_init: Created an extension cc interface for '3001@from-internal' with id 1 and parent 0

followed by the 'failure' after the hangup:

[Feb  8 13:30:48] CC[12136]: ccss.c:1522 cc_monitor_destroy: Core 0: Calling destructor for monitor 3001@from-internal
[Feb  8 13:30:48] CC[12136]: ccss.c:1415 cc_interface_destroy: Destroying cc interface 3001@from-internal
[Feb  8 13:30:48] CC[12108]: ccss.c:2956 cc_do_state_change: Core 0: State change to 1 requested. Reason: CC offered to caller SIP/3000-00000000
[Feb  8 13:30:48] CC[12108]: ccss.c:2959 cc_do_state_change: Core 0: Unable to find core instance.

Full call trace:

   -- Executing [3001@from-internal:1] ExecIf("SIP/3000-00000000", "0?Set(__RINGTIMER=0)") in new stack
   -- Executing [3001@from-internal:2] Macro("SIP/3000-00000000", "exten-vm,3001,3001,0,0,0") in new stack
   -- Executing [s@macro-exten-vm:1] Macro("SIP/3000-00000000", "user-callerid,") in new stack
   -- Executing [s@macro-user-callerid:1] Set("SIP/3000-00000000", "AMPUSER=3000") in new stack
   -- Executing [s@macro-user-callerid:2] GotoIf("SIP/3000-00000000", "0?report") in new stack
   -- Executing [s@macro-user-callerid:3] ExecIf("SIP/3000-00000000", "1?Set(REALCALLERIDNUM=3000)") in new stack
   -- Executing [s@macro-user-callerid:4] Set("SIP/3000-00000000", "AMPUSER=3000") in new stack
   -- Executing [s@macro-user-callerid:5] Set("SIP/3000-00000000", "AMPUSERCIDNAME=Aastra White") in new stack
   -- Executing [s@macro-user-callerid:6] GotoIf("SIP/3000-00000000", "0?report") in new stack
   -- Executing [s@macro-user-callerid:7] Set("SIP/3000-00000000", "AMPUSERCID=3000") in new stack
   -- Executing [s@macro-user-callerid:8] Set("SIP/3000-00000000", "CALLERID(all)="Aastra White" <3000>") in new stack
   -- Executing [s@macro-user-callerid:9] NoOp("SIP/3000-00000000", "[TRACE](3) Current Concurrency Count for 3000: 0, User Limit: 0") in new stack
   -- Executing [s@macro-user-callerid:10] GotoIf("SIP/3000-00000000", "0?limit") in new stack
   -- Executing [s@macro-user-callerid:11] ExecIf("SIP/3000-00000000", "0?Set(GROUP(concurrency_limit)=3000)") in new stack
   -- Executing [s@macro-user-callerid:12] GosubIf("SIP/3000-00000000", "7?sub-ccss,s,1(macro-exten-vm,3001)") in new stack
   -- Executing [s@sub-ccss:1] ExecIf("SIP/3000-00000000", "0?Return()") in new stack
   -- Executing [s@sub-ccss:2] Set("SIP/3000-00000000", "CCSS_SETUP=TRUE") in new stack
   -- Executing [s@sub-ccss:3] NoOp("SIP/3000-00000000", "[TRACE](3) AMPUSER: 3000 Calling 3001:macro-exten-vm checking if all happy") in new stack
   -- Executing [s@sub-ccss:4] GosubIf("SIP/3000-00000000", "7?monitor_config,1(macro-exten-vm,3001):monitor_default,1(macro-exten-vm,3001)") in new stack
   -- Executing [monitor_config@sub-ccss:1] Set("SIP/3000-00000000", "CALLCOMPLETION(cc_monitor_policy)=generic") in new stack
   -- Executing [monitor_config@sub-ccss:2] GotoIf("SIP/3000-00000000", "1?set_monitor") in new stack
   -- Goto (sub-ccss,monitor_config,6)
   -- Executing [monitor_config@sub-ccss:6] Set("SIP/3000-00000000", "CALLCOMPLETION(cc_max_monitors)=") in new stack
   -- Executing [monitor_config@sub-ccss:7] Return("SIP/3000-00000000", "TRUE") in new stack
   -- Executing [s@sub-ccss:5] GosubIf("SIP/3000-00000000", "7?agent_config,1(macro-exten-vm,3001):agent_default,1(macro-exten-vm,3001)") in new stack
   -- Executing [agent_config@sub-ccss:1] Set("SIP/3000-00000000", "CALLCOMPLETION(cc_agent_policy)=generic") in new stack
   -- Executing [agent_config@sub-ccss:2] Set("SIP/3000-00000000", "CALLCOMPLETION(cc_offer_timer)=30") in new stack
   -- Executing [agent_config@sub-ccss:3] Set("SIP/3000-00000000", "CALLCOMPLETION(ccbs_available_timer)=4800") in new stack
   -- Executing [agent_config@sub-ccss:4] Set("SIP/3000-00000000", "CALLCOMPLETION(ccnr_available_timer)=7200") in new stack
   -- Executing [agent_config@sub-ccss:5] ExecIf("SIP/3000-00000000", "1?Set(CALLCOMPLETION(cc_recall_timer)=5)") in new stack
   -- Executing [agent_config@sub-ccss:6] ExecIf("SIP/3000-00000000", "1?Set(CALLCOMPLETION(cc_max_agents)=5)") in new stack
   -- Executing [agent_config@sub-ccss:7] ExecIf("SIP/3000-00000000", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/3000_3001@from-ccss-internal)") in new stack
   -- Executing [agent_config@sub-ccss:8] ExecIf("SIP/3000-00000000", "1?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/3000_3001@from-ccss-extension)") in new stack
   -- Executing [agent_config@sub-ccss:9] ExecIf("SIP/3000-00000000", "9?Set(CALLCOMPLETION(cc_callback_macro)=ccss-default)") in new stack
   -- Executing [agent_config@sub-ccss:10] Return("SIP/3000-00000000", "") in new stack
   -- Executing [s@sub-ccss:6] Return("SIP/3000-00000000", "") in new stack
   -- Executing [s@macro-user-callerid:13] ExecIf("SIP/3000-00000000", "0?Set(CHANNEL(language)=)") in new stack
   -- Executing [s@macro-user-callerid:14] GotoIf("SIP/3000-00000000", "0?continue") in new stack
   -- Executing [s@macro-user-callerid:15] Set("SIP/3000-00000000", "__TTL=64") in new stack
   -- Executing [s@macro-user-callerid:16] GotoIf("SIP/3000-00000000", "1?continue") in new stack
   -- Goto (macro-user-callerid,s,27)
   -- Executing [s@macro-user-callerid:27] Set("SIP/3000-00000000", "CALLERID(number)=3000") in new stack
   -- Executing [s@macro-user-callerid:28] Set("SIP/3000-00000000", "CALLERID(name)=Aastra White") in new stack
   -- Executing [s@macro-user-callerid:29] NoOp("SIP/3000-00000000", "Using CallerID "Aastra White" <3000>") in new stack
   -- Executing [s@macro-exten-vm:2] Set("SIP/3000-00000000", "RingGroupMethod=none") in new stack
   -- Executing [s@macro-exten-vm:3] Set("SIP/3000-00000000", "__EXTTOCALL=3001") in new stack
   -- Executing [s@macro-exten-vm:4] Set("SIP/3000-00000000", "RT=15") in new stack
   -- Executing [s@macro-exten-vm:5] Macro("SIP/3000-00000000", "record-enable,3001,IN") in new stack
   -- Executing [s@macro-record-enable:1] GotoIf("SIP/3000-00000000", "1?check") in new stack
   -- Goto (macro-record-enable,s,4)
   -- Executing [s@macro-record-enable:4] ExecIf("SIP/3000-00000000", "0?MacroExit()") in new stack
   -- Executing [s@macro-record-enable:5] GotoIf("SIP/3000-00000000", "0?Group:OUT") in new stack
   -- Goto (macro-record-enable,s,15)
   -- Executing [s@macro-record-enable:15] GotoIf("SIP/3000-00000000", "1?IN") in new stack
   -- Goto (macro-record-enable,s,20)
   -- Executing [s@macro-record-enable:20] ExecIf("SIP/3000-00000000", "1?MacroExit()") in new stack
   -- Executing [s@macro-exten-vm:6] Macro("SIP/3000-00000000", "dial-one,15,tr,3001") in new stack
   -- Executing [s@macro-dial-one:1] Set("SIP/3000-00000000", "DEXTEN=3001") in new stack
   -- Executing [s@macro-dial-one:2] Set("SIP/3000-00000000", "DIALSTATUS_CW=") in new stack
   -- Executing [s@macro-dial-one:3] GosubIf("SIP/3000-00000000", "0?screen,1") in new stack
   -- Executing [s@macro-dial-one:4] GosubIf("SIP/3000-00000000", "0?cf,1") in new stack
   -- Executing [s@macro-dial-one:5] GotoIf("SIP/3000-00000000", "1?skip1") in new stack
   -- Goto (macro-dial-one,s,8)
   -- Executing [s@macro-dial-one:8] GotoIf("SIP/3000-00000000", "0?nodial") in new stack
   -- Executing [s@macro-dial-one:9] GotoIf("SIP/3000-00000000", "0?continue") in new stack
   -- Executing [s@macro-dial-one:10] Set("SIP/3000-00000000", "EXTHASCW=ENABLED") in new stack
   -- Executing [s@macro-dial-one:11] GotoIf("SIP/3000-00000000", "0?next1:cwinusebusy") in new stack
   -- Goto (macro-dial-one,s,23)
   -- Executing [s@macro-dial-one:23] GotoIf("SIP/3000-00000000", "1?next3:continue") in new stack
   -- Goto (macro-dial-one,s,24)
   -- Executing [s@macro-dial-one:24] ExecIf("SIP/3000-00000000", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
   -- Executing [s@macro-dial-one:25] GotoIf("SIP/3000-00000000", "0?nodial") in new stack
   -- Executing [s@macro-dial-one:26] GosubIf("SIP/3000-00000000", "1?dstring,1:dlocal,1") in new stack
   -- Executing [dstring@macro-dial-one:1] Set("SIP/3000-00000000", "DSTRING=") in new stack
   -- Executing [dstring@macro-dial-one:2] Set("SIP/3000-00000000", "DEVICES=3001") in new stack
   -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/3000-00000000", "0?Return()") in new stack
   -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/3000-00000000", "0?Set(DEVICES=001)") in new stack
   -- Executing [dstring@macro-dial-one:5] Set("SIP/3000-00000000", "LOOPCNT=1") in new stack
   -- Executing [dstring@macro-dial-one:6] Set("SIP/3000-00000000", "ITER=1") in new stack
   -- Executing [dstring@macro-dial-one:7] Set("SIP/3000-00000000", "THISDIAL=SIP/3001") in new stack
   -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/3000-00000000", "1?zap2dahdi,1") in new stack
   -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/3000-00000000", "0?Return()") in new stack
   -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/3000-00000000", "NEWDIAL=") in new stack
   -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/3000-00000000", "LOOPCNT2=1") in new stack
   -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/3000-00000000", "ITER2=1") in new stack
   -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/3000-00000000", "THISPART2=SIP/3001") in new stack
   -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/3000-00000000", "0?Set(THISPART2=DAHDI/3001)") in new stack
   -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/3000-00000000", "NEWDIAL=SIP/3001&") in new stack
   -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/3000-00000000", "ITER2=2") in new stack
   -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/3000-00000000", "0?begin2") in new stack
   -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/3000-00000000", "THISDIAL=SIP/3001") in new stack
   -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/3000-00000000", "") in new stack
   -- Executing [dstring@macro-dial-one:9] Set("SIP/3000-00000000", "DSTRING=SIP/3001&") in new stack
   -- Executing [dstring@macro-dial-one:10] Set("SIP/3000-00000000", "ITER=2") in new stack
   -- Executing [dstring@macro-dial-one:11] GotoIf("SIP/3000-00000000", "0?begin") in new stack
   -- Executing [dstring@macro-dial-one:12] Set("SIP/3000-00000000", "DSTRING=SIP/3001") in new stack
   -- Executing [dstring@macro-dial-one:13] Return("SIP/3000-00000000", "") in new stack
   -- Executing [s@macro-dial-one:27] GotoIf("SIP/3000-00000000", "0?nodial") in new stack
   -- Executing [s@macro-dial-one:28] GotoIf("SIP/3000-00000000", "1?skiptrace") in new stack
   -- Goto (macro-dial-one,s,30)
   -- Executing [s@macro-dial-one:30] Set("SIP/3000-00000000", "D_OPTIONS=tr") in new stack
   -- Executing [s@macro-dial-one:31] ExecIf("SIP/3000-00000000", "0?SIPAddHeader(Alert-Info: )") in new stack
   -- Executing [s@macro-dial-one:32] ExecIf("SIP/3000-00000000", "0?SIPAddHeader()") in new stack
   -- Executing [s@macro-dial-one:33] ExecIf("SIP/3000-00000000", "0?Set(CHANNEL(musicclass)=)") in new stack
   -- Executing [s@macro-dial-one:34] GosubIf("SIP/3000-00000000", "0?qwait,1") in new stack
   -- Executing [s@macro-dial-one:35] Set("SIP/3000-00000000", "__CWIGNORE=") in new stack
   -- Executing [s@macro-dial-one:36] Set("SIP/3000-00000000", "__KEEPCID=TRUE") in new stack
   -- Executing [s@macro-dial-one:37] GotoIf("SIP/3000-00000000", "0?usegoto,1") in new stack
   -- Executing [s@macro-dial-one:38] Dial("SIP/3000-00000000", "SIP/3001,15,tr") in new stack
[Feb  8 13:30:46] CC[12136]: ccss.c:1793 cc_extension_monitor_init: Created an extension cc interface for '3001@from-internal' with id 1 and parent 0
 == Using SIP RTP TOS bits 184
 == Using SIP RTP CoS mark 5
   -- Called 3001
   -- SIP/3001-00000001 is ringing
 == Spawn extension (macro-dial-one, s, 38) exited non-zero on 'SIP/3000-00000000' in macro 'dial-one'
 == Spawn extension (macro-exten-vm, s, 6) exited non-zero on 'SIP/3000-00000000' in macro 'exten-vm'
 == Spawn extension (from-internal, 3001, 2) exited non-zero on 'SIP/3000-00000000'
   -- Executing [h@from-internal:1] Macro("SIP/3000-00000000", "hangupcall") in new stack
   -- Executing [s@macro-hangupcall:1] GotoIf("SIP/3000-00000000", "1?skiprg") in new stack
   -- Goto (macro-hangupcall,s,4)
   -- Executing [s@macro-hangupcall:4] GotoIf("SIP/3000-00000000", "1?skipblkvm") in new stack
   -- Goto (macro-hangupcall,s,7)
   -- Executing [s@macro-hangupcall:7] GotoIf("SIP/3000-00000000", "1?theend") in new stack
   -- Goto (macro-hangupcall,s,9)
   -- Executing [s@macro-hangupcall:9] Hangup("SIP/3000-00000000", "") in new stack
 == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/3000-00000000' in macro 'hangupcall'
 == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/3000-00000000'
[Feb  8 13:30:48] CC[12136]: ccss.c:1522 cc_monitor_destroy: Core 0: Calling destructor for monitor 3001@from-internal
[Feb  8 13:30:48] CC[12136]: ccss.c:1415 cc_interface_destroy: Destroying cc interface 3001@from-internal
[Feb  8 13:30:48] CC[12108]: ccss.c:2956 cc_do_state_change: Core 0: State change to 1 requested. Reason: CC offered to caller SIP/3000-00000000
[Feb  8 13:30:48] CC[12108]: ccss.c:2959 cc_do_state_change: Core 0: Unable to find core instance.

Now setting cc_monitor_policy in sip.conf for SIP/3001, note after the dial we get:

[Feb  8 13:34:39] CC[12149]: ccss.c:1793 cc_extension_monitor_init: Created an extension cc interface for '3001@from-internal' with id 2 and parent 0

as well as:

[Feb  8 13:34:39] CC[12125]: ccss.c:4003 ast_cc_monitor_count: Counted 0 monitors
[Feb  8 13:34:39] CC[12149]: ccss.c:2193 count_agents: Counted 0 agents
[Feb  8 13:34:39] CC[12149]: ccss.c:973 find_agent_callbacks: Returning agent backend generic
[Feb  8 13:34:39] CC[12149]: ccss.c:2262 cc_agent_init: Core 1: Created an agent for caller SIP/3000
[Feb  8 13:34:39] CC[12149]: ccss.c:886 find_monitor_callbacks: Returning monitor backend generic
[Feb  8 13:34:39] CC[12149]: ccss.c:1973 cc_device_monitor_init: Core 1: Created a device cc interface for 'SIP/3001' with id 3 and parent 2
   -- SIP/3001-00000003 is ringing
[Feb  8 13:34:39] CC[12125]: ccss.c:4003 ast_cc_monitor_count: Counted 1 monitors
[Feb  8 13:34:39] CC[12149]: ccss.c:2057 ast_handle_cc_control_frame: Core 1: Device SIP/3001 sent us multiple CC control frames. Ignoring those beyond the first.
[Feb  8 13:34:39] CC[12149]: ccss.c:886 find_monitor_callbacks: Returning monitor backend generic

then after we hangup we get:

[Feb  8 13:34:42] CC[12108]: ccss.c:2956 cc_do_state_change: Core 1: State change to 1 requested. Reason: CC offered to caller SIP/3000-00000002
[Feb  8 13:34:42] CC[12108]: ccss.c:2385 cc_generic_agent_start_offer_timer: Core 1: About to schedule offer timer expiration for 30000 ms
[Feb  8 13:34:42] CC[12108]: ccss.c:2716 cc_caller_offered: Core 1: Started the offer timer for the agent SIP/3000!

at which point I can do a successful CallCompletionRequest()

Full trace below:

   -- Executing [3001@from-internal:1] ExecIf("SIP/3000-00000002", "0?Set(__RINGTIMER=0)") in new stack
   -- Executing [3001@from-internal:2] Macro("SIP/3000-00000002", "exten-vm,3001,3001,0,0,0") in new stack
   -- Executing [s@macro-exten-vm:1] Macro("SIP/3000-00000002", "user-callerid,") in new stack
   -- Executing [s@macro-user-callerid:1] Set("SIP/3000-00000002", "AMPUSER=3000") in new stack
   -- Executing [s@macro-user-callerid:2] GotoIf("SIP/3000-00000002", "0?report") in new stack
   -- Executing [s@macro-user-callerid:3] ExecIf("SIP/3000-00000002", "1?Set(REALCALLERIDNUM=3000)") in new stack
   -- Executing [s@macro-user-callerid:4] Set("SIP/3000-00000002", "AMPUSER=3000") in new stack
   -- Executing [s@macro-user-callerid:5] Set("SIP/3000-00000002", "AMPUSERCIDNAME=Aastra White") in new stack
   -- Executing [s@macro-user-callerid:6] GotoIf("SIP/3000-00000002", "0?report") in new stack
   -- Executing [s@macro-user-callerid:7] Set("SIP/3000-00000002", "AMPUSERCID=3000") in new stack
   -- Executing [s@macro-user-callerid:8] Set("SIP/3000-00000002", "CALLERID(all)="Aastra White" <3000>") in new stack
   -- Executing [s@macro-user-callerid:9] NoOp("SIP/3000-00000002", "[TRACE](3) Current Concurrency Count for 3000: 0, User Limit: 0") in new stack
   -- Executing [s@macro-user-callerid:10] GotoIf("SIP/3000-00000002", "0?limit") in new stack
   -- Executing [s@macro-user-callerid:11] ExecIf("SIP/3000-00000002", "0?Set(GROUP(concurrency_limit)=3000)") in new stack
   -- Executing [s@macro-user-callerid:12] GosubIf("SIP/3000-00000002", "7?sub-ccss,s,1(macro-exten-vm,3001)") in new stack
   -- Executing [s@sub-ccss:1] ExecIf("SIP/3000-00000002", "0?Return()") in new stack
   -- Executing [s@sub-ccss:2] Set("SIP/3000-00000002", "CCSS_SETUP=TRUE") in new stack
   -- Executing [s@sub-ccss:3] NoOp("SIP/3000-00000002", "[TRACE](3) AMPUSER: 3000 Calling 3001:macro-exten-vm checking if all happy") in new stack
   -- Executing [s@sub-ccss:4] GosubIf("SIP/3000-00000002", "7?monitor_config,1(macro-exten-vm,3001):monitor_default,1(macro-exten-vm,3001)") in new stack
   -- Executing [monitor_config@sub-ccss:1] Set("SIP/3000-00000002", "CALLCOMPLETION(cc_monitor_policy)=generic") in new stack
   -- Executing [monitor_config@sub-ccss:2] GotoIf("SIP/3000-00000002", "1?set_monitor") in new stack
   -- Goto (sub-ccss,monitor_config,6)
   -- Executing [monitor_config@sub-ccss:6] Set("SIP/3000-00000002", "CALLCOMPLETION(cc_max_monitors)=") in new stack
   -- Executing [monitor_config@sub-ccss:7] Return("SIP/3000-00000002", "TRUE") in new stack
   -- Executing [s@sub-ccss:5] GosubIf("SIP/3000-00000002", "7?agent_config,1(macro-exten-vm,3001):agent_default,1(macro-exten-vm,3001)") in new stack
   -- Executing [agent_config@sub-ccss:1] Set("SIP/3000-00000002", "CALLCOMPLETION(cc_agent_policy)=generic") in new stack
   -- Executing [agent_config@sub-ccss:2] Set("SIP/3000-00000002", "CALLCOMPLETION(cc_offer_timer)=30") in new stack
   -- Executing [agent_config@sub-ccss:3] Set("SIP/3000-00000002", "CALLCOMPLETION(ccbs_available_timer)=4800") in new stack
   -- Executing [agent_config@sub-ccss:4] Set("SIP/3000-00000002", "CALLCOMPLETION(ccnr_available_timer)=7200") in new stack
   -- Executing [agent_config@sub-ccss:5] ExecIf("SIP/3000-00000002", "1?Set(CALLCOMPLETION(cc_recall_timer)=5)") in new stack
   -- Executing [agent_config@sub-ccss:6] ExecIf("SIP/3000-00000002", "1?Set(CALLCOMPLETION(cc_max_agents)=5)") in new stack
   -- Executing [agent_config@sub-ccss:7] ExecIf("SIP/3000-00000002", "0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/3000_3001@from-ccss-internal)") in new stack
   -- Executing [agent_config@sub-ccss:8] ExecIf("SIP/3000-00000002", "1?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/3000_3001@from-ccss-extension)") in new stack
   -- Executing [agent_config@sub-ccss:9] ExecIf("SIP/3000-00000002", "9?Set(CALLCOMPLETION(cc_callback_macro)=ccss-default)") in new stack
   -- Executing [agent_config@sub-ccss:10] Return("SIP/3000-00000002", "") in new stack
   -- Executing [s@sub-ccss:6] Return("SIP/3000-00000002", "") in new stack
   -- Executing [s@macro-user-callerid:13] ExecIf("SIP/3000-00000002", "0?Set(CHANNEL(language)=)") in new stack
   -- Executing [s@macro-user-callerid:14] GotoIf("SIP/3000-00000002", "0?continue") in new stack
   -- Executing [s@macro-user-callerid:15] Set("SIP/3000-00000002", "__TTL=64") in new stack
   -- Executing [s@macro-user-callerid:16] GotoIf("SIP/3000-00000002", "1?continue") in new stack
   -- Goto (macro-user-callerid,s,27)
   -- Executing [s@macro-user-callerid:27] Set("SIP/3000-00000002", "CALLERID(number)=3000") in new stack
   -- Executing [s@macro-user-callerid:28] Set("SIP/3000-00000002", "CALLERID(name)=Aastra White") in new stack
   -- Executing [s@macro-user-callerid:29] NoOp("SIP/3000-00000002", "Using CallerID "Aastra White" <3000>") in new stack
   -- Executing [s@macro-exten-vm:2] Set("SIP/3000-00000002", "RingGroupMethod=none") in new stack
   -- Executing [s@macro-exten-vm:3] Set("SIP/3000-00000002", "__EXTTOCALL=3001") in new stack
   -- Executing [s@macro-exten-vm:4] Set("SIP/3000-00000002", "RT=15") in new stack
   -- Executing [s@macro-exten-vm:5] Macro("SIP/3000-00000002", "record-enable,3001,IN") in new stack
   -- Executing [s@macro-record-enable:1] GotoIf("SIP/3000-00000002", "1?check") in new stack
   -- Goto (macro-record-enable,s,4)
   -- Executing [s@macro-record-enable:4] ExecIf("SIP/3000-00000002", "0?MacroExit()") in new stack
   -- Executing [s@macro-record-enable:5] GotoIf("SIP/3000-00000002", "0?Group:OUT") in new stack
   -- Goto (macro-record-enable,s,15)
   -- Executing [s@macro-record-enable:15] GotoIf("SIP/3000-00000002", "1?IN") in new stack
   -- Goto (macro-record-enable,s,20)
   -- Executing [s@macro-record-enable:20] ExecIf("SIP/3000-00000002", "1?MacroExit()") in new stack
   -- Executing [s@macro-exten-vm:6] Macro("SIP/3000-00000002", "dial-one,15,tr,3001") in new stack
   -- Executing [s@macro-dial-one:1] Set("SIP/3000-00000002", "DEXTEN=3001") in new stack
   -- Executing [s@macro-dial-one:2] Set("SIP/3000-00000002", "DIALSTATUS_CW=") in new stack
   -- Executing [s@macro-dial-one:3] GosubIf("SIP/3000-00000002", "0?screen,1") in new stack
   -- Executing [s@macro-dial-one:4] GosubIf("SIP/3000-00000002", "0?cf,1") in new stack
   -- Executing [s@macro-dial-one:5] GotoIf("SIP/3000-00000002", "1?skip1") in new stack
   -- Goto (macro-dial-one,s,8)
   -- Executing [s@macro-dial-one:8] GotoIf("SIP/3000-00000002", "0?nodial") in new stack
   -- Executing [s@macro-dial-one:9] GotoIf("SIP/3000-00000002", "0?continue") in new stack
   -- Executing [s@macro-dial-one:10] Set("SIP/3000-00000002", "EXTHASCW=ENABLED") in new stack
   -- Executing [s@macro-dial-one:11] GotoIf("SIP/3000-00000002", "0?next1:cwinusebusy") in new stack
   -- Goto (macro-dial-one,s,23)
   -- Executing [s@macro-dial-one:23] GotoIf("SIP/3000-00000002", "1?next3:continue") in new stack
   -- Goto (macro-dial-one,s,24)
   -- Executing [s@macro-dial-one:24] ExecIf("SIP/3000-00000002", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
   -- Executing [s@macro-dial-one:25] GotoIf("SIP/3000-00000002", "0?nodial") in new stack
   -- Executing [s@macro-dial-one:26] GosubIf("SIP/3000-00000002", "1?dstring,1:dlocal,1") in new stack
   -- Executing [dstring@macro-dial-one:1] Set("SIP/3000-00000002", "DSTRING=") in new stack
   -- Executing [dstring@macro-dial-one:2] Set("SIP/3000-00000002", "DEVICES=3001") in new stack
   -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/3000-00000002", "0?Return()") in new stack
   -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/3000-00000002", "0?Set(DEVICES=001)") in new stack
   -- Executing [dstring@macro-dial-one:5] Set("SIP/3000-00000002", "LOOPCNT=1") in new stack
   -- Executing [dstring@macro-dial-one:6] Set("SIP/3000-00000002", "ITER=1") in new stack
   -- Executing [dstring@macro-dial-one:7] Set("SIP/3000-00000002", "THISDIAL=SIP/3001") in new stack
   -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/3000-00000002", "1?zap2dahdi,1") in new stack
   -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/3000-00000002", "0?Return()") in new stack
   -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/3000-00000002", "NEWDIAL=") in new stack
   -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/3000-00000002", "LOOPCNT2=1") in new stack
   -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/3000-00000002", "ITER2=1") in new stack
   -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/3000-00000002", "THISPART2=SIP/3001") in new stack
   -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/3000-00000002", "0?Set(THISPART2=DAHDI/3001)") in new stack
   -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/3000-00000002", "NEWDIAL=SIP/3001&") in new stack
   -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/3000-00000002", "ITER2=2") in new stack
   -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/3000-00000002", "0?begin2") in new stack
   -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/3000-00000002", "THISDIAL=SIP/3001") in new stack
   -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/3000-00000002", "") in new stack
   -- Executing [dstring@macro-dial-one:9] Set("SIP/3000-00000002", "DSTRING=SIP/3001&") in new stack
   -- Executing [dstring@macro-dial-one:10] Set("SIP/3000-00000002", "ITER=2") in new stack
   -- Executing [dstring@macro-dial-one:11] GotoIf("SIP/3000-00000002", "0?begin") in new stack
   -- Executing [dstring@macro-dial-one:12] Set("SIP/3000-00000002", "DSTRING=SIP/3001") in new stack
   -- Executing [dstring@macro-dial-one:13] Return("SIP/3000-00000002", "") in new stack
   -- Executing [s@macro-dial-one:27] GotoIf("SIP/3000-00000002", "0?nodial") in new stack
   -- Executing [s@macro-dial-one:28] GotoIf("SIP/3000-00000002", "1?skiptrace") in new stack
   -- Goto (macro-dial-one,s,30)
   -- Executing [s@macro-dial-one:30] Set("SIP/3000-00000002", "D_OPTIONS=tr") in new stack
   -- Executing [s@macro-dial-one:31] ExecIf("SIP/3000-00000002", "0?SIPAddHeader(Alert-Info: )") in new stack
   -- Executing [s@macro-dial-one:32] ExecIf("SIP/3000-00000002", "0?SIPAddHeader()") in new stack
   -- Executing [s@macro-dial-one:33] ExecIf("SIP/3000-00000002", "0?Set(CHANNEL(musicclass)=)") in new stack
   -- Executing [s@macro-dial-one:34] GosubIf("SIP/3000-00000002", "0?qwait,1") in new stack
   -- Executing [s@macro-dial-one:35] Set("SIP/3000-00000002", "__CWIGNORE=") in new stack
   -- Executing [s@macro-dial-one:36] Set("SIP/3000-00000002", "__KEEPCID=TRUE") in new stack
   -- Executing [s@macro-dial-one:37] GotoIf("SIP/3000-00000002", "0?usegoto,1") in new stack
   -- Executing [s@macro-dial-one:38] Dial("SIP/3000-00000002", "SIP/3001,15,tr") in new stack
[Feb  8 13:34:39] CC[12149]: ccss.c:1793 cc_extension_monitor_init: Created an extension cc interface for '3001@from-internal' with id 2 and parent 0
 == Using SIP RTP TOS bits 184
 == Using SIP RTP CoS mark 5
   -- Called 3001
[Feb  8 13:34:39] CC[12125]: ccss.c:4003 ast_cc_monitor_count: Counted 0 monitors
[Feb  8 13:34:39] CC[12149]: ccss.c:2193 count_agents: Counted 0 agents
[Feb  8 13:34:39] CC[12149]: ccss.c:973 find_agent_callbacks: Returning agent backend generic
[Feb  8 13:34:39] CC[12149]: ccss.c:2262 cc_agent_init: Core 1: Created an agent for caller SIP/3000
[Feb  8 13:34:39] CC[12149]: ccss.c:886 find_monitor_callbacks: Returning monitor backend generic
[Feb  8 13:34:39] CC[12149]: ccss.c:1973 cc_device_monitor_init: Core 1: Created a device cc interface for 'SIP/3001' with id 3 and parent 2
   -- SIP/3001-00000003 is ringing
[Feb  8 13:34:39] CC[12125]: ccss.c:4003 ast_cc_monitor_count: Counted 1 monitors
[Feb  8 13:34:39] CC[12149]: ccss.c:2057 ast_handle_cc_control_frame: Core 1: Device SIP/3001 sent us multiple CC control frames. Ignoring those beyond the first.
[Feb  8 13:34:39] CC[12149]: ccss.c:886 find_monitor_callbacks: Returning monitor backend generic
   -- SIP/3001-00000003 is ringing
 == Spawn extension (macro-dial-one, s, 38) exited non-zero on 'SIP/3000-00000002' in macro 'dial-one'
 == Spawn extension (macro-exten-vm, s, 6) exited non-zero on 'SIP/3000-00000002' in macro 'exten-vm'
 == Spawn extension (from-internal, 3001, 2) exited non-zero on 'SIP/3000-00000002'
   -- Executing [h@from-internal:1] Macro("SIP/3000-00000002", "hangupcall") in new stack
   -- Executing [s@macro-hangupcall:1] GotoIf("SIP/3000-00000002", "1?skiprg") in new stack
   -- Goto (macro-hangupcall,s,4)
   -- Executing [s@macro-hangupcall:4] GotoIf("SIP/3000-00000002", "1?skipblkvm") in new stack
   -- Goto (macro-hangupcall,s,7)
   -- Executing [s@macro-hangupcall:7] GotoIf("SIP/3000-00000002", "1?theend") in new stack
   -- Goto (macro-hangupcall,s,9)
   -- Executing [s@macro-hangupcall:9] Hangup("SIP/3000-00000002", "") in new stack
 == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/3000-00000002' in macro 'hangupcall'
 == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/3000-00000002'
[Feb  8 13:34:42] CC[12108]: ccss.c:2956 cc_do_state_change: Core 1: State change to 1 requested. Reason: CC offered to caller SIP/3000-00000002
[Feb  8 13:34:42] CC[12108]: ccss.c:2385 cc_generic_agent_start_offer_timer: Core 1: About to schedule offer timer expiration for 30000 ms
[Feb  8 13:34:42] CC[12108]: ccss.c:2716 cc_caller_offered: Core 1: Started the offer timer for the agent SIP/3000!

Comments:By: Philippe Lindheimer (p_lindheimer) 2011-02-09 21:03:22.000-0600

oops - patch was added to wrong ticket, it was meant for:

https://issues.asterisk.org/view.php?id=18763

it should be deleted.