[Spce-user] Voicemail dead air after upgrade 2.6->2.7->2.8

Dave Massey dave at optionsdsl.ca
Wed Jul 20 11:12:18 EDT 2016


Ok I pulled some logs, no rewrite rules anymore.  

kamailio-proxy.

Jul 20 11:08:41 sip /usr/sbin/kamailio[2216]: INFO: <script>: New request - M=INVITE R=sip:2000 at sip.optionsdsl.ca;user=phone F=sip:dmassey at sip.optionsdsl.ca T=sip:2000 at sip.optionsdsl.ca;user=phone IP=10.40.36.100:5061 (127.0.0.1:5060) ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2216]: INFO: <script>: Authentication failed, no credentials - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: New request - M=INVITE R=sip:2000 at sip.optionsdsl.ca;user=phone F=sip:dmassey at sip.optionsdsl.ca T=sip:2000 at sip.optionsdsl.ca;user=phone IP=10.40.36.100:5061 (127.0.0.1:5060) ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Clear caller preferences - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Load caller preferences for uuid '4687aa6f-b80f-42bf-8caf-fe92a7922866' and domain part of uri 'sip:dmassey at sip.optionsdsl.ca' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Load dialplan IDs for domain 'sip:dmassey at sip.optionsdsl.ca' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Fetched dialplan IDs caller_in='1', callee_in='2' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Use 'P-NGCP-Src-Ip' for CDR IP - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Dialog set total - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Dialog set user, userout, account, accountout to '4687aa6f-b80f-42bf-8caf-fe92a7922866/3' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: IP authorization for caller not provisioned, allow call - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: User-Provided CLI 'dmassey' taken from From-User - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Applying caller-in domain rewrite rules on user-provided CLI using dpid '1' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No matching rewrite rules for 'dmassey' found - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Checking User-provided CLI against allowed CLIs - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: User-provided CLI 'dmassey' rejected, using network-provided CLI '19057722572' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting '19057722572 at sip.optionsdsl.ca' as initiating user-provided CLI - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting '19057722572 at sip.optionsdsl.ca' as initiating network-provided CLI - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Searching for callee - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Applying callee-in domain rewrite rules using dpid '2' - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No matching rewrite rules for '2000' found - R=sip:2000 at sip.optionsdsl.ca;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Call to VoiceBox - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Dialog set mark type to local - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Dialog set mark peer to voicebox - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting acc source-leg for uuid '4687aa6f-b80f-42bf-8caf-fe92a7922866': '4687aa6f-b80f-42bf-8caf-fe92a7922866|dmassey|sip.optionsdsl.ca|19057722572|||3|||0|call|10.40.36.100|1469027321.375544' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting acc destination-leg for uuid '4687aa6f-b80f-42bf-8caf-fe92a7922866': '0|||<null>|2000|4687aa6f-b80f-42bf-8caf-fe92a7922866|abc19057722572|voicebox.local|abc19057722572|voicebox.local' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Relaying request, du='sip:127.0.0.1:5070' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Use mediaproxy for forward direction for IPv4/IPv4 - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Remove existing ICE candidates (if any) for callee - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting P-Caller-UUID to '4687aa6f-b80f-42bf-8caf-fe92a7922866' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting P-Callee-UUID to '4687aa6f-b80f-42bf-8caf-fe92a7922866' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: User Agent header removed - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Prepare From display-name setting - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No selector set, not setting CLI - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Prepare From username setting - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No selector set, not setting CLI - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Setting From to '<sip:19057722572 at sip.optionsdsl.ca>' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Prepare PAI username setting - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No selector set, not setting CLI - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Prepare PPI username setting - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No selector set, not setting CLI - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Prepare Diversion setting - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No selector set, not setting CLI - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Prepare History-Info setting - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: No selector set, not setting CLI - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd849e5 at 10.40.36.100
Jul 20 11:08:41 sip /usr/sbin/kamailio[2218]: INFO: <script>: Request leaving server, D-URI='sip:127.0.0.1:5070' - R=sip:abc19057722572 at voicebox.local;user=phone ID=9e9180a3-9caa923a-dcd8



Asterisk (voicemail) log, never updates beyond the entries after startup.  

root at sip:/var/log/ngcp# cat voicemail.log 
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: loader.c:874 in load_modules: 2 modules will be loaded.
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: res_odbc.c:537 in odbc_obj_connect: Connecting asterisk
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: res_odbc.c:565 in odbc_obj_connect: res_odbc: Connected to asterisk [asterisk]
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: res_odbc.c:320 in load_odbc_config: Registered ODBC class 'asterisk' dsn->[asterisk]
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: res_odbc.c:737 in load_module: res_odbc loaded.
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: config.c:1276 in ast_config_engine_register: Registered Config Engine odbc
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: cdr.c:1419 in do_reload: CDR simple logging enabled.
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: loader.c:874 in load_modules: 31 modules will be loaded.
Jul 20 11:06:02 sip asterisk[4934]: WARNING[4934]: res_features.c:2851 in load_config: Could not load features.conf
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: res_smdi.c:862 in smdi_load: Unable to load config smdi.conf: SMDI disabled
Jul 20 11:06:02 sip asterisk[4934]: WARNING[4934]: res_smdi.c:1337 in load_module: No SMDI interfaces are available to listen on, not starting SMDI listener.
Jul 20 11:06:02 sip asterisk[4934]: WARNING[4934]: chan_iax2.c:2102 in reload_firmware: Error opening firmware directory '/var/lib/asterisk/firmware/iax': No such file or directory
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: iax2-provision.c:518 in iax_provision_reload: No IAX provisioning configuration found, IAX provisioning disabled.
Jul 20 11:06:02 sip asterisk[4934]: WARNING[4934]: cdr_odbc.c:268 in odbc_load_module: cdr_odbc: Unable to load config for ODBC CDR's: cdr_odbc.conf
Jul 20 11:06:02 sip asterisk[4934]: WARNING[4934]: app_voicemail.c:8485 in load_config: maxsilence should be less than minmessage or you may get empty messages
Jul 20 11:06:02 sip asterisk[4934]: NOTICE[4934]: manager.c:2958 in init_manager: Unable to open management configuration manager.conf.  Call management disabled.
root at sip:/var/log/ngcp# 











> On Jul 20, 2016, at 3:20 AM, Alex Lutay <alutay at sipwise.com> wrote:


> 
> Also,
> 
> I would start with kamailio-proxy and asterisk logs for your test call.
> 
> Ensure there is no rewrite rules applied, also verify that you have no
> outdated *.customtt.tt2 files in /etc/ngc-config/templates/
> 
> On 07/20/2016 12:54 AM, Dave Massey wrote:
>> I have an issue where voicemail is dead air once connected.
>> In 2.6 I had a rewrite rule that changes *98 in to 2000 and it worked fine.
>> 2.8 If I dial *98 I get dead air, if I dial 2000 directly i get a message saying the number I dialed isn't recognized.
>> I dont know where to start to look?
> 
> -- 
> Alex Lutay
> _______________________________________________
> Spce-user mailing list
> Spce-user at lists.sipwise.com
> https://lists.sipwise.com/listinfo/spce-user

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20160720/a1010368/attachment-0001.html>


More information about the Spce-user mailing list