Summary: | ASTERISK-25229: Exchanging Device and Mailbox State Using PJSIP fails after restart of peer | ||
Reporter: | Vadim (cron333) | Labels: | |
Date Opened: | 2015-07-03 09:25:27 | Date Closed: | |
Priority: | Major | Regression? | |
Status: | Open/New | Components: | Resources/res_pjsip Resources/res_pjsip_publish_asterisk |
Versions: | 13.4.0 13.5.0 | Frequency of Occurrence | Constant |
Related Issues: | |||
Environment: | CentOS-7 x86_64 | Attachments: | ( 0) debug.txt ( 1) DebugPJSIP.txt ( 2) PJSIP_dump_1.txt ( 3) pjsip_outbound_publish_412.patch ( 4) pjsip_outbound_publish_debug.patch ( 5) pjsip.log ( 6) ServA.txt ( 7) ServA-172.16.2.14.txt ( 8) ServA-172.16.2.14.txt ( 9) ServB.txt (10) ServB-172.16.2.15.txt (11) ServB-172.16.2.15.txt (12) Снимок_экрана_2015-07-16_в_0.17.47.png |
Description: | There are two servers: "A" and "B".
When we restart "Asterisk" on "A" we will see in the console of "B": [Jul 3 14:17:13] WARNING[17452]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge. After this "B' can't share a device state to "A", but "A" to "B" can. If we restart "Asterisk" on the server "B", the server "A" will not be able to share a device state to "B", but "B" to "A" can. The configuration, that has been used: https://wiki.asterisk.org/wiki/display/AST/Exchanging+Device+and+Mailbox+State+Using+PJSIP?showComments=true | ||
Comments: | By: Asterisk Team (asteriskteam) 2015-07-03 09:25:29.344-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. By: Rusty Newton (rnewton) 2015-07-06 12:57:57.522-0500 Please provide: * Asterisk versions for both systems. * Asterisk logs demonstrating the issue[1] - including verbose and debug. For both systems. [1]: https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information By: Vadim (cron333) 2015-07-09 07:56:03.646-0500 Asterisk 13.4.0 on both systems A: 192.168.1.146 B: 192.168.1.148 On both: SIP-port: 5060, PJSIP-port: 5071 B - service asterisk restart In the console of A: "[Jul 9 15:06:14] WARNING[14301]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge. [Jul 9 15:06:14] WARNING[14301]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge." Call through the server A (from 111 to 1001) The console of B is empty! ('core set debug 5', 'pjsip set logger on') The debug_log of A is in the attached file. From B to A the exchange of the device state is correct. Debug A: [Edit by Rusty - Removed debug log as per the guidelines. Please follow the guidelines] By: Rusty Newton (rnewton) 2015-07-09 19:13:50.174-0500 Attaching reporter's debug log after removing it from the previous comment. By: Mark Michelson (mmichelson) 2015-07-10 09:29:39.255-0500 I don't see the warning messages in A's debug. What you've attached only goes as late as 14:53 on July 9, but the warning you copied into your comment says it happened at 15:06. Did some of the debug log get cut off? By: Mark Michelson (mmichelson) 2015-07-10 09:34:00.912-0500 Oh, and another data point: can we see the pjsip.conf files for the A and B boxes? I know you pointed to the example wiki page, but that wiki page has no authentication configured. So I would be interested in seeing what you have for in your pjsip.conf file. With the pjsip.conf file and the PJSIP debug that apparently was cut off from the previously posted debug log, we can see potentially why there are issues with regards to authentication realm. By: Vadim (cron333) 2015-07-10 10:04:43.503-0500 Sorry, i'll send a new debug log a little bit later ... By: Vadim (cron333) 2015-07-13 08:59:53.721-0500 i did the same situation: the call from 111 to 1001 (on the server A) P. S. CLI>logger add channel myDebugLog notice,warning,error,debug,verbose,dtmf By: Rusty Newton (rnewton) 2015-07-15 15:46:28.679-0500 Same issue with the new debug logs. I don't see the WARNING that you mentioned. On the CLI you can see what log types are going where with "logger show channels" After you get settings how you need, makes sure to run "logger reload" and "logger rotate". Verify the logs contain what you expect to be there before posting them. By: Vadim (cron333) 2015-07-15 16:29:10.199-0500 I don't see the WARNING messages also ... By: Rusty Newton (rnewton) 2015-07-16 15:53:13.758-0500 I want to clarify... Despite the WARNING's apparently not occurring.. does the problem still occur, that device and mailbox state is not exchanged? By: Vadim (cron333) 2015-07-17 03:28:20.395-0500 yes, exactly, as it's written above ... If restart the asterisk on "A" after the restart (asterisk) on "B", "A" will exchange to "B", but "B" will not! And if restart the asterisk on 'B" after the restart on "A", "B" will exchange to "A", but "A" will not. (for the current settings of the pjsip) By: Rusty Newton (rnewton) 2015-08-24 09:59:33.411-0500 Thanks for all the detail. I was able to reproduce the issue by stopping and starting one Asterisk instance from the CLI. After it came back up, the other instance would no longer publish state, yet the instance that was just started back would continue to publish state. There was at least one time where this issue didn't occur. There must be some aspect of timing involved. By: Alexei Gradinari (alexei gradinari) 2016-02-05 11:57:08.149-0600 Asterisk 'A' receives a 412 (Conditional Request Failed) response from restarted Asterisk 'B'. Asterisk 'A' has to recreate publish session. There is bug in res_pjsip_outbound_publish.c The function sip_outbound_publish_client_alloc is called with wrong object while processing 412 code. This patch fixes it. By: Alexei Gradinari (alexei gradinari) 2016-02-05 12:27:23.188-0600 Debug if could not send message. By: Tolmachev Ivan (tol_iwan) 2016-02-10 01:35:20.660-0600 I installed the patch. I tried with asterisk 13.7.0 and 13.7.2. Overloads the "A". On the "B" I get res_pjsip_outbound_authenticator_digest.c: 135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge. "B" does not send condition "A". "A" sends the status to "B". Overloads the "B". Reversed. The patch does not work? By: Alexei Gradinari (alexei gradinari) 2016-02-10 09:47:34.597-0600 This patch works in my configuration (without auth between asterisks). Can you check it without auth? By: Tolmachev Ivan (tol_iwan) 2016-02-10 23:51:27.829-0600 Configuration matches the specified ServA.txt and ServA.txt. The difference in the IP-address and port. Do I understand that in this configuration, no Auth? Auth only use for endpoint inside asterisk. Now try again to install the patch and the asterisk. Maybe I missed something. By: Tolmachev Ivan (tol_iwan) 2016-02-11 05:13:47.334-0600 Reinstall. Asterisk 13.7.2 I do on the "A" "core restart now". On the "B" message, too: WARNING [27742]: res_pjsip_outbound_authenticator_digest.c: 135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge. "B" does not send status to the "A" By: Alexei Gradinari (alexei gradinari) 2016-02-11 09:16:06.704-0600 Is there only one transport in your configuration which used both for endpoints and asterisk peers? Can you check with different transports. For example: [transport-udp] ; type=transport protocol=udp bind=0.0.0.0:5071 [transport-peer]; type=transport protocol=udp bind=0.0.0.0:5090 [instance2] type=endpoint transport=transport-peer [instance1] type=endpoint transport=transport-peer By: Alexei Gradinari (alexei gradinari) 2016-02-11 09:19:59.397-0600 Are you sure you patched asterisk with pjsip_outbound_publish_412.patch? Can you capture traffic between asterisk peers? By: Tolmachev Ivan (tol_iwan) 2016-02-12 00:26:44.434-0600 Laid pjsip.log file Initial conditions: 1. ServA 172.16.2.14, ServB 172.16.2.15 2. 780 - phone on Serva, 785 - phone on ServB 3. Both asterisk stopped. Run: 1. ServA asterisk start. 2. ServA - CLI 3. ServA - sip set debug ip 172.16.2.15 4. ServA - pjsip set logger host 172.16.2.15 5. ServB asterisk start. 6. Status device ServA <-> ServB OK 7. ServB asterisk stop. 8. ServB asterisk start. 9. Status device ServA <- ServB OK 10. Status device ServA -> ServB FAIL Message WARNING [1776]: res_pjsip_outbound_authenticator_digest.c: 135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge. occurs when "ServB asterisk start". This message does not appear, if in step: 6. Status device ServA <-> ServB OK 6.1 The device is switched off 785 7. ServB asterisk stop. 8. ServB asterisk start. In this case all the same: 9. Status device ServA <- ServB OK 10. Status device ServA -> ServB FAIL By: Tolmachev Ivan (tol_iwan) 2016-02-12 00:31:10.284-0600 Before installing Asterisk: pjsip_outbound_publish_412.patch pjsip_outbound_publish_debug.patch File "res_pjsip_outbound_publish.c" changed. By: Tolmachev Ivan (tol_iwan) 2016-02-12 05:20:38.099-0600 Files pjsip.conf completely: - ServA-172.16.2.14.txt - ServB-172.16.2.15.txt By: Tolmachev Ivan (tol_iwan) 2016-02-12 06:13:32.793-0600 You can show your pjsip.conf and extensions.conf? Where it works. By: Alexei Gradinari (alexei gradinari) 2016-02-12 09:49:02.824-0600 I think restarted asterisk sends '401 Unauthorized' because it treats another asterisk peer as endpoint-local. You should set different transports for peers and endpoint-local. I modified your configs, see attachments. Could, you, please, test it with these configs. By: Alexei Gradinari (alexei gradinari) 2016-02-12 09:54:51.448-0600 My modified configs affected by another bug ASTERISK-25316. Could you, please, change the order of transport in configuration files. 1st transport-peer, then transport-udp The last one will used for qualifying endpoint-local By: Alexei Gradinari (alexei gradinari) 2016-02-12 10:00:56.903-0600 Another solution - identify peer by ip-address to avoid auth. ; on ServA [instance2] type=identify endpoint=instance2 match=172.16.2.15 ; on ServB [instance1] type=identify endpoint=instance1 match=172.16.2.14 By: Tolmachev Ivan (tol_iwan) 2016-02-16 01:34:16.608-0600 No changes. I tried: 1c. your configuration 2. Swaps the 1st transport-peer, then transport-udp 3. Add the section [identify] 4. Moved rooms 780 and 785 on the SIP. In PJSIP left only instance. There are no results. It is possible to check whether the patch became asterisk? By: Alexei Gradinari (alexei gradinari) 2016-02-16 10:28:31.077-0600 What version of pjproject is asterisk compiled with? By: Tolmachev Ivan (tol_iwan) 2016-02-16 10:33:15.046-0600 http://www.pjsip.org/ 2.4.5 By: Alexei Gradinari (alexei gradinari) 2016-02-16 10:42:58.468-0600 I use https://github.com/asterisk/pjproject which is 2.4 version with patches for asterisk By: Tolmachev Ivan (tol_iwan) 2016-02-16 10:48:14.119-0600 OK. Tomorrow will set By: Tolmachev Ivan (tol_iwan) 2016-02-17 03:26:10.207-0600 Hi! Install https://github.com/asterisk/pjproject. No changes. On solved the problem. For convenience, I add a number of tests on 781 ServA. For convenience, I add a number of tests on 784 ServB. ServA: instead [Instance2] type = asterisk-publication devicestate_publish = instance2-devicestate device_state = yes used [Instance2] type = asterisk-publication devicestate_publish = instance2-devicestate device_state = yes ServB: similarly. Now ServB "core restart now". ServA: 780 @ default: PJSIP / 780 State: Idle servB: 780 @ default: PJSIP / 780 State: Unavailable Do call 781-> 780. ServA: 780 @ default: PJSIP / 780 State: Ringing servB: 780 @ default: PJSIP / 780 State: Ringing Further, there is no problem with the status. But! Periodically ServB: WARNING [23432]: res_pjsip_pubsub.c: 2968 pubsub_on_rx_publish_request: No registered publish handler for event presence Two questions: Why is the problem so decided? Why do I get WARNING? By: Alexei Gradinari (alexei gradinari) 2016-02-17 09:19:20.857-0600 Can you clarify what resolved your problem? The parts of configs "instead" and "used" are the same. About "780 @ default: PJSIP / 780 State: Unavailable" It's normal, because after start ServB knows nothing about 780. When status changes on ServA it's propagated to ServB and ServB changes status for 780. About WARNING [23432]: res_pjsip_pubsub.c: 2968 pubsub_on_rx_publish_request: No registered publish handler for event presence May be this warning about Mailbox state. If you don't want to exchange Mailbox states you should add mailbox_state=no By: Tolmachev Ivan (tol_iwan) 2016-02-17 23:14:51.250-0600 I'm sorry. ServA: instead [Instance2] type = asterisk-publication *devicestate_publish = instance2-devicestate* device_state = yes used [Instance2] type = asterisk-publication *devicestate_publish = instance2* device_state = yes ServB: similarly. By: Tolmachev Ivan (tol_iwan) 2016-02-18 06:36:00.863-0600 WARNING [23432]: res_pjsip_pubsub.c: 2968 pubsub_on_rx_publish_request: No registered publish handler for event presence I switch off the phone option "send status". Messages ceased. Thank you. By: Tolmachev Ivan (tol_iwan) 2016-02-18 06:36:42.806-0600 When the patch is included in the release? By: Richard Mudgett (rmudgett) 2016-02-22 09:41:47.328-0600 Patch was merged. By: Vadim (cron333) 2016-03-18 16:03:00.784-0500 Sorry, but the situation persists ... When we are executing a command 'service asterisk restart' on the server A (ex., CentOS), on the console of the server B appears the message: 'res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge' - and all repeats But, if we stop both servers and then start them - everything works. Or, if we stop the one server, and start it after a while (from one to several minutes) - everything works also. And the message doesn't appear on the console of the second server ... By: Asterisk Team (asteriskteam) 2016-03-18 16:03:01.105-0500 This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable. By: Richard Mudgett (rmudgett) 2016-03-18 18:53:21.451-0500 [~cron333] The merged patch has not made it into a released version yet. It will be in v13.8.0. Are you using the tip of the v13 branch for your testing? By: Vadim (cron333) 2016-03-19 04:12:18.135-0500 I'm using v.13.7.2 with the patch from here ... By: Alexei Gradinari (alexei gradinari) 2016-03-21 13:53:44.333-0500 Vadim, Сan you upload the current pjsip.conf files for both asterisk peers? Can you capture SIP traffic between asterisk peers? By: Vadim (cron333) 2016-03-22 01:43:42.497-0500 After A is restarted, B has not been sending the PUBLISH message to A. (only A -> B) There is nothing to dump (tcpdump). PJSIP (pjsip set logger on) silent also. The config-files i posted here already. By: Alexei Gradinari (alexei gradinari) 2016-03-22 09:26:42.776-0500 Can you start tcpdump before restart A and stop after you get "Unable to create request with auth.No auth credentials for any realms in challenge."? I need a whole config. You posted only part of config. I use 2 transports: 1st for asterisk publications 2nd for endpoints Do you use only one transport? By: Alexei Gradinari (alexei gradinari) 2016-03-22 09:30:49.849-0500 Can you show pjsip show endpoint instance1 on server B before and after restart serv A By: Vadim (cron333) 2016-03-29 14:22:57.764-0500 >Can you start tcpdump before restart A and stop after you get "Unable to create request with auth.No auth credentials for any realms in challenge."? In the attached file (PJSIP_dump_1.txt). tcpdump was started on the B with the command: "tcpdump -nn -s 0 host A -w /home/vadim/PJSIP_dump_1" >I need a whole config. You posted only part of config. It's the whole config ... >Do you use only one transport? I have tried both options (one transport and two transports) with the same result ... (when I was executing tcmpdump PJSIP had two transports (ports: 5071 and 5072). endpoints had the port 5072 >Can you show >pjsip show endpoint instance1 >on server B before and after restart serv A before: pjsip show endpoint instance1: {noformat} ========================================================================================= Endpoint: instance1 Unknown 0 of inf Transport: transport-ep udp 0 0 0.0.0.0:5072 ParameterName : ParameterValue ==================================================== 100rel : yes accountcode : aggregate_mwi : true allow : (nothing) allow_subscribe : true allow_transfer : true aors : auth : call_group : callerid : <unknown> callerid_privacy : allowed_not_screened callerid_tag : connected_line_method : invite context : default cos_audio : 0 cos_video : 0 device_state_busy_at : 0 direct_media : true direct_media_glare_mitigation : none direct_media_method : invite disable_direct_media_on_nat : false dtls_ca_file : dtls_ca_path : dtls_cert_file : dtls_cipher : dtls_fingerprint : SHA-256 dtls_private_key : dtls_rekey : 0 dtls_setup : active dtls_verify : No dtmf_mode : rfc4733 fax_detect : false force_avp : false force_rport : true from_domain : from_user : g726_non_standard : false ice_support : false identify_by : username inband_progress : false language : mailboxes : media_address : media_encryption : no media_encryption_optimistic : false media_use_received_transport : false message_context : moh_suggest : default mwi_from_user : named_call_group : named_pickup_group : one_touch_recording : false outbound_auth : outbound_proxy : pickup_group : record_off_feature : automixmon record_on_feature : automixmon rewrite_contact : false rpid_immediate : false rtp_engine : asterisk rtp_ipv6 : false rtp_keepalive : 0 rtp_symmetric : false rtp_timeout : 0 rtp_timeout_hold : 0 sdp_owner : - sdp_session : Asterisk send_diversion : true send_pai : false send_rpid : false set_var : srtp_tag_32 : false sub_min_expiry : 0 t38_udptl : false t38_udptl_ec : none t38_udptl_ipv6 : false t38_udptl_maxdatagram : 0 t38_udptl_nat : false timers : yes timers_min_se : 90 timers_sess_expires : 1800 tone_zone : tos_audio : 0 tos_video : 0 transport : transport-ep trust_id_inbound : false trust_id_outbound : false use_avpf : false use_ptime : false user_eq_phone : false {noformat} after: {noformat} [Mar 29 22:19:12] WARNING[7846]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge. {noformat} pjsip show endpoint instance1: {noformat} ========================================================================================= Endpoint: instance1 Unknown 0 of inf Transport: transport-ep udp 0 0 0.0.0.0:5072 ParameterName : ParameterValue ==================================================== 100rel : yes accountcode : aggregate_mwi : true allow : (nothing) allow_subscribe : true allow_transfer : true aors : auth : call_group : callerid : <unknown> callerid_privacy : allowed_not_screened callerid_tag : connected_line_method : invite context : default cos_audio : 0 cos_video : 0 device_state_busy_at : 0 direct_media : true direct_media_glare_mitigation : none direct_media_method : invite disable_direct_media_on_nat : false dtls_ca_file : dtls_ca_path : dtls_cert_file : dtls_cipher : dtls_fingerprint : SHA-256 dtls_private_key : dtls_rekey : 0 dtls_setup : active dtls_verify : No dtmf_mode : rfc4733 fax_detect : false force_avp : false force_rport : true from_domain : from_user : g726_non_standard : false ice_support : false identify_by : username inband_progress : false language : mailboxes : media_address : media_encryption : no media_encryption_optimistic : false media_use_received_transport : false message_context : moh_suggest : default mwi_from_user : named_call_group : named_pickup_group : one_touch_recording : false outbound_auth : outbound_proxy : pickup_group : record_off_feature : automixmon record_on_feature : automixmon rewrite_contact : false rpid_immediate : false rtp_engine : asterisk rtp_ipv6 : false rtp_keepalive : 0 rtp_symmetric : false rtp_timeout : 0 rtp_timeout_hold : 0 sdp_owner : - sdp_session : Asterisk send_diversion : true send_pai : false send_rpid : false set_var : srtp_tag_32 : false sub_min_expiry : 0 t38_udptl : false t38_udptl_ec : none t38_udptl_ipv6 : false t38_udptl_maxdatagram : 0 t38_udptl_nat : false timers : yes timers_min_se : 90 timers_sess_expires : 1800 tone_zone : tos_audio : 0 tos_video : 0 transport : transport-ep trust_id_inbound : false trust_id_outbound : false use_avpf : false use_ptime : false user_eq_phone : false {noformat} By: Richard Mudgett (rmudgett) 2016-03-29 15:06:45.378-0500 [~cron333] Please do not paste configs and other large things into comments. Attach them as files instead. By: Alexei Gradinari (alexei gradinari) 2016-03-29 18:18:55.231-0500 One of your server (172.31.17.48) is behind NAT > Via: SIP/2.0/UDP 172.31.17.48:5072;rport=5072;received=52.29.123.238;branch=z9hG4bKPjb23c4846-ac5d-49db-a343-389c4633b883 Can you test without NAT? By: Vadim (cron333) 2016-03-30 02:13:17.829-0500 >Can you test without NAT? Unfortunately no. This is Amazon (AWS) >One of your server (172.31.17.48) is behind NAT Both servers are behind NAT (Full Cone NAT). They are both deployed on Amazon ... By: Alexei Gradinari (alexei gradinari) 2016-03-30 09:05:05.525-0500 I think you should configure authentication between instance1 and instance2. |