gersmann/gist:f51a5f71d73e931d09c2 Secret

## gistfile1.txt
Last login: Sun Apr 21 23:56:47 on ttys004
MacDose:~ gersmann$ cd Workspaces/ahn-test2/
MacDose:ahn-test2 gersmann$ ahn start
Starting Adhearsion server at /Users/gersmann/Workspaces/ahn-test2
[2013-04-22 09:48:43] TRACE Adhearsion::Initializer: OS: darwin12.3.0 - RUBY: ruby 2.0.0
[2013-04-22 09:48:43] TRACE Adhearsion::Initializer: Environment: {"rvm_bin_path"=>"/Users/gersmann/.rvm/bin", "TERM_PROGRAM"=>"iTerm.app", "GEM_HOME"=>"/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger", "rvm_error_clr"=>"\e[31m", "TERM"=>"xterm-256color", "SHELL"=>"/bin/bash", "rvm_notify_clr"=>"\e[32m", "IRBRC"=>"/Users/gersmann/.rvm/rubies/ruby-2.0.0-p0/.irbrc", "TMPDIR"=>"/var/folders/6l/97s6xzp94_z264n3666ryhpw0000gn/T/", "Apple_PubSub_Socket_Render"=>"/tmp/launch-jHaQ5D/Render", "OLDPWD"=>"/Users/gersmann", "MY_RUBY_HOME"=>"/Users/gersmann/.rvm/rubies/ruby-2.0.0-p0", "USER"=>"gersmann", "COMMAND_MODE"=>"unix2003", "__array_start"=>"0", "rvm_reset_clr"=>"\e(B\e[m", "rvm_path"=>"/Users/gersmann/.rvm", "SSH_AUTH_SOCK"=>"/tmp/launch-xclPGQ/Listeners", "__CF_USER_TEXT_ENCODING"=>"0x1F5:0:3", "Apple_Ubiquity_Message"=>"/tmp/launch-bvMD6z/Apple_Ubiquity_Message", "rvm_sticky_flag"=>"1", "escape_flag"=>"1", "rvm_prefix"=>"/Users/gersmann", "PATH"=>"/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/bin:/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@global/bin:/Users/gersmann/.rvm/rubies/ruby-2.0.0-p0/bin:/Users/gersmann/.rvm/bin:/opt/local/bin:/opt/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin", "PWD"=>"/Users/gersmann/Workspaces/ahn-test2", "LANG"=>"de_DE.UTF-8", "ITERM_PROFILE"=>"Default", "_second"=>"1", "rvm_version"=>"1.19.1 (stable)", "rvm_debug_clr"=>"\e[35m", "SHLVL"=>"1", "COLORFGBG"=>"7;0", "HOME"=>"/Users/gersmann", "TAUTH"=>"1afaf62b63827d78c1eab3f0ed37c5cf", "rvm_ruby_string"=>"ruby-2.0.0-p0", "ITERM_SESSION_ID"=>"w0t0p0", "_first"=>"0", "LOGNAME"=>"gersmann", "GEM_PATH"=>"/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger:/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@global", "rvm_delete_flag"=>"0", "rvm_warn_clr"=>"\e[33m", "RUBY_VERSION"=>"ruby-2.0.0-p0", "_"=>"/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/bin/ahn", "_ORIGINAL_GEM_PATH"=>"/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger:/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@global", "BUNDLE_BIN_PATH"=>"/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@global/gems/bundler-1.3.5/bin/bundle", "BUNDLE_GEMFILE"=>"/Users/gersmann/Workspaces/ahn-test2/Gemfile", "RUBYOPT"=>"-I/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@global/gems/bundler-1.3.5/lib -rbundler/setup"}
[2013-04-22 09:48:43] TRACE Adhearsion::Initializer:   # ******* Configuration for punchblock **************

  # The domain at which to address calls [AHN_PUNCHBLOCK_CALLS_DOMAIN]
  config.punchblock.calls_domain       = 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. [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. [AHN_PUNCHBLOCK_MEDIA_ENGINE]
  config.punchblock.media_engine       = nil

  # The domain at which to address mixers [AHN_PUNCHBLOCK_MIXERS_DOMAIN]
  config.punchblock.mixers_domain      = nil

  # Authentication credentials [AHN_PUNCHBLOCK_PASSWORD]
  config.punchblock.password           = deleted

  # 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           = "admin"

  # ******* Configuration for platform **************

  # Lifetime of a call after it has hung up [AHN_PLATFORM_AFTER_HANGUP_LIFETIME]
  config.platform.after_hangup_lifetime = 30

  # Active environment. Supported values: development, production, staging, test [AHN_PLATFORM_ENVIRONMENT]
  config.platform.environment           = :development

  # 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"]

  # 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                  = "/Users/gersmann/Workspaces/ahn-test2"


[2013-04-22 09:48:43] TRACE Adhearsion::Initializer: Gem versions: ["bundler 1.3.5", "rake 10.0.4", "i18n 0.6.1", "multi_json 1.7.2", "activesupport 3.2.13", "adhearsion-loquacious 1.9.3", "timers 1.1.0", "celluloid 0.13.0", "countdownlatch 1.0.0", "deep_merge 1.0.0", "ffi 1.7.0", "future-resource 1.0.0", "connection_pool 1.0.0", "rubinius-core-api 0.0.1", "rubinius-actor 0.0.2", "girl_friday 0.11.2", "has-guarded-handlers 1.5.0", "little-plugger 1.1.3", "logging 1.8.1", "coderay 1.0.9", "method_source 0.8.1", "slop 3.4.4", "pry 0.9.12.1", "eventmachine 1.0.3", "nokogiri 1.5.9", "niceogiri 1.1.1", "blather 0.8.4", "nio4r 0.4.3", "celluloid-io 0.13.1", "ruby_ami 1.3.3", "json 1.7.7", "ruby_fs 1.1.0", "ruby_speech 1.1.0", "state_machine 1.2.0", "punchblock 1.8.2", "thor 0.18.1", "adhearsion 2.3.1", "adhearsion-asterisk 1.3.1", "diff-lcs 1.2.4", "rspec-core 2.13.1", "rspec-expectations 2.13.0", "rspec-mocks 2.13.1", "rspec 2.13.0"]
[2013-04-22 09:48:43] DEBUG Adhearsion::LinuxProcName: Error while attaching libc function prctl: Function 'prctl' not found in [libc.dylib]
[2013-04-22 09:48:43] INFO  Adhearsion::Initializer: Setting RAILS_ENV to "development"
[2013-04-22 09:48:43] INFO  Adhearsion::PunchblockPlugin::Initializer: Starting connection to server
[2013-04-22 09:48:43] DEBUG RubyAMI::Client: Starting up...
[2013-04-22 09:48:43] DEBUG RubyAMI::Client: Starting up...
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Asterisk Call Manager/1.3

[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Asterisk Call Manager/1.3

[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Stream::Connected:0x007f82a5c15b18>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a5ad9420 @name="login", @headers={"Username"=>"admin", "Secret"=>"deleted", "Events"=>"On"}, @action_id="df4fbe6e-722e-4df3-816b-564e301c4636", @response=#<FutureResource:0x007f82a5ae37b8 @resource_lock=#<Monitor:0x007f82a5ae3790 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a5ae2fe8>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a5ae2ed0 @monitor=#<Monitor:0x007f82a5ae3790 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a5ae2fe8>>, @cond=#<ConditionVariable:0x007f82a5ae2098 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a5ae0b58>>>>, @response_callback=#<Proc:0x007f82a5ad9bc8@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/ruby_ami-1.3.3/lib/ruby_ami/client.rb:164>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a5ae03b0>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND] Action: login
ActionID: df4fbe6e-722e-4df3-816b-564e301c4636
Username: admin
Secret: deleted
Events: On


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Stream::Connected:0x007f82a5c6f8e8>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND] Action: login
ActionID: e2a62958-94db-4ecc-9274-a5f474ec65f9
Username: admin
Secret: deleted
Events: On


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: df4fbe6e-722e-4df3-816b-564e301c4636
Message: Authentication accepted

Event: FullyBooted
Privilege: system,all
Status: Fully Booted


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"df4fbe6e-722e-4df3-816b-564e301c4636", "Message"=>"Authentication accepted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: e2a62958-94db-4ecc-9274-a5f474ec65f9
Message: Authentication accepted

Event: FullyBooted
Privilege: system,all
Status: Fully Booted


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="FullyBooted", headers={"Privilege"=>"system,all", "Status"=>"Fully Booted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"e2a62958-94db-4ecc-9274-a5f474ec65f9", "Message"=>"Authentication accepted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="FullyBooted", headers={"Privilege"=>"system,all", "Status"=>"Fully Booted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Response headers={"ActionID"=>"e2a62958-94db-4ecc-9274-a5f474ec65f9", "Message"=>"Authentication accepted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"df4fbe6e-722e-4df3-816b-564e301c4636", "Message"=>"Authentication accepted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a4abda78 @name="events", @headers={"EventMask"=>"Off"}, @action_id="0bdfec92-0ba2-4301-9142-2bb3a6af17ef", @response=#<FutureResource:0x007f82a4abd780 @resource_lock=#<Monitor:0x007f82a4abd6b8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abd5c8>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4abd5a0 @monitor=#<Monitor:0x007f82a4abd6b8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abd5c8>>, @cond=#<ConditionVariable:0x007f82a4abd4d8 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4abd410>>>>, @response_callback=nil, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4abd3c0>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="FullyBooted", headers={"Privilege"=>"system,all", "Status"=>"Fully Booted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Event name="FullyBooted", headers={"Privilege"=>"system,all", "Status"=>"Fully Booted"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a4abda78 @name="events", @headers={"EventMask"=>"Off"}, @action_id="0bdfec92-0ba2-4301-9142-2bb3a6af17ef", @response=#<FutureResource:0x007f82a4abd780 @resource_lock=#<Monitor:0x007f82a4abd6b8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abd5c8>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4abd5a0 @monitor=#<Monitor:0x007f82a4abd6b8 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abd5c8>>, @cond=#<ConditionVariable:0x007f82a4abd4d8 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4abd410>>>>, @response_callback=nil, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4abd3c0>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND] Action: events
ActionID: 0bdfec92-0ba2-4301-9142-2bb3a6af17ef
EventMask: Off


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: 0bdfec92-0ba2-4301-9142-2bb3a6af17ef
Events: Off


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a48d6ea8 @name="command", @headers={"Command"=>"dialplan add extension 1,1,AGI,agi:async into adhearsion-redirect"}, @action_id="9b18abdf-8b48-4a9a-b280-b08eca1a90a3", @response=#<FutureResource:0x007f82a48d5710 @resource_lock=#<Monitor:0x007f82a48d4db0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a48d48b0>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a48d4270 @monitor=#<Monitor:0x007f82a48d4db0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a48d48b0>>, @cond=#<ConditionVariable:0x007f82a48df8f0 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a48dee00>>>>, @response_callback=nil, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a48e7a00>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a5ac3e18 @name="command", @headers={"Command"=>"dialplan show adhearsion-redirect"}, @action_id="2f9322db-47e8-4d6f-b750-e7bdbafd8016", @response=#<FutureResource:0x007f82a5aca3f8 @resource_lock=#<Monitor:0x007f82a5aca1a0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a5ac94a8>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a5ac9340 @monitor=#<Monitor:0x007f82a5aca1a0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a5ac94a8>>, @cond=#<ConditionVariable:0x007f82a5ac9110 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a5ac8af8>>>>, @response_callback=#<Proc:0x007f82a5ab8270@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk.rb:147>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a5ad3e08>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"0bdfec92-0ba2-4301-9142-2bb3a6af17ef", "Events"=>"Off"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"0bdfec92-0ba2-4301-9142-2bb3a6af17ef", "Events"=>"Off"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:43] WARN  Punchblock::Translator::Asterisk: Recordings directory /var/punchblock/record does not exist. Recording might not work. This warning can be ignored if Adhearsion is running on a separate machine than Asterisk. See http://adhearsion.com/docs/call-controllers#recording
[2013-04-22 09:48:43] INFO  Adhearsion::PunchblockPlugin::Initializer: Connected to Punchblock server
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a48d6ea8 @name="command", @headers={"Command"=>"dialplan add extension 1,1,AGI,agi:async into adhearsion-redirect"}, @action_id="9b18abdf-8b48-4a9a-b280-b08eca1a90a3", @response=#<FutureResource:0x007f82a48d5710 @resource_lock=#<Monitor:0x007f82a48d4db0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a48d48b0>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a48d4270 @monitor=#<Monitor:0x007f82a48d4db0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a48d48b0>>, @cond=#<ConditionVariable:0x007f82a48df8f0 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a48dee00>>>>, @response_callback=nil, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a48e7a00>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND] Action: command
ActionID: 9b18abdf-8b48-4a9a-b280-b08eca1a90a3
Command: dialplan add extension 1,1,AGI,agi:async into adhearsion-redirect


AHN> [2013-04-22 09:48:43] INFO  Adhearsion::Console: Launching Adhearsion Console
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Response: Follows
Privilege: Command
ActionID: 9b18abdf-8b48-4a9a-b280-b08eca1a90a3
Extension '1,1,AGI(agi:async)' added into 'adhearsion-redirect' context
--END COMMAND--


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"Privilege"=>"Command", "ActionID"=>"9b18abdf-8b48-4a9a-b280-b08eca1a90a3", "Extension '1,1,AGI(agi"=>"async)' added into 'adhearsion-redirect' context\n--END COMMAND--"}, text_body="Extension '1,1,AGI(agi:async)' added into 'adhearsion-redirect' context", events=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"Privilege"=>"Command", "ActionID"=>"9b18abdf-8b48-4a9a-b280-b08eca1a90a3", "Extension '1,1,AGI(agi"=>"async)' added into 'adhearsion-redirect' context\n--END COMMAND--"}, text_body="Extension '1,1,AGI(agi:async)' added into 'adhearsion-redirect' context", events=nil, action=nil>
[2013-04-22 09:48:43] INFO  Adhearsion::Process: Transitioning from booting to running with 0 active calls due to booted event.
[2013-04-22 09:48:43] INFO  Adhearsion::Initializer: Adhearsion v2.3.1 initialized in "development"!
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a5ac3e18 @name="command", @headers={"Command"=>"dialplan show adhearsion-redirect"}, @action_id="2f9322db-47e8-4d6f-b750-e7bdbafd8016", @response=#<FutureResource:0x007f82a5aca3f8 @resource_lock=#<Monitor:0x007f82a5aca1a0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a5ac94a8>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a5ac9340 @monitor=#<Monitor:0x007f82a5aca1a0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a5ac94a8>>, @cond=#<ConditionVariable:0x007f82a5ac9110 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a5ac8af8>>>>, @response_callback=#<Proc:0x007f82a5ab8270@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk.rb:147>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a5ad3e08>>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [SEND] Action: command
ActionID: 2f9322db-47e8-4d6f-b750-e7bdbafd8016
Command: dialplan show adhearsion-redirect


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] Response: Follows
Privilege: Command
ActionID: 2f9322db-47e8-4d6f-b750-e7bdbafd8016

[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] [ Context 'adhearsion-redirect' created by 'pbx_config' ]
  '1' =>            1. AGI(agi:async)                             [pbx_config]

-= 1 extension (1 priority) in 1 context. =-
--END COMMAND--


[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"Privilege"=>"Command", "ActionID"=>"2f9322db-47e8-4d6f-b750-e7bdbafd8016"}, 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=nil, action=nil>
[2013-04-22 09:48:43] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"Privilege"=>"Command", "ActionID"=>"2f9322db-47e8-4d6f-b750-e7bdbafd8016"}, 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=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Event: Newchannel
Privilege: call,all
Channel: SIP/placetel.de-0000000c
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum: +498941150126
CallerIDName:
AccountCode:
Exten: 498912509582
Context: adhearsion
Uniqueid: 1366616927.16

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: SIPURI
Value: sip:62.134.52.198:8001
Uniqueid: 1366616927.16

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: SIPDOMAIN
Value: 84.167.111.51
Uniqueid: 1366616927.16


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"498912509582", "Context"=>"adhearsion", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"SIPURI", "Value"=>"sip:62.134.52.198:8001", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"SIPDOMAIN", "Value"=>"84.167.111.51", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"498912509582", "Context"=>"adhearsion", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: SIPCALLID
Value: 48F160B7-5174EB5D0005F05E-A74F4700
Uniqueid: 1366616927.16

Event: Newstate
Privilege: call,all
Channel: SIP/placetel.de-0000000c
ChannelState: 4
ChannelStateDesc: Ring
CallerIDNum: +498941150126
CallerIDName:
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1366616927.16

Event: Newexten
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Context: adhearsion
Extension: 498912509582
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1366616927.16

Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000c
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20498912509582%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"SIPURI", "Value"=>"sip:62.134.52.198:8001", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"SIPCALLID", "Value"=>"48F160B7-5174EB5D0005F05E-A74F4700", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Context"=>"adhearsion", "Extension"=>"498912509582", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20498912509582%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"SIPCALLID", "Value"=>"48F160B7-5174EB5D0005F05E-A74F4700", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"SIPDOMAIN", "Value"=>"84.167.111.51", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "ChannelState"=>"4", "ChannelStateDesc"=>"Ring", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Context"=>"adhearsion", "Extension"=>"498912509582", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20498912509582%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] DEBUG Adhearsion::Call: : Receiving message: #<Punchblock::Event::Offer to="498912509582", from="unknown <SIP/+498941150126>", headers={:x_agi_request=>"async", :x_agi_channel=>"SIP/placetel.de-0000000c", :x_agi_language=>"en", :x_agi_type=>"SIP", :x_agi_uniqueid=>"1366616927.16", :x_agi_version=>"11.3.0", :x_agi_callerid=>"+498941150126", :x_agi_calleridname=>"unknown", :x_agi_callingpres=>"0", :x_agi_callingani2=>"0", :x_agi_callington=>"0", :x_agi_callingtns=>"0", :x_agi_dnid=>"498912509582", :x_agi_rdnis=>"unknown", :x_agi_context=>"adhearsion", :x_agi_extension=>"498912509582", :x_agi_priority=>"1", :x_agi_enhanced=>"0.0", :x_agi_accountcode=>"", :x_agi_threadid=>"4394532864"}, call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce"
[2013-04-22 09:48:47] INFO  Adhearsion::Router: Call a5ae7012-3ed4-42c3-95e2-2efeba8f36ce selected route "default" (Test)
[2013-04-22 09:48:47] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Executing command #<Punchblock::Command::Accept headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a4abcbf0 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Command"=>"EXEC RINGING", "CommandID"=>"f6efb9c0-65ce-47f4-b717-894e81b6540b"}, @action_id="a8c3b8ed-25b1-489f-93c1-5689c441a294", @response=#<FutureResource:0x007f82a4abca88 @resource_lock=#<Monitor:0x007f82a4abca60 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abca10>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4abc9e8 @monitor=#<Monitor:0x007f82a4abca60 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abca10>>, @cond=#<ConditionVariable:0x007f82a4abc9c0 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4abc970>>>>, @response_callback=#<Proc:0x007f82a4abcba0@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4abc920>>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a4abcbf0 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Command"=>"EXEC RINGING", "CommandID"=>"f6efb9c0-65ce-47f4-b717-894e81b6540b"}, @action_id="a8c3b8ed-25b1-489f-93c1-5689c441a294", @response=#<FutureResource:0x007f82a4abca88 @resource_lock=#<Monitor:0x007f82a4abca60 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abca10>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4abc9e8 @monitor=#<Monitor:0x007f82a4abca60 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abca10>>, @cond=#<ConditionVariable:0x007f82a4abc9c0 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4abc970>>>>, @response_callback=#<Proc:0x007f82a4abcba0@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4abc920>>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [SEND] Action: agi
ActionID: a8c3b8ed-25b1-489f-93c1-5689c441a294
Channel: SIP/placetel.de-0000000c
Command: EXEC RINGING
CommandID: f6efb9c0-65ce-47f4-b717-894e81b6540b


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: a8c3b8ed-25b1-489f-93c1-5689c441a294
Message: Added AGI command to queue


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"a8c3b8ed-25b1-489f-93c1-5689c441a294", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"a8c3b8ed-25b1-489f-93c1-5689c441a294", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000c
CommandId: 1601798088
Command: EXEC RINGING

Event: AGIExec
Privilege: agi,all
SubEvent: End
Channel: SIP/placetel.de-0000000c
CommandId: 1601798088
Command: EXEC RINGING
ResultCode: 200
Result: Success


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1601798088", "Command"=>"EXEC RINGING"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1601798088", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1601798088", "Command"=>"EXEC RINGING"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Event: AsyncAGI
Privilege: agi,all
SubEvent: Exec
Channel: SIP/placetel.de-0000000c
CommandID: f6efb9c0-65ce-47f4-b717-894e81b6540b
Result: 200%20result%3D0%0A


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000c", "CommandID"=>"f6efb9c0-65ce-47f4-b717-894e81b6540b", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1601798088", "Command"=>"EXEC RINGING", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000c", "CommandID"=>"f6efb9c0-65ce-47f4-b717-894e81b6540b", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/placetel.de-0000000c", :commandid=>"1601798088", :command=>"EXEC RINGING"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:47] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/placetel.de-0000000c", :commandid=>"1601798088", :command=>"EXEC RINGING", :resultcode=>"200", :result=>"Success"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:47] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/placetel.de-0000000c", :commandid=>"f6efb9c0-65ce-47f4-b717-894e81b6540b", :result=>"200%20result%3D0%0A"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:47] INFO  Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Executing controller #<Test call=a5ae7012-3ed4-42c3-95e2-2efeba8f36ce, metadata={}>
[2013-04-22 09:48:47] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Executing command #<Punchblock::Command::Answer headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a4aafae0 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Command"=>"ANSWER", "CommandID"=>"dfb55263-2fa1-4c15-8385-573f51010629"}, @action_id="828d835a-70c8-472e-9a73-b6bdaa987f32", @response=#<FutureResource:0x007f82a4aaf720 @resource_lock=#<Monitor:0x007f82a4aaf6d0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4aaf680>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4aaf658 @monitor=#<Monitor:0x007f82a4aaf6d0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4aaf680>>, @cond=#<ConditionVariable:0x007f82a4aaf540 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4aaf4a0>>>>, @response_callback=#<Proc:0x007f82a4aaf9c8@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4aaf450>>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a4aafae0 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Command"=>"ANSWER", "CommandID"=>"dfb55263-2fa1-4c15-8385-573f51010629"}, @action_id="828d835a-70c8-472e-9a73-b6bdaa987f32", @response=#<FutureResource:0x007f82a4aaf720 @resource_lock=#<Monitor:0x007f82a4aaf6d0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4aaf680>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4aaf658 @monitor=#<Monitor:0x007f82a4aaf6d0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4aaf680>>, @cond=#<ConditionVariable:0x007f82a4aaf540 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4aaf4a0>>>>, @response_callback=#<Proc:0x007f82a4aaf9c8@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4aaf450>>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [SEND] Action: agi
ActionID: 828d835a-70c8-472e-9a73-b6bdaa987f32
Channel: SIP/placetel.de-0000000c
Command: ANSWER
CommandID: dfb55263-2fa1-4c15-8385-573f51010629


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: 828d835a-70c8-472e-9a73-b6bdaa987f32
Message: Added AGI command to queue


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"828d835a-70c8-472e-9a73-b6bdaa987f32", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"828d835a-70c8-472e-9a73-b6bdaa987f32", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000c
CommandId: 1956523739
Command: ANSWER

