From 723e222e5143badf905bc80034f0f86690378e6f Mon Sep 17 00:00:00 2001 From: William Morgan Date: Mon, 17 Aug 2009 11:47:20 -0400 Subject: [PATCH] rewrite logging to have multiple levels: debug, info, etc. Level is now set by SUP_LOG_LEVEL environment variable. Big patch here, but most of it is replacing the old Redwood::log calls. Some work on poll-mode, which subclasses log-mode. Remind me never to use inheritance again. --- bin/sup | 38 ++++++++----- lib/sup.rb | 23 ++++---- lib/sup/colormap.rb | 12 ++-- lib/sup/crypto.rb | 6 +- lib/sup/ferret_index.rb | 40 +++++++------- lib/sup/hook.rb | 4 +- lib/sup/imap.rb | 14 ++--- lib/sup/index.rb | 10 ++-- lib/sup/logger.rb | 89 ++++++++++++++++++------------ lib/sup/maildir.rb | 6 +- lib/sup/mbox.rb | 2 +- lib/sup/mbox/ssh-file.rb | 8 +-- lib/sup/message-chunks.rb | 2 +- lib/sup/message.rb | 28 +++++----- lib/sup/mode.rb | 4 +- lib/sup/modes/edit-message-mode.rb | 2 +- lib/sup/modes/label-list-mode.rb | 2 +- lib/sup/modes/log-mode.rb | 42 ++++++++------ lib/sup/modes/poll-mode.rb | 16 +++--- lib/sup/modes/reply-mode.rb | 2 +- lib/sup/modes/thread-view-mode.rb | 4 +- lib/sup/poll.rb | 15 ++--- lib/sup/sent.rb | 2 - lib/sup/source.rb | 2 +- lib/sup/textfield.rb | 4 +- lib/sup/util.rb | 2 +- lib/sup/xapian_index.rb | 14 ++--- 27 files changed, 206 insertions(+), 187 deletions(-) diff --git a/bin/sup b/bin/sup index 0fb28fa..155bb65 100755 --- a/bin/sup +++ b/bin/sup @@ -95,17 +95,17 @@ module LibC else; "libc.so.6" end - Redwood::log "dynamically loading setlocale() from #{setlocale_lib}" + debug "dynamically loading setlocale() from #{setlocale_lib}" begin dlload setlocale_lib extern "void setlocale(int, const char *)" - Redwood::log "setting locale..." + debug "setting locale..." LibC.setlocale(6, "") # LC_ALL == 6 rescue RuntimeError => e - Redwood::log "cannot dlload setlocale(); ncurses wide character support probably broken." - Redwood::log "dlload error was #{e.class}: #{e.message}" + warn "cannot dlload setlocale(); ncurses wide character support probably broken." + warn "dlload error was #{e.class}: #{e.message}" if Config::CONFIG['arch'] =~ /bsd/ - Redwood::log "BSD variant detected. You may have to install a compat6x package to acquire libc." + warn "BSD variant detected. You may have to install a compat6x package to acquire libc." end end end @@ -163,7 +163,7 @@ begin if(s = Redwood::SourceManager.source_for DraftManager.source_name) DraftManager.source = s else - Redwood::log "no draft source, auto-adding..." + debug "no draft source, auto-adding..." Redwood::SourceManager.add_source DraftManager.new_source end @@ -175,18 +175,24 @@ begin HookManager.run "startup" - log "starting curses" + debug "starting curses" + Redwood::Logger.remove_sink $stderr start_cursing bm = BufferManager.init Colormap.new.populate_colormap - log "initializing mail index buffer" + debug "initializing log buffer" + lmode = Redwood::LogMode.new "system log" + lmode.on_kill { Logger.clear! } + Logger.add_sink lmode + Logger.force_message "Welcome to Sup! Log level is set to #{Logger.level}." + + debug "initializing inbox buffer" imode = InboxMode.new ibuf = bm.spawn "Inbox", imode - log "ready for interaction!" - Logger.make_buf + debug "ready for interaction!" bm.draw_screen @@ -196,7 +202,7 @@ begin begin s.connect rescue SourceError => e - Redwood::log "fatal error loading from #{s}: #{e.message}" + error "fatal error loading from #{s}: #{e.message}" end end end unless $opts[:no_initial_poll] @@ -320,17 +326,19 @@ ensure Redwood::finish stop_cursing - Redwood::log "stopped cursing" + Redwood::Logger.remove_all_sinks! + Redwood::Logger.add_sink $stderr, false + debug "stopped cursing" if SuicideManager.instantiated? && SuicideManager.die? - Redwood::log "I've been ordered to commit seppuku. I obey!" + info "I've been ordered to commit seppuku. I obey!" end if Redwood::exceptions.empty? - Redwood::log "no fatal errors. good job, william." + debug "no fatal errors. good job, william." Index.save else - Redwood::log "oh crap, an exception" + error "oh crap, an exception" end Index.unlock diff --git a/lib/sup.rb b/lib/sup.rb index 00ad87c..ed14458 100644 --- a/lib/sup.rb +++ b/lib/sup.rb @@ -233,28 +233,25 @@ require "sup/hook" Redwood::HookManager.init Redwood::HOOK_DIR ## everything we need to get logging working -require "sup/buffer" -require "sup/keymap" -require "sup/mode" -require "sup/modes/scroll-mode" -require "sup/modes/text-mode" -require "sup/modes/log-mode" require "sup/logger" -module Redwood - def log s; Logger.log s; end - module_function :log -end +Redwood::Logger.init.add_sink $stderr +include Redwood::LogsStuff ## determine encoding and character set $encoding = Locale.current.charset if $encoding - Redwood::log "using character set encoding #{$encoding.inspect}" + debug "using character set encoding #{$encoding.inspect}" else - Redwood::log "warning: can't find character set by using locale, defaulting to utf-8" + warn "can't find character set by using locale, defaulting to utf-8" $encoding = "UTF-8" end -## now everything else (which can feel free to call Redwood::log at load time) +require "sup/buffer" +require "sup/keymap" +require "sup/mode" +require "sup/modes/scroll-mode" +require "sup/modes/text-mode" +require "sup/modes/log-mode" require "sup/update" require "sup/suicide" require "sup/message-chunks" diff --git a/lib/sup/colormap.rb b/lib/sup/colormap.rb index 38787cd..fbbbfc9 100644 --- a/lib/sup/colormap.rb +++ b/lib/sup/colormap.rb @@ -129,7 +129,7 @@ class Colormap @next_id = (@next_id + 1) % NUM_COLORS @next_id += 1 if @next_id == 0 # 0 is always white on black id = @next_id - Redwood::log "colormap: for color #{sym}, using id #{id} -> #{fg}, #{bg}" + debug "colormap: for color #{sym}, using id #{id} -> #{fg}, #{bg}" Curses.init_pair id, fg, bg or raise ArgumentError, "couldn't initialize curses color pair #{fg}, #{bg} (key #{id})" @@ -137,7 +137,7 @@ class Colormap ## delete the old mapping, if it exists if @users[cp] @users[cp].each do |usym| - Redwood::log "dropping color #{usym} (#{id})" + warn "dropping color #{usym} (#{id})" @entries[usym][3] = nil end @users[cp] = [] @@ -155,7 +155,7 @@ class Colormap ## to the default ones. def populate_colormap user_colors = if File.exists? Redwood::COLOR_FN - Redwood::log "loading user colors from #{Redwood::COLOR_FN}" + debug "loading user colors from #{Redwood::COLOR_FN}" Redwood::load_yaml_obj Redwood::COLOR_FN end @@ -171,7 +171,7 @@ class Colormap fg = Curses.const_get "COLOR_#{ufg.upcase}" rescue NameError error ||= "Warning: there is no color named \"#{ufg}\", using fallback." - Redwood::log "Warning: there is no color named \"#{ufg}\"" + warn "there is no color named \"#{ufg}\"" end end @@ -180,7 +180,7 @@ class Colormap bg = Curses.const_get "COLOR_#{ubg.upcase}" rescue NameError error ||= "Warning: there is no color named \"#{ubg}\", using fallback." - Redwood::log "Warning: there is no color named \"#{ubg}\"" + warn "there is no color named \"#{ubg}\"" end end @@ -190,7 +190,7 @@ class Colormap Curses.const_get "A_#{a.upcase}" rescue NameError error ||= "Warning: there is no attribute named \"#{a}\", using fallback." - Redwood::log "Warning: there is no attribute named \"#{a}\", using fallback." + warn "there is no attribute named \"#{a}\", using fallback." end end end diff --git a/lib/sup/crypto.rb b/lib/sup/crypto.rb index a3f7afc..7f044b9 100644 --- a/lib/sup/crypto.rb +++ b/lib/sup/crypto.rb @@ -18,10 +18,10 @@ class CryptoManager @cmd = case bin when /\S/ - Redwood::log "crypto: detected gpg binary in #{bin}" + debug "crypto: detected gpg binary in #{bin}" "#{bin} --quiet --batch --no-verbose --logger-fd 1 --use-agent" else - Redwood::log "crypto: no gpg binary detected" + debug "crypto: no gpg binary detected" nil end end @@ -154,9 +154,7 @@ private def run_gpg args cmd = "#{@cmd} #{args} 2> /dev/null" - #Redwood::log "crypto: running: #{cmd}" output = `#{cmd}` - #Redwood::log "crypto: output: #{output.inspect}" unless $?.success? output end end diff --git a/lib/sup/ferret_index.rb b/lib/sup/ferret_index.rb index 3655d7a..df1139d 100644 --- a/lib/sup/ferret_index.rb +++ b/lib/sup/ferret_index.rb @@ -18,13 +18,13 @@ class FerretIndex < BaseIndex def load_index dir=File.join(@dir, "ferret") if File.exists? dir - Redwood::log "loading index..." + debug "loading index..." @index_mutex.synchronize do @index = Ferret::Index::Index.new(:path => dir, :analyzer => @analyzer, :id_field => 'message_id') - Redwood::log "loaded index of #{@index.size} messages" + debug "loaded index of #{@index.size} messages" end else - Redwood::log "creating index..." + debug "creating index..." @index_mutex.synchronize do field_infos = Ferret::Index::FieldInfos.new :store => :yes field_infos.add_field :message_id, :index => :untokenized @@ -90,9 +90,9 @@ class FerretIndex < BaseIndex if entry[:source_id] && entry[:source_info] && entry[:label] && ((entry[:source_id].to_i > source_id) || (entry[:source_info].to_i < m.source_info)) labels += entry[:label].to_set_of_symbols - #Redwood::log "found updated version of message #{m.id}: #{m.subj}" - #Redwood::log "previous version was at #{entry[:source_id].inspect}:#{entry[:source_info].inspect}, this version at #{source_id.inspect}:#{m.source_info.inspect}" - #Redwood::log "merged labels are #{labels.inspect} (index #{entry[:label].inspect}, message #{m.labels.inspect})" + #debug "found updated version of message #{m.id}: #{m.subj}" + #debug "previous version was at #{entry[:source_id].inspect}:#{entry[:source_info].inspect}, this version at #{source_id.inspect}:#{m.source_info.inspect}" + #debug "merged labels are #{labels.inspect} (index #{entry[:label].inspect}, message #{m.labels.inspect})" entry = {} end @@ -151,7 +151,7 @@ class FerretIndex < BaseIndex while true limit = (query[:limit])? [EACH_BY_DATE_NUM, query[:limit] - offset].min : EACH_BY_DATE_NUM results = @index_mutex.synchronize { @index.search ferret_query, :sort => "date DESC", :limit => limit, :offset => offset } - Redwood::log "got #{results.total_hits} results for query (offset #{offset}) #{ferret_query.inspect}" + debug "got #{results.total_hits} results for query (offset #{offset}) #{ferret_query.inspect}" results.hits.each do |hit| yield @index_mutex.synchronize { @index[hit.doc][:message_id] }, lambda { build_message hit.doc } end @@ -170,7 +170,7 @@ class FerretIndex < BaseIndex SAME_SUBJECT_DATE_LIMIT = 7 MAX_CLAUSES = 1000 def each_message_in_thread_for m, opts={} - #Redwood::log "Building thread for #{m.id}: #{m.subj}" + #debug "Building thread for #{m.id}: #{m.subj}" messages = {} searched = {} num_queries = 0 @@ -191,10 +191,10 @@ class FerretIndex < BaseIndex q = build_ferret_query :qobj => q p1 = @index_mutex.synchronize { @index.search(q).hits.map { |hit| @index[hit.doc][:message_id] } } - Redwood::log "found #{p1.size} results for subject query #{q}" + debug "found #{p1.size} results for subject query #{q}" p2 = @index_mutex.synchronize { @index.search(q.to_s, :limit => :all).hits.map { |hit| @index[hit.doc][:message_id] } } - Redwood::log "found #{p2.size} results in string form" + debug "found #{p2.size} results in string form" pending = (pending + p1 + p2).uniq end @@ -225,7 +225,7 @@ class FerretIndex < BaseIndex end mid = @index[docid][:message_id] unless messages.member?(mid) - #Redwood::log "got #{mid} as a child of #{id}" + #debug "got #{mid} as a child of #{id}" messages[mid] ||= lambda { build_message docid } refs = @index[docid][:refs].split pending += refs.select { |id| !searched[id] } @@ -235,10 +235,10 @@ class FerretIndex < BaseIndex end if killed - #Redwood::log "thread for #{m.id} is killed, ignoring" + #debug "thread for #{m.id} is killed, ignoring" false else - #Redwood::log "ran #{num_queries} queries to build thread of #{messages.size} messages for #{m.id}: #{m.subj}" if num_queries > 0 + #debug "ran #{num_queries} queries to build thread of #{messages.size} messages for #{m.id}: #{m.subj}" if num_queries > 0 messages.each { |mid, builder| yield mid, builder } true end @@ -285,13 +285,13 @@ class FerretIndex < BaseIndex end q.add_query Ferret::Search::TermQuery.new(:label, "spam"), :must_not - Redwood::log "contact search: #{q}" + debug "contact search: #{q}" contacts = {} num = h[:num] || 20 @index_mutex.synchronize do @index.search_each q, :sort => "date DESC", :limit => :all do |docid, score| break if contacts.size >= num - #Redwood::log "got message #{docid} to: #{@index[docid][:to].inspect} and from: #{@index[docid][:from].inspect}" + #debug "got message #{docid} to: #{@index[docid][:to].inspect} and from: #{@index[docid][:from].inspect}" f = @index[docid][:from] t = @index[docid][:to] @@ -381,10 +381,10 @@ class FerretIndex < BaseIndex field, name = $1, ($3 || $4) case field when "filename" - Redwood::log "filename - translated #{field}:#{name} to attachments:(#{name.downcase})" + debug "filename: translated #{field}:#{name} to attachments:(#{name.downcase})" "attachments:(#{name.downcase})" when "filetype" - Redwood::log "filetype - translated #{field}:#{name} to attachments:(*.#{name.downcase})" + debug "filetype: translated #{field}:#{name} to attachments:(*.#{name.downcase})" "attachments:(*.#{name.downcase})" end end @@ -396,13 +396,13 @@ class FerretIndex < BaseIndex if realdate case field when "after" - Redwood::log "chronic: translated #{field}:#{datestr} to #{realdate.end}" + debug "chronic: translated #{field}:#{datestr} to #{realdate.end}" "date:(>= #{sprintf "%012d", realdate.end.to_i})" when "before" - Redwood::log "chronic: translated #{field}:#{datestr} to #{realdate.begin}" + debug "chronic: translated #{field}:#{datestr} to #{realdate.begin}" "date:(<= #{sprintf "%012d", realdate.begin.to_i})" else - Redwood::log "chronic: translated #{field}:#{datestr} to #{realdate}" + debug "chronic: translated #{field}:#{datestr} to #{realdate}" "date:(<= #{sprintf "%012d", realdate.end.to_i}) date:(>= #{sprintf "%012d", realdate.begin.to_i})" end else diff --git a/lib/sup/hook.rb b/lib/sup/hook.rb index a492a07..0c41162 100644 --- a/lib/sup/hook.rb +++ b/lib/sup/hook.rb @@ -40,7 +40,7 @@ class HookManager end def log s - Redwood::log "hook[#@__name]: #{s}" + info "hook[#@__name]: #{s}" end def ask_yes_or_no q @@ -146,7 +146,7 @@ private end def log m - Redwood::log("hook: " + m) + info("hook: " + m) end end diff --git a/lib/sup/imap.rb b/lib/sup/imap.rb index 14acdb7..c2904fb 100644 --- a/lib/sup/imap.rb +++ b/lib/sup/imap.rb @@ -160,13 +160,13 @@ class IMAP < Source return if last_id == @ids.length range = (@ids.length + 1) .. last_id - Redwood::log "fetching IMAP headers #{range}" + debug "fetching IMAP headers #{range}" fetch(range, ['RFC822.SIZE', 'INTERNALDATE', 'FLAGS']).each do |v| id = make_id v @ids << id @imap_state[id] = { :id => v.seqno, :flags => v.attr["FLAGS"] } end - Redwood::log "done fetching IMAP headers" + debug "done fetching IMAP headers" end synchronized :scan_mailbox @@ -225,7 +225,7 @@ private if good_results.empty? raise FatalSourceError, "no IMAP response for #{ids} containing all fields #{fields.join(', ')} (got #{results.size} results)" elsif good_results.size < results.size - Redwood::log "Your IMAP server sucks. It sent #{results.size} results for a request for #{good_results.size} messages. What are you using, Binc?" + warn "Your IMAP server sucks. It sent #{results.size} results for a request for #{good_results.size} messages. What are you using, Binc?" end good_results @@ -253,12 +253,12 @@ private raise Net::IMAP::NoResponseError unless @imap.capability().member? "AUTH=CRAM-MD5" @imap.authenticate 'CRAM-MD5', @username, @password rescue Net::IMAP::BadResponseError, Net::IMAP::NoResponseError => e - Redwood::log "CRAM-MD5 authentication failed: #{e.class}. Trying LOGIN auth..." + debug "CRAM-MD5 authentication failed: #{e.class}. Trying LOGIN auth..." begin raise Net::IMAP::NoResponseError unless @imap.capability().member? "AUTH=LOGIN" @imap.authenticate 'LOGIN', @username, @password rescue Net::IMAP::BadResponseError, Net::IMAP::NoResponseError => e - Redwood::log "LOGIN authentication failed: #{e.class}. Trying plain-text LOGIN..." + debug "LOGIN authentication failed: #{e.class}. Trying plain-text LOGIN..." @imap.login @username, @password end end @@ -275,7 +275,7 @@ private def say s @say_id = BufferManager.say s, @say_id if BufferManager.instantiated? - Redwood::log s + debug s end def shutup @@ -332,7 +332,7 @@ private rescue *RECOVERABLE_ERRORS => e if (retries += 1) <= 3 @imap = nil - Redwood::log "got #{e.class.name}: #{e.message.inspect}" + warn "got #{e.class.name}: #{e.message.inspect}" sleep 2 retry end diff --git a/lib/sup/index.rb b/lib/sup/index.rb index 19d753e..dfaeee8 100644 --- a/lib/sup/index.rb +++ b/lib/sup/index.rb @@ -6,7 +6,7 @@ begin require 'chronic' $have_chronic = true rescue LoadError => e - Redwood::log "optional 'chronic' library not found (run 'gem install chronic' to install)" + debug "optional 'chronic' library not found; date-time query restrictions disabled" $have_chronic = false end @@ -31,7 +31,7 @@ class BaseIndex def lockfile; File.join @dir, "lock" end def lock - Redwood::log "locking #{lockfile}..." + debug "locking #{lockfile}..." begin @lock.lock rescue Lockfile::MaxTriesLockError @@ -91,7 +91,7 @@ EOS def unlock if @lock && @lock.locked? - Redwood::log "unlocking #{lockfile}..." + debug "unlocking #{lockfile}..." @lock.unlock end end @@ -102,7 +102,7 @@ EOS end def save - Redwood::log "saving index and sources..." + debug "saving index and sources..." FileUtils.mkdir_p @dir unless File.exists? @dir SourceManager.save_sources save_index @@ -215,6 +215,6 @@ case index_name else fail "unknown index type #{index_name.inspect}" end Index = Redwood.const_get "#{index_name.capitalize}Index" -Redwood::log "using index #{Index.name}" +debug "using index #{Index.name}" end diff --git a/lib/sup/logger.rb b/lib/sup/logger.rb index 4ac6551..ccaeae0 100644 --- a/lib/sup/logger.rb +++ b/lib/sup/logger.rb @@ -1,54 +1,73 @@ +require "sup" +require 'stringio' +require 'thread' + module Redwood +## simple centralized logger. outputs to multiple sinks by calling << on them. +## also keeps a record of all messages, so that adding a new sink will send all +## previous messages to it by default. class Logger - @@instance = nil + include Singleton - attr_reader :buf + LEVELS = %w(debug info warn error) # in order! - def initialize - raise "only one Log can be defined" if @@instance - @@instance = self - @mode = LogMode.new - @respawn = true - @spawning = false # to prevent infinite loops! + def initialize level=nil + level ||= ENV["SUP_LOG_LEVEL"] || "info" + @level = LEVELS.index(level) or raise ArgumentError, "invalid log level #{level.inspect}: should be one of #{LEVELS * ', '}" + @mutex = Mutex.new + @buf = StringIO.new + @sinks = [] end - ## must be called if you want to see anything! - ## once called, will respawn if killed... - def make_buf - return if @mode.buffer || !BufferManager.instantiated? || !@respawn || @spawning - @spawning = true - @mode.buffer = BufferManager.instance.spawn "log", @mode, :hidden => true, :system => true - @spawning = false + def level; LEVELS[@level] end + + def add_sink s, copy_current=true + @mutex.synchronize do + @sinks << s + s << @buf.string if copy_current + end end - def log s -# $stderr.puts s - make_buf - prefix = "#{Time.now}: " - padding = " " * prefix.length - first = true - s.split(/[\r\n]/).each do |l| - l = l.chomp - if first - first = false - @mode << "#{prefix}#{l}\n" - else - @mode << "#{padding}#{l}\n" + def remove_sink s; @mutex.synchronize { @sinks.delete s } end + def remove_all_sinks!; @mutex.synchronize { @sinks.clear } end + def clear!; @mutex.synchronize { @buf = StringIO.new } end + + LEVELS.each_with_index do |l, method_level| + define_method(l) do |s| + if method_level >= @level + send_message format_message(l, Time.now, s) end end - $stderr.puts "[#{Time.now}] #{s.chomp}" unless BufferManager.instantiated? && @mode.buffer end - - def self.method_missing m, *a - @@instance = Logger.new unless @@instance - @@instance.send m, *a + + ## send a message regardless of the current logging level + def force_message m; send_message format_message(nil, Time.now, m) end + +private + + ## level can be nil! + def format_message level, time, msg + prefix = case level + when "warn"; "WARNING: " + when "error"; "ERROR: " + else "" + end + "[#{time.to_s}] #{prefix}#{msg}\n" end - def self.buffer - @@instance.buf + ## actually distribute the message + def send_message m + @mutex.synchronize do + @sinks.each { |sink| sink << m } + @buf << m + end end end +## include me to have top-level #debug, #info, etc. methods. +module LogsStuff + Logger::LEVELS.each { |l| define_method(l) { |s| Logger.instance.send(l, s) } } end +end diff --git a/lib/sup/maildir.rb b/lib/sup/maildir.rb index 80903e2..3661abb 100644 --- a/lib/sup/maildir.rb +++ b/lib/sup/maildir.rb @@ -115,7 +115,7 @@ class Maildir < Source initial_poll = @ids.empty? - Redwood::log "scanning maildir #@dir..." + debug "scanning maildir #@dir..." begin @mtimes.each_key do |d| subdir = File.join(@dir, d) @@ -134,7 +134,7 @@ class Maildir < Source @ids_to_fns[id] = fn end else - Redwood::log "no poll on #{d}. mtime on indicates no new messages." + debug "no poll on #{d}. mtime on indicates no new messages." end end @ids = @dir_ids.values.flatten.uniq.sort! @@ -142,7 +142,7 @@ class Maildir < Source raise FatalSourceError, "Problem scanning Maildir directories: #{e.message}." end - Redwood::log "done scanning maildir" + debug "done scanning maildir" @last_scan = Time.now end synchronized :scan_mailbox diff --git a/lib/sup/mbox.rb b/lib/sup/mbox.rb index e1e3a4d..3f3abad 100644 --- a/lib/sup/mbox.rb +++ b/lib/sup/mbox.rb @@ -15,7 +15,7 @@ module MBox Time.parse time, 0 true rescue NoMethodError - Redwood::log "found invalid date in potential mbox split line, not splitting: #{l.inspect}" + warn "found invalid date in potential mbox split line, not splitting: #{l.inspect}" false end end diff --git a/lib/sup/mbox/ssh-file.rb b/lib/sup/mbox/ssh-file.rb index d474636..4ae4bba 100644 --- a/lib/sup/mbox/ssh-file.rb +++ b/lib/sup/mbox/ssh-file.rb @@ -16,12 +16,6 @@ class SSHFileError < StandardError; end ## all of the methods here can throw SSHFileErrors, SocketErrors, ## Net::SSH::Exceptions and Errno::ENOENTs. -## debugging TODO: remove me -def debug s - Redwood::log s -end -module_function :debug - ## a simple buffer of contiguous data class Buffer def initialize @@ -154,7 +148,7 @@ private ## TODO: share this code with imap def say s @say_id = BufferManager.say s, @say_id if BufferManager.instantiated? - Redwood::log s + info s end def shutup diff --git a/lib/sup/message-chunks.rb b/lib/sup/message-chunks.rb index 0d742d9..1eda174 100644 --- a/lib/sup/message-chunks.rb +++ b/lib/sup/message-chunks.rb @@ -132,7 +132,7 @@ EOS def viewable?; @lines.nil? end def view_default! path cmd = "/usr/bin/run-mailcap --action=view '#{@content_type}:#{path}' 2>/dev/null" - Redwood::log "running: #{cmd.inspect}" + debug "running: #{cmd.inspect}" system cmd $? == 0 end diff --git a/lib/sup/message.rb b/lib/sup/message.rb index 1e9c659..ed27d3d 100644 --- a/lib/sup/message.rb +++ b/lib/sup/message.rb @@ -73,7 +73,7 @@ class Message else id = "sup-faked-" + Digest::MD5.hexdigest(raw_header) from = header["from"] - #Redwood::log "faking non-existent message-id for message from #{from}: #{id}" + #debug "faking non-existent message-id for message from #{from}: #{id}" id end @@ -81,7 +81,7 @@ class Message header["from"] else name = "Sup Auto-generated Fake Sender " - #Redwood::log "faking non-existent sender for message #@id: #{name}" + #debug "faking non-existent sender for message #@id: #{name}" name end) @@ -92,11 +92,11 @@ class Message begin Time.parse date rescue ArgumentError => e - #Redwood::log "faking mangled date header for #{@id} (orig #{header['date'].inspect} gave error: #{e.message})" + #debug "faking mangled date header for #{@id} (orig #{header['date'].inspect} gave error: #{e.message})" Time.now end else - #Redwood::log "faking non-existent date header for #{@id}" + #debug "faking non-existent date header for #{@id}" Time.now end @@ -210,7 +210,7 @@ class Message parse_header @source.load_header(@source_info) message_to_chunks @source.load_message(@source_info) rescue SourceError, SocketError => e - Redwood::log "problem getting messages from #{@source}: #{e.message}" + warn "problem getting messages from #{@source}: #{e.message}" ## we need force_to_top here otherwise this window will cover ## up the error message one @source.error ||= e @@ -244,7 +244,7 @@ EOS begin yield rescue SourceError => e - Redwood::log "problem getting messages from #{@source}: #{e.message}" + warn "problem getting messages from #{@source}: #{e.message}" @source.error ||= e Redwood::report_broken_sources :force_to_top => true error_message e.message @@ -335,25 +335,25 @@ private def multipart_signed_to_chunks m if m.body.size != 2 - Redwood::log "warning: multipart/signed with #{m.body.size} parts (expecting 2)" + warn "multipart/signed with #{m.body.size} parts (expecting 2)" return end payload, signature = m.body if signature.multipart? - Redwood::log "warning: multipart/signed with payload multipart #{payload.multipart?} and signature multipart #{signature.multipart?}" + warn "multipart/signed with payload multipart #{payload.multipart?} and signature multipart #{signature.multipart?}" return end ## this probably will never happen if payload.header.content_type == "application/pgp-signature" - Redwood::log "warning: multipart/signed with payload content type #{payload.header.content_type}" + warn "multipart/signed with payload content type #{payload.header.content_type}" return end if signature.header.content_type != "application/pgp-signature" ## unknown signature type; just ignore. - #Redwood::log "warning: multipart/signed with signature content type #{signature.header.content_type}" + #warn "multipart/signed with signature content type #{signature.header.content_type}" return end @@ -362,23 +362,23 @@ private def multipart_encrypted_to_chunks m if m.body.size != 2 - Redwood::log "warning: multipart/encrypted with #{m.body.size} parts (expecting 2)" + warn "multipart/encrypted with #{m.body.size} parts (expecting 2)" return end control, payload = m.body if control.multipart? - Redwood::log "warning: multipart/encrypted with control multipart #{control.multipart?} and payload multipart #{payload.multipart?}" + warn "multipart/encrypted with control multipart #{control.multipart?} and payload multipart #{payload.multipart?}" return end if payload.header.content_type != "application/octet-stream" - Redwood::log "warning: multipart/encrypted with payload content type #{payload.header.content_type}" + warn "multipart/encrypted with payload content type #{payload.header.content_type}" return end if control.header.content_type != "application/pgp-encrypted" - Redwood::log "warning: multipart/encrypted with control content type #{signature.header.content_type}" + warn "multipart/encrypted with control content type #{signature.header.content_type}" return end diff --git a/lib/sup/mode.rb b/lib/sup/mode.rb index 6433492..209ca45 100644 --- a/lib/sup/mode.rb +++ b/lib/sup/mode.rb @@ -92,10 +92,10 @@ EOS unless err.empty? message = err.first.read if message =~ /^\s*$/ - Redwood::log "error running #{command} (but no error message)" + warn "error running #{command} (but no error message)" BufferManager.flash "Error running #{command}!" else - Redwood::log "error running #{command}: #{message}" + warn "error running #{command}: #{message}" BufferManager.flash "Error: #{message}" end return diff --git a/lib/sup/modes/edit-message-mode.rb b/lib/sup/modes/edit-message-mode.rb index a48930a..8da316f 100644 --- a/lib/sup/modes/edit-message-mode.rb +++ b/lib/sup/modes/edit-message-mode.rb @@ -325,7 +325,7 @@ protected BufferManager.flash "Message sent!" true rescue SystemCallError, SendmailCommandFailed, CryptoManager::Error => e - Redwood::log "Problem sending mail: #{e.message}" + warn "Problem sending mail: #{e.message}" BufferManager.flash "Problem sending mail: #{e.message}" false end diff --git a/lib/sup/modes/label-list-mode.rb b/lib/sup/modes/label-list-mode.rb index 53287c1..f65ec2e 100644 --- a/lib/sup/modes/label-list-mode.rb +++ b/lib/sup/modes/label-list-mode.rb @@ -73,7 +73,7 @@ protected ## TODO make the labelmanager responsible for label counts ## and then it can listen to labeled and unlabeled events, etc. if total == 0 && !LabelManager::RESERVED_LABELS.include?(label) && !LabelManager.new_label?(label) - Redwood::log "no hits for label #{label}, deleting" + debug "no hits for label #{label}, deleting" LabelManager.delete label next end diff --git a/lib/sup/modes/log-mode.rb b/lib/sup/modes/log-mode.rb index de16b5e..07fa9dd 100644 --- a/lib/sup/modes/log-mode.rb +++ b/lib/sup/modes/log-mode.rb @@ -1,36 +1,40 @@ +require 'stringio' module Redwood +## a variant of text mode that allows the user to automatically follow text, +## and respawns when << is called if necessary. + class LogMode < TextMode register_keymap do |k| k.add :toggle_follow, "Toggle follow mode", 'f' end - def initialize + def initialize buffer_name @follow = true - super + @buffer_name = buffer_name + @on_kill = [] + super() end + ## register callbacks for when the buffer is killed + def on_kill &b; @on_kill << b end + def toggle_follow @follow = !@follow - if buffer - if @follow - jump_to_line lines - buffer.content_height + 1 # leave an empty line at bottom - end - buffer.mark_dirty + if @follow + jump_to_line(lines - buffer.content_height + 1) # leave an empty line at bottom end + buffer.mark_dirty end - def text= t - super - if buffer && @follow - follow_top = lines - buffer.content_height + 1 - jump_to_line follow_top if topline < follow_top + def << s + unless buffer + BufferManager.spawn @buffer_name, self, :hidden => true, :system => true end - end - def << line - super - if buffer && @follow + s.split("\n").each { |l| super(l + "\n") } # insane. different << semantics. + + if @follow follow_top = lines - buffer.content_height + 1 jump_to_line follow_top if topline < follow_top end @@ -39,6 +43,12 @@ class LogMode < TextMode def status super + " (follow: #@follow)" end + + def cleanup + @on_kill.each { |cb| cb.call self } + self.text = "" + super + end end end diff --git a/lib/sup/modes/poll-mode.rb b/lib/sup/modes/poll-mode.rb index 5849f3e..cf61343 100644 --- a/lib/sup/modes/poll-mode.rb +++ b/lib/sup/modes/poll-mode.rb @@ -3,18 +3,16 @@ module Redwood class PollMode < LogMode def initialize @new = true - super - end - - def puts s="" - self << s + "\n" + super "poll for new messages" end def poll - puts unless @new - @new = false - puts "Poll started at #{Time.now}" - PollManager.do_poll { |s| puts s } + unless @new + @new = false + self << "\n" + end + self << "Poll started at #{Time.now}\n" + PollManager.do_poll { |s| self << (s + "\n") } end end diff --git a/lib/sup/modes/reply-mode.rb b/lib/sup/modes/reply-mode.rb index c79c5db..700dfc1 100644 --- a/lib/sup/modes/reply-mode.rb +++ b/lib/sup/modes/reply-mode.rb @@ -56,7 +56,7 @@ EOS ## don't check that it's an Account, though; assume they know what they're ## doing. if hook_reply_from && !(hook_reply_from.is_a? Person) - Redwood::log "reply-from returned non-Person, using default from." + info "reply-from returned non-Person, using default from." hook_reply_from = nil end diff --git a/lib/sup/modes/thread-view-mode.rb b/lib/sup/modes/thread-view-mode.rb index 737f6f1..bac4792 100644 --- a/lib/sup/modes/thread-view-mode.rb +++ b/lib/sup/modes/thread-view-mode.rb @@ -212,14 +212,14 @@ EOS bt = to.size > 1 ? "#{to.size} recipients" : to.to_s if BufferManager.ask_yes_or_no "Really bounce to #{bt}?" - Redwood::log "Bounce Command: #{cmd}" + debug "bounce command: #{cmd}" begin IO.popen(cmd, 'w') do |sm| sm.puts m.raw_message end raise SendmailCommandFailed, "Couldn't execute #{cmd}" unless $? == 0 rescue SystemCallError, SendmailCommandFailed => e - Redwood::log "Problem sending mail: #{e.message}" + warn "problem sending mail: #{e.message}" BufferManager.flash "Problem sending mail: #{e.message}" end end diff --git a/lib/sup/poll.rb b/lib/sup/poll.rb index a36a4c4..c348fb2 100644 --- a/lib/sup/poll.rb +++ b/lib/sup/poll.rb @@ -35,20 +35,17 @@ EOS @thread = nil @last_poll = nil @polling = false - end - - def buffer - b, new = BufferManager.spawn_unless_exists("poll for new messages", :hidden => true, :system => true) { PollMode.new } - b + @mode = nil end def poll return if @polling @polling = true + @mode ||= PollMode.new HookManager.run "before-poll" BufferManager.flash "Polling for new messages..." - num, numi, from_and_subj, from_and_subj_inbox = buffer.mode.poll + num, numi, from_and_subj, from_and_subj_inbox = @mode.poll if num > 0 BufferManager.flash "Loaded #{num.pluralize 'new message'}, #{numi} to inbox." else @@ -86,7 +83,7 @@ EOS begin yield "Loading from #{source}... " unless source.done? || (source.respond_to?(:has_errors?) && source.has_errors?) rescue SourceError => e - Redwood::log "problem getting messages from #{source}: #{e.message}" + warn "problem getting messages from #{source}: #{e.message}" Redwood::report_broken_sources :force_to_top => true next end @@ -142,7 +139,7 @@ EOS source.each do |offset, source_labels| if source.has_errors? - Redwood::log "error loading messages from #{source}: #{source.error.message}" + warn "error loading messages from #{source}: #{source.error.message}" return end @@ -155,7 +152,7 @@ EOS yield m end rescue SourceError => e - Redwood::log "problem getting messages from #{source}: #{e.message}" + warn "problem getting messages from #{source}: #{e.message}" Redwood::report_broken_sources :force_to_top => true end end diff --git a/lib/sup/sent.rb b/lib/sup/sent.rb index d381395..9203dd6 100644 --- a/lib/sup/sent.rb +++ b/lib/sup/sent.rb @@ -8,7 +8,6 @@ class SentManager def initialize source_uri @source = nil @source_uri = source_uri - Redwood::log "SentManager intialized with source uri: #@source_uri" end def source_id; @source.id; end @@ -21,7 +20,6 @@ class SentManager def default_source @source = Recoverable.new SentLoader.new - Redwood::log "SentManager initializing default source: #@source." @source_uri = @source.uri @source end diff --git a/lib/sup/source.rb b/lib/sup/source.rb index 7c9a265..8154591 100644 --- a/lib/sup/source.rb +++ b/lib/sup/source.rb @@ -139,7 +139,7 @@ class Source header[k] = begin Rfc2047.decode_to $encoding, v rescue Errno::EINVAL, Iconv::InvalidEncoding, Iconv::IllegalSequence => e - #Redwood::log "warning: error decoding RFC 2047 header (#{e.class.name}): #{e.message}" + #debug "warning: error decoding RFC 2047 header (#{e.class.name}): #{e.message}" v end end diff --git a/lib/sup/textfield.rb b/lib/sup/textfield.rb index c748c7a..b8dec59 100644 --- a/lib/sup/textfield.rb +++ b/lib/sup/textfield.rb @@ -112,11 +112,11 @@ class TextField unless @history.empty? value = get_cursed_value @i ||= @history.size - #Redwood::log "history before #{@history.inspect}" + #debug "history before #{@history.inspect}" @history[@i] = value #unless value =~ /^\s*$/ @i = (@i + (c == Ncurses::KEY_UP ? -1 : 1)) % @history.size @value = @history[@i] - #Redwood::log "history after #{@history.inspect}" + #debug "history after #{@history.inspect}" set_cursed_value @value Ncurses::Form::REQ_END_FIELD end diff --git a/lib/sup/util.rb b/lib/sup/util.rb index 5d57361..3f6b840 100644 --- a/lib/sup/util.rb +++ b/lib/sup/util.rb @@ -653,7 +653,7 @@ class Iconv begin Iconv.iconv(target + "//IGNORE", charset, text + " ").join[0 .. -2] rescue Errno::EINVAL, Iconv::InvalidEncoding, Iconv::InvalidCharacter, Iconv::IllegalSequence => e - Redwood::log "warning: error (#{e.class.name}) decoding text from #{charset} to #{target}: #{text[0 ... 20]}" + info "couldn't transcode text from #{charset} to #{target} (\"#{text[0 ... 20]}\"...)" text end end diff --git a/lib/sup/xapian_index.rb b/lib/sup/xapian_index.rb index f79b055..dbf6643 100644 --- a/lib/sup/xapian_index.rb +++ b/lib/sup/xapian_index.rb @@ -221,10 +221,10 @@ class XapianIndex < BaseIndex field, name = $1, ($3 || $4) case field when "filename" - Redwood::log "filename - translated #{field}:#{name} to attachment:\"#{name.downcase}\"" + debug "filename: translated #{field}:#{name} to attachment:\"#{name.downcase}\"" "attachment:\"#{name.downcase}\"" when "filetype" - Redwood::log "filetype - translated #{field}:#{name} to attachment_extension:#{name.downcase}" + debug "filetype: translated #{field}:#{name} to attachment_extension:#{name.downcase}" "attachment_extension:#{name.downcase}" end end @@ -238,13 +238,13 @@ class XapianIndex < BaseIndex if realdate case field when "after" - Redwood::log "chronic: translated #{field}:#{datestr} to #{realdate.end}" + debug "chronic: translated #{field}:#{datestr} to #{realdate.end}" "date:#{realdate.end.to_i}..#{lastdate}" when "before" - Redwood::log "chronic: translated #{field}:#{datestr} to #{realdate.begin}" + debug "chronic: translated #{field}:#{datestr} to #{realdate.begin}" "date:#{firstdate}..#{realdate.end.to_i}" else - Redwood::log "chronic: translated #{field}:#{datestr} to #{realdate}" + debug "chronic: translated #{field}:#{datestr} to #{realdate}" "date:#{realdate.begin.to_i}..#{realdate.end.to_i}" end else @@ -413,10 +413,10 @@ class XapianIndex < BaseIndex m.attachments.each { |a| text << [a, PREFIX['attachment']] } truncated_date = if m.date < MIN_DATE - Redwood::log "warning: adjusting too-low date #{m.date} for indexing" + debug "warning: adjusting too-low date #{m.date} for indexing" MIN_DATE elsif m.date > MAX_DATE - Redwood::log "warning: adjusting too-high date #{m.date} for indexing" + debug "warning: adjusting too-high date #{m.date} for indexing" MAX_DATE else m.date -- 2.45.2