[2019-04-09 16:06:48.691100] Asterisk 16.3.0 built by root @ 5723d3300f4d on a x86_64 running Linux on 2019-04-08 23:40:40 UTC [2019-04-09 16:06:48.699723] VERBOSE[85] message.c: Message handler 'dialplan' registered. [2019-04-09 16:06:48.701197] VERBOSE[85] pbx_functions.c: Registered custom function 'MESSAGE' [2019-04-09 16:06:48.702020] VERBOSE[85] pbx_functions.c: Registered custom function 'MESSAGE_DATA' [2019-04-09 16:06:48.703272] VERBOSE[85] pbx_app.c: Registered application 'MessageSend' [2019-04-09 16:06:48.706370] VERBOSE[85] manager.c: Manager registered action MessageSend [2019-04-09 16:06:48.706444] VERBOSE[85] channel.c: Registered channel type 'Surrogate' (Surrogate channel used to pull channel from an application) [2019-04-09 16:06:48.707514] VERBOSE[85] manager.c: Manager registered action BridgeTechnologyList [2019-04-09 16:06:48.708153] VERBOSE[85] manager.c: Manager registered action BridgeTechnologySuspend [2019-04-09 16:06:48.708794] VERBOSE[85] manager.c: Manager registered action BridgeTechnologyUnsuspend [2019-04-09 16:06:48.709146] VERBOSE[85] dns_core.c: Registered DNS resolver 'system' with priority '2147483647' [2019-04-09 16:06:48.709382] VERBOSE[85] pbx.c: Asterisk PBX Core Initializing [2019-04-09 16:06:48.709412] VERBOSE[85] pbx.c: Registering builtin functions: [2019-04-09 16:06:48.711590] VERBOSE[85] pbx_functions.c: Registered custom function 'EXCEPTION' [2019-04-09 16:06:48.712377] VERBOSE[85] pbx_functions.c: Registered custom function 'TESTTIME' [2019-04-09 16:06:48.713092] VERBOSE[85] manager.c: Manager registered action ShowDialPlan [2019-04-09 16:06:48.714305] VERBOSE[85] manager.c: Manager registered action ExtensionStateList [2019-04-09 16:06:48.716689] VERBOSE[85] pbx_app.c: Registered application 'Answer' [2019-04-09 16:06:48.717692] VERBOSE[85] pbx_app.c: Registered application 'BackGround' [2019-04-09 16:06:48.718300] VERBOSE[85] pbx_app.c: Registered application 'Busy' [2019-04-09 16:06:48.719040] VERBOSE[85] pbx_app.c: Registered application 'Congestion' [2019-04-09 16:06:48.720753] VERBOSE[85] pbx_app.c: Registered application 'ExecIfTime' [2019-04-09 16:06:48.721901] VERBOSE[85] pbx_app.c: Registered application 'Goto' [2019-04-09 16:06:48.722974] VERBOSE[85] pbx_app.c: Registered application 'GotoIf' [2019-04-09 16:06:48.724010] VERBOSE[85] pbx_app.c: Registered application 'GotoIfTime' [2019-04-09 16:06:48.725944] VERBOSE[85] pbx_app.c: Registered application 'ImportVar' [2019-04-09 16:06:48.726697] VERBOSE[85] pbx_app.c: Registered application 'Hangup' [2019-04-09 16:06:48.727439] VERBOSE[85] pbx_app.c: Registered application 'Incomplete' [2019-04-09 16:06:48.728157] VERBOSE[85] pbx_app.c: Registered application 'NoOp' [2019-04-09 16:06:48.728889] VERBOSE[85] pbx_app.c: Registered application 'Proceeding' [2019-04-09 16:06:48.730645] VERBOSE[85] pbx_app.c: Registered application 'Progress' [2019-04-09 16:06:48.731306] VERBOSE[85] pbx_app.c: Registered application 'RaiseException' [2019-04-09 16:06:48.731958] VERBOSE[85] pbx_app.c: Registered application 'Ringing' [2019-04-09 16:06:48.732670] VERBOSE[85] pbx_app.c: Registered application 'SayAlpha' [2019-04-09 16:06:48.733494] VERBOSE[85] pbx_app.c: Registered application 'SayAlphaCase' [2019-04-09 16:06:48.734206] VERBOSE[85] pbx_app.c: Registered application 'SayDigits' [2019-04-09 16:06:48.736126] VERBOSE[85] pbx_app.c: Registered application 'SayNumber' [2019-04-09 16:06:48.736881] VERBOSE[85] pbx_app.c: Registered application 'SayPhonetic' [2019-04-09 16:06:48.737531] VERBOSE[85] pbx_app.c: Registered application 'SetAMAFlags' [2019-04-09 16:06:48.738210] VERBOSE[85] pbx_app.c: Registered application 'Wait' [2019-04-09 16:06:48.739107] VERBOSE[85] pbx_app.c: Registered application 'WaitDigit' [2019-04-09 16:06:48.741105] VERBOSE[85] pbx_app.c: Registered application 'WaitExten' [2019-04-09 16:06:48.742165] VERBOSE[85] pbx_app.c: Registered application 'Set' [2019-04-09 16:06:48.742971] VERBOSE[85] pbx_app.c: Registered application 'MSet' [2019-04-09 16:06:48.743475] VERBOSE[85] channel.c: Registered channel type 'Local' (Local Proxy Channel Driver) [2019-04-09 16:06:48.744224] VERBOSE[85] manager.c: Manager registered action LocalOptimizeAway [2019-04-09 16:06:48.744262] VERBOSE[85] loader.c: Asterisk Dynamic Loader Starting: [2019-04-09 16:06:48.745793] NOTICE[85] loader.c: 63 modules will be loaded. [2019-04-09 16:06:49.265451] VERBOSE[85] loader.c: Loading extconfig. [2019-04-09 16:06:49.265933] VERBOSE[85] loader.c: extconfig => (Configuration) [2019-04-09 16:06:49.265991] VERBOSE[85] loader.c: Loading logger. [2019-04-09 16:06:49.266019] VERBOSE[85] loader.c: logger => (Logger) [2019-04-09 16:06:49.266038] VERBOSE[85] loader.c: Loading res_curl.so. [2019-04-09 16:06:49.266318] VERBOSE[85] loader.c: res_curl.so => (cURL Resource Module) [2019-04-09 16:06:49.266344] VERBOSE[85] loader.c: Loading res_sorcery_memory.so. [2019-04-09 16:06:49.266374] VERBOSE[85] sorcery.c: Sorcery registered wizard 'memory' [2019-04-09 16:06:49.266399] VERBOSE[85] loader.c: res_sorcery_memory.so => (Sorcery In-Memory Object Wizard) [2019-04-09 16:06:49.266417] VERBOSE[85] loader.c: Loading res_sorcery_astdb.so. [2019-04-09 16:06:49.266440] VERBOSE[85] sorcery.c: Sorcery registered wizard 'astdb' [2019-04-09 16:06:49.266466] VERBOSE[85] loader.c: res_sorcery_astdb.so => (Sorcery Astdb Object Wizard) [2019-04-09 16:06:49.266485] VERBOSE[85] loader.c: Loading res_sorcery_memory_cache.so. [2019-04-09 16:06:49.266718] VERBOSE[85] sorcery.c: Sorcery registered wizard 'memory_cache' [2019-04-09 16:06:49.268785] VERBOSE[85] manager.c: Manager registered action SorceryMemoryCacheExpireObject [2019-04-09 16:06:49.271841] VERBOSE[85] manager.c: Manager registered action SorceryMemoryCacheExpire [2019-04-09 16:06:49.273169] VERBOSE[85] manager.c: Manager registered action SorceryMemoryCacheStaleObject [2019-04-09 16:06:49.274439] VERBOSE[85] manager.c: Manager registered action SorceryMemoryCacheStale [2019-04-09 16:06:49.277023] VERBOSE[85] manager.c: Manager registered action SorceryMemoryCachePopulate [2019-04-09 16:06:49.277072] VERBOSE[85] loader.c: res_sorcery_memory_cache.so => (Sorcery Memory Cache Object Wizard) [2019-04-09 16:06:49.277095] VERBOSE[85] loader.c: Loading res_sorcery_config.so. [2019-04-09 16:06:49.277121] VERBOSE[85] sorcery.c: Sorcery registered wizard 'config' [2019-04-09 16:06:49.277143] VERBOSE[85] loader.c: res_sorcery_config.so => (Sorcery Configuration File Object Wizard) [2019-04-09 16:06:49.277161] VERBOSE[85] loader.c: Loading ccss. [2019-04-09 16:06:49.278276] VERBOSE[85] pbx_app.c: Registered application 'CallCompletionRequest' [2019-04-09 16:06:49.279090] VERBOSE[85] pbx_app.c: Registered application 'CallCompletionCancel' [2019-04-09 16:06:49.281026] VERBOSE[85] loader.c: ccss => (Call Completion Supplementary Services) [2019-04-09 16:06:49.281094] VERBOSE[85] loader.c: Loading cdr. [2019-04-09 16:06:49.288264] NOTICE[85] cdr.c: CDR simple logging enabled. [2019-04-09 16:06:49.288313] VERBOSE[85] loader.c: cdr => (CDR Engine) [2019-04-09 16:06:49.288355] VERBOSE[85] loader.c: Loading cel. [2019-04-09 16:06:49.291544] VERBOSE[85] loader.c: cel => (CEL Engine) [2019-04-09 16:06:49.291647] VERBOSE[85] loader.c: Loading dnsmgr. [2019-04-09 16:06:49.291860] VERBOSE[85] loader.c: dnsmgr => (DNS Manager) [2019-04-09 16:06:49.291902] VERBOSE[85] loader.c: Loading dsp. [2019-04-09 16:06:49.292048] VERBOSE[85] loader.c: dsp => (DSP) [2019-04-09 16:06:49.292087] VERBOSE[85] loader.c: Loading enum. [2019-04-09 16:06:49.292220] VERBOSE[85] loader.c: enum => (ENUM Support) [2019-04-09 16:06:49.292258] VERBOSE[85] loader.c: Loading features. [2019-04-09 16:06:49.309417] VERBOSE[85] pbx_functions.c: Registered custom function 'FEATURE' [2019-04-09 16:06:49.310380] VERBOSE[85] pbx_functions.c: Registered custom function 'FEATUREMAP' [2019-04-09 16:06:49.312096] VERBOSE[85] pbx_app.c: Registered application 'Bridge' [2019-04-09 16:06:49.313816] VERBOSE[85] manager.c: Manager registered action Bridge [2019-04-09 16:06:49.313862] VERBOSE[85] loader.c: features => (Call Features) [2019-04-09 16:06:49.313913] VERBOSE[85] loader.c: Loading http. [2019-04-09 16:06:49.315295] VERBOSE[85] http.c: Bound HTTP server to address 127.0.0.1:0 [2019-04-09 16:06:49.315326] VERBOSE[85] loader.c: http => (Built-in HTTP Server) [2019-04-09 16:06:49.315363] VERBOSE[85] loader.c: Loading indications. [2019-04-09 16:06:49.316227] VERBOSE[85] indications.c: Registered indication country 'at' [2019-04-09 16:06:49.316273] VERBOSE[85] indications.c: Registered indication country 'au' [2019-04-09 16:06:49.316303] VERBOSE[85] indications.c: Registered indication country 'bg' [2019-04-09 16:06:49.316331] VERBOSE[85] indications.c: Registered indication country 'br' [2019-04-09 16:06:49.316359] VERBOSE[85] indications.c: Registered indication country 'be' [2019-04-09 16:06:49.316387] VERBOSE[85] indications.c: Registered indication country 'ch' [2019-04-09 16:06:49.316416] VERBOSE[85] indications.c: Registered indication country 'cl' [2019-04-09 16:06:49.316460] VERBOSE[85] indications.c: Registered indication country 'cn' [2019-04-09 16:06:49.316503] VERBOSE[85] indications.c: Registered indication country 'cz' [2019-04-09 16:06:49.316535] VERBOSE[85] indications.c: Registered indication country 'de' [2019-04-09 16:06:49.318116] VERBOSE[85] indications.c: Registered indication country 'dk' [2019-04-09 16:06:49.318151] VERBOSE[85] indications.c: Registered indication country 'ee' [2019-04-09 16:06:49.318181] VERBOSE[85] indications.c: Registered indication country 'es' [2019-04-09 16:06:49.318209] VERBOSE[85] indications.c: Registered indication country 'fi' [2019-04-09 16:06:49.318238] VERBOSE[85] indications.c: Registered indication country 'fr' [2019-04-09 16:06:49.318265] VERBOSE[85] indications.c: Registered indication country 'gr' [2019-04-09 16:06:49.318294] VERBOSE[85] indications.c: Registered indication country 'hu' [2019-04-09 16:06:49.318322] VERBOSE[85] indications.c: Registered indication country 'il' [2019-04-09 16:06:49.318351] VERBOSE[85] indications.c: Registered indication country 'in' [2019-04-09 16:06:49.318378] VERBOSE[85] indications.c: Registered indication country 'it' [2019-04-09 16:06:49.318406] VERBOSE[85] indications.c: Registered indication country 'lt' [2019-04-09 16:06:49.318445] VERBOSE[85] indications.c: Registered indication country 'jp' [2019-04-09 16:06:49.318491] VERBOSE[85] indications.c: Registered indication country 'mx' [2019-04-09 16:06:49.318520] VERBOSE[85] indications.c: Registered indication country 'my' [2019-04-09 16:06:49.318578] VERBOSE[85] indications.c: Registered indication country 'nl' [2019-04-09 16:06:49.318610] VERBOSE[85] indications.c: Registered indication country 'no' [2019-04-09 16:06:49.318640] VERBOSE[85] indications.c: Registered indication country 'nz' [2019-04-09 16:06:49.318668] VERBOSE[85] indications.c: Registered indication country 'ph' [2019-04-09 16:06:49.318696] VERBOSE[85] indications.c: Registered indication country 'pl' [2019-04-09 16:06:49.318723] VERBOSE[85] indications.c: Registered indication country 'pt' [2019-04-09 16:06:49.318751] VERBOSE[85] indications.c: Registered indication country 'ru' [2019-04-09 16:06:49.318779] VERBOSE[85] indications.c: Registered indication country 'se' [2019-04-09 16:06:49.318812] VERBOSE[85] indications.c: Registered indication country 'sg' [2019-04-09 16:06:49.318840] VERBOSE[85] indications.c: Registered indication country 'th' [2019-04-09 16:06:49.318874] VERBOSE[85] indications.c: Registered indication country 'uk' [2019-04-09 16:06:49.318902] VERBOSE[85] indications.c: Registered indication country 'us' [2019-04-09 16:06:49.318930] VERBOSE[85] indications.c: Registered indication country 'us-old' [2019-04-09 16:06:49.318959] VERBOSE[85] indications.c: Registered indication country 'tw' [2019-04-09 16:06:49.318987] VERBOSE[85] indications.c: Registered indication country 've' [2019-04-09 16:06:49.319016] VERBOSE[85] indications.c: Registered indication country 'za' [2019-04-09 16:06:49.319062] VERBOSE[85] indications.c: Setting default indication country to 'us' [2019-04-09 16:06:49.319258] VERBOSE[85] loader.c: indications => (Indication Tone Handling) [2019-04-09 16:06:49.319332] VERBOSE[85] loader.c: Loading acl. [2019-04-09 16:06:49.320692] VERBOSE[85] loader.c: acl => (Named ACL system) [2019-04-09 16:06:49.320762] VERBOSE[85] loader.c: Loading manager. [2019-04-09 16:06:49.324257] VERBOSE[85] manager.c: Manager registered action Ping [2019-04-09 16:06:49.325144] VERBOSE[85] manager.c: Manager registered action Events [2019-04-09 16:06:49.325926] VERBOSE[85] manager.c: Manager registered action Logoff [2019-04-09 16:06:49.326734] VERBOSE[85] manager.c: Manager registered action Login [2019-04-09 16:06:49.329754] VERBOSE[85] manager.c: Manager registered action Challenge [2019-04-09 16:06:49.330628] VERBOSE[85] manager.c: Manager registered action Hangup [2019-04-09 16:06:49.332224] VERBOSE[85] manager.c: Manager registered action Status [2019-04-09 16:06:49.334128] VERBOSE[85] manager.c: Manager registered action Setvar [2019-04-09 16:06:49.335061] VERBOSE[85] manager.c: Manager registered action Getvar [2019-04-09 16:06:49.336327] VERBOSE[85] manager.c: Manager registered action GetConfig [2019-04-09 16:06:49.337531] VERBOSE[85] manager.c: Manager registered action GetConfigJSON [2019-04-09 16:06:49.339968] VERBOSE[85] manager.c: Manager registered action UpdateConfig [2019-04-09 16:06:49.340902] VERBOSE[85] manager.c: Manager registered action CreateConfig [2019-04-09 16:06:49.341805] VERBOSE[85] manager.c: Manager registered action ListCategories [2019-04-09 16:06:49.344169] VERBOSE[85] manager.c: Manager registered action Redirect [2019-04-09 16:06:49.345135] VERBOSE[85] manager.c: Manager registered action Atxfer [2019-04-09 16:06:49.346023] VERBOSE[85] manager.c: Manager registered action CancelAtxfer [2019-04-09 16:06:49.347240] VERBOSE[85] manager.c: Manager registered action Originate [2019-04-09 16:06:49.349191] VERBOSE[85] manager.c: Manager registered action Command [2019-04-09 16:06:49.350216] VERBOSE[85] manager.c: Manager registered action ExtensionState [2019-04-09 16:06:49.351259] VERBOSE[85] manager.c: Manager registered action PresenceState [2019-04-09 16:06:49.352225] VERBOSE[85] manager.c: Manager registered action AbsoluteTimeout [2019-04-09 16:06:49.354188] VERBOSE[85] manager.c: Manager registered action MailboxStatus [2019-04-09 16:06:49.355131] VERBOSE[85] manager.c: Manager registered action MailboxCount [2019-04-09 16:06:49.356029] VERBOSE[85] manager.c: Manager registered action ListCommands [2019-04-09 16:06:49.356897] VERBOSE[85] manager.c: Manager registered action SendText [2019-04-09 16:06:49.358751] VERBOSE[85] manager.c: Manager registered action UserEvent [2019-04-09 16:06:49.359720] VERBOSE[85] manager.c: Manager registered action WaitEvent [2019-04-09 16:06:49.360476] VERBOSE[85] manager.c: Manager registered action CoreSettings [2019-04-09 16:06:49.361263] VERBOSE[85] manager.c: Manager registered action CoreStatus [2019-04-09 16:06:49.362099] VERBOSE[85] manager.c: Manager registered action Reload [2019-04-09 16:06:49.363993] VERBOSE[85] manager.c: Manager registered action LoggerRotate [2019-04-09 16:06:49.365286] VERBOSE[85] manager.c: Manager registered action CoreShowChannels [2019-04-09 16:06:49.366331] VERBOSE[85] manager.c: Manager registered action ModuleLoad [2019-04-09 16:06:49.367371] VERBOSE[85] manager.c: Manager registered action ModuleCheck [2019-04-09 16:06:49.369992] VERBOSE[85] manager.c: Manager registered action AOCMessage [2019-04-09 16:06:49.371221] VERBOSE[85] manager.c: Manager registered action Filter [2019-04-09 16:06:49.372203] VERBOSE[85] manager.c: Manager registered action BlindTransfer [2019-04-09 16:06:49.373406] VERBOSE[85] pbx_functions.c: Registered custom function 'AMI_CLIENT' [2019-04-09 16:06:49.422784] VERBOSE[85] loader.c: manager => (Asterisk Manager Interface) [2019-04-09 16:06:49.422888] VERBOSE[85] loader.c: Loading plc. [2019-04-09 16:06:49.423178] VERBOSE[85] loader.c: plc => (PLC) [2019-04-09 16:06:49.423221] VERBOSE[85] loader.c: Loading udptl. [2019-04-09 16:06:49.426917] VERBOSE[85] loader.c: udptl => (UDPTL) [2019-04-09 16:06:49.426967] VERBOSE[85] loader.c: Loading res_pjproject.so. [2019-04-09 16:06:49.431830] VERBOSE[85] loader.c: res_pjproject.so => (PJPROJECT Log and Utility Support) [2019-04-09 16:06:49.431902] VERBOSE[85] loader.c: Loading res_http_websocket.so. [2019-04-09 16:06:49.431966] VERBOSE[85] res_http_websocket.c: WebSocket registered sub-protocol 'echo' [2019-04-09 16:06:49.431990] VERBOSE[85] loader.c: res_http_websocket.so => (HTTP WebSocket Support) [2019-04-09 16:06:49.432025] VERBOSE[85] loader.c: Loading res_rtp_asterisk.so. [2019-04-09 16:06:49.432272] VERBOSE[85] rtp_engine.c: Registered RTP engine 'asterisk' [2019-04-09 16:06:49.433671] VERBOSE[85] res_rtp_asterisk.c: RTP Allocating from port range 10000 -> 20000 [2019-04-09 16:06:49.433735] VERBOSE[85] loader.c: res_rtp_asterisk.so => (Asterisk RTP Stack) [2019-04-09 16:06:49.433826] VERBOSE[85] loader.c: Loading chan_sip.so. [2019-04-09 16:06:49.433863] VERBOSE[85] chan_sip.c: SIP channel loading... [2019-04-09 16:06:49.444965] VERBOSE[85] chan_sip.c: SIP Listening on 0.0.0.0:5060 [2019-04-09 16:06:49.445040] VERBOSE[85] netsock2.c: Using SIP CoS mark 4 [2019-04-09 16:06:49.446249] VERBOSE[85] message.c: Message technology 'sip' registered. [2019-04-09 16:06:49.446328] VERBOSE[85] channel.c: Registered channel type 'SIP' (Session Initiation Protocol (SIP)) [2019-04-09 16:06:49.447070] VERBOSE[85] rtp_engine.c: Registered RTP glue 'SIP' [2019-04-09 16:06:49.448339] VERBOSE[85] pbx_app.c: Registered application 'SIPDtmfMode' [2019-04-09 16:06:49.450812] VERBOSE[85] pbx_app.c: Registered application 'SIPAddHeader' [2019-04-09 16:06:49.452146] VERBOSE[85] pbx_app.c: Registered application 'SIPRemoveHeader' [2019-04-09 16:06:49.454653] VERBOSE[85] pbx_functions.c: Registered custom function 'SIP_HEADER' [2019-04-09 16:06:49.455998] VERBOSE[85] pbx_functions.c: Registered custom function 'SIP_HEADERS' [2019-04-09 16:06:49.458340] VERBOSE[85] pbx_functions.c: Registered custom function 'SIPPEER' [2019-04-09 16:06:49.459467] VERBOSE[85] pbx_functions.c: Registered custom function 'CHECKSIPDOMAIN' [2019-04-09 16:06:49.459698] VERBOSE[85] manager.c: Manager registered action SIPpeers [2019-04-09 16:06:49.459872] VERBOSE[85] manager.c: Manager registered action SIPshowpeer [2019-04-09 16:06:49.460016] VERBOSE[85] manager.c: Manager registered action SIPqualifypeer [2019-04-09 16:06:49.460186] VERBOSE[85] manager.c: Manager registered action SIPshowregistry [2019-04-09 16:06:49.460460] VERBOSE[85] manager.c: Manager registered action SIPnotify [2019-04-09 16:06:49.460682] VERBOSE[85] manager.c: Manager registered action SIPpeerstatus [2019-04-09 16:06:49.460935] VERBOSE[85] res_http_websocket.c: WebSocket registered sub-protocol 'sip' [2019-04-09 16:06:49.460966] VERBOSE[85] loader.c: chan_sip.so => (Session Initiation Protocol (SIP)) [2019-04-09 16:06:49.460988] VERBOSE[85] loader.c: Loading res_speech.so. [2019-04-09 16:06:49.461008] VERBOSE[85] loader.c: res_speech.so => (Generic Speech Recognition API) [2019-04-09 16:06:49.461026] VERBOSE[85] loader.c: Loading res_stasis.so. [2019-04-09 16:06:49.461078] VERBOSE[85] message.c: Message handler 'ari' registered. [2019-04-09 16:06:49.461131] VERBOSE[85] loader.c: res_stasis.so => (Stasis application support) [2019-04-09 16:06:49.461152] VERBOSE[85] loader.c: Loading format_pcm.so. [2019-04-09 16:06:49.461409] VERBOSE[85] file.c: Registered file format pcm, extension(s) pcm|ulaw|ul|mu|ulw [2019-04-09 16:06:49.461522] VERBOSE[85] file.c: Registered file format alaw, extension(s) alaw|al|alw [2019-04-09 16:06:49.463208] VERBOSE[85] file.c: Registered file format au, extension(s) au [2019-04-09 16:06:49.463242] VERBOSE[85] file.c: Registered file format g722, extension(s) g722 [2019-04-09 16:06:49.463270] VERBOSE[85] loader.c: format_pcm.so => (Raw/Sun uLaw/ALaw 8KHz (PCM,PCMA,AU), G.722 16Khz) [2019-04-09 16:06:49.463290] VERBOSE[85] loader.c: Loading format_gsm.so. [2019-04-09 16:06:49.463318] VERBOSE[85] file.c: Registered file format gsm, extension(s) gsm [2019-04-09 16:06:49.463365] VERBOSE[85] loader.c: format_gsm.so => (Raw GSM data) [2019-04-09 16:06:49.463389] VERBOSE[85] loader.c: Loading format_sln.so. [2019-04-09 16:06:49.463409] VERBOSE[85] file.c: Registered file format sln, extension(s) sln|raw [2019-04-09 16:06:49.463437] VERBOSE[85] file.c: Registered file format sln12, extension(s) sln12 [2019-04-09 16:06:49.463463] VERBOSE[85] file.c: Registered file format sln16, extension(s) sln16 [2019-04-09 16:06:49.463488] VERBOSE[85] file.c: Registered file format sln24, extension(s) sln24 [2019-04-09 16:06:49.463513] VERBOSE[85] file.c: Registered file format sln32, extension(s) sln32 [2019-04-09 16:06:49.463539] VERBOSE[85] file.c: Registered file format sln44, extension(s) sln44 [2019-04-09 16:06:49.463594] VERBOSE[85] file.c: Registered file format sln48, extension(s) sln48 [2019-04-09 16:06:49.463623] VERBOSE[85] file.c: Registered file format sln96, extension(s) sln96 [2019-04-09 16:06:49.463650] VERBOSE[85] file.c: Registered file format sln192, extension(s) sln192 [2019-04-09 16:06:49.463677] VERBOSE[85] loader.c: format_sln.so => (Raw Signed Linear Audio support (SLN) 8khz-192khz) [2019-04-09 16:06:49.463695] VERBOSE[85] loader.c: Loading format_vox.so. [2019-04-09 16:06:49.463716] VERBOSE[85] file.c: Registered file format vox, extension(s) vox [2019-04-09 16:06:49.463742] VERBOSE[85] loader.c: format_vox.so => (Dialogic VOX (ADPCM) File Format) [2019-04-09 16:06:49.463761] VERBOSE[85] loader.c: Loading format_wav.so. [2019-04-09 16:06:49.463781] VERBOSE[85] file.c: Registered file format wav, extension(s) wav [2019-04-09 16:06:49.463807] VERBOSE[85] file.c: Registered file format wav16, extension(s) wav16 [2019-04-09 16:06:49.463835] VERBOSE[85] loader.c: format_wav.so => (Microsoft WAV/WAV16 format (8kHz/16kHz Signed Linear)) [2019-04-09 16:06:49.463853] VERBOSE[85] loader.c: Loading res_ari_model.so. [2019-04-09 16:06:49.463961] VERBOSE[85] loader.c: res_ari_model.so => (ARI Model validators) [2019-04-09 16:06:49.464009] VERBOSE[85] loader.c: Loading res_stasis_recording.so. [2019-04-09 16:06:49.464082] VERBOSE[85] loader.c: res_stasis_recording.so => (Stasis application recording support) [2019-04-09 16:06:49.464121] VERBOSE[85] loader.c: Loading res_agi.so. [2019-04-09 16:06:49.464931] VERBOSE[85] res_agi.c: AGI Command 'answer' registered [2019-04-09 16:06:49.465491] VERBOSE[85] res_agi.c: AGI Command 'asyncagi break' registered [2019-04-09 16:06:49.466154] VERBOSE[85] res_agi.c: AGI Command 'channel status' registered [2019-04-09 16:06:49.469279] VERBOSE[85] res_agi.c: AGI Command 'database del' registered [2019-04-09 16:06:49.469919] VERBOSE[85] res_agi.c: AGI Command 'database deltree' registered [2019-04-09 16:06:49.470487] VERBOSE[85] res_agi.c: AGI Command 'database get' registered [2019-04-09 16:06:49.471073] VERBOSE[85] res_agi.c: AGI Command 'database put' registered [2019-04-09 16:06:49.471649] VERBOSE[85] res_agi.c: AGI Command 'exec' registered [2019-04-09 16:06:49.472302] VERBOSE[85] res_agi.c: AGI Command 'get data' registered [2019-04-09 16:06:49.475006] VERBOSE[85] res_agi.c: AGI Command 'get full variable' registered [2019-04-09 16:06:49.475764] VERBOSE[85] res_agi.c: AGI Command 'get option' registered [2019-04-09 16:06:49.476336] VERBOSE[85] res_agi.c: AGI Command 'get variable' registered [2019-04-09 16:06:49.476954] VERBOSE[85] res_agi.c: AGI Command 'hangup' registered [2019-04-09 16:06:49.477472] VERBOSE[85] res_agi.c: AGI Command 'noop' registered [2019-04-09 16:06:49.478096] VERBOSE[85] res_agi.c: AGI Command 'receive char' registered [2019-04-09 16:06:49.479705] VERBOSE[85] res_agi.c: AGI Command 'receive text' registered [2019-04-09 16:06:49.480454] VERBOSE[85] res_agi.c: AGI Command 'record file' registered [2019-04-09 16:06:49.481352] VERBOSE[85] res_agi.c: AGI Command 'say alpha' registered [2019-04-09 16:06:49.482019] VERBOSE[85] res_agi.c: AGI Command 'say digits' registered [2019-04-09 16:06:49.482702] VERBOSE[85] res_agi.c: AGI Command 'say number' registered [2019-04-09 16:06:49.483308] VERBOSE[85] res_agi.c: AGI Command 'say phonetic' registered [2019-04-09 16:06:49.483987] VERBOSE[85] res_agi.c: AGI Command 'say date' registered [2019-04-09 16:06:49.485767] VERBOSE[85] res_agi.c: AGI Command 'say time' registered [2019-04-09 16:06:49.486416] VERBOSE[85] res_agi.c: AGI Command 'say datetime' registered [2019-04-09 16:06:49.487121] VERBOSE[85] res_agi.c: AGI Command 'send image' registered [2019-04-09 16:06:49.487862] VERBOSE[85] res_agi.c: AGI Command 'send text' registered [2019-04-09 16:06:49.488612] VERBOSE[85] res_agi.c: AGI Command 'set autohangup' registered [2019-04-09 16:06:49.489251] VERBOSE[85] res_agi.c: AGI Command 'set callerid' registered [2019-04-09 16:06:49.489872] VERBOSE[85] res_agi.c: AGI Command 'set context' registered [2019-04-09 16:06:49.490534] VERBOSE[85] res_agi.c: AGI Command 'set extension' registered [2019-04-09 16:06:49.491338] VERBOSE[85] res_agi.c: AGI Command 'set music' registered [2019-04-09 16:06:49.493492] VERBOSE[85] res_agi.c: AGI Command 'set priority' registered [2019-04-09 16:06:49.494123] VERBOSE[85] res_agi.c: AGI Command 'set variable' registered [2019-04-09 16:06:49.494922] VERBOSE[85] res_agi.c: AGI Command 'stream file' registered [2019-04-09 16:06:49.495833] VERBOSE[85] res_agi.c: AGI Command 'control stream file' registered [2019-04-09 16:06:49.496431] VERBOSE[85] res_agi.c: AGI Command 'tdd mode' registered [2019-04-09 16:06:49.498138] VERBOSE[85] res_agi.c: AGI Command 'verbose' registered [2019-04-09 16:06:49.498858] VERBOSE[85] res_agi.c: AGI Command 'wait for digit' registered [2019-04-09 16:06:49.499591] VERBOSE[85] res_agi.c: AGI Command 'speech create' registered [2019-04-09 16:06:49.500183] VERBOSE[85] res_agi.c: AGI Command 'speech set' registered [2019-04-09 16:06:49.500816] VERBOSE[85] res_agi.c: AGI Command 'speech destroy' registered [2019-04-09 16:06:49.501402] VERBOSE[85] res_agi.c: AGI Command 'speech load grammar' registered [2019-04-09 16:06:49.502030] VERBOSE[85] res_agi.c: AGI Command 'speech unload grammar' registered [2019-04-09 16:06:49.502748] VERBOSE[85] res_agi.c: AGI Command 'speech activate grammar' registered [2019-04-09 16:06:49.503347] VERBOSE[85] res_agi.c: AGI Command 'speech deactivate grammar' registered [2019-04-09 16:06:49.505150] VERBOSE[85] res_agi.c: AGI Command 'speech recognize' registered [2019-04-09 16:06:49.506457] VERBOSE[85] pbx_app.c: Registered application 'DeadAGI' [2019-04-09 16:06:49.507840] VERBOSE[85] pbx_app.c: Registered application 'EAGI' [2019-04-09 16:06:49.510241] VERBOSE[85] manager.c: Manager registered action AGI [2019-04-09 16:06:49.512241] VERBOSE[85] pbx_app.c: Registered application 'AGI' [2019-04-09 16:06:49.512279] VERBOSE[85] loader.c: res_agi.so => (Asterisk Gateway Interface (AGI)) [2019-04-09 16:06:49.512369] VERBOSE[85] loader.c: Loading res_ari.so. [2019-04-09 16:06:49.517839] VERBOSE[85] loader.c: res_ari.so => (Asterisk RESTful Interface) [2019-04-09 16:06:49.517884] VERBOSE[85] loader.c: Loading sounds. [2019-04-09 16:06:49.517961] VERBOSE[85] loader.c: sounds => (Sounds Index) [2019-04-09 16:06:49.517981] VERBOSE[85] loader.c: Loading codec_ulaw.so. [2019-04-09 16:06:49.518228] VERBOSE[85] translate.c: Registered translator 'ulawtolin' from codec ulaw to slin, table cost, 900000, computational cost 155 [2019-04-09 16:06:49.518420] VERBOSE[85] translate.c: Registered translator 'lintoulaw' from codec slin to ulaw, table cost, 600000, computational cost 118 [2019-04-09 16:06:49.518675] VERBOSE[85] translate.c: Registered translator 'lintotestlaw' from codec slin to testlaw, table cost, 600000, computational cost 202 [2019-04-09 16:06:49.518862] VERBOSE[85] translate.c: Registered translator 'testlawtolin' from codec testlaw to slin, table cost, 900000, computational cost 129 [2019-04-09 16:06:49.518892] VERBOSE[85] loader.c: codec_ulaw.so => (mu-Law Coder/Decoder) [2019-04-09 16:06:49.518911] VERBOSE[85] loader.c: Loading pbx_config.so. [2019-04-09 16:06:49.519127] VERBOSE[85] pbx_variables.c: Setting global variable 'CongestionTimeout' to '10' [2019-04-09 16:06:49.519189] VERBOSE[85] pbx_variables.c: Setting global variable 'AbsoluteTimeout' to '14460' [2019-04-09 16:06:49.519516] VERBOSE[85] pbx.c: Time to scan old dialplan and merge leftovers back into the new: 0.000003 sec [2019-04-09 16:06:49.520987] VERBOSE[85] pbx.c: Time to restore hints and swap in new dialplan: 0.000020 sec [2019-04-09 16:06:49.521009] VERBOSE[85] pbx.c: Time to delete the old dialplan: 0.000001 sec [2019-04-09 16:06:49.521028] VERBOSE[85] pbx.c: Total time merge_contexts_delete: 0.000024 sec [2019-04-09 16:06:49.521047] VERBOSE[85] pbx.c: pbx_config successfully loaded 0 contexts (enable debug for details). [2019-04-09 16:06:49.521825] VERBOSE[85] manager.c: Manager registered action DialplanExtensionAdd [2019-04-09 16:06:49.522084] VERBOSE[85] manager.c: Manager registered action DialplanExtensionRemove [2019-04-09 16:06:49.522111] VERBOSE[85] loader.c: pbx_config.so => (Text Extension Configuration) [2019-04-09 16:06:49.522130] VERBOSE[85] loader.c: Loading codec_gsm.so. [2019-04-09 16:06:49.523731] VERBOSE[85] translate.c: Registered translator 'gsmtolin' from codec gsm to slin, table cost, 900000, computational cost 1501 [2019-04-09 16:06:49.527699] VERBOSE[85] translate.c: Registered translator 'lintogsm' from codec slin to gsm, table cost, 600000, computational cost 2852 [2019-04-09 16:06:49.527760] VERBOSE[85] loader.c: codec_gsm.so => (GSM Coder/Decoder) [2019-04-09 16:06:49.527783] VERBOSE[85] loader.c: Loading codec_adpcm.so. [2019-04-09 16:06:49.528153] VERBOSE[85] translate.c: Registered translator 'adpcmtolin' from codec adpcm to slin, table cost, 900000, computational cost 321 [2019-04-09 16:06:49.528856] VERBOSE[85] translate.c: Registered translator 'lintoadpcm' from codec slin to adpcm, table cost, 600000, computational cost 639 [2019-04-09 16:06:49.528899] VERBOSE[85] loader.c: codec_adpcm.so => (Adaptive Differential PCM Coder/Decoder) [2019-04-09 16:06:49.528919] VERBOSE[85] loader.c: Loading bridge_builtin_interval_features.so. [2019-04-09 16:06:49.528940] VERBOSE[85] loader.c: bridge_builtin_interval_features.so => (Built in bridging interval features) [2019-04-09 16:06:49.528958] VERBOSE[85] loader.c: Loading bridge_holding.so. [2019-04-09 16:06:49.528977] VERBOSE[85] bridge.c: Registered bridge technology holding_bridge [2019-04-09 16:06:49.528997] VERBOSE[85] loader.c: bridge_holding.so => (Holding bridge module) [2019-04-09 16:06:49.529014] VERBOSE[85] loader.c: Loading bridge_softmix.so. [2019-04-09 16:06:49.529032] VERBOSE[85] bridge.c: Registered bridge technology softmix [2019-04-09 16:06:49.529051] VERBOSE[85] loader.c: bridge_softmix.so => (Multi-party software based channel mixing) [2019-04-09 16:06:49.529089] VERBOSE[85] loader.c: Loading bridge_builtin_features.so. [2019-04-09 16:06:49.529111] VERBOSE[85] loader.c: bridge_builtin_features.so => (Built in bridging features) [2019-04-09 16:06:49.529128] VERBOSE[85] loader.c: Loading bridge_simple.so. [2019-04-09 16:06:49.529147] VERBOSE[85] bridge.c: Registered bridge technology simple_bridge [2019-04-09 16:06:49.529166] VERBOSE[85] loader.c: bridge_simple.so => (Simple two channel bridging module) [2019-04-09 16:06:49.529183] VERBOSE[85] loader.c: Loading bridge_native_rtp.so. [2019-04-09 16:06:49.529202] VERBOSE[85] bridge.c: Registered bridge technology native_rtp [2019-04-09 16:06:49.529221] VERBOSE[85] loader.c: bridge_native_rtp.so => (Native RTP bridging module) [2019-04-09 16:06:49.529238] VERBOSE[85] loader.c: Loading chan_bridge_media.so. [2019-04-09 16:06:49.529919] VERBOSE[85] channel.c: Registered channel type 'Announcer' (Bridge Media Announcing Channel Driver) [2019-04-09 16:06:49.529948] VERBOSE[85] channel.c: Registered channel type 'Recorder' (Bridge Media Recording Channel Driver) [2019-04-09 16:06:49.529969] VERBOSE[85] loader.c: chan_bridge_media.so => (Bridge Media Channel Driver) [2019-04-09 16:06:49.529987] VERBOSE[85] loader.c: Loading func_callerid.so. [2019-04-09 16:06:49.533327] VERBOSE[85] pbx_functions.c: Registered custom function 'CALLERPRES' [2019-04-09 16:06:49.534808] VERBOSE[85] pbx_functions.c: Registered custom function 'CALLERID' [2019-04-09 16:06:49.536035] VERBOSE[85] pbx_functions.c: Registered custom function 'CONNECTEDLINE' [2019-04-09 16:06:49.537848] VERBOSE[85] pbx_functions.c: Registered custom function 'REDIRECTING' [2019-04-09 16:06:49.537879] VERBOSE[85] loader.c: func_callerid.so => (Party ID related dialplan functions (Caller-ID, Connected-line, Redirecting)) [2019-04-09 16:06:49.537899] VERBOSE[85] loader.c: Loading func_timeout.so. [2019-04-09 16:06:49.540923] VERBOSE[85] pbx_functions.c: Registered custom function 'TIMEOUT' [2019-04-09 16:06:49.540968] VERBOSE[85] loader.c: func_timeout.so => (Channel timeout dialplan functions) [2019-04-09 16:06:49.541007] VERBOSE[85] loader.c: Loading res_http_media_cache.so. [2019-04-09 16:06:49.541062] VERBOSE[85] bucket.c: Registered bucket scheme 'http' [2019-04-09 16:06:49.541093] VERBOSE[85] bucket.c: Registered bucket scheme 'https' [2019-04-09 16:06:49.541113] VERBOSE[85] loader.c: res_http_media_cache.so => (HTTP Media Cache Backend) [2019-04-09 16:06:49.541156] VERBOSE[85] loader.c: Loading res_stasis_playback.so. [2019-04-09 16:06:49.541199] VERBOSE[85] loader.c: res_stasis_playback.so => (Stasis application playback support) [2019-04-09 16:06:49.541232] VERBOSE[85] loader.c: Loading res_stasis_snoop.so. [2019-04-09 16:06:49.541252] VERBOSE[85] loader.c: res_stasis_snoop.so => (Stasis application snoop support) [2019-04-09 16:06:49.541279] VERBOSE[85] loader.c: Loading res_stasis_answer.so. [2019-04-09 16:06:49.541300] VERBOSE[85] loader.c: res_stasis_answer.so => (Stasis application answer support) [2019-04-09 16:06:49.541347] VERBOSE[85] loader.c: Loading res_ari_endpoints.so. [2019-04-09 16:06:49.541371] VERBOSE[85] loader.c: res_ari_endpoints.so => (RESTful API module - Endpoint resources) [2019-04-09 16:06:49.541596] VERBOSE[85] loader.c: Loading res_ari_bridges.so. [2019-04-09 16:06:49.541631] VERBOSE[85] loader.c: res_ari_bridges.so => (RESTful API module - Bridge resources) [2019-04-09 16:06:49.541678] VERBOSE[85] loader.c: Loading res_ari_sounds.so. [2019-04-09 16:06:49.541700] VERBOSE[85] loader.c: res_ari_sounds.so => (RESTful API module - Sound resources) [2019-04-09 16:06:49.541750] VERBOSE[85] loader.c: Loading res_ari_events.so. [2019-04-09 16:06:49.541780] VERBOSE[85] res_http_websocket.c: WebSocket registered sub-protocol 'ari' [2019-04-09 16:06:49.541802] VERBOSE[85] loader.c: res_ari_events.so => (RESTful API module - WebSocket resource) [2019-04-09 16:06:49.541846] VERBOSE[85] loader.c: Loading res_ari_asterisk.so. [2019-04-09 16:06:49.541868] VERBOSE[85] loader.c: res_ari_asterisk.so => (RESTful API module - Asterisk resources) [2019-04-09 16:06:49.541953] VERBOSE[85] loader.c: Loading res_ari_channels.so. [2019-04-09 16:06:49.541974] VERBOSE[85] loader.c: res_ari_channels.so => (RESTful API module - Channel resources) [2019-04-09 16:06:49.542016] VERBOSE[85] loader.c: Loading res_ari_applications.so. [2019-04-09 16:06:49.542038] VERBOSE[85] loader.c: res_ari_applications.so => (RESTful API module - Stasis application resources) [2019-04-09 16:06:49.542102] VERBOSE[85] loader.c: Loading res_ari_playbacks.so. [2019-04-09 16:06:49.542131] VERBOSE[85] loader.c: res_ari_playbacks.so => (RESTful API module - Playback control resources) [2019-04-09 16:06:49.542191] VERBOSE[85] loader.c: Loading res_ari_recordings.so. [2019-04-09 16:06:49.542218] VERBOSE[85] loader.c: res_ari_recordings.so => (RESTful API module - Recording resources) [2019-04-09 16:06:49.542244] VERBOSE[85] loader.c: Loading app_stasis.so. [2019-04-09 16:06:49.545817] VERBOSE[85] pbx_app.c: Registered application 'Stasis' [2019-04-09 16:06:49.545861] VERBOSE[85] loader.c: app_stasis.so => (Stasis dialplan application) [2019-04-09 16:06:49.547090] VERBOSE[85] asterisk.c: Asterisk Ready. [2019-04-09 16:07:19.409348] VERBOSE[359] asterisk.c: Remote UNIX connection [2019-04-09 16:07:22.238543] NOTICE[381] chan_sip.c: You must have debugging enabled (SIP or Asterisk) in order to dump SIP history. [2019-04-09 16:07:58.154381] Asterisk 16.3.0 built by root @ 5723d3300f4d on a x86_64 running Linux on 2019-04-08 23:40:40 UTC [2019-04-09 16:07:58.153486] VERBOSE[396] loader.c: Reloading module 'logger' (Logger) [2019-04-09 16:07:58.154156] DEBUG[396] config.c: Parsing /etc/asterisk/logger.conf [2019-04-09 16:07:58.154894] VERBOSE[396] logger.c: Asterisk Queue Logger restarted [2019-04-09 16:08:22.447246] DEBUG[397] http.c: HTTP opening session. Top level [2019-04-09 16:08:22.461402] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/resources.json [2019-04-09 16:08:22.461481] DEBUG[397] http.c: match request [ari/api-docs/resources.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.461505] DEBUG[397] http.c: match request [ari/api-docs/resources.json] with handler [static] len 6 [2019-04-09 16:08:22.461526] DEBUG[397] http.c: match request [ari/api-docs/resources.json] with handler [ari] len 3 [2019-04-09 16:08:22.461545] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.461682] DEBUG[397] res_ari.c: ast_ari_get_docs(resources.json) [2019-04-09 16:08:22.486758] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:22.506310] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/asterisk.json [2019-04-09 16:08:22.506365] DEBUG[397] http.c: match request [ari/api-docs/asterisk.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.506388] DEBUG[397] http.c: match request [ari/api-docs/asterisk.json] with handler [static] len 6 [2019-04-09 16:08:22.506407] DEBUG[397] http.c: match request [ari/api-docs/asterisk.json] with handler [ari] len 3 [2019-04-09 16:08:22.506424] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.506467] DEBUG[397] res_ari.c: ast_ari_get_docs(asterisk.json) [2019-04-09 16:08:22.527731] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:22.588085] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/endpoints.json [2019-04-09 16:08:22.588162] DEBUG[397] http.c: match request [ari/api-docs/endpoints.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.588188] DEBUG[397] http.c: match request [ari/api-docs/endpoints.json] with handler [static] len 6 [2019-04-09 16:08:22.588208] DEBUG[397] http.c: match request [ari/api-docs/endpoints.json] with handler [ari] len 3 [2019-04-09 16:08:22.588228] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.588277] DEBUG[397] res_ari.c: ast_ari_get_docs(endpoints.json) [2019-04-09 16:08:22.601683] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:22.650118] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/channels.json [2019-04-09 16:08:22.650189] DEBUG[397] http.c: match request [ari/api-docs/channels.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.650214] DEBUG[397] http.c: match request [ari/api-docs/channels.json] with handler [static] len 6 [2019-04-09 16:08:22.650233] DEBUG[397] http.c: match request [ari/api-docs/channels.json] with handler [ari] len 3 [2019-04-09 16:08:22.650251] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.650298] DEBUG[397] res_ari.c: ast_ari_get_docs(channels.json) [2019-04-09 16:08:22.670691] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:22.900174] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/bridges.json [2019-04-09 16:08:22.900260] DEBUG[397] http.c: match request [ari/api-docs/bridges.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.900285] DEBUG[397] http.c: match request [ari/api-docs/bridges.json] with handler [static] len 6 [2019-04-09 16:08:22.900306] DEBUG[397] http.c: match request [ari/api-docs/bridges.json] with handler [ari] len 3 [2019-04-09 16:08:22.900326] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.900377] DEBUG[397] res_ari.c: ast_ari_get_docs(bridges.json) [2019-04-09 16:08:22.915980] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:22.962401] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/recordings.json [2019-04-09 16:08:22.962476] DEBUG[397] http.c: match request [ari/api-docs/recordings.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.962501] DEBUG[397] http.c: match request [ari/api-docs/recordings.json] with handler [static] len 6 [2019-04-09 16:08:22.962522] DEBUG[397] http.c: match request [ari/api-docs/recordings.json] with handler [ari] len 3 [2019-04-09 16:08:22.962542] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.962627] DEBUG[397] res_ari.c: ast_ari_get_docs(recordings.json) [2019-04-09 16:08:22.966712] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:22.988634] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/sounds.json [2019-04-09 16:08:22.988699] DEBUG[397] http.c: match request [ari/api-docs/sounds.json] with handler [httpstatus] len 10 [2019-04-09 16:08:22.988726] DEBUG[397] http.c: match request [ari/api-docs/sounds.json] with handler [static] len 6 [2019-04-09 16:08:22.988747] DEBUG[397] http.c: match request [ari/api-docs/sounds.json] with handler [ari] len 3 [2019-04-09 16:08:22.988766] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:22.988814] DEBUG[397] res_ari.c: ast_ari_get_docs(sounds.json) [2019-04-09 16:08:22.990842] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:23.011478] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/playbacks.json [2019-04-09 16:08:23.011588] DEBUG[397] http.c: match request [ari/api-docs/playbacks.json] with handler [httpstatus] len 10 [2019-04-09 16:08:23.011624] DEBUG[397] http.c: match request [ari/api-docs/playbacks.json] with handler [static] len 6 [2019-04-09 16:08:23.011653] DEBUG[397] http.c: match request [ari/api-docs/playbacks.json] with handler [ari] len 3 [2019-04-09 16:08:23.011681] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:23.011738] DEBUG[397] res_ari.c: ast_ari_get_docs(playbacks.json) [2019-04-09 16:08:23.014229] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:23.031791] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/deviceStates.json [2019-04-09 16:08:23.031846] DEBUG[397] http.c: match request [ari/api-docs/deviceStates.json] with handler [httpstatus] len 10 [2019-04-09 16:08:23.031870] DEBUG[397] http.c: match request [ari/api-docs/deviceStates.json] with handler [static] len 6 [2019-04-09 16:08:23.031890] DEBUG[397] http.c: match request [ari/api-docs/deviceStates.json] with handler [ari] len 3 [2019-04-09 16:08:23.031909] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:23.031951] DEBUG[397] res_ari.c: ast_ari_get_docs(deviceStates.json) [2019-04-09 16:08:23.042484] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:23.061492] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/mailboxes.json [2019-04-09 16:08:23.061616] DEBUG[397] http.c: match request [ari/api-docs/mailboxes.json] with handler [httpstatus] len 10 [2019-04-09 16:08:23.061646] DEBUG[397] http.c: match request [ari/api-docs/mailboxes.json] with handler [static] len 6 [2019-04-09 16:08:23.061668] DEBUG[397] http.c: match request [ari/api-docs/mailboxes.json] with handler [ari] len 3 [2019-04-09 16:08:23.061707] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:23.061775] DEBUG[397] res_ari.c: ast_ari_get_docs(mailboxes.json) [2019-04-09 16:08:23.063706] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:23.083660] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/events.json [2019-04-09 16:08:23.083736] DEBUG[397] http.c: match request [ari/api-docs/events.json] with handler [httpstatus] len 10 [2019-04-09 16:08:23.083761] DEBUG[397] http.c: match request [ari/api-docs/events.json] with handler [static] len 6 [2019-04-09 16:08:23.083783] DEBUG[397] http.c: match request [ari/api-docs/events.json] with handler [ari] len 3 [2019-04-09 16:08:23.083802] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:23.083849] DEBUG[397] res_ari.c: ast_ari_get_docs(events.json) [2019-04-09 16:08:23.092442] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:23.139541] DEBUG[397] http.c: HTTP Request URI is /ari/api-docs/applications.json [2019-04-09 16:08:23.139643] DEBUG[397] http.c: match request [ari/api-docs/applications.json] with handler [httpstatus] len 10 [2019-04-09 16:08:23.139668] DEBUG[397] http.c: match request [ari/api-docs/applications.json] with handler [static] len 6 [2019-04-09 16:08:23.139689] DEBUG[397] http.c: match request [ari/api-docs/applications.json] with handler [ari] len 3 [2019-04-09 16:08:23.139708] DEBUG[397] http.c: Match made with [ari] [2019-04-09 16:08:23.139758] DEBUG[397] res_ari.c: ast_ari_get_docs(applications.json) [2019-04-09 16:08:23.147443] DEBUG[397] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:23.195397] DEBUG[399] http.c: HTTP opening session. Top level [2019-04-09 16:08:23.209633] DEBUG[399] http.c: HTTP Request URI is /ari/events?app=bridge-dial [2019-04-09 16:08:23.209701] DEBUG[399] http.c: match request [ari/events] with handler [httpstatus] len 10 [2019-04-09 16:08:23.209724] DEBUG[399] http.c: match request [ari/events] with handler [static] len 6 [2019-04-09 16:08:23.209742] DEBUG[399] http.c: match request [ari/events] with handler [ari] len 3 [2019-04-09 16:08:23.209768] DEBUG[399] http.c: Match made with [ari] [2019-04-09 16:08:23.209837] DEBUG[399] res_ari.c: Finding handler for events [2019-04-09 16:08:23.209865] DEBUG[399] res_ari.c: Checking endpoints [2019-04-09 16:08:23.209919] DEBUG[399] res_ari.c: Checking bridges [2019-04-09 16:08:23.209960] DEBUG[399] res_ari.c: Checking sounds [2019-04-09 16:08:23.209996] DEBUG[399] res_ari.c: Checking events [2019-04-09 16:08:23.210019] DEBUG[399] res_ari.c: Got it! [2019-04-09 16:08:23.210279] DEBUG[399] ari/resource_events.c: /events WebSocket attempted [2019-04-09 16:08:23.210315] VERBOSE[399] stasis/app.c: Creating Stasis app 'bridge-dial' [2019-04-09 16:08:23.210339] DEBUG[399] stasis.c: Topic 'ari:application/bridge-dial': 0x7fdcd4004df0 created [2019-04-09 16:08:23.210743] DEBUG[399] pbx.c: Registered extension context 'stasis-bridge-dial'; registrar: res_stasis [2019-04-09 16:08:23.210805] DEBUG[399] pbx.c: Added extension '_.' priority 1 to stasis-bridge-dial (0x7fdcd4006050) [2019-04-09 16:08:23.210846] DEBUG[399] pbx.c: Added extension 'h' priority 1 to stasis-bridge-dial (0x7fdcd4006050) [2019-04-09 16:08:23.211028] VERBOSE[399] res_http_websocket.c: WebSocket connection from '127.0.0.1:42140' for protocol '' accepted using version '13' [2019-04-09 16:08:23.211075] DEBUG[399] ari/resource_events.c: /events WebSocket established [2019-04-09 16:08:38.152456] DEBUG[397] iostream.c: TCP timeout reading data [2019-04-09 16:08:38.152529] DEBUG[397] http.c: HTTP closing session. Top level [2019-04-09 16:08:54.962170] VERBOSE[381] chan_sip.c: <--- SIP read from UDP:192.168.1.300:5060 ---> INVITE sip:18588675309@192.168.1.200:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.300:5060;branch=z9hG4bK1sansay755697336rdb3574 Record-Route: To: From: ;tag=sansay755697336rdb3574 Call-ID: 221854977-1-4091820138@192.168.1.400 CSeq: 1 INVITE Contact: Supported: timer,100rel,replaces Session-Expires: 600;refresher=uac Min-SE: 90 P-Asserted-Identity: Max-Forwards: 69 Content-Type: application/sdp Content-Length: 272 v=0 o=Sansay-VSXi 188 1 IN IP4 192.168.1.300 s=Session Controller c=IN IP4 67.231.5.91 t=0 0 m=audio 41014 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv a=ptime:20 <-------------> [2019-04-09 16:08:54.962241] DEBUG[381] chan_sip.c: Header 0 [ 50]: INVITE sip:18588675309@192.168.1.200:5060 SIP/2.0 [2019-04-09 16:08:54.962298] DEBUG[381] chan_sip.c: Header 1 [ 73]: Via: SIP/2.0/UDP 192.168.1.300:5060;branch=z9hG4bK1sansay755697336rdb3574 [2019-04-09 16:08:54.962311] DEBUG[381] chan_sip.c: Header 2 [ 78]: Record-Route: [2019-04-09 16:08:54.962324] DEBUG[381] chan_sip.c: Header 3 [ 36]: To: [2019-04-09 16:08:54.962336] DEBUG[381] chan_sip.c: Header 4 [ 77]: From: ;tag=sansay755697336rdb3574 [2019-04-09 16:08:54.962348] DEBUG[381] chan_sip.c: Header 5 [ 45]: Call-ID: 221854977-1-4091820138@192.168.1.400 [2019-04-09 16:08:54.962359] DEBUG[381] chan_sip.c: Header 6 [ 14]: CSeq: 1 INVITE [2019-04-09 16:08:54.962370] DEBUG[381] chan_sip.c: Header 7 [ 46]: Contact: [2019-04-09 16:08:54.962381] DEBUG[381] chan_sip.c: Header 8 [ 32]: Supported: timer,100rel,replaces [2019-04-09 16:08:54.962393] DEBUG[381] chan_sip.c: Header 9 [ 34]: Session-Expires: 600;refresher=uac [2019-04-09 16:08:54.962403] DEBUG[381] chan_sip.c: Header 10 [ 10]: Min-SE: 90 [2019-04-09 16:08:54.962415] DEBUG[381] chan_sip.c: Header 11 [ 58]: P-Asserted-Identity: [2019-04-09 16:08:54.962427] DEBUG[381] chan_sip.c: Header 12 [ 16]: Max-Forwards: 69 [2019-04-09 16:08:54.962438] DEBUG[381] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [2019-04-09 16:08:54.962448] DEBUG[381] chan_sip.c: Header 14 [ 19]: Content-Length: 272 [2019-04-09 16:08:54.962458] DEBUG[381] chan_sip.c: Header 15 [ 0]: [2019-04-09 16:08:54.962469] DEBUG[381] chan_sip.c: Body 0 [ 3]: v=0 [2019-04-09 16:08:54.962480] DEBUG[381] chan_sip.c: Body 1 [ 40]: o=Sansay-VSXi 188 1 IN IP4 192.168.1.300 [2019-04-09 16:08:54.962491] DEBUG[381] chan_sip.c: Body 2 [ 20]: s=Session Controller [2019-04-09 16:08:54.962502] DEBUG[381] chan_sip.c: Body 3 [ 20]: c=IN IP4 67.231.5.91 [2019-04-09 16:08:54.962512] DEBUG[381] chan_sip.c: Body 4 [ 5]: t=0 0 [2019-04-09 16:08:54.962523] DEBUG[381] chan_sip.c: Body 5 [ 30]: m=audio 41014 RTP/AVP 0 18 101 [2019-04-09 16:08:54.962534] DEBUG[381] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2019-04-09 16:08:54.962544] DEBUG[381] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2019-04-09 16:08:54.962598] DEBUG[381] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2019-04-09 16:08:54.962610] DEBUG[381] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [2019-04-09 16:08:54.962621] DEBUG[381] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-15 [2019-04-09 16:08:54.962632] DEBUG[381] chan_sip.c: Body 11 [ 10]: a=sendrecv [2019-04-09 16:08:54.962644] DEBUG[381] chan_sip.c: Body 12 [ 10]: a=ptime:20 [2019-04-09 16:08:54.962659] VERBOSE[381] chan_sip.c: --- (15 headers 13 lines) --- [2019-04-09 16:08:54.962698] DEBUG[381] chan_sip.c: = Looking for Call ID: 221854977-1-4091820138@192.168.1.400 (Checking From) --From tag sansay755697336rdb3574 --To-tag [2019-04-09 16:08:54.963065] DEBUG[381] acl.c: For destination '192.168.1.300', our source address is '192.168.1.200'. [2019-04-09 16:08:54.963088] DEBUG[381] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.200:5060 [2019-04-09 16:08:54.963140] DEBUG[381] netsock2.c: Splitting '192.168.1.300:5060' into... [2019-04-09 16:08:54.963152] DEBUG[381] netsock2.c: ...host '192.168.1.300' and port '5060'. [2019-04-09 16:08:54.963196] VERBOSE[381] chan_sip.c: Sending to 192.168.1.300:5060 (no NAT) [2019-04-09 16:08:54.963232] DEBUG[381] chan_sip.c: Allocating new SIP dialog for 221854977-1-4091820138@192.168.1.400 - INVITE (No RTP) [2019-04-09 16:08:54.963289] DEBUG[381][C-00000001] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2019-04-09 16:08:54.963323] DEBUG[381][C-00000001] sip/reqresp_parser.c: Begin: parsing SIP "Supported: timer,100rel,replaces" [2019-04-09 16:08:54.963345] DEBUG[381][C-00000001] sip/reqresp_parser.c: Found SIP option: -timer- [2019-04-09 16:08:54.963357] DEBUG[381][C-00000001] sip/reqresp_parser.c: Matched SIP option: timer [2019-04-09 16:08:54.963367] DEBUG[381][C-00000001] sip/reqresp_parser.c: Found SIP option: -100rel- [2019-04-09 16:08:54.963377] DEBUG[381][C-00000001] sip/reqresp_parser.c: Matched SIP option: 100rel [2019-04-09 16:08:54.963393] DEBUG[381][C-00000001] sip/reqresp_parser.c: Found SIP option: -replaces- [2019-04-09 16:08:54.963404] DEBUG[381][C-00000001] sip/reqresp_parser.c: Matched SIP option: replaces [2019-04-09 16:08:54.963438] DEBUG[381][C-00000001] netsock2.c: Splitting '192.168.1.300:5060' into... [2019-04-09 16:08:54.963450] DEBUG[381][C-00000001] netsock2.c: ...host '192.168.1.300' and port '5060'. [2019-04-09 16:08:54.963478] VERBOSE[381][C-00000001] chan_sip.c: Sending to 192.168.1.300:5060 (no NAT) [2019-04-09 16:08:54.963498] DEBUG[381][C-00000001] chan_sip.c: Initializing initreq for method INVITE - callid 221854977-1-4091820138@192.168.1.400 [2019-04-09 16:08:54.963514] VERBOSE[381][C-00000001] chan_sip.c: Using INVITE request as basis request - 221854977-1-4091820138@192.168.1.400 [2019-04-09 16:08:54.963612] DEBUG[381][C-00000001] netsock2.c: Splitting '192.168.1.300' into... [2019-04-09 16:08:54.963626] DEBUG[381][C-00000001] netsock2.c: ...host '192.168.1.300' and port ''. [2019-04-09 16:08:54.963701] VERBOSE[381][C-00000001] chan_sip.c: No matching peer for '+17608675309' from '192.168.1.300:5060' [2019-04-09 16:08:54.963763] DEBUG[381][C-00000001] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fdcec013d70' [2019-04-09 16:08:54.964217] DEBUG[381][C-00000001] res_rtp_asterisk.c: Allocated port 12846 for RTP instance '0x7fdcec013d70' [2019-04-09 16:08:54.964292] DEBUG[381][C-00000001] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:12846 (12846) for RTP instance '0x7fdcec013d70' [2019-04-09 16:08:54.965161] DEBUG[381][C-00000001] netsock2.c: Splitting '192.168.1.200' into... [2019-04-09 16:08:54.965177] DEBUG[381][C-00000001] netsock2.c: ...host '192.168.1.200' and port ''. [2019-04-09 16:08:54.965220] DEBUG[381][C-00000001] netsock2.c: Splitting '192.168.1.200' into... [2019-04-09 16:08:54.965232] DEBUG[381][C-00000001] netsock2.c: ...host '192.168.1.200' and port ''. [2019-04-09 16:08:54.965277] DEBUG[381][C-00000001] netsock2.c: Splitting '172.17.0.1' into... [2019-04-09 16:08:54.965289] DEBUG[381][C-00000001] netsock2.c: ...host '172.17.0.1' and port ''. [2019-04-09 16:08:54.965308] DEBUG[381][C-00000001] netsock2.c: Splitting '172.17.0.1' into... [2019-04-09 16:08:54.965319] DEBUG[381][C-00000001] netsock2.c: ...host '172.17.0.1' and port ''. [2019-04-09 16:08:54.965355] DEBUG[381][C-00000001] rtp_engine.c: RTP instance '0x7fdcec013d70' is setup and ready to go [2019-04-09 16:08:54.965438] DEBUG[381][C-00000001] netsock2.c: Splitting 'pod06-minikube-02.dev-core.fvscloud.com' into... [2019-04-09 16:08:54.965452] DEBUG[381][C-00000001] netsock2.c: ...host 'pod06-minikube-02.dev-core.fvscloud.com' and port ''. [2019-04-09 16:08:54.972363] DEBUG[381][C-00000001] acl.c: Multiple addresses. Using the first only [2019-04-09 16:08:54.972511] DEBUG[381][C-00000001] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fdcec013d70' [2019-04-09 16:08:54.972613] VERBOSE[381][C-00000001] netsock2.c: Using SIP RTP CoS mark 5 [2019-04-09 16:08:54.972643] DEBUG[381][C-00000001] chan_sip.c: Setting NAT on RTP to On [2019-04-09 16:08:54.972692] DEBUG[381][C-00000001] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2019-04-09 16:08:54.972723] DEBUG[381][C-00000001] chan_sip.c: Processing session-level SDP o=Sansay-VSXi 188 1 IN IP4 192.168.1.300... OK. [2019-04-09 16:08:54.972736] DEBUG[381][C-00000001] chan_sip.c: Processing session-level SDP s=Session Controller... UNSUPPORTED OR FAILED. [2019-04-09 16:08:54.972752] DEBUG[381][C-00000001] netsock2.c: Splitting '67.231.5.91' into... [2019-04-09 16:08:54.972763] DEBUG[381][C-00000001] netsock2.c: ...host '67.231.5.91' and port ''. [2019-04-09 16:08:54.972778] DEBUG[381][C-00000001] chan_sip.c: Processing session-level SDP c=IN IP4 67.231.5.91... OK. [2019-04-09 16:08:54.972790] DEBUG[381][C-00000001] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2019-04-09 16:08:54.972837] VERBOSE[381][C-00000001] chan_sip.c: Found RTP audio format 0 [2019-04-09 16:08:54.972858] DEBUG[381][C-00000001] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7fdcc65511a0 [2019-04-09 16:08:54.972884] VERBOSE[381][C-00000001] chan_sip.c: Found RTP audio format 18 [2019-04-09 16:08:54.972897] DEBUG[381][C-00000001] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7fdcc65511a0 [2019-04-09 16:08:54.972912] VERBOSE[381][C-00000001] chan_sip.c: Found RTP audio format 101 [2019-04-09 16:08:54.972952] VERBOSE[381][C-00000001] chan_sip.c: Found audio description format PCMU for ID 0 [2019-04-09 16:08:54.972965] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2019-04-09 16:08:54.972986] VERBOSE[381][C-00000001] chan_sip.c: Found audio description format G729 for ID 18 [2019-04-09 16:08:54.972998] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2019-04-09 16:08:54.973039] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [2019-04-09 16:08:54.973058] VERBOSE[381][C-00000001] chan_sip.c: Found audio description format telephone-event for ID 101 [2019-04-09 16:08:54.973070] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2019-04-09 16:08:54.973087] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [2019-04-09 16:08:54.973100] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [2019-04-09 16:08:54.973115] DEBUG[381][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [2019-04-09 16:08:54.973140] DEBUG[381][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7fdcec018f88) from 0x7fdcc65511a0 to 0x7fdcc65511a0 [2019-04-09 16:08:54.973155] DEBUG[381][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x7fdcec003388) from 0x7fdcc65511a0 to 0x7fdcc65511a0 [2019-04-09 16:08:54.973168] DEBUG[381][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 101 (0x7fdcec002b18) from 0x7fdcc65511a0 to 0x7fdcc65511a0 [2019-04-09 16:08:54.973193] VERBOSE[381][C-00000001] chan_sip.c: Capabilities: us - (ulaw), peer - audio=(ulaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw) [2019-04-09 16:08:54.973210] VERBOSE[381][C-00000001] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [2019-04-09 16:08:54.973280] DEBUG[381][C-00000001] acl.c: For destination '67.231.5.91', our source address is '192.168.1.200'. [2019-04-09 16:08:54.973295] DEBUG[381][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fdcec013d70' [2019-04-09 16:08:54.973313] VERBOSE[381][C-00000001] res_rtp_asterisk.c: 0x7fdcec014d20 -- Strict RTP learning after remote address set to: 67.231.5.91:41014 [2019-04-09 16:08:54.973328] VERBOSE[381][C-00000001] chan_sip.c: Peer audio RTP is at port 67.231.5.91:41014 [2019-04-09 16:08:54.973348] DEBUG[381][C-00000001] rtp_engine.c: Copying rx payload mapping 0 (0x7fdcec018f88) from 0x7fdcc65511a0 to 0x7fdcec013f48 [2019-04-09 16:08:54.973362] DEBUG[381][C-00000001] rtp_engine.c: Copying rx payload mapping 18 (0x7fdcec003388) from 0x7fdcc65511a0 to 0x7fdcec013f48 [2019-04-09 16:08:54.973375] DEBUG[381][C-00000001] rtp_engine.c: Copying rx payload mapping 101 (0x7fdcec002b18) from 0x7fdcc65511a0 to 0x7fdcec013f48 [2019-04-09 16:08:54.973387] DEBUG[381][C-00000001] rtp_engine.c: Copying tx payload mapping 0 (0x7fdcec018f88) from 0x7fdcc65511a0 to 0x7fdcec013f48 [2019-04-09 16:08:54.973398] DEBUG[381][C-00000001] rtp_engine.c: Copying tx payload mapping 18 (0x7fdcec003388) from 0x7fdcc65511a0 to 0x7fdcec013f48 [2019-04-09 16:08:54.973410] DEBUG[381][C-00000001] rtp_engine.c: Copying tx payload mapping 101 (0x7fdcec002b18) from 0x7fdcc65511a0 to 0x7fdcec013f48 [2019-04-09 16:08:54.973423] DEBUG[381][C-00000001] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fdcec013d70' [2019-04-09 16:08:54.973451] DEBUG[381][C-00000001] chan_sip.c: We're settling with these formats: (ulaw) [2019-04-09 16:08:54.973475] DEBUG[381][C-00000001] chan_sip.c: Checking SIP call limits for device [2019-04-09 16:08:54.973488] DEBUG[381][C-00000001] chan_sip.c: Updating call counter for incoming call [2019-04-09 16:08:54.973519] DEBUG[381][C-00000001] netsock2.c: Splitting '192.168.1.200:5060' into... [2019-04-09 16:08:54.973532] DEBUG[381][C-00000001] netsock2.c: ...host '192.168.1.200' and port ''. [2019-04-09 16:08:54.973582] DEBUG[381][C-00000001] netsock2.c: Splitting '192.168.1.300' into... [2019-04-09 16:08:54.973595] DEBUG[381][C-00000001] netsock2.c: ...host '192.168.1.300' and port ''. [2019-04-09 16:08:54.973614] VERBOSE[381][C-00000001] chan_sip.c: Looking for 18588675309 in pstn (domain 192.168.1.200) [2019-04-09 16:08:54.973675] DEBUG[381][C-00000001] chan_sip.c: Incoming INVITE with 'timer' option supported [2019-04-09 16:08:54.973692] DEBUG[381][C-00000001] chan_sip.c: INVITE also has "Session-Expires" header. [2019-04-09 16:08:54.973708] DEBUG[381][C-00000001] chan_sip.c: Session-Expires: 600 [2019-04-09 16:08:54.973719] DEBUG[381][C-00000001] chan_sip.c: Refresher: UAC [2019-04-09 16:08:54.973733] DEBUG[381][C-00000001] chan_sip.c: INVITE also has "Min-SE" header. [2019-04-09 16:08:54.973745] DEBUG[381][C-00000001] chan_sip.c: Received Min-SE: 90 [2019-04-09 16:08:54.973923] DEBUG[381][C-00000001] stasis.c: Topic 'channel:1554826134.0': 0x7fdcec004620 created [2019-04-09 16:08:54.973942] DEBUG[381][C-00000001] stasis.c: Topic 'cache:4/channel:1554826134.0': 0x7fdcec011370 created [2019-04-09 16:08:54.974062] DEBUG[381][C-00000001] channel.c: Channel 0x7fdcec019030 'SIP/192.168.1.300-00000000' allocated [2019-04-09 16:08:54.974101] DEBUG[381][C-00000001] chan_sip.c: *** Our native formats are (ulaw) [2019-04-09 16:08:54.974114] DEBUG[381][C-00000001] chan_sip.c: *** Joint capabilities are (ulaw) [2019-04-09 16:08:54.974127] DEBUG[381][C-00000001] chan_sip.c: *** Our capabilities are (ulaw) [2019-04-09 16:08:54.974138] DEBUG[381][C-00000001] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [2019-04-09 16:08:54.974149] DEBUG[381][C-00000001] chan_sip.c: This channel will not be able to handle video. [2019-04-09 16:08:54.974276] DEBUG[381][C-00000001] sip/route.c: sip_route_process_header: [2019-04-09 16:08:54.974294] VERBOSE[381][C-00000001] sip/route.c: sip_route_dump: route/path hop: [2019-04-09 16:08:54.974371] DEBUG[381][C-00000001] chan_sip.c: SIP/192.168.1.300-00000000: New call is still down.... Trying... [2019-04-09 16:08:54.974430] VERBOSE[381][C-00000001] chan_sip.c: <--- Transmitting (no NAT) to 192.168.1.300:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.300:5060;branch=z9hG4bK1sansay755697336rdb3574;received=192.168.1.300 Record-Route: From: ;tag=sansay755697336rdb3574 To: Call-ID: 221854977-1-4091820138@192.168.1.400 CSeq: 1 INVITE Server: SmartLine Media Server Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 600;refresher=uac Contact: Content-Length: 0 <------------> [2019-04-09 16:08:54.974450] DEBUG[381][C-00000001] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [2019-04-09 16:08:54.974463] DEBUG[381][C-00000001] chan_sip.c: Header 1 [ 96]: Via: SIP/2.0/UDP 192.168.1.300:5060;branch=z9hG4bK1sansay755697336rdb3574;received=192.168.1.300 [2019-04-09 16:08:54.974477] DEBUG[381][C-00000001] chan_sip.c: Header 2 [ 78]: Record-Route: [2019-04-09 16:08:54.974489] DEBUG[381][C-00000001] chan_sip.c: Header 3 [ 77]: From: ;tag=sansay755697336rdb3574 [2019-04-09 16:08:54.974501] DEBUG[381][C-00000001] chan_sip.c: Header 4 [ 36]: To: [2019-04-09 16:08:54.974514] DEBUG[381][C-00000001] chan_sip.c: Header 5 [ 45]: Call-ID: 221854977-1-4091820138@192.168.1.400 [2019-04-09 16:08:54.974526] DEBUG[381][C-00000001] chan_sip.c: Header 6 [ 14]: CSeq: 1 INVITE [2019-04-09 16:08:54.974538] DEBUG[381][C-00000001] chan_sip.c: Header 7 [ 30]: Server: SmartLine Media Server [2019-04-09 16:08:54.974579] DEBUG[381][C-00000001] chan_sip.c: Header 8 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2019-04-09 16:08:54.974593] DEBUG[381][C-00000001] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2019-04-09 16:08:54.974606] DEBUG[381][C-00000001] chan_sip.c: Header 10 [ 34]: Session-Expires: 600;refresher=uac [2019-04-09 16:08:54.974618] DEBUG[381][C-00000001] chan_sip.c: Header 11 [ 46]: Contact: [2019-04-09 16:08:54.974630] DEBUG[381][C-00000001] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2019-04-09 16:08:54.974642] DEBUG[381][C-00000001] chan_sip.c: Header 13 [ 0]: [2019-04-09 16:08:54.974675] DEBUG[381][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.1.300:5060 [2019-04-09 16:08:54.975124] DEBUG[369] devicestate.c: No provider found, checking channel drivers for SIP - 192.168.1.300 [2019-04-09 16:08:54.975179] DEBUG[369] chan_sip.c: Checking device state for peer 192.168.1.300 [2019-04-09 16:08:54.975199] DEBUG[369] devicestate.c: Changing state for SIP/192.168.1.300 - state 4 (Invalid) [2019-04-09 16:08:54.977772] DEBUG[402][C-00000001] pbx_variables.c: Result of 'AbsoluteTimeout' is '14460' [2019-04-09 16:08:54.977811] DEBUG[402][C-00000001] pbx.c: Launching 'Set' [2019-04-09 16:08:54.977826] VERBOSE[402][C-00000001] pbx.c: Executing [18588675309@pstn:1] Set("SIP/192.168.1.300-00000000", "TIMEOUT(absolute)=14460") in new stack [2019-04-09 16:08:54.977993] VERBOSE[402][C-00000001] func_timeout.c: Channel will hangup at 2019-04-09 20:09:54.977 UTC. [2019-04-09 16:08:54.978033] DEBUG[402][C-00000001] pbx.c: Launching 'Stasis' [2019-04-09 16:08:54.978056] VERBOSE[402][C-00000001] pbx.c: Executing [18588675309@pstn:2] Stasis("SIP/192.168.1.300-00000000", "bridge-dial,inbound,SIP/12345+17604009986@192.168.1.100") in new stack [2019-04-09 16:08:54.978241] DEBUG[402][C-00000001] stasis/app.c: Channel '1554826134.0' is 1 interested in bridge-dial [2019-04-09 16:08:54.978809] DEBUG[401] res_http_websocket.c: Writing websocket string of length 659 [2019-04-09 16:08:54.978835] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 659 [2019-04-09 16:08:55.050576] DEBUG[403] http.c: HTTP opening session. Top level [2019-04-09 16:08:55.063436] DEBUG[403] http.c: HTTP Request URI is /ari/channels/create?app=bridge-dial&endpoint=SIP%2F12345%2B17604009986%40192.168.1.100&appArgs=dialed [2019-04-09 16:08:55.063475] DEBUG[403] http.c: match request [ari/channels/create] with handler [httpstatus] len 10 [2019-04-09 16:08:55.063490] DEBUG[403] http.c: match request [ari/channels/create] with handler [static] len 6 [2019-04-09 16:08:55.063502] DEBUG[403] http.c: match request [ari/channels/create] with handler [ari] len 3 [2019-04-09 16:08:55.063519] DEBUG[403] http.c: Match made with [ari] [2019-04-09 16:08:55.063575] DEBUG[403] res_ari.c: Finding handler for channels [2019-04-09 16:08:55.063589] DEBUG[403] res_ari.c: Checking endpoints [2019-04-09 16:08:55.063600] DEBUG[403] res_ari.c: Checking bridges [2019-04-09 16:08:55.063618] DEBUG[403] res_ari.c: Checking sounds [2019-04-09 16:08:55.063629] DEBUG[403] res_ari.c: Checking events [2019-04-09 16:08:55.063639] DEBUG[403] res_ari.c: Checking asterisk [2019-04-09 16:08:55.063656] DEBUG[403] res_ari.c: Checking channels [2019-04-09 16:08:55.063674] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.063684] DEBUG[403] res_ari.c: Finding handler for create [2019-04-09 16:08:55.063694] DEBUG[403] res_ari.c: Checking create [2019-04-09 16:08:55.063727] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.064172] DEBUG[403] chan_sip.c: Asked to create a SIP channel with formats: (slin) [2019-04-09 16:08:55.064388] DEBUG[403] chan_sip.c: Allocating new SIP dialog for 6469a84116c5dc7911f6a54052f1402a@[fe80::8212:4d89:9a4f:eb18]:5060 - INVITE (No RTP) [2019-04-09 16:08:55.064453] DEBUG[403] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fdce400a480' [2019-04-09 16:08:55.064677] DEBUG[403] res_rtp_asterisk.c: Allocated port 10352 for RTP instance '0x7fdce400a480' [2019-04-09 16:08:55.064743] DEBUG[403] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:10352 (10352) for RTP instance '0x7fdce400a480' [2019-04-09 16:08:55.065218] DEBUG[403] netsock2.c: Splitting '192.168.1.200' into... [2019-04-09 16:08:55.065234] DEBUG[403] netsock2.c: ...host '192.168.1.200' and port ''. [2019-04-09 16:08:55.065260] DEBUG[403] netsock2.c: Splitting '192.168.1.200' into... [2019-04-09 16:08:55.065271] DEBUG[403] netsock2.c: ...host '192.168.1.200' and port ''. [2019-04-09 16:08:55.065296] DEBUG[403] netsock2.c: Splitting '172.17.0.1' into... [2019-04-09 16:08:55.065308] DEBUG[403] netsock2.c: ...host '172.17.0.1' and port ''. [2019-04-09 16:08:55.065326] DEBUG[403] netsock2.c: Splitting '172.17.0.1' into... [2019-04-09 16:08:55.065352] DEBUG[403] netsock2.c: ...host '172.17.0.1' and port ''. [2019-04-09 16:08:55.065373] DEBUG[403] rtp_engine.c: RTP instance '0x7fdce400a480' is setup and ready to go [2019-04-09 16:08:55.065407] DEBUG[403] netsock2.c: Splitting 'pod06-minikube-02.dev-core.fvscloud.com' into... [2019-04-09 16:08:55.065420] DEBUG[403] netsock2.c: ...host 'pod06-minikube-02.dev-core.fvscloud.com' and port ''. [2019-04-09 16:08:55.069210] DEBUG[403] acl.c: Multiple addresses. Using the first only [2019-04-09 16:08:55.069325] DEBUG[403] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fdce400a480' [2019-04-09 16:08:55.069361] VERBOSE[403] netsock2.c: Using SIP RTP CoS mark 5 [2019-04-09 16:08:55.069375] DEBUG[403] chan_sip.c: Setting NAT on RTP to On [2019-04-09 16:08:55.069389] DEBUG[403] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2019-04-09 16:08:55.136462] DEBUG[403] netsock2.c: Splitting '192.168.1.100' into... [2019-04-09 16:08:55.136513] DEBUG[403] netsock2.c: ...host '192.168.1.100' and port ''. [2019-04-09 16:08:55.136628] DEBUG[403] acl.c: For destination '192.168.1.100', our source address is '192.168.1.200'. [2019-04-09 16:08:55.136649] DEBUG[403] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.200:5060 [2019-04-09 16:08:55.136664] DEBUG[403] chan_sip.c: Setting NAT on RTP to On [2019-04-09 16:08:55.136723] DEBUG[403] chan_sip.c: SIP call-id changed from '6469a84116c5dc7911f6a54052f1402a@[fe80::8212:4d89:9a4f:eb18]:5060' to '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' [2019-04-09 16:08:55.136790] DEBUG[403] stasis.c: Topic 'channel:1554826135.1': 0x7fdce4007fe0 created [2019-04-09 16:08:55.136806] DEBUG[403] stasis.c: Topic 'cache:5/channel:1554826135.1': 0x7fdce4008180 created [2019-04-09 16:08:55.136880] DEBUG[403] channel.c: Channel 0x7fdce40027e0 'SIP/192.168.1.100-00000001' allocated [2019-04-09 16:08:55.136913] DEBUG[403] chan_sip.c: *** Our native formats are (ulaw) [2019-04-09 16:08:55.136926] DEBUG[403] chan_sip.c: *** Joint capabilities are (nothing) [2019-04-09 16:08:55.136939] DEBUG[403] chan_sip.c: *** Our capabilities are (ulaw) [2019-04-09 16:08:55.136950] DEBUG[403] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [2019-04-09 16:08:55.136963] DEBUG[403] chan_sip.c: *** Our preferred formats from the incoming channel are (slin) [2019-04-09 16:08:55.136974] DEBUG[403] chan_sip.c: This channel will not be able to handle video. [2019-04-09 16:08:55.137121] DEBUG[403] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [2019-04-09 16:08:55.137139] DEBUG[403] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [2019-04-09 16:08:55.137309] DEBUG[403] res_stasis.c: bridge-dial: Subscribing to 1554826135.1 [2019-04-09 16:08:55.137335] DEBUG[403] stasis/app.c: Channel '1554826135.1' is 1 interested in bridge-dial [2019-04-09 16:08:55.137645] DEBUG[403] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:55.138204] DEBUG[404] stasis/app.c: Channel '1554826135.1' is 2 interested in bridge-dial [2019-04-09 16:08:55.138364] DEBUG[401] res_http_websocket.c: Writing websocket string of length 639 [2019-04-09 16:08:55.138378] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 639 [2019-04-09 16:08:55.138510] DEBUG[401] res_http_websocket.c: Writing websocket string of length 609 [2019-04-09 16:08:55.138525] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 609 [2019-04-09 16:08:55.138653] DEBUG[401] res_http_websocket.c: Writing websocket string of length 592 [2019-04-09 16:08:55.138666] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 592 [2019-04-09 16:08:55.155250] DEBUG[403] http.c: HTTP Request URI is /ari/bridges?type=mixing [2019-04-09 16:08:55.155291] DEBUG[403] http.c: match request [ari/bridges] with handler [httpstatus] len 10 [2019-04-09 16:08:55.155304] DEBUG[403] http.c: match request [ari/bridges] with handler [static] len 6 [2019-04-09 16:08:55.155315] DEBUG[403] http.c: match request [ari/bridges] with handler [ari] len 3 [2019-04-09 16:08:55.155325] DEBUG[403] http.c: Match made with [ari] [2019-04-09 16:08:55.155353] DEBUG[403] res_ari.c: Finding handler for bridges [2019-04-09 16:08:55.155365] DEBUG[403] res_ari.c: Checking endpoints [2019-04-09 16:08:55.155376] DEBUG[403] res_ari.c: Checking bridges [2019-04-09 16:08:55.155386] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.155516] DEBUG[403] stasis.c: Topic 'bridge:139f2626-443b-4b27-a6f3-b13505e0af09': 0x7fdce4011f10 created [2019-04-09 16:08:55.155533] DEBUG[403] stasis.c: Topic 'cache:6/bridge:139f2626-443b-4b27-a6f3-b13505e0af09': 0x7fdce4012030 created [2019-04-09 16:08:55.155629] DEBUG[403] bridge_native_rtp.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' can not use native RTP bridge as two channels are required [2019-04-09 16:08:55.155645] DEBUG[403] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2019-04-09 16:08:55.155664] DEBUG[403] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2019-04-09 16:08:55.155676] DEBUG[403] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [2019-04-09 16:08:55.155692] DEBUG[403] bridge.c: Chose bridge technology simple_bridge [2019-04-09 16:08:55.155702] DEBUG[403] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: calling simple_bridge technology constructor [2019-04-09 16:08:55.155713] DEBUG[403] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: calling simple_bridge technology start [2019-04-09 16:08:55.155868] DEBUG[403] http.c: HTTP keeping session open. status_code:200 [2019-04-09 16:08:55.174512] DEBUG[403] http.c: HTTP Request URI is /ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09/addChannel?channel=1554826134.0%2C1554826135.1 [2019-04-09 16:08:55.174605] DEBUG[403] http.c: match request [ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09/addChannel] with handler [httpstatus] len 10 [2019-04-09 16:08:55.174629] DEBUG[403] http.c: match request [ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09/addChannel] with handler [static] len 6 [2019-04-09 16:08:55.174648] DEBUG[403] http.c: match request [ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09/addChannel] with handler [ari] len 3 [2019-04-09 16:08:55.174665] DEBUG[403] http.c: Match made with [ari] [2019-04-09 16:08:55.174704] DEBUG[403] res_ari.c: Finding handler for bridges [2019-04-09 16:08:55.174722] DEBUG[403] res_ari.c: Checking endpoints [2019-04-09 16:08:55.174740] DEBUG[403] res_ari.c: Checking bridges [2019-04-09 16:08:55.174757] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.174773] DEBUG[403] res_ari.c: Finding handler for 139f2626-443b-4b27-a6f3-b13505e0af09 [2019-04-09 16:08:55.174790] DEBUG[403] res_ari.c: Checking bridgeId [2019-04-09 16:08:55.174807] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.174824] DEBUG[403] res_ari.c: Finding handler for addChannel [2019-04-09 16:08:55.174841] DEBUG[403] res_ari.c: Checking addChannel [2019-04-09 16:08:55.174857] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.174909] DEBUG[403] stasis/control.c: 1554826134.0: Sending channel add_to_bridge command [2019-04-09 16:08:55.178684] DEBUG[402][C-00000001] bridge_roles.c: Roles did not exist on channel SIP/192.168.1.300-00000000 [2019-04-09 16:08:55.178758] DEBUG[402][C-00000001] stasis/control.c: 1554826134.0: Adding to bridge 139f2626-443b-4b27-a6f3-b13505e0af09 [2019-04-09 16:08:55.178814] DEBUG[402][C-00000001] stasis/app.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' is 1 interested in bridge-dial [2019-04-09 16:08:55.179234] DEBUG[405][C-00000001] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: 0x7fdce80066e0(SIP/192.168.1.300-00000000) is joining [2019-04-09 16:08:55.179444] DEBUG[405][C-00000001] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: pushing 0x7fdce80066e0(SIP/192.168.1.300-00000000) [2019-04-09 16:08:55.179504] VERBOSE[405][C-00000001] bridge_channel.c: Channel SIP/192.168.1.300-00000000 joined 'simple_bridge' stasis-bridge <139f2626-443b-4b27-a6f3-b13505e0af09> [2019-04-09 16:08:55.179649] DEBUG[405][C-00000001] bridge_native_rtp.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' can not use native RTP bridge as two channels are required [2019-04-09 16:08:55.179673] DEBUG[405][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2019-04-09 16:08:55.179693] DEBUG[405][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2019-04-09 16:08:55.179711] DEBUG[405][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [2019-04-09 16:08:55.179728] DEBUG[405][C-00000001] bridge.c: Chose bridge technology simple_bridge [2019-04-09 16:08:55.179745] DEBUG[405][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09 is already using the new technology. [2019-04-09 16:08:55.179783] DEBUG[405][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: 0x7fdce80066e0(SIP/192.168.1.300-00000000) is joining simple_bridge technology [2019-04-09 16:08:55.179934] DEBUG[405][C-00000001] res_rtp_asterisk.c: Changing ssrc from 1735446102 to 537896846 due to a source change [2019-04-09 16:08:55.180695] DEBUG[401] res_http_websocket.c: Writing websocket string of length 922 [2019-04-09 16:08:55.180735] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 922 [2019-04-09 16:08:55.180922] DEBUG[402][C-00000001] stasis/app.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' is 2 interested in bridge-dial [2019-04-09 16:08:55.181089] DEBUG[403] stasis/control.c: 1554826135.1: Sending channel add_to_bridge command [2019-04-09 16:08:55.339009] DEBUG[404] bridge_roles.c: Roles did not exist on channel SIP/192.168.1.100-00000001 [2019-04-09 16:08:55.339119] DEBUG[404] stasis/control.c: 1554826135.1: Adding to bridge 139f2626-443b-4b27-a6f3-b13505e0af09 [2019-04-09 16:08:55.339164] DEBUG[404] stasis/app.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' is 3 interested in bridge-dial [2019-04-09 16:08:55.339705] DEBUG[406] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: 0x7fdcec000bd0(SIP/192.168.1.100-00000001) is joining [2019-04-09 16:08:55.339921] DEBUG[406] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: pushing 0x7fdcec000bd0(SIP/192.168.1.100-00000001) [2019-04-09 16:08:55.340028] VERBOSE[406] bridge_channel.c: Channel SIP/192.168.1.100-00000001 joined 'simple_bridge' stasis-bridge <139f2626-443b-4b27-a6f3-b13505e0af09> [2019-04-09 16:08:55.340171] DEBUG[406] bridge_native_rtp.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09'. Checking compatability for channels 'SIP/192.168.1.300-00000000' and 'SIP/192.168.1.100-00000001' [2019-04-09 16:08:55.340229] DEBUG[406] bridge_native_rtp.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' can not use native RTP bridge as channel 'SIP/192.168.1.300-00000000' has features which prevent it [2019-04-09 16:08:55.340254] DEBUG[406] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2019-04-09 16:08:55.340276] DEBUG[406] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2019-04-09 16:08:55.340295] DEBUG[406] bridge.c: Bridge technology softmix does not have any capabilities we want. [2019-04-09 16:08:55.340314] DEBUG[406] bridge.c: Chose bridge technology simple_bridge [2019-04-09 16:08:55.340334] DEBUG[406] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09 is already using the new technology. [2019-04-09 16:08:55.340356] DEBUG[406] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: 0x7fdcec000bd0(SIP/192.168.1.100-00000001) is joining simple_bridge technology [2019-04-09 16:08:55.340451] DEBUG[406] channel.c: Channel SIP/192.168.1.100-00000001 setting read format path: ulaw -> ulaw [2019-04-09 16:08:55.340485] DEBUG[406] channel.c: Channel SIP/192.168.1.300-00000000 setting write format path: ulaw -> ulaw [2019-04-09 16:08:55.340518] DEBUG[406] channel.c: Channel SIP/192.168.1.300-00000000 setting read format path: ulaw -> ulaw [2019-04-09 16:08:55.340546] DEBUG[406] channel.c: Channel SIP/192.168.1.100-00000001 setting write format path: ulaw -> ulaw [2019-04-09 16:08:55.340999] DEBUG[406] res_rtp_asterisk.c: Changing ssrc from 149803632 to 1546296150 due to a source change [2019-04-09 16:08:55.341862] DEBUG[377] cdr.c: Finalized CDR for SIP/192.168.1.100-00000001 - start 1554826135.137984 answer 0.000000 end 1554826135.341848 dispo FAILED [2019-04-09 16:08:55.342172] DEBUG[401] res_http_websocket.c: Writing websocket string of length 922 [2019-04-09 16:08:55.342196] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 922 [2019-04-09 16:08:55.342456] DEBUG[401] res_http_websocket.c: Writing websocket string of length 656 [2019-04-09 16:08:55.342477] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 656 [2019-04-09 16:08:55.342714] DEBUG[401] res_http_websocket.c: Writing websocket string of length 686 [2019-04-09 16:08:55.342737] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 686 [2019-04-09 16:08:55.342915] DEBUG[401] res_http_websocket.c: Writing websocket string of length 633 [2019-04-09 16:08:55.342936] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 633 [2019-04-09 16:08:55.343159] DEBUG[401] res_http_websocket.c: Writing websocket string of length 648 [2019-04-09 16:08:55.343184] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 648 [2019-04-09 16:08:55.343371] DEBUG[401] res_http_websocket.c: Writing websocket string of length 583 [2019-04-09 16:08:55.343393] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 583 [2019-04-09 16:08:55.343741] DEBUG[404] stasis/app.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' is 4 interested in bridge-dial [2019-04-09 16:08:55.343936] DEBUG[403] http.c: HTTP keeping session open. status_code:204 [2019-04-09 16:08:55.366912] DEBUG[403] http.c: HTTP Request URI is /ari/channels/1554826135.1/dial?timeout=10 [2019-04-09 16:08:55.366985] DEBUG[403] http.c: match request [ari/channels/1554826135.1/dial] with handler [httpstatus] len 10 [2019-04-09 16:08:55.367024] DEBUG[403] http.c: match request [ari/channels/1554826135.1/dial] with handler [static] len 6 [2019-04-09 16:08:55.367047] DEBUG[403] http.c: match request [ari/channels/1554826135.1/dial] with handler [ari] len 3 [2019-04-09 16:08:55.367066] DEBUG[403] http.c: Match made with [ari] [2019-04-09 16:08:55.367114] DEBUG[403] res_ari.c: Finding handler for channels [2019-04-09 16:08:55.367135] DEBUG[403] res_ari.c: Checking endpoints [2019-04-09 16:08:55.367155] DEBUG[403] res_ari.c: Checking bridges [2019-04-09 16:08:55.367175] DEBUG[403] res_ari.c: Checking sounds [2019-04-09 16:08:55.367195] DEBUG[403] res_ari.c: Checking events [2019-04-09 16:08:55.367215] DEBUG[403] res_ari.c: Checking asterisk [2019-04-09 16:08:55.367235] DEBUG[403] res_ari.c: Checking channels [2019-04-09 16:08:55.367253] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.367272] DEBUG[403] res_ari.c: Finding handler for 1554826135.1 [2019-04-09 16:08:55.367291] DEBUG[403] res_ari.c: Checking create [2019-04-09 16:08:55.367310] DEBUG[403] res_ari.c: Checking channelId [2019-04-09 16:08:55.367330] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.367348] DEBUG[403] res_ari.c: Finding handler for dial [2019-04-09 16:08:55.367366] DEBUG[403] res_ari.c: Checking continue [2019-04-09 16:08:55.367385] DEBUG[403] res_ari.c: Checking move [2019-04-09 16:08:55.367402] DEBUG[403] res_ari.c: Checking redirect [2019-04-09 16:08:55.367432] DEBUG[403] res_ari.c: Checking answer [2019-04-09 16:08:55.367453] DEBUG[403] res_ari.c: Checking ring [2019-04-09 16:08:55.367471] DEBUG[403] res_ari.c: Checking dtmf [2019-04-09 16:08:55.367490] DEBUG[403] res_ari.c: Checking mute [2019-04-09 16:08:55.367509] DEBUG[403] res_ari.c: Checking hold [2019-04-09 16:08:55.367527] DEBUG[403] res_ari.c: Checking moh [2019-04-09 16:08:55.367545] DEBUG[403] res_ari.c: Checking silence [2019-04-09 16:08:55.367603] DEBUG[403] res_ari.c: Checking play [2019-04-09 16:08:55.367622] DEBUG[403] res_ari.c: Checking record [2019-04-09 16:08:55.367735] DEBUG[403] res_ari.c: Checking variable [2019-04-09 16:08:55.367755] DEBUG[403] res_ari.c: Checking snoop [2019-04-09 16:08:55.367773] DEBUG[403] res_ari.c: Checking dial [2019-04-09 16:08:55.367792] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:08:55.368062] DEBUG[403] http.c: HTTP keeping session open. status_code:204 [2019-04-09 16:08:55.368166] DEBUG[404] bridge.c: Putting interval hook 0x7fdcec006978 with interval 9999 in the heap on features 0x7fdce4000e50 [2019-04-09 16:08:55.368260] DEBUG[404] chan_sip.c: Outgoing Call for 12345+17604009986 [2019-04-09 16:08:55.368286] DEBUG[404] chan_sip.c: Updating call counter for outgoing call [2019-04-09 16:08:55.368592] DEBUG[404] chan_sip.c: ** Our capability: (ulaw) Video flag: False Text flag: False [2019-04-09 16:08:55.368621] DEBUG[404] chan_sip.c: ** Our prefcodec: (slin) [2019-04-09 16:08:55.368669] VERBOSE[404] chan_sip.c: Audio is at 10352 [2019-04-09 16:08:55.368730] VERBOSE[404] chan_sip.c: Adding codec ulaw to SDP [2019-04-09 16:08:55.368773] VERBOSE[404] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [2019-04-09 16:08:55.368804] DEBUG[404] chan_sip.c: -- Done with adding codecs to SDP [2019-04-09 16:08:55.368844] DEBUG[404] chan_sip.c: Done building SDP. Settling with this capability: (ulaw) [2019-04-09 16:08:55.368870] DEBUG[404] chan_sip.c: Initializing initreq for method INVITE - callid 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:08:55.368895] DEBUG[404] chan_sip.c: Header 0 [ 51]: INVITE sip:12345+17604009986@192.168.1.100 SIP/2.0 [2019-04-09 16:08:55.368917] DEBUG[404] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:08:55.368939] DEBUG[404] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2019-04-09 16:08:55.368971] DEBUG[404] chan_sip.c: Header 3 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:08:55.369006] DEBUG[404] chan_sip.c: Header 4 [ 42]: To: [2019-04-09 16:08:55.369039] DEBUG[404] chan_sip.c: Header 5 [ 47]: Contact: [2019-04-09 16:08:55.369062] DEBUG[404] chan_sip.c: Header 6 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:08:55.369084] DEBUG[404] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2019-04-09 16:08:55.369104] DEBUG[404] chan_sip.c: Header 8 [ 34]: User-Agent: SmartLine Media Server [2019-04-09 16:08:55.369123] DEBUG[404] chan_sip.c: Header 9 [ 35]: Date: Tue, 09 Apr 2019 16:08:55 GMT [2019-04-09 16:08:55.369143] DEBUG[404] chan_sip.c: Header 10 [ 20]: Session-Expires: 600 [2019-04-09 16:08:55.369164] DEBUG[404] chan_sip.c: Header 11 [ 11]: Min-SE: 180 [2019-04-09 16:08:55.369185] DEBUG[404] chan_sip.c: Header 12 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2019-04-09 16:08:55.369205] DEBUG[404] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [2019-04-09 16:08:55.369225] DEBUG[404] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [2019-04-09 16:08:55.369259] VERBOSE[404] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.1.100:5060: INVITE sip:12345+17604009986@192.168.1.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca Max-Forwards: 70 From: ;tag=as30ac8d32 To: Contact: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 INVITE User-Agent: SmartLine Media Server Date: Tue, 09 Apr 2019 16:08:55 GMT Session-Expires: 600 Min-SE: 180 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 283 v=0 o=root 648690495 648690495 IN IP4 192.168.1.200 s=SmartLine Media Server c=IN IP4 192.168.1.200 t=0 0 m=audio 10352 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=maxptime:150 a=sendrecv --- [2019-04-09 16:08:55.369300] DEBUG[404] chan_sip.c: Header 0 [ 51]: INVITE sip:12345+17604009986@192.168.1.100 SIP/2.0 [2019-04-09 16:08:55.369322] DEBUG[404] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:08:55.369342] DEBUG[404] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2019-04-09 16:08:55.369362] DEBUG[404] chan_sip.c: Header 3 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:08:55.369383] DEBUG[404] chan_sip.c: Header 4 [ 42]: To: [2019-04-09 16:08:55.369404] DEBUG[404] chan_sip.c: Header 5 [ 47]: Contact: [2019-04-09 16:08:55.369424] DEBUG[404] chan_sip.c: Header 6 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:08:55.369447] DEBUG[404] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2019-04-09 16:08:55.369466] DEBUG[404] chan_sip.c: Header 8 [ 34]: User-Agent: SmartLine Media Server [2019-04-09 16:08:55.369486] DEBUG[404] chan_sip.c: Header 9 [ 35]: Date: Tue, 09 Apr 2019 16:08:55 GMT [2019-04-09 16:08:55.369506] DEBUG[404] chan_sip.c: Header 10 [ 20]: Session-Expires: 600 [2019-04-09 16:08:55.369526] DEBUG[404] chan_sip.c: Header 11 [ 11]: Min-SE: 180 [2019-04-09 16:08:55.369546] DEBUG[404] chan_sip.c: Header 12 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2019-04-09 16:08:55.369603] DEBUG[404] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [2019-04-09 16:08:55.369624] DEBUG[404] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [2019-04-09 16:08:55.369644] DEBUG[404] chan_sip.c: Header 15 [ 19]: Content-Length: 283 [2019-04-09 16:08:55.369664] DEBUG[404] chan_sip.c: Header 16 [ 0]: [2019-04-09 16:08:55.369684] DEBUG[404] chan_sip.c: Body 0 [ 3]: v=0 [2019-04-09 16:08:55.369704] DEBUG[404] chan_sip.c: Body 1 [ 48]: o=root 648690495 648690495 IN IP4 192.168.1.200 [2019-04-09 16:08:55.369725] DEBUG[404] chan_sip.c: Body 2 [ 24]: s=SmartLine Media Server [2019-04-09 16:08:55.369744] DEBUG[404] chan_sip.c: Body 3 [ 23]: c=IN IP4 192.168.1.200 [2019-04-09 16:08:55.369765] DEBUG[404] chan_sip.c: Body 4 [ 5]: t=0 0 [2019-04-09 16:08:55.369786] DEBUG[404] chan_sip.c: Body 5 [ 27]: m=audio 10352 RTP/AVP 0 101 [2019-04-09 16:08:55.369805] DEBUG[404] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2019-04-09 16:08:55.369825] DEBUG[404] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [2019-04-09 16:08:55.369845] DEBUG[404] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [2019-04-09 16:08:55.369864] DEBUG[404] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [2019-04-09 16:08:55.369883] DEBUG[404] chan_sip.c: Body 10 [ 10]: a=ptime:20 [2019-04-09 16:08:55.369902] DEBUG[404] chan_sip.c: Body 11 [ 14]: a=maxptime:150 [2019-04-09 16:08:55.369922] DEBUG[404] chan_sip.c: Body 12 [ 10]: a=sendrecv [2019-04-09 16:08:55.370024] DEBUG[404] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #16 [2019-04-09 16:08:55.370052] DEBUG[404] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.1.100:5060 [2019-04-09 16:08:55.374166] DEBUG[401] res_http_websocket.c: Writing websocket string of length 653 [2019-04-09 16:08:55.374211] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 653 [2019-04-09 16:08:55.392233] VERBOSE[381] chan_sip.c: <--- SIP read from UDP:192.168.1.100:5060 ---> SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca From: ;tag=as30ac8d32 To: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 INVITE Server: kamailio (4.1.6 (x86_64/linux)) Content-Length: 0 <-------------> [2019-04-09 16:08:55.392290] DEBUG[381] chan_sip.c: Header 0 [ 50]: SIP/2.0 100 trying -- your call is important to us [2019-04-09 16:08:55.392316] DEBUG[381] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:08:55.392336] DEBUG[381] chan_sip.c: Header 2 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:08:55.392355] DEBUG[381] chan_sip.c: Header 3 [ 42]: To: [2019-04-09 16:08:55.392374] DEBUG[381] chan_sip.c: Header 4 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:08:55.392392] DEBUG[381] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2019-04-09 16:08:55.392411] DEBUG[381] chan_sip.c: Header 6 [ 39]: Server: kamailio (4.1.6 (x86_64/linux)) [2019-04-09 16:08:55.392429] DEBUG[381] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2019-04-09 16:08:55.392453] VERBOSE[381] chan_sip.c: --- (8 headers 0 lines) --- [2019-04-09 16:08:55.392492] DEBUG[381] chan_sip.c: = Looking for Call ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 (Checking To) --From tag as30ac8d32 --To-tag [2019-04-09 16:08:55.392696] DEBUG[381] chan_sip.c: *** SIP TIMER: Cancelling retransmission #16 - INVITE (got response) [2019-04-09 16:08:55.392725] DEBUG[381] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' Request 102: Found [2019-04-09 16:08:55.392759] DEBUG[381] chan_sip.c: SIP response 100 to standard invite [2019-04-09 16:08:56.119068] VERBOSE[381] chan_sip.c: <--- SIP read from UDP:192.168.1.100:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca Record-Route: Record-Route: To: ;tag=gK08ab5f50 From: ;tag=as30ac8d32 Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 INVITE Contact: Content-Length: 0 <-------------> [2019-04-09 16:08:56.119154] DEBUG[381] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [2019-04-09 16:08:56.119185] DEBUG[381] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:08:56.119208] DEBUG[381] chan_sip.c: Header 2 [ 78]: Record-Route: [2019-04-09 16:08:56.119230] DEBUG[381] chan_sip.c: Header 3 [ 40]: Record-Route: [2019-04-09 16:08:56.119251] DEBUG[381] chan_sip.c: Header 4 [ 57]: To: ;tag=gK08ab5f50 [2019-04-09 16:08:56.119273] DEBUG[381] chan_sip.c: Header 5 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:08:56.119293] DEBUG[381] chan_sip.c: Header 6 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:08:56.119314] DEBUG[381] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2019-04-09 16:08:56.119335] DEBUG[381] chan_sip.c: Header 8 [ 45]: Contact: [2019-04-09 16:08:56.119355] DEBUG[381] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2019-04-09 16:08:56.119382] VERBOSE[381] chan_sip.c: --- (10 headers 0 lines) --- [2019-04-09 16:08:56.119427] DEBUG[381] chan_sip.c: = Looking for Call ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 (Checking To) --From tag as30ac8d32 --To-tag gK08ab5f50 [2019-04-09 16:08:56.119626] DEBUG[381] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' Request 102: Found [2019-04-09 16:08:56.119660] DEBUG[381] chan_sip.c: SIP response 180 to standard invite [2019-04-09 16:08:56.119699] DEBUG[381] sip/route.c: sip_route_process_header: [2019-04-09 16:08:56.119723] DEBUG[381] sip/route.c: sip_route_process_header: [2019-04-09 16:08:56.119745] VERBOSE[381] sip/route.c: sip_route_dump: route/path hop: [2019-04-09 16:08:56.119764] VERBOSE[381] sip/route.c: sip_route_dump: route/path hop: [2019-04-09 16:08:56.120185] DEBUG[401] res_http_websocket.c: Writing websocket string of length 584 [2019-04-09 16:08:56.120212] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 584 [2019-04-09 16:08:56.120406] DEBUG[369] devicestate.c: No provider found, checking channel drivers for SIP - 192.168.1.100 [2019-04-09 16:08:56.120439] DEBUG[369] chan_sip.c: Checking device state for peer 192.168.1.100 [2019-04-09 16:08:56.120474] DEBUG[369] devicestate.c: Changing state for SIP/192.168.1.100 - state 4 (Invalid) [2019-04-09 16:08:56.122741] VERBOSE[405][C-00000001] chan_sip.c: <--- Transmitting (no NAT) to 192.168.1.300:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.300:5060;branch=z9hG4bK1sansay755697336rdb3574;received=192.168.1.300 Record-Route: From: ;tag=sansay755697336rdb3574 To: ;tag=as19f9b3df Call-ID: 221854977-1-4091820138@192.168.1.400 CSeq: 1 INVITE Server: SmartLine Media Server Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Session-Expires: 600;refresher=uac Contact: Content-Length: 0 <------------> [2019-04-09 16:08:56.122805] DEBUG[405][C-00000001] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [2019-04-09 16:08:56.122829] DEBUG[405][C-00000001] chan_sip.c: Header 1 [ 96]: Via: SIP/2.0/UDP 192.168.1.300:5060;branch=z9hG4bK1sansay755697336rdb3574;received=192.168.1.300 [2019-04-09 16:08:56.122853] DEBUG[405][C-00000001] chan_sip.c: Header 2 [ 78]: Record-Route: [2019-04-09 16:08:56.122874] DEBUG[405][C-00000001] chan_sip.c: Header 3 [ 77]: From: ;tag=sansay755697336rdb3574 [2019-04-09 16:08:56.122895] DEBUG[405][C-00000001] chan_sip.c: Header 4 [ 51]: To: ;tag=as19f9b3df [2019-04-09 16:08:56.122916] DEBUG[405][C-00000001] chan_sip.c: Header 5 [ 45]: Call-ID: 221854977-1-4091820138@192.168.1.400 [2019-04-09 16:08:56.122936] DEBUG[405][C-00000001] chan_sip.c: Header 6 [ 14]: CSeq: 1 INVITE [2019-04-09 16:08:56.122957] DEBUG[405][C-00000001] chan_sip.c: Header 7 [ 30]: Server: SmartLine Media Server [2019-04-09 16:08:56.122978] DEBUG[405][C-00000001] chan_sip.c: Header 8 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [2019-04-09 16:08:56.123007] DEBUG[405][C-00000001] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2019-04-09 16:08:56.123040] DEBUG[405][C-00000001] chan_sip.c: Header 10 [ 34]: Session-Expires: 600;refresher=uac [2019-04-09 16:08:56.123075] DEBUG[405][C-00000001] chan_sip.c: Header 11 [ 46]: Contact: [2019-04-09 16:08:56.123099] DEBUG[405][C-00000001] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2019-04-09 16:08:56.123121] DEBUG[405][C-00000001] chan_sip.c: Header 13 [ 0]: [2019-04-09 16:08:56.123178] DEBUG[405][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.1.300:5060 [2019-04-09 16:08:56.123295] DEBUG[405][C-00000001] channel.c: Driver for channel 'SIP/192.168.1.300-00000000' does not support indication 3, emulating it [2019-04-09 16:08:56.123444] DEBUG[405][C-00000001] channel.c: Channel SIP/192.168.1.300-00000000 setting write format path: slin -> ulaw [2019-04-09 16:08:56.123517] DEBUG[405][C-00000001] channel.c: Prodding channel 'SIP/192.168.1.300-00000000' [2019-04-09 16:08:56.123607] DEBUG[405][C-00000001] res_rtp_asterisk.c: Setting the marker bit due to a source update [2019-04-09 16:08:56.123818] DEBUG[401] res_http_websocket.c: Writing websocket string of length 631 [2019-04-09 16:08:56.123839] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 631 [2019-04-09 16:09:05.374544] DEBUG[406] bridge_channel.c: Executing hook 0x7fdcec006978 on 0x7fdcec000bd0(SIP/192.168.1.100-00000001) [2019-04-09 16:09:05.374715] DEBUG[406] bridge_channel.c: Removed interval hook 0x7fdcec006978 from 0x7fdcec000bd0(SIP/192.168.1.100-00000001) [2019-04-09 16:09:05.374897] DEBUG[404] channel.c: Soft-Hanging (0x20) up channel 'SIP/192.168.1.100-00000001' [2019-04-09 16:09:05.375058] DEBUG[404] bridge_channel.c: Setting 0x7fdcec000bd0(SIP/192.168.1.100-00000001) state from:0 to:2 [2019-04-09 16:09:05.375195] DEBUG[404] bridge.c: Waiting for 0x7fdcec000bd0(SIP/192.168.1.100-00000001) bridge thread to die. [2019-04-09 16:09:05.375337] DEBUG[401] res_http_websocket.c: Writing websocket string of length 617 [2019-04-09 16:09:05.375355] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 617 [2019-04-09 16:09:05.375639] DEBUG[401] res_http_websocket.c: Writing websocket string of length 622 [2019-04-09 16:09:05.375663] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 622 [2019-04-09 16:09:05.375822] DEBUG[401] res_http_websocket.c: Writing websocket string of length 627 [2019-04-09 16:09:05.375840] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 627 [2019-04-09 16:09:05.376168] DEBUG[406] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: pulling 0x7fdcec000bd0(SIP/192.168.1.100-00000001) [2019-04-09 16:09:05.376205] VERBOSE[406] bridge_channel.c: Channel SIP/192.168.1.100-00000001 left 'simple_bridge' stasis-bridge <139f2626-443b-4b27-a6f3-b13505e0af09> [2019-04-09 16:09:05.376223] DEBUG[406] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: 0x7fdcec000bd0(SIP/192.168.1.100-00000001) is leaving simple_bridge technology [2019-04-09 16:09:05.376322] DEBUG[406] bridge_native_rtp.c: Bridge '139f2626-443b-4b27-a6f3-b13505e0af09' can not use native RTP bridge as two channels are required [2019-04-09 16:09:05.376341] DEBUG[406] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [2019-04-09 16:09:05.376358] DEBUG[406] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [2019-04-09 16:09:05.376374] DEBUG[406] bridge.c: Bridge technology softmix does not have any capabilities we want. [2019-04-09 16:09:05.376389] DEBUG[406] bridge.c: Chose bridge technology simple_bridge [2019-04-09 16:09:05.376403] DEBUG[406] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09 is already using the new technology. [2019-04-09 16:09:05.376507] DEBUG[406] stasis/control.c: 1554826135.1, 139f2626-443b-4b27-a6f3-b13505e0af09: Channel was departed from bridge [2019-04-09 16:09:05.376531] DEBUG[406] stasis/app.c: bridge '139f2626-443b-4b27-a6f3-b13505e0af09': is 3 interested in bridge-dial [2019-04-09 16:09:05.376594] DEBUG[406] stasis/control.c: reason: Channel was departed from bridge [2019-04-09 16:09:05.377018] DEBUG[377] cdr.c: Finalized CDR for SIP/192.168.1.300-00000000 - start 1554826134.975060 answer 0.000000 end 1554826145.377016 dispo NO ANSWER [2019-04-09 16:09:05.377899] DEBUG[404] stasis/app.c: channel '1554826135.1': is 1 interested in bridge-dial [2019-04-09 16:09:05.378042] DEBUG[404] channel.c: Channel 0x7fdce40027e0 'SIP/192.168.1.100-00000001' hanging up. Refs: 2 [2019-04-09 16:09:05.378109] DEBUG[404] chan_sip.c: Hangup call SIP/192.168.1.100-00000001, SIP callid 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:09:05.378137] DEBUG[404] chan_sip.c: Hanging up channel in state Ringing (not UP) [2019-04-09 16:09:05.378244] VERBOSE[404] chan_sip.c: Scheduling destruction of SIP dialog '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' in 32000 ms (Method: INVITE) [2019-04-09 16:09:05.378282] DEBUG[404] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' Request 102: Found [2019-04-09 16:09:05.378385] VERBOSE[404] chan_sip.c: Reliably Transmitting (no NAT) to 192.168.1.100:5060: CANCEL sip:12345+17604009986@192.168.1.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca Max-Forwards: 70 From: ;tag=as30ac8d32 To: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 CANCEL User-Agent: SmartLine Media Server Content-Length: 0 --- [2019-04-09 16:09:05.378421] DEBUG[404] chan_sip.c: Header 0 [ 51]: CANCEL sip:12345+17604009986@192.168.1.100 SIP/2.0 [2019-04-09 16:09:05.378447] DEBUG[404] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:09:05.378472] DEBUG[404] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2019-04-09 16:09:05.378496] DEBUG[404] chan_sip.c: Header 3 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:09:05.378522] DEBUG[404] chan_sip.c: Header 4 [ 42]: To: [2019-04-09 16:09:05.378598] DEBUG[404] chan_sip.c: Header 5 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:09:05.378629] DEBUG[404] chan_sip.c: Header 6 [ 16]: CSeq: 102 CANCEL [2019-04-09 16:09:05.378653] DEBUG[404] chan_sip.c: Header 7 [ 34]: User-Agent: SmartLine Media Server [2019-04-09 16:09:05.378675] DEBUG[404] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2019-04-09 16:09:05.378697] DEBUG[404] chan_sip.c: Header 9 [ 0]: [2019-04-09 16:09:05.378767] DEBUG[404] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #12 [2019-04-09 16:09:05.378795] DEBUG[404] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.1.100:5060 [2019-04-09 16:09:05.378917] VERBOSE[404] chan_sip.c: Scheduling destruction of SIP dialog '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' in 32000 ms (Method: INVITE) [2019-04-09 16:09:05.378981] DEBUG[404] channel.c: Channel 0x7fdce40027e0 'SIP/192.168.1.100-00000001' destroying [2019-04-09 16:09:05.385725] VERBOSE[381] chan_sip.c: <--- SIP read from UDP:192.168.1.100:5060 ---> SIP/2.0 200 canceling Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca From: ;tag=as30ac8d32 To: ;tag=a6a1c5f60faecf035a1ae5b6e96e979a-5919 Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 CANCEL Server: kamailio (4.1.6 (x86_64/linux)) Content-Length: 0 <-------------> [2019-04-09 16:09:05.385766] DEBUG[381] chan_sip.c: Header 0 [ 21]: SIP/2.0 200 canceling [2019-04-09 16:09:05.385795] DEBUG[381] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:09:05.385822] DEBUG[381] chan_sip.c: Header 2 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:09:05.385847] DEBUG[381] chan_sip.c: Header 3 [ 84]: To: ;tag=a6a1c5f60faecf035a1ae5b6e96e979a-5919 [2019-04-09 16:09:05.385872] DEBUG[381] chan_sip.c: Header 4 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:09:05.385895] DEBUG[381] chan_sip.c: Header 5 [ 16]: CSeq: 102 CANCEL [2019-04-09 16:09:05.385918] DEBUG[381] chan_sip.c: Header 6 [ 39]: Server: kamailio (4.1.6 (x86_64/linux)) [2019-04-09 16:09:05.385943] DEBUG[381] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2019-04-09 16:09:05.385972] VERBOSE[381] chan_sip.c: --- (8 headers 0 lines) --- [2019-04-09 16:09:05.386014] DEBUG[381] chan_sip.c: = Looking for Call ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 (Checking To) --From tag as30ac8d32 --To-tag a6a1c5f60faecf035a1ae5b6e96e979a-5919 [2019-04-09 16:09:05.386124] DEBUG[381] chan_sip.c: Acked pending invite 102 [2019-04-09 16:09:05.386147] DEBUG[381] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [2019-04-09 16:09:05.386174] DEBUG[381] chan_sip.c: Stopping retransmission on '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' of Request 102: Match Found [2019-04-09 16:09:05.386335] DEBUG[369] devicestate.c: No provider found, checking channel drivers for SIP - 192.168.1.100 [2019-04-09 16:09:05.386358] DEBUG[369] chan_sip.c: Checking device state for peer 192.168.1.100 [2019-04-09 16:09:05.386386] DEBUG[369] devicestate.c: Changing state for SIP/192.168.1.100 - state 4 (Invalid) [2019-04-09 16:09:05.386518] DEBUG[377] cdr.c: Finalized CDR for SIP/192.168.1.100-00000001 - start 1554826135.370387 answer 0.000000 end 1554826145.386516 dispo NO ANSWER [2019-04-09 16:09:05.386547] DEBUG[377] cdr.c: CDR for SIP/192.168.1.100-00000001 is dialed and has no Party B; discarding [2019-04-09 16:09:05.386606] DEBUG[377] cdr.c: CDR for SIP/192.168.1.100-00000001 is dialed and has no Party B; discarding [2019-04-09 16:09:05.386831] DEBUG[401] res_http_websocket.c: Writing websocket string of length 912 [2019-04-09 16:09:05.386850] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 912 [2019-04-09 16:09:05.387028] DEBUG[401] res_http_websocket.c: Writing websocket string of length 575 [2019-04-09 16:09:05.387046] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 575 [2019-04-09 16:09:05.387189] DEBUG[401] res_http_websocket.c: Writing websocket string of length 631 [2019-04-09 16:09:05.387206] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 631 [2019-04-09 16:09:05.387353] DEBUG[401] res_http_websocket.c: Writing websocket string of length 631 [2019-04-09 16:09:05.387371] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 631 [2019-04-09 16:09:05.387441] DEBUG[401] stasis/app.c: channel '1554826135.1': is 0 interested in bridge-dial [2019-04-09 16:09:05.387493] DEBUG[401] stasis/app.c: channel '1554826135.1' unsubscribed from bridge-dial [2019-04-09 16:09:05.387513] DEBUG[401] stasis.c: Topic 'cache:5/channel:1554826135.1': 0x7fdce4008180 destroyed [2019-04-09 16:09:05.387539] DEBUG[401] stasis.c: Topic 'channel:1554826135.1': 0x7fdce4007fe0 destroyed [2019-04-09 16:09:05.397873] VERBOSE[381] chan_sip.c: <--- SIP read from UDP:192.168.1.100:5060 ---> SIP/2.0 487 transaction terminated Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca To: ;tag=gK08ab5f50 From: ;tag=as30ac8d32 Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 INVITE Content-Length: 0 <-------------> [2019-04-09 16:09:05.397932] DEBUG[381] chan_sip.c: Header 0 [ 34]: SIP/2.0 487 transaction terminated [2019-04-09 16:09:05.397954] DEBUG[381] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:09:05.397986] DEBUG[381] chan_sip.c: Header 2 [ 57]: To: ;tag=gK08ab5f50 [2019-04-09 16:09:05.398005] DEBUG[381] chan_sip.c: Header 3 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:09:05.398021] DEBUG[381] chan_sip.c: Header 4 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:09:05.398037] DEBUG[381] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2019-04-09 16:09:05.398053] DEBUG[381] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [2019-04-09 16:09:05.398074] VERBOSE[381] chan_sip.c: --- (7 headers 0 lines) --- [2019-04-09 16:09:05.398107] DEBUG[381] chan_sip.c: = Looking for Call ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 (Checking To) --From tag as30ac8d32 --To-tag gK08ab5f50 [2019-04-09 16:09:05.398191] DEBUG[381] chan_sip.c: Stopping retransmission on '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' of Request 102: Match Found [2019-04-09 16:09:05.398213] DEBUG[381] chan_sip.c: SIP response 487 to standard invite [2019-04-09 16:09:05.398274] VERBOSE[381] chan_sip.c: Transmitting (no NAT) to 192.168.1.100:5060: ACK sip:+17604009986@192.168.16.8:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca Max-Forwards: 70 From: ;tag=as30ac8d32 To: ;tag=gK08ab5f50 Contact: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 CSeq: 102 ACK User-Agent: SmartLine Media Server Content-Length: 0 --- [2019-04-09 16:09:05.398297] DEBUG[381] chan_sip.c: Header 0 [ 46]: ACK sip:+17604009986@192.168.16.8:5060 SIP/2.0 [2019-04-09 16:09:05.398314] DEBUG[381] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 192.168.1.200:5060;branch=z9hG4bK0b5565ca [2019-04-09 16:09:05.398330] DEBUG[381] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2019-04-09 16:09:05.398347] DEBUG[381] chan_sip.c: Header 3 [ 54]: From: ;tag=as30ac8d32 [2019-04-09 16:09:05.398363] DEBUG[381] chan_sip.c: Header 4 [ 57]: To: ;tag=gK08ab5f50 [2019-04-09 16:09:05.398378] DEBUG[381] chan_sip.c: Header 5 [ 47]: Contact: [2019-04-09 16:09:05.398394] DEBUG[381] chan_sip.c: Header 6 [ 61]: Call-ID: 556ede474567230453bd538f0b8325b8@192.168.1.200:5060 [2019-04-09 16:09:05.398409] DEBUG[381] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [2019-04-09 16:09:05.398425] DEBUG[381] chan_sip.c: Header 8 [ 34]: User-Agent: SmartLine Media Server [2019-04-09 16:09:05.398440] DEBUG[381] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2019-04-09 16:09:05.398455] DEBUG[381] chan_sip.c: Header 10 [ 0]: [2019-04-09 16:09:05.398497] DEBUG[381] chan_sip.c: Trying to put 'ACK sip:+17' onto UDP socket destined for 192.168.1.100:5060 [2019-04-09 16:09:05.398594] DEBUG[381] chan_sip.c: Updating call counter for outgoing call [2019-04-09 16:09:05.398669] VERBOSE[381] chan_sip.c: Scheduling destruction of SIP dialog '556ede474567230453bd538f0b8325b8@192.168.1.200:5060' in 32000 ms (Method: INVITE) [2019-04-09 16:09:05.415352] DEBUG[403] http.c: HTTP Request URI is /ari/channels/1554826135.1 [2019-04-09 16:09:05.415398] DEBUG[403] http.c: match request [ari/channels/1554826135.1] with handler [httpstatus] len 10 [2019-04-09 16:09:05.415416] DEBUG[403] http.c: match request [ari/channels/1554826135.1] with handler [static] len 6 [2019-04-09 16:09:05.415433] DEBUG[403] http.c: match request [ari/channels/1554826135.1] with handler [ari] len 3 [2019-04-09 16:09:05.415448] DEBUG[403] http.c: Match made with [ari] [2019-04-09 16:09:05.415489] DEBUG[403] res_ari.c: Finding handler for channels [2019-04-09 16:09:05.415506] DEBUG[403] res_ari.c: Checking endpoints [2019-04-09 16:09:05.415522] DEBUG[403] res_ari.c: Checking bridges [2019-04-09 16:09:05.415538] DEBUG[403] res_ari.c: Checking sounds [2019-04-09 16:09:05.415580] DEBUG[403] res_ari.c: Checking events [2019-04-09 16:09:05.415598] DEBUG[403] res_ari.c: Checking asterisk [2019-04-09 16:09:05.415613] DEBUG[403] res_ari.c: Checking channels [2019-04-09 16:09:05.415627] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:09:05.415642] DEBUG[403] res_ari.c: Finding handler for 1554826135.1 [2019-04-09 16:09:05.415656] DEBUG[403] res_ari.c: Checking create [2019-04-09 16:09:05.415670] DEBUG[403] res_ari.c: Checking channelId [2019-04-09 16:09:05.415685] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:09:05.415828] DEBUG[403] http.c: HTTP keeping session open. status_code:404 [2019-04-09 16:09:05.435800] DEBUG[403] http.c: HTTP Request URI is /ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09 [2019-04-09 16:09:05.435852] DEBUG[403] http.c: match request [ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09] with handler [httpstatus] len 10 [2019-04-09 16:09:05.435872] DEBUG[403] http.c: match request [ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09] with handler [static] len 6 [2019-04-09 16:09:05.435888] DEBUG[403] http.c: match request [ari/bridges/139f2626-443b-4b27-a6f3-b13505e0af09] with handler [ari] len 3 [2019-04-09 16:09:05.435903] DEBUG[403] http.c: Match made with [ari] [2019-04-09 16:09:05.435938] DEBUG[403] res_ari.c: Finding handler for bridges [2019-04-09 16:09:05.435955] DEBUG[403] res_ari.c: Checking endpoints [2019-04-09 16:09:05.435969] DEBUG[403] res_ari.c: Checking bridges [2019-04-09 16:09:05.435984] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:09:05.435999] DEBUG[403] res_ari.c: Finding handler for 139f2626-443b-4b27-a6f3-b13505e0af09 [2019-04-09 16:09:05.436013] DEBUG[403] res_ari.c: Checking bridgeId [2019-04-09 16:09:05.436029] DEBUG[403] res_ari.c: Got it! [2019-04-09 16:09:05.436052] DEBUG[403] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: telling all channels to leave the party [2019-04-09 16:09:05.436070] DEBUG[403] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: dissolving bridge with cause 16(Normal Clearing) [2019-04-09 16:09:05.436088] DEBUG[403] bridge_channel.c: Setting 0x7fdce80066e0(SIP/192.168.1.300-00000000) state from:0 to:2 [2019-04-09 16:09:05.436252] DEBUG[403] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: queueing action type:13 sub:1001 [2019-04-09 16:09:05.436372] DEBUG[403] http.c: HTTP keeping session open. status_code:204 [2019-04-09 16:09:05.436464] DEBUG[405][C-00000001] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: pulling 0x7fdce80066e0(SIP/192.168.1.300-00000000) [2019-04-09 16:09:05.436489] VERBOSE[405][C-00000001] bridge_channel.c: Channel SIP/192.168.1.300-00000000 left 'simple_bridge' stasis-bridge <139f2626-443b-4b27-a6f3-b13505e0af09> [2019-04-09 16:09:05.436506] DEBUG[405][C-00000001] bridge_channel.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: 0x7fdce80066e0(SIP/192.168.1.300-00000000) is leaving simple_bridge technology [2019-04-09 16:09:05.436702] DEBUG[405][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09 is dissolved, not performing smart bridge operation. [2019-04-09 16:09:05.436760] DEBUG[405][C-00000001] res_rtp_asterisk.c: Changing ssrc from 537896846 to 2073326342 due to a source change [2019-04-09 16:09:05.436832] DEBUG[405][C-00000001] bridge_channel.c: Bridge is returning 0x7fdce80066e0(SIP/192.168.1.300-00000000) to write format ulaw [2019-04-09 16:09:05.436871] DEBUG[405][C-00000001] channel.c: Channel SIP/192.168.1.300-00000000 setting write format path: ulaw -> ulaw [2019-04-09 16:09:05.436900] DEBUG[405][C-00000001] stasis/control.c: 1554826134.0, 139f2626-443b-4b27-a6f3-b13505e0af09: Channel was departed from bridge [2019-04-09 16:09:05.436921] DEBUG[405][C-00000001] stasis/app.c: bridge '139f2626-443b-4b27-a6f3-b13505e0af09': is 2 interested in bridge-dial [2019-04-09 16:09:05.436963] DEBUG[405][C-00000001] stasis/control.c: reason: Channel was departed from bridge [2019-04-09 16:09:05.437288] DEBUG[402][C-00000001] stasis/control.c: 1554826134.0: Channel departing bridge [2019-04-09 16:09:05.437314] DEBUG[402][C-00000001] bridge.c: Waiting for 0x7fdce80066e0(SIP/192.168.1.300-00000000) bridge thread to die. [2019-04-09 16:09:05.437442] DEBUG[402][C-00000001] bridge.c: Bridge technology native_rtp does not have any capabilities we want. [2019-04-09 16:09:05.437472] DEBUG[402][C-00000001] bridge.c: Bridge technology simple_bridge does not have any capabilities we want. [2019-04-09 16:09:05.437496] DEBUG[402][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [2019-04-09 16:09:05.437512] DEBUG[402][C-00000001] bridge.c: Chose bridge technology holding_bridge [2019-04-09 16:09:05.437528] DEBUG[402][C-00000001] bridge.c: Bridge 051c140c-06f5-4d07-9329-bea86e686d18: calling holding_bridge technology constructor [2019-04-09 16:09:05.437543] DEBUG[402][C-00000001] bridge.c: Bridge 051c140c-06f5-4d07-9329-bea86e686d18: calling holding_bridge technology start [2019-04-09 16:09:05.437616] WARNING[402][C-00000001] bridge.c: Channel SIP/192.168.1.300-00000000 has a PBX thread and cannot be imparted into bridge 051c140c-06f5-4d07-9329-bea86e686d18 [2019-04-09 16:09:05.437658] DEBUG[402][C-00000001] stasis/app.c: bridge '139f2626-443b-4b27-a6f3-b13505e0af09': is 1 interested in bridge-dial [2019-04-09 16:09:05.437712] DEBUG[402][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: actually destroying stasis bridge, nobody wants it anymore [2019-04-09 16:09:05.437770] DEBUG[402][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: calling stasis bridge destructor [2019-04-09 16:09:05.437787] DEBUG[402][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: calling simple_bridge technology stop [2019-04-09 16:09:05.437802] DEBUG[402][C-00000001] bridge.c: Bridge 139f2626-443b-4b27-a6f3-b13505e0af09: calling simple_bridge technology destructor [2019-04-09 16:09:05.437991] DEBUG[401] res_http_websocket.c: Writing websocket string of length 629 [2019-04-09 16:09:05.438010] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 629 [2019-04-09 16:09:05.438206] DEBUG[401] res_http_websocket.c: Writing websocket string of length 634 [2019-04-09 16:09:05.438233] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 634 [2019-04-09 16:09:05.438469] DEBUG[401] res_http_websocket.c: Writing websocket string of length 893 [2019-04-09 16:09:05.438488] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 893 [2019-04-09 16:09:05.438668] DEBUG[401] res_http_websocket.c: Writing websocket string of length 451 [2019-04-09 16:09:05.438686] DEBUG[401] res_http_websocket.c: Writing websocket text frame, length 451 [2019-04-09 16:09:05.438759] DEBUG[401] stasis/app.c: bridge '139f2626-443b-4b27-a6f3-b13505e0af09': is 0 interested in bridge-dial [2019-04-09 16:09:05.438780] DEBUG[401] stasis/app.c: bridge '139f2626-443b-4b27-a6f3-b13505e0af09' unsubscribed from bridge-dial [2019-04-09 16:09:05.438799] DEBUG[401] stasis.c: Topic 'cache:6/bridge:139f2626-443b-4b27-a6f3-b13505e0af09': 0x7fdce4012030 destroyed [2019-04-09 16:09:05.438827] DEBUG[401] stasis.c: Topic 'bridge:139f2626-443b-4b27-a6f3-b13505e0af09': 0x7fdce4011f10 destroyed