[Freeswitch-users] Freeswitch seems to be giving conflicting timestamps - what's the deal here?

Tue Jun 17 21:39:04 MSD 2014

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 at 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 at 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 at 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 at voip.ourdomain.com:5080>;tag=Hj722eXX0yj8S
>
>    Contact: <sip:+1410xxx3048 at 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 at 209.216.2.202
>
>    CSeq: 103 INVITE
>
>    User-Agent: DidForSale-GW
>
>    Max-Forwards: 70
>
>    Remote-Party-ID: "+1410xxx3048" <sip:+1410xxx3048 at 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 at 209.216.2.202>;tag=as0e92c0c8
>
>    To: <sip:1410xxx7612 at voip.ourdomain.com:5080>;tag=Hj722eXX0yj8S
>
>    Call-ID: 63cd75ae5caa77be67d5a6944e86f5fe at 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/+1
> 410xxx3048 at 209.216.2.202 entering state [ready][200]
>
> 2014-06-17 12:07:58.787035 [DEBUG] sofia.c:5863 Channel sofia/external/+1
> 410xxx3048 at 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* <http://www.qsystemsengineering.com/>
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140617/9c101120/attachment.html 