Call declined to all phones (Code 603)

Our FreePBX server was compromised, and consequently I upgraded all of the modules that had upgrades available and had to create new iptables rules. Since this has occurred, all phones are declining incoming and outgoing calls. I attempted to place a call from one internal extension to another, and got the same result.

A bit about our configuration: Our FreePBX service is on a DigitalOcean droplet, and our trunking provider is NexVortex.

For the sake of simplicity, I have added iptables rules to allow ALL traffic from our local network AND from our trunks.

Below is the output from /var/log/asterisk/full during the time I made the call. If anyone can suggest what might be going on or where I should look next, I’d appreciate it. Thanks!

[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: – Goto (macro-prepend-cid,s,5)
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: – Executing [s@macro-prepend-cid:5] Set(“SIP/34732-00000008”, “_RGPREFIX=TEST”) in new stack
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: – Executing [s@macro-prepend-cid:6] Set(“SIP/34732-00000008”, “CALLERID(name)=TESTXXXX”) in new stack
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: – Executing [1000@from-internal:18] Set(“SIP/34732-00000008”, “RecordMethod=Group”) in new stack
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: – Executing [1000@from-internal:19] Gosub(“SIP/34732-00000008”, “sub-record-check,s,1(exten,1000,)”) in new stack
[2016-06-30 09:55:52] ERROR[29894][C-00000007] app_stack.c: Attempt to reach a non-existent destination for Gosub: (Context:sub-record-check, Extension:s, Priority:1)
[2016-06-30 09:55:52] ERROR[29894][C-00000007] app_stack.c: Attempt to reach a non-existent destination for Gosub: (Context:sub-record-check, Extension:s, Priority:1)
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: == Spawn extension (from-internal, 1000, 19) exited non-zero on ‘SIP/34732-00000008’
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/34732-00000008”, “”) in new stack
[2016-06-30 09:55:52] VERBOSE[29894][C-00000007] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/34732-00000008’
[2016-06-30 09:57:02] VERBOSE[29244][C-00000008] netsock2.c: == Using SIP RTP TOS bits 184
[2016-06-30 09:57:02] VERBOSE[29244][C-00000008] netsock2.c: == Using SIP RTP CoS mark 5
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:1] GotoIf(“SIP/34732-00000009”, “0?ext-local,1000,1”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:2] Macro(“SIP/34732-00000009”, “user-callerid,”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/34732-00000009”, “TOUCH_MONITOR=1467295022.43”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/34732-00000009”, “AMPUSER=34732”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/34732-00000009”, “0?report”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/34732-00000009”, “1?Set(REALCALLERIDNUM=34732)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/34732-00000009”, “AMPUSER=3473”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/34732-00000009”, “0?limit”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/34732-00000009”, “AMPUSERCIDNAME=XXXX”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/34732-00000009”, “0?report”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:9] Set(“SIP/34732-00000009”, “AMPUSERCID=3473”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:10] Set(“SIP/34732-00000009”, “__DIAL_OPTIONS=tr”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/34732-00000009”, “CALLERID(all)=“XXXX” <3473>”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/34732-00000009”, “0?limit”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:13] ExecIf(“SIP/34732-00000009”, “0?Set(GROUP(concurrency_limit)=3473)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:14] GosubIf(“SIP/34732-00000009”, “7?sub-ccss,s,1(from-internal,1000)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-ccss:1] ExecIf(“SIP/34732-00000009”, “0?Return()”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-ccss:2] Set(“SIP/34732-00000009”, “CCSS_SETUP=TRUE”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-ccss:3] GosubIf(“SIP/34732-00000009”, “0?monitor_config,1(from-internal,1000):monitor_default,1(from-internal,1000)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [monitor_default@sub-ccss:1] GotoIf(“SIP/34732-00000009”, “1?is_exten”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Goto (sub-ccss,monitor_default,4)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [monitor_default@sub-ccss:4] Set(“SIP/34732-00000009”, “CALLCOMPLETION(cc_monitor_policy)=generic”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [monitor_default@sub-ccss:5] Set(“SIP/34732-00000009”, “CALLCOMPLETION(cc_max_monitors)=5”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [monitor_default@sub-ccss:6] Return(“SIP/34732-00000009”, “TRUE”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-ccss:4] GosubIf(“SIP/34732-00000009”, “7?agent_config,1():agent_default,1()”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:1] Set(“SIP/34732-00000009”, “CALLCOMPLETION(cc_agent_policy)=generic”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:2] Set(“SIP/34732-00000009”, “CALLCOMPLETION(cc_offer_timer)=30”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:3] Set(“SIP/34732-00000009”, “CALLCOMPLETION(ccbs_available_timer)=”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:4] Set(“SIP/34732-00000009”, “CALLCOMPLETION(ccnr_available_timer)=”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:5] Set(“SIP/34732-00000009”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2016-06-30 09:57:02] WARNING[29931][C-00000008] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-06-30 09:57:02] WARNING[29931][C-00000008] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:6] ExecIf(“SIP/34732-00000009”, “1?Set(CALLCOMPLETION(cc_recall_timer)=)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:7] ExecIf(“SIP/34732-00000009”, “1?Set(CALLCOMPLETION(cc_max_agents)=)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:8] ExecIf(“SIP/34732-00000009”, “0?Set(CALLCOMPLETION(cc_agent_dialstring)=Local/3473_1000@from-ccss-)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:9] Set(“SIP/34732-00000009”, “CALLCOMPLETION(cc_callback_macro)=ccss-default”) in new stack
[2016-06-30 09:57:02] WARNING[29931][C-00000008] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-06-30 09:57:02] WARNING[29931][C-00000008] ccss.c: Usage of cc_callback_macro is deprecated. Please use cc_callback_sub instead.
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [agent_config@sub-ccss:10] Return(“SIP/34732-00000009”, “”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-ccss:5] Set(“SIP/34732-00000009”, “DB(AMPUSER/3473/ccss/last_number)=1000”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-ccss:6] Return(“SIP/34732-00000009”, “”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:15] ExecIf(“SIP/34732-00000009”, “0?Set(CHANNEL(language)=)”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/34732-00000009”, “0?continue”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:17] Set(“SIP/34732-00000009”, “__TTL=64”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:18] GotoIf(“SIP/34732-00000009”, “1?continue”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Goto (macro-user-callerid,s,29)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:29] Set(“SIP/34732-00000009”, “CALLERID(number)=3473”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/34732-00000009”, “CALLERID(name)=XXXX”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/34732-00000009”, “CDR(cnum)=3473”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/34732-00000009”, “CDR(cnam)=XXXX”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/34732-00000009”, “CHANNEL(language)=en”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:3] Set(“SIP/34732-00000009”, “DIAL_OPTIONS=trI”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:4] Set(“SIP/34732-00000009”, “CONNECTEDLINE(num,i)=1000”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:5] Gosub(“SIP/34732-00000009”, “sub-presencestate-display,s,1(1000)”) in new stack
[2016-06-30 09:57:02] WARNING[29931][C-00000008] func_presencestate.c: PRESENCE_STATE unknown
[2016-06-30 09:57:02] WARNING[29931][C-00000008] func_presencestate.c: PRESENCE_STATE unknown
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@sub-presencestate-display:1] Goto(“SIP/34732-00000009”, “state-,1”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Goto (sub-presencestate-display,state-,1)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [state-@sub-presencestate-display:1] Set(“SIP/34732-00000009”, “PRESENCESTATE_DISPLAY=”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [state-@sub-presencestate-display:2] Return(“SIP/34732-00000009”, “”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:6] Set(“SIP/34732-00000009”, “CONNECTEDLINE(name)=Downtown Main”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:7] Set(“SIP/34732-00000009”, “FM_DIALSTATUS=UNKNOWN”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:8] Set(“SIP/34732-00000009”, “__EXTTOCALL=1000”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:9] Set(“SIP/34732-00000009”, “__PICKUPMARK=1000”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:10] Macro(“SIP/34732-00000009”, “blkvm-setifempty,”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/34732-00000009”, “1?init”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/34732-00000009”, “__BLKVM_CHANNEL=SIP/34732-00000009”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/34732-00000009”, “SHARED(BLKVM,SIP/34732-00000009)=TRUE”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/34732-00000009”, “GOSUB_RETVAL=TRUE”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/34732-00000009”, “”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:11] GotoIf(“SIP/34732-00000009”, “1?skipov”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Goto (from-internal,1000,14)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:14] Set(“SIP/34732-00000009”, “RRNODEST=”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:15] Set(“SIP/34732-00000009”, “__NODEST=1000”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:16] GosubIf(“SIP/34732-00000009”, “0?sub-fmsetcid,s,1()”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:17] Macro(“SIP/34732-00000009”, “prepend-cid,TEST”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-prepend-cid:1] GotoIf(“SIP/34732-00000009”, “1?REPCID”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Goto (macro-prepend-cid,s,5)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-prepend-cid:5] Set(“SIP/34732-00000009”, “_RGPREFIX=TEST”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [s@macro-prepend-cid:6] Set(“SIP/34732-00000009”, “CALLERID(name)=XXXX”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:18] Set(“SIP/34732-00000009”, “RecordMethod=Group”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [1000@from-internal:19] Gosub(“SIP/34732-00000009”, “sub-record-check,s,1(exten,1000,)”) in new stack
[2016-06-30 09:57:02] ERROR[29931][C-00000008] app_stack.c: Attempt to reach a non-existent destination for Gosub: (Context:sub-record-check, Extension:s, Priority:1)
[2016-06-30 09:57:02] ERROR[29931][C-00000008] app_stack.c: Attempt to reach a non-existent destination for Gosub: (Context:sub-record-check, Extension:s, Priority:1)
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: == Spawn extension (from-internal, 1000, 19) exited non-zero on ‘SIP/34732-00000009’
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: – Executing [h@from-internal:1] Hangup(“SIP/34732-00000009”, “”) in new stack
[2016-06-30 09:57:02] VERBOSE[29931][C-00000008] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/34732-00000009’

if your server was compromised, what did you do to fix it? simply upgrading modules will not get rid of what the bad guys did. unless you can figure out exactly what they did, i would suggest that you restore the system from a known good back up

I would suggest to reinstall and set up your box from the start. Also think about having an in premise pbx to avoid such things.
Finally make a new test and put your log in preformated text block because this way is unreadable.

Thanks for the replies, everybody. As it turns out, the problem was that the call recordings module needed to updated, along with a few modules which had the recordings module as a dependency.

I agree it would be a good idea to start from scratch, but that just isn’t an option for me right now. I’m a one-person IT department, and this is the PBX for our entire organization. I realize it is far from ideal, but I’m sure you all can understand that I only have the resources I have.

I was not able to determine exactly how they gained access. I was made aware of the issue through an abuse report citing a phishing operation. I found and resolved this issue (mod_proxy was enabled, phishy domains registered to the server’s IP address, and was redirecting URLs with the /cgi-bin string to an external IP).

Other than that, here are the things I have done so far:

• Turned off password authentication for SSH (now only uses public key authentication), and only allowed login for my (standard) user account.
• Changed the root password, then disabled login for root.
• Ran rkhunter to check for rootkits and other issues (no problems).
• Set up additional firewall rules so that traffic is only allowed from our two office sites and our two trunk lines (this includes port 80, 5060-5061, and 22).

Short of a complete rebuild, I’d appreciate any other additional advice anyone can give. Thanks again!