Zapotek/arachni — Issue #126: Arachni WebUI dies when generating html report (snow leopard)
Author: rsussland
Created: 2012-01-05 09:14:46+00:00
State: open

Am using experimental updated a few hours ago.

This problem does not occur with the CLI. I was able to scan testfire and generate an html report via the CLI

I did a test run against demo.testfire.net using the web interface. Everything went smoothly and the scan completed, generating an .afr file, except when I tried to generate an html report, at which point the ruby interpreter for arachni_web died.

Am using RVM (local install) 1.9.2-p290:

Here are the log files of arachni_web and rpcd:

ARACHNI_WEB:

rsussland-ltm:~ rsussland$ arachni_web
DataObjects::URI.new with arguments is deprecated, use a Hash of URI components (/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/dm-do-adapter-1.1.0/lib/dm-do-adapter/adapter.rb:231:in `new')
DataObjects::URI.new with arguments is deprecated, use a Hash of URI components (/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/dm-do-adapter-1.1.0/lib/dm-do-adapter/adapter.rb:231:in `new')
DataObjects::URI.new with arguments is deprecated, use a Hash of URI components (/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/dm-do-adapter-1.1.0/lib/dm-do-adapter/adapter.rb:231:in `new')
DataObjects::URI.new with arguments is deprecated, use a Hash of URI components (/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/dm-do-adapter-1.1.0/lib/dm-do-adapter/adapter.rb:231:in `new')
DataObjects::URI.new with arguments is deprecated, use a Hash of URI components (/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/dm-do-adapter-1.1.0/lib/dm-do-adapter/adapter.rb:231:in `new')
== Sinatra/1.3.2 has taken the stage on 4567 for development with backup from Thin
>> Thin web server (v1.3.1 codename Triple Espresso)
>> Maximum connections set to 1024
>> Listening on 0.0.0.0:4567, CTRL+C to stop

[*] Creating HTML report...
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/crypto/rsa_aes_cbc.rb:64: [BUG] Segmentation fault
ruby 1.9.2p290 (2011-07-09 revision 32553) [x86_64-darwin10.8.0]

-- control frame ----------
c:0029 p:---- s:0113 b:0113 l:000112 d:000112 CFUNC :public_encrypt
c:0028 p:0181 s:0109 b:0107 l:000106 d:000106 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/crypto/rsa_aes_cbc.rb:64
c:0027 p:0192 s:0098 b:0098 l:000097 d:000097 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/reports/html.rb:157
c:0026 p:0091 s:0092 b:0092 l:000091 d:000091 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/report_manager.rb:252
c:0025 p:0137 s:0085 b:0085 l:000084 d:000084 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/report_manager.rb:201
c:0024 p:0076 s:0078 b:0077 l:001040 d:000076 LAMBDA /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/server.rb:1084
c:0023 p:---- s:0073 b:0073 l:000072 d:000072 FINISH
c:0022 p:0015 s:0071 b:0071 l:000f18 d:000070 BLOCK /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:115
c:0021 p:---- s:0069 b:0069 l:000068 d:000068 FINISH
c:0020 p:---- s:0067 b:0067 l:000066 d:000066 CFUNC :catch
c:0019 p:0014 s:0063 b:0063 l:000051 d:000062 BLOCK /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:121
c:0018 p:0007 s:0060 b:0060 l:000059 d:000059 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/server.rb:33
c:0017 p:0018 s:0052 b:0052 l:000051 d:000051 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:120
c:0016 p:0012 s:0048 b:0048 l:000d50 d:000047 BLOCK /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:98
c:0015 p:---- s:0046 b:0046 l:000045 d:000045 FINISH
c:0014 p:---- s:0044 b:0044 l:000043 d:000043 CFUNC :call
c:0013 p:0011 s:0041 b:0041 l:000032 d:000040 BLOCK /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:942
c:0012 p:---- s:0038 b:0038 l:000037 d:000037 FINISH
c:0011 p:---- s:0036 b:0036 l:000035 d:000035 CFUNC :each
c:0010 p:0094 s:0033 b:0033 l:000032 d:000032 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:939
c:0009 p:---- s:0028 b:0028 l:000027 d:000027 FINISH
c:0008 p:---- s:0026 b:0026 l:000025 d:000025 CFUNC :run_machine
c:0007 p:0248 s:0023 b:0023 l:000022 d:000022 METHOD /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:179
c:0006 p:0142 s:0016 b:0016 l:002120 d:002120 TOP /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/bin/arachni_web:52
c:0005 p:---- s:0013 b:0013 l:000012 d:000012 FINISH
c:0004 p:---- s:0011 b:0011 l:000010 d:000010 CFUNC :load
c:0003 p:0127 s:0007 b:0007 l:0014f8 d:000b50 EVAL /Users/rsussland/.rvm/gems/ruby-1.9.2-p290/bin/arachni_web:19
c:0002 p:---- s:0004 b:0004 l:000003 d:000003 FINISH
c:0001 p:0000 s:0002 b:0002 l:0014f8 d:0014f8 TOP
---------------------------
-- Ruby level backtrace information ----------------------------------------
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/bin/arachni_web:19:in `

'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/bin/arachni_web:19:in `load'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/bin/arachni_web:52:in `'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:179:in `run'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:179:in `run_machine'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:939:in `run_deferred_callbacks'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:939:in `each'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:942:in `block in run_deferred_callbacks'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/eventmachine-1.0.0.beta.4/lib/eventmachine.rb:942:in `call'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:98:in `block in async_schedule'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:120:in `async_catch_execute'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/server.rb:33:in `async_handle_exception'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:121:in `block in async_catch_execute'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:121:in `catch'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/async_sinatra-0.5.0/lib/sinatra/async.rb:115:in `block in async_runner'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/server.rb:1084:in `block in '
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/report_manager.rb:201:in `get'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/ui/web/report_manager.rb:252:in `convert'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/reports/html.rb:157:in `run'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/crypto/rsa_aes_cbc.rb:64:in `encrypt'
/Users/rsussland/.rvm/gems/ruby-1.9.2-p290/gems/arachni-0.4/lib/arachni/crypto/rsa_aes_cbc.rb:64:in `public_encrypt'

-- C level backtrace information -------------------------------------------

[NOTE]
You may have encountered a bug in the Ruby interpreter or extension libraries.
Bug reports are welcome.
For details: http://www.ruby-lang.org/bugreport.html

Abort trap

---------------------------

RPC SERVER:

rsussland-ltm:~ rsussland$ sudo -E arachni_rpcd
Password:
Arachni - Web Application Security Scanner Framework
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:17:32.238057 #525] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.238431 #525] INFO -- System: Listening on localhost:20693
Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:17:32.247588 #526] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.247950 #526] INFO -- System: Listening on localhost:35233
Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:17:32.277057 #527] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.277478 #527] INFO -- System: Listening on localhost:39949
Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:17:32.288796 #528] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.289195 #528] INFO -- System: Listening on localhost:3908
Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:17:32.331487 #529] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.331847 #529] INFO -- System: Listening on localhost:41552
Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:17:32.340181 #530] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.340518 #530] INFO -- System: Listening on localhost:7135
I, [2012-01-05T00:17:32.383622 #493] INFO -- System: RPC Server started.
I, [2012-01-05T00:17:32.383812 #493] INFO -- System: Listening on localhost:7331
I, [2012-01-05T00:17:56.172445 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:17:56.216415 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:18:11.595579 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:18:11.596563 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:18:18.445681 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:18:18.446424 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:18:23.003927 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:18:25.040838 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:18:25.047291 #493] INFO -- Call: node.neighbours [127.0.0.1]
I, [2012-01-05T00:18:25.050425 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:18:31.379068 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:18:31.379947 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:18:39.528459 #493] INFO -- Call: dispatcher.dispatch [127.0.0.1]
Arachni - Web Application Security Scanner Framework v0.4 [0.2.5]
Author: Tasos "Zapotek" Laskos

(With the support of the community and the Arachni Team.)

Website: http://github.com/Zapotek/arachni
Documentation: http://github.com/Zapotek/arachni/wiki

I, [2012-01-05T00:18:39.555903 #525] INFO -- Call: opts.set [127.0.0.1]
I, [2012-01-05T00:18:39.556076 #887] INFO -- System: RPC Server started.
I, [2012-01-05T00:18:39.556376 #887] INFO -- System: Listening on localhost:53308
I, [2012-01-05T00:18:39.567786 #525] INFO -- Call: plugins.load [127.0.0.1]
I, [2012-01-05T00:18:39.594130 #525] INFO -- Call: modules.load [127.0.0.1]
I, [2012-01-05T00:18:39.685557 #525] INFO -- Call: framework.run [127.0.0.1]
I, [2012-01-05T00:18:39.735605 #525] INFO -- Call: framework.paused? [127.0.0.1]
I, [2012-01-05T00:18:39.802374 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:18:44.802678 #525] INFO -- Call: framework.progress_data [127.0.0.1]
encoding error : output conversion failed due to conv error, bytes 0x92 0x73 0x20 0x62
I/O error : encoder error
I, [2012-01-05T00:18:49.797833 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:18:54.797669 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:18:56.165877 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:18:56.178389 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:18:59.797809 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:04.798044 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:09.799319 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:14.797644 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:19.798000 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:24.798017 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:29.798504 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:34.800970 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:39.802259 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:44.797952 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:49.800327 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:54.798862 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:19:56.165950 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:19:56.180677 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:19:59.798921 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:04.803125 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:09.798696 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:14.804325 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:19.799207 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:24.801312 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:29.799784 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:34.799679 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:39.801114 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:44.799842 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:49.801048 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:54.800580 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:20:56.166594 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:20:56.175034 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:20:59.864195 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:04.800678 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:09.801406 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:14.879479 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:19.801404 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:24.801339 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:29.889259 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:34.809272 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:39.801437 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:44.801245 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:49.802690 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:54.802188 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:21:56.167466 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:21:56.176506 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:21:59.802028 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:04.802375 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:09.804215 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:14.802445 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:19.803129 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:24.803043 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:29.802796 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:34.803195 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:39.803571 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:44.804896 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:49.804147 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:54.804148 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:22:56.168660 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:22:56.177478 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:22:59.889296 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:04.804520 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:09.829451 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:14.804594 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:19.805354 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:24.805663 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:29.805119 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:34.805299 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:39.806974 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:44.805330 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:49.805681 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:54.805956 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:23:56.171797 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:23:56.180429 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:23:59.806529 #525] INFO -- Call: framework.progress_data [127.0.0.1]
encoding error : output conversion failed due to conv error, bytes 0x92 0x73 0x20 0x62
I/O error : encoder error
I, [2012-01-05T00:24:04.806364 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:09.807076 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:14.807330 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:19.844887 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:24.807206 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:29.808234 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:34.807015 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:39.807038 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:44.807963 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:49.809525 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:54.807561 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:24:56.170366 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:24:56.180874 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:24:59.901930 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:04.807461 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:09.807658 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:14.812131 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:19.813160 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:24.808456 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:29.808492 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:34.809698 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:39.809162 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:44.813947 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:49.812384 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:54.811343 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:25:56.172009 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:25:57.818532 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:25:59.812190 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:04.916674 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:09.816359 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:14.810242 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:19.838959 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:24.810432 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:29.812905 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:34.889998 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:39.817753 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:44.921041 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:49.813356 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:54.813769 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:26:56.172058 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:26:58.015804 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:26:59.812909 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:04.813130 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:09.812885 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:14.816212 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:19.814100 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:24.813471 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:29.813566 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:34.813735 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:39.813860 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:44.816613 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:49.815094 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:50.171319 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:27:50.171760 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:27:52.520346 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:27:56.172953 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:27:56.181243 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:27:59.126380 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:27:59.126860 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:27:59.136840 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:03.258056 #525] INFO -- Call: framework.paused? [127.0.0.1]
I, [2012-01-05T00:28:03.307688 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:08.310505 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:13.310877 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:18.306417 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:23.306541 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:28.306733 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:33.306798 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:38.308112 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:43.327500 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:48.308950 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:53.308820 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:28:56.172910 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:28:56.183089 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:28:58.307728 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:03.308155 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:08.309856 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:13.309582 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:18.308177 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:23.308883 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:28.313205 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:33.410258 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:38.308753 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:43.310921 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:48.310345 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:53.309545 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:29:56.173997 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:29:56.287943 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:29:58.309366 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:03.311169 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:08.310724 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:13.311723 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:18.311291 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:23.311731 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:28.311376 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:33.311644 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:38.314968 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:43.314010 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:48.312397 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:53.313132 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:30:56.174799 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:30:56.183278 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:30:58.312784 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:03.313241 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:08.313260 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:13.313224 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:18.313485 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:23.313476 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:28.313791 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:33.313876 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:38.317134 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:43.317148 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:48.345352 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:53.314563 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:31:56.175624 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:31:56.185845 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:31:58.317037 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:03.314955 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:08.315038 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:13.315453 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:18.315429 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:23.423695 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:28.317671 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:33.316208 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:38.316069 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:43.321157 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:48.317171 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:53.350790 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:32:56.176021 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:32:56.184612 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:32:58.317579 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:03.316778 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:08.340976 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:13.317379 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:18.322231 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:23.317579 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:28.317944 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:33.317982 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:38.317938 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:43.318750 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:48.318763 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:53.318538 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:33:56.175786 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:33:56.183786 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:33:58.320538 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:03.327589 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:08.319021 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:13.323060 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:18.320593 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:23.319843 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:28.319554 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:33.319801 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:38.320002 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:43.320232 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:48.320803 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:53.320623 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:34:56.177523 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:34:58.505827 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:34:58.506272 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:03.324659 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:08.324639 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:13.325414 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:18.322412 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:23.325267 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:28.324982 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:31.296357 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:35:31.296762 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:35:31.305251 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:40.788852 #493] INFO -- Call: dispatcher.alive? [127.0.0.1]
I, [2012-01-05T00:35:40.789277 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:35:40.797484 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:45.141786 #525] INFO -- Call: framework.paused? [127.0.0.1]
I, [2012-01-05T00:35:45.193525 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:50.191476 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:55.193361 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:35:56.178560 #493] INFO -- Call: dispatcher.stats [127.0.0.1]
I, [2012-01-05T00:35:57.309412 #525] INFO -- Call: framework.busy? [127.0.0.1]
I, [2012-01-05T00:35:57.314033 #525] INFO -- Call: framework.clean_up! [127.0.0.1]
I, [2012-01-05T00:35:57.840562 #525] INFO -- Call: framework.auditstore [127.0.0.1]
I, [2012-01-05T00:36:00.360574 #525] INFO -- Call: framework.progress_data [127.0.0.1]
I, [2012-01-05T00:36:03.330007 #525] INFO -- Call: service.shutdown! [127.0.0.1]
I, [2012-01-05T00:36:03.330147 #525] INFO -- System: Shutting down in 2 seconds...
I, [2012-01-05T00:36:05.193478 #525] INFO -- Call: framework.progress_data [127.0.0.1]

... curious if you making an encryption call when going from .afr to cbc via the web? Seems odd.