SPA3102 - Problems with incoming calls on PSTN line - single call looks like multiple calls

talktalkt · ‎04-05-2013

Hello,

I live in Portugal, and have a SPA3012 connected to a PSTN line of Portugal Telecom (via the FXO port), and a normal telephone connected to the SPA3102's FXS port. During an incoming call on the PSTN line, the phone rings and shows the caller ID correctly. However, after approx. 3 rings, the caller ID display disappears, and then shows again as "unknown number". The phone keeps ringing, but the phone thinks this is now a new call.

In other words, the single incoming call looks to the phone like 2 or 3 (or more, if I let it ring longer) separate calls, each of about 3 rings (the phone's log confirms this). The caller ID only is shown for the first one, the subsequent ones show up as "unknown" (which makes sense, since after the 3rd ring of course no new caller ID code was transmitted).

If I answer the call, most of the time it is OK (connection made), but if I answer just after the 3rd ring (or the 6th or 9th), then the SPA3102 will *not* answer the incoming call, but give me a VOIP dialtone for an outgoing call instead. So it seems that I am answering the call in the "break" between what the SPA3102 thinks are multiple incoming calls. If I just hang up (after getting the VOIP dialtone), the phone will then continue to ring.

I have tried this on different local PSTN lines (to make sure it's not a line problem), and also with different phones connected to the SPA3102 (to make sure it's not a phone issue).

So I think it must be a configuration problem of the SPA3102. I have configured it according to this guide from Portugal Telecom: Link

Any ideas what I might need to change to fix this?

Many thanks in advance!

Dan Lukes · ‎04-05-2013

Debug&syslog may help to analyze this.

talktalkt · ‎04-11-2013

Thanks for the suggestion! I captured a syslog of an incoming call on the PSTN line (I just let it ring several times without answering the call), and the phone registered it as 2 or 3 separate calls (first one showing the correct caller ID, then the subsequent "calls" showing "unknown caller").

Log:

09/04/2013 20:55,Debug,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,OP:STUNTS = 16 ( 16 68)

09/04/2013 20:55,Debug,192.168.1.86,OP:SUBDLG = 2 ( 2 6444)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPLIN = 0 ( 2 140)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPREG = 3 ( 4 468)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPSES = 12 ( 12 8192)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPDLG = 10 ( 10 148)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPAUS = 0 ( 8 588)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPSTS = 32 ( 32 6064)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPCTS = 32 ( 32 580)

09/04/2013 20:55,Debug,192.168.1.86,OP:SIPCOR = 0 ( 1 28)

09/04/2013 20:55,Debug,192.168.1.86,OP:TIMEOU = 111 (120 52)

09/04/2013 20:55,Debug,192.168.1.86,OP:RTPTXB = 64 ( 64 108)

09/04/2013 20:55,Debug,192.168.1.86,OP:RTPREB = 40 ( 40 48)

09/04/2013 20:55,Debug,192.168.1.86,OP:RTPRXB = 96 ( 96 192)

09/04/2013 20:55,Debug,192.168.1.86,--- OBJ POOL STAT ---

09/04/2013 20:55,Debug,192.168.1.86,CC:Clean Up

09/04/2013 20:55,Debug,192.168.1.86,Sess Terminated

09/04/2013 20:55,Debug,192.168.1.86,DLG Terminated 2e2da4

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,ACK sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ATo: <>;tag=27bbeb0ecf3c1099i0\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 ACK\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(385)

09/04/2013 20:55,Debug,192.168.1.86,DLG Terminated 2e32d8

09/04/2013 20:55,Debug,192.168.1.86,CC:Ended

09/04/2013 20:55,Debug,192.168.1.86,[0:0]AUD Rel Call

09/04/2013 20:55,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0024e22c;a=0)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 200 OK\0x0D\0x0ATo: <>;tag=27bbeb0ecf3c1099i0\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(302)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 487 Request Terminated\0x0D\0x0ATo: <>;tag=27bbeb0ecf3c1099i0\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(318)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,CANCEL sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ATo: <>\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(334)

09/04/2013 20:55,Debug,192.168.1.86,[1:0]AUD Rel Call

09/04/2013 20:55,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0025422c;a=0)

09/04/2013 20:55,Debug,192.168.1.86,FXO:Stop CNDD

09/04/2013 20:55,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:55,Debug,192.168.1.86,FXO:On Hook

09/04/2013 20:55,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:55,Debug,192.168.1.86,AUD:Play PSTN Tone 9

09/04/2013 20:55,Debug,192.168.1.86,[1:0]RTP Rx Dn

09/04/2013 20:55,Debug,192.168.1.86,CC:Ringback

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 180 Ringing\0x0D\0x0ATo: <>;tag=27bbeb0ecf3c1099i0\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AContact: +351289934899 <>\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0ARemote-Party-ID: +351289934899 <>+351289934899@sip.freevoipdeal.com>;screen=yes;party=called\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(466)

09/04/2013 20:55,Debug,192.168.1.86,[0:0]RTP Rx Up

09/04/2013 20:55,Debug,192.168.1.86,[0:0]AUD ALLOC CALL (port=16400)

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 100 Trying\0x0D\0x0ATo: <>\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(283)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,INVITE sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-86817105\0x0D\0x0AFrom: <192.168.1.86>;tag=4b8d5800f1ef384do1\0x0D\0x0ATo: <>\0x0D\0x0ARemote-Party-ID: <192.168.1.86>;screen=yes;party=calling\0x0D\0x0AAlert-Info: Bellcore-r1\0x0D\0x0ACall-ID: 68089c3c-f8446141@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AExpires: 240\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 255\0x0D\0x0AAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER\0x0D\0x0ASupported: x-sipura, replaces\0x0D\0x0AContent-Type: application/sdp\0x0D\0x0A\0x0D\0x0Av=0\0x0D\0x0Ao=- 5733838 5733838 IN IP4 192.168.1.86\0x0D\0x0As=-\0x0D\0x0Ac=IN IP4 192.168.1.86\0x0D\0x0At=0 0\0x0D\0x0Am=audio 16398 RTP/AVP 0 100 101\0x0D\0x0Aa=rtpmap:0 PCMU/8000\0x0D\0x0Aa=rtpmap:100 NSE/8000\0x0D\0x0Aa=fmtp:100 192-193\0x0D\0x0Aa=rtpmap:101 telephone-event/8000\0x0D\0x0Aa=fmtp:101 0-15\0x0D\0x0Aa=ptime:30\0x0D\0x0Aa=sendrecv

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(851)

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:55,Debug,192.168.1.86,[1:0]RTP Rx Up

09/04/2013 20:55,Debug,192.168.1.86,[1:0]AUD ALLOC CALL (port=16398)

09/04/2013 20:55,Debug,192.168.1.86,Calling:+351289934899@127.0.0.1:5060

09/04/2013 20:55,Debug,192.168.1.86,FXO:Start CNDD

09/04/2013 20:55,Debug,192.168.1.86,Sess Terminated

09/04/2013 20:55,Debug,192.168.1.86,DLG Terminated 2e3244

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,ACK sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ATo: <>;tag=d9ea0895f299b665i0\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 ACK\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(385)

09/04/2013 20:55,Debug,192.168.1.86,DLG Terminated 2e31b0

09/04/2013 20:55,Debug,192.168.1.86,CC:Ended

09/04/2013 20:55,Debug,192.168.1.86,[0:0]AUD Rel Call

09/04/2013 20:55,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0024e22c;a=0)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 200 OK\0x0D\0x0ATo: <>;tag=d9ea0895f299b665i0\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(302)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 487 Request Terminated\0x0D\0x0ATo: <>;tag=d9ea0895f299b665i0\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(318)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,CANCEL sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ATo: <>\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(334)

09/04/2013 20:55,Debug,192.168.1.86,[1:0]AUD Rel Call

09/04/2013 20:55,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0025422c;a=0)

09/04/2013 20:55,Debug,192.168.1.86,FXO:Stop CNDD

09/04/2013 20:55,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:55,Debug,192.168.1.86,FXO:On Hook

09/04/2013 20:55,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:55,Debug,192.168.1.86,AUD:Play PSTN Tone 9

09/04/2013 20:55,Debug,192.168.1.86,[1:0]RTP Rx Dn

09/04/2013 20:55,Debug,192.168.1.86,CC:Ringback

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 180 Ringing\0x0D\0x0ATo: <>;tag=d9ea0895f299b665i0\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AContact: +351289934899 <>\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0ARemote-Party-ID: +351289934899 <>+351289934899@sip.freevoipdeal.com>;screen=yes;party=called\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(466)

09/04/2013 20:55,Debug,192.168.1.86,[0:0]RTP Rx Up

09/04/2013 20:55,Debug,192.168.1.86,[0:0]AUD ALLOC CALL (port=16396)

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 100 Trying\0x0D\0x0ATo: <>\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(283)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,INVITE sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-8087a9a5\0x0D\0x0AFrom: <192.168.1.86>;tag=122038fbcab7d135o1\0x0D\0x0ATo: <>\0x0D\0x0ARemote-Party-ID: <192.168.1.86>;screen=yes;party=calling\0x0D\0x0AAlert-Info: Bellcore-r1\0x0D\0x0ACall-ID: 9ee0b0f3-f6d4f99d@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AExpires: 240\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 255\0x0D\0x0AAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER\0x0D\0x0ASupported: x-sipura, replaces\0x0D\0x0AContent-Type: application/sdp\0x0D\0x0A\0x0D\0x0Av=0\0x0D\0x0Ao=- 5733237 5733237 IN IP4 192.168.1.86\0x0D\0x0As=-\0x0D\0x0Ac=IN IP4 192.168.1.86\0x0D\0x0At=0 0\0x0D\0x0Am=audio 16394 RTP/AVP 0 100 101\0x0D\0x0Aa=rtpmap:0 PCMU/8000\0x0D\0x0Aa=rtpmap:100 NSE/8000\0x0D\0x0Aa=fmtp:100 192-193\0x0D\0x0Aa=rtpmap:101 telephone-event/8000\0x0D\0x0Aa=fmtp:101 0-15\0x0D\0x0Aa=ptime:30\0x0D\0x0Aa=sendrecv

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(851)

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:55,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:55,Debug,192.168.1.86,[1:0]RTP Rx Up

09/04/2013 20:55,Debug,192.168.1.86,[1:0]AUD ALLOC CALL (port=16394)

09/04/2013 20:55,Debug,192.168.1.86,Calling:+351289934899@127.0.0.1:5060

09/04/2013 20:55,Debug,192.168.1.86,FXO:Start CNDD

09/04/2013 20:55,Debug,192.168.1.86,Sess Terminated

09/04/2013 20:55,Debug,192.168.1.86,DLG Terminated 2e311c

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,ACK sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ATo: <>;tag=5d00126d7b9b7418i0\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 ACK\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(385)

09/04/2013 20:55,Debug,192.168.1.86,DLG Terminated 2e3088

09/04/2013 20:55,Debug,192.168.1.86,CC:Ended

09/04/2013 20:55,Debug,192.168.1.86,[0:0]AUD Rel Call

09/04/2013 20:55,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0024e22c;a=0)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 200 OK\0x0D\0x0ATo: <>;tag=5d00126d7b9b7418i0\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(302)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,SIP/2.0 487 Request Terminated\0x0D\0x0ATo: <>;tag=5d00126d7b9b7418i0\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]->127.0.0.1:5061(318)

09/04/2013 20:55,Info,192.168.1.86,

09/04/2013 20:55,Debug,192.168.1.86,CANCEL sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ATo: <>\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:55,Info,192.168.1.86,[0]<<127.0.0.1:5061(334)

09/04/2013 20:55,Debug,192.168.1.86,[1:0]AUD Rel Call

09/04/2013 20:55,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0025422c;a=0)

09/04/2013 20:55,Debug,192.168.1.86,FXO:Stop CNDD

09/04/2013 20:55,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:55,Debug,192.168.1.86,FXO:On Hook

09/04/2013 20:55,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,IDBG:rs:12

09/04/2013 20:54,Debug,192.168.1.86,IDBG:sc-0

09/04/2013 20:54,Debug,192.168.1.86,AUD:Play PSTN Tone 9

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Dn

09/04/2013 20:54,Debug,192.168.1.86,CC:Ringback

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 180 Ringing\0x0D\0x0ATo: <>;tag=5d00126d7b9b7418i0\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AContact: +351289934899 <>\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0ARemote-Party-ID: +351289934899 <>+351289934899@sip.freevoipdeal.com>;screen=yes;party=called\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(466)

09/04/2013 20:54,Debug,192.168.1.86,[0:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD ALLOC CALL (port=16392)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 100 Trying\0x0D\0x0ATo: <>\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(283)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,INVITE sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-16e79d04\0x0D\0x0AFrom: <192.168.1.86>;tag=1cc0cbdf6213b94co1\0x0D\0x0ATo: <>\0x0D\0x0ARemote-Party-ID: <192.168.1.86>;screen=yes;party=calling\0x0D\0x0AAlert-Info: Bellcore-r1\0x0D\0x0ACall-ID: e383b19b-ab29aec0@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AExpires: 240\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 255\0x0D\0x0AAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER\0x0D\0x0ASupported: x-sipura, replaces\0x0D\0x0AContent-Type: application/sdp\0x0D\0x0A\0x0D\0x0Av=0\0x0D\0x0Ao=- 5732640 5732640 IN IP4 192.168.1.86\0x0D\0x0As=-\0x0D\0x0Ac=IN IP4 192.168.1.86\0x0D\0x0At=0 0\0x0D\0x0Am=audio 16390 RTP/AVP 0 100 101\0x0D\0x0Aa=rtpmap:0 PCMU/8000\0x0D\0x0Aa=rtpmap:100 NSE/8000\0x0D\0x0Aa=fmtp:100 192-193\0x0D\0x0Aa=rtpmap:101 telephone-event/8000\0x0D\0x0Aa=fmtp:101 0-15\0x0D\0x0Aa=ptime:30\0x0D\0x0Aa=sendrecv

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(851)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD ALLOC CALL (port=16390)

09/04/2013 20:54,Debug,192.168.1.86,Calling:+351289934899@127.0.0.1:5060

09/04/2013 20:54,Debug,192.168.1.86,FXO:Start CNDD

09/04/2013 20:54,Debug,192.168.1.86,Sess Terminated

09/04/2013 20:54,Debug,192.168.1.86,DLG Terminated 2e2f60

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,ACK sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ATo: <>;tag=b16b2aa41a48def2i0\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 ACK\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(385)

09/04/2013 20:54,Debug,192.168.1.86,DLG Terminated 2e2ff4

09/04/2013 20:54,Debug,192.168.1.86,CC:Ended

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD Rel Call

09/04/2013 20:54,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0024e22c;a=0)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 200 OK\0x0D\0x0ATo: <>;tag=b16b2aa41a48def2i0\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(302)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 487 Request Terminated\0x0D\0x0ATo: <>;tag=b16b2aa41a48def2i0\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(318)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,CANCEL sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ATo: <>\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(334)

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD Rel Call

09/04/2013 20:54,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0025422c;a=0)

09/04/2013 20:54,Debug,192.168.1.86,FXO:Stop CNDD

09/04/2013 20:54,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,FXO:On Hook

09/04/2013 20:54,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,IDBG:rs:12

09/04/2013 20:54,Debug,192.168.1.86,IDBG:sc-0

09/04/2013 20:54,Debug,192.168.1.86,AUD:Play PSTN Tone 9

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Dn

09/04/2013 20:54,Debug,192.168.1.86,CC:Ringback

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 180 Ringing\0x0D\0x0ATo: <>;tag=b16b2aa41a48def2i0\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AContact: +351289934899 <>\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0ARemote-Party-ID: +351289934899 <>+351289934899@sip.freevoipdeal.com>;screen=yes;party=called\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(466)

09/04/2013 20:54,Debug,192.168.1.86,[0:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD ALLOC CALL (port=16388)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 100 Trying\0x0D\0x0ATo: <>\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(283)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,INVITE sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-9a667eaa\0x0D\0x0AFrom: <192.168.1.86>;tag=c15bc7429f98baeao1\0x0D\0x0ATo: <>\0x0D\0x0ARemote-Party-ID: <192.168.1.86>;screen=yes;party=calling\0x0D\0x0AAlert-Info: Bellcore-r1\0x0D\0x0ACall-ID: 7cc32022-75be378a@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AExpires: 240\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 255\0x0D\0x0AAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER\0x0D\0x0ASupported: x-sipura, replaces\0x0D\0x0AContent-Type: application/sdp\0x0D\0x0A\0x0D\0x0Av=0\0x0D\0x0Ao=- 5732037 5732037 IN IP4 192.168.1.86\0x0D\0x0As=-\0x0D\0x0Ac=IN IP4 192.168.1.86\0x0D\0x0At=0 0\0x0D\0x0Am=audio 16386 RTP/AVP 0 100 101\0x0D\0x0Aa=rtpmap:0 PCMU/8000\0x0D\0x0Aa=rtpmap:100 NSE/8000\0x0D\0x0Aa=fmtp:100 192-193\0x0D\0x0Aa=rtpmap:101 telephone-event/8000\0x0D\0x0Aa=fmtp:101 0-15\0x0D\0x0Aa=ptime:30\0x0D\0x0Aa=sendrecv

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(851)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD ALLOC CALL (port=16386)

09/04/2013 20:54,Debug,192.168.1.86,Calling:+351289934899@127.0.0.1:5060

09/04/2013 20:54,Debug,192.168.1.86,FXO:Start CNDD

09/04/2013 20:54,Debug,192.168.1.86,Sess Terminated

09/04/2013 20:54,Debug,192.168.1.86,DLG Terminated 2e2e38

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,ACK sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ATo: <>;tag=487f0c82b5ac3457i0\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 ACK\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(384)

09/04/2013 20:54,Debug,192.168.1.86,DLG Terminated 2e2ecc

09/04/2013 20:54,Debug,192.168.1.86,CC:Ended

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD Rel Call

09/04/2013 20:54,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0024e22c;a=0)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 200 OK\0x0D\0x0ATo: <>;tag=487f0c82b5ac3457i0\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(301)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 487 Request Terminated\0x0D\0x0ATo: <>;tag=487f0c82b5ac3457i0\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(317)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,CANCEL sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ATo: <>\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(333)

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD Rel Call

09/04/2013 20:54,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0025422c;a=0)

09/04/2013 20:54,Debug,192.168.1.86,FXO:Stop CNDD

09/04/2013 20:54,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,FXO:On Hook

09/04/2013 20:54,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,AUD:Play PSTN Tone 9

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Dn

09/04/2013 20:54,Debug,192.168.1.86,CC:Ringback

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 180 Ringing\0x0D\0x0ATo: <>;tag=487f0c82b5ac3457i0\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AContact: +351289934899 <>\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0ARemote-Party-ID: +351289934899 <>+351289934899@sip.freevoipdeal.com>;screen=yes;party=called\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(465)

09/04/2013 20:54,Debug,192.168.1.86,[0:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD ALLOC CALL (port=16384)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 100 Trying\0x0D\0x0ATo: <>\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(282)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,INVITE sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-3752516b\0x0D\0x0AFrom: <192.168.1.86>;tag=835cf5c32b3bf43o1\0x0D\0x0ATo: <>\0x0D\0x0ARemote-Party-ID: <192.168.1.86>;screen=yes;party=calling\0x0D\0x0AAlert-Info: Bellcore-r1\0x0D\0x0ACall-ID: 8fb23010-df09b61f@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AExpires: 240\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 255\0x0D\0x0AAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER\0x0D\0x0ASupported: x-sipura, replaces\0x0D\0x0AContent-Type: application/sdp\0x0D\0x0A\0x0D\0x0Av=0\0x0D\0x0Ao=- 5731440 5731440 IN IP4 192.168.1.86\0x0D\0x0As=-\0x0D\0x0Ac=IN IP4 192.168.1.86\0x0D\0x0At=0 0\0x0D\0x0Am=audio 16482 RTP/AVP 0 100 101\0x0D\0x0Aa=rtpmap:0 PCMU/8000\0x0D\0x0Aa=rtpmap:100 NSE/8000\0x0D\0x0Aa=fmtp:100 192-193\0x0D\0x0Aa=rtpmap:101 telephone-event/8000\0x0D\0x0Aa=fmtp:101 0-15\0x0D\0x0Aa=ptime:30\0x0D\0x0Aa=sendrecv

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(850)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD ALLOC CALL (port=16482)

09/04/2013 20:54,Debug,192.168.1.86,Calling:+351289934899@127.0.0.1:5060

09/04/2013 20:54,Debug,192.168.1.86,FXO:Start CNDD

09/04/2013 20:54,Debug,192.168.1.86,Sess Terminated

09/04/2013 20:54,Debug,192.168.1.86,DLG Terminated 2e32d8

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,ACK sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ATo: <>;tag=41a4673363daabc0i0\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 ACK\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(385)

09/04/2013 20:54,Debug,192.168.1.86,DLG Terminated 2e2da4

09/04/2013 20:54,Debug,192.168.1.86,CC:Ended

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD Rel Call

09/04/2013 20:54,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0024e22c;a=0)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 200 OK\0x0D\0x0ATo: <>;tag=41a4673363daabc0i0\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(302)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 487 Request Terminated\0x0D\0x0ATo: <>;tag=41a4673363daabc0i0\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(318)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,CANCEL sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ATo: <>\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 CANCEL\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(334)

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD Rel Call

09/04/2013 20:54,Debug,192.168.1.86,[0]FM Alert Stop RxTx (c=0025422c;a=0)

09/04/2013 20:54,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,FXO:On Hook

09/04/2013 20:54,Debug,192.168.1.86,AUD:Stop PSTN Tone

09/04/2013 20:54,Debug,192.168.1.86,IDBG:rs:12

09/04/2013 20:54,Debug,192.168.1.86,IDBG:sc-0

09/04/2013 20:54,Debug,192.168.1.86,FXO:CNDD Name= Phone=969622043

09/04/2013 20:54,Debug,192.168.1.86,FXO:Stop CNDD

09/04/2013 20:54,Debug,192.168.1.86,FXO:CNDD name=, number=969622043

09/04/2013 20:54,Debug,192.168.1.86,-- Caller ID:\0x0A-- Name = (null)\0x0A-- Remote Number = 969622043\0x0A-- Dialable Number = (null)\0x0A-- No Number Reason = (null)\0x0A-- No Name Reason = (null)\0x0A-- Message Waiting = (null)\0x0A-- Date and Time = 04/09 20:54

09/04/2013 20:54,Debug,192.168.1.86,fxo cnddwrap_feed parse ok 969622043 status=2

09/04/2013 20:54,Debug,192.168.1.86,caller id parse number=969622043

09/04/2013 20:54,Debug,192.168.1.86,AUD:Play PSTN Tone 9

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Dn

09/04/2013 20:54,Debug,192.168.1.86,CC:Ringback

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 180 Ringing\0x0D\0x0ATo: <>;tag=41a4673363daabc0i0\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AContact: +351289934899 <>\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0ARemote-Party-ID: +351289934899 <>+351289934899@sip.freevoipdeal.com>;screen=yes;party=called\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(466)

