Aptana Studioの練習 ActiverScaffoldの動作解析(Search編)

Aptana Studioの練習 ActiverScaffoldの動作解析(Search編)

ふっと思い立ち、今開発中のActiveScaffoldのデバッグ途中のThread階層を晒す。
Aptana Studioの「デバッグ」ビューの画面です。

実施した操作

ActiveScaffoldにて1組のモデル、コントローラを作成。
デバッグモードでdevelopment、mongrelサーバを起動し、ブラウザから該当モデルのURLにアクセス。
単純にlistのアクションが完了する。
そこで、デバッガ上でコントローラーのファイル先頭から

class StoreController < ApplicationController
  active_scaffold :store
  layout "layout"

ブレークポイントはactive_scaffold :storeの行に配置。
さらに今度は「sid1="-700"」という、テストレコードに対して1件のみヒットする条件でSearchボタンをクリック。
Search開始。

デバッガ上での操作

Search実行後、ちゃんと例のブレークポイントの行で処理が停止する。
そこからステップオーバーを2回実行。
layoutの行をステップオーバーした直後に以下のThreadが出て階層が一気に増えて、dependencies.rb:343で再度止まる。

ここで既に私の素人知識では???。「何故いきなり飛んだのか?」「どこに飛んだのか?」「何がどう状態が動いたのか?」さっぱり判らない。いつもですとここで諦めてました。
でも今夜はもう少し追ってみます。実は、新しい機能として「直前のSearch条件をcookieか何かに保持し、直後にCSV出力のアクションが実行されたらそのSearch条件を込みで絞込み出力させたい」というのが出てきたので、どのように条件を保持しているのか知りたかったのです。

Ruby Thread - 178 (Step end at C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:343)	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:343	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:202	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:94	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:248	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:452	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/dependencies.rb:464	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/inflector.rb:250	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/inflector.rb:250	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/activesupport-1.4.4/lib/active_support/core_ext/string/inflections.rb:148	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/actionpack-1.13.5/lib/action_controller/routing.rb:1317	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/rails-1.2.5/lib/dispatcher.rb:40	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel/rails.rb:78	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel/rails.rb:76	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel.rb:618	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel.rb:617	
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel.rb:736	

「デバッグ」ビューの中の上記の各行を上下に選択しなおすと、「変数」ビューやプログラムソースのビューの状態が変わります。
で、このパスと行番号の羅列が、下から上へのソースの呼び出し順であることに『やっと気が付く』。あるスレッドのスタックトレース情報ってことですか?なるほど。
以前はこの状態になっても、適当に触って、適当にステップを進めるとあっちゃこっちゃに飛んでさっぱり動きを追えてる気がしませんでした。今回はいけるかも?
 
で、冷静に見ると、

  1. activesupport ???
  2. actionpack ルーティング解決
  3. rails Railsアプリのディスパッチ処理
  4. mongrel Webサーバ側の処理(リクエスト、レスポンス)

の4階層の処理ですね。
なんとなくActiveScaffold以前の処理の処理中のような気がしてきました。
下のほうはわかりそうだ。

あと一つ補足すると、ブレーク停止中の各ソース間でジャンプした位置というのは矢印で表示されているのですが、

  • 現在停止中の最新の位置 青矢印、1つだけ、一番上の行のみ
  • それ以前の各メソッド間でのジャンプ位置 青白矢印、それ以外

という表示ルールがあることにも気が付いた。

Mongrel
	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel.rb:617	

この階層で、

              # Process each handler in registered order until we run out or one finalizes the response.
              handlers.each do |handler|
                handler.process(request, response)
                break if response.done or client.closed?
              end

という処理がある。
を、request、responseとかそれらしい変数が渡されている。
ということで「変数」ビューにて変数内容をチェック。
requestオブジェクトの内容

request	#<Mongrel::HttpRequest:0x5645078>	
	@body	#<StringIO:0x5645064>	
	@dispatchers	Array[0]	
	@params	Mongrel::HttpParams[25]	
		'SERVER_NAME'	"localhost"	
		'HTTP_X_PROTOTYPE_VERSION'	"1.5.0"	
		'PATH_INFO'	"/store/update_table"	
		'HTTP_ACCEPT_ENCODING'	"gzip,deflate"	
		'HTTP_USER_AGENT'	"Mozilla/5.0 (Windows; U; Windows NT 5.1; ja; rv:1.9.0.5) Gecko/2008120122 Firefox/3.0.5"	
		'SCRIPT_NAME'	"/"	
		'SERVER_PROTOCOL'	"HTTP/1.1"	
		'HTTP_ACCEPT_LANGUAGE'	"ja,en-us;q=0.7,en;q=0.3"	
		'HTTP_HOST'	"localhost:3000"	
		'REMOTE_ADDR'	"127.0.0.1"	
		'SERVER_SOFTWARE'	"Mongrel 1.0.1"	
		'HTTP_KEEP_ALIVE'	"300"	
		'REQUEST_PATH'	"/store/update_table"	
		'HTTP_REFERER'	"http://localhost:3000/store"	
		'HTTP_COOKIE'	"_store_session_id=e2b5dac1930bbfb837cf39c133acb657"	
		'HTTP_ACCEPT_CHARSET'	"Shift_JIS,utf-8;q=0.7,*;q=0.7"	
		'HTTP_VERSION'	"HTTP/1.1"	
		'REQUEST_URI'	"/store/update_table?search%5Bid%5D=&search%5Bkanban_id%5D=&search%5Bactive%5D=&search%5Bstep%5D=&search%5Bupdated_at%5D=&search%5Bcreated_at%5D=&search%5Bhinban%5D=&search%5Bseirino%5D=&search%5Bh%5D=&search%5Bs%5D=&search%5Bsid2%5D=&search%5Bsdt2%5D=&search%5Bsid1%5D=701-&search%5Bsdt1%5D=&search%5Bsid0%5D=&search%5Bsdt0%5D=&search%5Bstorehinban%5D=&search%5Bstoreno%5D=&search%5Blineno%5D=&commit=Search"	
		'SERVER_PORT'	"3000"	
		'GATEWAY_INTERFACE'	"CGI/1.2"	
		'QUERY_STRING'	"search%5Bid%5D=&search%5Bkanban_id%5D=&search%5Bactive%5D=&search%5Bstep%5D=&search%5Bupdated_at%5D=&search%5Bcreated_at%5D=&search%5Bhinban%5D=&search%5Bseirino%5D=&search%5Bh%5D=&search%5Bs%5D=&search%5Bsid2%5D=&search%5Bsdt2%5D=&search%5Bsid1%5D=701-&search%5Bsdt1%5D=&search%5Bsid0%5D=&search%5Bsdt0%5D=&search%5Bstorehinban%5D=&search%5Bstoreno%5D=&search%5Blineno%5D=&commit=Search"	
		'HTTP_ACCEPT'	"text/javascript, text/html, application/xml, text/xml, */*"	
		'HTTP_X_REQUESTED_WITH'	"XMLHttpRequest"	
		'HTTP_CONNECTION'	"keep-alive"	
		'REQUEST_METHOD'	"GET"	
	@socket	#<TCPSocket:0x5657ebc>	

ふむ、これによって@paramsの'QUERY_STRING'に検索条件が入ってることが判明。しかし他の検索入力は空で実行したが全部パラメータ渡しされてるなあ。search%5B○○%5D=&ってなってるけど、つまりsearch[○○]=△△&search[○○]=△△…っというパラメータということですか。○○がカラム名、△△が検索条件キー。
まずcookieに保存する第1候補として、このrequest.@params['QUERY_STRING']が上がりました。

MongrelのCGIラッパー

でも、更に先が。
以下のスタック階層を見るとcgiオブジェクト(Mongrel::CGIWrapper)が頑張ってくれているようです。

	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/mongrel-1.0.1-mswin32/lib/mongrel/rails.rb:76	
cgi	#<Mongrel::CGIWrapper:0x5644df8>	
	@args	nil	
	@cookies	Hash[1]	
		'_store_session_id'	_store_session_id=e2b5dac1930bbfb837cf39c133acb657; path=	
			@_dc_obj	Array[1]	
				[0]	"e2b5dac1930bbfb837cf39c133acb657"	
			@domain	nil	
			@expires	nil	
			@name	"_store_session_id"	
			@path	""	
			@secure	nil	
			@value	Array[1]	
				[0]	"e2b5dac1930bbfb837cf39c133acb657"	
	@default_really_final	nil	
	@handler	#<Mongrel::Rails::RailsHandler:0x53db0bc>	
		@active_request_path	"/store/update_table"	
		@files	#<Mongrel::DirHandler:0x53db058>	
		@guard	#<Mutex:0x53db044>	
		@listener	#<Mongrel::HttpServer:0x3eb2730>	
		@tick	Sun Feb 01 01:26:49 +0900 2009	
	@head	Hash[0]	
	@input	#<StringIO:0x5645064>	
	@multipart	nil	
	@out_called	nil	
	@output_cookies	nil	
	@output_hidden	nil	
	@params	Hash[20]	
		'search[s]'	Array[0]	
		'search[created_at]'	Array[0]	
		'commit'	Array[1]	
			[0]	"Search"	
		'search[h]'	Array[0]	
		'search[kanban_id]'	Array[0]	
		'search[storeno]'	Array[0]	
		'search[id]'	Array[0]	
		'search[sdt2]'	Array[0]	
		'search[seirino]'	Array[0]	
		'search[storehinban]'	Array[0]	
		'search[sdt1]'	Array[0]	
		'search[sid2]'	Array[0]	
		'search[sdt0]'	Array[0]	
		'search[sid1]'	Array[0]	
		'search[sid0]'	Array[0]	
		'search[hinban]'	Array[0]	
		'search[updated_at]'	Array[0]	
		'search[step]'	Array[0]	
		'search[active]'	Array[0]	
		'search[lineno]'	Array[0]	
	@request	#<Mongrel::HttpRequest:0x5645078>	
	@response	#<Mongrel::HttpResponse:0x564508c>	

なので、これも使うか期待しましょう。でも余計な検索条件が正規化された状態で持つことができればもっと良い気がする。
でもそれだとSQL文に近いからセキュリティ的に良くない?

いやまて、sid1=-700で検索したはず…Array[0]って空ってことだよなあ。
器が準備されただけ?
…先に進みます。

actionpack

一気にactionpackまで。そこまでは余り変化が無かったのですが。

	C:/InstantRails/ruby/lib/ruby/gems/1.8/gems/actionpack-1.13.5/lib/action_controller/routing.rb:1317	

actionpackに移って、から、@cgiは渡されずにrequestのみ。paramsの内容もディスパッチャのルート整理できれいにされてるし。
今度のrequestオブジェクトはActionController::CgiRequestだそうです。

