TECH7Fox / sip-hass-card

A SIP client inside home assistant!
MIT License
179 stars 38 forks source link

linphonec SIP/2.0 488 Not acceptable here #78

Closed sascha005 closed 2 years ago

sascha005 commented 2 years ago

Hello,

Hello, I have one last problem with the connection of linphonec. I can call the extension of the sip-card with linphonec. This works perfectly. But I cannot call the extension from linphonec over the sip-card. I get the error: "SIP/2.0 488 Not acceptable here" in the linphonec log. Unfortunately I have no idea what the exact reason is. Can someone give me a hint ? Thanks in advance.

Here is the log file from the outgoing call from the sip card to linphonec:

2022-05-17 09:55:27:779 liblinphone-message-Using (r/w) config information from /root/.linphonerc 2022-05-17 09:55:27:785 liblinphone-message-Initializing LinphoneCore 4.4.21 2022-05-17 09:55:27:786 liblinphone-message-Sal nat helper [enabled] 2022-05-17 09:55:27:787 mediastreamer-message-Mediastreamer2 factory 4.4.0 (git: unknown) initialized. 2022-05-17 09:55:27:787 mediastreamer-message-CPU count set to 1 2022-05-17 09:55:27:787 mediastreamer-message-ms_factory_init() done: platform_tags=linux,arm,embedded 2022-05-17 09:55:27:787 mediastreamer-message-srtp init 2022-05-17 09:55:28:361 mediastreamer-message-Registering all soundcard handlers 2022-05-17 09:55:28:364 mediastreamer-message-New PulseAudio context state: PA_CONTEXT_CONNECTING 2022-05-17 09:55:28:365 mediastreamer-message-New PulseAudio context state: PA_CONTEXT_FAILED 2022-05-17 09:55:28:366 mediastreamer-message-Connection to the pulseaudio server failed 2022-05-17 09:55:28:419 mediastreamer-message-Card 'ALSA: default' added with capabilities [capture, playback] 2022-05-17 09:55:28:419 mediastreamer-message-ALSA: found card with name [snd_rpi_googlevoicehat_soundcar], long name [snd_rpi_googlevoicehat_soundcard]. 2022-05-17 09:55:28:427 mediastreamer-message-Card 'ALSA: snd_rpi_googlevoicehat_soundcar' added with capabilities [capture, playback] 2022-05-17 09:55:28:429 mediastreamer-message-ALSA: found card with name [vc4-hdmi], long name [vc4-hdmi]. 2022-05-17 09:55:28:439 mediastreamer-message-alsa error in pcm_hw.c:1544 - SNDRV_PCM_IOCTL_INFO failed (-25) 2022-05-17 09:55:28:445 mediastreamer-message-alsa error in pcm_hw.c:1715 - open '/dev/snd/pcmC1D0p' failed (-19) 2022-05-17 09:55:28:448 mediastreamer-message-Registering all webcam handlers 2022-05-17 09:55:28:449 mediastreamer-message-Webcam StaticImage: Static picture added 2022-05-17 09:55:28:449 mediastreamer-message-ms_factory_init_voip() done 2022-05-17 09:55:28:449 mediastreamer-message-Loading ms plugins from [/usr/lib/arm-linux-gnueabihf/mediastreamer/plugins] 2022-05-17 09:55:28:449 mediastreamer-message-Cannot open directory /usr/lib/arm-linux-gnueabihf/mediastreamer/plugins: No such file or directory 2022-05-17 09:55:28:450 liblinphone-message-Core callbacks [0x601a60] registered on core [0x603fe0] 2022-05-17 09:55:28:450 liblinphone-message-Core callbacks [0x5ffe70] registered on core [0x603fe0] 2022-05-17 09:55:28:450 ortp-message-oRTP-4.4.0 initialized. 2022-05-17 09:55:28:450 liblinphone-message-Codec opus/48000 fmtp=[useinbandfec=1] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:450 liblinphone-message-Codec SILK/16000 fmtp=[] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:450 liblinphone-message-Codec speex/16000 fmtp=[vbr=on] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:450 liblinphone-message-Codec speex/8000 fmtp=[vbr=on] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec PCMU/8000 fmtp=[] number=0, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec PCMA/8000 fmtp=[] number=8, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec red/1000 fmtp=[] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec t140/1000 fmtp=[] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec GSM/8000 fmtp=[] number=3, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec G722/8000 fmtp=[] number=9, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec iLBC/8000 fmtp=[mode=30] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:451 liblinphone-message-Codec AMR/8000 fmtp=[octet-align=1] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec AMR-WB/16000 fmtp=[octet-align=1] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec G729/8000 fmtp=[annexb=yes] number=18, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec mpeg4-generic/16000 fmtp=[config=F8EE2000; constantDuration=512; indexDeltaLength=3; indexLength=3; mode=AAC-hbr; profile-level-id=76; sizeLength=13; streamType=5] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec mpeg4-generic/22050 fmtp=[config=F8EE2000; constantDuration=512; indexDeltaLength=3; indexLength=3; mode=AAC-hbr; profile-level-id=76; sizeLength=13; streamType=5] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec mpeg4-generic/32000 fmtp=[config=F8E82000; constantDuration=512; indexDeltaLength=3; indexLength=3; mode=AAC-hbr; profile-level-id=76; sizeLength=13; streamType=5] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec mpeg4-generic/44100 fmtp=[config=F8E82000; constantDuration=512; indexDeltaLength=3; indexLength=3; mode=AAC-hbr; profile-level-id=76; sizeLength=13; streamType=5] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:452 liblinphone-message-Codec mpeg4-generic/48000 fmtp=[config=F8EE2000; constantDuration=512; indexDeltaLength=3; indexLength=3; mode=AAC-hbr; profile-level-id=76; sizeLength=13; streamType=5] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec iSAC/16000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec speex/32000 fmtp=[vbr=on] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec SILK/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec SILK/12000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec SILK/24000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec G726-16/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec G726-24/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:453 liblinphone-message-Codec G726-32/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:458 liblinphone-message-Codec G726-40/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec AAL2-G726-16/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec AAL2-G726-24/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec AAL2-G726-32/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec AAL2-G726-40/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec CODEC2/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec BV16/8000 fmtp=[] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:459 liblinphone-message-Codec VP8/90000 fmtp=[] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec H264/90000 fmtp=[profile-level-id=42801F] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec H265/90000 fmtp=[] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec MP4V-ES/90000 fmtp=[profile-level-id=3] number=-1, default enablement: 16) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec H263-1998/90000 fmtp=[CIF=1;QCIF=1] number=-1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec H263/90000 fmtp=[] number=34, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec 1016/8000 fmtp=[] number=1, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec G723/8000 fmtp=[] number=4, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:460 liblinphone-message-Codec LPC/8000 fmtp=[] number=7, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:461 liblinphone-message-Codec L16/44100 fmtp=[] number=10, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:461 liblinphone-message-Codec L16/44100 fmtp=[] number=11, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:461 liblinphone-message-Codec CN/8000 fmtp=[] number=13, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:461 liblinphone-message-Codec H261/90000 fmtp=[] number=31, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:461 liblinphone-message-Codec MPV/90000 fmtp=[] number=32, default enablement: 0) added to the list of possible codecs. 2022-05-17 09:55:28:461 belle-sip-message-Root ca path set to /etc/ssl/certs 2022-05-17 09:55:28:461 belle-sip-message-Root ca path set to /etc/ssl/certs 2022-05-17 09:55:28:499 mediastreamer-message-Loading ms plugins from [/usr/lib/arm-linux-gnueabihf/mediastreamer/plugins] 2022-05-17 09:55:28:499 mediastreamer-message-Cannot open directory /usr/lib/arm-linux-gnueabihf/mediastreamer/plugins: No such file or directory 2022-05-17 09:55:28:499 liblinphone-warning-'/usr/share/sounds/linphone/rings/oldphone.wav' ring file does not exist 2022-05-17 09:55:28:500 liblinphone-message-linphone_core_set_playback_gain_db(): no active call. 2022-05-17 09:55:28:500 liblinphone-message-linphone_core_set_mic_gain_db(): no active call. 2022-05-17 09:55:28:500 liblinphone-message-[ToneManager] create ToneManager() 2022-05-17 09:55:28:500 liblinphone-message-Sal nat helper [enabled] 2022-05-17 09:55:28:500 liblinphone-message-Sal use rports [enabled] 2022-05-17 09:55:28:501 liblinphone-message-MTU is supposed to be 1300, rtp payload max size will be 1240 2022-05-17 09:55:28:501 mediastreamer-message-Could not find encoder for SILK 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for iLBC 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for AMR 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for AMR-WB 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for G729 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for mpeg4-generic 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for mpeg4-generic 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for mpeg4-generic 2022-05-17 09:55:28:502 mediastreamer-message-Could not find encoder for mpeg4-generic 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for mpeg4-generic 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for iSAC 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for SILK 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for SILK 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for SILK 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for G726-16 2022-05-17 09:55:28:503 mediastreamer-message-Could not find encoder for G726-24 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for G726-32 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for G726-40 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for AAL2-G726-16 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for AAL2-G726-24 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for AAL2-G726-32 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for AAL2-G726-40 2022-05-17 09:55:28:504 mediastreamer-message-Could not find encoder for CODEC2 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for BV16 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for 1016 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for G723 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for LPC 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for CN 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for H264 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for H265 2022-05-17 09:55:28:505 mediastreamer-message-Could not find encoder for MP4V-ES 2022-05-17 09:55:28:506 mediastreamer-message-Could not find encoder for H263-1998 2022-05-17 09:55:28:506 mediastreamer-message-Could not find encoder for H263 2022-05-17 09:55:28:506 mediastreamer-message-Could not find encoder for H261 2022-05-17 09:55:28:506 mediastreamer-message-Could not find encoder for MPV 2022-05-17 09:55:28:506 liblinphone-message-Supported codec red/1000 fmtp= automatically added to codec list. 2022-05-17 09:55:28:506 liblinphone-message-Supported codec t140/1000 fmtp= automatically added to codec list. 2022-05-17 09:55:28:506 liblinphone-message-Sal use rports [enabled] 2022-05-17 09:55:28:507 belle-sip-message-belle_sip_stack_set_well_know_port() : set to [5060] 2022-05-17 09:55:28:507 belle-sip-message-belle_sip_stack_set_well_know_port_tls() : set to [5061] 2022-05-17 09:55:28:507 belle-sip-message-Root ca path set to /usr/share/linphone/rootca.pem 2022-05-17 09:55:28:507 liblinphone-message-Sal::unlistenPorts(): done 2022-05-17 09:55:28:508 belle-sip-message-Creating listening point [0x60ca10] on [sip:[::0]:5060;transport=UDP] 2022-05-17 09:55:28:508 belle-sip-message-Creating listening point [0x6147e8] on [sip:[::0]:5060;transport=TCP] 2022-05-17 09:55:28:509 belle-sip-message-Creating listening point [0x6062e0] on [sip:[::0]:-1;transport=TLS] 2022-05-17 09:55:28:509 belle-sip-message-Random TCP port is 35675 2022-05-17 09:55:28:509 belle-sip-message-Root ca path set to /etc/ssl/certs 2022-05-17 09:55:28:509 belle-sip-message-Root ca path set to /etc/ssl/certs 2022-05-17 09:55:28:510 belle-sip-message-Root ca path set to /usr/share/linphone/rootca.pem 2022-05-17 09:55:28:532 liblinphone-message-linphone_proxy_config_is_server_config_changed : 0 2022-05-17 09:55:28:533 liblinphone-message-Publish params have changed on proxy config [0x616fa0] 2022-05-17 09:55:28:533 liblinphone-message-Invalidating friends maps for list [0x65f320] 2022-05-17 09:55:28:533 liblinphone-message-linphone_core_find_auth_info(): returning auth info username=102, realm=asterisk 2022-05-17 09:55:28:535 liblinphone-message-Opening linphone database /root/.local/share/linphone/linphone.db with backend Sqlite3 2022-05-17 09:55:28:579 liblinphone-message-Start measurement of [Get chat rooms.]. 2022-05-17 09:55:28:582 liblinphone-message-Duration of [Get chat rooms.]: 2ms. 2022-05-17 09:55:28:582 belle-sip-message-Root ca path set to /usr/share/linphone/rootca.pem 2022-05-17 09:55:28:583 liblinphone-message-SIP network reachability state is now [UP] 2022-05-17 09:55:28:583 liblinphone-message-Media network reachability state is now [UP] 2022-05-17 09:55:28:598 liblinphone-message-LinphoneProxyConfig [0x616fa0] about to register (LinphoneCore version: 4.4.21) 2022-05-17 09:55:28:648 belle-sip-message-belle_sip_client_transaction_send_request(): waiting channel to be ready 2022-05-17 09:55:28:648 belle-sip-message-channel [0x6a12d0]: starting resolution of 192.168.179.192 2022-05-17 09:55:28:648 belle-sip-message-channel 0x6a12d0: state RES_IN_PROGRESS 2022-05-17 09:55:28:648 belle-sip-message-transaction [0x6ca278] channel state changed to [RES_IN_PROGRESS] 2022-05-17 09:55:28:648 belle-sip-message-channel 0x6a12d0: state RES_DONE 2022-05-17 09:55:28:648 belle-sip-message-transaction [0x6ca278] channel state changed to [RES_DONE] 2022-05-17 09:55:28:649 belle-sip-message-channel 0x6a12d0: state CONNECTING 2022-05-17 09:55:28:649 belle-sip-message-transaction [0x6ca278] channel state changed to [CONNECTING] 2022-05-17 09:55:28:649 belle-sip-message-Trying to connect to [TCP://::ffff:192.168.179.192:5060] 2022-05-17 09:55:28:649 belle-sip-message-Neither Expires header nor corresponding Contact header found, checking from original request 2022-05-17 09:55:28:650 belle-sip-message-Refresher [0x6ca208] takes ownership of transaction [0x6ca278] 2022-05-17 09:55:28:650 liblinphone-message-Proxy config [0x616fa0] for identity [sip:102@homeassistant.local] moving from state [LinphoneRegistrationNone] to [LinphoneRegistrationProgress] on core [0x603fe0] 2022-05-17 09:55:28:650 liblinphone-message-_linphone_update_dependent_proxy_config(): 0x616fa0 is registered, checking for [0x616fa0] ->dependency=(nil) 2022-05-17 09:55:28:670 belle-sip-message-Channel has local address 192.168.179.182:42044 2022-05-17 09:55:28:671 belle-sip-message-channel 0x6a12d0: state READY 2022-05-17 09:55:28:671 belle-sip-message-transaction [0x6ca278] channel state changed to [READY] 2022-05-17 09:55:28:671 belle-sip-message-Changing [client] [REGISTER] transaction [0x6ca278], from state [INIT] to [TRYING] 2022-05-17 09:55:28:672 belle-sip-message-channel [0x6a12d0]: message sent to [TCP://192.168.179.192:5060], size: [575] bytes REGISTER sip:homeassistant.local SIP/2.0 Via: SIP/2.0/TCP 192.168.179.182:42044;alias;branch=z9hG4bK.Ucg4MR2~7;rport From: sip:102@homeassistant.local;tag=1qM1sVGB8 To: sip:102@homeassistant.local CSeq: 20 REGISTER Call-ID: hFA7RrOu5t Max-Forwards: 70 Supported: replaces, outbound, gruu Accept: application/sdp Accept: text/plain Accept: application/vnd.gsma.rcs-ft-http+xml Contact: sip:102@192.168.179.182:42044;transport=tcp;+sip.instance="" Expires: 3600 User-Agent: Linphonec/4.4.21 Content-Length: 0

2022-05-17 09:55:28:714 belle-sip-message-channel [0x6a12d0]: received [480] new bytes from [TCP://192.168.179.192:5060]: SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 192.168.179.182:42044;rport=42044;received=192.168.179.182;branch=z9hG4bK.Ucg4MR2~7;alias Call-ID: hFA7RrOu5t From: sip:102@homeassistant.local;tag=1qM1sVGB8 To: sip:102@homeassistant.local;tag=z9hG4bK.Ucg4MR2~7 CSeq: 20 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1652774128/fa516f2ed30980d1858ab3a111ea6b5b",opaque="6b520fae4d2db6a1",algorithm=md5,qop="auth" Server: Asterisk PBX 18.10.1 Content-Length: 0

2022-05-17 09:55:28:731 belle-sip-message-channel [0x6a12d0] [480] bytes parsed 2022-05-17 09:55:28:731 belle-sip-message-channel [0x6a12d0]: discovered public ip and port are [192.168.179.182:42044] 2022-05-17 09:55:28:731 belle-sip-message-Found transaction matching response. 2022-05-17 09:55:28:731 belle-sip-message-Changing [client] [REGISTER] transaction [0x6ca278], from state [TRYING] to [COMPLETED] 2022-05-17 09:55:28:732 liblinphone-warning-Non unique realm found for 102 2022-05-17 09:55:28:732 liblinphone-message-linphone_core_find_auth_info(): returning auth info username=102, realm=asterisk 2022-05-17 09:55:28:733 liblinphone-message-AuthStack::authFound() for Username[102];Userid[];Realm[asterisk];Domain[homeassistant.local];Algorithm[]; 2022-05-17 09:55:28:733 belle-sip-message-Auth info found for [102] realm [asterisk] 2022-05-17 09:55:28:762 belle-sip-message-Changing [client] [REGISTER] transaction [0x6cbf38], from state [INIT] to [TRYING] 2022-05-17 09:55:28:763 belle-sip-message-channel [0x6a12d0]: message sent to [TCP://192.168.179.192:5060], size: [854] bytes REGISTER sip:homeassistant.local SIP/2.0 Via: SIP/2.0/TCP 192.168.179.182:42044;alias;branch=z9hG4bK.-DKDZ8Pey;rport From: sip:102@homeassistant.local;tag=1qM1sVGB8 To: sip:102@homeassistant.local CSeq: 21 REGISTER Call-ID: hFA7RrOu5t Max-Forwards: 70 Supported: replaces, outbound, gruu Accept: application/sdp Accept: text/plain Accept: application/vnd.gsma.rcs-ft-http+xml Contact: sip:102@192.168.179.182:42044;transport=tcp;+sip.instance="" Expires: 3600 User-Agent: Linphonec/4.4.21 Content-Length: 0 Authorization: Digest realm="asterisk", nonce="1652774128/fa516f2ed30980d1858ab3a111ea6b5b", algorithm=md5, opaque="6b520fae4d2db6a1", username="102", uri="sip:homeassistant.local", response="8315fb296f194352f58e2eba666b9fa9", cnonce="A1GHfJqotKquqCPO", nc=00000001, qop=auth

2022-05-17 09:55:28:764 belle-sip-message-Changing [client] [REGISTER] transaction [0x6ca278], from state [COMPLETED] to [TERMINATED] 2022-05-17 09:55:28:764 belle-sip-message-Client internal REGISTER transaction [0x6ca278] terminated 2022-05-17 09:55:28:784 belle-sip-message-channel [0x6a12d0]: received [445] new bytes from [TCP://192.168.179.192:5060]: SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.179.182:42044;rport=42044;received=192.168.179.182;branch=z9hG4bK.-DKDZ8Pey;alias Call-ID: hFA7RrOu5t From: sip:102@homeassistant.local;tag=1qM1sVGB8 To: sip:102@homeassistant.local;tag=z9hG4bK.-DKDZ8Pey CSeq: 21 REGISTER Date: Tue, 17 May 2022 07:55:28 GMT Contact: sip:102@192.168.179.182:42044;transport=TCP;expires=3599 Expires: 3600 Server: Asterisk PBX 18.10.1 Content-Length: 0

2022-05-17 09:55:28:804 belle-sip-message-channel [0x6a12d0] [445] bytes parsed 2022-05-17 09:55:28:804 belle-sip-message-Found transaction matching response. 2022-05-17 09:55:28:804 belle-sip-message-Changing [client] [REGISTER] transaction [0x6cbf38], from state [TRYING] to [COMPLETED] 2022-05-17 09:55:28:805 belle-sip-message-Refresher [0x6ca208]: has no contact for request [0x6c0d48]. 2022-05-17 09:55:28:805 belle-sip-message-Refresher[0x6ca208]: scheduling next timer in 3239100 ms for purpose [normal refresh] 2022-05-17 09:55:28:805 liblinphone-message-Register refresher [200] reason [OK] for proxy [<sip:192.168.179.192;transport=tcp>] 2022-05-17 09:55:28:805 liblinphone-message-Proxy config [0x616fa0] for identity [sip:102@homeassistant.local] moving from state [LinphoneRegistrationProgress] to [LinphoneRegistrationOk] on core [0x603fe0] 2022-05-17 09:55:28:805 liblinphone-message-Updating friends for identity [sip:102@homeassistant.local] on core [0x603fe0] 2022-05-17 09:55:28:806 liblinphone-message-_linphone_update_dependent_proxy_config(): 0x616fa0 is registered, checking for [0x616fa0] ->dependency=(nil) 2022-05-17 09:55:28:806 belle-sip-message-Changing [client] [REGISTER] transaction [0x6cbf38], from state [COMPLETED] to [TERMINATED] 2022-05-17 09:55:28:806 belle-sip-message-Client internal REGISTER transaction [0x6cbf38] terminated 2022-05-17 09:55:35:388 belle-sip-message-channel [0x6a12d0]: received [2957] new bytes from [TCP://192.168.179.192:5060]: INVITE sip:102@192.168.179.182:42044;transport=TCP SIP/2.0 Via: SIP/2.0/TCP 192.168.179.192:5060;rport;branch=z9hG4bKPje82b4879-1828-407f-8c44-90e7541ebb26;alias From: "sascha" sip:100@asterisk;tag=ca2e2a10-d920-4622-91ee-c43825371b0e To: sip:102@192.168.179.182 Contact: sip:asterisk@192.168.179.192:5060;transport=TCP Call-ID: b10f7ffa-aa68-4151-ba66-ca05a000d322 CSeq: 25599 INVITE Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub, histinfo Session-Expires: 1800 Min-SE: 90 P-Asserted-Identity: "sascha" sip:100@asterisk Remote-Party-ID: "sascha" sip:100@asterisk;party=calling;privacy=off;screen=no Max-Forwards: 70 User-Agent: Asterisk PBX 18.10.1 Content-Type: application/sdp Content-Length: 2115

v=0 o=- 843460226 843460226 IN IP4 192.168.179.192 s=Asterisk c=IN IP4 192.168.179.192 t=0 0 a=msid-semantic:WMS a=group:BUNDLE audio-0 m=audio 12886 UDP/TLS/RTP/SAVPF 0 8 9 107 110 3 111 4 101 a=connection:new a=setup:actpass a=fingerprint:SHA-256 BB:E3:E0:17:FE:AD:9A:5F:DE:74:05:59:9C:16:F7:39:35:E8:CA:06:B0:0B:70:3A:EF:62:76:D7:C7:70:A0:9E a=ice-ufrag:5f97ea51372fa04258add778508ec7b2 a=ice-pwd:235f7a125fbd4fc52a748755025e106a a=candidate:Hc0a8b3c0 1 UDP 2130706431 192.168.179.192 12886 typ host a=candidate:Hac110001 1 UDP 2130706431 172.17.0.1 12886 typ host a=candidate:Hac1e2001 1 UDP 2130706431 172.30.32.1 12886 typ host a=candidate:Hd5d88573 1 UDP 2130706431 fe80::f9b3:3214:9eb6:cc3 12886 typ host a=candidate:H6b69f4cb 1 UDP 2130706431 fe80::42:c0ff:fed6:dfb9 12886 typ host a=candidate:H3f164c04 1 UDP 2130706431 fe80::42:adff:fe77:5ce7 12886 typ host a=candidate:Hc8a0e5 1 UDP 2130706431 fe80::9cd8:f8ff:fef7:3b2c 12886 typ host a=candidate:H3638c60d 1 UDP 2130706431 fe80::9c8c:91ff:fe61:6197 12886 typ host a=candidate:Hb1b2d05f 1 UDP 2130706431 fe80::c800:8eff:fee1:91fc 12886 typ host a=candidate:H94067e5a 1 UDP 2130706431 fe80::8850:f0ff:fe05:b49e 12886 typ host a=candidate:H9b25fc89 1 UDP 2130706431 fe80::8e5:a9ff:feb3:4bfa 12886 typ host a=candidate:H519b1f3a 1 UDP 2130706431 fe80::68ef:b5ff:feee:af56 12886 typ host a=candidate:H28585933 1 UDP 2130706431 fe80::4c53:1aff:fe43:76c6 12886 typ host a=candidate:H8ebe720a 1 UDP 2130706431 fe80::f047:62ff:fe85:d29f 12886 typ host a=candidate:S5dc2f5bf 1 UDP 1694498815 93.194.245.191 12886 typ srflx raddr 192.168.179.192 rport 12886 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:107 opus/48000/2 a=rtpmap:110 speex/8000 a=rtpmap:3 GSM/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:60 a=sendrecv a=rtcp-mux a=ssrc:477285162 cname:fb721d85-06b7-43a6-a2dc-d26a2134af34 a=msid:d2c3337f-e311-49cf-a24e-22ea3a3b1153 08ab58a3-2bde-42ae-a48c-8093c8f039e1 a=rtcp-fb: transport-cc a=mid:audio-0

2022-05-17 09:55:35:440 belle-sip-message-channel [0x6a12d0] [842] bytes parsed 2022-05-17 09:55:35:441 belle-sip-message-channel [0x6a12d0] read [2115] bytes of body from [192.168.179.192:5060] 2022-05-17 09:55:35:469 belle-sip-message-Changing [server] [INVITE] transaction [0x6c34a0], from state [INIT] to [PROCEEDING] 2022-05-17 09:55:35:470 belle-sip-message-channel [0x6a12d0]: message sent to [TCP://192.168.179.192:5060], size: [317] bytes SIP/2.0 100 Trying Via: SIP/2.0/TCP 192.168.179.192:5060;rport;branch=z9hG4bKPje82b4879-1828-407f-8c44-90e7541ebb26;alias From: "sascha" sip:100@asterisk;tag=ca2e2a10-d920-4622-91ee-c43825371b0e To: sip:102@192.168.179.182 Call-ID: b10f7ffa-aa68-4151-ba66-ca05a000d322 CSeq: 25599 INVITE Content-Length: 0

2022-05-17 09:55:35:471 belle-sip-message-New server dialog [0x608178] , local tag [H~0gJ5k], remote tag [ca2e2a10-d920-4622-91ee-c43825371b0e] 2022-05-17 09:55:35:471 liblinphone-message-op [0x6b5468] : set_or_update_dialog() current=[0] new=[0x608178] 2022-05-17 09:55:35:471 liblinphone-message-New incoming call from ["sascha" sip:100@asterisk] to [sip:102@192.168.179.182] 2022-05-17 09:55:35:516 liblinphone-message-Found payload PCMU/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload PCMA/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload G722/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload opus/48000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload speex/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload GSM/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload G726-32/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload G723/8000 fmtp= 2022-05-17 09:55:35:517 liblinphone-message-Found payload telephone-event/8000 fmtp=0-16 2022-05-17 09:55:35:523 liblinphone-message-New MediaSession [0x717d3c] initialized (liblinphone version: 4.4.21) 2022-05-17 09:55:35:524 liblinphone-error-LinphoneCore has video disabled for both capture and display, but video policy is to start the call with video. This is a possible mis-use of the API. In this case, video is disabled in default LinphoneCallParams 2022-05-17 09:55:35:524 liblinphone-message-Found media local-ip from signaling. 2022-05-17 09:55:35:525 liblinphone-message-stream#0 [audio] in state [Stopped]: multicast role is [inactive] 2022-05-17 09:55:35:526 ortp-message-RtpSession bound to [::0] ports [7078] [7079] 2022-05-17 09:55:35:527 liblinphone-message-Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_80 2022-05-17 09:55:35:527 liblinphone-message-Configured srtp crypto suite: AES_CM_128_HMAC_SHA1_32 2022-05-17 09:55:35:527 liblinphone-message-Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_80 2022-05-17 09:55:35:527 liblinphone-message-Configured srtp crypto suite: AES_256_CM_HMAC_SHA1_32 2022-05-17 09:55:35:527 mediastreamer-message-Creating ZRTP engine on rtp session [0x6b3c50] ssrc 0xa9facbb7 2022-05-17 09:55:35:542 ortp-message-rtp_session_enable_network_simulation:DISABLING NETWORK SIMULATION 2022-05-17 09:55:35:542 mediastreamer-message-Setting DSCP to 46 for MSAudio stream. 2022-05-17 09:55:35:542 liblinphone-message-Created stream#0 [audio] in state [Stopped] 2022-05-17 09:55:35:545 liblinphone-message-Doing SDP offer/answer process of type incoming 2022-05-17 09:55:35:545 liblinphone-message-Declining mline 0, no corresponding stream in local capabilities description. 2022-05-17 09:55:35:547 belle-sip-message-channel [0x6a12d0]: message sent to [TCP://192.168.179.192:5060], size: [411] bytes SIP/2.0 488 Not acceptable here Via: SIP/2.0/TCP 192.168.179.192:5060;rport;branch=z9hG4bKPje82b4879-1828-407f-8c44-90e7541ebb26;alias From: "sascha" sip:100@asterisk;tag=ca2e2a10-d920-4622-91ee-c43825371b0e To: sip:102@192.168.179.182;tag=H~0gJ5k Call-ID: b10f7ffa-aa68-4151-ba66-ca05a000d322 CSeq: 25599 INVITE User-Agent: Linphonec/4.4.21 Supported: replaces, outbound, gruu Content-Length: 0

2022-05-17 09:55:35:547 belle-sip-message-Changing [server] [INVITE] transaction [0x6c34a0], from state [PROCEEDING] to [COMPLETED] 2022-05-17 09:55:35:547 belle-sip-message-Dialog [0x608178]: now updated by transaction [0x6c34a0]. 2022-05-17 09:55:35:547 belle-sip-message-Dialog [0x608178] deleted (is_expired=0) 2022-05-17 09:55:35:548 liblinphone-message-StreamsGroup::finish() called. 2022-05-17 09:55:35:548 mediastreamer-message-================================================================================= 2022-05-17 09:55:35:548 mediastreamer-message- FILTER USAGE STATISTICS 2022-05-17 09:55:35:548 mediastreamer-message-Name Count Time/tick (ms) CPU Usage 2022-05-17 09:55:35:548 mediastreamer-message- min mean max sd 2022-05-17 09:55:35:548 mediastreamer-message---------------------------------------------------------------------------------- 2022-05-17 09:55:35:548 mediastreamer-message-MSSpeexEC 0 0.00 0.00 0.00 0.00 0.0 2022-05-17 09:55:35:548 mediastreamer-message-MSRtpSend 0 0.00 0.00 0.00 0.00 0.0 2022-05-17 09:55:35:548 mediastreamer-message-================================================================================= 2022-05-17 09:55:35:549 mediastreamer-message-Stopping ZRTP context on session [(nil)] 2022-05-17 09:55:35:549 mediastreamer-message-ZRTP context destroyed 2022-05-17 09:55:35:570 belle-sip-message-channel [0x6a12d0]: received [418] new bytes from [TCP://192.168.179.192:5060]: ACK sip:102@192.168.179.182:42044;transport=TCP SIP/2.0 Via: SIP/2.0/TCP 192.168.179.192:5060;rport;branch=z9hG4bKPje82b4879-1828-407f-8c44-90e7541ebb26;alias From: "sascha" sip:100@asterisk;tag=ca2e2a10-d920-4622-91ee-c43825371b0e To: sip:102@192.168.179.182;tag=H~0gJ5k Call-ID: b10f7ffa-aa68-4151-ba66-ca05a000d322 CSeq: 25599 ACK Max-Forwards: 70 User-Agent: Asterisk PBX 18.10.1 Content-Length: 0

2022-05-17 09:55:35:595 belle-sip-message-channel [0x6a12d0] [418] bytes parsed 2022-05-17 09:55:35:595 belle-sip-message-Found transaction [0x6c34a0] matching request. 2022-05-17 09:55:35:595 belle-sip-message-Changing [server] [INVITE] transaction [0x6c34a0], from state [COMPLETED] to [CONFIRMED] 2022-05-17 09:55:35:595 belle-sip-message-Changing [server] [INVITE] transaction [0x6c34a0], from state [CONFIRMED] to [TERMINATED] 2022-05-17 09:55:35:595 belle-sip-message-Server INVITE transaction [0x6c34a0] terminated 2022-05-17 09:55:35:596 liblinphone-message-Dialog [0x608178] terminated for op [0x6b5468] 2022-05-17 09:55:35:616 liblinphone-message-op [0x6b5468] : set_or_update_dialog() current=[0x608178] new=[0] 2022-05-17 09:55:35:616 belle-sip-message-Transaction [0x6c34a0] deleted 2022-05-17 09:55:35:617 liblinphone-message-Destroying op [0x6b5468] of type [SalOpCall] 2022-05-17 09:55:38:709 liblinphone-message-[ToneManager] linphoneCoreStopRinging 2022-05-17 09:55:38:710 liblinphone-message-[ToneManager] doStopRingtone 2022-05-17 09:55:38:710 liblinphone-message-[ToneManager] linphoneCoreStopDtmfStream 2022-05-17 09:55:38:710 liblinphone-message-[ToneManager] doStopTone 2022-05-17 09:55:38:714 liblinphone-message-Destroying friends. 2022-05-17 09:55:38:714 liblinphone-message-Destroying friends done. 2022-05-17 09:55:38:716 liblinphone-warning-Non unique realm found for 102 2022-05-17 09:55:38:716 liblinphone-message-linphone_core_find_auth_info(): returning auth info username=102, realm=asterisk 2022-05-17 09:55:38:716 liblinphone-message-AuthStack::authFound() for Username[102];Userid[];Realm[asterisk];Domain[homeassistant.local];Algorithm[]; 2022-05-17 09:55:38:717 belle-sip-message-Auth info found for [102] realm [asterisk] 2022-05-17 09:55:38:753 belle-sip-message-Transaction [0x6cbf38] deleted 2022-05-17 09:55:38:754 belle-sip-message-Changing [client] [REGISTER] transaction [0x767a68], from state [INIT] to [TRYING] 2022-05-17 09:55:38:756 belle-sip-message-channel [0x6a12d0]: message sent to [TCP://192.168.179.192:5060], size: [851] bytes REGISTER sip:homeassistant.local SIP/2.0 Via: SIP/2.0/TCP 192.168.179.182:42044;alias;branch=z9hG4bK.1uYnQ8-2n;rport From: sip:102@homeassistant.local;tag=1qM1sVGB8 To: sip:102@homeassistant.local CSeq: 22 REGISTER Call-ID: hFA7RrOu5t Max-Forwards: 70 Supported: replaces, outbound, gruu Accept: application/sdp Accept: text/plain Accept: application/vnd.gsma.rcs-ft-http+xml Contact: sip:102@192.168.179.182:42044;transport=tcp;+sip.instance="" Expires: 0 User-Agent: Linphonec/4.4.21 Content-Length: 0 Authorization: Digest realm="asterisk", nonce="1652774128/fa516f2ed30980d1858ab3a111ea6b5b", algorithm=md5, opaque="6b520fae4d2db6a1", username="102", uri="sip:homeassistant.local", response="b515dea8ca673798e45dab742828024a", cnonce="Bm~z19BOqFupfH~e", nc=00000002, qop=auth

2022-05-17 09:55:38:756 belle-sip-message-Refresher [0x6ca208] stopped. 2022-05-17 09:55:38:756 liblinphone-message-Unregistration started. 2022-05-17 09:55:38:857 belle-sip-message-channel [0x6a12d0]: received [373] new bytes from [TCP://192.168.179.192:5060]: SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.179.182:42044;rport=42044;received=192.168.179.182;branch=z9hG4bK.1uYnQ8-2n;alias Call-ID: hFA7RrOu5t From: sip:102@homeassistant.local;tag=1qM1sVGB8 To: sip:102@homeassistant.local;tag=z9hG4bK.1uYnQ8-2n CSeq: 22 REGISTER Date: Tue, 17 May 2022 07:55:38 GMT Expires: 0 Server: Asterisk PBX 18.10.1 Content-Length: 0

2022-05-17 09:55:38:880 belle-sip-message-channel [0x6a12d0] [373] bytes parsed 2022-05-17 09:55:38:880 belle-sip-message-Found transaction matching response. 2022-05-17 09:55:38:880 belle-sip-message-Changing [client] [REGISTER] transaction [0x767a68], from state [TRYING] to [COMPLETED] 2022-05-17 09:55:38:881 belle-sip-message-Refresher [0x6ca208] stopped. 2022-05-17 09:55:38:881 belle-sip-message-Refresher [0x6ca208] not scheduling next refresh, because it was stopped 2022-05-17 09:55:38:881 liblinphone-message-Register refresher [200] reason [OK] for proxy [<sip:192.168.179.192;transport=tcp>] 2022-05-17 09:55:38:882 liblinphone-message-Proxy config [0x616fa0] for identity [sip:102@homeassistant.local] moving from state [LinphoneRegistrationOk] to [LinphoneRegistrationCleared] on core [0x603fe0] 2022-05-17 09:55:38:882 liblinphone-message-_linphone_update_dependent_proxy_config(): 0x616fa0 is registered, checking for [0x616fa0] ->dependency=(nil) 2022-05-17 09:55:38:882 belle-sip-message-Changing [client] [REGISTER] transaction [0x767a68], from state [COMPLETED] to [TERMINATED] 2022-05-17 09:55:38:882 belle-sip-message-Client internal REGISTER transaction [0x767a68] terminated 2022-05-17 09:55:38:883 belle-sip-message-Garbage collecting unowned object of type belle_sip_header_contact_t 2022-05-17 09:55:38:883 belle-sip-message-Garbage collecting unowned object of type belle_sip_header_contact_t 2022-05-17 09:55:38:983 belle-sip-message-Refresher [0x6ca208] stopped. 2022-05-17 09:55:38:984 liblinphone-message-Destroying op [0x609470] of type [SalOpRegister] 2022-05-17 09:55:38:984 belle-sip-message-Refresher [0x6ca208] stopped. 2022-05-17 09:55:38:985 belle-sip-message-Transaction [0x767a68] deleted 2022-05-17 09:55:38:986 belle-sip-message-Transaction [0x6ca278] deleted 2022-05-17 09:55:38:987 liblinphone-message-Reseting transports 2022-05-17 09:55:38:987 belle-sip-message-Listening point destroying [1] channels 2022-05-17 09:55:38:987 belle-sip-message-channel 0x6a12d0: state DISCONNECTED 2022-05-17 09:55:38:988 belle-sip-message-Channel [0x6a12d0] destroyed 2022-05-17 09:55:38:989 belle-sip-message-Listening point [0x60ca10] on [sip:[::0]:5060;transport=UDP] destroyed 2022-05-17 09:55:38:989 belle-sip-message-Listening point [0x6147e8] on [sip:[::0]:5060;transport=TCP] destroyed 2022-05-17 09:55:38:989 belle-sip-message-Listening point [0x6062e0] on [sip:[::0]:35675;transport=TLS] destroyed 2022-05-17 09:55:38:990 liblinphone-message-Sal::unlistenPorts(): done 2022-05-17 09:55:38:990 belle-sip-message-http provider destroyed. 2022-05-17 09:55:38:990 belle-sip-message-stack [0x5eb0b8] destroyed. 2022-05-17 09:55:39:059 liblinphone-message-Destroying core: 0x6036b8 2022-05-17 09:55:39:060 liblinphone-message-[ToneManager] destroy ToneManager()

TECH7Fox commented 2 years ago

I guess it has something to do with the codecs.

Please share your pjsip_custom.conf, Asterisk logs and browser console.

sascha005 commented 2 years ago

Hi Thank you for your Help. Here is the Asterisk Log:

[May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4770 session_inv_on_tsx_state_changed: Disconnected [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Completed Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4189 session_on_tsx_state:
[May 18 19:04:08] DEBUG[695]: chan_pjsip.c:2975 chan_pjsip_session_end: PJSIP/102-00000002 [May 18 19:04:08] DEBUG[695]: chan_pjsip.c:2992 chan_pjsip_session_end:
[May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/100-00000001: Indicated Private Cause Code [May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/100-00000001 [May 18 19:04:08] DEBUG[682]: cdr.c:1473 cdr_object_finalize: Finalized CDR for PJSIP/100-00000001 - start 1652893448.230283 answer 0.000000 end 1652893448.523118 dur 0.292 bill 1652893448.523 dispo NO ANSWER [May 18 19:04:08] DEBUG[814][C-00000002]: channel.c:2549 ast_hangup: Channel 0x7f048c007cb0 'PJSIP/102-00000002' hanging up. Refs: 2 [May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:2522 chan_pjsip_hangup: PJSIP/102-00000002 [May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:2540 chan_pjsip_hangup: Cause: 488 [May 18 19:04:08] == Everyone is busy/congested at this time (1:0/0/1) [May 18 19:04:08] DEBUG[814][C-00000002]: app_dial.c:1306 wait_for_answer: PJSIP/100-00000001: No outging channels available [May 18 19:04:08] DEBUG[814][C-00000002]: app_dial.c:3429 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL. [May 18 19:04:08] DEBUG[814][C-00000002]: app_dial.c:3460 dial_exec_full: PJSIP/100-00000001: Done [May 18 19:04:08] -- Auto fallthrough, channel 'PJSIP/100-00000001' status is 'CHANUNAVAIL' [May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/100-00000001: Indicated Congestion [May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/100-00000001 [May 18 19:04:08] DEBUG[673]: devicestate.c:466 do_state_change: Changing state for PJSIP/100 - state 3 (Busy) [May 18 19:04:08] DEBUG[790]: app_queue.c:2683 device_state_cb: Device 'PJSIP/100' changed to state '3' (Busy) but we don't care because they're not a member of any queue. [May 18 19:04:08] DEBUG[696]: chan_pjsip.c:2489 hangup: PJSIP/102-00000002 [May 18 19:04:08] DEBUG[696]: res_pjsip_session.c:3456 ast_sip_session_terminate: PJSIP/102-00000002 Response 488 [May 18 19:04:08] DEBUG[696]: res_pjsip_session.c:3528 ast_sip_session_terminate:
[May 18 19:04:08] DEBUG[696]: res_pjsip_session.c:2912 session_destructor: 102: Destroying SIP session [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c1b84e0) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c1b84e0) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:2275 ast_rtp_dtls_stop: (0x7f045c1b84e0) DTLS stop [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c1b84e0) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c1b84e0) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4514 handle_outgoing_response: PJSIP/100-00000001: Method is INVITE, Response is 503 Service Unavailable [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4533 handle_outgoing_response: PJSIP/100-00000001 [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:3981 rtp_deallocate_transport: (0x7f045c1b84e0) ICE RTP transport deallocating [May 18 19:04:08] DEBUG[696]: res_rtp_asterisk.c:918 ast_rtp_ice_stop: (0x7f045c1b84e0) ICE stopped [May 18 19:04:08] DEBUG[696]: rtp_engine.c:455 instance_destructor: Destroyed RTP instance '0x7f045c1b84e0' [May 18 19:04:08] DEBUG[696]: channel.c:2196 ast_channel_destructor: Channel 0x7f048c007cb0 'PJSIP/102-00000002' destroying [May 18 19:04:08] DEBUG[696]: stasis.c:442 topic_dtor: Destroying topic. name: channel:1652893448.2, detail: [May 18 19:04:08] DEBUG[696]: stasis.c:451 topic_dtor: Topic 'channel:1652893448.2': 0x7f048c001a30 destroyed [May 18 19:04:08] DEBUG[696]: channel_internal_api.c:680 ast_channel_nativeformats_set: : MultistreamFormats: (nothing) [May 18 19:04:08] DEBUG[696]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [May 18 19:04:08] DEBUG[696]: chan_pjsip.c:2513 hangup:
[May 18 19:04:08] DEBUG[682]: cdr.c:1473 cdr_object_finalize: Finalized CDR for PJSIP/102-00000002 - start 1652893448.232594 answer 0.000000 end 1652893448.524022 dur 0.291 bill 1652893448.524 dispo NO ANSWER [May 18 19:04:08] DEBUG[682]: cdr.c:1313 cdr_object_create_public_records: CDR for PJSIP/102-00000002 is dialed and has no Party B; discarding [May 18 19:04:08] DEBUG[673]: devicestate.c:466 do_state_change: Changing state for PJSIP/102 - state 1 (Not in use) [May 18 19:04:08] DEBUG[695]: res_http_websocket.c:381 __ast_websocket_write: Writing websocket text frame, length 552 [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4630 session_inv_on_state_changed: PJSIP/100-00000001 Event: TSX_STATE Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4656 session_inv_on_state_changed: PJSIP/100-00000001: Source of transaction state change is TX_MSG [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4704 session_inv_on_state_changed:
[May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/100-00000001 TSX State: Completed Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4770 session_inv_on_tsx_state_changed: Disconnected [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Completed Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4189 session_on_tsx_state:
[May 18 19:04:08] DEBUG[695]: chan_pjsip.c:2975 chan_pjsip_session_end: PJSIP/100-00000001 [May 18 19:04:08] DEBUG[695]: chan_pjsip.c:2992 chan_pjsip_session_end:
[May 18 19:04:08] DEBUG[814][C-00000002]: channel.c:2459 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'PJSIP/100-00000001' [May 18 19:04:08] DEBUG[814][C-00000002]: channel.c:2549 ast_hangup: Channel 0x7f045c1b88a0 'PJSIP/100-00000001' hanging up. Refs: 2 [May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:2522 chan_pjsip_hangup: PJSIP/100-00000001 [May 18 19:04:08] DEBUG[695]: chan_pjsip.c:2489 hangup: PJSIP/100-00000001 [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:3456 ast_sip_session_terminate: PJSIP/100-00000001 Response 503 [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:3528 ast_sip_session_terminate:
[May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:2912 session_destructor: 100: Destroying SIP session [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c13a530) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c13a530) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:2275 ast_rtp_dtls_stop: (0x7f045c13a530) DTLS stop [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c13a530) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f045c13a530) DTLS srtp - stopped timeout timer' [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:3981 rtp_deallocate_transport: (0x7f045c13a530) ICE RTP transport deallocating [May 18 19:04:08] DEBUG[695]: res_rtp_asterisk.c:918 ast_rtp_ice_stop: (0x7f045c13a530) ICE stopped [May 18 19:04:08] DEBUG[695]: rtp_engine.c:455 instance_destructor: Destroyed RTP instance '0x7f045c13a530' [May 18 19:04:08] DEBUG[695]: chan_pjsip.c:2513 hangup:
[May 18 19:04:08] DEBUG[814][C-00000002]: chan_pjsip.c:2540 chan_pjsip_hangup: Cause: 503 [May 18 19:04:08] DEBUG[814][C-00000002]: channel.c:2196 ast_channel_destructor: Channel 0x7f045c1b88a0 'PJSIP/100-00000001' destroying [May 18 19:04:08] DEBUG[814][C-00000002]: stasis.c:442 topic_dtor: Destroying topic. name: channel:1652893448.1, detail: [May 18 19:04:08] DEBUG[814][C-00000002]: stasis.c:451 topic_dtor: Topic 'channel:1652893448.1': 0x7f045c1bb2b0 destroyed [May 18 19:04:08] DEBUG[814][C-00000002]: channel_internal_api.c:680 ast_channel_nativeformats_set: : MultistreamFormats: (nothing) [May 18 19:04:08] DEBUG[814][C-00000002]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [May 18 19:04:08] DEBUG[673]: devicestate.c:466 do_state_change: Changing state for PJSIP/100 - state 1 (Not in use) [May 18 19:04:08] DEBUG[790]: app_queue.c:2683 device_state_cb: Device 'PJSIP/100' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 19:04:08] DEBUG[682]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: channel:1652893448.3, detail: [May 18 19:04:08] DEBUG[682]: stasis.c:614 stasis_topic_create_with_detail: Topic 'channel:1652893448.3': 0x7f04700073d0 created [May 18 19:04:08] DEBUG[682]: stasis.c:442 topic_dtor: Destroying topic. name: channel:1652893448.3, detail: [May 18 19:04:08] DEBUG[682]: stasis.c:451 topic_dtor: Topic 'channel:1652893448.3': 0x7f04700073d0 destroyed [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4760 session_inv_on_tsx_state_changed: Session ended [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4189 session_on_tsx_state:
[May 18 19:04:08] DEBUG[695]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f045c00a9c8 for Request msg ACK/cseq=1159 (rdata0x7f045c0a95d8) [May 18 19:04:08] DEBUG[695]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000024 to use for Request msg ACK/cseq=1159 (rdata0x7f045c0a95d8) [May 18 19:04:08] DEBUG[695]: res_pjsip_endpoint_identifier_ip.c:275 common_identify: No identify sections to match against [May 18 19:04:08] DEBUG[695]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '100' domain 'rheingauer.duckdns.org' [May 18 19:04:08] DEBUG[695]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '100' domain 'rheingauer.duckdns.org' [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: (null session) TSX State: Confirmed Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4760 session_inv_on_tsx_state_changed: Session ended [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Confirmed Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[695]: res_pjsip_session.c:4189 session_on_tsx_state:
[May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4760 session_inv_on_tsx_state_changed: Session ended [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 19:04:08] DEBUG[694]: res_pjsip_session.c:4189 session_on_tsx_state:
[May 18 19:04:28] DEBUG[662]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [May 18 19:04:28] DEBUG[661]: threadpool.c:1029 worker_thread_destroy: Destroying worker thread 0

My pjsip_custom.conf is empty as it is the default config of the Hass Asterisk Addon.

Btw. I can also not Call the linphonec Extension from the Softphone on my Smartphone. Same 488 Error Message. So the Problem must be on the linphonec client site i guess.

Sascha

TECH7Fox commented 2 years ago

My pjsip_custom.conf is empty as it is the default config of the Hass Asterisk Addon.

You sure pjsip_default.conf is empty? What extension did you use for the card then?

You need to create a simple endpoint in pjsip_custom.conf for your softphone to register as. Example here

TECH7Fox commented 2 years ago

No reaction so will close this for now. Let me know if you are still having this issue.