/lib/thingfish/daemon.rb
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: