Engaged signal issue

Hi,

I’ve got two identical Sangoma S500 phones, both running the same firmware, and all settings are identical (bar the obvious).

When one phone rings another extension/phone that’s in use, they get an engaged signal (The boop, boop, boop noise).

When the other phone rings an in use extension they get no engaged signal, instead they the phone has 1 second of silence then returns the user to the main screen of the phone with no indication of what’s wrong.

Both were tested with dialling the same phone/extension, so it must be the other end that the issue is occurring. Still quite new to this so no idea where to look for this issue! EDIT: I should clarify that the issue is the one that doesn’t get the engaged signal :stuck_out_tongue:

Got round to looking at this again…
Any extension with a voicemailbox is getting a “The person is currently on the phone, please leave a message” but anyone without a mailbox is just cutting off instantly rather than getting an engaged signal.

Any suggestions based on that extra information?

EDIT: Additionall, call waiting features are turned off on the phones. We don’t use call waiting, we just want an engaged signal.

Have you looked at the Optional Destination settings at the bottom of the “Advanced” tab.

I suspect that the “Remote Disconnect” in the Template Options tab in EPM for each phone is set to something different.

@cynjut I’ve played around with this, if i set it to terminal at permanent hold, or the SITS tone, or to ring they work fine. However if i set it to terminate at busy or congested signal it just does the same thing as above.

@lgaetz I’ve tried it with both phones with remote disconnect set to on and off, no change unfortunately.

Check your log at /var/log/asterisk/full and see if you are getting an error. I suspect you are getting a codec error on the “busy tone” sound file.

