Skip to content

Instantly share code, notes, and snippets.

@system123

system123/MinCallController

Last active August 29, 2015 14:03
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save system123/93c5c24e73fff17e54fe to your computer and use it in GitHub Desktop.
Save system123/93c5c24e73fff17e54fe to your computer and use it in GitHub Desktop.
Download ZIP
Call recording completion bug
Raw
MinCallController
class ClickToCallController < Adhearsion::CallController
def run
answer
call.on_end {
logger.info "CALL HAS ENDED - THIS IS ON_END METHOD"
}
call.on_joined {
@recorder = record async: true do |event|
logger.info "CALL RECORDING IS COMPLETED: #{event.recording.uri}"
end
}
call.on_unjoined {
@recorder.stop! if @recorder.executing?
}
@status = dial next_number, ringback: 'ring', from: outbound_id
hangup
end
private
def next_number
metadata[:callee_num]
end
def outbound_id
metadata[:outbound_id]
end
end
Raw
Trace Log
enigma@teleforgepbx:/var/enigmasoft/C2D/current $ bundle exec ahn start
Starting Adhearsion server at /var/enigmasoft/C2D/releases/20140715094916
/var/enigmasoft/C2D/shared/bundle/jruby/1.9/gems/logging-1.8.2/lib/logging/appenders/io.rb:74 warning: syswrite for buffered IO
[2014-07-15 20:08:35.706] TRACE Adhearsion::Initializer: OS: linux - RUBY: jruby 1.9.3
[2014-07-15 20:08:35.722] TRACE Adhearsion::Initializer: Environment: {"SHLVL"=>"1", "BUNDLE_GEMFILE"=>"/var/enigmasoft/C2D/releases/20140715094916/Gemfile", "QTINC"=>"/usr/lib/qt-3.3/include", "GEM_HOME"=>"/var/enigmasoft/C2D/shared/bundle/jruby/1.9", "rvm_prefix"=>"/home/enigma", "SSH_CLIENT"=>"105.237.75.74 57109 22", "TZ"=>"Africa/Johannesburg", "rvm_version"=>"1.25.27 (stable)", "USER"=>"enigma", "MAIL"=>"/var/spool/mail/enigma", "RUBY_VERSION"=>"jruby-1.7.12", "_system_arch"=>"i386", "LOGNAME"=>"enigma", "_ORIGINAL_GEM_PATH"=>"/home/enigma/.rvm/gems/jruby-1.7.12@click2call:/home/enigma/.rvm/gems/jruby-1.7.12@global", "_system_name"=>"CentOS", "SSH_TTY"=>"/dev/pts/0", "rvm_ruby_string"=>"jruby-1.7.12", "LESSOPEN"=>"|/usr/bin/lesspipe.sh %s", "XFILESEARCHPATH"=>"/usr/dt/app-defaults/%L/Dt", "rvm_delete_flag"=>"0", "PATH"=>"/var/enigmasoft/C2D/shared/bundle/jruby/1.9/bin:/home/enigma/.rvm/gems/jruby-1.7.12@click2call/bin:/home/enigma/.rvm/gems/jruby-1.7.12@global/bin:/home/enigma/.rvm/rubies/jruby-1.7.12/bin:/home/enigma/.rvm/bin:/usr/lib/qt-3.3/bin:/usr/local/bin:/bin:/usr/bin:/usr/local/sbin:/usr/sbin:/sbin:/home/enigma/bin", "MY_RUBY_HOME"=>"/home/enigma/.rvm/rubies/jruby-1.7.12", "PWD"=>"/var/enigmasoft/C2D/current", "SSH_ASKPASS"=>"/usr/libexec/openssh/gnome-ssh-askpass", "_system_version"=>"6", "HISTCONTROL"=>"ignoredups", "HISTSIZE"=>"1000", "NLSPATH"=>"/usr/dt/lib/nls/msg/%L/%N.cat", "LS_COLORS"=>"rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;05;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arj=01;31:*.taz=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.dz=01;31:*.gz=01;31:*.lz=01;31:*.xz=01;31:*.bz2=01;31:*.tbz=01;31:*.tbz2=01;31:*.bz=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.rar=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.jpg=01;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.axv=01;35:*.anx=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.axa=01;36:*.oga=01;36:*.spx=01;36:*.xspf=01;36:", "QTLIB"=>"/usr/lib/qt-3.3/lib", "_system_type"=>"Linux", "SSH_CONNECTION"=>"105.237.75.74 57109 123.123.123.123 22", "PS1"=>"\\[\e[32m\\]\\u@\\h:\\w $ \\[\e(B\e[m\\]", "IRBRC"=>"/home/enigma/.rvm/rubies/jruby-1.7.12/.irbrc", "HOME"=>"/home/enigma", "TERM"=>"xterm", "RUBYOPT"=>"-rbundler/setup", "CVS_RSH"=>"ssh", "HOSTNAME"=>"teleforgepbx.co.za", "RUBYLIB"=>"/home/enigma/.rvm/gems/jruby-1.7.12@global/gems/bundler-1.6.2/lib", "rvm_path"=>"/home/enigma/.rvm", "rvm_bin_path"=>"/home/enigma/.rvm/bin", "G_BROKEN_FILENAMES"=>"1", "QTDIR"=>"/usr/lib/qt-3.3", "GEM_PATH"=>"", "LANG"=>"en_US.UTF-8", "BUNDLE_BIN_PATH"=>"/home/enigma/.rvm/gems/jruby-1.7.12@global/gems/bundler-1.6.2/bin/bundle", "SHELL"=>"/bin/bash", "OLDPWD"=>"/home/enigma", "_"=>"/home/enigma/.rvm/gems/jruby-1.7.12@global/bin/bundle"}
/var/enigmasoft/C2D/shared/bundle/jruby/1.9/gems/logging-1.8.2/lib/logging/appenders/io.rb:74 warning: syswrite for buffered IO
[2014-07-15 20:08:35.723] TRACE Adhearsion::Initializer: # ******* Configuration for virginia **************
# The object that will be handling the requests. Must be a Reel:App. [AHN_VIRGINIA_HANDLER]
config.virginia.handler = RequestHandler
# IP to bind the listener to [AHN_VIRGINIA_HOST]
config.virginia.host = "0.0.0.0"
# The port to bind the listener to [AHN_VIRGINIA_PORT]
config.virginia.port = 8080
# ******* Configuration for lemondrop **************
# host where the database is running [AHN_LEMONDROP_HOST]
config.lemondrop.host = "localhost"
# valid database password [AHN_LEMONDROP_PASSWORD]
config.lemondrop.password = nil
# port where the database is listening [AHN_LEMONDROP_PORT]
config.lemondrop.port = 6379
# path to Unix socket where Redis is listening (Optional; to use, set host and port to nil) [AHN_LEMONDROP_SOCKET]
config.lemondrop.socket = ""
# URI to the Redis instance. Use this or specify each piece of connection information separately below. [AHN_LEMONDROP_URI]
config.lemondrop.uri = "redis://127.0.0.1:6379"
# valid database username [AHN_LEMONDROP_USERNAME]
config.lemondrop.username = ""
# ******* Configuration for sequella **************
# Database adapter. It should be an adapter supported by Sequel [AHN_SEQUELLA_ADAPTER]
config.sequella.adapter = "jdbc:mysql"
# Database name [AHN_SEQUELLA_DATABASE]
config.sequella.database = "somedb"
# host where the database is running [AHN_SEQUELLA_HOST]
config.sequella.host = "localhost"
# paths to model files to load [AHN_SEQUELLA_MODEL_PATHS]
config.sequella.model_paths = "/var/enigmasoft/C2D/releases/20140715094916/app/models"
# valid database password [AHN_SEQUELLA_PASSWORD]
config.sequella.password = "*********"
# port where the database is listening [AHN_SEQUELLA_PORT]
config.sequella.port = 3306
# URI to the database instance. Use this or specify each piece of connection information separately below. [AHN_SEQUELLA_URI]
config.sequella.uri = "jdbc:mysql://localhost:3306/somedb?user=root&password=*********&zeroDateTimeBehavior=convertToNull"
# valid database username [AHN_SEQUELLA_USERNAME]
config.sequella.username = "root"
# ******* Configuration for punchblock **************
# Directory containing certificates for securing the connection. [AHN_PUNCHBLOCK_CERTS_DIRECTORY]
config.punchblock.certs_directory = nil
# The amount of time to wait for a connection [AHN_PUNCHBLOCK_CONNECTION_TIMEOUT]
config.punchblock.connection_timeout = 60
# The default TTS voice to use. This is deprecated, please see core media config options for forward compatability. [AHN_PUNCHBLOCK_DEFAULT_VOICE]
config.punchblock.default_voice = nil
# Enable or disable Punchblock connectivity to a Voice server [AHN_PUNCHBLOCK_ENABLED]
config.punchblock.enabled = true
# Host punchblock needs to connect (where rayo/asterisk/freeswitch is located) [AHN_PUNCHBLOCK_HOST]
config.punchblock.host = "127.0.0.1"
# The media engine to use. Defaults to platform default. This is deprecated, please see core media config options for forward compatability. [AHN_PUNCHBLOCK_MEDIA_ENGINE]
config.punchblock.media_engine = nil
# Authentication credentials [AHN_PUNCHBLOCK_PASSWORD]
config.punchblock.password = "**********"
# Platform punchblock shall use to connect to the Telephony provider. Currently supported values:
# - :xmpp
# - :asterisk
# - :freeswitch [AHN_PUNCHBLOCK_PLATFORM]
config.punchblock.platform = :asterisk
# Port punchblock needs to connect [AHN_PUNCHBLOCK_PORT]
config.punchblock.port = 5038
# The number of times to (re)attempt connection to the server [AHN_PUNCHBLOCK_RECONNECT_ATTEMPTS]
config.punchblock.reconnect_attempts = Infinity
# Delay between connection attempts [AHN_PUNCHBLOCK_RECONNECT_TIMER]
config.punchblock.reconnect_timer = 5
# The root domain at which to address the server [AHN_PUNCHBLOCK_ROOT_DOMAIN]
config.punchblock.root_domain = nil
# Authentication credentials [AHN_PUNCHBLOCK_USERNAME]
config.punchblock.username = "username"
# ******* Configuration for platform **************
# Lifetime of a call after it has hung up. Should be set to the minimum functional value for your application. Call actors (threads) living after hangup consume more system resources and reduce the concurrent call capacity of your application. [AHN_PLATFORM_AFTER_HANGUP_LIFETIME]
config.platform.after_hangup_lifetime = 1
# Active environment. Supported values: development, production, staging, test [AHN_PLATFORM_ENVIRONMENT]
config.platform.environment = :production
# Folder to include the own libraries to be used. Adhearsion loads any ruby file
# located into this folder during the bootstrap process. Set to nil if you do not
# want these files to be loaded. This folder is relative to the application root folder. [AHN_PLATFORM_LIB]
config.platform.lib = "lib"
# Log configuration [AHN_PLATFORM_LOGGING]
config.platform.logging
# A log formatter to apply to all active outputters. If nil, the Adhearsion default formatter will be used. [AHN_PLATFORM_LOGGING_FORMATTER]
config.platform.logging.formatter = nil
# Supported levels (in increasing severity) -- :trace < :debug < :info < :warn < :error < :fatal [AHN_PLATFORM_LOGGING_LEVEL]
config.platform.logging.level = :trace
# An array of log outputters to use. The default is to log to stdout and log/adhearsion.log.
# Each item must be either a string to use as a filename, or a valid Logging appender (see http://github.com/TwP/logging) [AHN_PLATFORM_LOGGING_OUTPUTTERS]
config.platform.logging.outputters = ["log/adhearsion.log"]
# Media configuration [AHN_PLATFORM_MEDIA]
config.platform.media
# The default renderer used for all output. Set nil to use platform default. [AHN_PLATFORM_MEDIA_DEFAULT_RENDERER]
config.platform.media.default_renderer = nil
# The default voice used for all output. Set nil to use platform default. [AHN_PLATFORM_MEDIA_DEFAULT_VOICE]
config.platform.media.default_voice = nil
# Adhearsion process name, useful to make it easier to find in the process list
# Pro tip: set this to your application's name and you can do "killall myapp"
# Does not work under JRuby. [AHN_PLATFORM_PROCESS_NAME]
config.platform.process_name = "ahn"
# Adhearsion application root folder [AHN_PLATFORM_ROOT]
config.platform.root = "/var/enigmasoft/C2D/releases/20140715094916"
# ******* Configuration for recording_manager **************
# ******* Configuration for notification_manager **************
[2014-07-15 20:08:35.724] TRACE Adhearsion::Initializer: Gem versions: ["rake 10.3.2", "i18n 0.6.9", "json 1.8.1", "minitest 5.4.0", "thread_safe 0.3.4", "tzinfo 1.2.1", "activesupport 4.1.4", "adhearsion-loquacious 1.9.3", "bundler 1.6.2", "timers 1.1.0", "celluloid 0.15.2", "countdownlatch 1.0.0", "deep_merge 1.0.1", "ffi 1.9.3", "connection_pool 1.2.0", "rubinius-core-api 0.0.1", "rubinius-actor 0.0.2", "girl_friday 0.11.2", "has-guarded-handlers 1.6.0", "little-plugger 1.1.3", "multi_json 1.10.1", "logging 1.8.2", "coderay 1.1.0", "method_source 0.8.2", "slop 3.5.0", "spoon 0.0.4", "pry 0.10.0", "eventmachine 1.0.3", "nokogiri 1.6.2.1", "niceogiri 1.1.2", "blather 1.0.0", "future-resource 1.1.0", "nio4r 1.0.0", "celluloid-io 0.15.0", "ruby_ami 2.2.1", "ruby_fs 1.1.1", "ruby_jid 1.0.0", "ruby_speech 2.3.2", "state_machine 1.2.0", "descendants_tracker 0.0.4", "ice_nine 0.11.0", "axiom-types 0.1.1", "coercible 1.0.0", "equalizer 0.0.9", "virtus 1.0.2", "punchblock 2.5.2", "thor 0.18.1", "adhearsion 2.5.3", "colorize 0.7.3", "net-ssh 2.9.1", "net-scp 1.2.1", "sshkit 1.5.1", "capistrano 3.2.1", "capistrano-bundler 1.1.2", "fssm 0.2.10", "http_parser.rb 0.6.0", "http 0.6.1", "jdbc-mysql 5.1.30", "redis 3.1.0", "lemondrop 0.1.2", "websocket_parser 0.1.6", "reel 0.5.0", "rvm1-capistrano3 1.2.4", "sequel 4.12.0", "sequella 1.1.0", "virginia 0.2.1"]
/var/enigmasoft/C2D/shared/bundle/jruby/1.9/gems/logging-1.8.2/lib/logging/appenders/io.rb:74 warning: syswrite for buffered IO
[2014-07-15 20:08:35.861] INFO Adhearsion::Initializer: Setting RAILS_ENV to "production"
[2014-07-15 20:08:35.870] WARN Virginia::Plugin: Virginia has been loaded
/var/enigmasoft/C2D/shared/bundle/jruby/1.9/gems/logging-1.8.2/lib/logging/appenders/io.rb:74 warning: syswrite for buffered IO
[2014-07-15 20:08:35.916] INFO Lemondrop::Plugin::Service: Lemondrop connected to Redis at localhost:6379
[2014-07-15 20:08:35.928] INFO Sequella::Service: Sequella connecting: jdbc:mysql://localhost:3306/somedb?user=root&password=*********&zeroDateTimeBehavior=convertToNull
/var/enigmasoft/C2D/shared/bundle/jruby/1.9/gems/logging-1.8.2/lib/logging/appenders/io.rb:74 warning: syswrite for buffered IO
[2014-07-15 20:08:36.008] DEBUG Sequella::Service: Loading Sequel models from /var/enigmasoft/C2D/releases/20140715094916/app/models
[2014-07-15 20:08:36.660] INFO Adhearsion::Console: Launching Adhearsion Console
AHN> [2014-07-15 20:08:36.984] DEBUG Punchblock::Connection::Asterisk: Starting up...
[2014-07-15 20:08:37.027] INFO RecordingManager: Starting recoding file manager
[2014-07-15 20:08:37.136] INFO NotificationManager: Starting notification worker
[2014-07-15 20:08:37.423] INFO Adhearsion::PunchblockPlugin::Initializer: Starting connection to server
[2014-07-15 20:08:37.428] TRACE Punchblock::Connection::Asterisk: [SEND] Action: login
ActionID: 5df7f09b-cf2b-4518-b304-572159cb6304
Username: username
Secret: **********
Events: On
[2014-07-15 20:08:37.431] TRACE Punchblock::Connection::Asterisk: [RECV] Asterisk Call Manager/1.3
[2014-07-15 20:08:37.433] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 5df7f09b-cf2b-4518-b304-572159cb6304
Message: Authentication accepted
Event: FullyBooted
Privilege: system,all
Status: Fully Booted
[2014-07-15 20:08:37.441] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"5df7f09b-cf2b-4518-b304-572159cb6304", "Message"=>"Authentication accepted"}, text_body=nil, events=[]>
[2014-07-15 20:08:37.442] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="FullyBooted", headers={"Privilege"=>"system,all", "Status"=>"Fully Booted"}, text_body=nil, events=[]>
[2014-07-15 20:08:37.471] TRACE Punchblock::Connection::Asterisk: [SEND] Action: command
ActionID: 33cfcff7-1bc5-4a27-85b3-dd9bc339824f
Command: dialplan add extension 1,1,AGI,agi:async into adhearsion-redirect
[2014-07-15 20:08:37.473] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Follows
Privilege: Command
ActionID: 33cfcff7-1bc5-4a27-85b3-dd9bc339824f
Extension '1,1,AGI(agi:async)' added into 'adhearsion-redirect' context
--END COMMAND--
[2014-07-15 20:08:37.474] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"Privilege"=>"Command", "ActionID"=>"33cfcff7-1bc5-4a27-85b3-dd9bc339824f"}, text_body="Extension '1,1,AGI(agi:async)' added into 'adhearsion-redirect' context", events=[]>
[2014-07-15 20:08:37.479] TRACE Punchblock::Connection::Asterisk: [SEND] Action: command
ActionID: f9eab928-a3a6-46ab-9198-ef0508f4b9db
Command: dialplan show adhearsion-redirect
[2014-07-15 20:08:37.482] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Follows
Privilege: Command
ActionID: f9eab928-a3a6-46ab-9198-ef0508f4b9db
[ Context 'adhearsion-redirect' created by 'pbx_config' ]
'1' => 1. AGI(agi:async) [pbx_config]
-= 1 extension (1 priority) in 1 context. =-
--END COMMAND--
[2014-07-15 20:08:37.483] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"Privilege"=>"Command", "ActionID"=>"f9eab928-a3a6-46ab-9198-ef0508f4b9db"}, text_body="[ Context 'adhearsion-redirect' created by 'pbx_config' ]\n '1' => 1. AGI(agi:async) [pbx_config]\n\n-= 1 extension (1 priority) in 1 context. =-", events=[]>
[2014-07-15 20:08:37.524] INFO Adhearsion::PunchblockPlugin::Initializer: Connected to Punchblock server
[2014-07-15 20:08:37.553] INFO Adhearsion::Process: Transitioning from booting to running with 0 active calls due to booted event.
[2014-07-15 20:08:37.554] INFO Adhearsion::Initializer: Adhearsion v2.5.3 initialized in "production"!
[2014-07-15 20:09:17.485] TRACE Punchblock::Connection::Asterisk: [RECV] Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/200
PeerStatus: Unregistered
Cause: Expired
[2014-07-15 20:09:17.496] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="PeerStatus", headers={"Privilege"=>"system,all", "ChannelType"=>"SIP", "Peer"=>"SIP/200", "PeerStatus"=>"Unregistered", "Cause"=>"Expired"}, text_body=nil, events=[]>
[2014-07-15 20:09:31.847] TRACE Punchblock::Connection::Asterisk: [RECV] Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/200
PeerStatus: Registered
Address: 105.236.104.245:57827
[2014-07-15 20:09:31.848] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="PeerStatus", headers={"Privilege"=>"system,all", "ChannelType"=>"SIP", "Peer"=>"SIP/200", "PeerStatus"=>"Registered", "Address"=>"105.236.104.245:57827"}, text_body=nil, events=[]>
[2014-07-15 20:09:34.333] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Registry
Privilege: system,all
ChannelType: SIP
Username: 27876540893
Domain: 196.15.185.48
Status: Registered
[2014-07-15 20:09:34.334] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Registry", headers={"Privilege"=>"system,all", "ChannelType"=>"SIP", "Username"=>"27876540893", "Domain"=>"196.15.185.48", "Status"=>"Registered"}, text_body=nil, events=[]>
[2014-07-15 20:10:10.555] TRACE Punchblock::Connection::Asterisk: [RECV] Event: PeerStatus
Privilege: system,all
ChannelType: SIP
Peer: SIP/500
PeerStatus: Registered
Address: 41.76.201.166:2051
[2014-07-15 20:10:10.557] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="PeerStatus", headers={"Privilege"=>"system,all", "ChannelType"=>"SIP", "Peer"=>"SIP/500", "PeerStatus"=>"Registered", "Address"=>"41.76.201.166:2051"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.370] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Executing command #<Punchblock::Command::Dial target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:39 +0200, request_id="deffe10a-a9b5-46aa-8781-c4c64bc94c59", headers={}, to="SIP/200", from="123", uri="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", timeout=nil, join=nil>
[2014-07-15 20:10:39.430] TRACE Punchblock::Connection::Asterisk: [SEND] Action: originate
ActionID: 4d07a0a4-1fde-41f3-b02e-299d59030b46
Async: true
Context: adhearsion-redirect
Exten: 1
Priority: 1
Channel: SIP/200
Callerid: 123
Variable: punchblock_call_id=6c1918fc-8a45-4a8a-9c96-36e43fc279aa
[2014-07-15 20:10:39.432] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 4d07a0a4-1fde-41f3-b02e-299d59030b46
Message: Originate successfully queued
[2014-07-15 20:10:39.433] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"4d07a0a4-1fde-41f3-b02e-299d59030b46", "Message"=>"Originate successfully queued"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.438] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Channel: SIP/200-000000e5
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: 200
CallerIDName:
AccountCode:
Exten:
Context: from-internal
Uniqueid: 1405447839.273
[2014-07-15 20:10:39.439] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"200", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"from-internal", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.441] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: SIPCALLID
Value: 3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060
Uniqueid: 1405447839.273
[2014-07-15 20:10:39.447] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"SIPCALLID", "Value"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.448] TRACE Punchblock::Connection::Asterisk: [RECV] Event: ChannelUpdate
Privilege: system,all
Channel: SIP/200-000000e5
Uniqueid: 1405447839.273
Channeltype: SIP
SIPcallid: 3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060
SIPfullcontact: sip:200@105.236.104.245:57827;ob
Event: ChannelUpdate
Privilege: system,all
Channel: SIP/200-000000e5
Channeltype: SIP
SIPcallid: 3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060
SIPfullcontact: sip:200@105.236.104.245:57827;ob
Peername: 200
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: punchblock_call_id
Value: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa
Uniqueid: 1405447839.273
Event: NewAccountCode
Privilege: call,all
Channel: SIP/200-000000e5
Uniqueid: 1405447839.273
AccountCode:
OldAccountCode:
Event: NewCallerid
Privilege: call,all
Channel: SIP/200-000000e5
CallerIDNum: 123
CallerIDName:
Uniqueid: 1405447839.273
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[2014-07-15 20:10:39.464] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447839.273", "Channeltype"=>"SIP", "SIPcallid"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "SIPfullcontact"=>"sip:200@105.236.104.245:57827;ob"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.469] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/200-000000e5", "Channeltype"=>"SIP", "SIPcallid"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "SIPfullcontact"=>"sip:200@105.236.104.245:57827;ob", "Peername"=>"200"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.471] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"punchblock_call_id", "Value"=>"6c1918fc-8a45-4a8a-9c96-36e43fc279aa", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.472] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447839.273", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=[]>
[2014-07-15 20:10:39.495] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "CallerIDNum"=>"123", "CallerIDName"=>"", "Uniqueid"=>"1405447839.273", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=[]>
[2014-07-15 20:10:39.535] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:39 +0200, name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447839.273", "AccountCode"=>"", "OldAccountCode"=>""}>
[2014-07-15 20:10:39.540] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:39 +0200, name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "CallerIDNum"=>"123", "CallerIDName"=>"", "Uniqueid"=>"1405447839.273", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}>
[2014-07-15 20:10:39.544] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:39 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"punchblock_call_id", "Value"=>"6c1918fc-8a45-4a8a-9c96-36e43fc279aa", "Uniqueid"=>"1405447839.273"}>
[2014-07-15 20:10:45.802] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Channel: SIP/200-000000e5
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: 123
CallerIDName:
ConnectedLineNum: 123
ConnectedLineName:
Uniqueid: 1405447839.273
[2014-07-15 20:10:45.804] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "ChannelState"=>"5", "ChannelStateDesc"=>"Ringing", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:45.816] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:45 +0200, name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "ChannelState"=>"5", "ChannelStateDesc"=>"Ringing", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447839.273"}>
[2014-07-15 20:10:45.824] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Ringing target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:45 +0200, headers={}>
[2014-07-15 20:10:47.465] TRACE Punchblock::Connection::Asterisk: [RECV] Event: ChannelUpdate
Privilege: system,all
Channel: SIP/200-000000e5
Channeltype: SIP
Uniqueid: 1405447839.273
SIPcallid: 3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060
SIPfullcontact: sip:200@105.236.104.245:57827;ob
Peername: 200
[2014-07-15 20:10:47.466] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/200-000000e5", "Channeltype"=>"SIP", "Uniqueid"=>"1405447839.273", "SIPcallid"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "SIPfullcontact"=>"sip:200@105.236.104.245:57827;ob", "Peername"=>"200"}, text_body=nil, events=[]>
[2014-07-15 20:10:47.474] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Channel: SIP/200-000000e5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 123
CallerIDName:
ConnectedLineNum: 123
ConnectedLineName:
Uniqueid: 1405447839.273
Event: OriginateResponse
Privilege: call,all
ActionID: 4d07a0a4-1fde-41f3-b02e-299d59030b46
Response: Success
Channel: SIP/200-000000e5
Context: adhearsion-redirect
Exten: 1
Reason: 4
Uniqueid: 1405447839.273
CallerIDNum: 123
CallerIDName: <unknown>
[2014-07-15 20:10:47.475] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:47.476] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="OriginateResponse", headers={"Privilege"=>"call,all", "ActionID"=>"4d07a0a4-1fde-41f3-b02e-299d59030b46", "Response"=>"Success", "Channel"=>"SIP/200-000000e5", "Context"=>"adhearsion-redirect", "Exten"=>"1", "Reason"=>"4", "Uniqueid"=>"1405447839.273", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>"}, text_body=nil, events=[]>
[2014-07-15 20:10:47.480] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newexten
Privilege: dialplan,all
Channel: SIP/200-000000e5
Context: adhearsion-redirect
Extension: 1
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1405447839.273
Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: SIP/200-000000e5
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F200-000000e5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447839.273%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240724624%0A%0A
[2014-07-15 20:10:47.486] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:47 +0200, name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/200-000000e5", "Channeltype"=>"SIP", "Uniqueid"=>"1405447839.273", "SIPcallid"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "SIPfullcontact"=>"sip:200@105.236.104.245:57827;ob", "Peername"=>"200"}>
[2014-07-15 20:10:47.481] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Context"=>"adhearsion-redirect", "Extension"=>"1", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:47.491] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/200-000000e5", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F200-000000e5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447839.273%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240724624%0A%0A"}, text_body=nil, events=[]>
[2014-07-15 20:10:47.494] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:47 +0200, name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447839.273"}>
[2014-07-15 20:10:47.500] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:47 +0200, name="OriginateResponse", headers={"Privilege"=>"call,all", "ActionID"=>"4d07a0a4-1fde-41f3-b02e-299d59030b46", "Response"=>"Success", "Channel"=>"SIP/200-000000e5", "Context"=>"adhearsion-redirect", "Exten"=>"1", "Reason"=>"4", "Uniqueid"=>"1405447839.273", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>"}>
[2014-07-15 20:10:47.515] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:47 +0200, name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Context"=>"adhearsion-redirect", "Extension"=>"1", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1405447839.273"}>
[2014-07-15 20:10:47.520] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:47 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/200-000000e5", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F200-000000e5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447839.273%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240724624%0A%0A"}>
[2014-07-15 20:10:47.522] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Answered target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:47 +0200, headers={}>
[2014-07-15 20:10:47.545] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Executing controller #<ClickToCallController call=6c1918fc-8a45-4a8a-9c96-36e43fc279aa, metadata={:callee_num=>"SIP/Telejunction/0987654321", :extension=>"200", :call_ref=>"123traceLogging3", :outbound_id=>"123", :callee=>"0987654321"}>
[2014-07-15 20:10:48.161] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Executing command #<Punchblock::Component::Output target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, request_id="0a38bf86-d457-4ddb-9cb6-955fdd04c8d5", voice=nil, interrupt_on=nil, start_offset=nil, start_paused=nil, repeat_interval=nil, repeat_times=0, max_time=nil, renderer=nil, render_documents=[#<Punchblock::Component::Output::Document target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, url=nil, content_type="application/ssml+xml", value=<speak version="1.0" xml:lang="en-US" xmlns="http://www.w3.org/2001/10/synthesis">ring</speak>>]>
[2014-07-15 20:10:48.203] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: 90bcb719-04e6-471b-af0a-2e67fb9b7dcb
Channel: SIP/200-000000e5
Command: EXEC Playback "ring"
CommandID: 853ad9d8-7b24-4684-b714-bb90576035f6
[2014-07-15 20:10:48.204] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 90bcb719-04e6-471b-af0a-2e67fb9b7dcb
Message: Added AGI command to queue
[2014-07-15 20:10:48.204] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"90bcb719-04e6-471b-af0a-2e67fb9b7dcb", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.213] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Executing command #<Punchblock::Command::Dial target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, request_id="9717596d-5c5d-4e10-a4e5-9fab5f4c7f72", headers={}, to="SIP/Telejunction/0987654321", from="123", uri="4119bd7f-e193-410b-95d5-991dca1e2a28", timeout=nil, join=nil>
[2014-07-15 20:10:48.217] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: Start
Channel: SIP/200-000000e5
CommandId: 162390841
Command: EXEC Playback "ring"
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: PLAYBACKSTATUS
Value: FAILED
Uniqueid: 1405447839.273
Event: AGIExec
Privilege: agi,all
SubEvent: End
Channel: SIP/200-000000e5
CommandId: 162390841
Command: EXEC Playback "ring"
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
SubEvent: Exec
Channel: SIP/200-000000e5
CommandID: 853ad9d8-7b24-4684-b714-bb90576035f6
Result: 200%20result%3D0%0A
[2014-07-15 20:10:48.217] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/200-000000e5", "CommandId"=>"162390841", "Command"=>"EXEC Playback \"ring\""}, text_body=nil, events=[]>
[2014-07-15 20:10:48.218] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"PLAYBACKSTATUS", "Value"=>"FAILED", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.221] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/200-000000e5", "CommandId"=>"162390841", "Command"=>"EXEC Playback \"ring\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.225] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/200-000000e5", "CommandID"=>"853ad9d8-7b24-4684-b714-bb90576035f6", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.242] TRACE Punchblock::Connection::Asterisk: [SEND] Action: originate
ActionID: 559d813b-9ead-4018-9e6d-bb6a1692db39
Async: true
Context: adhearsion-redirect
Exten: 1
Priority: 1
Channel: SIP/Telejunction/0987654321
Callerid: 123
Variable: punchblock_call_id=4119bd7f-e193-410b-95d5-991dca1e2a28
[2014-07-15 20:10:48.243] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 559d813b-9ead-4018-9e6d-bb6a1692db39
Message: Originate successfully queued
[2014-07-15 20:10:48.244] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"559d813b-9ead-4018-9e6d-bb6a1692db39", "Message"=>"Originate successfully queued"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.251] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newchannel
Privilege: call,all
Channel: SIP/Telejunction-000000e6
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten:
Context: from-trunk-sip-Telejunction
Uniqueid: 1405447848.274
[2014-07-15 20:10:48.252] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"from-trunk-sip-Telejunction", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.254] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: SIPCALLID
Value: 677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060
Uniqueid: 1405447848.274
[2014-07-15 20:10:48.254] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"SIPCALLID", "Value"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.258] TRACE Punchblock::Connection::Asterisk: [RECV] Event: ChannelUpdate
Privilege: system,all
Channel: SIP/Telejunction-000000e6
Uniqueid: 1405447848.274
Channeltype: SIP
SIPcallid: 677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060
SIPfullcontact:
Event: ChannelUpdate
Privilege: system,all
Channel: SIP/Telejunction-000000e6
Channeltype: SIP
SIPcallid: 677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060
SIPfullcontact:
Peername: Telejunction
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: punchblock_call_id
Value: 4119bd7f-e193-410b-95d5-991dca1e2a28
Uniqueid: 1405447848.274
Event: NewAccountCode
Privilege: call,all
Channel: SIP/Telejunction-000000e6
Uniqueid: 1405447848.274
AccountCode:
OldAccountCode:
Event: NewCallerid
Privilege: call,all
Channel: SIP/Telejunction-000000e6
CallerIDNum: 123
CallerIDName:
Uniqueid: 1405447848.274
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
[2014-07-15 20:10:48.261] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "Channeltype"=>"SIP", "SIPcallid"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "SIPfullcontact"=>""}, text_body=nil, events=[]>
[2014-07-15 20:10:48.286] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/200-000000e5", "CommandId"=>"162390841", "Command"=>"EXEC Playback \"ring\""}>
[2014-07-15 20:10:48.266] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/Telejunction-000000e6", "Channeltype"=>"SIP", "SIPcallid"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "SIPfullcontact"=>"", "Peername"=>"Telejunction"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.295] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"punchblock_call_id", "Value"=>"4119bd7f-e193-410b-95d5-991dca1e2a28", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.297] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"PLAYBACKSTATUS", "Value"=>"FAILED", "Uniqueid"=>"1405447839.273"}>
[2014-07-15 20:10:48.299] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=[]>
[2014-07-15 20:10:48.300] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "CallerIDNum"=>"123", "CallerIDName"=>"", "Uniqueid"=>"1405447848.274", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=[]>
[2014-07-15 20:10:48.310] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/200-000000e5", "CommandId"=>"162390841", "Command"=>"EXEC Playback \"ring\"", "ResultCode"=>"200", "Result"=>"Success"}>
[2014-07-15 20:10:48.321] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/200-000000e5", "CommandID"=>"853ad9d8-7b24-4684-b714-bb90576035f6", "Result"=>"200%20result%3D0%0A"}>
[2014-07-15 20:10:48.346] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"punchblock_call_id", "Value"=>"4119bd7f-e193-410b-95d5-991dca1e2a28", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:48.349] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "AccountCode"=>"", "OldAccountCode"=>""}>
[2014-07-15 20:10:48.353] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "CallerIDNum"=>"123", "CallerIDName"=>"", "Uniqueid"=>"1405447848.274", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}>
[2014-07-15 20:10:48.342] ERROR Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: <Punchblock::Event::Complete> #<Punchblock::Event::Complete target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id="f5d9e16a-3547-4393-96ae-6bec5a4dee6c", source_uri="f5d9e16a-3547-4393-96ae-6bec5a4dee6c", domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, reason=#<Punchblock::Event::Complete::Error target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name=:error, details="Terminated due to playback error">, recording=nil, fax=nil, fax_metadata={}>
[2014-07-15 20:10:48.360] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Complete target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id="f5d9e16a-3547-4393-96ae-6bec5a4dee6c", source_uri="f5d9e16a-3547-4393-96ae-6bec5a4dee6c", domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, reason=#<Punchblock::Event::Complete::Error target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:48 +0200, name=:error, details="Terminated due to playback error">, recording=nil, fax=nil, fax_metadata={}>
[2014-07-15 20:10:52.472] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newstate
Privilege: call,all
Channel: SIP/Telejunction-000000e6
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: 123
CallerIDName:
ConnectedLineNum: 123
ConnectedLineName:
Uniqueid: 1405447848.274
[2014-07-15 20:10:52.473] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "ChannelState"=>"5", "ChannelStateDesc"=>"Ringing", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:52.485] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:52 +0200, name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "ChannelState"=>"5", "ChannelStateDesc"=>"Ringing", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:52.491] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Ringing target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:52 +0200, headers={}>
[2014-07-15 20:10:54.362] TRACE Punchblock::Connection::Asterisk: [RECV] Event: ChannelUpdate
Privilege: system,all
Channel: SIP/Telejunction-000000e6
Channeltype: SIP
Uniqueid: 1405447848.274
SIPcallid: 677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060
SIPfullcontact: sip:196.15.185.48:5061
Peername: Telejunction
Event: Newstate
Privilege: call,all
Channel: SIP/Telejunction-000000e6
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: 123
CallerIDName:
ConnectedLineNum: 123
ConnectedLineName:
Uniqueid: 1405447848.274
Event: OriginateResponse
Privilege: call,all
ActionID: 559d813b-9ead-4018-9e6d-bb6a1692db39
Response: Success
Channel: SIP/Telejunction-000000e6
Context: adhearsion-redirect
Exten: 1
Reason: 4
Uniqueid: 1405447848.274
CallerIDNum: 123
CallerIDName: <unknown>
[2014-07-15 20:10:54.364] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/Telejunction-000000e6", "Channeltype"=>"SIP", "Uniqueid"=>"1405447848.274", "SIPcallid"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "SIPfullcontact"=>"sip:196.15.185.48:5061", "Peername"=>"Telejunction"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.368] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.369] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="OriginateResponse", headers={"Privilege"=>"call,all", "ActionID"=>"559d813b-9ead-4018-9e6d-bb6a1692db39", "Response"=>"Success", "Channel"=>"SIP/Telejunction-000000e6", "Context"=>"adhearsion-redirect", "Exten"=>"1", "Reason"=>"4", "Uniqueid"=>"1405447848.274", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.377] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="ChannelUpdate", headers={"Privilege"=>"system,all", "Channel"=>"SIP/Telejunction-000000e6", "Channeltype"=>"SIP", "Uniqueid"=>"1405447848.274", "SIPcallid"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "SIPfullcontact"=>"sip:196.15.185.48:5061", "Peername"=>"Telejunction"}>
[2014-07-15 20:10:54.382] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"123", "CallerIDName"=>"", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:54.384] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="OriginateResponse", headers={"Privilege"=>"call,all", "ActionID"=>"559d813b-9ead-4018-9e6d-bb6a1692db39", "Response"=>"Success", "Channel"=>"SIP/Telejunction-000000e6", "Context"=>"adhearsion-redirect", "Exten"=>"1", "Reason"=>"4", "Uniqueid"=>"1405447848.274", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>"}>
[2014-07-15 20:10:54.386] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newexten
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Context: adhearsion-redirect
Extension: 1
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1405447848.274
Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: SIP/Telejunction-000000e6
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2FTelejunction-000000e6%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447848.274%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240970384%0A%0A
[2014-07-15 20:10:54.387] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Context"=>"adhearsion-redirect", "Extension"=>"1", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.392] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Context"=>"adhearsion-redirect", "Extension"=>"1", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:54.393] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/Telejunction-000000e6", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2FTelejunction-000000e6%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447848.274%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240970384%0A%0A"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.398] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/Telejunction-000000e6", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2FTelejunction-000000e6%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447848.274%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240970384%0A%0A"}>
[2014-07-15 20:10:54.411] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Answered target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, headers={}>
[2014-07-15 20:10:54.422] INFO Adhearsion::CallController::Dial::Dial: 4488a07b-8954-4553-91f3-ad424ee8a191: #dial joining call 4119bd7f-e193-410b-95d5-991dca1e2a28 to 6c1918fc-8a45-4a8a-9c96-36e43fc279aa
[2014-07-15 20:10:54.432] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Joining to #<Celluloid::ActorProxy:0x6db9f5>
[2014-07-15 20:10:54.456] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Executing command #<Punchblock::Command::Join target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, request_id="037a36f8-260c-4cde-b906-802983670027", call_uri="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", mixer_name=nil, direction=nil, media=nil>
[2014-07-15 20:10:54.475] TRACE Punchblock::Connection::Asterisk: [SEND] Action: agi
ActionID: a545daf9-e264-48ef-8549-fb47af56c90d
Channel: SIP/Telejunction-000000e6
Command: EXEC Bridge "SIP/200-000000e5,F(adhearsion-redirect,1,1)"
CommandID: 6c032c9d-f410-4846-af14-883588c53021
[2014-07-15 20:10:54.477] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: a545daf9-e264-48ef-8549-fb47af56c90d
Message: Added AGI command to queue
[2014-07-15 20:10:54.486] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"a545daf9-e264-48ef-8549-fb47af56c90d", "Message"=>"Added AGI command to queue"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.553] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: Start
Channel: SIP/Telejunction-000000e6
CommandId: 1742475957
Command: EXEC Bridge "SIP/200-000000e5,F(adhearsion-redirect,1,1)"
Event: Newchannel
Privilege: call,all
Channel: Bridge/SIP/200-000000e5
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten:
Context:
Uniqueid: 1405447854.275
Event: MusicOnHold
Privilege: call,all
State: Stop
Channel: SIP/200-000000e5
UniqueID: 1405447839.273
Event: Newstate
Privilege: call,all
Channel: Bridge/SIP/200-000000e5
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum:
CallerIDName:
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1405447854.275
Event: Masquerade
Privilege: call,all
Clone: SIP/200-000000e5
CloneState: Up
Original: Bridge/SIP/200-000000e5
OriginalState: Up
Event: Rename
Privilege: call,all
Channel: SIP/200-000000e5
Newname: SIP/200-000000e5<MASQ>
Uniqueid: 1405447839.273
Event: Rename
Privilege: call,all
Channel: Bridge/SIP/200-000000e5
Newname: SIP/200-000000e5
Uniqueid: 1405447854.275
Event: Rename
Privilege: call,all
Channel: SIP/200-000000e5<MASQ>
Newname: Bridge/SIP/200-000000e5<ZOMBIE>
Uniqueid: 1405447839.273
Event: NewCallerid
Privilege: call,all
Channel: SIP/200-000000e5
CallerIDNum: 123
CallerIDName:
Uniqueid: 1405447854.275
CID-CallingPres: 0 (Presentation Allowed, Not Screened)
Event: BridgeExec
Privilege: call,all
Response: Success
Channel1: SIP/Telejunction-000000e6
Channel2: SIP/200-000000e5
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: BRIDGEPEER
Value: SIP/200-000000e5
Uniqueid: 1405447848.274
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: BRIDGEPEER
Value: SIP/Telejunction-000000e6
Uniqueid: 1405447854.275
Event: NewAccountCode
Privilege: call,all
Channel: SIP/200-000000e5
Uniqueid: 1405447854.275
AccountCode:
OldAccountCode:
Event: Bridge
Privilege: call,all
Bridgestate: Link
Bridgetype: core
Channel1: SIP/Telejunction-000000e6
Channel2: SIP/200-000000e5
Uniqueid1: 1405447848.274
Uniqueid2: 1405447854.275
CallerID1: 123
CallerID2: 123
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: BRIDGEPEER
Value: SIP/200-000000e5
Uniqueid: 1405447848.274
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: BRIDGEPVTCALLID
Value: 3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060
Uniqueid: 1405447848.274
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: BRIDGEPEER
Value: SIP/Telejunction-000000e6
Uniqueid: 1405447854.275
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: BRIDGEPVTCALLID
Value: 677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060
Uniqueid: 1405447854.275
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: BRIDGEPEER
Value: SIP/200-000000e5
Uniqueid: 1405447848.274
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: BRIDGEPVTCALLID
Value: 3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060
Uniqueid: 1405447848.274
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: BRIDGEPEER
Value: SIP/Telejunction-000000e6
Uniqueid: 1405447854.275
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: BRIDGEPVTCALLID
Value: 677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060
Uniqueid: 1405447854.275
Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: Bridge/SIP/200-000000e5<ZOMBIE>
Event: VarSet
Privilege: dialplan,all
Channel: Bridge/SIP/200-000000e5<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1405447839.273
Event: SoftHangupRequest
Privilege: call,all
Channel: Bridge/SIP/200-000000e5<ZOMBIE>
Uniqueid: 1405447839.273
Cause: 16
Event: Hangup
Privilege: call,all
Channel: Bridge/SIP/200-000000e5<ZOMBIE>
Uniqueid: 1405447839.273
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineN
[2014-07-15 20:10:54.555] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/Telejunction-000000e6", "CommandId"=>"1742475957", "Command"=>"EXEC Bridge \"SIP/200-000000e5,F(adhearsion-redirect,1,1)\""}, text_body=nil, events=[]>
[2014-07-15 20:10:54.569] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/200-000000e5", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.570] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="MusicOnHold", headers={"Privilege"=>"call,all", "State"=>"Stop", "Channel"=>"SIP/200-000000e5", "UniqueID"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.575] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="MusicOnHold", headers={"Privilege"=>"call,all", "State"=>"Stop", "Channel"=>"SIP/200-000000e5", "UniqueID"=>"1405447839.273"}>
[2014-07-15 20:10:54.577] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/200-000000e5", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.578] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Masquerade", headers={"Privilege"=>"call,all", "Clone"=>"SIP/200-000000e5", "CloneState"=>"Up", "Original"=>"Bridge/SIP/200-000000e5", "OriginalState"=>"Up"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.587] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Newname"=>"SIP/200-000000e5<MASQ>", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.589] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/200-000000e5", "Newname"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.594] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Newname"=>"SIP/200-000000e5<MASQ>", "Uniqueid"=>"1405447839.273"}>
[2014-07-15 20:10:54.599] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5<MASQ>", "Newname"=>"Bridge/SIP/200-000000e5<ZOMBIE>", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.619] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/Telejunction-000000e6", "CommandId"=>"1742475957", "Command"=>"EXEC Bridge \"SIP/200-000000e5,F(adhearsion-redirect,1,1)\""}>
[2014-07-15 20:10:54.635] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "CallerIDNum"=>"123", "CallerIDName"=>"", "Uniqueid"=>"1405447854.275", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.662] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "CallerIDNum"=>"123", "CallerIDName"=>"", "Uniqueid"=>"1405447854.275", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}>
[2014-07-15 20:10:54.663] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="BridgeExec", headers={"Privilege"=>"call,all", "Response"=>"Success", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.664] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/200-000000e5", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.688] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="BridgeExec", headers={"Privilege"=>"call,all", "Response"=>"Success", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5"}>
[2014-07-15 20:10:54.696] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.697] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=[]>
[2014-07-15 20:10:54.702] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5", "Uniqueid1"=>"1405447848.274", "Uniqueid2"=>"1405447854.275", "CallerID1"=>"123", "CallerID2"=>"123"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.703] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/200-000000e5", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.704] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.723] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/200-000000e5", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:54.716] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.761] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="BridgeExec", headers={"Privilege"=>"call,all", "Response"=>"Success", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5"}>
[2014-07-15 20:10:54.773] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:54.794] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:54.777] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5", "Uniqueid1"=>"1405447848.274", "Uniqueid2"=>"1405447854.275", "CallerID1"=>"123", "CallerID2"=>"123"}>
[2014-07-15 20:10:55.071] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275", "AccountCode"=>"", "OldAccountCode"=>""}>
[2014-07-15 20:10:54.839] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/200-000000e5", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.076] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.077] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.078] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:55.092] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.093] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/200-000000e5<ZOMBIE>"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.093] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/200-000000e5<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1405447839.273"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.100] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/200-000000e5", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:55.101] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Joined target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, call_uri="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", mixer_name=nil>
[2014-07-15 20:10:55.102] INFO Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Joined to call 6c1918fc-8a45-4a8a-9c96-36e43fc279aa
[2014-07-15 20:10:55.103] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:55.116] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:55.117] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5", "Uniqueid1"=>"1405447848.274", "Uniqueid2"=>"1405447854.275", "CallerID1"=>"123", "CallerID2"=>"123"}>
[2014-07-15 20:10:55.118] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Joined target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:54 +0200, call_uri="4119bd7f-e193-410b-95d5-991dca1e2a28", mixer_name=nil>
[2014-07-15 20:10:55.120] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Joined to call 4119bd7f-e193-410b-95d5-991dca1e2a28
[2014-07-15 20:10:55.125] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/200-000000e5<ZOMBIE>", "Uniqueid"=>"1405447839.273", "Cause"=>"16"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.125] TRACE Punchblock::Connection::Asterisk: [RECV] um: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 16
Cause-txt: Normal Clearing
[2014-07-15 20:10:55.134] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/200-000000e5<ZOMBIE>", "Uniqueid"=>"1405447839.273", "CallerIDNum"=>"<unknown>", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.141] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/200-000000e5", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:55.142] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"3b6a7ef772dbc3500c220d7e0079a34d@123.123.123.123:5060", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:10:55.189] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:55.196] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"677a8b933d92eb291b0657fe2b17a582@123.123.123.123:5060", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:55.197] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/200-000000e5<ZOMBIE>"}>
[2014-07-15 20:10:55.199] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Executing command #<Punchblock::Component::Record target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, request_id="8ccb2f9f-c46f-406e-beed-9e9c5607d5af", format=nil, initial_timeout=nil, final_timeout=nil, max_duration=nil, start_beep=nil, stop_beep=nil, start_paused=nil, direction=nil, mix=nil>
[2014-07-15 20:10:55.230] TRACE Punchblock::Connection::Asterisk: [SEND] Action: monitor
ActionID: 24ba1e7e-45c3-478f-af78-b473dd3aad1a
Channel: SIP/200-000000e5
File: /var/punchblock/record/fd768bdb-af09-4865-8ad4-3a61f98aaf41
Format: wav
Mix: true
[2014-07-15 20:10:55.232] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 24ba1e7e-45c3-478f-af78-b473dd3aad1a
Message: Started monitoring channel
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: __MONITORED
Value: true
Uniqueid: 1405447854.275
Event: MonitorStart
Privilege: call,all
Channel: SIP/200-000000e5
Uniqueid: 1405447854.275
[2014-07-15 20:10:55.233] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"24ba1e7e-45c3-478f-af78-b473dd3aad1a", "Message"=>"Started monitoring channel"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.235] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"__MONITORED", "Value"=>"true", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.236] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="MonitorStart", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:10:55.265] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"__MONITORED", "Value"=>"true", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:55.268] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:10:55 +0200, name="MonitorStart", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:10:56.624] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been created ---- /var/punchblock/record/fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav
[2014-07-15 20:10:56.624] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been created ---- /var/punchblock/record/fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav
[2014-07-15 20:10:58.122] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been updated
[2014-07-15 20:10:58.123] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been updated
[2014-07-15 20:10:59.621] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been updated
[2014-07-15 20:10:59.622] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been updated
[2014-07-15 20:11:02.622] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been updated
[2014-07-15 20:11:02.623] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been updated
[2014-07-15 20:11:04.123] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been updated
[2014-07-15 20:11:04.123] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been updated
[2014-07-15 20:11:05.621] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been updated
[2014-07-15 20:11:05.621] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been updated
[2014-07-15 20:11:08.621] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been updated
[2014-07-15 20:11:08.622] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been updated
[2014-07-15 20:11:08.940] TRACE Punchblock::Connection::Asterisk: [RECV] Event: HangupRequest
Privilege: call,all
Channel: SIP/Telejunction-000000e6
Uniqueid: 1405447848.274
[2014-07-15 20:11:08.941] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="HangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:11:08.947] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, name="HangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:11:08.952] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Bridge
Privilege: call,all
Bridgestate: Unlink
Bridgetype: core
Channel1: SIP/Telejunction-000000e6
Channel2: SIP/200-000000e5
Uniqueid1: 1405447848.274
Uniqueid2: 1405447854.275
CallerID1: 123
CallerID2: 123
[2014-07-15 20:11:08.953] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5", "Uniqueid1"=>"1405447848.274", "Uniqueid2"=>"1405447854.275", "CallerID1"=>"123", "CallerID2"=>"123"}, text_body=nil, events=[]>
[2014-07-15 20:11:08.958] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5", "Uniqueid1"=>"1405447848.274", "Uniqueid2"=>"1405447854.275", "CallerID1"=>"123", "CallerID2"=>"123"}>
[2014-07-15 20:11:08.964] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Unjoined target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, call_uri="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", mixer_name=nil>
[2014-07-15 20:11:08.964] INFO Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Unjoined from call 6c1918fc-8a45-4a8a-9c96-36e43fc279aa
[2014-07-15 20:11:08.967] TRACE Punchblock::Connection::Asterisk: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: BRIDGERESULT
Value: SUCCESS
Uniqueid: 1405447848.274
Event: AGIExec
Privilege: agi,all
SubEvent: End
Channel: SIP/Telejunction-000000e6
CommandId: 1742475957
Command: EXEC Bridge "SIP/200-000000e5,F(adhearsion-redirect,1,1)"
ResultCode: 200
Result: Success
Event: AsyncAGI
Privilege: agi,all
SubEvent: Exec
Channel: SIP/Telejunction-000000e6
CommandID: 6c032c9d-f410-4846-af14-883588c53021
Result: 200%20result%3D0%0A
Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: SIP/Telejunction-000000e6
Event: VarSet
Privilege: dialplan,all
Channel: SIP/Telejunction-000000e6
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1405447848.274
Event: SoftHangupRequest
Privilege: call,all
Channel: SIP/Telejunction-000000e6
Uniqueid: 1405447848.274
Cause: 16
Event: Hangup
Privilege: call,all
Channel: SIP/Telejunction-000000e6
Uniqueid: 1405447848.274
CallerIDNum: 123
CallerIDName: <unknown>
ConnectedLineNum: 123
ConnectedLineName: <unknown>
AccountCode:
Cause: 16
Cause-txt: Normal Clearing
[2014-07-15 20:11:08.967] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:11:08.986] DEBUG Adhearsion::CallController::Dial::Dial: 4488a07b-8954-4553-91f3-ad424ee8a191: Main calls were completed, waiting for any added calls: [#<CountDownLatch:0x64c4c1 @mutex=#<Mutex:0x1b15b1a>, @count=0, @conditional=#<ConditionVariable:0xd434f0>>]
[2014-07-15 20:11:08.998] DEBUG Adhearsion::CallController::Dial::Dial: 4488a07b-8954-4553-91f3-ad424ee8a191: All calls were completed, unblocking.
[2014-07-15 20:11:08.992] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/Telejunction-000000e6", "Channel2"=>"SIP/200-000000e5", "Uniqueid1"=>"1405447848.274", "Uniqueid2"=>"1405447854.275", "CallerID1"=>"123", "CallerID2"=>"123"}>
[2014-07-15 20:11:08.994] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:11:09.000] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/Telejunction-000000e6", "CommandId"=>"1742475957", "Command"=>"EXEC Bridge \"SIP/200-000000e5,F(adhearsion-redirect,1,1)\"", "ResultCode"=>"200", "Result"=>"Success"}>
[2014-07-15 20:11:09.002] INFO Adhearsion::CallController::Dial::Dial: 4488a07b-8954-4553-91f3-ad424ee8a191: #dial finished. Hanging up 1 outbound calls which are still active: 4119bd7f-e193-410b-95d5-991dca1e2a28.
[2014-07-15 20:11:08.968] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/Telejunction-000000e6", "CommandId"=>"1742475957", "Command"=>"EXEC Bridge \"SIP/200-000000e5,F(adhearsion-redirect,1,1)\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=[]>
[2014-07-15 20:11:08.968] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/Telejunction-000000e6", "CommandID"=>"6c032c9d-f410-4846-af14-883588c53021", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.003] INFO Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Hanging up
[2014-07-15 20:11:09.005] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/Telejunction-000000e6"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.006] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1405447848.274"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.006] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "Cause"=>"16"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.009] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Unjoined target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:08 +0200, call_uri="4119bd7f-e193-410b-95d5-991dca1e2a28", mixer_name=nil>
[2014-07-15 20:11:09.026] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Executing command #<Punchblock::Command::Hangup target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, request_id="a62cb5ba-efb8-455d-8840-ba9d83190cb6", headers={}>
[2014-07-15 20:11:09.009] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Unjoined from call 4119bd7f-e193-410b-95d5-991dca1e2a28
[2014-07-15 20:11:09.031] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.032] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/Telejunction-000000e6", "CommandID"=>"6c032c9d-f410-4846-af14-883588c53021", "Result"=>"200%20result%3D0%0A"}>
[2014-07-15 20:11:09.033] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/Telejunction-000000e6", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1405447848.274"}>
[2014-07-15 20:11:09.034] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/Telejunction-000000e6"}>
[2014-07-15 20:11:09.036] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "Cause"=>"16"}>
[2014-07-15 20:11:09.040] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Newexten
Privilege: dialplan,all
Channel: SIP/200-000000e5
Context: adhearsion-redirect
Extension: 1
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1405447854.275
[2014-07-15 20:11:09.041] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Context"=>"adhearsion-redirect", "Extension"=>"1", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.046] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/Telejunction-000000e6", "Uniqueid"=>"1405447848.274", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}>
[2014-07-15 20:11:09.051] DEBUG Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Receiving message: #<Punchblock::Event::End target_call_id="4119bd7f-e193-410b-95d5-991dca1e2a28", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, headers={}, reason=:hungup, platform_code="16">
[2014-07-15 20:11:09.051] INFO Adhearsion::OutboundCall: 4119bd7f-e193-410b-95d5-991dca1e2a28@: Call ended due to hungup
[2014-07-15 20:11:09.057] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Context"=>"adhearsion-redirect", "Extension"=>"1", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:11:09.062] TRACE Punchblock::Connection::Asterisk: [SEND] Action: hangup
ActionID: 1e778515-9a2f-45b6-b4cf-c4292e7bd25c
Channel: SIP/Telejunction-000000e6
Cause: 16
[2014-07-15 20:11:09.069] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Error
ActionID: 1e778515-9a2f-45b6-b4cf-c4292e7bd25c
Message: No such channel
[2014-07-15 20:11:09.071] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Error message="No such channel", headers=>
[2014-07-15 20:11:09.083] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Hanging up
[2014-07-15 20:11:09.087] TRACE Punchblock::Connection::Asterisk: [SEND] Action: stopmonitor
ActionID: 3b031d15-4c1f-4504-bec9-7fdbf6b631ea
Channel: SIP/200-000000e5
[2014-07-15 20:11:09.093] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Executing command #<Punchblock::Command::Hangup target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, request_id="7eeb533b-37c8-42e9-9b92-f76eaaf85b08", headers={}>
[2014-07-15 20:11:09.101] TRACE Punchblock::Connection::Asterisk: [SEND] Action: hangup
ActionID: 846a2a1d-e2dd-4327-83ff-2be793c36f61
Channel: SIP/200-000000e5
Cause: 16
[2014-07-15 20:11:09.132] TRACE Punchblock::Connection::Asterisk: [RECV] Response: Success
ActionID: 3b031d15-4c1f-4504-bec9-7fdbf6b631ea
Message: Stopped monitoring channel
Event: MonitorStop
Privilege: call,all
Channel: SIP/200-000000e5
Uniqueid: 1405447854.275
Response: Success
ActionID: 846a2a1d-e2dd-4327-83ff-2be793c36f61
Message: Channel Hungup
[2014-07-15 20:11:09.132] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"3b031d15-4c1f-4504-bec9-7fdbf6b631ea", "Message"=>"Stopped monitoring channel"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.134] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="MonitorStop", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.141] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="MonitorStop", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:11:09.142] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Response headers={"ActionID"=>"846a2a1d-e2dd-4327-83ff-2be793c36f61", "Message"=>"Channel Hungup"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.143] TRACE Punchblock::Connection::Asterisk: [RECV] Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: SIP/200-000000e5
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F200-000000e5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447854.275%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240724624%0A%0A
Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: SIP/200-000000e5
Event: VarSet
Privilege: dialplan,all
Channel: SIP/200-000000e5
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1405447854.275
Event: SoftHangupRequest
Privilege: call,all
Channel: SIP/200-000000e5
Uniqueid: 1405447854.275
Cause: 16
Event: Hangup
Privilege: call,all
Channel: SIP/200-000000e5
Uniqueid: 1405447854.275
CallerIDNum: 123
CallerIDName: <unknown>
ConnectedLineNum: 123
ConnectedLineName: <unknown>
AccountCode:
Cause: 16
Cause-txt: Normal Clearing
[2014-07-15 20:11:09.146] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/200-000000e5", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F200-000000e5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447854.275%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240724624%0A%0A"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.146] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/200-000000e5"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.147] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1405447854.275"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.148] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275", "Cause"=>"16"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.159] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/200-000000e5", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2F200-000000e5%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201405447854.275%0Aagi_version%3A%2011.5.1%0Aagi_callerid%3A%20123%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion-redirect%0Aagi_extension%3A%201%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%20-1240724624%0A%0A"}>
[2014-07-15 20:11:09.161] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/200-000000e5"}>
[2014-07-15 20:11:09.163] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=[]>
[2014-07-15 20:11:09.166] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/200-000000e5", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1405447854.275"}>
[2014-07-15 20:11:09.170] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275", "Cause"=>"16"}>
[2014-07-15 20:11:09.180] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Call was hung up while executing a controller
[2014-07-15 20:11:09.181] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/200-000000e5", "Uniqueid"=>"1405447854.275", "CallerIDNum"=>"123", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"123", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}>
[2014-07-15 20:11:09.183] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Receiving message: #<Punchblock::Event::End target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, headers={}, reason=:hangup_command, platform_code="16">
[2014-07-15 20:11:09.184] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Call ended due to hangup_command
[2014-07-15 20:11:09.185] DEBUG Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: Finished executing controller #<ClickToCallController call=6c1918fc-8a45-4a8a-9c96-36e43fc279aa, metadata={:callee_num=>"SIP/Telejunction/0987654321", :extension=>"200", :call_ref=>"123traceLogging3", :outbound_id=>"123", :callee=>"0987654321"}>
[2014-07-15 20:11:09.189] INFO Adhearsion::Router::Route: Call 6c1918fc-8a45-4a8a-9c96-36e43fc279aa routing completed. Hanging up now.
[2014-07-15 20:11:09.191] INFO Adhearsion::OutboundCall: 6c1918fc-8a45-4a8a-9c96-36e43fc279aa@: CALL HAS ENDED - THIS IS ON_END METHOD
[2014-07-15 20:11:09.192] DEBUG Adhearsion::CallController::Dial::Dial: 4488a07b-8954-4553-91f3-ad424ee8a191: Root call ended, unblocking connected calls
[2014-07-15 20:11:10.122] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-out.wav has been deleted
[2014-07-15 20:11:10.123] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41-in.wav has been deleted
[2014-07-15 20:11:10.126] DEBUG FSSM::Path: File fd768bdb-af09-4865-8ad4-3a61f98aaf41.wav has been created ---- /var/punchblock/record/fd768bdb-af09-4865-8ad4-3a61f98aaf41.wav
[2014-07-15 20:11:10.129] INFO RecordingManager: Starting recoding file manager
[2014-07-15 20:11:11.158] INFO ClickToCallController: CALL RECORDING IS COMPLETED: file:///var/punchblock/record/fd768bdb-af09-4865-8ad4-3a61f98aaf41.wav
[2014-07-15 20:11:11.160] WARN Adhearsion::PunchblockPlugin::Initializer: Event received for inactive call 6c1918fc-8a45-4a8a-9c96-36e43fc279aa: #<Punchblock::Event::Complete target_call_id="6c1918fc-8a45-4a8a-9c96-36e43fc279aa", target_mixer_name=nil, component_id="fd768bdb-af09-4865-8ad4-3a61f98aaf41", source_uri="fd768bdb-af09-4865-8ad4-3a61f98aaf41", domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, reason=#<Punchblock::Component::Record::Complete::MaxDuration target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, name=:"max-duration">, recording=#<Punchblock::Component::Record::Recording target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Tue, 15 Jul 2014 20:11:09 +0200, uri="file:///var/punchblock/record/fd768bdb-af09-4865-8ad4-3a61f98aaf41.wav", duration=nil, size=nil>, fax=nil, fax_metadata={}>
[2014-07-15 20:11:19.381] TRACE Punchblock::Connection::Asterisk: [RECV] Event: Registry
Privilege: system,all
ChannelType: SIP
Username: 27876540893
Domain: 196.15.185.48
Status: Registered
[2014-07-15 20:11:19.382] TRACE Punchblock::Connection::Asterisk: [RECV] #<RubyAMI::Event name="Registry", headers={"Privilege"=>"system,all", "ChannelType"=>"SIP", "Username"=>"27876540893", "Domain"=>"196.15.185.48", "Status"=>"Registered"}, text_body=nil, events=[]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment