/lib/thingfish/daemon.rb

https://bitbucket.org/laika/thingfish · Ruby · 648 lines · 417 code · 119 blank · 112 comment · 28 complexity · 2610c3b1ee8a7df57f4783ad578db54f MD5 · raw file

  1. #!/usr/bin/env ruby
  2. require 'socket'
  3. require 'uuidtools'
  4. require 'logger'
  5. require 'sync'
  6. require 'thingfish'
  7. require 'thingfish/constants'
  8. require 'thingfish/config'
  9. require 'thingfish/connectionmanager'
  10. require 'thingfish/exceptions'
  11. require 'thingfish/mixins'
  12. require 'thingfish/filestore'
  13. require 'thingfish/metastore'
  14. require 'thingfish/handler'
  15. require 'thingfish/request'
  16. require 'thingfish/response'
  17. # ThingFish daemon class
  18. #
  19. # == Synopsis
  20. #
  21. # require 'thingfish/daemon'
  22. # require 'thingfish/config'
  23. #
  24. # config = ThingFish::Config.load( "thingfish.conf" )
  25. # server = ThingFish::Daemon.new( config )
  26. #
  27. # accepter = server.run # => #<Thread:0x142317c sleep>
  28. #
  29. # Signal.trap( "INT" ) { server.shutdown("Interrupted") }
  30. # Signal.trap( "TERM" ) { server.shutdown("Terminated") }
  31. #
  32. # accepter.join
  33. #
  34. # == Version
  35. #
  36. # $Id$
  37. #
  38. # == Authors
  39. #
  40. # * Michael Granger <ged@FaerieMUD.org>
  41. # * Mahlon E. Smith <mahlon@martini.nu>
  42. #
  43. # :include: LICENSE
  44. #
  45. #---
  46. #
  47. # Please see the file LICENSE in the top-level directory for licensing details.
  48. #
  49. class ThingFish::Daemon
  50. include ThingFish::Constants,
  51. ThingFish::Loggable,
  52. ThingFish::Daemonizable,
  53. ThingFish::ResourceLoader,
  54. ThingFish::HtmlInspectableObject
  55. ### An exception class for signalling daemon threads that they need to shut down
  56. class Shutdown < Exception; end
  57. #################################################################
  58. ### C L A S S M E T H O D S
  59. #################################################################
  60. ### Parse the command line arguments and return an options struct
  61. def self::parse_args( args )
  62. require 'optparse'
  63. progname = Pathname.new( $0 )
  64. opts = self.get_default_options
  65. oparser = OptionParser.new do |oparser|
  66. oparser.accept( Pathname ) {|path| Pathname(path) }
  67. oparser.banner = "Usage: #{progname.basename} OPTIONS"
  68. oparser.separator ''
  69. oparser.separator 'Daemon Options:'
  70. oparser.on( '--config-file=STRING', '-f STRING', Pathname,
  71. "Specify a config file to use." ) do |cfg|
  72. opts.configfile = cfg
  73. end
  74. oparser.separator ''
  75. oparser.separator 'Other Options:'
  76. oparser.on_tail( '--help', '-h', FalseClass, "Display this help." ) do
  77. $stderr.puts oparser
  78. exit!
  79. end
  80. # Another typical switch to print the version.
  81. oparser.on_tail( "--version", "Show ThingFish version" ) do
  82. $stderr.puts ThingFish.version_string( true )
  83. exit!
  84. end
  85. end
  86. oparser.parse!
  87. return opts
  88. end
  89. ### Get the options struct filled with defaults
  90. def self::get_default_options
  91. require 'ostruct'
  92. options = OpenStruct.new
  93. return options
  94. end
  95. ### Create an instance, configure it with command line +args+, and start it.
  96. def self::run( args )
  97. options = self.parse_args( args )
  98. config = if options.configfile
  99. ThingFish::Config.load( options.configfile )
  100. else
  101. ThingFish::Config.new
  102. end
  103. ThingFish::Daemon.new( config ).start
  104. end
  105. #################################################################
  106. ### I N S T A N C E M E T H O D S
  107. #################################################################
  108. ### Create a new ThingFish daemon object that will listen on the specified +ip+
  109. ### and +port+.
  110. def initialize( config=nil )
  111. @config = config || ThingFish::Config.new
  112. @config.install
  113. @running = false
  114. # Load the profiler library if profiling is enabled
  115. @mutex = Sync.new
  116. @have_profiling = false
  117. @profile_connections = false
  118. if @config.profiling.enabled?
  119. @have_profiling = self.load_profiler
  120. if @config.profiling.connection_enabled?
  121. @profile_connections = true
  122. self.log.info "Enabled connection profiling for connections from localhost"
  123. end
  124. end
  125. # Load plugins for filestore, metastore, filters, and handlers
  126. @config.setup_data_directories
  127. @filestore = @config.create_configured_filestore
  128. @metastore = @config.create_configured_metastore
  129. @filters = @config.create_configured_filters
  130. @urimap = @config.create_configured_urimap
  131. # Run handler startup actions
  132. @urimap.handlers.each do |handler|
  133. self.log.debug " starting %p" % [ handler ]
  134. handler.on_startup( self )
  135. end
  136. @connection_threads = ThreadGroup.new
  137. @supervisor = nil
  138. @listener = TCPServer.new( @config.ip, @config.port )
  139. @listener.setsockopt( Socket::SOL_SOCKET, Socket::SO_REUSEADDR, 1 )
  140. @listener_thread = nil
  141. end
  142. ######
  143. public
  144. ######
  145. # URI to handler mapping object
  146. attr_reader :urimap
  147. # Flag that indicates whether the server is running
  148. attr_reader :running
  149. # The ThingFish::FileStore instance that acts as the interface to the file storage
  150. # mechanism used by the daemon.
  151. attr_reader :filestore
  152. # The ThingFish::MetaStore instance that acts as the interface to the metadata
  153. # mechanism used by the daemon.
  154. attr_reader :metastore
  155. # The ThingFish::Config instance that contains all current configuration
  156. # information used by the daemon.
  157. attr_reader :config
  158. # The Array of installed ThingFish::Filters
  159. attr_reader :filters
  160. # The listener socket
  161. attr_reader :listener
  162. # Boolean for testing if profiling is available
  163. attr_reader :have_profiling
  164. # A hash of active ConnectionManagers, keyed by the client socket they are managing
  165. attr_reader :connections
  166. # The thread which is responsible for cleanup of connection threads
  167. attr_reader :supervisor
  168. ### Start the server.
  169. def start
  170. self.log.info "Starting at: http://%s:%d/" % [ @config.ip, @config.port ]
  171. daemonize( @config.pidfile ) if @config.daemon
  172. become_user( @config.user ) if Process.euid.zero? and ! @config.user.nil?
  173. # Do any storage preparation tasks that may be required after dropping privileges.
  174. @filestore.on_startup
  175. @metastore.on_startup
  176. Signal.trap( "INT" ) { self.shutdown("Interrupted") }
  177. Signal.trap( "TERM" ) { self.shutdown("Terminated") }
  178. @running = true
  179. self.start_supervisor_thread
  180. self.start_listener.join
  181. end
  182. ### Start the thread responsible for handling incoming connections. Returns the new Thread
  183. ### object.
  184. def start_listener
  185. @listener_thread = Thread.new do
  186. Thread.current.abort_on_exception = true
  187. self.log.debug "Entering listen loop"
  188. begin
  189. while @running
  190. begin
  191. # use nonblocking accept so closing the socket causes the block to finish
  192. socket = @listener.accept_nonblock
  193. self.handle_connection( socket )
  194. rescue Errno::EAGAIN, Errno::ECONNABORTED, Errno::EPROTO, Errno::EINTR
  195. self.log.debug "No connections pending; waiting for listener to become readable."
  196. IO.select([ @listener ])
  197. next
  198. rescue IOError => err
  199. @running = false
  200. self.log.info "Listener got a %s: exiting accept loop" % [ err.class.name ]
  201. end
  202. end
  203. rescue Shutdown
  204. self.log.info "Got the shutdown signal."
  205. ensure
  206. @running = false
  207. @listener.close
  208. end
  209. self.log.debug "Exited listen loop"
  210. end
  211. self.log.debug "Listener thread is: %p" % [ @listener_thread ]
  212. return @listener_thread
  213. rescue Spec::Mocks::MockExpectationError
  214. # Re-raise expectation failures while testing
  215. raise
  216. rescue Exception => err
  217. self.log.error "Unhandled %s: %s" % [ err.class.name, err.message ]
  218. self.log.debug " %s" % [ err.backtrace.join("\n ") ]
  219. end
  220. ### Start a thread that monitors connection threads and cleans them up when they're done.
  221. def start_supervisor_thread
  222. self.log.info "Starting supervisor thread"
  223. # TODO: work crew thread collection
  224. @supervisor = Thread.new do
  225. Thread.current.abort_on_exception = true
  226. while @running || ! @connection_threads.list.empty?
  227. @connection_threads.list.find_all {|t| ! t.alive? }.each do |t|
  228. self.log.debug "Finishing up connection thread %p" % [ t ]
  229. t.join
  230. end
  231. sleep 0.5
  232. end
  233. self.log.info "Supervisor thread exiting"
  234. end
  235. self.log.debug "Supervisor thread is running (%p)" % [ @supervisor ]
  236. end
  237. ### Handle an incoming connection on the given +socket+.
  238. def handle_connection( socket )
  239. connection = ThingFish::ConnectionManager.new( socket, @config, &self.method(:dispatch) )
  240. self.log.info "Connect: %s (%p)" %
  241. [ connection.session_info, Thread.current ]
  242. t = Thread.new do
  243. Thread.current.abort_on_exception = true
  244. begin
  245. if @profile_connections && socket.peeraddr[3] == '127.0.0.1'
  246. self.profile( "connection" ) do
  247. connection.process
  248. end
  249. else
  250. connection.process
  251. end
  252. rescue Shutdown
  253. self.log.info "Forceful shutdown of connection thread %p." % [ Thread.current ]
  254. end
  255. self.log.debug "Connection thread %p done." % [ Thread.current ]
  256. end
  257. @connection_threads.add( t )
  258. rescue ::RuntimeError => err
  259. self.log.error "Fatal %s in connection thread for %p: %s\n " % [
  260. err.class.name,
  261. connection,
  262. err.message,
  263. err.backtrace.join( "\n " )
  264. ]
  265. end
  266. ### Shut the server down gracefully, outputting the specified +reason+ for the
  267. ### shutdown to the logs.
  268. def shutdown( reason="no reason", force=false )
  269. if @running
  270. @running = false
  271. else
  272. force = true
  273. end
  274. self.log.info "Shutting down %p from %p" % [ @listener_thread, Thread.current ]
  275. @listener_thread.raise( Shutdown ) if ! @listener_thread.nil? && @listener_thread.alive?
  276. if force
  277. self.log.warn "Forceful shutdown. Terminating %d active connection threads." %
  278. [ @connection_threads.list.length ]
  279. self.log.debug " Active threads: %p" % [ @connection_threads.list ]
  280. @connection_threads.list.each do |t|
  281. t.raise( Shutdown )
  282. end
  283. else
  284. self.log.warn "Graceful shutdown. Waiting on %d active connection threads." %
  285. [ @connection_threads.list.length ]
  286. self.log.debug " Active threads: %p" % [ @connection_threads.list ]
  287. end
  288. @supervisor.join
  289. end
  290. ### Returns a Hash of handler information of the form:
  291. ### {
  292. ### '<handlerclass>' => ['<installed uris>']
  293. ### }
  294. def handler_info
  295. info = {}
  296. self.urimap.map.each do |uri,handlers|
  297. handlers.each do |h|
  298. info[ h.plugin_name ] ||= []
  299. info[ h.plugin_name ] << uri
  300. end
  301. end
  302. return info
  303. end
  304. ### Returns a Hash of filter information of the form:
  305. ### {
  306. ### '<filterclass>' => [<version info>]
  307. ### }
  308. def filter_info
  309. info = {}
  310. self.filters.each do |filter|
  311. info[ filter.class.plugin_name ] = filter.info
  312. end
  313. return info
  314. end
  315. ### Store the data from the uploaded entity +body+ in the filestore;
  316. ### create/update any associated metadata.
  317. def store_resource( body, body_metadata, uuid=nil )
  318. new_resource = uuid.nil?
  319. uuid ||= UUIDTools::UUID.timestamp_create
  320. # :BRANCH: Deletes new resources if there's an error while storing
  321. # :BRANCH: Doesn't delete it if it's an update
  322. # Store the data, catching and cleaning up on error
  323. begin
  324. checksum = @filestore.store_io( uuid, body )
  325. body.unlink if body.respond_to?( :unlink )
  326. rescue => err
  327. self.log.error "Error saving resource to filestore: %s" % [ err.message ]
  328. @filestore.delete( uuid ) if new_resource
  329. raise
  330. end
  331. # Store some default metadata about the resource
  332. begin
  333. @metastore.transaction do
  334. now = Time.now.gmtime
  335. metadata = @metastore[ uuid ]
  336. metadata.update( body_metadata )
  337. # :BRANCH: Won't overwrite an existing creation date
  338. metadata.checksum = checksum
  339. metadata.created = now unless metadata.created
  340. metadata.modified = now
  341. self.log.info "Created new resource %s (%s, %0.2f KB), checksum is %s" % [
  342. uuid,
  343. metadata.format,
  344. Integer(metadata.extent) / 1024.0,
  345. metadata.checksum
  346. ]
  347. end
  348. rescue => err
  349. self.log.error "Error saving resource to metastore: %s" % [ err.message ]
  350. @filestore.delete( uuid ) if new_resource
  351. raise
  352. end
  353. return uuid
  354. end
  355. ### Recursively store all resources in the specified +request+ that are related to +body+.
  356. ### Use the specified +uuid+ for the 'related_to' metadata value.
  357. def store_related_resources( body, uuid, request )
  358. request.related_resources[ body ].each do |related_resource, related_metadata|
  359. related_metadata[ :related_to ] = uuid
  360. metadata = request.metadata[related_resource].merge( related_metadata )
  361. subuuid = self.store_resource( related_resource, metadata )
  362. self.store_related_resources( related_resource, subuuid, request )
  363. end
  364. rescue => err
  365. self.log.error "%s while storing related resource: %s" % [ err.class.name, err.message ]
  366. self.log.debug "Backtrace: %s" % [ err.backtrace.join("\n ") ]
  367. end
  368. ### Remove any resources that have a +related_to+ of the given UUID, and
  369. ### the given +relation+ (or any relation if none is specified)
  370. ### :TODO: Purge recursively?
  371. def purge_related_resources( uuid, relation=nil )
  372. results = @metastore.find_by_exact_properties( :related_to => uuid.to_s, :relation => relation )
  373. self.log.debug "Found %d UUIDS for purging" % [ results.length ]
  374. results.each do |subuuid,_|
  375. self.log.debug "purging appended resource %s for %s" % [ subuuid, uuid ]
  376. @metastore.delete_resource( subuuid )
  377. @filestore.delete( subuuid )
  378. end
  379. end
  380. # SMITH YOU!
  381. ### Dispatch the +request+ to filters and handlers and return a ThingFish::Response.
  382. def dispatch( request )
  383. response = ThingFish::Response.new( request.http_version, @config )
  384. self.profile_request( request, response ) do
  385. # Let the filters manhandle the request
  386. self.filter_request( request, response )
  387. # Now execute the given handlers on the request and response
  388. self.run_handlers( request, response ) unless response.is_handled?
  389. # Let the filters manhandle the response
  390. self.filter_response( response, request )
  391. end
  392. return response
  393. end
  394. ### Start a profile for the provided +block+ if profiling is enabled for the
  395. ### specified +request+.
  396. def profile_request( request, response, &block )
  397. if self.have_profiling and request.run_profile?
  398. description = request.uri.path.gsub( %r{/}, '_' ).sub( /^_/, '' ).chomp('_')
  399. self.profile( description, &block )
  400. else
  401. yield
  402. end
  403. end
  404. ### Start a profile for the provided +block+ if profiling is enabled, dumping the result
  405. ### out to a profile directory afterwards.
  406. def profile( description, &block )
  407. if self.have_profiling
  408. result = nil
  409. @mutex.synchronize( Sync::EX ) do
  410. result = RubyProf.profile( &block )
  411. end
  412. self.log.debug {
  413. output = ""
  414. printer = RubyProf::FlatPrinter.new( result )
  415. printer.print( output, 0 )
  416. output
  417. }
  418. filename = @config.profiledir_path + "%f#%x#%s" % [
  419. Time.now,
  420. Thread.current.object_id * 2,
  421. description
  422. ]
  423. File.open( "#{filename}.html", 'w' ) do | profile |
  424. printer = RubyProf::GraphHtmlPrinter.new( result )
  425. printer.print( profile )
  426. # profile.print( Marshal.dump([ request, result ]) ) # TODO!!
  427. end
  428. else
  429. yield
  430. end
  431. end
  432. ### Attempt to load and configure the profiling library.
  433. def load_profiler
  434. require 'ruby-prof'
  435. # enable additonal optional profile measurements
  436. mask = RubyProf::PROCESS_TIME
  437. mask |= RubyProf::CPU_TIME if
  438. @config.profiling.metrics.include?( 'cpu' ) and ! RubyProf::CPU_TIME.nil?
  439. mask |= RubyProf::ALLOCATIONS if
  440. @config.profiling.metrics.include?( 'allocations' ) and ! RubyProf::ALLOCATIONS.nil?
  441. mask |= RubyProf::MEMORY if
  442. @config.profiling.metrics.include?( 'memory' ) and ! RubyProf::MEMORY.nil?
  443. RubyProf.measure_mode = mask
  444. self.log.info "Enabled profiling"
  445. return true
  446. rescue Exception => err
  447. self.log.error "Couldn't load profiler: %s" % [ err.message ]
  448. self.log.debug( err.backtrace.join("\n") )
  449. return false
  450. end
  451. ### Filter and potentially modify the incoming request.
  452. def filter_request( request, response )
  453. @filters.each do |filter|
  454. # self.log.debug "Passing request through %s" % [ filter.class.name ]
  455. begin
  456. filter.handle_request( request, response )
  457. rescue Exception => err
  458. self.log.error "Request filter raised a %s: %s" %
  459. [ err.class.name, err.message ]
  460. self.log.debug " " + err.backtrace.join("\n ")
  461. else
  462. response.filters << filter
  463. ensure
  464. request.check_body_ios
  465. end
  466. # Allow filters to interrupt the dispatch; auth filter
  467. # uses this to deny the request before incurring the cost of
  468. # all the filters that may come behind it. Auth adds identity
  469. # information to the request (and so acts like other filters),
  470. # whereas authorization acts on a request based on the
  471. # added identity information (and so is a handler).
  472. break if response.handled?
  473. end
  474. end
  475. ### Filter (and potentially modify) the outgoing response with the filters
  476. ### that were registered with it during the request-filtering stage
  477. def filter_response( response, request )
  478. response.filters.each do |filter|
  479. # self.log.debug "Passing response through %s" % [ filter.class.name ]
  480. begin
  481. filter.handle_response( response, request )
  482. rescue Exception => err
  483. self.log.error "Response filter raised a %s: %s" %
  484. [ err.class.name, err.message ]
  485. self.log.debug " " + err.backtrace.join("\n ")
  486. ensure
  487. if response.body.respond_to?( :rewind )
  488. response.body.open if response.body.closed?
  489. response.body.rewind
  490. end
  491. end
  492. end
  493. end
  494. ### Iterate through the handlers for this URI and execute each one. Stop
  495. ### executing handlers as soon as the response's status changes.
  496. def run_handlers( request, response )
  497. delegators, processor = @urimap.resolve( request.uri )
  498. self.log.debug "Dispatching to %s via %d delegators" %
  499. [ processor.class.name, delegators.length ]
  500. return self.run_handler_chain( request, response, delegators, processor )
  501. end
  502. ### Recursively delegate the given +request+ and +response+ to the
  503. ### specified +delegators+. Once +delegators+ is empty, run the
  504. ### +processor+ for the current request.
  505. def run_handler_chain( request, response, delegators, processor )
  506. request.check_body_ios
  507. # If there aren't any delegators left to run through, run the processor
  508. if delegators.empty?
  509. response.handlers << processor
  510. return processor.process( request, response )
  511. else
  512. delegator = delegators.first
  513. response.handlers << delegator
  514. next_delegators = delegators[ 1..-1 ]
  515. self.log.debug "Delegating to %s" % [ delegator.class.name ]
  516. return delegator.delegate( request, response ) do |dreq, dres|
  517. self.run_handler_chain( dreq, dres, next_delegators, processor )
  518. end
  519. end
  520. end
  521. end # class ThingFish::Daemon
  522. # vim: set nosta noet ts=4 sw=4: