rchalk
Active Member
- Joined
- Feb 19, 2010
- Messages
- 403
- Reaction score
- 55
I have an older system, with Superfecta 2.11.16 installed. For almost all calls, this works fine, but I have set up a separate server, using long device names and passwords, but with valid Caller ID numbers. When calling from this system to the main system, the calls time out to a busy signal. If I disable Superfecta, the calls complete normally.
I suspected the long device names were causing the problem, but looking at the logs, these numbers do not show up. Only the caller ID from the calling phone shows in the log.
Here is the relevant portion of the log for the failed call. Below that is the log for a call to the same number, with Superfecta enabled, but from a different VOIP system. In looking at the failed call, Superfecta gets to "Execute Scheme" and hangs. In looking at the similar successful call, it says Scheme completed, and then processes the call
Thanks for any advice or suggestions you may have...
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:1] Set("SIP/VOIP.MS_Richard-00000024", "__FROM_DID=2017670850") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:2] Gosub("SIP/VOIP.MS_Richard-00000024", "app-blacklist-check|s|1") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/VOIP.MS_Richard-00000024", "") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:2] GotoIf("SIP/VOIP.MS_Richard-00000024", "0?blacklisted") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:3] Set("SIP/VOIP.MS_Richard-00000024", "CALLED_BLACKLIST=1") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:4] Return("SIP/VOIP.MS_Richard-00000024", "") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:3] Set("SIP/VOIP.MS_Richard-00000024", "CIDSFSCHEME=QUxMfEFMTA==") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:4] AGI("SIP/VOIP.MS_Richard-00000024", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta is Answering the Channel
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Scheme is ALL
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The DID passed from Asterisk is: 2017670850
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The number passed from Asterisk is: 7069630070
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The CID name passed from Asterisk is: TECHNOVATIONS
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Executing Scheme..
[2018-12-05 09:03:59] DEBUG[3610] res_agi.c: SIP/VOIP.MS_Richard-00000024 hungup
[2018-12-05 09:03:59] VERBOSE[3610] logger.c: == Spawn extension (from-trunk, 2017670850, 4)
Here is the second log for successful call
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:1] Set("SIP/VOIP.MS_Richard-0000002e", "__FROM_DID=2017670850") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:2] Gosub("SIP/VOIP.MS_Richard-0000002e", "app-blacklist-check|s|1") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/VOIP.MS_Richard-0000002e", "") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:2] GotoIf("SIP/VOIP.MS_Richard-0000002e", "0?blacklisted") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:3] Set("SIP/VOIP.MS_Richard-0000002e", "CALLED_BLACKLIST=1") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:4] Return("SIP/VOIP.MS_Richard-0000002e", "") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:3] Set("SIP/VOIP.MS_Richard-0000002e", "CIDSFSCHEME=QUxMfEFMTA==") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:4] AGI("SIP/VOIP.MS_Richard-0000002e", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta is Answering the Channel
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Scheme is ALL
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The DID passed from Asterisk is: 2017670850
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The number passed from Asterisk is: 7069630050
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The CID name passed from Asterisk is: Chalk Richard
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Executing Scheme..
[[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:5] Set("SIP/VOIP.MS_Richard-0000002e", "CALLERID(name)=") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:6] ExecIf("SIP/VOIP.MS_Richard-0000002e", "1 |Set|CALLERID(name)=7069630050") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:7] Set("SIP/VOIP.MS_Richard-0000002e", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:8] SetCallerPres("SIP/VOIP.MS_Richard-0000002e", "allowed_not_screened") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:9] Goto("SIP/VOIP.MS_Richard-0000002e", "ivr-2|s|1") in new stack
[
I suspected the long device names were causing the problem, but looking at the logs, these numbers do not show up. Only the caller ID from the calling phone shows in the log.
Here is the relevant portion of the log for the failed call. Below that is the log for a call to the same number, with Superfecta enabled, but from a different VOIP system. In looking at the failed call, Superfecta gets to "Execute Scheme" and hangs. In looking at the similar successful call, it says Scheme completed, and then processes the call
Thanks for any advice or suggestions you may have...
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:1] Set("SIP/VOIP.MS_Richard-00000024", "__FROM_DID=2017670850") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:2] Gosub("SIP/VOIP.MS_Richard-00000024", "app-blacklist-check|s|1") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/VOIP.MS_Richard-00000024", "") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:2] GotoIf("SIP/VOIP.MS_Richard-00000024", "0?blacklisted") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:3] Set("SIP/VOIP.MS_Richard-00000024", "CALLED_BLACKLIST=1") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [s@app-blacklist-check:4] Return("SIP/VOIP.MS_Richard-00000024", "") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:3] Set("SIP/VOIP.MS_Richard-00000024", "CIDSFSCHEME=QUxMfEFMTA==") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Executing [2017670850@from-trunk:4] AGI("SIP/VOIP.MS_Richard-00000024", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta is Answering the Channel
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Scheme is ALL
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The DID passed from Asterisk is: 2017670850
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The number passed from Asterisk is: 7069630070
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The CID name passed from Asterisk is: TECHNOVATIONS
[2018-12-05 09:03:56] VERBOSE[3610] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Executing Scheme..
[2018-12-05 09:03:59] DEBUG[3610] res_agi.c: SIP/VOIP.MS_Richard-00000024 hungup
[2018-12-05 09:03:59] VERBOSE[3610] logger.c: == Spawn extension (from-trunk, 2017670850, 4)
Here is the second log for successful call
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:1] Set("SIP/VOIP.MS_Richard-0000002e", "__FROM_DID=2017670850") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:2] Gosub("SIP/VOIP.MS_Richard-0000002e", "app-blacklist-check|s|1") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/VOIP.MS_Richard-0000002e", "") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:2] GotoIf("SIP/VOIP.MS_Richard-0000002e", "0?blacklisted") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:3] Set("SIP/VOIP.MS_Richard-0000002e", "CALLED_BLACKLIST=1") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [s@app-blacklist-check:4] Return("SIP/VOIP.MS_Richard-0000002e", "") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:3] Set("SIP/VOIP.MS_Richard-0000002e", "CIDSFSCHEME=QUxMfEFMTA==") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:4] AGI("SIP/VOIP.MS_Richard-0000002e", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta is Answering the Channel
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Scheme is ALL
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The DID passed from Asterisk is: 2017670850
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The number passed from Asterisk is: 7069630050
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The CID name passed from Asterisk is: Chalk Richard
[2018-12-05 09:12:54] VERBOSE[3918] logger.c: /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Executing Scheme..
[[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:5] Set("SIP/VOIP.MS_Richard-0000002e", "CALLERID(name)=") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:6] ExecIf("SIP/VOIP.MS_Richard-0000002e", "1 |Set|CALLERID(name)=7069630050") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:7] Set("SIP/VOIP.MS_Richard-0000002e", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:8] SetCallerPres("SIP/VOIP.MS_Richard-0000002e", "allowed_not_screened") in new stack
[2018-12-05 09:12:58] VERBOSE[3918] logger.c: -- Executing [2017670850@from-trunk:9] Goto("SIP/VOIP.MS_Richard-0000002e", "ivr-2|s|1") in new stack
[
Last edited:
Phone System 