Event: Newstate
Privilege: call,all
Channel: SIP/placetel.de-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: +498941150126
CallerIDName:
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1366616927.16


[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1956523739", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1956523739", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:47] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: End
Channel: SIP/placetel.de-0000000c
CommandId: 1956523739
Command: ANSWER
ResultCode: 200
Result: Success

Event: AsyncAGI
Privilege: agi,all
SubEvent: Exec
Channel: SIP/placetel.de-0000000c
CommandID: dfb55263-2fa1-4c15-8385-573f51010629
Result: 200%20result%3D0%0A


[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1956523739", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1956523739", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000c", "CommandID"=>"dfb55263-2fa1-4c15-8385-573f51010629", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000c", "CommandID"=>"dfb55263-2fa1-4c15-8385-573f51010629", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Offer to="498912509582", from="unknown <SIP/+498941150126>", headers={:x_agi_request=>"async", :x_agi_channel=>"SIP/placetel.de-0000000c", :x_agi_language=>"en", :x_agi_type=>"SIP", :x_agi_uniqueid=>"1366616927.16", :x_agi_version=>"11.3.0", :x_agi_callerid=>"+498941150126", :x_agi_calleridname=>"unknown", :x_agi_callingpres=>"0", :x_agi_callingani2=>"0", :x_agi_callington=>"0", :x_agi_callingtns=>"0", :x_agi_dnid=>"498912509582", :x_agi_rdnis=>"unknown", :x_agi_context=>"adhearsion", :x_agi_extension=>"498912509582", :x_agi_priority=>"1", :x_agi_enhanced=>"0.0", :x_agi_accountcode=>"", :x_agi_threadid=>"4394532864"}, call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce"
[2013-04-22 09:48:48] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/placetel.de-0000000c", :commandid=>"1956523739", :command=>"ANSWER"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newstate", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000c", :channelstate=>"6", :channelstatedesc=>"Up", :calleridnum=>"+498941150126", :calleridname=>"", :connectedlinenum=>"", :connectedlinename=>"", :uniqueid=>"1366616927.16"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Answered headers_hash={}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/placetel.de-0000000c", :commandid=>"1956523739", :command=>"ANSWER", :resultcode=>"200", :result=>"Success"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/placetel.de-0000000c", :commandid=>"dfb55263-2fa1-4c15-8385-573f51010629", :result=>"200%20result%3D0%0A"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::OutboundCall: : Executing command #<Punchblock::Command::Dial to="SIP/08925007641@placetel.de", from="unknown <SIP/+498941150126>", join=nil, headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a4177950 @name="originate", @headers={"Async"=>"true", "Application"=>"AGI", "Data"=>"agi:async", "Channel"=>"SIP/08925007641@placetel.de", "Callerid"=>"unknown <SIP/+498941150126>", "Variable"=>"punchblock_call_id=b70bd8ad-b1fb-4c60-82e9-18b68de7650a"}, @action_id="92934441-e1db-4659-a5e4-a96a19d13c59", @response=#<FutureResource:0x007f82a4177270 @resource_lock=#<Monitor:0x007f82a4176f50 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4176b18>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4176730 @monitor=#<Monitor:0x007f82a4176f50 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4176b18>>, @cond=#<ConditionVariable:0x007f82a4176708 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a41762d0>>>>, @response_callback=#<Proc:0x007f82a41778b0@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/ami_action.rb:44>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4175ab0>>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a4177950 @name="originate", @headers={"Async"=>"true", "Application"=>"AGI", "Data"=>"agi:async", "Channel"=>"SIP/08925007641@placetel.de", "Callerid"=>"unknown <SIP/+498941150126>", "Variable"=>"punchblock_call_id=b70bd8ad-b1fb-4c60-82e9-18b68de7650a"}, @action_id="92934441-e1db-4659-a5e4-a96a19d13c59", @response=#<FutureResource:0x007f82a4177270 @resource_lock=#<Monitor:0x007f82a4176f50 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4176b18>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4176730 @monitor=#<Monitor:0x007f82a4176f50 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4176b18>>, @cond=#<ConditionVariable:0x007f82a4176708 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a41762d0>>>>, @response_callback=#<Proc:0x007f82a41778b0@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/ami_action.rb:44>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4175ab0>>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [SEND] Action: originate
ActionID: 92934441-e1db-4659-a5e4-a96a19d13c59
Async: true
Application: AGI
Data: agi:async
Channel: SIP/08925007641@placetel.de
Callerid: unknown <SIP/+498941150126>
Variable: punchblock_call_id=b70bd8ad-b1fb-4c60-82e9-18b68de7650a


[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: 92934441-e1db-4659-a5e4-a96a19d13c59
Message: Originate successfully queued


[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"92934441-e1db-4659-a5e4-a96a19d13c59", "Message"=>"Originate successfully queued"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] Event: Newchannel
Privilege: call,all
Channel: SIP/placetel.de-0000000d
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten:
Context: adhearsion
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: SIPCALLID
Value: 4618534968ae6e00106c2c90285a011b@fpbx.de
Uniqueid: 1366616928.17


[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"adhearsion", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"92934441-e1db-4659-a5e4-a96a19d13c59", "Message"=>"Originate successfully queued"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"SIPCALLID", "Value"=>"4618534968ae6e00106c2c90285a011b@fpbx.de", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"adhearsion", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: punchblock_call_id
Value: b70bd8ad-b1fb-4c60-82e9-18b68de7650a
Uniqueid: 1366616928.17

Event: NewAccountCode
Privilege: call,all
Channel: SIP/placetel.de-0000000d
Uniqueid: 1366616928.17
AccountCode:
OldAccountCode:

Event: NewCallerid
Privilege: call,all
Channel: SIP/placetel.de-0000000d
CallerIDNum: SIP/+498941150126
CallerIDName: unknown
Uniqueid: 1366616928.17
CID-CallingPres: 0 (Presentation Allowed, Not Screened)


[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"punchblock_call_id", "Value"=>"b70bd8ad-b1fb-4c60-82e9-18b68de7650a", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"SIPCALLID", "Value"=>"4618534968ae6e00106c2c90285a011b@fpbx.de", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "Uniqueid"=>"1366616928.17", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"punchblock_call_id", "Value"=>"b70bd8ad-b1fb-4c60-82e9-18b68de7650a", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "Uniqueid"=>"1366616928.17", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"punchblock_call_id", :value=>"b70bd8ad-b1fb-4c60-82e9-18b68de7650a", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="NewCallerid", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :calleridnum=>"SIP/+498941150126", :calleridname=>"unknown", :uniqueid=>"1366616928.17", :cid_callingpres=>"0 (Presentation Allowed, Not Screened)"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:48] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="NewAccountCode", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :uniqueid=>"1366616928.17", :accountcode=>"", :oldaccountcode=>""}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:49] TRACE RubyAMI::Client: [RECV] Event: Newstate
Privilege: call,all
Channel: SIP/placetel.de-0000000d
ChannelState: 5
ChannelStateDesc: Ringing
CallerIDNum: SIP/+498941150126
CallerIDName: unknown
ConnectedLineNum: SIP/+498941150126
ConnectedLineName: unknown
Uniqueid: 1366616928.17


[2013-04-22 09:48:49] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "ChannelState"=>"5", "ChannelStateDesc"=>"Ringing", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "ConnectedLineNum"=>"SIP/+498941150126", "ConnectedLineName"=>"unknown", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:49] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "ChannelState"=>"5", "ChannelStateDesc"=>"Ringing", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "ConnectedLineNum"=>"SIP/+498941150126", "ConnectedLineName"=>"unknown", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:49] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newstate", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :channelstate=>"5", :channelstatedesc=>"Ringing", :calleridnum=>"SIP/+498941150126", :calleridname=>"unknown", :connectedlinenum=>"SIP/+498941150126", :connectedlinename=>"unknown", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:49] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Ringing headers_hash={}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Event: Newstate
Privilege: call,all
Channel: SIP/placetel.de-0000000d
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum: SIP/+498941150126
CallerIDName: unknown
ConnectedLineNum: SIP/+498941150126
ConnectedLineName: unknown
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: punchblock_call_id
Value: b70bd8ad-b1fb-4c60-82e9-18b68de7650a
Uniqueid: 1366616928.17

Event: NewAccountCode
Privilege: call,all
Channel: SIP/placetel.de-0000000d
Uniqueid: 1366616928.17
AccountCode:
OldAccountCode:


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "ConnectedLineNum"=>"SIP/+498941150126", "ConnectedLineName"=>"unknown", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"punchblock_call_id", "Value"=>"b70bd8ad-b1fb-4c60-82e9-18b68de7650a", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "ConnectedLineNum"=>"SIP/+498941150126", "ConnectedLineName"=>"unknown", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Event: OriginateResponse
Privilege: call,all
ActionID: 92934441-e1db-4659-a5e4-a96a19d13c59
Response: Success
Channel: SIP/placetel.de-0000000d
Context:
Exten:
Reason: 4
Uniqueid: 1366616928.17
CallerIDNum: SIP/+498941150126
CallerIDName: unknown

Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000d
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000d%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616928.17%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20SIP%2F%2B498941150126%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%0Aagi_extension%3A%20%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204396093440%0A%0A


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="OriginateResponse", headers={"Privilege"=>"call,all", "ActionID"=>"92934441-e1db-4659-a5e4-a96a19d13c59", "Response"=>"Success", "Channel"=>"SIP/placetel.de-0000000d", "Context"=>"", "Exten"=>"", "Reason"=>"4", "Uniqueid"=>"1366616928.17", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000d", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000d%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616928.17%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20SIP%2F%2B498941150126%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%0Aagi_extension%3A%20%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204396093440%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"punchblock_call_id", "Value"=>"b70bd8ad-b1fb-4c60-82e9-18b68de7650a", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="OriginateResponse", headers={"Privilege"=>"call,all", "ActionID"=>"92934441-e1db-4659-a5e4-a96a19d13c59", "Response"=>"Success", "Channel"=>"SIP/placetel.de-0000000d", "Context"=>"", "Exten"=>"", "Reason"=>"4", "Uniqueid"=>"1366616928.17", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000d", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000d%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616928.17%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20SIP%2F%2B498941150126%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%0Aagi_extension%3A%20%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204396093440%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newstate", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :channelstate=>"6", :channelstatedesc=>"Up", :calleridnum=>"SIP/+498941150126", :calleridname=>"unknown", :connectedlinenum=>"SIP/+498941150126", :connectedlinename=>"unknown", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="NewAccountCode", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :uniqueid=>"1366616928.17", :accountcode=>"", :oldaccountcode=>""}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Answered headers_hash={}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"punchblock_call_id", :value=>"b70bd8ad-b1fb-4c60-82e9-18b68de7650a", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="OriginateResponse", attributes_hash={:privilege=>"call,all", :actionid=>"92934441-e1db-4659-a5e4-a96a19d13c59", :response=>"Success", :channel=>"SIP/placetel.de-0000000d", :context=>"", :exten=>"", :reason=>"4", :uniqueid=>"1366616928.17", :calleridnum=>"SIP/+498941150126", :calleridname=>"unknown"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/placetel.de-0000000d", :env=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000d%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616928.17%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20SIP%2F%2B498941150126%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%0Aagi_extension%3A%20%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204396093440%0A%0A"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::CallController::Dial::Dial: #dial joining call b70bd8ad-b1fb-4c60-82e9-18b68de7650a to a5ae7012-3ed4-42c3-95e2-2efeba8f36ce
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Executing command #<Punchblock::Command::Answer headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a43dabe8 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Command"=>"ANSWER", "CommandID"=>"25c50cdc-ed52-4439-a363-83c62daa2d2c"}, @action_id="9ab02a49-4f47-4634-948e-27e211b551c8", @response=#<FutureResource:0x007f82a43daa30 @resource_lock=#<Monitor:0x007f82a43daa08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a43da990>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a43da968 @monitor=#<Monitor:0x007f82a43daa08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a43da990>>, @cond=#<ConditionVariable:0x007f82a43da940 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a43da8c8>>>>, @response_callback=#<Proc:0x007f82a43dab98@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a43da878>>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a43dabe8 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Command"=>"ANSWER", "CommandID"=>"25c50cdc-ed52-4439-a363-83c62daa2d2c"}, @action_id="9ab02a49-4f47-4634-948e-27e211b551c8", @response=#<FutureResource:0x007f82a43daa30 @resource_lock=#<Monitor:0x007f82a43daa08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a43da990>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a43da968 @monitor=#<Monitor:0x007f82a43daa08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a43da990>>, @cond=#<ConditionVariable:0x007f82a43da940 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a43da8c8>>>>, @response_callback=#<Proc:0x007f82a43dab98@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a43da878>>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [SEND] Action: agi
ActionID: 9ab02a49-4f47-4634-948e-27e211b551c8
Channel: SIP/placetel.de-0000000c
Command: ANSWER
CommandID: 25c50cdc-ed52-4439-a363-83c62daa2d2c


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: 9ab02a49-4f47-4634-948e-27e211b551c8
Message: Added AGI command to queue


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"9ab02a49-4f47-4634-948e-27e211b551c8", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"9ab02a49-4f47-4634-948e-27e211b551c8", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000c
CommandId: 1102078446
Command: ANSWER

Event: AGIExec
Privilege: agi,all
SubEvent: End
Channel: SIP/placetel.de-0000000c
CommandId: 1102078446
Command: ANSWER
ResultCode: 200
Result: Success

Event: AsyncAGI
Privilege: agi,all
SubEvent: Exec
Channel: SIP/placetel.de-0000000c
CommandID: 25c50cdc-ed52-4439-a363-83c62daa2d2c
Result: 200%20result%3D0%0A


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1102078446", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1102078446", "Command"=>"ANSWER"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1102078446", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000c", "CommandID"=>"25c50cdc-ed52-4439-a363-83c62daa2d2c", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c", "CommandId"=>"1102078446", "Command"=>"ANSWER", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000c", "CommandID"=>"25c50cdc-ed52-4439-a363-83c62daa2d2c", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/placetel.de-0000000c", :commandid=>"1102078446", :command=>"ANSWER"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/placetel.de-0000000c", :commandid=>"1102078446", :command=>"ANSWER", :resultcode=>"200", :result=>"Success"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/placetel.de-0000000c", :commandid=>"25c50cdc-ed52-4439-a363-83c62daa2d2c", :result=>"200%20result%3D0%0A"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Executing command #<Punchblock::Command::Join call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", mixer_name=nil, direction=nil, media=nil, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a4abe108 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000d", "Command"=>"EXEC Bridge \"SIP/placetel.de-0000000c\"", "CommandID"=>"458780d1-79ff-460f-a377-005ca11840c6"}, @action_id="97a88bab-b996-4ad6-8b98-2af6e6f78f3b", @response=#<FutureResource:0x007f82a4abdc30 @resource_lock=#<Monitor:0x007f82a4abdb90 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abda78>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4abd898 @monitor=#<Monitor:0x007f82a4abdb90 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abda78>>, @cond=#<ConditionVariable:0x007f82a4abd7a8 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4abd4d8>>>>, @response_callback=#<Proc:0x007f82a4abdfc8@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4abd280>>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a4abe108 @name="agi", @headers={"Channel"=>"SIP/placetel.de-0000000d", "Command"=>"EXEC Bridge \"SIP/placetel.de-0000000c\"", "CommandID"=>"458780d1-79ff-460f-a377-005ca11840c6"}, @action_id="97a88bab-b996-4ad6-8b98-2af6e6f78f3b", @response=#<FutureResource:0x007f82a4abdc30 @resource_lock=#<Monitor:0x007f82a4abdb90 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abda78>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a4abd898 @monitor=#<Monitor:0x007f82a4abdb90 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a4abda78>>, @cond=#<ConditionVariable:0x007f82a4abd7a8 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a4abd4d8>>>>, @response_callback=#<Proc:0x007f82a4abdfc8@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/component/asterisk/agi_command.rb:43>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a4abd280>>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [SEND] Action: agi
ActionID: 97a88bab-b996-4ad6-8b98-2af6e6f78f3b
Channel: SIP/placetel.de-0000000d
Command: EXEC Bridge "SIP/placetel.de-0000000c"
CommandID: 458780d1-79ff-460f-a377-005ca11840c6


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Response: Success
ActionID: 97a88bab-b996-4ad6-8b98-2af6e6f78f3b
Message: Added AGI command to queue


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Response headers={"ActionID"=>"97a88bab-b996-4ad6-8b98-2af6e6f78f3b", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Response headers={"ActionID"=>"97a88bab-b996-4ad6-8b98-2af6e6f78f3b", "Message"=>"Added AGI command to queue"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Event: AGIExec
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000d
CommandId: 1351659748
Command: EXEC Bridge "SIP/placetel.de-0000000c"


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000d", "CommandId"=>"1351659748", "Command"=>"EXEC Bridge \"SIP/placetel.de-0000000c\""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Event: Newchannel
Privilege: call,all
Channel: Bridge/SIP/placetel.de-0000000c
ChannelState: 0
ChannelStateDesc: Down
CallerIDNum:
CallerIDName:
AccountCode:
Exten:
Context:
Uniqueid: 1366616931.18

Event: MusicOnHold
Privilege: call,all
State: Stop
Channel: SIP/placetel.de-0000000c
UniqueID: 1366616927.16

Event: Newstate
Privilege: call,all
Channel: Bridge/SIP/placetel.de-0000000c
ChannelState: 6
ChannelStateDesc: Up
CallerIDNum:
CallerIDName:
ConnectedLineNum:
ConnectedLineName:
Uniqueid: 1366616931.18

Event: Masquerade
Privilege: call,all
Clone: SIP/placetel.de-0000000c
CloneState: Up
Original: Bridge/SIP/placetel.de-0000000c
OriginalState: Up

Event: Rename
Privilege: call,all
Channel: SIP/placetel.de-0000000c
Newname: SIP/placetel.de-0000000c<MASQ>
Uniqueid: 1366616927.16

Event: Rename
Privilege: call,all
Channel: Bridge/SIP/placetel.de-0000000c
Newname: SIP/placetel.de-0000000c
Uniqueid: 1366616931.18

Event: Rename
Privilege: call,all
Channel: SIP/placetel.de-0000000c<MASQ>
Newname: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Uniqueid: 1366616927.16

Event: NewCallerid
Privilege: call,all
Channel: SIP/placetel.de-0000000c
CallerIDNum: +498941150126
CallerIDName:
Uniqueid: 1366616931.18
CID-CallingPres: 0 (Presentation Allowed, Not Screened)

Event: BridgeExec
Privilege: call,all
Response: Success
Channel1: SIP/placetel.de-0000000d
Channel2: SIP/placetel.de-0000000c

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: BRIDGEPEER
Value: SIP/placetel.de-0000000c
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: BRIDGEPEER
Value: SIP/placetel.de-0000000d
Uniqueid: 1366616931.18

Event: NewAccountCode
Privilege: call,all
Channel: SIP/placetel.de-0000000c
Uniqueid: 1366616931.18
AccountCode:
OldAccountCode:

Event: Bridge
Privilege: call,all
Bridgestate: Link
Bridgetype: core
Channel1: SIP/placetel.de-0000000d
Channel2: SIP/placetel.de-0000000c
Uniqueid1: 1366616928.17
Uniqueid2: 1366616931.18
CallerID1: SIP/+498941150126
CallerID2: +498941150126

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: BRIDGEPEER
Value: SIP/placetel.de-0000000c
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: BRIDGEPVTCALLID
Value: 48F160B7-5174EB5D0005F05E-A74F4700
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: BRIDGEPEER
Value: SIP/placetel.de-0000000d
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: BRIDGEPVTCALLID
Value: 4618534968ae6e00106c2c90285a011b@fpbx.de
Uniqueid: 1366616931.18

Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>

Event: VarSet
Privilege: dialplan,all
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1366616927.16


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000d", "CommandId"=>"1351659748", "Command"=>"EXEC Bridge \"SIP/placetel.de-0000000c\""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="MusicOnHold", headers={"Privilege"=>"call,all", "State"=>"Stop", "Channel"=>"SIP/placetel.de-0000000c", "UniqueID"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Masquerade", headers={"Privilege"=>"call,all", "Clone"=>"SIP/placetel.de-0000000c", "CloneState"=>"Up", "Original"=>"Bridge/SIP/placetel.de-0000000c", "OriginalState"=>"Up"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newchannel", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c", "ChannelState"=>"0", "ChannelStateDesc"=>"Down", "CallerIDNum"=>"", "CallerIDName"=>"", "AccountCode"=>"", "Exten"=>"", "Context"=>"", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Newname"=>"SIP/placetel.de-0000000c<MASQ>", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c", "Newname"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="MusicOnHold", headers={"Privilege"=>"call,all", "State"=>"Stop", "Channel"=>"SIP/placetel.de-0000000c", "UniqueID"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c<MASQ>", "Newname"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "Uniqueid"=>"1366616931.18", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newstate", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c", "ChannelState"=>"6", "ChannelStateDesc"=>"Up", "CallerIDNum"=>"", "CallerIDName"=>"", "ConnectedLineNum"=>"", "ConnectedLineName"=>"", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="BridgeExec", headers={"Privilege"=>"call,all", "Response"=>"Success", "Channel1"=>"SIP/placetel.de-0000000d", "Channel2"=>"SIP/placetel.de-0000000c"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Masquerade", headers={"Privilege"=>"call,all", "Clone"=>"SIP/placetel.de-0000000c", "CloneState"=>"Up", "Original"=>"Bridge/SIP/placetel.de-0000000c", "OriginalState"=>"Up"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Newname"=>"SIP/placetel.de-0000000c<MASQ>", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/placetel.de-0000000d", "Channel2"=>"SIP/placetel.de-0000000c", "Uniqueid1"=>"1366616928.17", "Uniqueid2"=>"1366616931.18", "CallerID1"=>"SIP/+498941150126", "CallerID2"=>"+498941150126"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="MusicOnHold", attributes_hash={:privilege=>"call,all", :state=>"Stop", :channel=>"SIP/placetel.de-0000000c", :uniqueid=>"1366616927.16"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c", "Newname"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"48F160B7-5174EB5D0005F05E-A74F4700", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Rename", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000c", :newname=>"SIP/placetel.de-0000000c<MASQ>", :uniqueid=>"1366616927.16"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="NewCallerid", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"", "Uniqueid"=>"1366616931.18", "CID-CallingPres"=>"0 (Presentation Allowed, Not Screened)"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Rename", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c<MASQ>", "Newname"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"4618534968ae6e00106c2c90285a011b@fpbx.de", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="BridgeExec", headers={"Privilege"=>"call,all", "Response"=>"Success", "Channel1"=>"SIP/placetel.de-0000000d", "Channel2"=>"SIP/placetel.de-0000000c"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="NewCallerid", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000c", :calleridnum=>"+498941150126", :calleridname=>"", :uniqueid=>"1366616931.18", :cid_callingpres=>"0 (Presentation Allowed, Not Screened)"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/placetel.de-0000000d", :commandid=>"1351659748", :command=>"EXEC Bridge \"SIP/placetel.de-0000000c\""}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] Event: SoftHangupRequest
Privilege: call,all
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Uniqueid: 1366616927.16
Cause: 16

Event: Newexten
Privilege: dialplan,all
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1366616927.16

Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Env: agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2Fplacetel.de-0000000c%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A

Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>

Event: VarSet
Privilege: dialplan,all
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1366616927.16

Event: Hangup
Privilege: call,all
Channel: Bridge/SIP/placetel.de-0000000c<ZOMBIE>
Uniqueid: 1366616927.16
CallerIDNum: <unknown>
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown


[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Uniqueid"=>"1366616927.16", "Cause"=>"16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="NewAccountCode", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18", "AccountCode"=>"", "OldAccountCode"=>""}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="BridgeExec", attributes_hash={:privilege=>"call,all", :response=>"Success", :channel1=>"SIP/placetel.de-0000000d", :channel2=>"SIP/placetel.de-0000000c"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"BRIDGEPEER", :value=>"SIP/placetel.de-0000000c", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="BridgeExec", attributes_hash={:privilege=>"call,all", :response=>"Success", :channel1=>"SIP/placetel.de-0000000d", :channel2=>"SIP/placetel.de-0000000c"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2Fplacetel.de-0000000c%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Link", "Bridgetype"=>"core", "Channel1"=>"SIP/placetel.de-0000000d", "Channel2"=>"SIP/placetel.de-0000000c", "Uniqueid1"=>"1366616928.17", "Uniqueid2"=>"1366616931.18", "CallerID1"=>"SIP/+498941150126", "CallerID2"=>"+498941150126"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"BRIDGEPEER", :value=>"SIP/placetel.de-0000000d", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Uniqueid"=>"1366616927.16", "CallerIDNum"=>"<unknown>", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="NewAccountCode", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000c", :uniqueid=>"1366616931.18", :accountcode=>"", :oldaccountcode=>""}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Bridge", attributes_hash={:privilege=>"call,all", :bridgestate=>"Link", :bridgetype=>"core", :channel1=>"SIP/placetel.de-0000000d", :channel2=>"SIP/placetel.de-0000000c", :uniqueid1=>"1366616928.17", :uniqueid2=>"1366616931.18", :callerid1=>"SIP/+498941150126", :callerid2=>"+498941150126"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"48F160B7-5174EB5D0005F05E-A74F4700", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Bridge", attributes_hash={:privilege=>"call,all", :bridgestate=>"Link", :bridgetype=>"core", :channel1=>"SIP/placetel.de-0000000d", :channel2=>"SIP/placetel.de-0000000c", :uniqueid1=>"1366616928.17", :uniqueid2=>"1366616931.18", :callerid1=>"SIP/+498941150126", :callerid2=>"+498941150126"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"BRIDGEPEER", "Value"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Joined call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", mixer_name=nil, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"BRIDGEPVTCALLID", "Value"=>"4618534968ae6e00106c2c90285a011b@fpbx.de", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"BRIDGEPEER", :value=>"SIP/placetel.de-0000000c", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Joined call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", mixer_name=nil, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"BRIDGEPVTCALLID", :value=>"48F160B7-5174EB5D0005F05E-A74F4700", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Uniqueid"=>"1366616927.16", "Cause"=>"16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2Fplacetel.de-0000000c%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616927.16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", "Uniqueid"=>"1366616927.16", "CallerIDNum"=>"<unknown>", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"BRIDGEPEER", :value=>"SIP/placetel.de-0000000d", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"BRIDGEPVTCALLID", :value=>"4618534968ae6e00106c2c90285a011b@fpbx.de", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>", :env=>"agi_request%3A%20async%0Aagi_channel%3A%20Bridge%2FSIP%2Fplacetel.de-0000000c%3CZOMBIE%3E%0Aagi_language%3A%20en%0Aagi_type%3A%20NULL%0Aagi_uniqueid%3A%201366616927.16%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20unknown%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%2067%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20unknown%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:51] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"Bridge/SIP/placetel.de-0000000c<ZOMBIE>"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOS
Value: ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSBRIDGED
Value: ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1366616928.17


[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSJITTERBRIDGED
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSLOSSBRIDGED
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSRTTBRIDGED
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOS
Value: ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSBRIDGED
Value: ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSJITTERBRIDGED
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSLOSSBRIDGED
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1366616928.17

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: RTPAUDIOQOSRTTBRIDGED
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1366616928.17

Event: HangupRequest
Privilege: call,all
Channel: SIP/placetel.de-0000000d
Uniqueid: 1366616928.17

Event: Bridge
Privilege: call,all
Bridgestate: Unlink
Bridgetype: core
Channel1: SIP/placetel.de-0000000d
Channel2: SIP/placetel.de-0000000c
Uniqueid1: 1366616928.17
Uniqueid2: 1366616931.18
CallerID1: SIP/+498941150126
CallerID2: +498941150126

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable:
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOS", :value=>"ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSBRIDGED", :value=>"ssrc=68075731;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSJITTER", :value=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSJITTERBRIDGED", :value=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSLOSS", :value=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSLOSSBRIDGED", :value=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSRTT", :value=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSRTTBRIDGED", :value=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="HangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/placetel.de-0000000d", "Channel2"=>"SIP/placetel.de-0000000c", "Uniqueid1"=>"1366616928.17", "Uniqueid2"=>"1366616931.18", "CallerID1"=>"SIP/+498941150126", "CallerID2"=>"+498941150126"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSBRIDGED", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] BRIDGERESULT
Value: SUCCESS
Uniqueid: 1366616928.17

Event: AGIExec
Privilege: agi,all
SubEvent: End
Channel: SIP/placetel.de-0000000d
CommandId: 1351659748
Command: EXEC Bridge "SIP/placetel.de-0000000c"
ResultCode: 200
Result: Success

Event: AsyncAGI
Privilege: agi,all
SubEvent: Exec
Channel: SIP/placetel.de-0000000d
CommandID: 458780d1-79ff-460f-a377-005ca11840c6
Result: 200%20result%3D0%0A

Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: SIP/placetel.de-0000000d

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000d
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1366616928.17

Event: Hangup
Privilege: call,all
Channel: SIP/placetel.de-0000000d
Uniqueid: 1366616928.17
CallerIDNum: SIP/+498941150126
CallerIDName: unknown
ConnectedLineNum: SIP/+498941150126
ConnectedLineName: unknown
AccountCode:
Cause: 16
Cause-txt: Normal Clearing

Event: SoftHangupRequest
Privilege: call,all
Channel: SIP/placetel.de-0000000c
Uniqueid: 1366616931.18
Cause: 16

Event: Newexten
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Context: adhearsion
Extension: h
Priority: 1
Application: AGI
AppData: agi:async
Uniqueid: 1366616931.18

Event: AsyncAGI
Privilege: agi,all
SubEvent: Start
Channel: SIP/placetel.de-0000000c
Env: agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616931.18%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A

Event: AsyncAGI
Privilege: agi,all
SubEvent: End
Channel: SIP/placetel.de-0000000c

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: AGISTATUS
Value: HANGUP
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOS
Value: ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSJITTER
Value: minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSLOSS
Value: minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOSRTT
Value: minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;
Uniqueid: 1366616931.18

Event: VarSet
Privilege: dialplan,all
Channel: SIP/placetel.de-0000000c
Variable: RTPAUDIOQOS
Value: ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000
Uniqueid: 1366616931.18

Event: Hangup
Privilege: call,all
Channel: SIP/placetel.de-0000000c
Uniqueid: 1366616931.18
CallerIDNum: +498941150126
CallerIDName: <unknown>
ConnectedLineNum: <unknown>
ConnectedLineName: <unknown>
AccountCode:
Cause: 0
Cause-txt: Unknown


[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSJITTERBRIDGED", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000d", "CommandId"=>"1351659748", "Command"=>"EXEC Bridge \"SIP/placetel.de-0000000c\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000d", "CommandID"=>"458780d1-79ff-460f-a377-005ca11840c6", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSLOSSBRIDGED", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000d"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "ConnectedLineNum"=>"SIP/+498941150126", "ConnectedLineName"=>"unknown", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOS", :value=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18", "Cause"=>"16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSBRIDGED", :value=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="HangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Bridge", headers={"Privilege"=>"call,all", "Bridgestate"=>"Unlink", "Bridgetype"=>"core", "Channel1"=>"SIP/placetel.de-0000000d", "Channel2"=>"SIP/placetel.de-0000000c", "Uniqueid1"=>"1366616928.17", "Uniqueid2"=>"1366616931.18", "CallerID1"=>"SIP/+498941150126", "CallerID2"=>"+498941150126"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616931.18%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"RTPAUDIOQOSRTTBRIDGED", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSJITTER", :value=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSJITTERBRIDGED", :value=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSLOSS", :value=>"minrxlost=0.000000;maxrxlost=0.00[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSLOSSBRIDGED", :value=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", :uniqueid=0000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"BRIDGERESULT", "Value"=>"SUCCESS", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="HangupRequest", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSRTT", :value=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Bridge", attributes_hash={:privilege=>"call,all", :bridgestate=>"Unlink", :bridgetype=>"core", :channel1=>"SIP/placetel.de-0000000d", :channel2=>"SIP/placetel.de-0000000c", :uniqueid1=>"1366616928.17", :uniqueid2=>"1366616931.18", :callerid1=>"SIP/+498941150126", :callerid2=>"+498941150126"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Bridge", attributes_hash={:privilege=>"call,all", :bridgestate=>"Unlink", :bridgetype=>"core", :channel1=>"SIP/placetel.de-0000000d", :channel2=>"SIP/placetel.de-0000000c", :uniqueid1=>"1366616928.17", :uniqueid2=>"1366616931.18", :callerid1=>"SIP/+498941150126", :callerid2=>"+498941150126"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"RTPAUDIOQOSRTTBRIDGED", :value=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AGIExec", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000d", "CommandId"=>"1351659748", "Command"=>"EXEC Bridge \"SIP/placetel.de-0000000c\"", "ResultCode"=>"200", "Result"=>"Success"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Exec", "Channel"=>"SIP/placetel.de-0000000d", "CommandID"=>"458780d1-79ff-460f-a377-005ca11840c6", "Result"=>"200%20result%3D0%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000d"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000d", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616928.17"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"BRIDGERESULT", :value=>"SUCCESS", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Unjoined call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", mixer_name=nil, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000d", "Uniqueid"=>"1366616928.17", "CallerIDNum"=>"SIP/+498941150126", "CallerIDName"=>"unknown", "ConnectedLineNum"=>"SIP/+498941150126", "ConnectedLineName"=>"unknown", "AccountCode"=>"", "Cause"=>"16", "Cause-txt"=>"Normal Clearing"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="SoftHangupRequest", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18", "Cause"=>"16"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Newexten", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Context"=>"adhearsion", "Extension"=>"h", "Priority"=>"1", "Application"=>"AGI", "AppData"=>"agi:async", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Unjoined call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", mixer_name=nil, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"Start", "Channel"=>"SIP/placetel.de-0000000c", "Env"=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616931.18%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="AsyncAGI", headers={"Privilege"=>"agi,all", "SubEvent"=>"End", "Channel"=>"SIP/placetel.de-0000000c"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"AGISTATUS", "Value"=>"HANGUP", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AGIExec", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/placetel.de-0000000d", :commandid=>"1351659748", :command=>"EXEC Bridge \"SIP/placetel.de-0000000c\"", :resultcode=>"200", :result=>"Success"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::CallController::Dial::Dial: #dial finished. Hanging up 1 outbound calls: b70bd8ad-b1fb-4c60-82e9-18b68de7650a.
[2013-04-22 09:48:55] INFO  Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Hanging up
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Executing command #<Punchblock::Command::Hangup headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSJITTER", "Value"=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSLOSS", "Value"=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOSRTT", "Value"=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="VarSet", headers={"Privilege"=>"dialplan,all", "Channel"=>"SIP/placetel.de-0000000c", "Variable"=>"RTPAUDIOQOS", "Value"=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", "Uniqueid"=>"1366616931.18"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-EVENTS]: #<RubyAMI::Event name="Hangup", headers={"Privilege"=>"call,all", "Channel"=>"SIP/placetel.de-0000000c", "Uniqueid"=>"1366616931.18", "CallerIDNum"=>"+498941150126", "CallerIDName"=>"<unknown>", "ConnectedLineNum"=>"<unknown>", "ConnectedLineName"=>"<unknown>", "AccountCode"=>"", "Cause"=>"0", "Cause-txt"=>"Unknown"}, text_body=nil, events=nil, action=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="SoftHangupRequest", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000c", :uniqueid=>"1366616931.18", :cause=>"16"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Newexten", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :context=>"adhearsion", :extension=>"h", :priority=>"1", :application=>"AGI", :appdata=>"agi:async", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Start", :channel=>"SIP/placetel.de-0000000c", :env=>"agi_request%3A%20async%0Aagi_channel%3A%20SIP%2Fplacetel.de-0000000c%0Aagi_language%3A%20en%0Aagi_type%3A%20SIP%0Aagi_uniqueid%3A%201366616931.18%0Aagi_version%3A%2011.3.0%0Aagi_callerid%3A%20%2B498941150126%0Aagi_calleridname%3A%20unknown%0Aagi_callingpres%3A%200%0Aagi_callingani2%3A%200%0Aagi_callington%3A%200%0Aagi_callingtns%3A%200%0Aagi_dnid%3A%20498912509582%0Aagi_rdnis%3A%20unknown%0Aagi_context%3A%20adhearsion%0Aagi_extension%3A%20h%0Aagi_priority%3A%201%0Aagi_enhanced%3A%200.0%0Aagi_accountcode%3A%20%0Aagi_threadid%3A%204394532864%0A%0A"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"Exec", :channel=>"SIP/placetel.de-0000000d", :commandid=>"458780d1-79ff-460f-a377-005ca11840c6", :result=>"200%20result%3D0%0A"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/placetel.de-0000000d"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000d", :variable=>"AGISTATUS", :value=>"HANGUP", :uniqueid=>"1366616928.17"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Hangup", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000d", :uniqueid=>"1366616928.17", :calleridnum=>"SIP/+498941150126", :calleridname=>"unknown", :connectedlinenum=>"SIP/+498941150126", :connectedlinename=>"unknown", :accountcode=>"", :cause=>"16", :cause_txt=>"Normal Clearing"}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] INFO  Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Call was hung up
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Finished executing controller #<Test call=a5ae7012-3ed4-42c3-95e2-2efeba8f36ce, metadata={}>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="AsyncAGI", attributes_hash={:privilege=>"agi,all", :subevent=>"End", :channel=>"SIP/placetel.de-0000000c"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] INFO  Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Hanging up
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Executing command #<Punchblock::Command::Hangup headers_hash={}, target_call_id=nil, component_id=nil, target_mixer_name=nil, state_name=:new>
[2013-04-22 09:48:55] DEBUG Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Receiving message: #<Punchblock::Event::End reason=:hangup, headers_hash={}, target_call_id="b70bd8ad-b1fb-4c60-82e9-18b68de7650a", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] INFO  Adhearsion::OutboundCall: b70bd8ad-b1fb-4c60-82e9-18b68de7650a: Call ended
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [QUEUE]: #<RubyAMI::Action:0x007f82a6188d48 @name="hangup", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Cause"=>16}, @action_id="75ceb88d-a3d4-4bfa-8d84-fc56adc49723", @response=#<FutureResource:0x007f82a6188a28 @resource_lock=#<Monitor:0x007f82a6188910 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a6188820>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a61887f8 @monitor=#<Monitor:0x007f82a6188910 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a6188820>>, @cond=#<ConditionVariable:0x007f82a6188668 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a6188528>>>>, @response_callback=#<Proc:0x007f82a6188d70@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/call.rb:184>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a61883e8>>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [SEND]: #<RubyAMI::Action:0x007f82a6188d48 @name="hangup", @headers={"Channel"=>"SIP/placetel.de-0000000c", "Cause"=>16}, @action_id="75ceb88d-a3d4-4bfa-8d84-fc56adc49723", @response=#<FutureResource:0x007f82a6188a28 @resource_lock=#<Monitor:0x007f82a6188910 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a6188820>>, @resource_value_blocker=#<MonitorMixin::ConditionVariable:0x007f82a61887f8 @monitor=#<Monitor:0x007f82a6188910 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x007f82a6188820>>, @cond=#<ConditionVariable:0x007f82a6188668 @waiters={}, @waiters_mutex=#<Mutex:0x007f82a6188528>>>>, @response_callback=#<Proc:0x007f82a6188d70@/Users/gersmann/.rvm/gems/ruby-2.0.0-p0@expertiger/gems/punchblock-1.8.2/lib/punchblock/translator/asterisk/call.rb:184>, @state=:new, @events=[], @event_lock=#<Mutex:0x007f82a61883e8>>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [SEND] Action: hangup
ActionID: 75ceb88d-a3d4-4bfa-8d84-fc56adc49723
Channel: SIP/placetel.de-0000000c
Cause: 16


[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] Response: Error
ActionID: 75ceb88d-a3d4-4bfa-8d84-fc56adc49723
Message: No such channel


[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV] #<RubyAMI::Error message="No such channel", headers=>
[2013-04-22 09:48:55] TRACE RubyAMI::Client: [RECV-ACTIONS]: #<RubyAMI::Error message="No such channel", headers=>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"AGISTATUS", :value=>"HANGUP", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOS", :value=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSJITTER", :value=>"minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0.000000;stdevrxjitter=0.000000;reported_minjitter=0.000000;reported_maxjitter=0.000000;reported_avgjitter=0.000000;reported_stdevjitter=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSRTT", :value=>"minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrtt=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOSLOSS", :value=>"minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.000000;stdevrxlost=0.000000;reported_minlost=0.000000;reported_maxlost=0.000000;reported_avglost=0.000000;reported_stdevlost=0.000000;", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="VarSet", attributes_hash={:privilege=>"dialplan,all", :channel=>"SIP/placetel.de-0000000c", :variable=>"RTPAUDIOQOS", :value=>"ssrc=1168581270;themssrc=0;lp=0;rxjitter=0.000000;rxcount=0;txjitter=0.000000;txcount=0;rlp=0;rtt=0.000000", :uniqueid=>"1366616931.18"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::Asterisk::AMI::Event name="Hangup", attributes_hash={:privilege=>"call,all", :channel=>"SIP/placetel.de-0000000c", :uniqueid=>"1366616931.18", :calleridnum=>"+498941150126", :calleridname=>"<unknown>", :connectedlinenum=>"<unknown>", :connectedlinename=>"<unknown>", :accountcode=>"", :cause=>"0", :cause_txt=>"Unknown"}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] DEBUG Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Receiving message: #<Punchblock::Event::End reason=:hangup, headers_hash={}, target_call_id="a5ae7012-3ed4-42c3-95e2-2efeba8f36ce", component_id=nil, target_mixer_name=nil>
[2013-04-22 09:48:55] INFO  Adhearsion::Call: a5ae7012-3ed4-42c3-95e2-2efeba8f36ce: Call ended