See
https://wiki.freeswitch.org/wiki/Fsctl#sync_clock
and
https://wiki.freeswitch.org/wiki/Fsctl#sync_clock_when_idle
(the latter being much better to avoid incorrect durations in CDRs)

FS initiates an internal clock from the time at start then uses the monotonic clock to run it. The result is it can diverge from the system clock in some cases.

The reason your're seeing two different times is probably that one (SIP trace) is using the system time and the other (log messages) is using the internal FreeSWITCH one.


On 17 June 2014 18:11, Phil Quesinberry <philq@qsystemsengineering.com> wrote:

Looking into an intermittent problem that we’re having with one of our DIDs, I just noticed that some of the logged timestamps don’t seem to make sense, it’s like there are two different clocks at work here.  What’s interesting is that I’m seeing this wrong time in received contact header info as well but I’m guessing that’s coming back to us from our own NTP timestamp in the SDP we send back to them after the initial invite.  The system time is set correctly.

Here is a short excerpt of the console log with siptrace enabled on the external profile demonstrating this behavior:

recv 939 bytes from udp/[209.216.2.202]:5060 at 16:10:58.987966:

   ------------------------------------------------------------------------

   INVITE sip:1410xxx7612@173.59.xxx.xxx:5080;transport=udp SIP/2.0

   Via: SIP/2.0/UDP 209.216.2.202:5060;branch=z9hG4bK68239f89;rport

   From: "+1410xxx3048" <sip:+1410xxx3048@209.216.2.202>;tag=as0e92c0c82014-06-17 12:07:58.767052 [DEBUG] switch_core_session.c:1034 Send signal sofia/external/+1410xxx3048@209.216.2.202 [BREAK]

   To: <sip:1410xxx7612@voip.ourdomain.com:5080>;tag=Hj722eXX0yj8S

   Contact: <sip:+1410xxx3048@209.216.2.202>2014-06-17 12:07:58.767052 [DEBUG] switch_core_session.c:1034 Send signal sofia/external/+1410xxx3048@209.216.2.202 [BREAK]

   Call-ID: 63cd75ae5caa77be67d5a6944e86f5fe@209.216.2.202

   CSeq: 103 INVITE

   User-Agent: DidForSale-GW

   Max-Forwards: 70

   Remote-Party-ID: "+1410xxx3048" <sip:+1410xxx3048@209.216.2.202>;privacy=off;screen=no

   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY

   Content-Type: application/sdp

   Content-Length: 289

   v=0

   o=root 2802 2803 IN IP4 207.223.69.137

   s=session

   c=IN IP4 207.223.69.137

   t=0 0

   m=audio 51480 RTP/AVP 0 8 18 101

   a=rtpmap:0 PCMU/8000

   a=rtpmap:8 PCMA/8000

   a=rtpmap:18 G729/8000

   a=fmtp:18 annexb=no

   a=rtpmap:101 telephone-event/8000

   a=fmtp:101 0-16

   a=silenceSupp:off - - - -

   ------------------------------------------------------------------------

send 405 bytes to udp/[209.216.2.202]:5060 at 16:10:58.988281:

   ------------------------------------------------------------------------

   SIP/2.0 100 Trying

   Via: SIP/2.0/UDP 209.216.2.202:5060;branch=z9hG4bK68239f89;rport=5060

   From: "+1410xxx3048" <sip:+1410xxx3048@209.216.2.202>;tag=as0e92c0c8

   To: <sip:1410xxx7612@voip.ourdomain.com:5080>;tag=Hj722eXX0yj8S

   Call-ID: 63cd75ae5caa77be67d5a6944e86f5fe@209.216.2.202

   CSeq: 103 INVITE

   User-Agent: FreeSWITCH-mod_sofia/1.5.6b+git~20131022T212715Z~20a55d3cc6

   Content-Length: 0

   ------------------------------------------------------------------------

2014-06-17 12:07:58.787035 [DEBUG] sofia.c:5863 Channel sofia/external/+1410xxx3048@209.216.2.202 entering state [ready][200]

2014-06-17 12:07:58.787035 [DEBUG] sofia.c:5863 Channel sofia/external/+1410xxx3048@209.216.2.202 entering state [received][100]

2014-06-17 12:07:58.787035 [DEBUG] sofia.c:5873 Remote SDP:

v=0

o=root 2802 2803 IN IP4 207.223.69.137

s=session

c=IN IP4 207.223.69.137

t=0 0

m=audio 51480 RTP/AVP 0 8 18 101

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

2014-06-17 12:07:58.787035 [DEBUG] switch_core_media.c:2990 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]

2014-06-17 12:07:58.787035 [DEBUG] switch_core_media.c:1879 Already using PCMU

2014-06-17 12:07:58.787035 [DEBUG] switch_core_media.c:3161 Set 2833 dtmf send/recv payload to 101

Is this expected behavior or is this a bug in the version we’re using?

Thanks.

Phil Quesinberry

Q Systems Engineering, Inc.

Embedded Hardware and Software Development

(410) 969-8002

http://www.qsystemsengineering.com


_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
consulting@freeswitch.org
http://www.freeswitchsolutions.com

FreeSWITCH-powered IP PBX: The CudaTel Communication Server
http://www.cudatel.com

Official FreeSWITCH Sites
http://www.freeswitch.org
http://wiki.freeswitch.org
http://www.cluecon.com

FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org