[Home]

Summary:ASTERISK-28418: Timezone Problem
Reporter:Mesut Altürk (multimesut)Labels:pjsip
Date Opened:2019-05-17 08:55:23Date Closed:2019-06-05 12:00:01
Priority:MinorRegression?
Status:Closed/CompleteComponents:Channels/chan_sip/General
Versions:13.23.1 Frequency of
Occurrence		Occasional
Related
Issues:
Environment:Attachments:
Description:Hello,
I'm using Asterisk Asterisk 13.23.1. About 10 days later my rules are not working.  It records incorrect data on the CDR table. Then when I enter the CLI, I see that the time of modules like "chan_sip.c, acl.c, netsock2.c" is wrong, but the times of other messages are correct. I can't get a detailed log because it always comes along. But there's CLI out here. What could be the reason?

{noformat}
root@:~# timedatectl
Local time: Fri 2019-05-17 15:26:10 +03
Universal time: Fri 2019-05-17 12:26:10 UTC
RTC time: Fri 2019-05-17 12:26:10
Time zone: Europe/Istanbul (+03, +0300)
NTP enabled: no
NTP synchronized: yes
RTC in local TZ: no
DST active: n/a
root@:~# asterisk -rvvvv -T
[May 17 15:26:42]     -- Executing [s@macro-stdexten-withoutvm:32] Dial("SIP/156205-00019cfa", "SIP/156111,30,TtrXx") in new stack
[May 17 15:26:42]   == Using SIP RTP TOS bits 184
[May 17 15:26:42]   == Using SIP RTP CoS mark 5
[May 17 15:26:42]     -- Called SIP/156111
[May 17 15:26:42]     -- SIP/156111-00019cfb is ringing
[2019-05-17 12:26:42] ERROR[4991]: netsock2.c:305 ast_sockaddr_resolve: getaddrinfo("sip.sunucunuz.com", "(null)", ...): Name or service not known
[2019-05-17 12:26:42] WARNING[4991]: acl.c:835 resolve_first: Unable to lookup 'sip.sunucunuz.com'
[2019-05-17 12:26:42] WARNING[4991]: acl.c:974 ast_ouraddrfor: Cannot connect to (null): Invalid argument
[2019-05-17 12:26:42] WARNING[4991]: chan_sip.c:3781 __sip_xmit: sip_xmit of 0x7f44c0928360 (len 392) to (null) returned -1: Invalid argument
[2019-05-17 12:26:42] NOTICE[4991]: chan_sip.c:15906 sip_reg_timeout:    -- Registration for '@sip.sunucunuz.com' timed out, trying again (Attempt #370)
[2019-05-17 12:26:42] ERROR[4991]: netsock2.c:305 ast_sockaddr_resolve: getaddrinfo("sip.sunucunuz.com", "(null)", ...): Name or service not known
[2019-05-17 12:26:42] WARNING[4991]: acl.c:835 resolve_first: Unable to lookup 'sip.sunucunuz.com'
[2019-05-17 12:26:42] WARNING[4991]: acl.c:974 ast_ouraddrfor: Cannot connect to (null): Invalid argument
[2019-05-17 12:26:42] WARNING[4991]: chan_sip.c:3781 __sip_xmit: sip_xmit of 0x7f4531f87a50 (len 394) to (null) returned -1: Invalid argument
[2019-05-17 12:26:42] NOTICE[4991]: chan_sip.c:15906 sip_reg_timeout:    -- Registration for '@sip.sunucunuz.com' timed out, trying again (Attempt #42523)
[2019-05-17 12:26:43] ERROR[4991]: netsock2.c:305 ast_sockaddr_resolve: getaddrinfo("sip.host.com.tr", "(null)", ...): Name or service not known
[2019-05-17 12:26:43] WARNING[4991]: acl.c:835 resolve_first: Unable to lookup 'sip.host.com.tr'
[2019-05-17 12:26:43] WARNING[4991]: acl.c:974 ast_ouraddrfor: Cannot connect to (null): Invalid argument
[2019-05-17 12:26:43] WARNING[4991]: chan_sip.c:3781 __sip_xmit: sip_xmit of 0x7f44c068d3f0 (len 388) to (null) returned -1: Invalid argument
[2019-05-17 12:26:43] NOTICE[4991]: chan_sip.c:15906 sip_reg_timeout:    -- Registration for '@sip.host.com.tr' timed out, trying again (Attempt #42524)
[May 17 15:26:43]     -- SIP/161112-00019cf8 answered SIP/161115-00019cf7
[May 17 15:26:43]     -- Channel SIP/161112-00019cf8 joined 'simple_bridge' basic-bridge <56bd8beb-a408-4c10-be5a-a44bd69c270e>
[May 17 15:26:43]     -- Channel SIP/161115-00019cf7 joined 'simple_bridge' basic-bridge <56bd8beb-a408-4c10-be5a-a44bd69c270e>
{noformat}
Comments:By: Asterisk Team (asteriskteam) 2019-05-17 08:55:24.105-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.
By: Benjamin Keith Ford (bford) 2019-05-20 09:43:06.487-0500

Out of curiosity, can you try to reproduce this problem with PJSIP?

Also, are you using realtime? If so, what are you storing in realtime? What does your CDR config look like?
By: Mesut Altürk (multimesut) 2019-05-20 09:59:39.949-0500

Hello,

No working realtime. settings in conf files. CDR in mysql. unfortunately, I cannot reproduce the problem with PJSIP. 800 internal working system. but many modules are showing the clock incorrectly. example "Last reload time","netsock2.c","acl.c"
By: Benjamin Keith Ford (bford) 2019-05-20 11:41:27.010-0500

Just to clarify, does that you mean you were able to test with PJSIP and could not reproduce the problem, or you are unable to set PJSIP up to test this? For your CDR configuration, are you setting any of the timezone options by chance? Or have you tried setting them to your timezone specifically?
By: Mesut Altürk (multimesut) 2019-05-22 08:28:46.171-0500

Hi, Yes, true. I can't establish PJSIP. Made as follows.

asterisk;

*CLI> cdr show status
Call Detail Record (CDR) settings
----------------------------------
 Logging:                    Enabled
 Mode:                       Simple
 Log unanswered calls:       No
 Log congestion:             No

* Registered Backends
 -------------------
   Adaptive ODBC


cdr_adaptive_odbc.conf;

[PT1C_Global]
connection=PT1C_asteriskcdrdb
table=cdr


res_odbc.conf;

[PT1C_asteriskcdrdb]
enabled=>yes
dsn=>MySQL-asteriskcdrdb
pooling=>no
limit=>1
pre-connect=>yes
username=>test
password=>123456

By: Benjamin Keith Ford (bford) 2019-05-22 09:19:11.214-0500

There is an option called "usegmtime" you can put in cdr_adaptive_odbc.conf under your "PT1C_Global" section. Can you try setting this option and provide the timestamp of the CDR output that is wrong for you, as well as your actual time (from system clock, not Asterisk)? Also, what timezone are you under? This can help figure out if it's something Asterisk is doing, and is not intended to be a solution; just information gathering.
By: Asterisk Team (asteriskteam) 2019-06-05 12:00:01.404-0500

Suspended due to lack of activity. This issue will be automatically re-opened if the reporter posts a comment. If you are not the reporter and would like this re-opened please create a new issue instead. If the new issue is related to this one a link will be created during the triage process. Further information on issue tracker usage can be found in the Asterisk Issue Guidlines [1].

[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines
By: Mesut Altürk (multimesut) 2019-06-07 08:42:38.447-0500

thanks, i'll try it. I last arranged it as follows. I am using gmt + 3 time zone.

cdr_adaptive_odbc.conf;
[PT1C_Global]
usegmtime=yes
connection=PT1C_asteriskcdrdb
table=cdr
;alias recordingfile=>recordingfile
alias start=>calldate
By: Asterisk Team (asteriskteam) 2019-06-07 08:42:39.214-0500

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.
By: Mesut Altürk (multimesut) 2019-06-07 08:47:33.451-0500

when I set it this way, the clock is wrong. (usegmtime=yes)  I am using gmt + 3 time zone.
By: Chris Savinovich (csavinovich) 2019-06-10 17:27:32.647-0500

Hello Mesut, when you say "the clock is wrong" it is not clear what clock is wrong. Is it the CDR listing? can you please be more specific and also provide a copy of what you get and what you expect.
Chris

By: Mesut Altürk (multimesut) 2019-06-11 02:20:01.495-0500

Hello Chris,

I am using gmt + 3 time zone.

if i do "usegmtime=yes"  time is 12:00 (false)
if i do "usegmtime=no"  time is 15:00 (true)

but after 2-3 months of use, the clock returns to gmtime.
By: Chris Savinovich (csavinovich) 2019-06-12 15:52:23.780-0500

Hello Mesut, your problem is most probably the NTP not enabled.  According to your logs:
```
root@:~# timedatectl
Local time: Fri 2019-05-17 15:26:10 +03
Universal time: Fri 2019-05-17 12:26:10 UTC
RTC time: Fri 2019-05-17 12:26:10
Time zone: Europe/Istanbul (+03, +0300)
NTP enabled: no  <--- RIGHT HERE
```
This causes the different time readings. All applications read the time correctly, it is just that some use the UTC time but other use the UTC+3 time.  Setting the NTP correctly in your system will cause all apps to receive a uniform time. Google in how to enable NTP properly. and then let us know.
Thanks
Chris

By: Mesut Altürk (multimesut) 2019-06-13 02:29:53.031-0500

thank you for the answer. I have my daily running cron. I don't think ntp is the problem. A rare problem with asterisk causes clock deviation.

cron;
#!/bin/sh
/etc/init.d/ntp stop > /dev/null
TZ=Europe/Istanbul
if ntpdate tr.pool.ntp.org 1> /dev/null ;then
echo "Sync success!"
/etc/init.d/hwclock.sh stop
else
echo "Sync failed!"
fi
echo `date "+%x %R"`
/etc/init.d/ntp start > /dev/null
By: Chris Savinovich (csavinovich) 2019-06-13 09:15:57.079-0500

Hi Mesut,
 Did you get the output of the timedatectl command to say NTP enabled = yes?, When you get it to say enabled=yes let me know.
Thanks
Chris

By: Mesut Altürk (multimesut) 2019-06-13 09:21:13.995-0500

Hi Chris,
I was using the above script. I can activate(enabled=yes). we must follow up to 3 months to see the result.
Thanks
By: Chris Savinovich (csavinovich) 2019-06-13 14:12:07.210-0500

Hi Mesut, if you can activate it then would you please?... activate it, rebuild full, show me the output that says enabled=yes, and then let me know.
Thank you
Chris

By: Mesut Altürk (multimesut) 2019-06-14 01:07:48.297-0500

Hi Chris;

root@:~# timedatectl set-ntp on
root@:~# timedatectl
Warning: Ignoring the TZ variable. Reading the system's time zone setting only.

     Local time: Fri 2019-06-14 09:04:42 +03
 Universal time: Fri 2019-06-14 06:04:42 UTC
       RTC time: Fri 2019-06-14 06:04:41
      Time zone: Europe/Istanbul (+03, +0300)
    NTP enabled: yes
NTP synchronized: yes
RTC in local TZ: no
     DST active: n/a
By: Chris Savinovich (csavinovich) 2019-06-14 10:57:37.855-0500

....and what is Asterisk outputting now?
By: Chris Savinovich (csavinovich) 2019-06-14 11:10:04.079-0500

Hi Mesut: A couple more items to make sure the NTP is correct.
- set RTP on local TZ to yes, This you can do with:
    timedatectl set-local-rtc 1

- make sure the hardware clock is synchronized with localtime
  hwclock -r --localtime
 if it is not, then use hwclock to set it right

-and then show the logs

Thanks
Chris




By: Mesut Altürk (multimesut) 2019-06-17 06:56:21.410-0500

Hi Chris,

machine is a virtual server.

Thanks.
By: Chris Savinovich (csavinovich) 2019-06-17 15:23:58.682-0500

Hi Mesut, I am not sure if you have solved the problem or not (you are not saying the outcome of your changes) but in case the problem persists, I can tell you what I believe is going on: your hardware timezone and your linux instance are not synchronizing. Your hardware timezone is probably set to UTC and your linux instance is UTC+3. Your issue will persist until you find a way to synchronize both.
Thanks
Chris

By: Mesut Altürk (multimesut) 2019-06-28 08:21:56.562-0500

Hi Chris,

I'il set them up and follow them. the problem doesn't always happen. I cannot give information about her continuing. sometimes the clock deteriorates after 4 months. I'm watching. during this time the server and services do not restart at all.

Thanks.
By: Kevin Harwell (kharwell) 2019-06-28 16:34:31.126-0500

This is quite the unusual one. I am not discounting Asterisk's potential involvement here, but I wonder if this is some odd problem between the host, and hosted VM. If you can please provide the following information:

What OS is the host running? What OS is the hosted VM running? If possible please attach the _config.log_ file (can be found in the top level Asterisk directory where you built Asterisk from). Please also attach your _logger.conf_ file. As this is running Asterisk in VM where are Asterisk's libraries, executable, and configurations stored? In the VM itself or shared from the host?

If applicable what are the outputs of the following system commands for both host, and hosted:
{noformat}
$ ls -la /etc/localtime
{noformat}
{noformat}
$ echo $TZ
{noformat}
I know you have already provided above, but please provide again for both host and hosted, and associate it with the above information:
{noformat}
$ timedatectl
{noformat}
How is the system time, and timezone getting set when the VM is created? Could there be any scripts that are later setting the time and/or timezone?
By: Kevin Harwell (kharwell) 2019-06-28 16:54:26.276-0500

Also what is the output of the following from the VM running Asterisk:
{noformat}
$ ps aux | grep asterisk
{noformat}
By: Mesut Altürk (multimesut) 2019-07-01 07:09:10.039-0500

Hi Kevin,

;ESXi VSphere 6.5
***************************************************************************
[root@localhost:~] ls -la /etc/localtime
-r--r--r--    1 root     root            56 Apr 11  2016 /etc/localtime

[root@localhost:~] echo $TZ

[root@localhost:~] timedatectl
-sh: timedatectl: not found

;Asterisk / Debian 8
***************************************************************************
root@:~# ls -la /etc/localtime
lrwxrwxrwx 1 root root 35 Jun 30 23:59 /etc/localtime -> /usr/share/zoneinfo/Europe/Istanbul

root@:~# echo $TZ
EET-2EEST,M3.5.0/3,M10.5.0/4

root@:~# timedatectl
Warning: Ignoring the TZ variable. Reading the system's time zone setting only.

     Local time: Mon 2019-07-01 14:57:10 +03
 Universal time: Mon 2019-07-01 11:57:10 UTC
       RTC time: Mon 2019-07-01 11:57:10
      Time zone: Europe/Istanbul (+03, +0300)
    NTP enabled: yes
NTP synchronized: yes
RTC in local TZ: no
     DST active: n/a

root@:~# ps aux | grep asterisk
root      7745  0.0  0.0   4336   124 ?        S    Apr28   0:00 /bin/sh /usr/sbin/safe_asterisk -f
root      7749 16.2 34.2 4160228 1392008 ?     Sl   Apr28 15145:32 /usr/sbin/asterisk -f -f -vvvg -c
root     32211  0.0  0.0  12732  2084 pts/1    S+   14:59   0:00 grep asterisk

By: Asterisk Team (asteriskteam) 2019-07-16 12:00:01.993-0500

Suspended due to lack of activity. This issue will be automatically re-opened if the reporter posts a comment. If you are not the reporter and would like this re-opened please create a new issue instead. If the new issue is related to this one a link will be created during the triage process. Further information on issue tracker usage can be found in the Asterisk Issue Guidlines [1].

[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines