[Problem] D712 hinter NAT Ton nach 60 Sekunden

[Matthias78]

Hallo zusammen,
ich verzweifle gerade an einem SNOM D712 das in einem Home-Office steht.

Konstellation:
D712 - > Fritzbox 7530 an dynamischer IP -> Fritzbox 3490 (im Routerbetrieb) an Telekom Business mit fester IP -> Draytek Vigor 2960 -> Kerio OPERATOR

Rahmenbedingungen:
Firmware an D712 ist aktuell, der Kerio tut grundsätzlich was er soll.
Test von meinem Internetanschluss an einem D385 mit gleichen Zugangsdaten lief problemlos.
Freigegeben habe ich mittlerweile (TCP und UDP) 5060 / 5061 sowie 3478 / 3479 (STUN)
Telefon wurde zurückgesetzt und manuell mit den Zugangsdaten befüllt.

Fehlerbild:
Die Signalisierung am Telefon funktioniert tadellos, ausgehende Rufe werden auch initiiert. Allerdings hört man nichts - für ziemlich genau 62 Sekunden. Nach diesen 62 Sekunden geht die Sprache, völlig ohne Verzögerung, Echo oder andere Probleme. Das Gespräch wird nicht getrennt. Diese Zeitspanne ist absolut und jederzeit reproduzierbar. 62 Sekunden stille, dann alles normal.
Leider ist das Gerät extrem weit weg, ich habe also definitiv keinen direkten Zugriff. Morgen früh kann ich aber wieder aus der Ferne auf das Gerät schauen.

Hat irgendjemand eine Idee was das sein kann? Ich würde ins blaue auf irgendeinen Timeout tippen, wüsste aber nicht an welche Stelle ich ansetzen sollte...

Beigefügt ist die Logdatei vom Snom, zurückgesetzt direkt vor einem Anruf.

Bin über jeden Ansatz dankbar

Gruß
Matze

Log-Level
7 DEBUG0

Jan 18 19:42:44.042 [INFO ] PHN: WEB: Request 346/961/0: POST /log.htm HTTP/1.1
Jan 18 19:42:44.254 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=4, force_redraw=0
Jan 18 19:42:44.254 [NOTICE] PHN: Fetching URL: phone://mb_exit
Jan 18 19:42:44.256 [INFO ] PHN: Deleting channel -7, identity 1, state closed, total connection count 1
Jan 18 19:42:44.258 [INFO ] GUI: GUI: Allocating channel 13, line 1
Jan 18 19:42:44.262 [NOTICE] CSTA: csta_cid = 13 phone_cid13
Jan 18 19:42:44.263 [DEBUG0] MEDIA: MediaIpc::rtpSetup: rtp: RP19 rtcp: RC19 start: 49152 end: 65534
Jan 18 19:42:44.266 [INFO ] SIP: rtp_port::send_ice_rtp_packet(), rtp=true
Jan 18 19:42:44.266 [DEBUG0] MEDIA: MediaIpc::sendUdpPdu: name: RP19 remote: 80.???.???.???:3478 len: 28
Jan 18 19:42:44.267 [INFO ] SIP: rtp_port::send_ice_rtp_packet(), rtp=false
Jan 18 19:42:44.268 [DEBUG0] MEDIA: MediaIpc::sendUdpPdu: name: RC19 remote: 80.???.???.???:3478 len: 28
Jan 18 19:42:44.268 [INFO ] SIP: Dialog 13/19/1 going to trying
Jan 18 19:42:44.269 [INFO ] GUI: GUI: Line-Seize subscription was not sent
Jan 18 19:42:44.284 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=1, force_redraw=0
Jan 18 19:42:44.284 [DEBUG0] PHN: MbParser:: enter
Jan 18 19:42:44.284 [DEBUG0] PHN: MbParser:: selected_tree = /IPPhoneBatch/
Jan 18 19:42:44.292 [INFO ] PHN: Xpath applies: /IPPhoneBatch/
Jan 18 19:42:44.292 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:44.292 [INFO ] PHN: Xpath applies: /SnomIPPhoneBatch/
Jan 18 19:42:44.292 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:44.292 [DEBUG0] PHN: MbParser:: found tree = IPPhoneBatch
Jan 18 19:42:44.292 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneBatch
Jan 18 19:42:44.292 [DEBUG0] PHN: MbParserMainTag:: searching in subs
Jan 18 19:42:44.293 [DEBUG0] PHN: MbParserMainTag:: faoun tree = IPPhoneMenu
Jan 18 19:42:44.293 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneMenu
Jan 18 19:42:44.297 [WARN ] GUI: Minibrowser callback $/enter_number_fkey_list expecting vector result, but no vector callback defined
Jan 18 19:42:44.305 [INFO ] PHN: Xpath applies: /*
Jan 18 19:42:44.305 [DEBUG0] PHN: Xpath succesfully fetched: /*
Jan 18 19:42:44.305 [DEBUG0] PHN: Xpath succesfully fetched:
Jan 18 19:42:44.321 [INFO ] GUI: SetAudioPlaystate: 2
Jan 18 19:42:44.321 [DEBUG0] MEDIA: MediaIpc::SetupAudioDevice: audio_mode_handsfree 8 - audio_mode_none 5 0 - audio_playstate_synth
Jan 18 19:42:44.328 [DEBUG0] MEDIA: Synthesizer Command: PLAY 0 15 425
Jan 18 19:42:44.331 [DEBUG0] MEDIA: Socket 0x27c7c8/noname: state connected(5)
Jan 18 19:42:44.331 [DEBUG0] MEDIA: Socket 0x27cab8/noname: state connected(5)
Jan 18 19:42:44.332 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:44.332 [INFO ] MEDIA: 3522179 onSetupAudioDevice: 6 8 - 5 0 - 2
Jan 18 19:42:44.332 [INFO ] MEDIA: CAudioSubsystem::setAudioMode 0->6
Jan 18 19:42:44.337 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=1, force_redraw=0
Jan 18 19:42:44.433 [INFO ] MEDIA: playstate 0->2
Jan 18 19:42:44.434 [INFO ] MEDIA: setSynthProgram
Jan 18 19:42:44.436 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:44.450 [INFO ] PHN: WEB: Request 346/961/0: POST /log.htm HTTP/1.1
Jan 18 19:42:44.528 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=1, force_redraw=1
Jan 18 19:42:44.528 [DEBUG0] PHN: MbParser:: enter
Jan 18 19:42:44.528 [DEBUG0] PHN: MbParser:: selected_tree = /IPPhoneBatch/
Jan 18 19:42:44.539 [INFO ] PHN: Xpath applies: /IPPhoneBatch/
Jan 18 19:42:44.539 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:44.539 [INFO ] PHN: Xpath applies: /SnomIPPhoneBatch/
Jan 18 19:42:44.540 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:44.540 [DEBUG0] PHN: MbParser:: found tree = IPPhoneBatch
Jan 18 19:42:44.540 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneBatch
Jan 18 19:42:44.541 [DEBUG0] PHN: MbParserMainTag:: searching in subs
Jan 18 19:42:44.541 [DEBUG0] PHN: MbParserMainTag:: faoun tree = IPPhoneMenu
Jan 18 19:42:44.541 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneMenu
Jan 18 19:42:44.546 [WARN ] GUI: Minibrowser callback $/enter_number_fkey_list expecting vector result, but no vector callback defined
Jan 18 19:42:44.553 [INFO ] PHN: Xpath applies: /*
Jan 18 19:42:44.553 [DEBUG0] PHN: Xpath succesfully fetched: /*
Jan 18 19:42:44.555 [DEBUG0] PHN: Xpath succesfully fetched:
Jan 18 19:42:45.052 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:45.917 [INFO ] PHN: Hook switch pressed in state Edit_number (5)
Jan 18 19:42:45.921 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=2, force_redraw=1
Jan 18 19:42:45.921 [DEBUG0] PHN: MbParser:: enter
Jan 18 19:42:45.921 [DEBUG0] PHN: MbParser:: selected_tree = /IPPhoneBatch/
Jan 18 19:42:45.937 [INFO ] PHN: Xpath applies: /IPPhoneBatch/
Jan 18 19:42:45.937 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:45.937 [INFO ] PHN: Xpath applies: /SnomIPPhoneBatch/
Jan 18 19:42:45.937 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:45.937 [DEBUG0] PHN: MbParser:: found tree = IPPhoneBatch
Jan 18 19:42:45.938 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneBatch
Jan 18 19:42:45.938 [DEBUG0] PHN: MbParserMainTag:: searching in subs
Jan 18 19:42:45.938 [DEBUG0] PHN: MbParserMainTag:: faoun tree = IPPhoneMenu
Jan 18 19:42:45.938 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneMenu
Jan 18 19:42:45.945 [WARN ] GUI: Minibrowser callback $/enter_number_fkey_list expecting vector result, but no vector callback defined
Jan 18 19:42:45.952 [INFO ] PHN: Xpath applies: /*
Jan 18 19:42:45.952 [DEBUG0] PHN: Xpath succesfully fetched: /*
Jan 18 19:42:45.952 [DEBUG0] PHN: Xpath succesfully fetched:
Jan 18 19:42:47.473 [NOTICE] PHN: TPL: Socket 346 idle/connect timeout
Jan 18 19:42:47.773 [NOTICE] PHN: TPL: Socket 347 idle/connect timeout
Jan 18 19:42:47.976 [DEBUG0] SIP: SRTP disabled
Jan 18 19:42:47.977 [NOTICE] SIP: RTP: set_destination adr=80.???.???.???:14926
Jan 18 19:42:47.979 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000313
Jan 18 19:42:47.980 [DEBUG0] SIP: send 100 INVITE (102: 5c8b115c70d181872347a1c82e37c06a@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:42:47.991 [INFO ] GUI: find_function_key_for_uri: Looking to match <sip:[email protected]:49542;line=8ay7qtvy>
Jan 18 19:42:47.991 [INFO ] GUI: GUI: Allocating channel -8, line 1
Jan 18 19:42:47.997 [NOTICE] CSTA: csta_cid = 13 phone_cid13 csta_cid = -8 phone_cid-8
Jan 18 19:42:47.997 [INFO ] GUI: GUI: Line-Seize subscription was not sent
Jan 18 19:42:48.002 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000314
Jan 18 19:42:48.002 [DEBUG0] SIP: send 180 INVITE (102: 5c8b115c70d181872347a1c82e37c06a@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:42:48.006 [INFO ] SIP: Dialog -8/20/1 going to early
Jan 18 19:42:48.007 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=2, force_redraw=1
Jan 18 19:42:48.007 [DEBUG0] PHN: MbParser:: enter
Jan 18 19:42:48.007 [DEBUG0] PHN: MbParser:: selected_tree = /IPPhoneBatch/
Jan 18 19:42:48.018 [INFO ] PHN: Xpath applies: /IPPhoneBatch/
Jan 18 19:42:48.018 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:48.018 [INFO ] PHN: Xpath applies: /SnomIPPhoneBatch/
Jan 18 19:42:48.018 [INFO ] PHN: Xpath contains unrecognized steps, aborting
Jan 18 19:42:48.018 [DEBUG0] PHN: MbParser:: found tree = IPPhoneBatch
Jan 18 19:42:48.018 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneBatch
Jan 18 19:42:48.018 [DEBUG0] PHN: MbParserMainTag:: searching in subs
Jan 18 19:42:48.020 [DEBUG0] PHN: MbParserMainTag:: faoun tree = IPPhoneMenu
Jan 18 19:42:48.020 [DEBUG0] PHN: MbParserMainTag:: tree = IPPhoneMenu
Jan 18 19:42:48.021 [DEBUG0] PHN: Request lookup for number sip:+494625?????@80.???.???.???
Jan 18 19:42:48.027 [WARN ] GUI: Minibrowser callback $/enter_number_fkey_list expecting vector result, but no vector callback defined
Jan 18 19:42:48.038 [INFO ] PHN: Xpath applies: /*
Jan 18 19:42:48.038 [DEBUG0] PHN: Xpath succesfully fetched: /*
Jan 18 19:42:48.038 [DEBUG0] PHN: Xpath succesfully fetched:
Jan 18 19:42:48.072 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=2, force_redraw=1
Jan 18 19:42:48.073 [DEBUG0] MEDIA: MediaIpc::rtpSetup: rtp: RP20 rtcp: RC20 start: 49152 end: 65534
Jan 18 19:42:48.077 [INFO ] SIP: rtp_port::send_ice_rtp_packet(), rtp=true
Jan 18 19:42:48.077 [DEBUG0] MEDIA: MediaIpc::sendUdpPdu: name: RP20 remote: 80.???.???.???:3478 len: 28
Jan 18 19:42:48.079 [INFO ] SIP: rtp_port::send_ice_rtp_packet(), rtp=false
Jan 18 19:42:48.080 [DEBUG0] MEDIA: MediaIpc::sendUdpPdu: name: RC20 remote: 80.???.???.???:3478 len: 28
Jan 18 19:42:48.083 [INFO ] GUI: SetAudioPlaystate: 2
Jan 18 19:42:48.083 [DEBUG0] MEDIA: MediaIpc::SetupAudioDevice: audio_mode_ringer 1 - audio_mode_none 5 0 - audio_playstate_synth
Jan 18 19:42:48.085 [DEBUG0] MEDIA: MediaIpc::setRingMelody
Jan 18 19:42:48.085 [DEBUG0] MEDIA: MediaIpc::remRingMelody RINGER
Jan 18 19:42:48.090 [DEBUG0] MEDIA: Synthesizer Command: FILE RINGER PLAY 1000 0 0 LOOP 2 0 0
Jan 18 19:42:48.098 [INFO ] PHN: entering gui_object::display_on_minibrowser() state=1, force_redraw=0
Jan 18 19:42:48.100 [DEBUG0] MEDIA: Socket 0x2865f0/noname: state connected(5)
Jan 18 19:42:48.101 [DEBUG0] MEDIA: Socket 0x2868e0/noname: state connected(5)
Jan 18 19:42:48.101 [INFO ] MEDIA: 3525944 onSetupAudioDevice: 8 1 - 5 0 - 2
Jan 18 19:42:48.129 [INFO ] MEDIA: CAudioSubsystem::setAudioMode 6->8
Jan 18 19:42:48.161 [DEBUG0] MEDIA: MediaIpc::setSpeakerDefault: 6 1
Jan 18 19:42:48.162 [DEBUG0] MEDIA: MediaIpc::SetupAudioDevice: audio_mode_handsfree 8 - audio_mode_none 5 0 - audio_playstate_synth
Jan 18 19:42:48.163 [INFO ] PHN: Deleting channel 13, identity 1, state offhook, total connection count 2
Jan 18 19:42:48.163 [DEBUG0] GUI: Line 13: EndCall (6)
Jan 18 19:42:48.165 [INFO ] SIP: Dialog 13/19/0 going to terminated
Jan 18 19:42:48.169 [DEBUG0] SIP: connection 13 terminated
Jan 18 19:42:48.169 [INFO ] SIP: RTP: set_audible(0/0 -> 0/0): RP19 changed=0, update_req=0, adr=
Jan 18 19:42:48.170 [DEBUG0] MEDIA: MediaIpc::closeStream: 8e24bee2
Jan 18 19:42:48.170 [INFO ] SIP: rtp_port::release_turn_resources(), rtp relay port=0, rtcp relay port=0
Jan 18 19:42:48.170 [INFO ] SIP: RTP: set_audible(0/0 -> 0/0): RP19 changed=0, update_req=0, adr=
Jan 18 19:42:48.170 [NOTICE] MEDIA: MediaIpc::rtpClose: RP19
Jan 18 19:42:48.170 [NOTICE] MEDIA: MediaIpc::rtpClose: RC19
Jan 18 19:42:48.276 [DEBUG0] PHN: Request lookup for number sip:+494625?????@80.???.???.???
Jan 18 19:42:48.334 [INFO ] MEDIA: setSynthProgram
Jan 18 19:42:48.336 [INFO ] MEDIA: 3526179 onSetupAudioDevice: 6 8 - 5 0 - 2
Jan 18 19:42:48.336 [INFO ] MEDIA: CAudioSubsystem::setAudioMode 6->6
Jan 18 19:42:48.336 [DEBUG0] MEDIA: StreamClose: 2384772834
Jan 18 19:42:48.337 [NOTICE] MEDIA: onRtpClose: RP19
Jan 18 19:42:48.337 [DEBUG0] MEDIA: onRtpClose: name: RP19 ssrc: 0
Jan 18 19:42:48.338 [INFO ] MEDIA: NumberOfSocketsWithSsrc: ssrc: 0, sockets: 0
Jan 18 19:42:48.338 [DEBUG0] MEDIA: Socket 0x27c7c8/noname: state disconnected(7)
Jan 18 19:42:48.338 [DEBUG0] MEDIA: Socket 0x27c7c8/noname: state deleted(8)
Jan 18 19:42:48.338 [NOTICE] MEDIA: onRtpClose: RC19
Jan 18 19:42:48.338 [DEBUG0] MEDIA: onRtpClose: name: RC19 ssrc: 0
Jan 18 19:42:48.339 [INFO ] MEDIA: NumberOfSocketsWithSsrc: ssrc: 0, sockets: 0
Jan 18 19:42:48.340 [DEBUG0] MEDIA: Socket 0x27cab8/noname: state disconnected(7)
Jan 18 19:42:48.341 [DEBUG0] MEDIA: Socket 0x27cab8/noname: state deleted(8)
Jan 18 19:42:48.341 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:48.341 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:48.503 [DEBUG0] SIP: send 180 INVITE (102: 5c8b115c70d181872347a1c82e37c06a@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:42:49.273 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000315
Jan 18 19:42:49.274 [DEBUG0] SIP: send 200 OPTIONS (102: 4ecf1cbe59c4f3953c492ff1708ea8ca@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:42:49.504 [DEBUG0] SIP: send 180 INVITE (102: 5c8b115c70d181872347a1c82e37c06a@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:42:50.101 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:50.973 [DEBUG0] MEDIA: MediaIpc::setSpeakerDefault: 6 8
Jan 18 19:42:50.978 [INFO ] SIP: RTP: set_audible(0/0 -> 1/1): RP20 changed=1, update_req=1, adr=80.???.???.???:14926
Jan 18 19:42:50.978 [DEBUG0] MEDIA: MediaIpc::setStream: prot Udp ssrc 6c847806 rtp RP20 rtcp RC20 stream 0 r 1 w 1 dtmf inb 0 outb 0 outbpt 0 codec 8 length 160 ssrtp 0
Jan 18 19:42:50.979 [DEBUG0] MEDIA: MediaIpc::setStream: rtp addr: Udp:80.???.???.???:14926 :rtcp addr: Udp:[::]:0 srtp: 0 ssrtp: 0 rfc3551: 1 tos: 160 keepalive: 0
Jan 18 19:42:50.980 [DEBUG0] MEDIA: rtpmap_packet: '08081500'
Jan 18 19:42:50.981 [DEBUG0] MEDIA: MediaIpc::rtpSymmetric: RP20 0
Jan 18 19:42:50.984 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000316
Jan 18 19:42:50.985 [DEBUG0] SIP: send 200 INVITE (102: 5c8b115c70d181872347a1c82e37c06a@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:42:50.988 [INFO ] SIP: Dialog -8/20/3 going to confirmed
Jan 18 19:42:50.988 [INFO ] SIP: GuiConnected(id -8, 0, 1)
Jan 18 19:42:50.993 [DEBUG0] MEDIA: Synthesizer Command: PLAY 0 0 0
Jan 18 19:42:50.993 [INFO ] GUI: SetAudioPlaystate: 1
Jan 18 19:42:50.994 [DEBUG0] MEDIA: MediaIpc::SetupAudioDevice: audio_mode_handsfree 8 - audio_mode_none 5 0 - audio_playstate_rtp
Jan 18 19:42:51.022 [DEBUG0] MEDIA: UdpStream: 0 (1, 1) RP20 '3038303831353030' - 0 0
Jan 18 19:42:51.022 [DEBUG0] MEDIA: add ssrc 1820620806 for rtp socket RP20
Jan 18 19:42:51.022 [DEBUG0] MEDIA: Start/Change Call: 1820620806-----
Jan 18 19:42:51.023 [DEBUG0] MEDIA: Start Streaming at 0/0
Jan 18 19:42:51.023 [INFO ] MEDIA: CAudioSubsystem::StopCall: 654321
Jan 18 19:42:51.053 [INFO ] MEDIA: StopCall: active channels: 0
Jan 18 19:42:51.054 [INFO ] MEDIA: StopCall: channel 0 active: 0 ssrc: 0
Jan 18 19:42:51.054 [INFO ] MEDIA: StopCall: channel 1 active: 0 ssrc: 0
Jan 18 19:42:51.055 [NOTICE] MEDIA: PlayCall ssrc:1820620806 active: 0 use new channel
Jan 18 19:42:51.056 [INFO ] MEDIA: PlayCall: active channels: 1
Jan 18 19:42:51.056 [INFO ] MEDIA: PlayCall: channel 0 active: 1 ssrc: 1820620806
Jan 18 19:42:51.056 [INFO ] MEDIA: PlayCall: channel 1 active: 0 ssrc: 0
Jan 18 19:42:51.108 [INFO ] MEDIA: setSynthProgram
Jan 18 19:42:51.108 [INFO ] MEDIA: 3528962 onSetupAudioDevice: 6 8 - 5 0 - 1
Jan 18 19:42:51.108 [INFO ] MEDIA: playstate 2->1
Jan 18 19:42:51.109 [INFO ] MEDIA: CAudioSubsystem::setAudioMode 6->6
Jan 18 19:42:55.152 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:42:55.957 [INFO ] PHN: WEB: Request 349/956/0: POST /log.htm HTTP/1.1
Jan 18 19:42:58.993 [NOTICE] PHN: TPL: Socket 349 idle/connect timeout
Jan 18 19:43:00.202 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:00.963 [NOTICE] PHN: TPL: Socket 348 idle/connect timeout
Jan 18 19:43:04.586 [INFO ] PHN: Watchdog: keep fd dog = 5
Jan 18 19:43:04.586 [INFO ] PHN: Watchdog: pause =
Jan 18 19:43:04.587 [INFO ] PHN: Watchdog: watchdog setting =
Jan 18 19:43:05.253 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:09.339 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000317
Jan 18 19:43:09.339 [DEBUG0] SIP: send 200 OPTIONS (102: 79c89ab136d8f0254fc2a1e30c6b006f@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:43:10.303 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:14.797 [INFO ] PHN: WEB: Request 350/956/0: POST /log.htm HTTP/1.1
Jan 18 19:43:15.353 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:17.833 [NOTICE] PHN: TPL: Socket 350 idle/connect timeout
Jan 18 19:43:19.803 [NOTICE] PHN: TPL: Socket 351 idle/connect timeout
Jan 18 19:43:20.403 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:25.453 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:29.402 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000318
Jan 18 19:43:29.402 [DEBUG0] SIP: send 200 OPTIONS (102: 70f4dfe5658c9e9c2c8a8ce0130691e0@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:43:30.505 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:34.597 [INFO ] PHN: Watchdog: keep fd dog = 5
Jan 18 19:43:34.597 [INFO ] PHN: Watchdog: pause =
Jan 18 19:43:34.597 [INFO ] PHN: Watchdog: watchdog setting =
Jan 18 19:43:35.565 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:40.625 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:45.357 [INFO ] PHN: WEB: Request 353/956/0: POST /log.htm HTTP/1.1
Jan 18 19:43:45.675 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:48.393 [NOTICE] PHN: TPL: Socket 353 idle/connect timeout
Jan 18 19:43:49.466 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000319
Jan 18 19:43:49.466 [DEBUG0] SIP: send 200 OPTIONS (102: 0d5e539e7916364b572464020ca294d4@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:43:50.363 [NOTICE] PHN: TPL: Socket 352 idle/connect timeout
Jan 18 19:43:50.733 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:52.366 [DEBUG0] MEDIA: found stream without packet ssrc
Jan 18 19:43:52.366 [DEBUG0] MEDIA: set stream packet ssrc 719507357
Jan 18 19:43:52.366 [INFO ] MEDIA: HandleChangedPacketSsrc: set first ssrc 719507357
Jan 18 19:43:52.395 [DEBUG0] MEDIA: 3590249 networkToStream: ssrc 719507357 seqnr: 1626 pt 136 roc tx: 0 rx: 0
Jan 18 19:43:53.789 [INFO ] PHN: WEB: Request 354/956/0: POST /log.htm HTTP/1.1
Jan 18 19:43:55.802 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:43:56.833 [NOTICE] PHN: TPL: Socket 354 idle/connect timeout
Jan 18 19:43:58.793 [NOTICE] PHN: TPL: Socket 355 idle/connect timeout
Jan 18 19:44:00.852 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:04.606 [INFO ] PHN: Watchdog: keep fd dog = 5
Jan 18 19:44:04.606 [INFO ] PHN: Watchdog: pause =
Jan 18 19:44:04.607 [INFO ] PHN: Watchdog: watchdog setting =
Jan 18 19:44:05.902 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:09.536 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000320
Jan 18 19:44:09.537 [DEBUG0] SIP: send 200 OPTIONS (102: 11fbea275828b240793e2cd44de9695b@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:44:10.954 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:16.012 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:21.061 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:26.115 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:29.601 [DEBUG0] SIP: Use Connection Udp:80.???.???.???:5060 for packet 1000321
Jan 18 19:44:29.602 [DEBUG0] SIP: send 200 OPTIONS (102: 52d749370c812e8248da95a738e52c0f@80.???.???.???:5060) -> Udp:80.???.???.???:5060
Jan 18 19:44:31.176 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:34.617 [INFO ] PHN: Watchdog: keep fd dog = 5
Jan 18 19:44:34.617 [INFO ] PHN: Watchdog: pause =
Jan 18 19:44:34.617 [INFO ] PHN: Watchdog: watchdog setting =
Jan 18 19:44:36.240 [INFO ] PHN: Unknown message attribute type 0x8022
Jan 18 19:44:37.778 [INFO ] PHN: WEB: Request 356/956/0: POST /log.htm HTTP/1.1

 

[sonyKatze]

Die gezeigte Kette ist die Internet-Verbindung. Also kein VPN oder so, sondern das ist der Pfad den SIP/RTP gehen muss. Richtig?

1. Wer hört nichts; beide Gesprächspartner?
2. Haben beide Telefone die selbe Firmware-Version?

Man müsste wirklich vor Ort sein und auf der FRITZ!Box 7530 mitschneiden (1. Internet). Dann sieht man wohin der RTP-Strom gelenkt wird. Wenn Du wild herumspielen willst:
a) Snom → Web-Oberfläche → Identity → RTP Symmetrical → RTP: on (oder bzw. und)
b) Snom → Web-Oberfläche → Identity → NAT → Number of Initial Keep-Alives on RTP Port: 3
c) wobei ich aber auch mal ganz ohne STUN-Server probieren würde.
Und bitte die Port-Weiterleitungen löschen, denn die sind nur für SIP und nicht für RTP. Die Idee bei STUN ist auch gerade, dass die externen Ports erkannt werden. Also bitte keine Port-Weiterleitung darauf. Kannst Du lokal bei Dir erstmal testen.

​

3. Hast Du lokal bei Deinem Snom D385 auch eine FRITZ!Box oder was genau? Oder bist Du nicht Remote sondern lokal zum Draytek Vigor?​