Überhaupt scheint mir das alles arg sprunghaft, dass so oft (und scheinbar teils unnötig) neue Transports gebaut werden.
Insbesondere nach dem Event "die passende WAN Verbindung ist jetzt verfügbar" sollte man die erst(e) beste IP-Adresse aus dem VCM DNS Cache holen, statt die nächste. Die nächste sollte man sich nur dann nehmen wenn man sicher ist dass die vorherige nicht erreichbar ist obwohl die WAN Verbindung besteht, also wenn man abgeschätzt hat dass der Fehler beim Provider liegt.
Im Anhang ein Trace während der Aktivierung einer Line, welche trotz stabiler WAN Verbindung mehrere verschiede Transports baut.
Ja, toll, man darf keine TXT und keine PDF Dateien anhängen. Na dann hier:
Code: Alles auswählen
05/23/2017 22:22:18 schlimmchen on torvalds in /Setup/Voice-Call-Manager/Lines/SIP-Provider/Line/1UND1934XXXX
> tr # sip-p sip-c call vcm
SIP-Packet ON
SIP-Connection ON
Callmanager ON
VCM-DNS ON
05/23/2017 22:22:25 schlimmchen on torvalds in /Setup/Voice-Call-Manager/Lines/SIP-Provider/Line/1UND1934XXXX
> set act y
set ok:
Active VALUE: Yes
05/23/2017 22:22:28 schlimmchen on torvalds in /Setup/Voice-Call-Manager/Lines/SIP-Provider/Line/1UND1934XXXX
>
[VCM-DNS] 2017/05/23 22:22:28,224 [SIP Local SRV]: Registered domain "1und1.de" (line domain), new use count is 3
[Callmanager] 2017/05/23 22:22:28,224 [SIP-Provider] : 1UND1934XXXX: constructor -> registrar IP:unspecified
[Callmanager] 2017/05/23 22:22:28,224 [1UND1934XXXX Registrar Transport]: (Re)Starting with domain name "sip.1und1.de"
[VCM-DNS] 2017/05/23 22:22:28,225 [SIP DNS Cache]: Register: New use count for <_sip._udp.sip.1und1.de, Tag 0> is 3
[Callmanager] 2017/05/23 22:22:28,225 [1UND19349593 Registrar Transport]: Ignoring DNS update event (not bootstrapping)
[Callmanager] 2017/05/23 22:22:28,225 [1UND19349592 Registrar Transport]: Ignoring DNS update event (not bootstrapping)
[VCM-DNS] 2017/05/23 22:22:28,225 [SIP DNS Cache]: Searching 1. most preferred IP address for key <_sip._udp.sip.1und1.de, Tag 0>
[VCM-DNS] 2017/05/23 22:22:28,225 [SIP DNS Cache]: Found IP address 2001:8d8:104:100:212:227:124:130 for DNS name "1und1-1.sip.1und1.de", which is target for SRV record "_sip._udp.sip.1und1.de" with priority 0 and weight 0
[Callmanager] 2017/05/23 22:22:28,225 [1UND1934XXXX Registrar Transport]: Got valid IP address from DNS cache
[Callmanager] 2017/05/23 22:22:28,225 [1UND1934XXXX Registrar Transport]: New transport endpoint is [2001:8d8:104:100:212:227:124:130]:5060, transport state is "FixedIpBootstrapping"
[SIP-Connection] 2017/05/23 22:22:28,225 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Started IPv6 UDP listener on port 65461
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: registrar transport is ready
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: startRegistration: this:06c81bc0, caller:01a2340c, registration:enabled, register_info:NOT active
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: isNotAvailable:no, TimerExpired:no, this:06c81bc0
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: eNaUnregister
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: Unregister: CallId:497951934XXXX-1und1.de-3b422a20@00a0571f22dd
[Callmanager] 2017/05/23 22:22:28,225 [SIP-CALL] : cSipCall constructor (type 2) --- call=0539a020, MediaStub=0539a4e8, SIP call-id=1926561673@00a0571f22dd
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: Unregister: created SIP call
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:Ready, database has calls
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : -----[ GENERATE REGISTER, call-id=5956
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : m_RegisterContactUri:<::0>
[Callmanager] 2017/05/23 22:22:28,225 [SIP-Provider] : m_RegisterContactUri:<sip:497951934XXXX@[2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461>
[SIP-Packet] 2017/05/23 22:22:28,226 [Packet]:
Sending datagram (481 Bytes) from [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461 to [2001:8d8:104:100:212:227:124:130]:5060 using UDP (RtgTag 0):
REGISTER sip:1und1.de SIP/2.0\r\n
Via: SIP/2.0/UDP [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;branch=z9hG4bK-19cee601-6ddf0af9;rport\r\n
From: <sip:497951934XXXX@1und1.de>;tag=-1670203080--1235947966\r\n
To: <sip:497951934XXXX@1und1.de>\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 813 REGISTER\r\n
Allow: REGISTER, INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, OPTIONS, PRACK, UPDATE, SUBSCRIBE\r\n
Max-Forwards: 70\r\n
Contact: *\r\n
Expires: 0\r\n
User-Agent: Lancom\r\n
Content-Length: 0\r\n
\r\n
[Callmanager] 2017/05/23 22:22:28,226 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a31d6c
[Callmanager] 2017/05/23 22:22:28,226 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:Ready, database has calls
[Callmanager] 2017/05/23 22:22:28,226 [SIP-Provider] : 1UND1934XXXX: No messages were pending!
[Callmanager] 2017/05/23 22:22:28,226 [1UND1934XXXX Registrar Transport]: WAN connection "1UND1WAN" for line "1UND1934XXXX" is up
[Callmanager] 2017/05/23 22:22:28,226 [1UND1934XXXX Registrar Transport]: (Re)Starting with domain name "sip.1und1.de"
[VCM-DNS] 2017/05/23 22:22:28,226 [SIP DNS Cache]: Searching 2. most preferred IP address for key <_sip._udp.sip.1und1.de, Tag 0>
[VCM-DNS] 2017/05/23 22:22:28,226 [SIP DNS Cache]: Found IP address 2001:8d8:104:100:212:227:124:129 for DNS name "1und1-1.sip.1und1.de", which is target for SRV record "_sip._udp.sip.1und1.de" with priority 0 and weight 0
[Callmanager] 2017/05/23 22:22:28,226 [1UND1934XXXX Registrar Transport]: Got valid IP address from DNS cache
[Callmanager] 2017/05/23 22:22:28,226 [1UND1934XXXX Registrar Transport]: New transport endpoint is [2001:8d8:104:100:212:227:124:129]:5060, transport state is "FixedIpBootstrapping"
[SIP-Connection] 2017/05/23 22:22:28,226 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:129]:5060)]: Starting IPv6 UDP listener on port 65461 failed
[Callmanager] 2017/05/23 22:22:28,226 [SIP-Provider] : 1UND1934XXXX: registrar transport failed
[Callmanager] 2017/05/23 22:22:28,226 [SIP-Provider] : 1UND1934XXXX: stopRegistration: this:06c81bc0, caller:01a1eb3c, registration:enabled, register_info:active
[Callmanager] 2017/05/23 22:22:28,226 [1UND1934XXXX Registrar Transport]: (Re)Starting with domain name "sip.1und1.de"
[VCM-DNS] 2017/05/23 22:22:28,226 [SIP DNS Cache]: Searching 3. most preferred IP address for key <_sip._udp.sip.1und1.de, Tag 0>
[VCM-DNS] 2017/05/23 22:22:28,226 [SIP DNS Cache]: Found IP address 212.227.124.129 for DNS name "1und1-1.sip.1und1.de", which is target for SRV record "_sip._udp.sip.1und1.de" with priority 0 and weight 0
[Callmanager] 2017/05/23 22:22:28,227 [1UND1934XXXX Registrar Transport]: Got valid IP address from DNS cache
[Callmanager] 2017/05/23 22:22:28,227 [1UND1934XXXX Registrar Transport]: New transport endpoint is 212.227.124.129:5060, transport state is "FixedIpBootstrapping"
[SIP-Connection] 2017/05/23 22:22:28,227 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:129]:5060)]: Discarding (local socket was [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:0, Tag 0)
[SIP-Connection] 2017/05/23 22:22:28,227 [SIP UDP Transport (212.227.124.129:5060)]: Started IPv4 UDP listener on port 65461
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: registrar transport is ready
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: startRegistration: this:06c81bc0, caller:01a2340c, registration:enabled, register_info:NOT active
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: isNotAvailable:no, TimerExpired:no, this:06c81bc0
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: eNaUnregister
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: Unregister: CallId:497951934XXXX-1und1.de-3b422a20@00a0571f22dd
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a31d6c
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:Ready, database has calls
[Callmanager] 2017/05/23 22:22:28,227 [SIP-Provider] : 1UND1934XXXX: No messages were pending!
[Callmanager] 2017/05/23 22:22:28,227 [1UND1934XXXX Registrar Transport]: Could not connect the transport
[Callmanager] 2017/05/23 22:22:28,227 [1UND1934XXXX Registrar Transport]: WAN connection "1UND1WAN" for line "1UND1934XXXX" is up
[Callmanager] 2017/05/23 22:22:28,227 [1UND1934XXXX Registrar Transport]: WAN connection "1UND1WAN" for line "1UND1934XXXX" is up
[SIP-Connection] 2017/05/23 22:22:28,254 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Strict Mode: Provider uses expected endpoint
[SIP-Connection] 2017/05/23 22:22:28,254 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Processing new inbound SIP message
[SIP-Packet] 2017/05/23 22:22:28,254 [Packet]:
Receiving datagram (520 Bytes) at [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461 from [2001:8d8:104:100:212:227:124:130]:5060 using UDP (RtgTag 0):
SIP/2.0 401 Unauthorized\r\n
Via: SIP/2.0/UDP [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;received=2003:73:4F7F:B473:A0:57FF:FE1F:22DD;branch=z9hG4bK-19cee601-6ddf0af9;rport=65461\r\n
From: <sip:497951934XXXX@1und1.de>;tag=-1670203080--1235947966\r\n
To: <sip:497951934XXXX@1und1.de>;tag=b27e1a1d33761e85846fc98f5f3a7e58.6601\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 813 REGISTER\r\n
WWW-Authenticate: Digest realm="1und1.de", nonce="WSSbMFkkmgQSR8+pDRYnuPgosZUQc/x2"\r\n
Server: UI Kamailio\r\n
Content-Length: 0\r\n
\r\n
[SIP-Connection] 2017/05/23 22:22:28,254 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: User Agent (SIP line 1UND1934XXXX) proceeds with message
[Callmanager] 2017/05/23 22:22:28,254 [SIP-Provider] : cSipProviderLine::UnauthorizedHndl 1
[Callmanager] 2017/05/23 22:22:28,254 [SIP-Provider] : cSipProviderLine::UnauthorizedHndl 2 set true
[SIP-Packet] 2017/05/23 22:22:28,255 [Packet]:
Sending datagram (669 Bytes) from [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461 to [2001:8d8:104:100:212:227:124:130]:5060 using UDP (RtgTag 0):
REGISTER sip:1und1.de SIP/2.0\r\n
Via: SIP/2.0/UDP [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;branch=z9hG4bK-2d908f82-70c791eb;rport\r\n
From: <sip:497951934XXXX@1und1.de>;tag=-1670203080--1235947966\r\n
To: <sip:497951934XXXX@1und1.de>\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 814 REGISTER\r\n
Allow: REGISTER, INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, OPTIONS, PRACK, UPDATE, SUBSCRIBE\r\n
Max-Forwards: 70\r\n
Contact: *\r\n
Expires: 0\r\n
User-Agent: Lancom\r\n
Authorization: Digest username="497951934XXXX", realm="1und1.de", algorithm=MD5, uri="sip:1und1.de", nonce="WSSbMFkkmgQSR8+pDRYnuPgosZUQc/x2", response="8a8e1db80bb27085d6e7ef01c3ef424a"\r\n
Content-Length: 0\r\n
\r\n
[Callmanager] 2017/05/23 22:22:28,255 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a3161c
[SIP-Connection] 2017/05/23 22:22:28,285 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Strict Mode: Provider uses expected endpoint
[SIP-Connection] 2017/05/23 22:22:28,285 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Processing new inbound SIP message
[SIP-Packet] 2017/05/23 22:22:28,285 [Packet]:
Receiving datagram (425 Bytes) at [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461 from [2001:8d8:104:100:212:227:124:130]:5060 using UDP (RtgTag 0):
SIP/2.0 200 OK\r\n
Via: SIP/2.0/UDP [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;received=2003:73:4F7F:B473:A0:57FF:FE1F:22DD;branch=z9hG4bK-2d908f82-70c791eb;rport=65461\r\n
From: <sip:497951934XXXX@1und1.de>;tag=-1670203080--1235947966\r\n
To: <sip:497951934XXXX@1und1.de>;tag=b27e1a1d33761e85846fc98f5f3a7e58.0b3a\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 814 REGISTER\r\n
Server: UI Kamailio\r\n
Content-Length: 0\r\n
\r\n
[SIP-Connection] 2017/05/23 22:22:28,286 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: User Agent (SIP line 1UND1934XXXX) proceeds with message
[Callmanager] 2017/05/23 22:22:28,286 [SIP-Provider] : SIP WAN line OkHndl(): sequence valid:yes, message method:6
[Callmanager] 2017/05/23 22:22:28,286 [SIP-Provider] : -----[ 200 REGISTER OK HANDLE, call 0539a020, message's sequence 814, call's sequence 814
[Callmanager] 2017/05/23 22:22:28,286 [SIP-Provider] : RegisterOkHndl: Unregister -> restartShortRegisterTimer
[Callmanager] 2017/05/23 22:22:28,286 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:2, this:06c81bc0, Caller:01a32688
[Callmanager] 2017/05/23 22:22:28,287 [CALL-INFO] : ~cCmCallInfo 0 -> Caller:022c7db8, Cln.Number:497951934XXXX, Cld.Number:497951934XXXX
[Callmanager] 2017/05/23 22:22:28,287 [CALL-INFO] : ~cCmCallInfo 0.1 -> Caller:022c7db8
[Callmanager] 2017/05/23 22:22:28,287 [CALL-INFO] : ~cCmCallInfo 2 -> Caller:022c7db8
[Callmanager] 2017/05/23 22:22:28,287 [VCM] : cCmCall::ClearCall
[Callmanager] 2017/05/23 22:22:28,287 [VCM] : cCmCall::~cCmCall Cln.Number:, Cld.Number:
[SIP-Connection] 2017/05/23 22:22:28,287 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Discarding (local socket was [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461, Tag 0)
[Callmanager] 2017/05/23 22:22:30,286 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: isNotAvailable:no, TimerExpired:yes, this:06c81bc0
[Callmanager] 2017/05/23 22:22:30,286 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: eNaRegister
[Callmanager] 2017/05/23 22:22:30,286 [SIP-Provider] : 1UND1934XXXX: Register: CallId:497951934XXXX-1und1.de-3b422a20@00a0571f22dd
[Callmanager] 2017/05/23 22:22:30,286 [SIP-CALL] : cSipCall constructor (type 2) --- call=0539a020, MediaStub=0539a4e8, SIP call-id=3570597092@00a0571f22dd
[Callmanager] 2017/05/23 22:22:30,286 [SIP-Provider] : 1UND1934XXXX: Register: created SIP call
[Callmanager] 2017/05/23 22:22:30,286 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:StartupFail, database has calls
[Callmanager] 2017/05/23 22:22:30,286 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a31cec
[Callmanager] 2017/05/23 22:22:35,286 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: isNotAvailable:no, TimerExpired:yes, this:06c81bc0
[Callmanager] 2017/05/23 22:22:35,286 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: eNaRegister
[Callmanager] 2017/05/23 22:22:35,286 [SIP-Provider] : 1UND1934XXXX: Register: CallId:497951934XXXX-1und1.de-3b422a20@00a0571f22dd
[Callmanager] 2017/05/23 22:22:35,286 [SIP-Provider] : 1UND1934XXXX: Register: repeating REGISTER message
[Callmanager] 2017/05/23 22:22:35,286 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:StartupFail, database has calls
[Callmanager] 2017/05/23 22:22:35,286 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a31cec
[Callmanager] 2017/05/23 22:22:40,286 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: isNotAvailable:no, TimerExpired:yes, this:06c81bc0
[Callmanager] 2017/05/23 22:22:40,286 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: no answer from registrar, assuming timeout
[Callmanager] 2017/05/23 22:22:40,286 [SIP-Provider] : 1UND1934XXXX: registrar transport failed
[Callmanager] 2017/05/23 22:22:40,287 [SIP-Provider] : 1UND1934XXXX: stopRegistration: this:06c81bc0, caller:01a1eb3c, registration:enabled, register_info:active
[Callmanager] 2017/05/23 22:22:40,287 [1UND1934XXXX Registrar Transport]: (Re)Starting with domain name "sip.1und1.de"
[VCM-DNS] 2017/05/23 22:22:40,287 [SIP DNS Cache]: Searching 4. most preferred IP address for key <_sip._udp.sip.1und1.de, Tag 0>
[VCM-DNS] 2017/05/23 22:22:40,287 [SIP DNS Cache]: Found IP address 212.227.124.130 for DNS name "1und1-1.sip.1und1.de", which is target for SRV record "_sip._udp.sip.1und1.de" with priority 0 and weight 0
[Callmanager] 2017/05/23 22:22:40,287 [1UND1934XXXX Registrar Transport]: Got valid IP address from DNS cache
[Callmanager] 2017/05/23 22:22:40,287 [1UND1934XXXX Registrar Transport]: New transport endpoint is 212.227.124.130:5060, transport state is "FixedIpBootstrapping"
[SIP-Connection] 2017/05/23 22:22:40,287 [SIP UDP Transport (212.227.124.130:5060)]: Starting IPv4 UDP listener on port 65461 failed
[Callmanager] 2017/05/23 22:22:40,287 [SIP-Provider] : 1UND1934XXXX: registrar transport failed
[Callmanager] 2017/05/23 22:22:40,287 [SIP-Provider] : 1UND1934XXXX: stopRegistration: this:06c81bc0, caller:01a1eb3c, registration:enabled, register_info:NOT active
[Callmanager] 2017/05/23 22:22:40,287 [1UND1934XXXX Registrar Transport]: (Re)Starting with domain name "sip.1und1.de"
[VCM-DNS] 2017/05/23 22:22:40,287 [SIP DNS Cache]: Searching 5. most preferred IP address for key <_sip._udp.sip.1und1.de, Tag 0>
[VCM-DNS] 2017/05/23 22:22:40,288 [SIP DNS Cache]: Iterated all IP addresses for <_sip._udp.sip.1und1.de, Tag 0>
[Callmanager] 2017/05/23 22:22:40,288 [1UND1934XXXX Registrar Transport]: No (more) addresses to iterate -> Restarting
[Callmanager] 2017/05/23 22:22:40,288 [1UND1934XXXX Registrar Transport]: New restart backoff is 12 seconds
[Callmanager] 2017/05/23 22:22:40,288 [1UND1934XXXX Registrar Transport]: Restarting in 12 seconds
[Callmanager] 2017/05/23 22:22:40,288 [1UND1934XXXX Registrar Transport]: Could not connect the transport
[Callmanager] 2017/05/23 22:22:40,288 [1UND1934XXXX Registrar Transport]: WAN connection "1UND1WAN" for line "1UND1934XXXX" is up
[Callmanager] 2017/05/23 22:22:52,288 [1UND1934XXXX Registrar Transport]: (Re)Starting with domain name "sip.1und1.de"
[VCM-DNS] 2017/05/23 22:22:52,288 [SIP DNS Cache]: Searching 1. most preferred IP address for key <_sip._udp.sip.1und1.de, Tag 0>
[VCM-DNS] 2017/05/23 22:22:52,288 [SIP DNS Cache]: Found IP address 2001:8d8:104:100:212:227:124:130 for DNS name "1und1-1.sip.1und1.de", which is target for SRV record "_sip._udp.sip.1und1.de" with priority 0 and weight 0
[Callmanager] 2017/05/23 22:22:52,288 [1UND1934XXXX Registrar Transport]: Got valid IP address from DNS cache
[Callmanager] 2017/05/23 22:22:52,288 [1UND1934XXXX Registrar Transport]: New transport endpoint is [2001:8d8:104:100:212:227:124:130]:5060, transport state is "FixedIpBootstrapping"
[SIP-Connection] 2017/05/23 22:22:52,288 [SIP UDP Transport (212.227.124.130:5060)]: Discarding (local socket was 80.143.203.65:0, Tag 0)
[SIP-Connection] 2017/05/23 22:22:52,288 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Started IPv6 UDP listener on port 65461
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: registrar transport is ready
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: startRegistration: this:06c81bc0, caller:01a2340c, registration:enabled, register_info:NOT active
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: isNotAvailable:no, TimerExpired:no, this:06c81bc0
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: RegisterTimeout: eNaUnregister
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: Unregister: CallId:497951934XXXX-1und1.de-3b422a20@00a0571f22dd
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a31d6c
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:Ready, database has calls
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : -----[ GENERATE REGISTER, call-id=5957
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : m_RegisterContactUri:<sip:497951934XXXX@2003:73:4f7f:b473:a0:57ff:fe1f:22dd:65461>
[Callmanager] 2017/05/23 22:22:52,288 [SIP-Provider] : m_RegisterContactUri:<sip:497951934XXXX@80.143.203.65:65461>
[SIP-Packet] 2017/05/23 22:22:52,289 [Packet]:
Sending datagram (697 Bytes) from 80.143.203.65:65461 to 212.227.124.129:5060 using UDP (RtgTag 0):
REGISTER sip:1und1.de SIP/2.0\r\n
Via: SIP/2.0/UDP 80.143.203.65:65461;branch=z9hG4bK-ff8472ce-71cc65c4;rport\r\n
From: <sip:497951934XXXX@1und1.de>;tag=1164034081-1449025921\r\n
To: <sip:497951934XXXX@1und1.de>\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 815 REGISTER\r\n
Allow: REGISTER, INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, OPTIONS, PRACK, UPDATE, SUBSCRIBE\r\n
Max-Forwards: 70\r\n
Contact: <sip:497951934XXXX@80.143.203.65:65461;transport=UDP>\r\n
Expires: 480\r\n
User-Agent: Lancom\r\n
Authorization: Digest username="497951934XXXX", realm="1und1.de", algorithm=MD5, uri="sip:1und1.de", nonce="WSSbMFkkmgQSR8+pDRYnuPgosZUQc/x2", response="8a8e1db80bb27085d6e7ef01c3ef424a"\r\n
Content-Length: 0\r\n
\r\n
[Callmanager] 2017/05/23 22:22:52,289 [1UND1934XXXX Registrar Transport]: WAN connection "1UND1WAN" for line "1UND1934XXXX" is up
[SIP-Connection] 2017/05/23 22:22:52,321 [SIP UDP Transport (212.227.124.129:5060)]: Strict Mode: Provider uses expected endpoint
[SIP-Connection] 2017/05/23 22:22:52,321 [SIP UDP Transport (212.227.124.129:5060)]: Processing new inbound SIP message
[SIP-Packet] 2017/05/23 22:22:52,321 [Packet]:
Receiving datagram (472 Bytes) at 80.143.203.65:65461 from 212.227.124.129:5060 using UDP (RtgTag 0):
SIP/2.0 401 Unauthorized\r\n
Via: SIP/2.0/UDP 80.143.203.65:65461;received=80.143.203.65;branch=z9hG4bK-ff8472ce-71cc65c4;rport=65461\r\n
From: <sip:497951934XXXX@1und1.de>;tag=1164034081-1449025921\r\n
To: <sip:497951934XXXX@1und1.de>;tag=b27e1a1d33761e85846fc98f5f3a7e58.e2cb\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 815 REGISTER\r\n
WWW-Authenticate: Digest realm="1und1.de", nonce="WSSbSFkkmhwrWxyl2OaMbRMawHePW96D"\r\n
Server: UI Kamailio\r\n
Content-Length: 0\r\n
\r\n
[SIP-Connection] 2017/05/23 22:22:52,321 [SIP UDP Transport (212.227.124.129:5060)]: User Agent (SIP line 1UND1934XXXX) proceeds with message
[Callmanager] 2017/05/23 22:22:52,321 [SIP-Provider] : cSipProviderLine::UnauthorizedHndl 1
[Callmanager] 2017/05/23 22:22:52,321 [SIP-Provider] : cSipProviderLine::UnauthorizedHndl 2 set true
[SIP-Packet] 2017/05/23 22:22:52,322 [Packet]:
Sending datagram (697 Bytes) from 80.143.203.65:65461 to 212.227.124.129:5060 using UDP (RtgTag 0):
REGISTER sip:1und1.de SIP/2.0\r\n
Via: SIP/2.0/UDP 80.143.203.65:65461;branch=z9hG4bK-72beeebb-c9a8ca6e;rport\r\n
From: <sip:497951934XXXX@1und1.de>;tag=1164034081-1449025921\r\n
To: <sip:497951934XXXX@1und1.de>\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 816 REGISTER\r\n
Allow: REGISTER, INVITE, ACK, CANCEL, BYE, REFER, NOTIFY, OPTIONS, PRACK, UPDATE, SUBSCRIBE\r\n
Max-Forwards: 70\r\n
Contact: <sip:497951934XXXX@80.143.203.65:65461;transport=UDP>\r\n
Expires: 480\r\n
User-Agent: Lancom\r\n
Authorization: Digest username="497951934XXXX", realm="1und1.de", algorithm=MD5, uri="sip:1und1.de", nonce="WSSbSFkkmhwrWxyl2OaMbRMawHePW96D", response="9e781bc4481a37ad0e3a8b61691579c5"\r\n
Content-Length: 0\r\n
\r\n
[Callmanager] 2017/05/23 22:22:52,322 [SIP-Provider] : 1UND1934XXXX: restartShortRegisterTimer -> time:5, this:06c81bc0, Caller:01a3161c
[SIP-Connection] 2017/05/23 22:22:52,355 [SIP UDP Transport (212.227.124.129:5060)]: Strict Mode: Provider uses expected endpoint
[SIP-Connection] 2017/05/23 22:22:52,355 [SIP UDP Transport (212.227.124.129:5060)]: Processing new inbound SIP message
[SIP-Packet] 2017/05/23 22:22:52,355 [Packet]:
Receiving datagram (454 Bytes) at 80.143.203.65:65461 from 212.227.124.129:5060 using UDP (RtgTag 0):
SIP/2.0 200 OK\r\n
Via: SIP/2.0/UDP 80.143.203.65:65461;received=80.143.203.65;branch=z9hG4bK-72beeebb-c9a8ca6e;rport=65461\r\n
From: <sip:497951934XXXX@1und1.de>;tag=1164034081-1449025921\r\n
To: <sip:497951934XXXX@1und1.de>;tag=b27e1a1d33761e85846fc98f5f3a7e58.af68\r\n
Call-ID: 497951934XXXX-1und1.de-3b422a20@00a0571f22dd\r\n
CSeq: 816 REGISTER\r\n
Contact: <sip:497951934XXXX@80.143.203.65:65461;transport=UDP>;expires=7200\r\n
Server: UI Kamailio\r\n
Content-Length: 0\r\n
\r\n
[SIP-Connection] 2017/05/23 22:22:52,356 [SIP UDP Transport (212.227.124.129:5060)]: User Agent (SIP line 1UND1934XXXX) proceeds with message
[Callmanager] 2017/05/23 22:22:52,356 [SIP-Provider] : SIP WAN line OkHndl(): sequence valid:yes, message method:6
[Callmanager] 2017/05/23 22:22:52,356 [SIP-Provider] : -----[ 200 REGISTER OK HANDLE, call 0539a020, message's sequence 816, call's sequence 816
[Callmanager] 2017/05/23 22:22:52,356 [SIP-Provider] : RegisterOkHndl: found contact with expires value: Contact.Expires:7200, ResponseUri:<sip:497951934XXXX@80.143.203.65:65461;transport=UDP>, RegisterUri:<sip:497951934XXXX@80.143.203.65:65461>
[Callmanager] 2017/05/23 22:22:52,356 [SIP-Provider] : RegisterOkHndl: new expires: 7200
[Callmanager] 2017/05/23 22:22:52,356 [SIP-Provider] : Line '1UND1934XXXX' changed status to 'operable'
[Callmanager] 2017/05/23 22:22:52,357 [SIP-Provider] : 1UND1934XXXX: starting OPTIONS polling timer
[Callmanager] 2017/05/23 22:22:52,357 [SIP-Provider] : 1UND1934XXXX: restartRegisterTimer -> MinExpiresTime:0, time:7200, this:06c81bc0, Caller:01a323dc
[Callmanager] 2017/05/23 22:22:52,357 [CALL-INFO] : ~cCmCallInfo 0 -> Caller:022c7db8, Cln.Number:497951934XXXX, Cld.Number:497951934XXXX
[Callmanager] 2017/05/23 22:22:52,357 [CALL-INFO] : ~cCmCallInfo 0.1 -> Caller:022c7db8
[Callmanager] 2017/05/23 22:22:52,357 [CALL-INFO] : ~cCmCallInfo 2 -> Caller:022c7db8
[Callmanager] 2017/05/23 22:22:52,357 [VCM] : cCmCall::ClearCall
[Callmanager] 2017/05/23 22:22:52,357 [VCM] : cCmCall::~cCmCall Cln.Number:, Cld.Number:
[SIP-Connection] 2017/05/23 22:22:52,357 [SIP UDP Transport (212.227.124.129:5060)]: Discarding (local socket was 80.143.203.65:65461, Tag 0)
[Callmanager] 2017/05/23 22:22:54,357 [SIP-Provider] : 1UND1934XXXX: OPTIONS polling timeout: missing poll responses: 0, new OPTIONS polling timeout: 30 seconds
[Callmanager] 2017/05/23 22:22:54,357 [SIP-CALL] : cSipCall constructor (type 2) --- call=06d09260, MediaStub=06d09728, SIP call-id=892649273@00a0571f22dd
[Callmanager] 2017/05/23 22:22:54,357 [SIP-Provider] : 1UND1934XXXX: processing pending messages -> registrar transport state:Ready, database has calls
[Callmanager] 2017/05/23 22:22:54,357 [SIP-Provider] : -----[ GENERATE OPTIONS, call-id=5958
[SIP-Packet] 2017/05/23 22:22:54,357 [Packet]:
Sending datagram (465 Bytes) from [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461 to [2001:8d8:104:100:212:227:124:130]:5060 using UDP (RtgTag 0):
OPTIONS sip:[2001:8d8:104:100:212:227:124:130] SIP/2.0\r\n
Via: SIP/2.0/UDP [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;branch=z9hG4bK-656c641d-22aeb427;rport\r\n
From: <sip:[2001:8d8:104:100:212:227:124:130]>;tag=-2111750896-974576143\r\n
To: <sip:[2001:8d8:104:100:212:227:124:130]>\r\n
Call-ID: 892649273@00a0571f22dd\r\n
CSeq: 1 OPTIONS\r\n
Max-Forwards: 70\r\n
Accept: application/sdp\r\n
Contact: <sip:[2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;transport=UDP>\r\n
Content-Length: 0\r\n
\r\n
[SIP-Connection] 2017/05/23 22:22:54,386 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Strict Mode: Provider uses expected endpoint
[SIP-Connection] 2017/05/23 22:22:54,386 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: Processing new inbound SIP message
[SIP-Packet] 2017/05/23 22:22:54,386 [Packet]:
Receiving datagram (422 Bytes) at [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461 from [2001:8d8:104:100:212:227:124:130]:5060 using UDP (RtgTag 0):
SIP/2.0 200 OK\r\n
Via: SIP/2.0/UDP [2003:73:4f7f:b473:a0:57ff:fe1f:22dd]:65461;branch=z9hG4bK-656c641d-22aeb427;rport=65461;received=2003:73:4F7F:B473:A0:57FF:FE1F:22DD\r\n
From: <sip:[2001:8d8:104:100:212:227:124:130]>;tag=-2111750896-974576143\r\n
To: <sip:[2001:8d8:104:100:212:227:124:130]>;tag=b27e1a1d33761e85846fc98f5f3a7e58.8c1f\r\n
Call-ID: 892649273@00a0571f22dd\r\n
CSeq: 1 OPTIONS\r\n
Server: UI Kamailio\r\n
Content-Length: 0\r\n
\r\n
[SIP-Connection] 2017/05/23 22:22:54,386 [SIP UDP Transport ([2001:8d8:104:100:212:227:124:130]:5060)]: User Agent (SIP line 1UND1934XXXX) proceeds with message
[Callmanager] 2017/05/23 22:22:54,386 [SIP-Provider] : 1UND1934XXXX: Received a SIP response, resetting OPTIONS polling. New timeout: 300 seconds
[Callmanager] 2017/05/23 22:22:54,386 [SIP-Provider] : SIP WAN line OkHndl(): sequence valid:yes, message method:3
[Callmanager] 2017/05/23 22:22:54,387 [CALL-INFO] : ~cCmCallInfo 0 -> Caller:022c7db8, Cln.Number:, Cld.Number:
[Callmanager] 2017/05/23 22:22:54,387 [CALL-INFO] : ~cCmCallInfo 0.1 -> Caller:022c7db8
[Callmanager] 2017/05/23 22:22:54,387 [CALL-INFO] : ~cCmCallInfo 2 -> Caller:022c7db8
[Callmanager] 2017/05/23 22:22:54,387 [VCM] : cCmCall::ClearCall
[Callmanager] 2017/05/23 22:22:54,387 [VCM] : cCmCall::~cCmCall Cln.Number:, Cld.Number:
