PageRenderTime 89ms CodeModel.GetById 18ms app.highlight 64ms RepoModel.GetById 0ms app.codeStats 1ms

/lib/thingfish/daemon.rb

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