[Jul 28 16:06:59] Asterisk 13.10.0 built by user @ debian on a x86_64 running Linux on 2016-07-28 10:56:37 UTC [Jul 28 16:06:59] VERBOSE[1794] config.c: Parsing '/etc/asterisk/logger.conf': Found [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action DBGet [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action DBPut [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action DBDel [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action DBDelTree [Jul 28 16:06:59] VERBOSE[1794] message.c: Message handler 'dialplan' registered. [Jul 28 16:06:59] VERBOSE[1794] pbx_functions.c: Registered custom function 'MESSAGE' [Jul 28 16:06:59] VERBOSE[1794] pbx_functions.c: Registered custom function 'MESSAGE_DATA' [Jul 28 16:06:59] VERBOSE[1794] pbx_app.c: Registered application 'MessageSend' [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action MessageSend [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action DataGet [Jul 28 16:06:59] VERBOSE[1794] channel.c: Registered channel type 'Surrogate' (Surrogate channel used to pull channel from an application) [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action BridgeTechnologyList [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action BridgeTechnologySuspend [Jul 28 16:06:59] VERBOSE[1794] manager.c: Manager registered action BridgeTechnologyUnsuspend [Jul 28 16:06:59] VERBOSE[1794] loader.c: Asterisk Dynamic Loader Starting: [Jul 28 16:06:59] VERBOSE[1794] config.c: Parsing '/etc/asterisk/modules.conf': Found [Jul 28 16:07:00] ERROR[1794] config_options.c: Unable to load config file 'features.conf' [Jul 28 16:07:00] NOTICE[1794] features_config.c: Could not load features config; using defaults [Jul 28 16:07:00] VERBOSE[1794] pbx_functions.c: Registered custom function 'FEATURE' [Jul 28 16:07:00] VERBOSE[1794] pbx_functions.c: Registered custom function 'FEATUREMAP' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Bridge' [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Bridge [Jul 28 16:07:00] ERROR[1794] config_options.c: Unable to load config file 'acl.conf' [Jul 28 16:07:00] WARNING[1794] indications.c: Can't find indications config file indications.conf. [Jul 28 16:07:00] ERROR[1794] config_options.c: Unable to load config file 'cdr.conf' [Jul 28 16:07:00] NOTICE[1794] cdr.c: Failed to process CDR configuration; using defaults [Jul 28 16:07:00] NOTICE[1794] cdr.c: CDR simple logging enabled. [Jul 28 16:07:00] ERROR[1794] config_options.c: Unable to load config file 'udptl.conf' [Jul 28 16:07:00] NOTICE[1794] udptl.c: Could not load udptl config; using defaults [Jul 28 16:07:00] VERBOSE[1794] pbx.c: Asterisk PBX Core Initializing [Jul 28 16:07:00] VERBOSE[1794] pbx.c: Registering builtin functions: [Jul 28 16:07:00] VERBOSE[1794] pbx_functions.c: Registered custom function 'EXCEPTION' [Jul 28 16:07:00] VERBOSE[1794] pbx_functions.c: Registered custom function 'TESTTIME' [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ShowDialPlan [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ExtensionStateList [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Answer' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'BackGround' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Busy' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Congestion' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'ExecIfTime' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Goto' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'GotoIf' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'GotoIfTime' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'ImportVar' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Hangup' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Incomplete' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'NoOp' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Proceeding' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Progress' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'RaiseException' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Ringing' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'SayAlpha' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'SayAlphaCase' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'SayDigits' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'SayNumber' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'SayPhonetic' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'SetAMAFlags' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Wait' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'WaitExten' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'Set' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'MSet' [Jul 28 16:07:00] VERBOSE[1794] channel.c: Registered channel type 'Local' (Local Proxy Channel Driver) [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action LocalOptimizeAway [Jul 28 16:07:00] ERROR[1794] config_options.c: Unable to load config file 'cel.conf' [Jul 28 16:07:00] NOTICE[1794] cel.c: Failed to process CEL configuration; using defaults [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Ping [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Events [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Logoff [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Login [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Challenge [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Hangup [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Status [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Setvar [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Getvar [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action GetConfig [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action GetConfigJSON [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action UpdateConfig [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action CreateConfig [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ListCategories [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Redirect [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Atxfer [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Originate [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Command [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ExtensionState [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action PresenceState [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action AbsoluteTimeout [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action MailboxStatus [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action MailboxCount [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ListCommands [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action SendText [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action UserEvent [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action WaitEvent [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action CoreSettings [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action CoreStatus [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Reload [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action LoggerRotate [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action CoreShowChannels [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ModuleLoad [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action ModuleCheck [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action AOCMessage [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action Filter [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action BlindTransfer [Jul 28 16:07:00] VERBOSE[1794] pbx_functions.c: Registered custom function 'AMI_CLIENT' [Jul 28 16:07:00] NOTICE[1794] manager.c: Unable to open AMI configuration manager.conf, or configuration is invalid. [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'CallCompletionRequest' [Jul 28 16:07:00] VERBOSE[1794] pbx_app.c: Registered application 'CallCompletionCancel' [Jul 28 16:07:00] WARNING[1794] ccss.c: Could not find valid ccss.conf file. Using cc_max_requests default [Jul 28 16:07:00] WARNING[1794] ccss.c: Could not find valid ccss.conf file. Using cc_[state]_devstate defaults [Jul 28 16:07:00] VERBOSE[1794] loader.c: Asterisk Dynamic Loader Starting: [Jul 28 16:07:00] VERBOSE[1794] config.c: Parsing '/etc/asterisk/modules.conf': Found [Jul 28 16:07:00] NOTICE[1794] loader.c: 280 modules will be loaded. [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_statsd.so. [Jul 28 16:07:00] ERROR[1794] config_options.c: Unable to load config file 'statsd.conf' [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_pjsip_config_wizard.so. [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_pjsip_config_wizard.so => (PJSIP Config Wizard) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_sorcery_realtime.so. [Jul 28 16:07:00] VERBOSE[1794] sorcery.c: Sorcery registered wizard 'realtime' [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_sorcery_realtime.so => (Sorcery Realtime Object Wizard) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_sorcery_config.so. [Jul 28 16:07:00] VERBOSE[1794] sorcery.c: Sorcery registered wizard 'config' [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_sorcery_config.so => (Sorcery Configuration File Object Wizard) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_sorcery_memory_cache.so. [Jul 28 16:07:00] VERBOSE[1794] sorcery.c: Sorcery registered wizard 'memory_cache' [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action SorceryMemoryCacheExpireObject [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action SorceryMemoryCacheExpire [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action SorceryMemoryCacheStaleObject [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action SorceryMemoryCacheStale [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action SorceryMemoryCachePopulate [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_sorcery_memory_cache.so => (Sorcery Memory Cache Object Wizard) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_sorcery_memory.so. [Jul 28 16:07:00] VERBOSE[1794] sorcery.c: Sorcery registered wizard 'memory' [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_sorcery_memory.so => (Sorcery In-Memory Object Wizard) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_sorcery_astdb.so. [Jul 28 16:07:00] VERBOSE[1794] sorcery.c: Sorcery registered wizard 'astdb' [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_sorcery_astdb.so => (Sorcery Astdb Object Wizard) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_pjproject.so. [Jul 28 16:07:00] ERROR[1794] res_sorcery_config.c: Unable to load config file 'pjproject.conf' [Jul 28 16:07:00] VERBOSE[1794] loader.c: res_pjproject.so => (PJPROJECT Log and Utility Support) [Jul 28 16:07:00] VERBOSE[1794] loader.c: Loading res_pjsip.so. [Jul 28 16:07:00] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:00] VERBOSE[1794] res_pjsip.c: Local IPv4 address determined to be: 10.20.51.125 [Jul 28 16:07:00] VERBOSE[1794] res_pjsip.c: Local IPv6 address determined to be: [fe80::a00:27ff:fe86:ad35] [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action PJSIPShowEndpoints [Jul 28 16:07:00] VERBOSE[1794] manager.c: Manager registered action PJSIPShowEndpoint [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] ERROR[1794] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] ERROR[1794] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] res_pjsip/pjsip_configuration.c: Endpoint 123 is now Reachable [Jul 28 16:07:01] VERBOSE[1794] res_pjsip/pjsip_configuration.c: Endpoint 124 is now Reachable [Jul 28 16:07:01] ERROR[1794] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPQualify [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip.so => (Basic SIP resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_smdi.so. [Jul 28 16:07:01] NOTICE[1794] res_smdi.c: Unable to load config smdi.conf: SMDI disabled [Jul 28 16:07:01] NOTICE[1794] res_smdi.c: No SMDI interfaces are available to listen on, not starting SMDI listener. [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_phoneprov.so. [Jul 28 16:07:01] ERROR[1794] res_phoneprov.c: Unable to load config phoneprov.conf [Jul 28 16:07:01] ERROR[1794] res_phoneprov.c: Unable to load provisioning profiles. [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_pubsub.so. [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPShowSubscriptionsInbound [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPShowSubscriptionsOutbound [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPShowResourceLists [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_pubsub.so => (PJSIP event resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_rtp_multicast.so. [Jul 28 16:07:01] VERBOSE[1794] rtp_engine.c: Registered RTP engine 'multicast' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_rtp_multicast.so => (Multicast RTP Engine) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_http_websocket.so. [Jul 28 16:07:01] VERBOSE[1794] res_http_websocket.c: WebSocket registered sub-protocol 'echo' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_http_websocket.so => (HTTP WebSocket Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_monitor.so. [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'Monitor' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'StopMonitor' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'ChangeMonitor' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'PauseMonitor' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'UnpauseMonitor' [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action Monitor [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action StopMonitor [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action ChangeMonitor [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PauseMonitor [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action UnpauseMonitor [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_monitor.so => (Call Monitoring Resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_outbound_publish.so. [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_outbound_publish.so => (PJSIP Outbound Publish Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stun_monitor.so. [Jul 28 16:07:01] WARNING[1794] res_stun_monitor.c: Unable to load config res_stun_monitor.conf [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_crypto.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_crypto.so => (Cryptographic Digital Signatures) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_agi.so. [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'answer' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'asyncagi break' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'channel status' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'database del' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'database deltree' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'database get' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'database put' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'exec' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'get data' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'get full variable' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'get option' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'get variable' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'hangup' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'noop' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'receive char' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'receive text' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'record file' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say alpha' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say digits' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say number' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say phonetic' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say date' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say time' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'say datetime' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'send image' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'send text' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set autohangup' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set callerid' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set context' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set extension' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set music' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set priority' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'set variable' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'stream file' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'control stream file' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'tdd mode' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'verbose' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'wait for digit' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech create' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech set' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech destroy' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech load grammar' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech unload grammar' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech activate grammar' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech deactivate grammar' registered [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'speech recognize' registered [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'DeadAGI' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'EAGI' [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action AGI [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'AGI' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_agi.so => (Asterisk Gateway Interface (AGI)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_speech.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_speech.so => (Generic Speech Recognition API) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_session.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_session.so => (PJSIP Session resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_hep.so. [Jul 28 16:07:01] ERROR[1794] config_options.c: Unable to load config file 'hep.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_ari.so. [Jul 28 16:07:01] ERROR[1794] config_options.c: Unable to load config file 'ari.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_ari_model.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_ari_model.so => (ARI Model validators) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stasis_recording.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_stasis_recording.so => (Stasis application recording support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_fax.so. [Jul 28 16:07:01] NOTICE[1794] res_fax.c: Configuration file 'res_fax.conf' not found, using default options. [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'SendFAX' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'ReceiveFAX' [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action FAXSessions [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action FAXSession [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action FAXStats [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'FAXOPT' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_fax.so => (Generic FAX Applications) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_calendar.so. [Jul 28 16:07:01] ERROR[1794] res_calendar.c: Unable to load config calendar.conf [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stasis_snoop.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_stasis_snoop.so => (Stasis application snoop support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading func_periodic_hook.so. [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Registered extension context '__func_periodic_hook_context__'; registrar: func_periodic_hook [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'hook' priority 1 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'hook' priority 2 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'hook' priority 3 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'hook' priority 4 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'hook' priority 5 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'hook' priority 6 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'beep' priority 1 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx.c: Added extension 'beep' priority 2 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'PERIODIC_HOOK' [Jul 28 16:07:01] VERBOSE[1794] loader.c: func_periodic_hook.so => (Periodic dialplan hooks.) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stasis_answer.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_stasis_answer.so => (Stasis application answer support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stasis_playback.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_stasis_playback.so => (Stasis application playback support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stasis_device_state.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_stasis_device_state.so => (Stasis application device state support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_stasis.so. [Jul 28 16:07:01] VERBOSE[1794] message.c: Message handler 'ari' registered. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_stasis.so => (Stasis application support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_ael_share.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_ael_share.so => (share-able code for AEL) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_parking.so. [Jul 28 16:07:01] ERROR[1794] config_options.c: Unable to load config file 'res_parking.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_config_sqlite3.so. [Jul 28 16:07:01] ERROR[1794] res_config_sqlite3.c: Missing config file 'res_config_sqlite3.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_config_sqlite3.so => (SQLite 3 realtime config engine) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_timing_pthread.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_timing_pthread.so => (pthread Timing Interface) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_timing_timerfd.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_timing_timerfd.so => (Timerfd Timing Interface) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_authenticator_digest.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_authenticator_digest.so => (PJSIP authentication resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_transport_management.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_transport_management.so => (PJSIP Reliable Transport Management) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_endpoint_identifier_ip.so. [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] ERROR[1794] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_endpoint_identifier_ip.so => (PJSIP IP endpoint identifier) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_endpoint_identifier_user.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_endpoint_identifier_user.so => (PJSIP username endpoint identifier) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_registrar.so. [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPShowRegistrationsInbound [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_registrar.so => (PJSIP Registrar Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_xpidf_body_generator.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_xpidf_body_generator.so => (PJSIP Extension State PIDF Provider) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_format_attr_opus.so. [Jul 28 16:07:01] VERBOSE[1794] format.c: Registered format interface for codec 'opus' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_format_attr_opus.so => (Opus Format Attribute Module) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_dialog_info_body_generator.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_dialog_info_body_generator.so => (PJSIP Extension State Dialog Info+XML Provider) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_format_attr_vp8.so. [Jul 28 16:07:01] VERBOSE[1794] format.c: Registered format interface for codec 'vp8' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_format_attr_vp8.so => (VP8 Format Attribute Module) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_mwi_body_generator.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_mwi_body_generator.so => (PJSIP MWI resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_outbound_authenticator_digest.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_outbound_authenticator_digest.so => (PJSIP authentication resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_pidf_eyebeam_body_supplement.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_pidf_eyebeam_body_supplement.so => (PJSIP PIDF Eyebeam supplement) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_format_attr_silk.so. [Jul 28 16:07:01] VERBOSE[1794] format.c: Registered format interface for codec 'silk' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_format_attr_silk.so => (SILK Format Attribute Module) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_pidf_body_generator.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_pidf_body_generator.so => (PJSIP Extension State PIDF Provider) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_format_attr_celt.so. [Jul 28 16:07:01] VERBOSE[1794] format.c: Registered format interface for codec 'celt' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_format_attr_celt.so => (CELT Format Attribute Module) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_musiconhold.so. [Jul 28 16:07:01] WARNING[1794] res_musiconhold.c: No music on hold classes configured, disabling music on hold. [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'MusicOnHold' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'StartMusicOnHold' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'StopMusicOnHold' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_musiconhold.so => (Music On Hold Resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_pidf_digium_body_supplement.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_pidf_digium_body_supplement.so => (PJSIP PIDF Digium presence supplement) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_rtp_asterisk.so. [Jul 28 16:07:01] VERBOSE[1794] rtp_engine.c: Registered RTP engine 'asterisk' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_rtp_asterisk.so => (Asterisk RTP Stack) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_mwi.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_mwi.so => (PJSIP MWI resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_exten_state.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_exten_state.so => (PJSIP Extension State Notifications) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_publish_asterisk.so. [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_publish_asterisk.so => (PJSIP Asterisk Event PUBLISH Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_sdp_rtp.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_sdp_rtp.so => (PJSIP SDP RTP/AVP stream handler) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading chan_pjsip.so. [Jul 28 16:07:01] VERBOSE[1794] rtp_engine.c: Registered RTP glue 'PJSIP' [Jul 28 16:07:01] VERBOSE[1794] channel.c: Registered channel type 'PJSIP' (PJSIP Channel Driver) [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'PJSIP_DIAL_CONTACTS' [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'PJSIP_MEDIA_OFFER' [Jul 28 16:07:01] VERBOSE[1794] loader.c: chan_pjsip.so => (PJSIP Channel Driver) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_t38.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_t38.so => (PJSIP T.38 UDPTL Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading chan_skinny.so. [Jul 28 16:07:01] NOTICE[1794] chan_skinny.c: Configuring skinny from skinny.conf [Jul 28 16:07:01] NOTICE[1794] chan_skinny.c: Unable to load config skinny.conf, Skinny disabled. [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading chan_iax2.so. [Jul 28 16:07:01] ERROR[1794] chan_iax2.c: Unable to load config iax.conf [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading chan_rtp.so. [Jul 28 16:07:01] VERBOSE[1794] channel.c: Registered channel type 'MulticastRTP' (Multicast RTP Paging Channel Driver) [Jul 28 16:07:01] VERBOSE[1794] channel.c: Registered channel type 'UnicastRTP' (Unicast RTP Media Channel Driver) [Jul 28 16:07:01] VERBOSE[1794] loader.c: chan_rtp.so => (RTP Media Channel) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading chan_sip.so. [Jul 28 16:07:01] VERBOSE[1794] chan_sip.c: SIP channel loading... [Jul 28 16:07:01] NOTICE[1794] chan_sip.c: Unable to load config sip.conf [Jul 28 16:07:01] ERROR[1794] message.c: No 'sip' message technology found. [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading chan_mgcp.so. [Jul 28 16:07:01] NOTICE[1794] chan_mgcp.c: Unable to load config mgcp.conf, MGCP disabled [Jul 28 16:07:01] VERBOSE[1794] channel.c: Registered channel type 'MGCP' (Media Gateway Control Protocol (MGCP)) [Jul 28 16:07:01] VERBOSE[1794] rtp_engine.c: Registered RTP glue 'MGCP' [Jul 28 16:07:01] VERBOSE[1794] loader.c: chan_mgcp.so => (Media Gateway Control Protocol (MGCP)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_logger.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_logger.so => (PJSIP Packet Logger) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_transport_websocket.so. [Jul 28 16:07:01] VERBOSE[1794] res_http_websocket.c: WebSocket registered sub-protocol 'sip' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_transport_websocket.so => (PJSIP WebSocket Transport Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_notify.so. [Jul 28 16:07:01] ERROR[1794] config_options.c: Unable to load config file 'pjsip_notify.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_wav.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format wav, extension(s) wav [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format wav16, extension(s) wav16 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_wav.so => (Microsoft WAV/WAV16 format (8kHz/16kHz Signed Linear)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_dtmf_info.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_dtmf_info.so => (PJSIP DTMF INFO Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_g729.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g729, extension(s) g729 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_g729.so => (Raw G.729 data) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_path.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_path.so => (PJSIP Path Header Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_adsi.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_adsi.so => (ADSI Resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_refer.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_refer.so => (PJSIP Blind and Attended Transfer Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_sips_contact.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_sips_contact.so => (UAC SIPS Contact support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_diversion.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_diversion.so => (PJSIP Add Diversion Header Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_multihomed.so. [Jul 28 16:07:01] VERBOSE[1794] res_pjsip_multihomed.c: Performing DNS resolution of local hostname 'debian' to get local IPv4 and IPv6 address [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_multihomed.so => (PJSIP Multihomed Routing Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_h264.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format h264, extension(s) h264 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_h264.so => (Raw H.264 data) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_caller_id.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_caller_id.so => (PJSIP Caller ID Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_h263.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format h263, extension(s) h263 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_h263.so => (Raw H.263 data) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_gsm.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format gsm, extension(s) gsm [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_gsm.so => (Raw GSM data) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_ilbc.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format iLBC, extension(s) ilbc [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_ilbc.so => (Raw iLBC data) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_acl.so. [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_acl.so => (PJSIP ACL Resource) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_history.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_history.so => (PJSIP History) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_one_touch_record_info.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_one_touch_record_info.so => (PJSIP INFO One Touch Recording Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_nat.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_nat.so => (PJSIP NAT Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_outbound_registration.so. [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPUnregister [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPRegister [Jul 28 16:07:01] VERBOSE[1794] manager.c: Manager registered action PJSIPShowRegistrationsOutbound [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] ERROR[1794] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_outbound_registration.so => (PJSIP Outbound Registration Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_siren14.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format siren14, extension(s) siren14 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_siren14.so => (ITU G.722.1 Annex C (Siren14, licensed from Polycom)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_send_to_voicemail.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_send_to_voicemail.so => (PJSIP REFER Send to Voicemail Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_registrar_expire.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_registrar_expire.so => (PJSIP Contact Auto-Expiration) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_rfc3326.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_rfc3326.so => (PJSIP RFC3326 Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_g726.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g726-40, extension(s) g726-40 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g726-32, extension(s) g726-32 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g726-24, extension(s) g726-24 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g726-16, extension(s) g726-16 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_g726.so => (Raw G.726 (16/24/32/40kbps) data) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_header_funcs.so. [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'PJSIP_HEADER' [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_header_funcs.so => (PJSIP Header Functions) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_sln.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln, extension(s) sln|raw [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln12, extension(s) sln12 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln16, extension(s) sln16 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln24, extension(s) sln24 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln32, extension(s) sln32 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln44, extension(s) sln44 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln48, extension(s) sln48 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln96, extension(s) sln96 [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format sln192, extension(s) sln192 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_sln.so => (Raw Signed Linear Audio support (SLN) 8khz-192khz) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_dlg_options.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_dlg_options.so => (SIP OPTIONS in dialog handler) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_empty_info.so. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_empty_info.so => (PJSIP Empty INFO Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_pcm.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format pcm, extension(s) pcm|ulaw|ul|mu|ulw [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format alaw, extension(s) alaw|al|alw [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format au, extension(s) au [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g722, extension(s) g722 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_pcm.so => (Raw/Sun uLaw/ALaw 8KHz (PCM,PCMA,AU), G.722 16Khz) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_jpeg.so. [Jul 28 16:07:01] VERBOSE[1794] image.c: Registered format 'jpg' (JPEG (Joint Picture Experts Group)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_jpeg.so => (jpeg (joint picture experts group) image format) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_phoneprov_provider.so. [Jul 28 16:07:01] VERBOSE[1794] config.c: Parsing '/etc/asterisk/pjsip.conf': Found [Jul 28 16:07:01] ERROR[1794] res_pjsip_config_wizard.c: Unable to load config file 'pjsip_wizard.conf' [Jul 28 16:07:01] WARNING[1794] res_phoneprov.c: Provider 'res_pjsip_phoneprov_provider' cannot be registered: res_phoneprov not loaded. [Jul 28 16:07:01] ERROR[1794] res_pjsip_phoneprov_provider.c: Unable to register pjsip phoneprov provider. [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_vox.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format vox, extension(s) vox [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_vox.so => (Dialogic VOX (ADPCM) File Format) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading func_dialplan.so. [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'DIALPLAN_EXISTS' [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'VALID_EXTEN' [Jul 28 16:07:01] VERBOSE[1794] loader.c: func_dialplan.so => (Dialplan Context/Extension/Priority Checking Functions) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_g723.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g723sf, extension(s) g723|g723sf [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_g723.so => (G.723.1 Simple Timestamp File Format) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_g719.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format g719, extension(s) g719 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_g719.so => (ITU G.719) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading res_pjsip_messaging.so. [Jul 28 16:07:01] VERBOSE[1794] message.c: Message technology 'pjsip' registered. [Jul 28 16:07:01] VERBOSE[1794] loader.c: res_pjsip_messaging.so => (PJSIP Messaging Support) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_wav_gsm.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format wav49, extension(s) WAV|wav49 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_wav_gsm.so => (Microsoft WAV format (Proprietary GSM)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading format_siren7.so. [Jul 28 16:07:01] VERBOSE[1794] file.c: Registered file format siren7, extension(s) siren7 [Jul 28 16:07:01] VERBOSE[1794] loader.c: format_siren7.so => (ITU G.722.1 (Siren7, licensed from Polycom)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading app_stack.so. [Jul 28 16:07:01] VERBOSE[1794] res_agi.c: AGI Command 'gosub' registered [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'StackPop' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'Return' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'GosubIf' [Jul 28 16:07:01] VERBOSE[1794] pbx_app.c: Registered application 'Gosub' [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'LOCAL' [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'LOCAL_PEEK' [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'STACK_PEEK' [Jul 28 16:07:01] VERBOSE[1794] loader.c: app_stack.so => (Dialplan subroutines (Gosub, Return, etc)) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading func_devstate.so. [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'DEVICE_STATE' [Jul 28 16:07:01] VERBOSE[1794] pbx_functions.c: Registered custom function 'HINT' [Jul 28 16:07:01] VERBOSE[1794] loader.c: func_devstate.so => (Gets or sets a device state in the dialplan) [Jul 28 16:07:01] VERBOSE[1794] loader.c: Loading app_confbridge.so. [Jul 28 16:07:02] ERROR[1794] config_options.c: Unable to load config file 'confbridge.conf' [Jul 28 16:07:02] ERROR[1794] app_confbridge.c: Unable to load config. Not loading module. [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_agent_pool.so. [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action Agents [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action AgentLogoff [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'AGENT' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'AgentLogin' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'AgentRequest' [Jul 28 16:07:02] ERROR[1794] config_options.c: Unable to load config file 'agents.conf' [Jul 28 16:07:02] ERROR[1794] app_agent_pool.c: Unable to load config. Not loading module. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Unregistered application 'AgentLogin' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Unregistered application 'AgentRequest' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Unregistered custom function AGENT [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager unregistered action Agents [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager unregistered action AgentLogoff [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_presencestate.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PRESENCE_STATE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_presencestate.so => (Gets or sets a presence state in the dialplan) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cdr_manager.so. [Jul 28 16:07:02] WARNING[1794] cdr_manager.c: Failed to load configuration file. Module not activated. [Jul 28 16:07:02] VERBOSE[1794] cdr.c: Unregistered 'cdr_manager' CDR backend [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cdr_syslog.so. [Jul 28 16:07:02] ERROR[1794] cdr_syslog.c: Unable to load cdr_syslog.conf. Not logging custom CSV CDRs to syslog. [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cel_custom.so. [Jul 28 16:07:02] ERROR[1794] cel_custom.c: Unable to load cel_custom.conf. Not logging CEL to custom CSVs. [Jul 28 16:07:02] VERBOSE[1794] loader.c: cel_custom.so => (Customizable Comma Separated Values CEL Backend) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cdr_custom.so. [Jul 28 16:07:02] ERROR[1794] cdr_custom.c: Unable to load cdr_custom.conf. Not logging custom CSV CDRs. [Jul 28 16:07:02] VERBOSE[1794] loader.c: cdr_custom.so => (Customizable Comma Separated Values CDR Backend) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cel_sqlite3_custom.so. [Jul 28 16:07:02] WARNING[1794] cel_sqlite3_custom.c: Failed to load configuration file. Module not activated. [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cdr_csv.so. [Jul 28 16:07:02] WARNING[1794] cdr_csv.c: unable to load config: cdr.conf [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cdr_sqlite3_custom.so. [Jul 28 16:07:02] WARNING[1794] cdr_sqlite3_custom.c: Failed to load configuration file. Module not activated. [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading cel_manager.so. [Jul 28 16:07:02] WARNING[1794] cel_manager.c: Failed to load configuration file. CEL manager Module not activated. [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_record.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Record' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_record.so => (Trivial Record Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading pbx_spool.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: pbx_spool.so => (Outgoing Spool Support) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_cdr.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CDR' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CDR_PROP' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_cdr.so => (Call Detail Record (CDR) dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_bridgewait.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'BridgeWait' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_bridgewait.so => (Place the channel into a holding bridge application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_sendtext.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SendText' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_sendtext.so => (Send Text Applications) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_audiohookinherit.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'AUDIOHOOK_INHERIT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_audiohookinherit.so => (Audiohook inheritance placeholder function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_exec.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Exec' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'TryExec' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ExecIf' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_exec.so => (Executes dialplan applications) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_softhangup.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SoftHangup' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_softhangup.so => (Hangs up the requested channel) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_alarmreceiver.so. [Jul 28 16:07:02] VERBOSE[1794] app_alarmreceiver.c: AlarmReceiver: No config file [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_stasis.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Stasis' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_stasis.so => (Stasis dialplan application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_test.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'TestClient' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'TestServer' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_test.so => (Interface Test Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading bridge_native_rtp.so. [Jul 28 16:07:02] VERBOSE[1794] bridge.c: Registered bridge technology native_rtp [Jul 28 16:07:02] VERBOSE[1794] loader.c: bridge_native_rtp.so => (Native RTP bridging module) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_verbose.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Log' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Verbose' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_verbose.so => (Send verbose output) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_talkdetect.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'BackgroundDetect' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_talkdetect.so => (Playback with Talk Detection) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_mp3.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MP3Player' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_mp3.so => (Silly MP3 Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_alaw.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'alawtolin' from codec alaw to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintoalaw' from codec slin to alaw, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_alaw.so => (A-law Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_device_states.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_device_states.so => (RESTful API module - Device state resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_adpcm.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'adpcmtolin' from codec adpcm to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintoadpcm' from codec slin to adpcm, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_adpcm.so => (Adaptive Differential PCM Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_controlplayback.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ControlPlayback' [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action ControlPlayback [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_controlplayback.so => (Control Playback Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_version.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'VERSION' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_version.so => (Get Asterisk Version/Build Info) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_originate.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Originate' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_originate.so => (Originate call) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_adsiprog.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ADSIProg' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_adsiprog.so => (Asterisk ADSI Programming Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_config.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'AST_CONFIG' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_config.so => (Asterisk configuration file variable access) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_iconv.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ICONV' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_iconv.so => (Charset conversions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_asterisk.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_asterisk.so => (RESTful API module - Asterisk resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_url.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SendURL' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_url.so => (Send URL Applications) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading bridge_builtin_features.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: bridge_builtin_features.so => (Built in bridging features) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading pbx_ael.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'AELSub' [Jul 28 16:07:02] NOTICE[1794] pbx_ael.c: File /etc/asterisk/extensions.ael not found; AEL declining load [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_hep_rtcp.so. [Jul 28 16:07:02] WARNING[1794] res_hep_rtcp.c: res_hep is not loaded or running; declining module load [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_global.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'GLOBAL' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SHARED' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_global.so => (Variable dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_waitforsilence.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'WaitForSilence' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'WaitForNoise' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_waitforsilence.so => (Wait For Silence) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_pjsip_contact.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PJSIP_CONTACT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_pjsip_contact.so => (Get information about a PJSIP contact) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_disa.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'DISA' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_disa.so => (DISA (Direct Inward System Access) Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_extstate.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'EXTENSION_STATE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_extstate.so => (Gets an extension's state in the dialplan) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_shell.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SHELL' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_shell.so => (Collects the output generated by a command executed by the system shell) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_blacklist.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'BLACKLIST' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_blacklist.so => (Look up Caller*ID name/number from blacklist database) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_convert.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_convert.so => (File format conversion CLI command) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_events.so. [Jul 28 16:07:02] VERBOSE[1794] res_http_websocket.c: WebSocket registered sub-protocol 'ari' [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_events.so => (RESTful API module - WebSocket resource) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_realtime.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REALTIME' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REALTIME_STORE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REALTIME_DESTROY' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REALTIME_FIELD' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REALTIME_HASH' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_realtime.so => (Read/Write/Store/Destroy values from a RealTime repository) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_callerid.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CALLERPRES' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CALLERID' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CONNECTEDLINE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REDIRECTING' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_callerid.so => (Party ID related dialplan functions (Caller-ID, Connected-line, Redirecting)) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_channelredirect.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ChannelRedirect' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_channelredirect.so => (Redirects a given channel to a dialplan target) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_volume.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'VOLUME' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_volume.so => (Technology independent volume control) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_dialgroup.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'DIALGROUP' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_dialgroup.so => (Dialgroup dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_dumpchan.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'DumpChan' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_dumpchan.so => (Dump Info About The Calling Channel) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_db.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'DBdel' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'DBdeltree' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_db.so => (Database Access Functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_hangupcause.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'HANGUPCAUSE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'HANGUPCAUSE_KEYS' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'HangupCauseClear' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_hangupcause.so => (HANGUPCAUSE related functions and applications) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_directory.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Directory' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_directory.so => (Extension Directory) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_macro.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MacroExit' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MacroIf' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MacroExclusive' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Macro' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_macro.so => (Extension Macros) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_milliwatt.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Milliwatt' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_milliwatt.so => (Digital Milliwatt (mu-law) Test Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading bridge_softmix.so. [Jul 28 16:07:02] VERBOSE[1794] bridge.c: Registered bridge technology softmix [Jul 28 16:07:02] VERBOSE[1794] loader.c: bridge_softmix.so => (Multi-party software based channel mixing) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_sha1.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SHA1' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_sha1.so => (SHA-1 computation dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_uri.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'URIDECODE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'URIENCODE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_uri.so => (URI encode/decode dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading bridge_simple.so. [Jul 28 16:07:02] VERBOSE[1794] bridge.c: Registered bridge technology simple_bridge [Jul 28 16:07:02] VERBOSE[1794] loader.c: bridge_simple.so => (Simple two channel bridging module) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_directed_pickup.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Pickup' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'PickupChan' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_directed_pickup.so => (Directed Call Pickup Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_module.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'IFMODULE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_module.so => (Checks if Asterisk module is loaded in memory) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_limit.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_limit.so => (Resource limits) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_externalivr.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ExternalIVR' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_externalivr.so => (External IVR Interface Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_system.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'TrySystem' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'System' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_system.so => (Generic System() application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_frame_trace.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FRAME_TRACE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_frame_trace.so => (Frame Trace for internal ast_frame debugging.) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_mutestream.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MUTEAUDIO' [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action MuteAudio [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_mutestream.so => (Mute audio stream resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_security_log.so. [Jul 28 16:07:02] VERBOSE[1794] res_security_log.c: Security Logging Enabled [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_security_log.so => (Security Event Logging) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_channels.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_channels.so => (RESTful API module - Channel resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_authenticate.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Authenticate' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_authenticate.so => (Authentication Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_senddtmf.so. [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action PlayDTMF [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SendDTMF' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_senddtmf.so => (Send DTMF digits Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_callcompletion.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CALLCOMPLETION' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_callcompletion.so => (Call Control Configuration Function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_cdr.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'NoCDR' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ResetCDR' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_cdr.so => (Tell Asterisk to not maintain a CDR for the current call) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_nbscat.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'NBScat' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_nbscat.so => (Silly NBS Stream Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_transfer.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Transfer' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_transfer.so => (Transfers a caller to another extension) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_g722.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'g722tolin' from codec g722 to slin, table cost, 960000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintog722' from codec slin to g722, table cost, 825000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'g722tolin16' from codec g722 to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lin16tog722' from codec slin to g722, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_g722.so => (ITU G.722-64kbps G722 Transcoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading chan_phone.so. [Jul 28 16:07:02] ERROR[1794] chan_phone.c: Unable to load config phone.conf [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_voicemail.so. [Jul 28 16:07:02] WARNING[1794] app_voicemail.c: Failed to load configuration file. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'VoiceMail' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'VoiceMailMain' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MailboxExists' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'VMAuthenticate' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'VoiceMailPlayMsg' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'VMSayName' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MAILBOX_EXISTS' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'VM_INFO' [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action VoicemailUsersList [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action VoicemailRefresh [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_voicemail.so => (Comedian Mail (Voicemail System)) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_pjsip_endpoint.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PJSIP_ENDPOINT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_pjsip_endpoint.so => (Get information about a PJSIP endpoint) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_dictate.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Dictate' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_dictate.so => (Virtual Dictation Machine) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_clialiases.so. [Jul 28 16:07:02] ERROR[1794] res_clialiases.c: res_clialiases configuration file 'cli_aliases.conf' not found [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_clialiases.so => (CLI Aliases) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_srv.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SRVQUERY' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SRVRESULT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_srv.so => (SRV related dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_minivm.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MinivmRecord' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MinivmGreet' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MinivmNotify' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MinivmDelete' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MinivmAccMess' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MinivmMWI' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MINIVMACCOUNT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MINIVMCOUNTER' [Jul 28 16:07:02] WARNING[1794] app_minivm.c: Failed to load configuration file. Module activated with default settings. [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_minivm.so => (Mini VoiceMail (A minimal Voicemail e-mail System)) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_resample.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 12000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 16000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 24000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 32000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 44100khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 48000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 8000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 16000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 24000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 32000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 44100khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 48000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 12000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 24000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 32000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 44100khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 48000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 16000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 16000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 32000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 44100khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 48000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 24000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 16000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 24000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 44100khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 48000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 32000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 16000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 24000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 32000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 48000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 44100khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 16000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 24000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 32000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 44100khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 96000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 48000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 16000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 24000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 32000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 44100khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 48000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 96000khz -> 192000khz' from codec slin to slin, table cost, 800000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 8000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 12000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 16000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 24000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 32000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 44100khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 48000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'slin 192000khz -> 96000khz' from codec slin to slin, table cost, 850000, computational cost 999999 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_resample.so => (SLIN Resampling Codec) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_waitforring.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'WaitForRing' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_waitforring.so => (Waits until first ring after time) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_read.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Read' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_read.so => (Read Variable Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_enum.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ENUMRESULT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ENUMQUERY' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ENUMLOOKUP' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'TXTCIDNAME' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_enum.so => (ENUM related dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_chanspy.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ChanSpy' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ExtenSpy' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'DAHDIScan' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_chanspy.so => (Listen to the audio of an active channel) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading bridge_builtin_interval_features.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: bridge_builtin_interval_features.so => (Built in bridging interval features) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_cut.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CUT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SORT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_cut.so => (Cut out information from a string) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_followme.so. [Jul 28 16:07:02] WARNING[1794] app_followme.c: No follow me config file (followme.conf), so no follow me [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_g726.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'g726tolin' from codec g726 to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintog726' from codec slin to g726, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'g726aal2tolin' from codec g726aal2 to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintog726aal2' from codec slin to g726aal2, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_g726.so => (ITU G.726-32kbps G726 Transcoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading bridge_holding.so. [Jul 28 16:07:02] VERBOSE[1794] bridge.c: Registered bridge technology holding_bridge [Jul 28 16:07:02] VERBOSE[1794] loader.c: bridge_holding.so => (Holding bridge module) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_realtime.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_realtime.so => (Realtime Data Lookup/Rewrite) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_forkcdr.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ForkCDR' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_forkcdr.so => (Fork The CDR into 2 separate entities) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_festival.so. [Jul 28 16:07:02] WARNING[1794] app_festival.c: No such configuration file festival.conf [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading pbx_realtime.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: pbx_realtime.so => (Realtime Switch) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_sorcery.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'AST_SORCERY' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_sorcery.so => (Get a field from a sorcery object) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_sounds.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_sounds.so => (RESTful API module - Sound resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_env.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ENV' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'STAT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FILE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FILE_COUNT_LINE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FILE_FORMAT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_env.so => (Environment/filesystem dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_chanisavail.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ChanIsAvail' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_chanisavail.so => (Check channel availability) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_math.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MATH' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'INC' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'DEC' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_math.so => (Mathematical dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_playbacks.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_playbacks.so => (RESTful API module - Playback control resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_format_attr_h264.so. [Jul 28 16:07:02] VERBOSE[1794] format.c: Registered format interface for codec 'h264' [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_format_attr_h264.so => (H.264 Format Attribute Module) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_md5.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MD5' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_md5.so => (MD5 digest dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_talkdetect.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'TALK_DETECT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_talkdetect.so => (Talk detection dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_while.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'While' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'EndWhile' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ExitWhile' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ContinueWhile' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_while.so => (While Loops and Conditional Execution) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_rand.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'RAND' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_rand.so => (Random number dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_zapateller.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Zapateller' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_zapateller.so => (Block Telemarketers with Special Information Tone) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_waituntil.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'WaitUntil' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_waituntil.so => (Wait until specified time) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_dial.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Dial' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'RetryDial' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_dial.so => (Dialing Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_sms.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SMS' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_sms.so => (SMS/PSTN handler) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading chan_oss.so. [Jul 28 16:07:02] NOTICE[1794] chan_oss.c: Unable to load config oss.conf [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_base64.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'BASE64_ENCODE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'BASE64_DECODE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_base64.so => (base64 encode/decode dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_applications.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_applications.so => (RESTful API module - Stasis application resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading pbx_loopback.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: pbx_loopback.so => (Loopback Switch) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_morsecode.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Morsecode' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_morsecode.so => (Morse code) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_bridges.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_bridges.so => (RESTful API module - Bridge resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_amd.so. [Jul 28 16:07:02] ERROR[1794] app_amd.c: Configuration file amd.conf missing. [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_pjsip_endpoint_identifier_anonymous.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_pjsip_endpoint_identifier_anonymous.so => (PJSIP Anonymous endpoint identifier) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_hep_pjsip.so. [Jul 28 16:07:02] WARNING[1794] res_hep_pjsip.c: res_hep is not loaded or running; declining module load [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_channel.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CHANNEL' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CHANNELS' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MASTER_CHANNEL' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_channel.so => (Channel information dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_jitterbuffer.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'JITTERBUFFER' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_jitterbuffer.so => (Jitter buffer for read side of channel.) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_ilbc.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'ilbctolin' from codec ilbc to slin, table cost, 900000, computational cost 4000 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintoilbc' from codec slin to ilbc, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_ilbc.so => (iLBC Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_ices.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ICES' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_ices.so => (Encode and Stream via icecast and ices) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_playback.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Playback' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_playback.so => (Sound File Playback Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_gsm.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'gsmtolin' from codec gsm to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintogsm' from codec slin to gsm, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_gsm.so => (GSM Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_playtones.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'PlayTones' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'StopPlayTones' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_playtones.so => (Playtones Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading pbx_config.so. [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action DialplanExtensionAdd [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action DialplanExtensionRemove [Jul 28 16:07:02] VERBOSE[1794] config.c: Parsing '/etc/asterisk/extensions.conf': Found [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Registered extension context 'internal-context'; registrar: pbx_config [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension '_[*+#0-9].' priority 1 to internal-context [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension '_[*+#0-9].' priority 2 to internal-context [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension '_[*+#0-9].' priority 3 to internal-context [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Registered extension context '__func_periodic_hook_context__'; registrar: func_periodic_hook [Jul 28 16:07:02] VERBOSE[1794] pbx.c: merging incls/swits/igpats from old(__func_periodic_hook_context__) to new(__func_periodic_hook_context__) context, registrar = pbx_config [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'beep' priority 2 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'beep' priority 1 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'hook' priority 6 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'hook' priority 5 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'hook' priority 4 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'hook' priority 3 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'hook' priority 2 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Added extension 'hook' priority 1 (CID match '') to __func_periodic_hook_context__ [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Time to scan old dialplan and merge leftovers back into the new: 0.000767 sec [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Time to restore hints and swap in new dialplan: 0.000002 sec [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Time to delete the old dialplan: 0.000034 sec [Jul 28 16:07:02] VERBOSE[1794] pbx.c: Total time merge_contexts_delete: 0.000803 sec [Jul 28 16:07:02] VERBOSE[1794] loader.c: pbx_config.so => (Text Extension Configuration) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_ulaw.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'ulawtolin' from codec ulaw to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintoulaw' from codec slin to ulaw, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintotestlaw' from codec slin to testlaw, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'testlawtolin' from codec testlaw to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_ulaw.so => (mu-Law Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_sayunixtime.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SayUnixTime' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'DateTime' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_sayunixtime.so => (Say time) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_celgenuserevent.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'CELGenUserEvent' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_celgenuserevent.so => (Generate an User-Defined CEL event) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_groupcount.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'GROUP_COUNT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'GROUP_MATCH_COUNT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'GROUP_LIST' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'GROUP' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_groupcount.so => (Channel group dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_strings.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FIELDQTY' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FIELDNUM' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'FILTER' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REPLACE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'STRREPLACE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'LISTFILTER' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'REGEX' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ARRAY' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'QUOTE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'CSV_QUOTE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'LEN' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'STRFTIME' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'STRPTIME' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'EVAL' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'KEYPADHASH' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'HASHKEYS' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'HASH' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ClearHash' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'TOUPPER' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'TOLOWER' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SHIFT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'POP' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PUSH' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'UNSHIFT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PASSTHRU' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_strings.so => (String handling dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_timeout.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'TIMEOUT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_timeout.so => (Channel timeout dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_lock.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'LOCK' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'TRYLOCK' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'UNLOCK' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_lock.so => (Dialplan mutexes) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading pbx_dundi.so. [Jul 28 16:07:02] ERROR[1794] pbx_dundi.c: Unable to load config dundi.conf [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_privacy.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'PrivacyManager' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_privacy.so => (Require phone number to be entered, if no CallerID sent) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_sysinfo.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SYSINFO' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_sysinfo.so => (System information related functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_clioriginate.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_clioriginate.so => (Call origination and redirection from the CLI) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_holdintercept.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'HOLD_INTERCEPT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_holdintercept.so => (Hold interception dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_image.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SendImage' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_image.so => (Image Transmission Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_pitchshift.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PITCH_SHIFT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_pitchshift.so => (Audio Effects Dialplan Functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading chan_unistim.so. [Jul 28 16:07:02] ERROR[1794] chan_unistim.c: Unable to load config unistim.conf [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_mixmonitor.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'MixMonitor' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'StopMixMonitor' [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action MixMonitorMute [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action MixMonitor [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action StopMixMonitor [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'MIXMONITOR' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_mixmonitor.so => (Mixed Audio Monitoring Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_a_mu.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'alawtoulaw' from codec alaw to ulaw, table cost, 915000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'ulawtoalaw' from codec ulaw to alaw, table cost, 915000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_a_mu.so => (A-law and Mulaw direct Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_logic.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'ISNULL' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SET' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'EXISTS' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'IF' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'IFTIME' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'IMPORT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_logic.so => (Logical dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading chan_bridge_media.so. [Jul 28 16:07:02] VERBOSE[1794] channel.c: Registered channel type 'Announcer' (Bridge Media Announcing Channel Driver) [Jul 28 16:07:02] VERBOSE[1794] channel.c: Registered channel type 'Recorder' (Bridge Media Recording Channel Driver) [Jul 28 16:07:02] VERBOSE[1794] loader.c: chan_bridge_media.so => (Bridge Media Channel Driver) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_sprintf.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPRINTF' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_sprintf.so => (SPRINTF dialplan function) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_db.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'DB' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'DB_EXISTS' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'DB_DELETE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'DB_KEYS' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_db.so => (Database (astdb) related dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_userevent.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'UserEvent' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_userevent.so => (Custom User Event Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_pjsip_aor.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'PJSIP_AOR' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_pjsip_aor.so => (Get information about a PJSIP AOR) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_aes.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'AES_DECRYPT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'AES_ENCRYPT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_aes.so => (AES dialplan functions) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_speech_utils.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechCreate' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechLoadGrammar' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechUnloadGrammar' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechActivateGrammar' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechDeactivateGrammar' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechStart' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechBackground' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechDestroy' [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'SpeechProcessingSound' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPEECH' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPEECH_SCORE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPEECH_TEXT' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPEECH_GRAMMAR' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPEECH_ENGINE' [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'SPEECH_RESULTS_TYPE' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_speech_utils.so => (Dialplan Speech Applications) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_format_attr_h263.so. [Jul 28 16:07:02] VERBOSE[1794] format.c: Registered format interface for codec 'h263' [Jul 28 16:07:02] VERBOSE[1794] format.c: Registered format interface for codec 'h263p' [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_format_attr_h263.so => (H.263 Format Attribute Module) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_readexten.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'ReadExten' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_readexten.so => (Read and evaluate extension validity) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_getcpeid.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'GetCPEID' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_getcpeid.so => (Get ADSI CPE ID) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_page.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Page' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_page.so => (Page Multiple Phones) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading func_vmcount.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_functions.c: Registered custom function 'VMCOUNT' [Jul 28 16:07:02] VERBOSE[1794] loader.c: func_vmcount.so => (Indicator for whether a voice mailbox has messages in a given folder.) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_endpoints.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_endpoints.so => (RESTful API module - Endpoint resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_echo.so. [Jul 28 16:07:02] VERBOSE[1794] pbx_app.c: Registered application 'Echo' [Jul 28 16:07:02] VERBOSE[1794] loader.c: app_echo.so => (Simple Echo Application) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_ari_recordings.so. [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_ari_recordings.so => (RESTful API module - Recording resources) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading codec_lpc10.so. [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lpc10tolin' from codec lpc10 to slin, table cost, 900000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] translate.c: Registered translator 'lintolpc10' from codec slin to lpc10, table cost, 600000, computational cost 1 [Jul 28 16:07:02] VERBOSE[1794] loader.c: codec_lpc10.so => (LPC10 2.4kbps Coder/Decoder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading app_queue.so. [Jul 28 16:07:02] NOTICE[1794] app_queue.c: No queuerules.conf file found, queues will not follow penalty rules [Jul 28 16:07:02] NOTICE[1794] app_queue.c: No call queueing config file (queues.conf), so no call queues [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_manager_presencestate.so. [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action PresenceStateList [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_manager_presencestate.so => (Manager Presence State Topic Forwarder) [Jul 28 16:07:02] VERBOSE[1794] loader.c: Loading res_manager_devicestate.so. [Jul 28 16:07:02] VERBOSE[1794] manager.c: Manager registered action DeviceStateList [Jul 28 16:07:02] VERBOSE[1794] loader.c: res_manager_devicestate.so => (Manager Device State Topic Forwarder) [Jul 28 16:07:02] VERBOSE[1794] asterisk.c: Asterisk Ready. [Jul 28 16:07:07] VERBOSE[1797] asterisk.c: Remote UNIX connection [Jul 28 16:07:30] Asterisk 13.10.0 built by user @ debian on a x86_64 running Linux on 2016-07-28 10:56:37 UTC [Jul 28 16:07:30] DEBUG[1850] config.c: Parsing /etc/asterisk/logger.conf [Jul 28 16:07:30] VERBOSE[1850] config.c: Parsing '/etc/asterisk/logger.conf': Found [Jul 28 16:07:30] VERBOSE[1850] logger.c: Asterisk Queue Logger restarted [Jul 28 16:07:31] DEBUG[1840] res_pjsip_registrar_expire.c: Woke up at 1469714851 Interval: 30 [Jul 28 16:07:31] DEBUG[1840] res_pjsip_registrar_expire.c: Expiring 0 contacts [Jul 28 16:08:00] DEBUG[1823] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:00] DEBUG[1822] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:00] DEBUG[1821] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:00] DEBUG[1816] threadpool.c: Destroying worker thread 9 [Jul 28 16:08:00] DEBUG[1816] threadpool.c: Destroying worker thread 8 [Jul 28 16:08:00] DEBUG[1816] threadpool.c: Destroying worker thread 7 [Jul 28 16:08:00] DEBUG[1820] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:00] DEBUG[1816] threadpool.c: Destroying worker thread 6 [Jul 28 16:08:00] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=20 (rdata0x7f1324063078) [Jul 28 16:08:00] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (1088 bytes) from UDP:10.20.51.121:5060 ---> INVITE sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:5060;branch=z9hG4bK.~PxV8pbGH;rport From: ;tag=E9Dmk5~vu To: sip:124@10.20.51.125 CSeq: 20 INVITE Call-ID: uoJcxXJlhy Max-Forwards: 70 Supported: outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 549 Contact: ;+sip.instance="" User-Agent: Linphone/3.9.1 (belle-sip/1.4.2) v=0 o=123 575 635 IN IP4 10.20.51.121 s=Talk c=IN IP4 10.20.51.121 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7078 RTP/AVP 96 97 98 0 8 101 99 100 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 speex/16000 a=fmtp:97 vbr=on a=rtpmap:98 speex/8000 a=fmtp:98 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:99 telephone-event/16000 a=rtpmap:100 telephone-event/8000 m=video 9078 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 MP4V-ES/90000 a=fmtp:97 profile-level-id=3 [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=20 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000021 to use for Request msg INVITE/cseq=20 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=20 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '123' domain '10.20.51.125' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '123' domain '10.20.51.125' [Jul 28 16:08:00] DEBUG[1819] pjproject: endpoint .Response msg 401/INVITE/cseq=20 (tdta0x7f1318004d70) created [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:00] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (451 bytes) to UDP:10.20.51.121:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.20.51.121:5060;rport=5060;received=10.20.51.121;branch=z9hG4bK.~PxV8pbGH Call-ID: uoJcxXJlhy From: ;tag=E9Dmk5~vu To: ;tag=z9hG4bK.~PxV8pbGH CSeq: 20 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1469714880/8d32fa5c2c4b61ffc06d1c5570c1c60e",opaque="4203b3cc634da830",algorithm=md5,qop="auth" Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:00] DEBUG[1819] pjproject: tdta0x7f131800 .Destroying txdata Response msg 401/INVITE/cseq=20 (tdta0x7f1318004d70) [Jul 28 16:08:00] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=20 (rdata0x7f1324063078) [Jul 28 16:08:00] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (347 bytes) from UDP:10.20.51.121:5060 ---> ACK sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:5060;branch=z9hG4bK.~PxV8pbGH;rport Call-ID: uoJcxXJlhy From: ;tag=E9Dmk5~vu To: ;tag=z9hG4bK.~PxV8pbGH Contact: ;+sip.instance="" Max-Forwards: 70 CSeq: 20 ACK [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg ACK/cseq=20 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000021 to use for Request msg ACK/cseq=20 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=20 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '123' domain '10.20.51.125' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '123' domain '10.20.51.125' [Jul 28 16:08:00] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=21 (rdata0x7f1324063078) [Jul 28 16:08:00] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (1356 bytes) from UDP:10.20.51.121:5060 ---> INVITE sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:5060;branch=z9hG4bK.M72TLDke0;rport From: ;tag=E9Dmk5~vu To: sip:124@10.20.51.125 CSeq: 21 INVITE Call-ID: uoJcxXJlhy Max-Forwards: 70 Supported: outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 549 Contact: ;+sip.instance="" User-Agent: Linphone/3.9.1 (belle-sip/1.4.2) Authorization: Digest realm="asterisk", nonce="1469714880/8d32fa5c2c4b61ffc06d1c5570c1c60e", algorithm=md5, opaque="4203b3cc634da830", username="123", uri="sip:124@10.20.51.125", response="bca4d8f36d2ec4bc72e23cde1f3f83be", cnonce="76523cc5", nc=00000001, qop=auth v=0 o=123 575 635 IN IP4 10.20.51.121 s=Talk c=IN IP4 10.20.51.121 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7078 RTP/AVP 96 97 98 0 8 101 99 100 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 speex/16000 a=fmtp:97 vbr=on a=rtpmap:98 speex/8000 a=fmtp:98 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:99 telephone-event/16000 a=rtpmap:100 telephone-event/8000 m=video 9078 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 MP4V-ES/90000 a=fmtp:97 profile-level-id=3 [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=21 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000021 to use for Request msg INVITE/cseq=21 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=21 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '123' domain '10.20.51.125' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '123' domain '10.20.51.125' [Jul 28 16:08:00] DEBUG[1819] pjproject: endpoint .Response msg 401/INVITE/cseq=21 (tdta0x7f1318004d70) created [Jul 28 16:08:00] DEBUG[1819] res_pjsip_authenticator_digest.c: Calculated nonce 1469714880/8d32fa5c2c4b61ffc06d1c5570c1c60e. Actual nonce is 1469714880/8d32fa5c2c4b61ffc06d1c5570c1c60e [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: tdta0x7f131800 .Destroying txdata Response msg 401/INVITE/cseq=21 (tdta0x7f1318004d70) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d ..Transaction created for Request msg INVITE/cseq=21 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d .Incoming Request msg INVITE/cseq=21 (rdata0x7f1324218178) in state Null [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d ..State changed from Null to Trying, event=RX_MSG [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ...Transaction tsx0x7f131800d018 state changed to Trying [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b .UAS dialog created [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b .Module mod-invite added as dialog usage, data=0x7f131800f748 [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ..Session count inc to 2 by mod-invite [Jul 28 16:08:00] DEBUG[1819] pjproject: inv0x7f131800b .UAS invite session created for dialog dlg0x7f131800b658 [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b .Module Session Module added as dialog usage, data=(nil) [Jul 28 16:08:00] DEBUG[1819] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000021 to use for Request msg INVITE/cseq=21 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ..Session count inc to 2 by Session Module [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Negotiating incoming SDP media stream 'audio' using audio SDP handler [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f13180167b8' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Allocated port 29302 for RTP instance '0x7f13180167b8' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:29302 (29302) for RTP instance '0x7f13180167b8' [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 ICE session created, comp_cnt=2, role is Unknown agent [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 0 added: comp_id=1, type=host, foundation=Ha14337d, addr=10.20.51.125:29302, base=10.20.51.125:29302, prio=0x7effffff (2130706431) [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: RTP instance '0x7f13180167b8' is setup and ready to go [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f13180167b8' [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 1 added: comp_id=2, type=host, foundation=Ha14337d, addr=10.20.51.125:29303, base=10.20.51.125:29303, prio=0x7efffffe (2130706430) [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Destroying ICE session 0x7f131801a768 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131801cfa8 destroy request, ref_cnt=4 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131801dfa8 destroy request, ref_cnt=3 [Jul 28 16:08:00] DEBUG[1819] pjproject: ice_session.c ICE session 0x7f131801a768 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131801cfa8 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131801dfa8 destroyed [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 97 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 98 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 99 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 100 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 0 (0x2b64d00) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 8 (0x2b6a680) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 96 (0x7f131801e2d0) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 97 (0x7f131801e830) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 98 (0x7f131801add0) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 99 (0x2b6aa00) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 100 (0x7f131801e190) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Copying payload 101 (0x2b6aa40) from 0x7f131c1085b0 to 0x7f1318016980 [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Media stream 'audio' handled by audio [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Negotiating incoming SDP media stream 'video' using video SDP handler [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f1318024d88' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Allocated port 20264 for RTP instance '0x7f1318024d88' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:20264 (20264) for RTP instance '0x7f1318024d88' [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 ICE session created, comp_cnt=2, role is Unknown agent [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 0 added: comp_id=1, type=host, foundation=Ha14337d, addr=10.20.51.125:20264, base=10.20.51.125:20264, prio=0x7effffff (2130706431) [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: RTP instance '0x7f1318024d88' is setup and ready to go [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f1318024d88' [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 1 added: comp_id=2, type=host, foundation=Ha14337d, addr=10.20.51.125:20265, base=10.20.51.125:20265, prio=0x7efffffe (2130706430) [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Destroying ICE session 0x7f1318028ac8 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131802b308 destroy request, ref_cnt=4 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131802c308 destroy request, ref_cnt=3 [Jul 28 16:08:00] DEBUG[1819] pjproject: ice_session.c ICE session 0x7f1318028ac8 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131802b308 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131802c308 destroyed [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0x7f131c1085b0 [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Setting tx payload type 97 based on m type on 0x7f131c1085b0 [Jul 28 16:08:00] NOTICE[1819] res_pjsip_sdp_rtp.c: No joint capabilities for 'video' media stream between our configuration((h264)) and incoming SDP((vp8|mpeg4)) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled [Jul 28 16:08:00] DEBUG[1819] pjproject: endpoint .Response msg 100/INVITE/cseq=21 (tdta0x7f1318003d60) created [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b .Initial answer Response msg 100/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Jul 28 16:08:00] DEBUG[1819] pjproject: inv0x7f131800b .Sending Response msg 100/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ..Sending Response msg 100/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d ..Sending Response msg 100/INVITE/cseq=21 (tdta0x7f1318003d60) in state Trying [Jul 28 16:08:00] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (276 bytes) to UDP:10.20.51.121:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.20.51.121:5060;rport=5060;received=10.20.51.121;branch=z9hG4bK.M72TLDke0 Call-ID: uoJcxXJlhy From: ;tag=E9Dmk5~vu To: CSeq: 21 INVITE Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d ...State changed from Trying to Proceeding, event=TX_MSG [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ....Transaction tsx0x7f131800d018 state changed to Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123()' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131800d018) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is INCOMING [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Sending response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123()' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131800d018) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current transaction state is Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The transaction state change event is TX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is INCOMING [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Sending response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE, Response is 100 Trying [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b Module NAT added as dialog usage, data=(nil) [Jul 28 16:08:00] DEBUG[1796] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 28 16:08:00] DEBUG[1819] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/123-00000000 [Jul 28 16:08:00] DEBUG[1857][C-00000000] pbx.c: Launching 'Set' [Jul 28 16:08:00] VERBOSE[1857][C-00000000] pbx.c: Executing [124@internal-context:1] Set("PJSIP/123-00000000", "AGISIGHUP=no") in new stack [Jul 28 16:08:00] DEBUG[1857][C-00000000] pbx_variables.c: Result of 'EXTEN' is '124' [Jul 28 16:08:00] DEBUG[1857][C-00000000] pbx.c: Launching 'Dial' [Jul 28 16:08:00] VERBOSE[1857][C-00000000] pbx.c: Executing [124@internal-context:2] Dial("PJSIP/123-00000000", "PJSIP/124") in new stack [Jul 28 16:08:00] DEBUG[1819] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Jul 28 16:08:00] DEBUG[1819] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Jul 28 16:08:00] DEBUG[1819] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Jul 28 16:08:00] DEBUG[1819] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Jul 28 16:08:00] DEBUG[1819] config.c: extract uint from [58181] in [0, 4294967295] gives [58181](0) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 UAC dialog created [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 Module Outbound INVITE Auth added as dialog usage, data=(nil) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 Module mod-invite added as dialog usage, data=0x7f131801dd58 [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 .Session count inc to 2 by mod-invite [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 Module mod-100rel added as dialog usage, data=0x7f1318007080 [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 100rel module attached [Jul 28 16:08:00] DEBUG[1819] pjproject: inv0x7f1318012 UAC invite session created for dialog dlg0x7f13180126b8 [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 .Session count inc to 2 by Session Module [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 Module Session Module added as dialog usage, data=(nil) [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f13180254f8' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Allocated port 22352 for RTP instance '0x7f13180254f8' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:22352 (22352) for RTP instance '0x7f13180254f8' [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 ICE session created, comp_cnt=2, role is Unknown agent [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 0 added: comp_id=1, type=host, foundation=Ha14337d, addr=10.20.51.125:22352, base=10.20.51.125:22352, prio=0x7effffff (2130706431) [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: RTP instance '0x7f13180254f8' is setup and ready to go [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f13180254f8' [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 1 added: comp_id=2, type=host, foundation=Ha14337d, addr=10.20.51.125:22353, base=10.20.51.125:22353, prio=0x7efffffe (2130706430) [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Destroying ICE session 0x7f1318021ac8 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131801c028 destroy request, ref_cnt=4 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131801fa88 destroy request, ref_cnt=3 [Jul 28 16:08:00] DEBUG[1819] pjproject: ice_session.c ICE session 0x7f1318021ac8 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131801c028 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131801fa88 destroyed [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f131802eda8' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Allocated port 11352 for RTP instance '0x7f131802eda8' [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:11352 (11352) for RTP instance '0x7f131802eda8' [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 ICE session created, comp_cnt=2, role is Unknown agent [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 0 added: comp_id=1, type=host, foundation=Ha14337d, addr=10.20.51.125:11352, base=10.20.51.125:11352, prio=0x7effffff (2130706431) [Jul 28 16:08:00] DEBUG[1819] rtp_engine.c: RTP instance '0x7f131802eda8' is setup and ready to go [Jul 28 16:08:00] DEBUG[1819] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f131802eda8' [Jul 28 16:08:00] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:00] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Candidate 1 added: comp_id=2, type=host, foundation=Ha14337d, addr=10.20.51.125:11353, base=10.20.51.125:11353, prio=0x7efffffe (2130706430) [Jul 28 16:08:00] DEBUG[1819] pjproject: icess0x7f13180 Destroying ICE session 0x7f1318033948 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f1318010a98 destroy request, ref_cnt=4 [Jul 28 16:08:00] DEBUG[1819] pjproject: stuse0x7f13180 STUN session 0x7f131801ca48 destroy request, ref_cnt=3 [Jul 28 16:08:00] DEBUG[1819] pjproject: ice_session.c ICE session 0x7f1318033948 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f1318010a98 destroyed [Jul 28 16:08:00] DEBUG[1819] pjproject: stun_session.c STUN session 0x7f131801ca48 destroyed [Jul 28 16:08:00] DEBUG[1819] res_pjsip_t38.c: Not creating outgoing SDP stream: T.38 not enabled [Jul 28 16:08:00] DEBUG[1819] pjproject: endpoint Request msg INVITE/cseq=31219 (tdta0x7f1318004d70) created. [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 Module WebSocket Transport Module added as dialog usage, data=(nil) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 Module NAT added as dialog usage, data=(nil) [Jul 28 16:08:00] DEBUG[1819] pjproject: inv0x7f1318012 .Sending Request msg INVITE/cseq=31219 (tdta0x7f1318004d70) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ..Sending Request msg INVITE/cseq=31219 (tdta0x7f1318004d70) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f ...Transaction created for Request msg INVITE/cseq=31218 (tdta0x7f1318004d70) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f ..Sending Request msg INVITE/cseq=31218 (tdta0x7f1318004d70) in state Null [Jul 28 16:08:00] DEBUG[1819] pjproject: sip_resolve.c ...Target '10.20.51.121:58181' type=Unspecified resolved to '10.20.51.121:58181' type=UDP (UDP transport) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.20.51.125:5060 [Jul 28 16:08:00] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP request (970 bytes) to UDP:10.20.51.121:58181 ---> INVITE sip:09264158@10.20.51.121:58181 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.125:5060;rport;branch=z9hG4bKPjNkSjh2WLRbgh4W46kPiccuVYbQUa4Vb. From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: Contact: Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr CSeq: 31218 INVITE Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800 Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX 13.10.0 Content-Type: application/sdp Content-Length: 323 v=0 o=- 148906622 148906622 IN IP4 10.20.51.125 s=Asterisk c=IN IP4 10.20.51.125 t=0 0 m=audio 22352 RTP/AVP 8 18 101 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv m=video 11352 RTP/AVP 99 a=rtpmap:99 H264/90000 a=sendrecv [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f ...State changed from Null to Calling, event=TX_MSG [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ....Transaction tsx0x7f131801fb08 state changed to Calling [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is CALLING [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Sending request [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current transaction state is Calling [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The transaction state change event is TX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is CALLING [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Sending request [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE [Jul 28 16:08:00] VERBOSE[1857][C-00000000] app_dial.c: Called PJSIP/124 [Jul 28 16:08:00] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Response msg 100/INVITE/cseq=31218 (rdata0x7f1324063078) [Jul 28 16:08:00] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP response (352 bytes) from UDP:10.20.51.121:58181 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.20.51.125:5060;rport=5060;received=10.20.51.125;branch=z9hG4bKPjNkSjh2WLRbgh4W46kPiccuVYbQUa4Vb. Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: CSeq: 31218 INVITE Server: Blink 2.0.0 (Linux) Content-Length: 0 [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f13180126b8 for Response msg 100/INVITE/cseq=31218 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/124-00000047 on dialog dlg0x7f13180126b8 [Jul 28 16:08:00] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Response msg 100/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f .Incoming Response msg 100/INVITE/cseq=31218 (rdata0x7f1324218178) in state Calling [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f ..State changed from Calling to Proceeding, event=RX_MSG [Jul 28 16:08:00] DEBUG[1816] threadpool.c: Increasing threadpool SIP's size by 5 [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ...Received Response msg 100/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ...Transaction tsx0x7f131801fb08 state changed to Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current transaction state is Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The transaction state change event is RX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is CALLING [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Response is 100 Trying [Jul 28 16:08:00] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Response msg 180/INVITE/cseq=31218 (rdata0x7f1324063078) [Jul 28 16:08:00] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP response (521 bytes) from UDP:10.20.51.121:58181 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.20.51.125:5060;rport=5060;received=10.20.51.125;branch=z9hG4bKPjNkSjh2WLRbgh4W46kPiccuVYbQUa4Vb. Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: ;tag=aaae76ac-7015-4d62-92b6-394624dcb25e CSeq: 31218 INVITE Server: Blink 2.0.0 (Linux) Contact: Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER Content-Length: 0 [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f13180126b8 for Response msg 180/INVITE/cseq=31218 (rdata0x7f1324063078) [Jul 28 16:08:00] DEBUG[1818] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/124-00000047 on dialog dlg0x7f13180126b8 [Jul 28 16:08:00] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Response msg 180/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f .Incoming Response msg 180/INVITE/cseq=31218 (rdata0x7f1324218178) in state Proceeding [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131801f ..State changed from Proceeding to Proceeding, event=RX_MSG [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ...Received Response msg 180/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ....Route-set updated [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f1318012 ...Transaction tsx0x7f131801fb08 state changed to Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is EARLY [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Response is 180 Ringing [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current transaction state is Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The transaction state change event is RX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is EARLY [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Response is 180 Ringing [Jul 28 16:08:00] DEBUG[1808] devicestate.c: No provider found, checking channel drivers for PJSIP - 124 [Jul 28 16:08:00] DEBUG[1808] devicestate.c: Changing state for PJSIP/124 - state 6 (Ringing) [Jul 28 16:08:00] VERBOSE[1857][C-00000000] app_dial.c: PJSIP/124-00000001 is ringing [Jul 28 16:08:00] DEBUG[1808] devicestate.c: No provider found, checking channel drivers for PJSIP - 123 [Jul 28 16:08:00] DEBUG[1808] devicestate.c: Changing state for PJSIP/123 - state 2 (In use) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Jul 28 16:08:00] DEBUG[1819] pjproject: inv0x7f131800b .Sending Response msg 180/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ..Sending Response msg 180/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d ..Sending Response msg 180/INVITE/cseq=21 (tdta0x7f1318003d60) in state Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.20.51.125:5060 [Jul 28 16:08:00] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (459 bytes) to UDP:10.20.51.121:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.20.51.121:5060;rport=5060;received=10.20.51.121;branch=z9hG4bK.M72TLDke0 Call-ID: uoJcxXJlhy From: ;tag=E9Dmk5~vu To: ;tag=-ETaQK7rJfpsyXZQXwd6zezPXVAREANR CSeq: 21 INVITE Server: Asterisk PBX 13.10.0 Contact: Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE Content-Length: 0 [Jul 28 16:08:00] DEBUG[1819] pjproject: tsx0x7f131800d ...State changed from Proceeding to Proceeding, event=TX_MSG [Jul 28 16:08:00] DEBUG[1819] pjproject: dlg0x7f131800b ....Transaction tsx0x7f131800d018 state changed to Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131800d018) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is EARLY [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Sending response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131800d018) [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current transaction state is Proceeding [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The transaction state change event is TX_MSG [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: The current inv state is EARLY [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Sending response [Jul 28 16:08:00] DEBUG[1819] res_pjsip_session.c: Method is INVITE, Response is 180 Ringing [Jul 28 16:08:01] DEBUG[1825] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:01] DEBUG[1826] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:01] DEBUG[1827] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:01] DEBUG[1829] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:01] DEBUG[1795] threadpool.c: Destroying worker thread 11 [Jul 28 16:08:01] DEBUG[1795] threadpool.c: Destroying worker thread 12 [Jul 28 16:08:01] DEBUG[1795] threadpool.c: Destroying worker thread 13 [Jul 28 16:08:01] DEBUG[1795] threadpool.c: Destroying worker thread 14 [Jul 28 16:08:01] DEBUG[1824] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:01] DEBUG[1795] threadpool.c: Destroying worker thread 10 [Jul 28 16:08:01] DEBUG[1840] res_pjsip_registrar_expire.c: Woke up at 1469714881 Interval: 30 [Jul 28 16:08:01] DEBUG[1840] res_pjsip_registrar_expire.c: Expiring 0 contacts [Jul 28 16:08:01] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg PUBLISH/cseq=1 (rdata0x7f1324063078) [Jul 28 16:08:01] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (2268 bytes) from UDP:10.20.51.121:58181 ---> PUBLISH sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:58181;rport;branch=z9hG4bKPjf514de22-fda6-4723-a1b2-ab0f94cb50be Max-Forwards: 70 From: "yrid" ;tag=facc1f84-0d75-45e2-a6ec-88e6fdc12f0d To: "yrid" Call-ID: 145b52e8-e99f-4add-8d62-ed3130d3650e CSeq: 1 PUBLISH Event: presence Expires: 600 User-Agent: Blink 2.0.0 (Linux) Content-Type: application/pidf+xml Content-Length: 1814 openbusytruetruefalsetruetruetrueyridjan-siprBlink 2.0.0 (Linux)120activecd891f2d-01ac-4060-b78c-8fe805a949aasip%3A124%4010.20.51.125On the phone2016-07-28T16:08:03.607592+02:002016-07-28T16:08:03.607592+02:00cd891f2d-01ac-4060-b78c-8fe805a949aaBlink 2.0.0 (Linux) at jan-sipr2016-07-28T16:08:03.607592+02:00 [Jul 28 16:08:01] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg PUBLISH/cseq=1 (rdata0x7f1324063078) [Jul 28 16:08:01] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000021 to use for Request msg PUBLISH/cseq=1 (rdata0x7f1324063078) [Jul 28 16:08:01] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg PUBLISH/cseq=1 (rdata0x7f1324218178) [Jul 28 16:08:01] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:01] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '124' domain '10.20.51.125' [Jul 28 16:08:01] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '124' domain '10.20.51.125' [Jul 28 16:08:01] DEBUG[1819] pjproject: endpoint .Response msg 401/PUBLISH/cseq=1 (tdta0x7f1318034900) created [Jul 28 16:08:01] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:01] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:01] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:01] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:01] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (576 bytes) to UDP:10.20.51.121:58181 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.20.51.121:58181;rport=58181;received=10.20.51.121;branch=z9hG4bKPjf514de22-fda6-4723-a1b2-ab0f94cb50be Call-ID: 145b52e8-e99f-4add-8d62-ed3130d3650e From: "yrid" ;tag=facc1f84-0d75-45e2-a6ec-88e6fdc12f0d To: "yrid" ;tag=z9hG4bKPjf514de22-fda6-4723-a1b2-ab0f94cb50be CSeq: 1 PUBLISH WWW-Authenticate: Digest realm="asterisk",nonce="1469714881/59da09c442c796f9cc88f6ea9b427144",opaque="7faa2fbf24cade73",algorithm=md5,qop="auth" Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:01] DEBUG[1819] pjproject: tdta0x7f131803 .Destroying txdata Response msg 401/PUBLISH/cseq=1 (tdta0x7f1318034900) [Jul 28 16:08:01] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg PUBLISH/cseq=2 (rdata0x7f1324063078) [Jul 28 16:08:01] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (2562 bytes) from UDP:10.20.51.121:58181 ---> PUBLISH sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:58181;rport;branch=z9hG4bKPj275772f2-c2fd-4adc-b0f3-61cf060f1519 Max-Forwards: 70 From: "yrid" ;tag=facc1f84-0d75-45e2-a6ec-88e6fdc12f0d To: "yrid" Call-ID: 145b52e8-e99f-4add-8d62-ed3130d3650e CSeq: 2 PUBLISH Event: presence Expires: 600 User-Agent: Blink 2.0.0 (Linux) Authorization: Digest username="124", realm="asterisk", nonce="1469714881/59da09c442c796f9cc88f6ea9b427144", uri="sip:124@10.20.51.125", response="f144acf5543dad85cf8949ceb07beaee", algorithm=md5, cnonce="5b18014d-0e2b-4cc8-aa9a-40d4b54c77b4", opaque="7faa2fbf24cade73", qop=auth, nc=00000001 Content-Type: application/pidf+xml Content-Length: 1814 openbusytruetruefalsetruetruetrueyridjan-siprBlink 2.0.0 (Linux)120activecd891f2d-01ac-4060-b78c-8fe805a949aasip%3A124%4010.20.51.125On the phone2016-07-28T16:08:03.607592+02:002016-07-28T16:08:03.607592+02:00cd891f2d-01ac-4060-b78c-8fe805a949aaBlink 2.0.0 (Linux) at jan-sipr2016-07-28T16:08:03.607592+02:00 [Jul 28 16:08:01] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg PUBLISH/cseq=2 (rdata0x7f1324063078) [Jul 28 16:08:01] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000021 to use for Request msg PUBLISH/cseq=2 (rdata0x7f1324063078) [Jul 28 16:08:01] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg PUBLISH/cseq=2 (rdata0x7f1324218178) [Jul 28 16:08:01] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:01] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '124' domain '10.20.51.125' [Jul 28 16:08:01] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '124' domain '10.20.51.125' [Jul 28 16:08:01] DEBUG[1819] pjproject: endpoint .Response msg 401/PUBLISH/cseq=2 (tdta0x7f1318034900) created [Jul 28 16:08:01] DEBUG[1819] res_pjsip_authenticator_digest.c: Calculated nonce 1469714881/59da09c442c796f9cc88f6ea9b427144. Actual nonce is 1469714881/59da09c442c796f9cc88f6ea9b427144 [Jul 28 16:08:01] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:01] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:01] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:01] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:01] DEBUG[1819] pjproject: tdta0x7f131803 .Destroying txdata Response msg 401/PUBLISH/cseq=2 (tdta0x7f1318034900) [Jul 28 16:08:01] DEBUG[1819] res_pjsip_pubsub.c: Event presence does not match asterisk-devicestate [Jul 28 16:08:01] DEBUG[1819] res_pjsip_pubsub.c: Event presence does not match asterisk-mwi [Jul 28 16:08:01] WARNING[1819] res_pjsip_pubsub.c: No registered publish handler for event presence [Jul 28 16:08:01] DEBUG[1819] pjproject: endpoint .Response msg 489/PUBLISH/cseq=2 (tdta0x7f1318034900) created [Jul 28 16:08:01] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (426 bytes) to UDP:10.20.51.121:58181 ---> SIP/2.0 489 Bad Event Via: SIP/2.0/UDP 10.20.51.121:58181;rport=58181;received=10.20.51.121;branch=z9hG4bKPj275772f2-c2fd-4adc-b0f3-61cf060f1519 Call-ID: 145b52e8-e99f-4add-8d62-ed3130d3650e From: "yrid" ;tag=facc1f84-0d75-45e2-a6ec-88e6fdc12f0d To: "yrid" ;tag=z9hG4bKPj275772f2-c2fd-4adc-b0f3-61cf060f1519 CSeq: 2 PUBLISH Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:01] DEBUG[1819] pjproject: tdta0x7f131803 .Destroying txdata Response msg 489/PUBLISH/cseq=2 (tdta0x7f1318034900) [Jul 28 16:08:01] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Response msg 200/INVITE/cseq=31218 (rdata0x7f1324063078) [Jul 28 16:08:01] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP response (959 bytes) from UDP:10.20.51.121:58181 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.20.51.125:5060;rport=5060;received=10.20.51.125;branch=z9hG4bKPjNkSjh2WLRbgh4W46kPiccuVYbQUa4Vb. Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: ;tag=aaae76ac-7015-4d62-92b6-394624dcb25e CSeq: 31218 INVITE Server: Blink 2.0.0 (Linux) Allow: SUBSCRIBE, NOTIFY, PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, MESSAGE, REFER Contact: Supported: 100rel, replaces, norefersub, gruu Content-Type: application/sdp Content-Length: 362 v=0 o=- 3678703683 3678703684 IN IP4 10.20.51.121 s=Blink 2.0.0 (Linux) t=0 0 m=audio 50008 RTP/AVP 8 101 c=IN IP4 10.20.51.121 a=rtcp:50009 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=zrtp-hash:1.10 5ec9a21f6487a27dfd9b1cc3d77ebd93cde4abe19474c6575c520f98f6ebd85d a=sendrecv m=video 0 RTP/AVP 99 c=IN IP4 10.20.51.121 [Jul 28 16:08:01] DEBUG[1818] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f13180126b8 for Response msg 200/INVITE/cseq=31218 (rdata0x7f1324063078) [Jul 28 16:08:01] DEBUG[1818] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/124-00000047 on dialog dlg0x7f13180126b8 [Jul 28 16:08:01] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Response msg 200/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:01] DEBUG[1819] pjproject: tsx0x7f131801f .Incoming Response msg 200/INVITE/cseq=31218 (rdata0x7f1324218178) in state Proceeding [Jul 28 16:08:01] DEBUG[1819] pjproject: tsx0x7f131801f ..State changed from Proceeding to Terminated, event=RX_MSG [Jul 28 16:08:01] DEBUG[1819] pjproject: dlg0x7f1318012 ...Received Response msg 200/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:01] DEBUG[1819] pjproject: dlg0x7f1318012 ....Route-set updated [Jul 28 16:08:01] DEBUG[1819] pjproject: dlg0x7f1318012 ....Route-set frozen [Jul 28 16:08:01] DEBUG[1819] pjproject: dlg0x7f1318012 ...Transaction tsx0x7f131801fb08 state changed to Terminated [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The current inv state is CONNECTING [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Response is 200 OK [Jul 28 16:08:01] DEBUG[1819] pjproject: inv0x7f1318012 ....Got SDP answer in Response msg 200/INVITE/cseq=31218 (rdata0x7f1324218178) [Jul 28 16:08:01] DEBUG[1819] pjproject: inv0x7f1318012 ....SDP negotiation done, status=0 [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler [Jul 28 16:08:01] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:01] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:01] DEBUG[1819] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f13180254f8' [Jul 28 16:08:01] DEBUG[1819] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f131c107df0 [Jul 28 16:08:01] DEBUG[1819] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f131c107df0 [Jul 28 16:08:01] DEBUG[1819] rtp_engine.c: Copying payload 8 (0x7f131801e6e0) from 0x7f131c107df0 to 0x7f13180256c0 [Jul 28 16:08:01] DEBUG[1819] rtp_engine.c: Copying payload 101 (0x7f1318020650) from 0x7f131c107df0 to 0x7f13180256c0 [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Applying negotiated SDP media stream 'video' using video SDP handler [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Applied negotiated SDP media stream 'video' using video SDP handler [Jul 28 16:08:01] DEBUG[1819] pjproject: inv0x7f1318012 ....Received Response msg 200/INVITE/cseq=31218 (rdata0x7f1324218178), sending ACK [Jul 28 16:08:01] DEBUG[1819] pjproject: endpoint ....Request msg ACK/cseq=31218 (tdta0x7f1318034900) created. [Jul 28 16:08:01] DEBUG[1819] pjproject: dlg0x7f1318012 .....Sending Request msg ACK/cseq=31218 (tdta0x7f1318034900) [Jul 28 16:08:01] DEBUG[1819] pjproject: sip_resolve.c .....Target '10.20.51.121:58181' type=Unspecified resolved to '10.20.51.121:58181' type=UDP (UDP transport) [Jul 28 16:08:01] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP request (411 bytes) to UDP:10.20.51.121:58181 ---> ACK sip:09264158@10.20.51.121:58181 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.125:5060;rport;branch=z9hG4bKPjswsyESIppUtg9XS-k61h0PYtHxG-94Qz From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: ;tag=aaae76ac-7015-4d62-92b6-394624dcb25e Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr CSeq: 31218 ACK Max-Forwards: 70 User-Agent: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:01] DEBUG[1857][C-00000000] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jul 28 16:08:01] DEBUG[1857][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:01] DEBUG[1857][C-00000000] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:01] DEBUG[1857][C-00000000] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:01] DEBUG[1857][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:01] DEBUG[1857][C-00000000] acl.c: Attached to given IP address [Jul 28 16:08:01] DEBUG[1857][C-00000000] res_rtp_asterisk.c: 0x7f1318013730 -- Probation learning mode pass with source address 10.20.51.121:50008 [Jul 28 16:08:01] VERBOSE[1857][C-00000000] res_rtp_asterisk.c: 0x7f1318013730 -- Probation passed - setting RTP source address to 10.20.51.121:50008 [Jul 28 16:08:01] DEBUG[1857][C-00000000] res_rtp_asterisk.c: No remote address on RTP instance '0x7f13180167b8' so dropping frame [Jul 28 16:08:01] DEBUG[1857][C-00000000] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Jul 28 16:08:01] DEBUG[1857][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:01] DEBUG[1857][C-00000000] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:01] DEBUG[1857][C-00000000] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:01] DEBUG[1857][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:01] DEBUG[1857][C-00000000] acl.c: Attached to given IP address [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131801fb08) [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The current inv state is CONFIRMED [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Sending request [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Method is ACK [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The current transaction state is Terminated [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The transaction state change event is RX_MSG [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: The current inv state is CONFIRMED [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:01] DEBUG[1819] res_pjsip_session.c: Response is 200 OK [Jul 28 16:08:01] VERBOSE[1857][C-00000000] app_dial.c: PJSIP/124-00000001 answered PJSIP/123-00000000 [Jul 28 16:08:01] DEBUG[1796] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 28 16:08:01] DEBUG[1808] devicestate.c: No provider found, checking channel drivers for PJSIP - 124 [Jul 28 16:08:01] DEBUG[1808] devicestate.c: Changing state for PJSIP/124 - state 2 (In use) [Jul 28 16:08:01] DEBUG[1808] devicestate.c: No provider found, checking channel drivers for PJSIP - 123 [Jul 28 16:08:01] DEBUG[1808] devicestate.c: Changing state for PJSIP/123 - state 2 (In use) [Jul 28 16:08:01] DEBUG[1858] pjproject: inv0x7f131800b .SDP negotiation done, status=0 [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Applying negotiated SDP media stream 'audio' using audio SDP handler [Jul 28 16:08:01] DEBUG[1858] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:01] DEBUG[1858] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:01] DEBUG[1858] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f13180167b8' [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Don't have a default tx payload type 96 format for m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 97 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 98 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 101 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 99 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Setting tx payload type 100 based on m type on 0x7f1316735fe0 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 0 (0x2b64d00) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 8 (0x2b6a680) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 96 (0x2ce0ed0) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 97 (0x2cec120) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 98 (0x2cec5a0) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 99 (0x2b6aa00) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 100 (0x2e377f0) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] rtp_engine.c: Copying payload 101 (0x2b6aa40) from 0x7f1316735fe0 to 0x7f1318016980 [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Applied negotiated SDP media stream 'audio' using audio SDP handler [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Applying negotiated SDP media stream 'video' using video SDP handler [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Applied negotiated SDP media stream 'video' using video SDP handler [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Jul 28 16:08:01] DEBUG[1858] pjproject: inv0x7f131800b .Sending Response msg 200/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:01] DEBUG[1858] pjproject: dlg0x7f131800b ..Sending Response msg 200/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:01] DEBUG[1858] pjproject: tsx0x7f131800d ..Sending Response msg 200/INVITE/cseq=21 (tdta0x7f1318003d60) in state Proceeding [Jul 28 16:08:01] DEBUG[1858] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 10.20.51.125:5060 [Jul 28 16:08:01] VERBOSE[1858] res_pjsip_logger.c: <--- Transmitting SIP response (784 bytes) to UDP:10.20.51.121:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.20.51.121:5060;rport=5060;received=10.20.51.121;branch=z9hG4bK.M72TLDke0 Call-ID: uoJcxXJlhy From: ;tag=E9Dmk5~vu To: ;tag=-ETaQK7rJfpsyXZQXwd6zezPXVAREANR CSeq: 21 INVITE Server: Asterisk PBX 13.10.0 Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE Contact: Supported: 100rel, timer, replaces, norefersub Content-Type: application/sdp Content-Length: 248 v=0 o=- 575 637 IN IP4 10.20.51.125 s=Asterisk c=IN IP4 10.20.51.125 t=0 0 m=audio 29302 RTP/AVP 8 100 a=rtpmap:8 PCMA/8000 a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-16 a=ptime:20 a=maxptime:150 a=sendrecv m=video 0 RTP/AVP 96 97 [Jul 28 16:08:01] DEBUG[1858] pjproject: tsx0x7f131800d ...State changed from Proceeding to Completed, event=TX_MSG [Jul 28 16:08:01] DEBUG[1858] pjproject: dlg0x7f131800b ....Transaction tsx0x7f131800d018 state changed to Completed [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131800d018) [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The current inv state is CONNECTING [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Source of transaction state change is TX_MSG [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Sending response [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f131800d018) [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The current transaction state is Completed [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The transaction state change event is TX_MSG [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: The current inv state is CONNECTING [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Sending response [Jul 28 16:08:01] DEBUG[1858] res_pjsip_session.c: Method is INVITE, Response is 200 OK [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge_native_rtp.c: Bridge '32b3bb8b-6d79-40f9-b77d-0ce24c6b4385' can not use native RTP bridge as two channels are required [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Chose bridge technology simple_bridge [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: calling simple_bridge technology constructor [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: calling simple_bridge technology start [Jul 28 16:08:01] DEBUG[1818] pjproject: tsx0x7f131801f Timeout timer event [Jul 28 16:08:01] DEBUG[1818] pjproject: tsx0x7f131801f .State changed from Terminated to Destroyed, event=TIMER [Jul 28 16:08:01] DEBUG[1818] pjproject: tsx0x7f131801f Transaction destroyed! [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: 0x7f1338000bd8(PJSIP/124-00000001) is joining [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: pushing 0x7f1338000bd8(PJSIP/124-00000001) [Jul 28 16:08:01] VERBOSE[1864][C-00000000] bridge_channel.c: Channel PJSIP/124-00000001 joined 'simple_bridge' basic-bridge <32b3bb8b-6d79-40f9-b77d-0ce24c6b4385> [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge_native_rtp.c: Bridge '32b3bb8b-6d79-40f9-b77d-0ce24c6b4385' can not use native RTP bridge as two channels are required [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge.c: Chose bridge technology simple_bridge [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385 is already using the new technology. [Jul 28 16:08:01] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: 0x7f1338000bd8(PJSIP/124-00000001) is joining simple_bridge technology [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: 0x7f1338006b18(PJSIP/123-00000000) is joining [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: pushing 0x7f1338006b18(PJSIP/123-00000000) [Jul 28 16:08:01] VERBOSE[1857][C-00000000] bridge_channel.c: Channel PJSIP/123-00000000 joined 'simple_bridge' basic-bridge <32b3bb8b-6d79-40f9-b77d-0ce24c6b4385> [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge_native_rtp.c: Bridge '32b3bb8b-6d79-40f9-b77d-0ce24c6b4385' can not use native RTP bridge as it was forbidden while getting details [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Chose bridge technology simple_bridge [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385 is already using the new technology. [Jul 28 16:08:01] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: 0x7f1338006b18(PJSIP/123-00000000) is joining simple_bridge technology [Jul 28 16:08:01] DEBUG[1809] cdr.c: Finalized CDR for PJSIP/124-00000001 - start 1469714880.488402 answer 1469714881.979971 end 1469714881.982985 dispo ANSWERED [Jul 28 16:08:01] DEBUG[1864][C-00000000] stun.c: Runt Attribute (got 1, expecting 4) [Jul 28 16:08:01] DEBUG[1857][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Jul 28 16:08:01] DEBUG[1857][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7f13180167b8' [Jul 28 16:08:02] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg ACK/cseq=21 (rdata0x7f1324063078) [Jul 28 16:08:02] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (534 bytes) from UDP:10.20.51.121:5060 ---> ACK sip:10.20.51.125:5060 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:5060;rport;branch=z9hG4bK.11hhtRJbV From: ;tag=E9Dmk5~vu To: ;tag=-ETaQK7rJfpsyXZQXwd6zezPXVAREANR CSeq: 21 ACK Call-ID: uoJcxXJlhy Max-Forwards: 70 Authorization: Digest realm="asterisk", nonce="1469714880/8d32fa5c2c4b61ffc06d1c5570c1c60e", algorithm=md5, opaque="4203b3cc634da830", username="123", uri="sip:124@10.20.51.125", response="bca4d8f36d2ec4bc72e23cde1f3f83be", cnonce="76523cc5", nc=00000001, qop=auth [Jul 28 16:08:02] DEBUG[1818] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f131800b658 for Request msg ACK/cseq=21 (rdata0x7f1324063078) [Jul 28 16:08:02] DEBUG[1818] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000021 on dialog dlg0x7f131800b658 [Jul 28 16:08:02] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg ACK/cseq=21 (rdata0x7f1324218178) [Jul 28 16:08:02] DEBUG[1819] pjproject: dlg0x7f131800b .Received Request msg ACK/cseq=21 (rdata0x7f1324218178) [Jul 28 16:08:02] DEBUG[1819] pjproject: tsx0x7f131800d ..Request to terminate transaction [Jul 28 16:08:02] DEBUG[1819] pjproject: tsx0x7f131800d ...State changed from Completed to Terminated, event=USER [Jul 28 16:08:02] DEBUG[1819] pjproject: dlg0x7f131800b ....Transaction tsx0x7f131800d018 state changed to Terminated [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The current transaction state is Terminated [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The transaction state change event is USER [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The current inv state is CONNECTING [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: The current inv state is CONFIRMED [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: Received request [Jul 28 16:08:02] DEBUG[1819] res_pjsip_session.c: Method is ACK [Jul 28 16:08:02] DEBUG[1818] pjproject: tsx0x7f131800d Timeout timer event [Jul 28 16:08:02] DEBUG[1818] pjproject: tsx0x7f131800d .State changed from Terminated to Destroyed, event=TIMER [Jul 28 16:08:02] DEBUG[1818] pjproject: tdta0x7f131800 ..Destroying txdata Response msg 200/INVITE/cseq=21 (tdta0x7f1318003d60) [Jul 28 16:08:02] DEBUG[1818] pjproject: tsx0x7f131800d Transaction destroyed! [Jul 28 16:08:02] DEBUG[1857][C-00000000] res_rtp_asterisk.c: 0x7f13180172b0 -- Probation learning mode pass with source address 10.20.51.121:7078 [Jul 28 16:08:02] VERBOSE[1857][C-00000000] res_rtp_asterisk.c: 0x7f13180172b0 -- Probation passed - setting RTP source address to 10.20.51.121:7078 [Jul 28 16:08:02] DEBUG[1864][C-00000000] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Jul 28 16:08:02] DEBUG[1864][C-00000000] stun.c: Runt Attribute (got 2, expecting 4) [Jul 28 16:08:02] DEBUG[1864][C-00000000] stun.c: Runt Attribute (got 3, expecting 4) [Jul 28 16:08:02] DEBUG[1864][C-00000000] res_rtp_asterisk.c: Got RTCP report of 84 bytes [Jul 28 16:08:02] DEBUG[1864][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:02] DEBUG[1864][C-00000000] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:02] DEBUG[1864][C-00000000] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:02] DEBUG[1864][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:02] DEBUG[1864][C-00000000] acl.c: Attached to given IP address [Jul 28 16:08:02] DEBUG[1864][C-00000000] stun.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 4) [Jul 28 16:08:02] DEBUG[1864][C-00000000] stun.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 5) [Jul 28 16:08:03] DEBUG[1857][C-00000000] res_rtp_asterisk.c: Got RTCP report of 100 bytes [Jul 28 16:08:03] DEBUG[1857][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:03] DEBUG[1857][C-00000000] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:03] DEBUG[1857][C-00000000] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:03] DEBUG[1857][C-00000000] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:03] DEBUG[1857][C-00000000] acl.c: Attached to given IP address [Jul 28 16:08:03] DEBUG[1864][C-00000000] stun.c: Inconsistent Attribute (length 8228 exceeds remaining msg len 6) [Jul 28 16:08:03] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg BYE/cseq=22 (rdata0x7f1324063078) [Jul 28 16:08:03] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (581 bytes) from UDP:10.20.51.121:5060 ---> BYE sip:10.20.51.125:5060 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:5060;branch=z9hG4bK.FkOhvSKca;rport From: ;tag=E9Dmk5~vu To: ;tag=-ETaQK7rJfpsyXZQXwd6zezPXVAREANR CSeq: 22 BYE Call-ID: uoJcxXJlhy Max-Forwards: 70 User-Agent: Linphone/3.9.1 (belle-sip/1.4.2) Authorization: Digest realm="asterisk", nonce="1469714880/8d32fa5c2c4b61ffc06d1c5570c1c60e", algorithm=md5, opaque="4203b3cc634da830", username="123", uri="sip:10.20.51.125:5060", response="0ee680942ca114ab627e94df562a4af8", cnonce="ec779e7e", nc=00000002, qop=auth [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f131800b658 for Request msg BYE/cseq=22 (rdata0x7f1324063078) [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000021 on dialog dlg0x7f131800b658 [Jul 28 16:08:03] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg BYE/cseq=22 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f131800b .Received Request msg BYE/cseq=22 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131800d ...Transaction created for Request msg BYE/cseq=22 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131800d ..Incoming Request msg BYE/cseq=22 (rdata0x7f1324218178) in state Null [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131800d ...State changed from Null to Trying, event=RX_MSG [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f131800b ....Transaction tsx0x7f131800d018 state changed to Trying [Jul 28 16:08:03] DEBUG[1819] pjproject: endpoint .....Response msg 200/BYE/cseq=22 (tdta0x7f132404f340) created [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f131800b ......Sending Response msg 200/BYE/cseq=22 (tdta0x7f132404f340) [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131800d ......Sending Response msg 200/BYE/cseq=22 (tdta0x7f132404f340) in state Trying [Jul 28 16:08:03] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (306 bytes) to UDP:10.20.51.121:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.20.51.121:5060;rport=5060;received=10.20.51.121;branch=z9hG4bK.FkOhvSKca Call-ID: uoJcxXJlhy From: ;tag=E9Dmk5~vu To: ;tag=-ETaQK7rJfpsyXZQXwd6zezPXVAREANR CSeq: 22 BYE Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131800d .......State changed from Trying to Completed, event=TX_MSG [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f131800b ........Transaction tsx0x7f131800d018 state changed to Completed [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current transaction state is Completed [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The transaction state change event is TX_MSG [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current inv state is CONFIRMED [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Sending response [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Method is BYE, Response is 200 OK [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current inv state is DISCONNCTD [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Received request [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Method is BYE [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f131800b ......Session count dec to 4 by mod-invite [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '123(PJSIP/123-00000000)' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current transaction state is Completed [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The transaction state change event is RX_MSG [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current inv state is DISCONNCTD [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge_channel.c: Setting 0x7f1338006b18(PJSIP/123-00000000) state from:0 to:1 [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: pulling 0x7f1338006b18(PJSIP/123-00000000) [Jul 28 16:08:03] VERBOSE[1857][C-00000000] bridge_channel.c: Channel PJSIP/123-00000000 left 'simple_bridge' basic-bridge <32b3bb8b-6d79-40f9-b77d-0ce24c6b4385> [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: 0x7f1338006b18(PJSIP/123-00000000) is leaving simple_bridge technology [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: dissolving bridge with cause 16(Normal Clearing) [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge_channel.c: Setting 0x7f1338000bd8(PJSIP/124-00000001) state from:0 to:2 [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: queueing action type:13 sub:1001 [Jul 28 16:08:03] DEBUG[1809] cdr.c: Finalized CDR for PJSIP/123-00000000 - start 1469714880.486021 answer 1469714881.979982 end 1469714883.846039 dispo ANSWERED [Jul 28 16:08:03] DEBUG[1857][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385 is dissolved, not performing smart bridge operation. [Jul 28 16:08:03] DEBUG[1857][C-00000000] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Jul 28 16:08:03] DEBUG[1857][C-00000000] pbx.c: Spawn extension (internal-context,124,2) exited non-zero on 'PJSIP/123-00000000' [Jul 28 16:08:03] VERBOSE[1857][C-00000000] pbx.c: Spawn extension (internal-context, 124, 2) exited non-zero on 'PJSIP/123-00000000' [Jul 28 16:08:03] DEBUG[1857][C-00000000] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/123-00000000' [Jul 28 16:08:03] DEBUG[1857][C-00000000] channel.c: Hanging up channel 'PJSIP/123-00000000' [Jul 28 16:08:03] DEBUG[1857][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Jul 28 16:08:03] DEBUG[1808] devicestate.c: No provider found, checking channel drivers for PJSIP - 123 [Jul 28 16:08:03] DEBUG[1808] devicestate.c: Changing state for PJSIP/123 - state 1 (Not in use) [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: pulling 0x7f1338000bd8(PJSIP/124-00000001) [Jul 28 16:08:03] VERBOSE[1864][C-00000000] bridge_channel.c: Channel PJSIP/124-00000001 left 'simple_bridge' basic-bridge <32b3bb8b-6d79-40f9-b77d-0ce24c6b4385> [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge_channel.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: 0x7f1338000bd8(PJSIP/124-00000001) is leaving simple_bridge technology [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385 is dissolved, not performing smart bridge operation. [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: actually destroying basic bridge, nobody wants it anymore [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: calling basic bridge destructor [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: calling simple_bridge technology stop [Jul 28 16:08:03] DEBUG[1864][C-00000000] bridge.c: Bridge 32b3bb8b-6d79-40f9-b77d-0ce24c6b4385: calling simple_bridge technology destructor [Jul 28 16:08:03] DEBUG[1864][C-00000000] channel.c: Hanging up channel 'PJSIP/124-00000001' [Jul 28 16:08:03] DEBUG[1864][C-00000000] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Jul 28 16:08:03] DEBUG[1819] pjproject: endpoint .Request msg BYE/cseq=31220 (tdta0x7f1318003d60) created. [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Method is BYE [Jul 28 16:08:03] DEBUG[1819] pjproject: inv0x7f1318012 .Sending Request msg BYE/cseq=31220 (tdta0x7f1318003d60) [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f1318012 ..Sending Request msg BYE/cseq=31220 (tdta0x7f1318003d60) [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131801f ...Transaction created for Request msg BYE/cseq=31219 (tdta0x7f1318003d60) [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131801f ..Sending Request msg BYE/cseq=31219 (tdta0x7f1318003d60) in state Null [Jul 28 16:08:03] DEBUG[1819] pjproject: sip_resolve.c ...Target '10.20.51.121:58181' type=Unspecified resolved to '10.20.51.121:58181' type=UDP (UDP transport) [Jul 28 16:08:03] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP request (435 bytes) to UDP:10.20.51.121:58181 ---> BYE sip:09264158@10.20.51.121:58181 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.125:5060;rport;branch=z9hG4bKPjS6Ndr1YFZ6ZKGdhIajlX-YockvGRKETm From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: ;tag=aaae76ac-7015-4d62-92b6-394624dcb25e Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr CSeq: 31219 BYE Reason: Q.850;cause=16 Max-Forwards: 70 User-Agent: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131801f ...State changed from Null to Calling, event=TX_MSG [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f1318012 ....Transaction tsx0x7f131801fb08 state changed to Calling [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124(PJSIP/124-00000001)' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current transaction state is Calling [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The transaction state change event is TX_MSG [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current inv state is CONFIRMED [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Sending request [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Method is BYE [Jul 28 16:08:03] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Response msg 200/BYE/cseq=31219 (rdata0x7f1324063078) [Jul 28 16:08:03] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP response (386 bytes) from UDP:10.20.51.121:58181 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.20.51.125:5060;rport=5060;received=10.20.51.125;branch=z9hG4bKPjS6Ndr1YFZ6ZKGdhIajlX-YockvGRKETm Call-ID: 5m6BkTrnxVokYTGHf7JxBLR.0SIQxbsr From: ;tag=fqziQyXUegU.d0ZBV1tmaB9kEdj.B2Xz To: ;tag=aaae76ac-7015-4d62-92b6-394624dcb25e CSeq: 31219 BYE Server: Blink 2.0.0 (Linux) Content-Length: 0 [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Searching for serializer on dialog dlg0x7f13180126b8 for Response msg 200/BYE/cseq=31219 (rdata0x7f1324063078) [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/124-00000047 on dialog dlg0x7f13180126b8 [Jul 28 16:08:03] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Response msg 200/BYE/cseq=31219 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131801f .Incoming Response msg 200/BYE/cseq=31219 (rdata0x7f1324218178) in state Calling [Jul 28 16:08:03] DEBUG[1819] pjproject: tsx0x7f131801f ..State changed from Calling to Completed, event=RX_MSG [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f1318012 ...Received Response msg 200/BYE/cseq=31219 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f1318012 ...Transaction tsx0x7f131801fb08 state changed to Completed [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124()' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: There is no transaction involved in this state change [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current inv state is DISCONNCTD [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Source of transaction state change is RX_MSG [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Response is 200 OK [Jul 28 16:08:03] DEBUG[1819] pjproject: tdta0x7f131803 ....Destroying txdata Request msg ACK/cseq=31218 (tdta0x7f1318034900) [Jul 28 16:08:03] DEBUG[1819] pjproject: tdta0x7f131800 ....Destroying txdata Request msg INVITE/cseq=31218 (tdta0x7f1318004d70) [Jul 28 16:08:03] DEBUG[1819] pjproject: dlg0x7f1318012 .....Session count dec to 2 by mod-invite [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The state change pertains to the endpoint '124()' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current transaction state is Completed [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The transaction state change event is RX_MSG [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: The current inv state is DISCONNCTD [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Received response [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: Response is 200 OK [Jul 28 16:08:03] DEBUG[1819] res_pjsip_session.c: BYE received final response code 200 [Jul 28 16:08:03] DEBUG[1809] cdr.c: CDR for PJSIP/124-00000001 is dialed and has no Party B; discarding [Jul 28 16:08:03] DEBUG[1808] devicestate.c: No provider found, checking channel drivers for PJSIP - 124 [Jul 28 16:08:03] DEBUG[1808] devicestate.c: Changing state for PJSIP/124 - state 1 (Not in use) [Jul 28 16:08:03] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg PUBLISH/cseq=1 (rdata0x7f1324063078) [Jul 28 16:08:03] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (2270 bytes) from UDP:10.20.51.121:58181 ---> PUBLISH sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:58181;rport;branch=z9hG4bKPj8b54a72d-431f-4f62-b918-116224d31e97 Max-Forwards: 70 From: "yrid" ;tag=69bd835c-26f4-4eb9-b2d4-c3a89f2f3b3a To: "yrid" Call-ID: 552cec27-5da2-44c3-b09f-9f8d2b4916ae CSeq: 1 PUBLISH Event: presence Expires: 600 User-Agent: Blink 2.0.0 (Linux) Content-Type: application/pidf+xml Content-Length: 1816 openavailabletruetruefalsetruetruetrueyridjan-siprBlink 2.0.0 (Linux)120activecd891f2d-01ac-4060-b78c-8fe805a949aasip%3A124%4010.20.51.1252016-07-28T16:08:05.505780+02:00available2016-07-28T16:08:05.505780+02:00cd891f2d-01ac-4060-b78c-8fe805a949aaBlink 2.0.0 (Linux) at jan-sipr2016-07-28T16:08:05.505780+02:00 [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg PUBLISH/cseq=1 (rdata0x7f1324063078) [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000032 to use for Request msg PUBLISH/cseq=1 (rdata0x7f1324063078) [Jul 28 16:08:03] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg PUBLISH/cseq=1 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:03] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '124' domain '10.20.51.125' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '124' domain '10.20.51.125' [Jul 28 16:08:03] DEBUG[1819] pjproject: endpoint .Response msg 401/PUBLISH/cseq=1 (tdta0x7f1318004d70) created [Jul 28 16:08:03] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:03] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:03] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:03] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:03] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (576 bytes) to UDP:10.20.51.121:58181 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.20.51.121:58181;rport=58181;received=10.20.51.121;branch=z9hG4bKPj8b54a72d-431f-4f62-b918-116224d31e97 Call-ID: 552cec27-5da2-44c3-b09f-9f8d2b4916ae From: "yrid" ;tag=69bd835c-26f4-4eb9-b2d4-c3a89f2f3b3a To: "yrid" ;tag=z9hG4bKPj8b54a72d-431f-4f62-b918-116224d31e97 CSeq: 1 PUBLISH WWW-Authenticate: Digest realm="asterisk",nonce="1469714883/aabe3385b4612a48c6cf79c4affe4cc6",opaque="441b5758754ca877",algorithm=md5,qop="auth" Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:03] DEBUG[1819] pjproject: tdta0x7f131800 .Destroying txdata Response msg 401/PUBLISH/cseq=1 (tdta0x7f1318004d70) [Jul 28 16:08:03] DEBUG[1818] pjproject: sip_endpoint.c Processing incoming message: Request msg PUBLISH/cseq=2 (rdata0x7f1324063078) [Jul 28 16:08:03] VERBOSE[1818] res_pjsip_logger.c: <--- Received SIP request (2564 bytes) from UDP:10.20.51.121:58181 ---> PUBLISH sip:124@10.20.51.125 SIP/2.0 Via: SIP/2.0/UDP 10.20.51.121:58181;rport;branch=z9hG4bKPj002dd490-b0ee-490f-abe1-64153cd3a5b9 Max-Forwards: 70 From: "yrid" ;tag=69bd835c-26f4-4eb9-b2d4-c3a89f2f3b3a To: "yrid" Call-ID: 552cec27-5da2-44c3-b09f-9f8d2b4916ae CSeq: 2 PUBLISH Event: presence Expires: 600 User-Agent: Blink 2.0.0 (Linux) Authorization: Digest username="124", realm="asterisk", nonce="1469714883/aabe3385b4612a48c6cf79c4affe4cc6", uri="sip:124@10.20.51.125", response="a02583e2ea0d736e7d75a902a91fa9f9", algorithm=md5, cnonce="7a42dc55-2ae1-46ef-a88a-94b88f02a72d", opaque="441b5758754ca877", qop=auth, nc=00000001 Content-Type: application/pidf+xml Content-Length: 1816 openavailabletruetruefalsetruetruetrueyridjan-siprBlink 2.0.0 (Linux)120activecd891f2d-01ac-4060-b78c-8fe805a949aasip%3A124%4010.20.51.1252016-07-28T16:08:05.505780+02:00available2016-07-28T16:08:05.505780+02:00cd891f2d-01ac-4060-b78c-8fe805a949aaBlink 2.0.0 (Linux) at jan-sipr2016-07-28T16:08:05.505780+02:00 [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg PUBLISH/cseq=2 (rdata0x7f1324063078) [Jul 28 16:08:03] DEBUG[1818] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000032 to use for Request msg PUBLISH/cseq=2 (rdata0x7f1324063078) [Jul 28 16:08:03] DEBUG[1819] pjproject: sip_endpoint.c Distributing rdata to modules: Request msg PUBLISH/cseq=2 (rdata0x7f1324218178) [Jul 28 16:08:03] DEBUG[1819] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Jul 28 16:08:03] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '124' domain '10.20.51.125' [Jul 28 16:08:03] DEBUG[1819] res_pjsip_endpoint_identifier_user.c: Identified by From username '124' domain '10.20.51.125' [Jul 28 16:08:03] DEBUG[1819] pjproject: endpoint .Response msg 401/PUBLISH/cseq=2 (tdta0x7f1318004d70) created [Jul 28 16:08:03] DEBUG[1819] res_pjsip_authenticator_digest.c: Calculated nonce 1469714883/aabe3385b4612a48c6cf79c4affe4cc6. Actual nonce is 1469714883/aabe3385b4612a48c6cf79c4affe4cc6 [Jul 28 16:08:03] DEBUG[1819] netsock2.c: Splitting '10.20.51.125' into... [Jul 28 16:08:03] DEBUG[1819] netsock2.c: ...host '10.20.51.125' and port ''. [Jul 28 16:08:03] DEBUG[1819] netsock2.c: Splitting '10.20.51.121' into... [Jul 28 16:08:03] DEBUG[1819] netsock2.c: ...host '10.20.51.121' and port ''. [Jul 28 16:08:03] DEBUG[1819] pjproject: tdta0x7f131800 .Destroying txdata Response msg 401/PUBLISH/cseq=2 (tdta0x7f1318004d70) [Jul 28 16:08:03] DEBUG[1819] res_pjsip_pubsub.c: Event presence does not match asterisk-devicestate [Jul 28 16:08:03] DEBUG[1819] res_pjsip_pubsub.c: Event presence does not match asterisk-mwi [Jul 28 16:08:03] WARNING[1819] res_pjsip_pubsub.c: No registered publish handler for event presence [Jul 28 16:08:03] DEBUG[1819] pjproject: endpoint .Response msg 489/PUBLISH/cseq=2 (tdta0x7f1318004d70) created [Jul 28 16:08:03] VERBOSE[1819] res_pjsip_logger.c: <--- Transmitting SIP response (426 bytes) to UDP:10.20.51.121:58181 ---> SIP/2.0 489 Bad Event Via: SIP/2.0/UDP 10.20.51.121:58181;rport=58181;received=10.20.51.121;branch=z9hG4bKPj002dd490-b0ee-490f-abe1-64153cd3a5b9 Call-ID: 552cec27-5da2-44c3-b09f-9f8d2b4916ae From: "yrid" ;tag=69bd835c-26f4-4eb9-b2d4-c3a89f2f3b3a To: "yrid" ;tag=z9hG4bKPj002dd490-b0ee-490f-abe1-64153cd3a5b9 CSeq: 2 PUBLISH Server: Asterisk PBX 13.10.0 Content-Length: 0 [Jul 28 16:08:03] DEBUG[1819] pjproject: tdta0x7f131800 .Destroying txdata Response msg 489/PUBLISH/cseq=2 (tdta0x7f1318004d70) [Jul 28 16:08:06] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:06] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:06] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:06] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:06] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:06] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:06] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:06] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:06] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:06] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:08] DEBUG[1818] pjproject: tsx0x7f131801f Timeout timer event [Jul 28 16:08:08] DEBUG[1818] pjproject: tsx0x7f131801f .State changed from Completed to Terminated, event=TIMER [Jul 28 16:08:08] DEBUG[1818] pjproject: dlg0x7f1318012 ..Transaction tsx0x7f131801fb08 state changed to Terminated [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: The state change pertains to the endpoint '124()' [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f131801fb08 [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: The current transaction state is Terminated [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: The transaction state change event is TIMER [Jul 28 16:08:08] DEBUG[1818] res_pjsip_session.c: The current inv state is DISCONNCTD [Jul 28 16:08:08] DEBUG[1819] res_pjsip_session.c: Destroying SIP session with endpoint 124 [Jul 28 16:08:08] DEBUG[1819] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f13180254f8' [Jul 28 16:08:08] DEBUG[1819] rtp_engine.c: Destroyed RTP instance '0x7f13180254f8' [Jul 28 16:08:08] DEBUG[1819] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f131802eda8' [Jul 28 16:08:08] DEBUG[1819] rtp_engine.c: Destroyed RTP instance '0x7f131802eda8' [Jul 28 16:08:08] DEBUG[1819] pjproject: dlg0x7f1318012 .Session count dec to 0 by Session Module [Jul 28 16:08:08] DEBUG[1819] pjproject: dlg0x7f1318012 .Dialog destroyed [Jul 28 16:08:08] DEBUG[1818] pjproject: tsx0x7f131801f Timeout timer event [Jul 28 16:08:08] DEBUG[1818] pjproject: tsx0x7f131801f .State changed from Terminated to Destroyed, event=TIMER [Jul 28 16:08:08] DEBUG[1818] pjproject: tdta0x7f131800 ..Destroying txdata Request msg BYE/cseq=31219 (tdta0x7f1318003d60) [Jul 28 16:08:08] DEBUG[1818] pjproject: tsx0x7f131801f Transaction destroyed! [Jul 28 16:08:11] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:11] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:11] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:11] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:11] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:16] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:16] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:16] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:16] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:16] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:21] DEBUG[1863] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:21] DEBUG[1796] threadpool.c: Destroying worker thread 21 [Jul 28 16:08:21] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:21] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:21] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:21] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:21] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:23] DEBUG[1856] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:08:23] DEBUG[1796] threadpool.c: Destroying worker thread 15 [Jul 28 16:08:26] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:26] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:26] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:26] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:26] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:31] DEBUG[1840] res_pjsip_registrar_expire.c: Woke up at 1469714911 Interval: 30 [Jul 28 16:08:31] DEBUG[1840] res_pjsip_registrar_expire.c: Expiring 0 contacts [Jul 28 16:08:31] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:31] DEBUG[1836] netsock2.c: Splitting 'debian' into... [Jul 28 16:08:31] DEBUG[1836] netsock2.c: ...host 'debian' and port ''. [Jul 28 16:08:31] DEBUG[1836] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 28 16:08:31] DEBUG[1836] acl.c: Attached to given IP address [Jul 28 16:08:35] DEBUG[1818] pjproject: tsx0x7f131800d Timeout timer event [Jul 28 16:08:35] DEBUG[1818] pjproject: tsx0x7f131800d .State changed from Completed to Terminated, event=TIMER [Jul 28 16:08:35] DEBUG[1818] pjproject: dlg0x7f131800b ..Transaction tsx0x7f131800d018 state changed to Terminated [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: The state change pertains to the endpoint '123()' [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f131800d018 [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: The current transaction state is Terminated [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: The transaction state change event is TIMER [Jul 28 16:08:35] DEBUG[1818] res_pjsip_session.c: The current inv state is DISCONNCTD [Jul 28 16:08:35] DEBUG[1819] res_pjsip_session.c: Destroying SIP session with endpoint 123 [Jul 28 16:08:35] DEBUG[1819] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f13180167b8' [Jul 28 16:08:35] DEBUG[1819] rtp_engine.c: Destroyed RTP instance '0x7f13180167b8' [Jul 28 16:08:35] DEBUG[1819] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f1318024d88' [Jul 28 16:08:35] DEBUG[1819] rtp_engine.c: Destroyed RTP instance '0x7f1318024d88' [Jul 28 16:08:35] DEBUG[1819] pjproject: dlg0x7f131800b .Session count dec to 0 by Session Module [Jul 28 16:08:35] DEBUG[1819] pjproject: dlg0x7f131800b .Dialog destroyed [Jul 28 16:08:35] DEBUG[1818] pjproject: tsx0x7f131800d Timeout timer event [Jul 28 16:08:35] DEBUG[1818] pjproject: tsx0x7f131800d .State changed from Terminated to Destroyed, event=TIMER [Jul 28 16:08:35] DEBUG[1818] pjproject: tdta0x7f132404 ..Destroying txdata Response msg 200/BYE/cseq=22 (tdta0x7f132404f340) [Jul 28 16:08:35] DEBUG[1818] pjproject: tsx0x7f131800d Transaction destroyed! [Jul 28 16:08:36] VERBOSE[1850] asterisk.c: Remote UNIX connection disconnected [Jul 28 16:09:00] DEBUG[1861] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:09:00] DEBUG[1862] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:09:00] DEBUG[1860] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:09:00] DEBUG[1859] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:09:00] DEBUG[1816] threadpool.c: Destroying worker thread 19 [Jul 28 16:09:00] DEBUG[1816] threadpool.c: Destroying worker thread 20 [Jul 28 16:09:00] DEBUG[1816] threadpool.c: Destroying worker thread 18 [Jul 28 16:09:00] DEBUG[1816] threadpool.c: Destroying worker thread 17 [Jul 28 16:09:01] DEBUG[1840] res_pjsip_registrar_expire.c: Woke up at 1469714941 Interval: 30 [Jul 28 16:09:01] DEBUG[1840] res_pjsip_registrar_expire.c: Expiring 0 contacts [Jul 28 16:09:01] DEBUG[1858] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 28 16:09:01] DEBUG[1816] threadpool.c: Destroying worker thread 16 [Jul 28 16:09:10] DEBUG[1794] cdr.c: CDR Engine termination request received; waiting on messages... [Jul 28 16:09:10] VERBOSE[1794] asterisk.c: Asterisk cleanly ending (0). [Jul 28 16:09:10] VERBOSE[1794] asterisk.c: Executing last minute cleanups [Jul 28 16:09:10] VERBOSE[1794] res_musiconhold.c: Destroying musiconhold processes [Jul 28 16:09:10] VERBOSE[1794] manager.c: Manager unregistered action DBGet [Jul 28 16:09:10] VERBOSE[1794] manager.c: Manager unregistered action DBPut [Jul 28 16:09:10] VERBOSE[1794] manager.c: Manager unregistered action DBDel [Jul 28 16:09:10] VERBOSE[1794] manager.c: Manager unregistered action DBDelTree [Jul 28 16:09:10] DEBUG[1794] asterisk.c: Asterisk ending (0).