RE: Freeswitch seems to be giving conflicting timestamps

I have no idea how to reply to these messages and have them come up in the same thread, I was using Nabble to do it but they don’t appear to be getting updated messages now...

Thanks for clearing that up! I hadn’t seen that before, the server had recently been rebooted so I’m guessing that it pulled the BIOS time before NTP had a chance to update the clock.

- Phil

_____________________________________________
From: Phil Quesinberry

Sent: Tuesday, June 17, 2014 1:11 PM
To: 'freeswitch-users@lists.freeswitch.org'
Subject: Freeswitch seems to be giving conflicting timestamps - what's the deal here?

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