This is what I’m seeing in the log when trying to call and it cuts off:
– Executing [[email protected]:1] GotoIf(“PJSIP/507-00000a02”, “1?ext-local,583,1:followme-check,583,1”) in new stack
– Goto (ext-local,583,1)
– Executing [[email protected]:1] Set(“PJSIP/507-00000a02”, “__RINGTIMER=15”) in new stack
– Executing [[email protected]:2] Macro(“PJSIP/507-00000a02”, “exten-vm,novm,583,0,1,0”) in new stack
– Executing [[email protected]:1] Macro(“PJSIP/507-00000a02”, “user-callerid,”) in new stack
– Executing [[email protected]:1] Set(“PJSIP/507-00000a02”, “TOUCH_MONITOR=1477033356.2891”) in new stack
– Executing [[email protected]:2] Set(“PJSIP/507-00000a02”, “AMPUSER=507”) in new stack
– Executing [[email protected]:3] GotoIf(“PJSIP/507-00000a02”, “0?report”) in new stack
– Executing [[email protected]:4] ExecIf(“PJSIP/507-00000a02”, “1?Set(REALCALLERIDNUM=507)”) in new stack
– Executing [[email protected]:5] Set(“PJSIP/507-00000a02”, “AMPUSER=507”) in new stack
– Executing [[email protected]:6] GotoIf(“PJSIP/507-00000a02”, “0?limit”) in new stack
– Executing [[email protected]:7] Set(“PJSIP/507-00000a02”, “AMPUSERCIDNAME=James”) in new stack
– Executing [[email protected]:8] GotoIf(“PJSIP/507-00000a02”, “0?report”) in new stack
– Executing [[email protected]:9] Set(“PJSIP/507-00000a02”, “AMPUSERCID=507”) in new stack
– Executing [[email protected]:10] Set(“PJSIP/507-00000a02”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [[email protected]:11] Set(“PJSIP/507-00000a02”, “CALLERID(all)=“James” <507>”) in new stack
– Executing [[email protected]:12] GotoIf(“PJSIP/507-00000a02”, “0?limit”) in new stack
– Executing [[email protected]:13] ExecIf(“PJSIP/507-00000a02”, “0?Set(GROUP(concurrency_limit)=507)”) in new stack
– Executing [[email protected]:14] ExecIf(“PJSIP/507-00000a02”, “1?Set(CHANNEL(language)=en)”) in new stack
– Executing [[email protected]:15] GotoIf(“PJSIP/507-00000a02”, “0?continue”) in new stack
– Executing [[email protected]:16] ExecIf(“PJSIP/507-00000a02”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
– Executing [[email protected]:17] Set(“PJSIP/507-00000a02”, “__TTL=64”) in new stack
– Executing [[email protected]:18] GotoIf(“PJSIP/507-00000a02”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,29)
– Executing [[email protected]:29] Set(“PJSIP/507-00000a02”, “CALLERID(number)=507”) in new stack
– Executing [[email protected]:30] Set(“PJSIP/507-00000a02”, “CALLERID(name)=James”) in new stack
– Executing [[email protected]:31] GotoIf(“PJSIP/507-00000a02”, “0?cnum”) in new stack
– Executing [[email protected]:32] Set(“PJSIP/507-00000a02”, “CDR(cnam)=James”) in new stack
– Executing [[email protected]:33] Set(“PJSIP/507-00000a02”, “CDR(cnum)=507”) in new stack
– Executing [[email protected]:34] Set(“PJSIP/507-00000a02”, “CHANNEL(language)=en”) in new stack
– Executing [[email protected]:2] Set(“PJSIP/507-00000a02”, “RingGroupMethod=none”) in new stack
– Executing [[email protected]:3] Set(“PJSIP/507-00000a02”, “__EXTTOCALL=583”) in new stack
– Executing [[email protected]:4] Set(“PJSIP/507-00000a02”, “__PICKUPMARK=583”) in new stack
– Executing [[email protected]:5] Set(“PJSIP/507-00000a02”, “RT=15”) in new stack
– Executing [[email protected]:6] ExecIf(“PJSIP/507-00000a02”, “0?Macro(vm,novm,DIRECTDIAL,)”) in new stack
– Executing [[email protected]:7] ExecIf(“PJSIP/507-00000a02”, “0?MacroExit()”) in new stack
– Executing [[email protected]:8] Gosub(“PJSIP/507-00000a02”, “sub-record-check,s,1(exten,583,dontcare)”) in new stack
– Executing [[email protected]:1] GotoIf(“PJSIP/507-00000a02”, “0?initialized”) in new stack
– Executing [[email protected]:2] Set(“PJSIP/507-00000a02”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [[email protected]:3] Set(“PJSIP/507-00000a02”, “NOW=1477033356”) in new stack
– Executing [[email protected]:4] Set(“PJSIP/507-00000a02”, “__DAY=21”) in new stack
– Executing [[email protected]:5] Set(“PJSIP/507-00000a02”, “__MONTH=10”) in new stack
– Executing [[email protected]:6] Set(“PJSIP/507-00000a02”, “__YEAR=2016”) in new stack
– Executing [[email protected]:7] Set(“PJSIP/507-00000a02”, “__TIMESTR=20161021-080236”) in new stack
– Executing [[email protected]:8] Set(“PJSIP/507-00000a02”, “__FROMEXTEN=507”) in new stack
– Executing [[email protected]:9] Set(“PJSIP/507-00000a02”, “__MON_FMT=wav”) in new stack
– Executing [[email protected]:10] NoOp(“PJSIP/507-00000a02”, “Recordings initialized”) in new stack
– Executing [[email protected]:11] ExecIf(“PJSIP/507-00000a02”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [[email protected]:12] Set(“PJSIP/507-00000a02”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [[email protected]:13] ExecIf(“PJSIP/507-00000a02”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [[email protected]:14] GotoIf(“PJSIP/507-00000a02”, “5?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [[email protected]:17] GotoIf(“PJSIP/507-00000a02”, “1?sub-record-check,exten,1”) in new stack
– Goto (sub-record-check,exten,1)
– Executing [[email protected]:1] NoOp(“PJSIP/507-00000a02”, “Exten Recording Check between 507 and 583”) in new stack
– Executing [[email protected]:2] Set(“PJSIP/507-00000a02”, “CALLTYPE=internal”) in new stack
– Executing [[email protected]:3] ExecIf(“PJSIP/507-00000a02”, “0?Set(CALLTYPE=)”) in new stack
– Executing [[email protected]:4] Set(“PJSIP/507-00000a02”, “CALLEE=dontcare”) in new stack
– Executing [[email protected]:5] ExecIf(“PJSIP/507-00000a02”, “0?Set(CALLEE=dontcare)”) in new stack
– Executing [[email protected]:6] GotoIf(“PJSIP/507-00000a02”, “0?callee”) in new stack
– Executing [[email protected]:7] GotoIf(“PJSIP/507-00000a02”, “1?caller”) in new stack
– Goto (sub-record-check,exten,13)
– Executing [[email protected]:13] Set(“PJSIP/507-00000a02”, “RECMODE=dontcare”) in new stack
– Executing [[email protected]:14] ExecIf(“PJSIP/507-00000a02”, “0?Set(RECMODE=dontcare)”) in new stack
– Executing [[email protected]:15] ExecIf(“PJSIP/507-00000a02”, “1?Set(RECMODE=dontcare)”) in new stack
– Executing [[email protected]:16] Gosub(“PJSIP/507-00000a02”, “recordcheck,1(dontcare,internal,583)”) in new stack
– Executing [[email protected]:1] NoOp(“PJSIP/507-00000a02”, “Starting recording check against dontcare”) in new stack
– Executing [[email protected]:2] Goto(“PJSIP/507-00000a02”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [[email protected]:3] Return(“PJSIP/507-00000a02”, “”) in new stack
– Executing [[email protected]:17] Return(“PJSIP/507-00000a02”, “”) in new stack
– Executing [[email protected]:9] GotoIf(“PJSIP/507-00000a02”, “1?macrodial”) in new stack
– Goto (macro-exten-vm,s,15)
– Executing [[email protected]:15] GosubIf(“PJSIP/507-00000a02”, “0?clrheader,1()”) in new stack
– Executing [[email protected]:16] Macro(“PJSIP/507-00000a02”, “dial-one,15,Ttr,583”) in new stack
– Executing [[email protected]:1] Set(“PJSIP/507-00000a02”, “DEXTEN=583”) in new stack
– Executing [[email protected]:2] Set(“PJSIP/507-00000a02”, “DIALSTATUS_CW=”) in new stack
– Executing [[email protected]:3] GosubIf(“PJSIP/507-00000a02”, “0?screen,1()”) in new stack
– Executing [[email protected]:4] GosubIf(“PJSIP/507-00000a02”, “0?cf,1()”) in new stack
– Executing [[email protected]:5] GotoIf(“PJSIP/507-00000a02”, “1?skip1”) in new stack
– Goto (macro-dial-one,s,8)
– Executing [[email protected]:8] GotoIf(“PJSIP/507-00000a02”, “0?nodial”) in new stack
– Executing [[email protected]:9] GotoIf(“PJSIP/507-00000a02”, “0?continue”) in new stack
– Executing [[email protected]:10] Set(“PJSIP/507-00000a02”, “EXTHASCW=”) in new stack
– Executing [[email protected]:11] GotoIf(“PJSIP/507-00000a02”, “1?next1:cwinusebusy”) in new stack
– Goto (macro-dial-one,s,12)
– Executing [[email protected]:12] GotoIf(“PJSIP/507-00000a02”, “0?docfu:skip3”) in new stack
– Goto (macro-dial-one,s,16)
– Executing [[email protected]:16] GotoIf(“PJSIP/507-00000a02”, “1?next2:continue”) in new stack
– Goto (macro-dial-one,s,17)
– Executing [[email protected]:17] GotoIf(“PJSIP/507-00000a02”, “0?continue”) in new stack
– Executing [[email protected]:18] ExecIf(“PJSIP/507-00000a02”, “0?Set(DIALSTATUS=BUSY)”) in new stack
– Executing [[email protected]:19] GotoIf(“PJSIP/507-00000a02”, “0?cwinusebusy”) in new stack
– Executing [[email protected]:20] Set(“PJSIP/507-00000a02”, “DEXTEN=”) in new stack
– Executing [[email protected]:21] Set(“PJSIP/507-00000a02”, “DIALSTATUS=BUSY”) in new stack
– Executing [[email protected]:22] Goto(“PJSIP/507-00000a02”, “nodial”) in new stack
– Goto (macro-dial-one,s,53)
– Executing [[email protected]:53] ExecIf(“PJSIP/507-00000a02”, “0?Set(DIALSTATUS=NOANSWER)”) in new stack
– Executing [[email protected]:54] NoOp(“PJSIP/507-00000a02”, “Returned from dial-one with nothing to call and DIALSTATUS: BUSY”) in new stack
– Executing [[email protected]:55] MacroExit(“PJSIP/507-00000a02”, “”) in new stack
– Executing [[email protected]:17] Set(“PJSIP/507-00000a02”, “SV_DIALSTATUS=BUSY”) in new stack
– Executing [[email protected]:18] GosubIf(“PJSIP/507-00000a02”, “0?docfu,1()”) in new stack
– Executing [[email protected]:19] GosubIf(“PJSIP/507-00000a02”, “0?docfb,1()”) in new stack
– Executing [[email protected]:20] Set(“PJSIP/507-00000a02”, “DIALSTATUS=BUSY”) in new stack
– Executing [[email protected]:21] ExecIf(“PJSIP/507-00000a02”, “1?MacroExit()”) in new stack
– Executing [[email protected]:3] Set(“PJSIP/507-00000a02”, “__PICKUPMARK=”) in new stack
– Executing [[email protected]:4] GotoIf(“PJSIP/507-00000a02”, “1?app-blackhole,busy,1”) in new stack
– Goto (app-blackhole,busy,1)
– Executing [[email protected]:1] NoOp(“PJSIP/507-00000a02”, “Blackhole Dest: Busy”) in new stack
– Executing [[email protected]:2] Progress(“PJSIP/507-00000a02”, “”) in new stack
– Executing [[email protected]:3] Busy(“PJSIP/507-00000a02”, “20”) in new stack
[2016-10-21 08:02:36] WARNING[9180][C-0000049e]: channel.c:4910 ast_prod: Prodding channel ‘PJSIP/507-00000a02’ failed
== Spawn extension (app-blackhole, busy, 3) exited non-zero on ‘PJSIP/507-00000a02’

Seems this issue isn’t internal only like i though, if external numbers are engaged (presumably in this case, as they do eventually get through…) we get the same issue.

Log from the phone (Sangoma S500):
[10-21 12:34:43 50:0f:54] chn=0, AEC_switch = 0
[10-21 12:34:43 50:0f:54] MS: Chn 0 MSDspStopSendRev
[10-21 12:34:43 50:0f:54] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8dd
[10-21 12:34:43 50:0f:54] CALL: State=0x61, Event=0x127, Chn=0
[10-21 12:34:43 50:0f:54] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8d7
[10-21 12:34:43 50:0f:54] SIP: sdp_message_pro: Local IP is 172.18.67.21
[10-21 12:34:43 50:0f:54] SIP: SendInvite to 583, cid 437, wIP 0xac124315, port 12100, Interval 2, Codec 0, Audio 0
[10-21 12:34:43 50:0f:54] ReDialInfo: aid 0, line 0, Number 583
[10-21 12:34:43 50:0f:54] CALL: State=0x62, Event=0x201, Chn=0
[10-21 12:34:43 50:0f:54] SIP: aid 0, cid 437, tid 50818, did 0, REQUEST: INVITE, Event: 12
[10-21 12:34:43 50:0f:54] SIP: aid 0, cid 437, tid 50818, did 0, RESPONSE: 401 Unauthorized, 4xx received for Call!, Event: 12
[10-21 12:34:43 50:0f:54] SIP: find_authentication_info, aid 0, username: 507, realm: “asterisk”
[10-21 12:34:43 50:0f:54] SIP: find_auth_info, aid 0, username: 507, account match
[10-21 12:34:43 50:0f:54] SIP: aid 0, cid 437, tid 50819, did 0, REQUEST: INVITE, Event: 8
[10-21 12:34:43 50:0f:54] SIP: aid 0, cid 437, tid 50819, did 0, RESPONSE: 100 Trying, Call is being processed!, Event: 8
[10-21 12:34:43 50:0f:54] GUI: CALL_OFFHOOK, Index:0
[10-21 12:34:43 50:0f:54] GUI: 1:Call LCMSUBCallData:31035360:subdatastatistic:315
[10-21 12:34:43 50:0f:54] SIP: aid 0, cid 437, tid 50819, did 0, REQUEST: INVITE, Event: 12
[10-21 12:34:43 50:0f:54] SIP: aid 0, cid 437, tid 50819, did 0, RESPONSE: 486 Busy Here, 4xx received for Call!, Event: 12
[10-21 12:34:43 50:0f:54] SIP: ActionUrlCall, can’t get call_dialog!!!
[10-21 12:34:43 50:0f:54] SIP: ActionUrlPro active_url sip:[email protected]:5060
[10-21 12:34:43 50:0f:54] SIP: Send CALL_FAILURE (486 Busy Here) to LCM
[10-21 12:34:43 50:0f:54] SIP: aid 0 recv 486, Busy Here
[10-21 12:34:43 50:0f:54] CALL: State=0x62, Event=0x306, Chn=0
[10-21 12:34:43 50:0f:54] XPhoneRelPro:20481######===>>>Line 0 LineState 0x62…
[10-21 12:34:43 50:0f:54] SendSpecialEvent2LCM: Event=2534
[10-21 12:34:43 50:0f:54] CALL: _XPhoneNextState…
[10-21 12:34:43 50:0f:54] CALL: Clear Transfer, Conf and NS Flag
[10-21 12:34:43 50:0f:54] CALL: There isn’t any call, Release
[10-21 12:34:43 50:0f:54] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8f7
[10-21 12:34:43 50:0f:54] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x954
[10-21 12:34:43 50:0f:54] SendSpecialEvent2LCM: Event=2534
[10-21 12:34:43 50:0f:54] chn=0, AEC_switch = 0
[10-21 12:34:43 50:0f:54] MS: Chn 0 MSDspStopSendRev
[10-21 12:34:43 50:0f:54] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8e1
[10-21 12:34:43 50:0f:54] LCM: received CALL_FAILURE:2355,reason:Busy Here
[10-21 12:34:43 50:0f:54] GUI: CALL_OFFHOOKTYPE:1
[10-21 12:34:43 50:0f:54] GUI: CALL_OUTGOING, Index:0
[10-21 12:34:43 50:0f:54] GUI: MSG_PAINT
[10-21 12:34:43 50:0f:54] L2Call receive NormalReleaseEvent, release
[10-21 12:34:43 50:0f:54] SIPPro: 12811, Release All Sip Dialog!!
[10-21 12:34:43 50:0f:54] CALL: State=0x60, Event=0x91c, Chn=0
[10-21 12:34:43 50:0f:54] CALL: LCM Exit MenuCfg
[10-21 12:34:43 50:0f:54] GUI: num:0,HLGUIData.ScrewView.ScrewItemNum:0
[10-21 12:34:43 50:0f:54] GUI: CALL_FAILURE, Account:0
[10-21 12:34:43 50:0f:54] GUI:MS_ZRTP_END_EVENT
[10-21 12:34:43 50:0f:54] GUI: CALL_REL_ALL, Index:0
[10-21 12:34:43 50:0f:54] GUI: 2:Call LCMSUBCallData:31324544:subdatastatistic:316
[10-21 12:34:43 50:0f:54] GUI: Receive CALL_BUSY_UNLOCK_KEYPAD!
[10-21 12:34:43 50:0f:54] GUI:MS_ZRTP_END_EVENT
[10-21 12:34:43 50:0f:54] GUI: CALL_ONHOOK,index:0
[10-21 12:34:43 50:0f:54] GUI: CALL_ONHOOK, Index:0
[10-21 12:34:44 50:0f:54] CALL: State=0x60, Event=0x91c, Chn=0

Does this look more like a phone issue rather than a freepbx issue per chance? I don’t really understand what I’m looking at, but something doesn’t look right with that log…

Still unable to resolve this.

I’ve recatagorized this under “Sangoma Phones” as i’ve borrowed a yealink phone from someone else and i get the “busy here” tone as one would expect. On the Sangoma phones S300 and S500 (now running the latest 1.22 firmware) I get nothing.

Any suggestions on this new info?

Ita a firmware issue that we are working on. A bug for introduced when fixing something else. If you go back to firmware .16 you will get busy tone played. It will be fixed in next .19 firmware.

Huzzah! Thank you :slight_smile: I thought i was going mad.

Hi,

I see that the .19 firmware release notes are up on the wiki. However endpoint manager isn’t picking up a 1.23 version is there a way to force endpoint manager to check for an update?

Thanks

EDIT: Ah i found where it comes from, and it appears:
http://ct.schmoozecom.net/sangoma.1.22.tar.gz < works
http://ct.schmoozecom.net/sangoma.1.23.tar.gz < doesn’t exist

Does someone on the endpoint manager end need to upload the new version to that store?

We have not pushed it to EPm yet. We always wait a week or two to let users manually test the firmware.

Ah thanks, i’ll bare that in mind in the future.