09/04/2013 20:54,Debug,192.168.1.86,[0:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[0:0]AUD ALLOC CALL (port=16480)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,SIP/2.0 100 Trying\0x0D\0x0ATo: <>\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AServer: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 0

09/04/2013 20:54,Info,192.168.1.86,[0]->127.0.0.1:5061(283)

09/04/2013 20:54,Info,192.168.1.86,

09/04/2013 20:54,Debug,192.168.1.86,INVITE sip:+351289934899@127.0.0.1:5060 SIP/2.0\0x0D\0x0AVia: SIP/2.0/UDP 192.168.1.86:5061;branch=z9hG4bK-e82e15b4\0x0D\0x0AFrom: <192.168.1.86>;tag=ee29cdeda250e44co1\0x0D\0x0ATo: <>\0x0D\0x0ARemote-Party-ID: <192.168.1.86>;screen=yes;party=calling\0x0D\0x0AAlert-Info: Bellcore-r1\0x0D\0x0ACall-ID: 619bb341-90ce1f08@192.168.1.86\0x0D\0x0ACSeq: 101 INVITE\0x0D\0x0AMax-Forwards: 70\0x0D\0x0AContact: <192.168.1.86:5061>\0x0D\0x0AExpires: 240\0x0D\0x0AUser-Agent: Linksys/SPA3102-5.2.13(GW002)\0x0D\0x0AContent-Length: 255\0x0D\0x0AAllow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER\0x0D\0x0ASupported: x-sipura, replaces\0x0D\0x0AContent-Type: application/sdp\0x0D\0x0A\0x0D\0x0Av=0\0x0D\0x0Ao=- 5730006 5730006 IN IP4 192.168.1.86\0x0D\0x0As=-\0x0D\0x0Ac=IN IP4 192.168.1.86\0x0D\0x0At=0 0\0x0D\0x0Am=audio 16478 RTP/AVP 0 100 101\0x0D\0x0Aa=rtpmap:0 PCMU/8000\0x0D\0x0Aa=rtpmap:100 NSE/8000\0x0D\0x0Aa=fmtp:100 192-193\0x0D\0x0Aa=rtpmap:101 telephone-event/8000\0x0D\0x0Aa=fmtp:101 0-15\0x0D\0x0Aa=ptime:30\0x0D\0x0Aa=sendrecv

09/04/2013 20:54,Info,192.168.1.86,[0]<<127.0.0.1:5061(851)

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 101 --> 136

09/04/2013 20:54,Debug,192.168.1.86,SDP RTPMAP 100 --> 134

09/04/2013 20:54,Debug,192.168.1.86,[1:0]RTP Rx Up

09/04/2013 20:54,Debug,192.168.1.86,[1:0]AUD ALLOC CALL (port=16478)

09/04/2013 20:54,Debug,192.168.1.86,Calling:+351289934899@127.0.0.1:5060

09/04/2013 20:54,Debug,192.168.1.86,FXO:Start CNDD

Any idea what might be going wrong here?

Thank you!

j0hnny__p · ‎11-28-2013

I have exactly the same problem with my SPA3102. Has anyone found the solution?

My logs:

https://dl.dropboxusercontent.com/u/24065517/syslog.514.log

https://dl.dropboxusercontent.com/u/24065517/syslog.514_2.log

Bandit9999 · ‎11-11-2014

Sorry to drag up an old thread... but I've just got my spa3102 out of mothballs & trying to get it going on a Portuguese telecom.pt line

I get this exact same problem & it's driving me nuts :)

Any help appreciated!

Thanks

talktalkt · ‎11-11-2014

Well, at least I am not the only one with the problem!

But unfortunately, I never found a solution... tried lots of things, but no joy. Hopefully you'll have better luck!

Bandit9999 · ‎11-12-2014

Thanks for coming back to me.

The only ground I made was upgrading to the last release software 5.2.13 stops the repeated calls coming in every 3 seconds or so - you now just get the original call followed 3 rings later by what seems to be a voip call.

Strange behaviour that I think I'm going to have to admit defeat on...

Did you ever get any voip phone working successfully on the pt-meo line?

talktalkt · ‎11-12-2014

No problems whatsoever with the Gigaset IP series phones (e.g. Gigaset C470IP, C590IP, C610IP etc.). A much better experience... it's almost plug-and-go!

Also got a Fritzbox working, no major issues although it took a little more tinkering. Ultimately, the problem is specific to the SPA1302, haven't encountered that issue with any other VOIP equipment....

Bandit9999 · ‎11-12-2014

OK, thanks.

Although... after numerous hours!! I think I might have sorted it...

Voice PSTN Line - FXO Timer Values

PSTN Ring Timeout:

Portugal is fairly unusual in that the ring cadence is 1s on/5s off so the PSTN ring timeout needs to be 6s or more otherwise the spa thinks the call has stopped

kxr_temp_account · ‎03-27-2016

Thank you Bandit9999. I can't thank you enough. This problem was driving me nuts for almost a month. Increasing the time out value solved the problem. Thank you so much. I made this account just to thank you :)

Regards,
kxr