Dear FreePBX community members,
I have a working Freepbx installation (lets say pbx1) , with working inbound/outbound and local calls. The mysql database of pbx is replicated to another box - pbx2 . Outbound call through pbx2 works too, but when I’m calling a local SIP extension (between 2 extensions regeistered to pbx2), it rings for a second and then the caller party gets 603 declined (and called party gets cancel).
The Freepbx version on both of PBXes is 12.0.76.4 and they are installed from freepbx distribution image.
On pbx1 I have 3 commercial modules: extension routing, sys admin and xmpp. Does this difference have any effect, or it doesn’t matter? The config is identical (replicated database and no modifications in the custom files).
This is my sip flow:
Conv.| Time | 94.177.x.x | 82.79.x.x |
| | | 81.196.x.x |
0 |0.000000 | INVITE SDP (GSM spee | |
| |(45112) ------------------> (5060) | |
0 |0.000491 | 401 Unauthorized | |
| |(45112) <------------------ (5060) | |
0 |0.033248 | ACK | | |
| |(45112) ------------------> (5060) | |
0 |0.033928 | INVITE SDP (GSM spee | |
| |(45112) ------------------> (5060) | |
0 |0.274683 | 100 Trying| | |
| |(45112) <------------------ (5060) | |
1 |0.823690 | | INVITE SDP (g711U g7 |
| | |(5060) ------------------> (34717) |
0 |0.824255 | 180 Ringing | |
| |(45112) <------------------ (5060) | |
1 |0.913631 | | 180 Ringing |
| | |(5060) <------------------ (34717) |
0 |0.914643 | 180 Ringing | |
| |(45112) <------------------ (5060) | |
1 |2.827261 | | CANCEL | |
| | |(5060) ------------------> (34717) |
0 |2.833926 | 603 Declined | |
| |(45112) <------------------ (5060) | |
1 |2.836208 | | 200 OK | |
| | |(5060) <------------------ (34717) |
1 |2.836289 | | 487 Request Terminat |
| | |(5060) <------------------ (34717) |
1 |2.836351 | | ACK | |
| | |(5060) ------------------> (34717) |
0 |2.853194 | ACK | | |
| |(45112) ------------------> (5060) | |
the log :
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:1] GotoIf(“SIP/900-0000003b”, “0?ext-local,901,1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:2] Macro(“SIP/900-0000003b”, “user-callerid,”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/900-0000003b”, “TOUCH_MONITOR=1479290179.59”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/900-0000003b”, “AMPUSER=900”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/900-0000003b”, “0?report”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/900-0000003b”, “1?Set(REALCALLERIDNUM=900)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/900-0000003b”, “AMPUSER=900”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/900-0000003b”, “0?limit”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/900-0000003b”, “AMPUSERCIDNAME=Szabolcs1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/900-0000003b”, “0?report”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/900-0000003b”, “AMPUSERCID=900”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/900-0000003b”, “__DIAL_OPTIONS=Ttr”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/900-0000003b”, “CALLERID(all)=“Szabolcs1” <900>”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/900-0000003b”, “0?limit”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/900-0000003b”, “0?Set(GROUP(concurrency_limit)=900)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:14] GosubIf(“SIP/900-0000003b”, “7?sub-ccss,s,1(from-internal,901)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/900-0000003b”, “0?Return()”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/900-0000003b”, “CCSS_SETUP=TRUE”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/900-0000003b”, “0?monitor_config,1(from-internal,901):monitor_default,1(from-internal,901)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/900-0000003b”, “1?is_exten”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (sub-ccss,monitor_default,4)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [monitor_default@sub-ccss:4] Set(“SIP/900-0000003b”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [monitor_default@sub-ccss:5] Set(“SIP/900-0000003b”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [monitor_default@sub-ccss:6] Return(“SIP/900-0000003b”, “TRUE”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-ccss:4] GosubIf(“SIP/900-0000003b”, “7?agent_config,1():agent_default,1()”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:1] Set(“SIP/900-0000003b”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:2] Set(“SIP/900-0000003b”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:3] Set(“SIP/900-0000003b”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:4] Set(“SIP/900-0000003b”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:5] Set(“SIP/900-0000003b”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2016-11-16 11:56:19] WARNING[30287][C-000001b7] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:6] ExecIf(“SIP/900-0000003b”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:7] ExecIf(“SIP/900-0000003b”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:8] ExecIf(“SIP/900-0000003b”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/900_901@from-ccss-)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:9] Set(“SIP/900-0000003b”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2016-11-16 11:56:19] WARNING[30287][C-000001b7] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [agent_config@sub-ccss:10] Return(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-ccss:5] Set(“SIP/900-0000003b”, “DB(AMPUSER/900/ccss/last_number)=901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-ccss:6] Return(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:15] ExecIf(“SIP/900-0000003b”, “0?Set(CHANNEL(language)=)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/900-0000003b”, “0?continue”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:17] ExecIf(“SIP/900-0000003b”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:18] Set(“SIP/900-0000003b”, “__TTL=64”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:19] GotoIf(“SIP/900-0000003b”, “1?continue”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (macro-user-callerid,s,30)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/900-0000003b”, “CALLERID(number)=900”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/900-0000003b”, “CALLERID(name)=Szabolcs1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/900-0000003b”, “CDR(cnum)=900”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/900-0000003b”, “CDR(cnam)=Szabolcs1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-user-callerid:34] Set(“SIP/900-0000003b”, “CHANNEL(language)=en”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:3] Set(“SIP/900-0000003b”, “DIAL_OPTIONS=TtrI”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:4] Set(“SIP/900-0000003b”, “CONNECTEDLINE(num,i)=901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:5] Gosub(“SIP/900-0000003b”, “sub-presencestate-display,s,1(901)”) in new stack
[2016-11-16 11:56:19] WARNING[30287][C-000001b7] func_presencestate.c: PRESENCE_STATE unknown
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-presencestate-display:1] Goto(“SIP/900-0000003b”, “state-,1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (sub-presencestate-display,state-,1)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [state-@sub-presencestate-display:1] Set(“SIP/900-0000003b”, “PRESENCESTATE_DISPLAY=”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [state-@sub-presencestate-display:2] Return(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:6] Set(“SIP/900-0000003b”, “CONNECTEDLINE(name)=Szabolcs test1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:7] Set(“SIP/900-0000003b”, “FM_DIALSTATUS=NOT_INUSE”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:8] Set(“SIP/900-0000003b”, “__EXTTOCALL=901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:9] Set(“SIP/900-0000003b”, “__PICKUPMARK=901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:10] Macro(“SIP/900-0000003b”, “blkvm-setifempty,”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/900-0000003b”, “1?init”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/900-0000003b”, “__BLKVM_CHANNEL=SIP/900-0000003b”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/900-0000003b”, “SHARED(BLKVM,SIP/900-0000003b)=TRUE”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/900-0000003b”, “GOSUB_RETVAL=TRUE”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:11] GotoIf(“SIP/900-0000003b”, “1?skipov”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (from-internal,901,14)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:14] Set(“SIP/900-0000003b”, “RRNODEST=”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:15] Set(“SIP/900-0000003b”, “__NODEST=901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:16] GosubIf(“SIP/900-0000003b”, “0?sub-fmsetcid,s,1()”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:17] Set(“SIP/900-0000003b”, “RecordMethod=Group”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:18] Gosub(“SIP/900-0000003b”, “sub-record-check,s,1(exten,901,)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/900-0000003b”, “0?initialized”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:2] Set(“SIP/900-0000003b”, “__REC_STATUS=INITIALIZED”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/900-0000003b”, “NOW=1479290179”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:4] Set(“SIP/900-0000003b”, “__DAY=16”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:5] Set(“SIP/900-0000003b”, “__MONTH=11”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/900-0000003b”, “__YEAR=2016”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/900-0000003b”, “__TIMESTR=20161116-115619”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:8] Set(“SIP/900-0000003b”, “__FROMEXTEN=900”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/900-0000003b”, “__MON_FMT=wav”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/900-0000003b”, “Recordings initialized”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/900-0000003b”, “1?Set(ARG3=dontcare)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/900-0000003b”, “REC_POLICY_MODE_SAVE=”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/900-0000003b”, “0?Set(REC_STATUS=NO)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/900-0000003b”, “5?checkaction”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (sub-record-check,s,17)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/900-0000003b”, “1?sub-record-check,exten,1”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (sub-record-check,exten,1)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:1] NoOp(“SIP/900-0000003b”, “Exten Recording Check between 900 and 901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:2] Set(“SIP/900-0000003b”, “CALLTYPE=internal”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:3] ExecIf(“SIP/900-0000003b”, “0?Set(CALLTYPE=)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:4] Set(“SIP/900-0000003b”, “CALLEE=dontcare”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:5] ExecIf(“SIP/900-0000003b”, “0?Set(CALLEE=dontcare)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:6] GotoIf(“SIP/900-0000003b”, “0?callee”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:7] GotoIf(“SIP/900-0000003b”, “1?caller”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (sub-record-check,exten,13)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:13] Set(“SIP/900-0000003b”, “RECMODE=dontcare”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:14] ExecIf(“SIP/900-0000003b”, “0?Set(RECMODE=dontcare)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:15] ExecIf(“SIP/900-0000003b”, “1?Set(RECMODE=dontcare)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:16] Gosub(“SIP/900-0000003b”, “recordcheck,1(dontcare,internal,901)”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/900-0000003b”, “Starting recording check against dontcare”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/900-0000003b”, “dontcare”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [exten@sub-record-check:17] Return(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:19] Set(“SIP/900-0000003b”, “RingGroupMethod=ringallv2-prim”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:20] Set(“SIP/900-0000003b”, “_FMGRP=901”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:21] GotoIf(“SIP/900-0000003b”, “0?doconfirm”) in new stack
[2016-11-16 11:56:19] WARNING[30287][C-000001b7] ast_expr2.fl: ast_yyerror(): syntax error: syntax error, unexpected ‘+’, expecting $end; Input:
+
^
[2016-11-16 11:56:19] WARNING[30287][C-000001b7] ast_expr2.fl: If you have questions, please refer to https://wiki.asterisk.org/wiki/display/AST/Channel+Variables
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:22] Macro(“SIP/900-0000003b”, “dial,TtrI,”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/900-0000003b”, “1?dial”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Goto (macro-dial,s,3)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/900-0000003b”, “dialparties.agi”) in new stack
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: Caller ID name is ‘Szabolcs1’ number is ‘900’
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: Methodology of ring is ‘ringallv2-prim’
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – dialparties.agi: Extension 901 cf is disabled
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – dialparties.agi: Extension 901 do not disturb is disabled
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: Extension 901 has ExtensionState: 0
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: dialparties.agi: Extension 901 has ExtensionState: 0
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – dialparties.agi: Checking CW and CFB status for extension 901
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – dialparties.agi: dbset CALLTRACE/901 to 900
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – dialparties.agi: Filtered ARG3: 901
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] res_agi.c: – <SIP/900-0000003b>AGI Script dialparties.agi completed, returning 0
[2016-11-16 11:56:19] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-dial:7] Dial(“SIP/900-0000003b”, “SIP/901,2,TtrIM(auto-blkvm)”) in new stack
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] netsock2.c: == Using SIP VIDEO TOS bits 136
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] netsock2.c: == Using SIP VIDEO CoS mark 6
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] netsock2.c: == Using SIP RTP TOS bits 184
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] netsock2.c: == Using SIP RTP CoS mark 5
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] app_dial.c: – Called SIP/901
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] app_dial.c: – Connected line update to SIP/900-0000003b prevented.
[2016-11-16 11:56:20] VERBOSE[30287][C-000001b7] app_dial.c: – SIP/901-0000003c is ringing
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] app_dial.c: – Nobody picked up in 2000 ms
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-dial:8] Set(“SIP/900-0000003b”, “DIALSTATUS=NOANSWER”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-dial:9] GosubIf(“SIP/900-0000003b”, “0?NOANSWER,1”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:23] Goto(“SIP/900-0000003b”, “nextstep”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Goto (from-internal,901,25)
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:25] Set(“SIP/900-0000003b”, “RingGroupMethod=”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:26] GotoIf(“SIP/900-0000003b”, “0?nodest”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:27] Set(“SIP/900-0000003b”, “__NODEST=”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:28] Set(“SIP/900-0000003b”, “__PICKUPMARK=”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:29] Macro(“SIP/900-0000003b”, “blkvm-clr,”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/900-0000003b”, “SHARED(BLKVM,SIP/900-0000003b)=”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/900-0000003b”, “GOSUB_RETVAL=”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:30] Set(“SIP/900-0000003b”, “DIALSTATUS=NOANSWER”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@from-internal:31] Goto(“SIP/900-0000003b”, “ext-local,901,dest”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Goto (ext-local,901,3)
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@ext-local:3] Set(“SIP/900-0000003b”, “__PICKUPMARK=”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [901@ext-local:4] Goto(“SIP/900-0000003b”, “,return,1”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Goto (ext-local,return,1)
[2016-11-16 11:56:22] WARNING[30287][C-000001b7] pbx.c: Channel ‘SIP/900-0000003b’ sent to invalid extension but no invalid handler: context,exten,priority=ext-local,return,1
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [h@ext-local:1] Macro(“SIP/900-0000003b”, “hangupcall,”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/900-0000003b”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/900-0000003b”, “1?theend”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Goto (macro-hangupcall,s,4)
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/900-0000003b”, “”) in new stack
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/900-0000003b’ in macro ‘hangupcall’
[2016-11-16 11:56:22] VERBOSE[30287][C-000001b7] pbx.c: == Spawn extension (ext-local, h, 1) exited non-zero on ‘SIP/900-0000003b’
Could you please take a look ?
Regards,
Szabolcs