Summary: | ASTERISK-28418: Timezone Problem | ||
Reporter: | Mesut Altürk (multimesut) | Labels: | pjsip |
Date Opened: | 2019-05-17 08:55:23 | Date Closed: | 2019-06-05 12:00:01 |
Priority: | Minor | Regression? | |
Status: | Closed/Complete | Components: | 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 |