[2019-02-26 19:17:16] Asterisk 16.2.0 built by root @ freepbx.sangoma.local on a x86_64 running Linux on 2019-02-26 17:58:34 UTC [2019-02-26 19:17:16] VERBOSE[23365] logger.c: Asterisk Queue Logger restarted [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_config_curl.so' (Realtime Curl configuration) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_statsd.so' (Statsd client support) [2019-02-26 19:17:16] ERROR[23365] config_options.c: Unable to load config file 'statsd.conf' [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'cel' (CEL Engine) [2019-02-26 19:17:16] VERBOSE[23365] cel.c: CEL logging enabled. [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'dnsmgr' (DNS Manager) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'dsp' (DSP) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'enum' (ENUM Support) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'features' (Call Features) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'http' (Built-in HTTP Server) [2019-02-26 19:17:16] VERBOSE[23365] tcptls.c: TLS/SSL ECDH initialized (automatic), faster PFS ciphers enabled [2019-02-26 19:17:16] VERBOSE[23365] tcptls.c: TLS/SSL certificate ok [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'indications' (Indication Tone Handling) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'acl' (Named ACL system) [2019-02-26 19:17:16] ERROR[23365] config_options.c: Unable to load config file 'acl.conf' [2019-02-26 19:17:16] WARNING[23365] named_acl.c: Could not reload ACL config [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'manager' (Asterisk Manager Interface) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'plc' (PLC) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'udptl' (UDPTL) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjproject.so' (PJPROJECT Log and Utility Support) [2019-02-26 19:17:16] ERROR[23365] res_sorcery_config.c: Unable to load config file 'pjproject.conf' [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip.so' (Basic SIP resource) [2019-02-26 19:17:16] ERROR[22134] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] ERROR[22134] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] ERROR[22134] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] ERROR[22134] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] NOTICE[22134] sorcery.c: Type 'system' is not reloadable, maintaining previous values [2019-02-26 19:17:16] ERROR[22134] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_authenticator_digest.so' (PJSIP authentication resource) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_resolver_unbound.so' (Unbound DNS Resolver Support) [2019-02-26 19:17:16] ERROR[23365] config_options.c: Unable to load config file 'resolver_unbound.conf' [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_endpoint_identifier_ip.so' (PJSIP IP endpoint identifier) [2019-02-26 19:17:16] ERROR[23365] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_musiconhold.so' (Music On Hold Resource) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_crypto.so' (Cryptographic Digital Signatures) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_smdi.so' (Simplified Message Desk Interface (SMDI) Resource) [2019-02-26 19:17:16] NOTICE[23365] res_smdi.c: Unable to reload config smdi.conf: SMDI untouched [2019-02-26 19:17:16] WARNING[23365] res_smdi.c: No SMDI interfaces were specified to listen on, not starting SDMI listener. [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_xmpp.so' (Asterisk XMPP Interface) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_outbound_publish.so' (PJSIP Outbound Publish Support) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_rtp_asterisk.so' (Asterisk RTP Stack) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_publish_asterisk.so' (PJSIP Asterisk Event PUBLISH Support) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_mwi.so' (PJSIP MWI resource) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'chan_iax2.so' (Inter Asterisk eXchange (Ver 2)) [2019-02-26 19:17:16] NOTICE[23365] iax2/provision.c: No IAX provisioning configuration found, IAX provisioning disabled. [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'chan_sip.so' (Session Initiation Protocol (SIP)) [2019-02-26 19:17:16] VERBOSE[22167] chan_sip.c: Reloading SIP [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'chan_motif.so' (Motif Jingle Channel Driver) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_adsi.so' (ADSI Resource) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_fax.so' (Generic FAX Applications) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_outbound_registration.so' (PJSIP Outbound Registration Support) [2019-02-26 19:17:16] ERROR[23365] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_pjsip_notify.so' (CLI/AMI PJSIP NOTIFY Support) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_ari.so' (Asterisk RESTful Interface) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'codec_speex.so' (Speex Coder/Decoder) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'app_confbridge.so' (Conference Bridge Application) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_parking.so' (Call Parking Resource) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'cel_odbc.so' (ODBC CEL backend) [2019-02-26 19:17:16] VERBOSE[22167] netsock2.c: Using SIP TOS bits 96 [2019-02-26 19:17:16] VERBOSE[22167] netsock2.c: Using SIP CoS mark 4 [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found CEL table cel@asteriskcdrdb. [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found id column with type 4 with len 10, octetlen 10, and numlen (0,10) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found eventtype column with type -9 with len 30, octetlen 360, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found eventtime column with type 93 with len 19, octetlen 19, and numlen (0,10) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found cid_name column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found cid_num column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found cid_ani column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found cid_rdnis column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found cid_dnid column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found exten column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found context column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found channame column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found appname column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found appdata column with type -9 with len 255, octetlen 3060, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found amaflags column with type 4 with len 10, octetlen 10, and numlen (0,10) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found accountcode column with type -9 with len 20, octetlen 240, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found uniqueid column with type -9 with len 32, octetlen 384, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found linkedid column with type -9 with len 32, octetlen 384, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found peer column with type -9 with len 80, octetlen 960, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found userdeftype column with type -9 with len 255, octetlen 3060, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] cel_odbc.c: Found extra column with type -9 with len 512, octetlen 6144, and numlen (0,0) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'cel_manager.so' (Asterisk Manager Interface CEL Backend) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'app_voicemail.so' (Comedian Mail (Voicemail System)) [2019-02-26 19:17:16] WARNING[23365] app_voicemail.c: maxsilence should be less than minsecs or you may get empty messages [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'app_playback.so' (Sound File Playback Application) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'res_http_post.so' (HTTP POST support) [2019-02-26 19:17:16] VERBOSE[23365] loader.c: Reloading module 'app_queue.so' (True Call Queueing) [2019-02-26 19:17:16] NOTICE[23365] app_queue.c: queuerules.conf has not changed since it was last loaded. Not taking any action. [2019-02-26 19:17:34] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj0e7ee760-d9ba-48a8-9ce4-f2316f3d160b From: ;tag=ff8f7659-7983-49c5-a676-714dbb6cc117 To: Contact: Call-ID: c9ef21f0-c34d-437c-bb33-ae2dbae6117f CSeq: 60571 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:36] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:36] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj83862338-f5ea-4010-ae31-3c44f3da8b16 From: ;tag=dd4edaff-0546-4d94-8d57-2d764836c7f6 To: Contact: Call-ID: 173bc73e-d5ce-4625-89a7-7eb3f1091c40 CSeq: 28958 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:38] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj0e7ee760-d9ba-48a8-9ce4-f2316f3d160b From: ;tag=ff8f7659-7983-49c5-a676-714dbb6cc117 To: Contact: Call-ID: c9ef21f0-c34d-437c-bb33-ae2dbae6117f CSeq: 60571 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:38] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:39] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:39] VERBOSE[22133] res_pjsip_logger.c: <--- Received SIP request (807 bytes) from UDP:10.32.0.114:5060 ---> REGISTER sip:10.32.0.109:5060 SIP/2.0 Via: SIP/2.0/UDP 10.32.0.114;branch=z9hG4bKf61c164D5EBF72D From: "222" ;tag=1E842CEB-4EA81584 To: CSeq: 43 REGISTER Call-ID: 46c99a7f-4026a0d8-590afe61@10.32.0.114 Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" User-Agent: PolycomSoundPointIP-SPIP_670-UA/4.0.14.0987 Accept-Language: ru-ru,ru;q=0.9,en;q=0.8 Authorization: Digest username="222", realm="asterisk", nonce="1551208599/ce2a2766974de7594b9ce6b8e9882a46", qop=auth, cnonce="mdN4PgdTBg1ecw7", nc=00000003, opaque="69094e624a001e44", uri="sip:10.32.0.109:5060", response="24ef8458820c85d03659802e61919fd2", algorithm=MD5 Max-Forwards: 70 Expires: 30 Content-Length: 0 [2019-02-26 19:17:39] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP response (507 bytes) to UDP:10.32.0.114:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.32.0.114;rport=5060;received=10.32.0.114;branch=z9hG4bKf61c164D5EBF72D Call-ID: 46c99a7f-4026a0d8-590afe61@10.32.0.114 From: "222" ;tag=1E842CEB-4EA81584 To: ;tag=z9hG4bKf61c164D5EBF72D CSeq: 43 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1551208659/184855b22fd1cce08b30651572d764df",opaque="44f136c92965e3a1",stale=true,algorithm=md5,qop="auth" Server: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:39] VERBOSE[22133] res_pjsip_logger.c: <--- Received SIP request (808 bytes) from UDP:10.32.0.114:5060 ---> REGISTER sip:10.32.0.109:5060 SIP/2.0 Via: SIP/2.0/UDP 10.32.0.114;branch=z9hG4bK6f308126B07B204F From: "222" ;tag=1E842CEB-4EA81584 To: CSeq: 44 REGISTER Call-ID: 46c99a7f-4026a0d8-590afe61@10.32.0.114 Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" User-Agent: PolycomSoundPointIP-SPIP_670-UA/4.0.14.0987 Accept-Language: ru-ru,ru;q=0.9,en;q=0.8 Authorization: Digest username="222", realm="asterisk", nonce="1551208659/184855b22fd1cce08b30651572d764df", qop=auth, cnonce="h5F+cEcUdGUe3G3", nc=00000001, opaque="44f136c92965e3a1", uri="sip:10.32.0.109:5060", response="b18297fc8d0dd00ffa8210c126a29132", algorithm=MD5 Max-Forwards: 70 Expires: 30 Content-Length: 0 [2019-02-26 19:17:39] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP response (440 bytes) to UDP:10.32.0.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.32.0.114;rport=5060;received=10.32.0.114;branch=z9hG4bK6f308126B07B204F Call-ID: 46c99a7f-4026a0d8-590afe61@10.32.0.114 From: "222" ;tag=1E842CEB-4EA81584 To: ;tag=z9hG4bK6f308126B07B204F CSeq: 44 REGISTER Date: Tue, 26 Feb 2019 19:17:39 GMT Contact: ;expires=59 Expires: 60 Server: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:40] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:40] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:40] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj83862338-f5ea-4010-ae31-3c44f3da8b16 From: ;tag=dd4edaff-0546-4d94-8d57-2d764836c7f6 To: Contact: Call-ID: 173bc73e-d5ce-4625-89a7-7eb3f1091c40 CSeq: 28958 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:42] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:42] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj0e7ee760-d9ba-48a8-9ce4-f2316f3d160b From: ;tag=ff8f7659-7983-49c5-a676-714dbb6cc117 To: Contact: Call-ID: c9ef21f0-c34d-437c-bb33-ae2dbae6117f CSeq: 60571 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:44] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:46] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:46] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj0e7ee760-d9ba-48a8-9ce4-f2316f3d160b From: ;tag=ff8f7659-7983-49c5-a676-714dbb6cc117 To: Contact: Call-ID: c9ef21f0-c34d-437c-bb33-ae2dbae6117f CSeq: 60571 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:47] DEBUG[22144] res_pjsip_registrar.c: Woke up at 1551208667 Interval: 30 [2019-02-26 19:17:47] DEBUG[22144] res_pjsip_registrar.c: Expiring 0 contacts [2019-02-26 19:17:48] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:48] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying all contacts on AOR '222' [2019-02-26 19:17:48] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying contact '222;@a1314b083527d86d3f92b76cec5c0e25' on AOR '222' [2019-02-26 19:17:48] DEBUG[22134] res_pjsip.c: 0x7f8b88007da0: Wrapper created [2019-02-26 19:17:48] DEBUG[22134] res_pjsip.c: 0x7f8b88007da0: Set timer to 3000 msec [2019-02-26 19:17:48] DEBUG[22134] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.32.0.114' [2019-02-26 19:17:48] DEBUG[22134] res_pjsip/pjsip_resolver.c: Transport type for target '10.32.0.114' is 'UDP' [2019-02-26 19:17:48] DEBUG[22134] res_pjsip/pjsip_resolver.c: Target '10.32.0.114' is an IP address, skipping resolution [2019-02-26 19:17:48] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:49] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:50] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:50] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj0e7ee760-d9ba-48a8-9ce4-f2316f3d160b From: ;tag=ff8f7659-7983-49c5-a676-714dbb6cc117 To: Contact: Call-ID: c9ef21f0-c34d-437c-bb33-ae2dbae6117f CSeq: 60571 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:50] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:50] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: PJSIP tsx timer expired [2019-02-26 19:17:50] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: Timeout already handled [2019-02-26 19:17:50] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: wrapper destroyed [2019-02-26 19:17:51] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Internal tsx timer expired after 3000 msec [2019-02-26 19:17:51] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Timer handled here [2019-02-26 19:17:51] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Callbacks executed [2019-02-26 19:17:51] DEBUG[22134] res_pjsip/pjsip_options.c: Contact 222/sip:222@10.32.0.114:5060 status didn't change: Unreachable, RTT: 0.000 msec [2019-02-26 19:17:51] DEBUG[22134] res_pjsip/pjsip_options.c: AOR '222' now has 0 available contacts [2019-02-26 19:17:52] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:52] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:54] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:56] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:56] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:58] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:58] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying all contacts on AOR '222' [2019-02-26 19:17:58] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying contact '222;@a1314b083527d86d3f92b76cec5c0e25' on AOR '222' [2019-02-26 19:17:58] DEBUG[22134] res_pjsip.c: 0x7f8b88007d00: Wrapper created [2019-02-26 19:17:58] DEBUG[22134] res_pjsip.c: 0x7f8b88007d00: Set timer to 3000 msec [2019-02-26 19:17:58] DEBUG[22134] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.32.0.114' [2019-02-26 19:17:58] DEBUG[22134] res_pjsip/pjsip_resolver.c: Transport type for target '10.32.0.114' is 'UDP' [2019-02-26 19:17:58] DEBUG[22134] res_pjsip/pjsip_resolver.c: Target '10.32.0.114' is an IP address, skipping resolution [2019-02-26 19:17:58] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:17:59] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:00] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjeb03d278-5223-46bf-abfc-dcd37eaa0dfe From: ;tag=8a6b690f-2ac8-45b9-a2d6-66dd710cd4f2 To: Contact: Call-ID: eadd78cd-b0ed-4044-94ad-189334b411df CSeq: 48223 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:00] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:00] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:00] DEBUG[22133] res_pjsip.c: 0x7f8b88007930: PJSIP tsx timer expired [2019-02-26 19:18:00] DEBUG[22133] res_pjsip.c: 0x7f8b88007930: Timeout already handled [2019-02-26 19:18:00] DEBUG[22133] res_pjsip.c: 0x7f8b88007930: wrapper destroyed [2019-02-26 19:18:01] DEBUG[22165] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 2 instead [2019-02-26 19:18:01] DEBUG[22165] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 2 instead [2019-02-26 19:18:01] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: Internal tsx timer expired after 3000 msec [2019-02-26 19:18:01] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: Timer handled here [2019-02-26 19:18:01] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: Callbacks executed [2019-02-26 19:18:01] DEBUG[22165] res_timing_timerfd.c: Expected to acknowledge 1 ticks but got 2 instead [2019-02-26 19:18:01] DEBUG[22134] res_pjsip/pjsip_options.c: Contact 222/sip:222@10.32.0.114:5060 status didn't change: Unreachable, RTT: 0.000 msec [2019-02-26 19:18:01] DEBUG[22134] res_pjsip/pjsip_options.c: AOR '222' now has 0 available contacts [2019-02-26 19:18:01] DEBUG[23424] manager.c: Running action 'Login' [2019-02-26 19:18:01] DEBUG[23427] manager.c: Running action 'Login' [2019-02-26 19:18:01] DEBUG[23430] manager.c: Running action 'Login' [2019-02-26 19:18:02] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:02] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:04] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:06] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:06] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:08] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:08] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying all contacts on AOR '222' [2019-02-26 19:18:08] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying contact '222;@a1314b083527d86d3f92b76cec5c0e25' on AOR '222' [2019-02-26 19:18:08] DEBUG[22134] res_pjsip.c: 0x7f8b88007930: Wrapper created [2019-02-26 19:18:08] DEBUG[22134] res_pjsip.c: 0x7f8b88007930: Set timer to 3000 msec [2019-02-26 19:18:08] DEBUG[22134] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.32.0.114' [2019-02-26 19:18:08] DEBUG[22134] res_pjsip/pjsip_resolver.c: Transport type for target '10.32.0.114' is 'UDP' [2019-02-26 19:18:08] DEBUG[22134] res_pjsip/pjsip_resolver.c: Target '10.32.0.114' is an IP address, skipping resolution [2019-02-26 19:18:08] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:09] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:09] VERBOSE[22133] res_pjsip_logger.c: <--- Received SIP request (808 bytes) from UDP:10.32.0.114:5060 ---> REGISTER sip:10.32.0.109:5060 SIP/2.0 Via: SIP/2.0/UDP 10.32.0.114;branch=z9hG4bK8d34ca363FC4445F From: "222" ;tag=1E842CEB-4EA81584 To: CSeq: 45 REGISTER Call-ID: 46c99a7f-4026a0d8-590afe61@10.32.0.114 Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" User-Agent: PolycomSoundPointIP-SPIP_670-UA/4.0.14.0987 Accept-Language: ru-ru,ru;q=0.9,en;q=0.8 Authorization: Digest username="222", realm="asterisk", nonce="1551208659/184855b22fd1cce08b30651572d764df", qop=auth, cnonce="h5F+cEcUdGUe3G3", nc=00000002, opaque="44f136c92965e3a1", uri="sip:10.32.0.109:5060", response="f8ca56fe94713efb8c61abbea25d9aba", algorithm=MD5 Max-Forwards: 70 Expires: 30 Content-Length: 0 [2019-02-26 19:18:09] DEBUG[22133] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=45 (rdata0x7f8c0c002c28) [2019-02-26 19:18:09] DEBUG[22133] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000002c to use for Request msg REGISTER/cseq=45 (rdata0x7f8c0c002c28) [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '222' domain '10.32.0.109' [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_endpoint_identifier_user.c: Identified by From username '222' domain '10.32.0.109' [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '222-auth'. [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_authenticator_digest.c: Calculated nonce 1551208659/184855b22fd1cce08b30651572d764df. Actual nonce is 1551208659/184855b22fd1cce08b30651572d764df [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_registrar.c: Matched id '222' to aor '222' [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_registrar.c: Matched aor '222' by To username [2019-02-26 19:18:09] DEBUG[22134] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract uint from [10] in [0, 86400] gives [10](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [2019-02-26 19:18:09] DEBUG[22134] config.c: extract uint from [10] in [0, 86400] gives [10](0) [2019-02-26 19:18:09] DEBUG[22134] res_pjsip_registrar.c: Refreshed contact 'sip:222@10.32.0.114:5060' on AOR '222' with new expiration of 60 seconds [2019-02-26 19:18:09] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP response (440 bytes) to UDP:10.32.0.114:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.32.0.114;rport=5060;received=10.32.0.114;branch=z9hG4bK8d34ca363FC4445F Call-ID: 46c99a7f-4026a0d8-590afe61@10.32.0.114 From: "222" ;tag=1E842CEB-4EA81584 To: ;tag=z9hG4bK8d34ca363FC4445F CSeq: 45 REGISTER Date: Tue, 26 Feb 2019 19:18:09 GMT Contact: ;expires=59 Expires: 60 Server: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:10] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:10] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:10] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPjb3a70c3e-d719-4da2-bf6e-ac7d061617fc From: ;tag=34dd8bcd-dfd2-4de9-b2ac-09762068ad20 To: Contact: Call-ID: 4b14843f-5348-4da5-96b0-0e85ef4ed955 CSeq: 64035 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:10] DEBUG[22133] res_pjsip.c: 0x7f8b880074e0: PJSIP tsx timer expired [2019-02-26 19:18:10] DEBUG[22133] res_pjsip.c: 0x7f8b880074e0: Timeout already handled [2019-02-26 19:18:10] DEBUG[22133] res_pjsip.c: 0x7f8b880074e0: wrapper destroyed [2019-02-26 19:18:11] DEBUG[22133] res_pjsip.c: 0x7f8b88007930: Internal tsx timer expired after 3000 msec [2019-02-26 19:18:11] DEBUG[22133] res_pjsip.c: 0x7f8b88007930: Timer handled here [2019-02-26 19:18:11] DEBUG[22133] res_pjsip.c: 0x7f8b88007930: Callbacks executed [2019-02-26 19:18:11] DEBUG[22134] res_pjsip/pjsip_options.c: Contact 222/sip:222@10.32.0.114:5060 status didn't change: Unreachable, RTT: 0.000 msec [2019-02-26 19:18:11] DEBUG[22134] res_pjsip/pjsip_options.c: AOR '222' now has 0 available contacts [2019-02-26 19:18:12] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:12] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:14] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:16] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:16] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:16] DEBUG[23394] threadpool.c: Worker thread idle timeout reached. Dying. [2019-02-26 19:18:16] DEBUG[22089] threadpool.c: Destroying worker thread 11 [2019-02-26 19:18:16] DEBUG[23397] threadpool.c: Worker thread idle timeout reached. Dying. [2019-02-26 19:18:16] DEBUG[23399] threadpool.c: Worker thread idle timeout reached. Dying. [2019-02-26 19:18:16] DEBUG[22131] threadpool.c: Destroying worker thread 14 [2019-02-26 19:18:16] DEBUG[22131] threadpool.c: Destroying worker thread 16 [2019-02-26 19:18:16] DEBUG[23396] threadpool.c: Worker thread idle timeout reached. Dying. [2019-02-26 19:18:16] DEBUG[23395] threadpool.c: Worker thread idle timeout reached. Dying. [2019-02-26 19:18:16] DEBUG[22131] threadpool.c: Destroying worker thread 13 [2019-02-26 19:18:16] DEBUG[22131] threadpool.c: Destroying worker thread 12 [2019-02-26 19:18:16] DEBUG[23398] threadpool.c: Worker thread idle timeout reached. Dying. [2019-02-26 19:18:16] DEBUG[22131] threadpool.c: Destroying worker thread 15 [2019-02-26 19:18:17] DEBUG[22144] res_pjsip_registrar.c: Woke up at 1551208697 Interval: 30 [2019-02-26 19:18:17] DEBUG[22144] res_pjsip_registrar.c: Expiring 0 contacts [2019-02-26 19:18:18] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:18] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying all contacts on AOR '222' [2019-02-26 19:18:18] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying contact '222;@a1314b083527d86d3f92b76cec5c0e25' on AOR '222' [2019-02-26 19:18:18] DEBUG[22134] res_pjsip.c: 0x7f8b880074e0: Wrapper created [2019-02-26 19:18:18] DEBUG[22134] res_pjsip.c: 0x7f8b880074e0: Set timer to 3000 msec [2019-02-26 19:18:18] DEBUG[22134] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.32.0.114' [2019-02-26 19:18:18] DEBUG[22134] res_pjsip/pjsip_resolver.c: Transport type for target '10.32.0.114' is 'UDP' [2019-02-26 19:18:18] DEBUG[22134] res_pjsip/pjsip_resolver.c: Target '10.32.0.114' is an IP address, skipping resolution [2019-02-26 19:18:18] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj40d06a56-dbe4-49cb-8653-d612c898bcfc From: ;tag=343fece6-76f8-47e8-aeab-b60bbd4b94ef To: Contact: Call-ID: 6b8d2099-96ed-44b0-a99e-e1599c34cced CSeq: 58187 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:19] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj40d06a56-dbe4-49cb-8653-d612c898bcfc From: ;tag=343fece6-76f8-47e8-aeab-b60bbd4b94ef To: Contact: Call-ID: 6b8d2099-96ed-44b0-a99e-e1599c34cced CSeq: 58187 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:20] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:20] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj40d06a56-dbe4-49cb-8653-d612c898bcfc From: ;tag=343fece6-76f8-47e8-aeab-b60bbd4b94ef To: Contact: Call-ID: 6b8d2099-96ed-44b0-a99e-e1599c34cced CSeq: 58187 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:20] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj6f00229c-8002-424b-a913-6dca3707dc75 From: ;tag=0d93532d-72fd-49fc-bb53-050f9f3a02c0 To: Contact: Call-ID: a4093629-a0e7-4a54-8a67-db0313bc1e81 CSeq: 49026 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:20] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: PJSIP tsx timer expired [2019-02-26 19:18:20] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Timeout already handled [2019-02-26 19:18:20] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: wrapper destroyed [2019-02-26 19:18:21] DEBUG[22133] res_pjsip.c: 0x7f8b880074e0: Internal tsx timer expired after 3000 msec [2019-02-26 19:18:21] DEBUG[22133] res_pjsip.c: 0x7f8b880074e0: Timer handled here [2019-02-26 19:18:21] DEBUG[22133] res_pjsip.c: 0x7f8b880074e0: Callbacks executed [2019-02-26 19:18:21] DEBUG[22134] res_pjsip/pjsip_options.c: Contact 222/sip:222@10.32.0.114:5060 status didn't change: Unreachable, RTT: 0.000 msec [2019-02-26 19:18:21] DEBUG[22134] res_pjsip/pjsip_options.c: AOR '222' now has 0 available contacts [2019-02-26 19:18:22] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj40d06a56-dbe4-49cb-8653-d612c898bcfc From: ;tag=343fece6-76f8-47e8-aeab-b60bbd4b94ef To: Contact: Call-ID: 6b8d2099-96ed-44b0-a99e-e1599c34cced CSeq: 58187 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:22] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:22] DEBUG[23462] manager.c: Running action 'Login' [2019-02-26 19:18:24] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:26] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:26] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj40d06a56-dbe4-49cb-8653-d612c898bcfc From: ;tag=343fece6-76f8-47e8-aeab-b60bbd4b94ef To: Contact: Call-ID: 6b8d2099-96ed-44b0-a99e-e1599c34cced CSeq: 58187 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:28] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:28] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying all contacts on AOR '222' [2019-02-26 19:18:28] DEBUG[22134] res_pjsip/pjsip_options.c: Qualifying contact '222;@a1314b083527d86d3f92b76cec5c0e25' on AOR '222' [2019-02-26 19:18:28] DEBUG[22134] res_pjsip.c: 0x7f8b88007da0: Wrapper created [2019-02-26 19:18:28] DEBUG[22134] res_pjsip.c: 0x7f8b88007da0: Set timer to 3000 msec [2019-02-26 19:18:28] DEBUG[22134] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '10.32.0.114' [2019-02-26 19:18:28] DEBUG[22134] res_pjsip/pjsip_resolver.c: Transport type for target '10.32.0.114' is 'UDP' [2019-02-26 19:18:28] DEBUG[22134] res_pjsip/pjsip_resolver.c: Target '10.32.0.114' is an IP address, skipping resolution [2019-02-26 19:18:28] VERBOSE[22134] res_pjsip_logger.c: <--- Transmitting SIP request (412 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj487f0ca4-c3af-461f-a1aa-b878c84649df From: ;tag=60fc6b00-8f00-44c6-b3b8-69e98d3b17f7 To: Contact: Call-ID: 6b2a2540-884c-4810-91ac-ca4f01f2b7e3 CSeq: 1490 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:29] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (412 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj487f0ca4-c3af-461f-a1aa-b878c84649df From: ;tag=60fc6b00-8f00-44c6-b3b8-69e98d3b17f7 To: Contact: Call-ID: 6b2a2540-884c-4810-91ac-ca4f01f2b7e3 CSeq: 1490 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:30] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj40d06a56-dbe4-49cb-8653-d612c898bcfc From: ;tag=343fece6-76f8-47e8-aeab-b60bbd4b94ef To: Contact: Call-ID: 6b8d2099-96ed-44b0-a99e-e1599c34cced CSeq: 58187 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:30] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (412 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj487f0ca4-c3af-461f-a1aa-b878c84649df From: ;tag=60fc6b00-8f00-44c6-b3b8-69e98d3b17f7 To: Contact: Call-ID: 6b2a2540-884c-4810-91ac-ca4f01f2b7e3 CSeq: 1490 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:30] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj46fefbdb-a97f-4ec3-b6ee-fbb214684fa3 From: ;tag=427dc504-ecc7-4d79-8321-4e1377b90507 To: Contact: Call-ID: e0274977-24dc-45d2-b6f4-6250f911f115 CSeq: 557 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:30] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: PJSIP tsx timer expired [2019-02-26 19:18:30] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: Timeout already handled [2019-02-26 19:18:30] DEBUG[22133] res_pjsip.c: 0x7f8b88007d00: wrapper destroyed [2019-02-26 19:18:31] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Internal tsx timer expired after 3000 msec [2019-02-26 19:18:31] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Timer handled here [2019-02-26 19:18:31] DEBUG[22133] res_pjsip.c: 0x7f8b88007da0: Callbacks executed [2019-02-26 19:18:31] DEBUG[22134] res_pjsip/pjsip_options.c: Contact 222/sip:222@10.32.0.114:5060 status didn't change: Unreachable, RTT: 0.000 msec [2019-02-26 19:18:31] DEBUG[22134] res_pjsip/pjsip_options.c: AOR '222' now has 0 available contacts [2019-02-26 19:18:32] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (412 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPj487f0ca4-c3af-461f-a1aa-b878c84649df From: ;tag=60fc6b00-8f00-44c6-b3b8-69e98d3b17f7 To: Contact: Call-ID: 6b2a2540-884c-4810-91ac-ca4f01f2b7e3 CSeq: 1490 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:32] VERBOSE[22133] res_pjsip_logger.c: <--- Transmitting SIP request (413 bytes) to UDP:10.32.0.114:5060 ---> OPTIONS sip:222@10.32.0.114:5060 SIP/2.0 Via: SIP/2.0/UDP 10.55.55.10:5060;rport;branch=z9hG4bKPja917f974-3d1c-4c57-bbea-a2c93b89b142 From: ;tag=322cee35-27fe-41dc-ac45-e808df9c8742 To: Contact: Call-ID: f292676f-b8b8-4793-8606-5dadf5837057 CSeq: 48927 OPTIONS Max-Forwards: 70 User-Agent: FPBX-14.0.3.1(16.2.0) Content-Length: 0 [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command' [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command' [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command' [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command' [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command' [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command' [2019-02-26 19:18:32] DEBUG[23430] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [2019-02-26 19:18:32] DEBUG[23430] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [2019-02-26 19:18:32] DEBUG[23430] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [2019-02-26 19:18:32] DEBUG[23430] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [2019-02-26 19:18:32] DEBUG[23430] config.c: extract uint from [10] in [0, 86400] gives [10](0) [2019-02-26 19:18:32] DEBUG[23430] manager.c: Running action 'Command'