#<ActionController::CgiRequest:0x563c4a0 @cgi=#<Mongrel::CGIWrapper:0x5644df8 @out_called=false, @multipart=false, @handler=#<Mongrel::Rails::RailsHandler:0x53db0bc @guard=#<Mutex:0x53db044>, @files=#<Mongrel::DirHandler:0x53db058 @path="C:/InstantRails/rails_apps/store/public", @default_content_type="application/octet-stream", @index_html="index.html", @listing_allowed=false>, @active_request_path="/store/update_table", @listener=#<Mongrel::HttpServer:0x3eb2730 @socket=#<TCPServer:0x3eb26f4>, @acceptor=#<Thread:0x51ff70c sleep>, @workers=#<ThreadGroup:0x3eb26a4>, @port=3000, @classifier={"/"=>[#<Mongrel::Rails::RailsHandler:0x53db0bc ...>]}, @death_time=60, @num_processors=1024, @timeout=0, @host="0.0.0.0">, @tick=Sun Feb 01 01:26:49 +0900 2009>, @output_cookies=nil, @head={}, @params={"search[s]"=>[], "search[created_at]"=>[], "commit"=>["Search"], "search[h]"=>[], "search[kanban_id]"=>[], "search[storeno]"=>[], "search[id]"=>[], "search[sdt2]"=>[], "search[seirino]"=>[], "search[storehinban]"=>[], "search[sdt1]"=>[], "search[sid2]"=>[], "search[sdt0]"=>[], "search[sid1]"=>[], "search[sid0]"=>[], "search[hinban]"=>[], "search[updated_at]"=>[], "search[step]"=>[], "search[active]"=>[], "search[lineno]"=>[]}, @response=#<Mongrel::HttpResponse:0x564508c @body_sent=false, @body=#<StringIO:0x5645028>, @socket=#<TCPSocket:0x5657ebc>, @status=404, @status_sent=false, @header_sent=false, @header=#<Mongrel::HeaderOut:0x5644fd8 @allowed_duplicates={"WWW-Authenticate"=>true, "Set-Cookie2"=>true, "Set-Cookie"=>true, "Warning"=>true}, @out=#<StringIO:0x5645000>, @sent={"Date"=>true}>>, @output_hidden=nil, @request=#<Mongrel::HttpRequest:0x5645078 @body=#<StringIO:0x5645064>, @socket=#<TCPSocket:0x5657ebc>, @params={"SERVER_NAME"=>"localhost", "HTTP_X_PROTOTYPE_VERSION"=>"1.5.0", "PATH_INFO"=>"/store/update_table", "HTTP_ACCEPT_ENCODING"=>"gzip,deflate", "HTTP_USER_AGENT"=>"Mozilla/5.0 (Windows; U; Windows NT 5.1; ja; rv:1.9.0.5) Gecko/2008120122 Firefox/3.0.5", "SCRIPT_NAME"=>"/", "SERVER_PROTOCOL"=>"HTTP/1.1", "HTTP_ACCEPT_LANGUAGE"=>"ja,en-us;q=0.7,en;q=0.3", "HTTP_HOST"=>"localhost:3000", "REMOTE_ADDR"=>"127.0.0.1", "SERVER_SOFTWARE"=>"Mongrel 1.0.1", "HTTP_KEEP_ALIVE"=>"300", "REQUEST_PATH"=>"/store/update_table", "HTTP_REFERER"=>"http://localhost:3000/store", "HTTP_COOKIE"=>"_store_session_id=e2b5dac1930bbfb837cf39c133acb657", "HTTP_ACCEPT_CHARSET"=>"Shift_JIS,utf-8;q=0.7,*;q=0.7", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_URI"=>"/store/update_table?search%5Bid%5D=&search%5Bkanban_id%5D=&search%5Bactive%5D=&search%5Bstep%5D=&search%5Bupdated_at%5D=&search%5Bcreated_at%5D=&search%5Bhinban%5D=&search%5Bseirino%5D=&search%5Bh%5D=&search%5Bs%5D=&search%5Bsid2%5D=&search%5Bsdt2%5D=&search%5Bsid1%5D=701-&search%5Bsdt1%5D=&search%5Bsid0%5D=&search%5Bsdt0%5D=&search%5Bstorehinban%5D=&search%5Bstoreno%5D=&search%5Blineno%5D=&commit=Search", "SERVER_PORT"=>"3000", "GATEWAY_INTERFACE"=>"CGI/1.2", "QUERY_STRING"=>"search%5Bid%5D=&search%5Bkanban_id%5D=&search%5Bactive%5D=&search%5Bstep%5D=&search%5Bupdated_at%5D=&search%5Bcreated_at%5D=&search%5Bhinban%5D=&search%5Bseirino%5D=&search%5Bh%5D=&search%5Bs%5D=&search%5Bsid2%5D=&search%5Bsdt2%5D=&search%5Bsid1%5D=701-&search%5Bsdt1%5D=&search%5Bsid0%5D=&search%5Bsdt0%5D=&search%5Bstorehinban%5D=&search%5Bstoreno%5D=&search%5Blineno%5D=&commit=Search", "HTTP_ACCEPT"=>"text/javascript, text/html, application/xml, text/xml, */*", "HTTP_X_REQUESTED_WITH"=>"XMLHttpRequest", "HTTP_CONNECTION"=>"keep-alive", "REQUEST_METHOD"=>"GET"}, @dispatchers=[]>, @default_really_final=false, @cookies={"_store_session_id"=>["e2b5dac1930bbfb837cf39c133acb657"]}, @input=#<StringIO:0x5645064>, @args=nil>, @symbolized_path_parameters=nil, @env={"SERVER_NAME"=>"localhost", "HTTP_X_PROTOTYPE_VERSION"=>"1.5.0", "PATH_INFO"=>"/store/update_table", "HTTP_ACCEPT_ENCODING"=>"gzip,deflate", "HTTP_USER_AGENT"=>"Mozilla/5.0 (Windows; U; Windows NT 5.1; ja; rv:1.9.0.5) Gecko/2008120122 Firefox/3.0.5", "SCRIPT_NAME"=>"/", "SERVER_PROTOCOL"=>"HTTP/1.1", "HTTP_ACCEPT_LANGUAGE"=>"ja,en-us;q=0.7,en;q=0.3", "HTTP_HOST"=>"localhost:3000", "REMOTE_ADDR"=>"127.0.0.1", "SERVER_SOFTWARE"=>"Mongrel 1.0.1", "HTTP_KEEP_ALIVE"=>"300", "REQUEST_PATH"=>"/store/update_table", "HTTP_REFERER"=>"http://localhost:3000/store", "HTTP_COOKIE"=>"_store_session_id=e2b5dac1930bbfb837cf39c133acb657", "HTTP_ACCEPT_CHARSET"=>"Shift_JIS,utf-8;q=0.7,*;q=0.7", "HTTP_VERSION"=>"HTTP/1.1", "REQUEST_URI"=>"/store/update_table?search%5Bid%5D=&search%5Bkanban_id%5D=&search%5Bactive%5D=&search%5Bstep%5D=&search%5Bupdated_at%5D=&search%5Bcreated_at%5D=&search%5Bhinban%5D=&search%5Bseirino%5D=&search%5Bh%5D=&search%5Bs%5D=&search%5Bsid2%5D=&search%5Bsdt2%5D=&search%5Bsid1%5D=701-&search%5Bsdt1%5D=&search%5Bsid0%5D=&search%5Bsdt0%5D=&search%5Bstorehinban%5D=&search%5Bstoreno%5D=&search%5Blineno%5D=&commit=Search", "SERVER_PORT"=>"3000", "GATEWAY_INTERFACE"=>"CGI/1.2", "QUERY_STRING"=>"search%5Bid%5D=&search%5Bkanban_id%5D=&search%5Bactive%5D=&search%5Bstep%5D=&search%5Bupdated_at%5D=&search%5Bcreated_at%5D=&search%5Bhinban%5D=&search%5Bseirino%5D=&search%5Bh%5D=&search%5Bs%5D=&search%5Bsid2%5D=&search%5Bsdt2%5D=&search%5Bsid1%5D=701-&search%5Bsdt1%5D=&search%5Bsid0%5D=&search%5Bsdt0%5D=&search%5Bstorehinban%5D=&search%5Bstoreno%5D=&search%5Blineno%5D=&commit=Search", "HTTP_ACCEPT"=>"text/javascript, text/html, application/xml, text/xml, */*", "HTTP_X_REQUESTED_WITH"=>"XMLHttpRequest", "HTTP_CONNECTION"=>"keep-alive", "REQUEST_METHOD"=>"GET"}, @query_parameters={"commit"=>"Search", "search"=>{"updated_at"=>nil, "step"=>nil, "sdt0"=>nil, "sid0"=>nil, "hinban"=>nil, "storehinban"=>nil, "sdt1"=>nil, "sid1"=>"701-", "kanban_id"=>nil, "sdt2"=>nil, "sid2"=>nil, "id"=>nil, "storeno"=>nil, "s"=>nil, "h"=>nil, "seirino"=>nil, "lineno"=>nil, "created_at"=>nil, "active"=>nil}}, @path_parameters={"action"=>"update_table", "controller"=>"store"}, @request_parameters={"commit"=>"Search", "search"=>{"updated_at"=>nil, "step"=>nil, "sdt0"=>nil, "sid0"=>nil, "hinban"=>nil, "storehinban"=>nil, "sdt1"=>nil, "sid1"=>"701-", "kanban_id"=>nil, "sdt2"=>nil, "sid2"=>nil, "id"=>nil, "storeno"=>nil, "s"=>nil, "h"=>nil, "seirino"=>nil, "lineno"=>nil, "created_at"=>nil, "active"=>nil}}, @cookie_only=nil, @request_method=:get, @parameters=nil, @content_type=nil, @session_options={:tmpdir=>"C:/InstantRails/rails_apps/store/tmp/sessions/", :database_manager=>CGI::Session::PStore, :session_path=>"/", :prefix=>"ruby_sess."}>

あ、勘違いです。cgiオブジェクト、上を見るとあるようです。
でも @query_parameters というのも出来てます。Webの世界からだいぶRubyな世界の表現になってますね。これがSQLに変換されるのはいつの日か…

で、次の階層を見ると、どうもactivesupportが呼び出されて、StoreControllerの定数を定義?(constantize)
その次を見てもなんとなく、これから上位はmethod_missingから動的にControllerクラスを読み込もうとする処理で今回のSearchはこの処理の後っぽいと感じました。

なので、ここでactionpackのactioncontrollerの箇所でブレークポイントを置いて進もうとすると…いかん、AptanaStudioが固まった(汗)長時間リクエストをひっぱたしなー(小1時間くらい?)。これは再起動ですね。
Aptanaでは、javaw.exeやruby.exeのプロセスが残ってしまう落ちたを時々しますから、再度実行して起動しない場合はこの辺のプロセスが悪さしてないか確認ですね。

(馬鹿長いくせに続く)