# HG changeset patch
# User Sean Russell <ser@ser1.net>
# Date 1264875677 18000
#      Sat Jan 30 13:21:17 2010 -0500
# Node ID dd37f2831e1857fdafdac2e152c59b04aee57103
# Parent  1d15c6f53341f9274877fe985b223b0fd0fcd883
Bi-directional syncing of comments and state

== 2010.1 / 2010-01-30
* bugfix: Syncing is inefficient
* bugfix: Extract milestone and component creation
* bugfix: Filter out empty comments when updating Trac
* bugfix: Find a way to stop circular syncs
* bugfix: Add per-project configuration
* Add support for components
* Add debug mode
* Add ability to change title

diff --git a/.ditz/issue-3455abd67e78f997c74d72aff184585b74083415.yaml b/.ditz/issue-3455abd67e78f997c74d72aff184585b74083415.yaml
--- a/.ditz/issue-3455abd67e78f997c74d72aff184585b74083415.yaml
+++ b/.ditz/issue-3455abd67e78f997c74d72aff184585b74083415.yaml
@@ -3,10 +3,10 @@
 desc: ""
 type: :task
 component: trac to ditz
-release: "2010.2"
+release: "2010.1"
 reporter: Sean Russell <ser@ser1.net>
-status: :unstarted
-disposition: 
+status: :closed
+disposition: :fixed
 creation_time: 2010-01-27 04:13:08.968743 Z
 references: []
 
@@ -26,4 +26,12 @@
   - |-
     Right now, ditz-trac syncs by ID, but when that fails (the ticket was created on Trac, for instance)
     it attempts to match by title.  Also, the title isn't something that ditz-trac syncs.
+- - 2010-01-30 18:13:58.588646 Z
+  - Sean Russell <ser@ser1.net>
+  - assigned to release 2010.1 from 2010.2
+  - ""
+- - 2010-01-30 18:14:14.832681 Z
+  - Sean Russell <ser@ser1.net>
+  - closed with disposition fixed
+  - ""
 trac_id: 3
diff --git a/.ditz/issue-346223318c35bdac90b33437bc0d266e05475d9f.yaml b/.ditz/issue-346223318c35bdac90b33437bc0d266e05475d9f.yaml
--- a/.ditz/issue-346223318c35bdac90b33437bc0d266e05475d9f.yaml
+++ b/.ditz/issue-346223318c35bdac90b33437bc0d266e05475d9f.yaml
@@ -3,10 +3,10 @@
 desc: It's just noise.
 type: :bugfix
 component: ditz to trac
-release: 
+release: "2010.1"
 reporter: Sean Russell <ser@ser1.net>
-status: :unstarted
-disposition: 
+status: :closed
+disposition: :fixed
 creation_time: 2010-01-28 03:18:45.215182 Z
 references: []
 
@@ -16,4 +16,12 @@
   - Sean Russell <ser@ser1.net>
   - created
   - ""
+- - 2010-01-30 18:14:39.952715 Z
+  - Sean Russell <ser@ser1.net>
+  - assigned to release 2010.1 from unassigned
+  - ""
+- - 2010-01-30 18:15:01.288702 Z
+  - Sean Russell <ser@ser1.net>
+  - closed with disposition fixed
+  - ""
 trac_id: 12
diff --git a/.ditz/issue-4d26d5a4a0a8500f1b24d28a954c3624be95097f.yaml b/.ditz/issue-4d26d5a4a0a8500f1b24d28a954c3624be95097f.yaml
--- a/.ditz/issue-4d26d5a4a0a8500f1b24d28a954c3624be95097f.yaml
+++ b/.ditz/issue-4d26d5a4a0a8500f1b24d28a954c3624be95097f.yaml
@@ -5,8 +5,8 @@
 component: ditz-trac
 release: "2010.1"
 reporter: Sean Russell <ser@ser1.net>
-status: :unstarted
-disposition: 
+status: :closed
+disposition: :fixed
 creation_time: 2010-01-27 04:11:32.584890 Z
 references: []
 
@@ -24,4 +24,8 @@
   - Sean Russell <ser@ser1.net>
   - assigned to release 2010.1 from unassigned
   - ""
+- - 2010-01-30 18:13:38.248644 Z
+  - Sean Russell <ser@ser1.net>
+  - closed with disposition fixed
+  - ""
 trac_id: 1
diff --git a/.ditz/issue-e9972f258450d6aca85514f2a8d91b3240b66a41.yaml b/.ditz/issue-e9972f258450d6aca85514f2a8d91b3240b66a41.yaml
--- a/.ditz/issue-e9972f258450d6aca85514f2a8d91b3240b66a41.yaml
+++ b/.ditz/issue-e9972f258450d6aca85514f2a8d91b3240b66a41.yaml
@@ -3,7 +3,7 @@
 desc: pair() is pretty dumb about error cases.
 type: :bugfix
 component: ditz-trac
-release: "2010.1"
+release: "2010.2"
 reporter: Sean Russell <ser@ser1.net>
 status: :unstarted
 disposition: 
@@ -16,4 +16,8 @@
   - Sean Russell <ser@ser1.net>
   - created
   - ""
+- - 2010-01-30 18:14:25.968631 Z
+  - Sean Russell <ser@ser1.net>
+  - assigned to release 2010.2 from 2010.1
+  - ""
 trac_id: 10
diff --git a/.ditz/project.yaml b/.ditz/project.yaml
--- a/.ditz/project.yaml
+++ b/.ditz/project.yaml
@@ -11,13 +11,17 @@
 releases: 
 - !ditz.rubyforge.org,2008-03-06/release 
   name: "2010.1"
-  status: :unreleased
-  release_time: 
+  status: :released
+  release_time: 2010-01-30 18:20:19.161223 Z
   log_events: 
   - - 2010-01-27 04:32:11.788699 Z
     - Sean Russell <ser@ser1.net>
     - created
     - ""
+  - - 2010-01-30 18:20:19.161257 Z
+    - Sean Russell <ser@ser1.net>
+    - released
+    - ""
 - !ditz.rubyforge.org,2008-03-06/release 
   name: "2010.2"
   status: :unreleased
diff --git a/trac-sync.rb b/trac-sync.rb
--- a/trac-sync.rb
+++ b/trac-sync.rb
@@ -2,6 +2,9 @@
 #
 # Provides ditz <-> trac synchronization
 #
+# Author::  Sean Russell <seanerussell@gmail.com>
+# Version:: 2010.1
+#
 # Command added:
 #   ditz sync: synchronize issues with Trac
 #
@@ -12,6 +15,7 @@
 require 'rubygems'
 require 'trac4r'
 require 'ditz'
+require 'logger'
 
 module Ditz
 
@@ -105,8 +109,8 @@
     DSTATUS_TSTATUS[ :paused ] = "assigned" 
 
 
-    def initialize( project, config, trac )
-      @project, @config, @trac = project, config, trac
+    def initialize( project, config, trac, logger )
+      @project, @config, @trac, @logger = project, config, trac, logger
     end
 
 
@@ -115,15 +119,17 @@
     def pair( tickets )
       rv = []
       issues = @project.issues.clone
+      @logger.debug("Have #{tickets.size} tickets")
+      @logger.debug("Tickets: #{tickets.collect{|t|t.summary}.inspect}")
       for ticket in tickets 
         issue = issues.find { |i| equal?( ticket, i ) }
         if issue
           if !issue.trac_id.nil? and (issue.trac_id != ticket.id)
-            puts "ERROR! Found a match by title, but the IDs don't match!!"
-            puts "       issue has #{issue.trac_id}, ticket has #{ticket.id}"
+            @logger.error("ERROR! Found a match by title, but the IDs don't match!!")
+            @logger.error("       issue has #{issue.trac_id}, ticket has #{ticket.id}")
             # TODO do something useful here
           end
-          puts "Found ticket/issue match #{ issue.trac_id ? "by id" : "by name"}"
+          @logger.info("Found ticket/issue match #{ issue.trac_id ? "by id" : "by name"}")
           issues.delete(issue)
           issue.trac_id = ticket.id if issue.trac_id.nil?
         end
@@ -132,6 +138,7 @@
       # Now put the left-over, unmatched issues in with a nil ticket
       # TODO check here that none of these issues have trac_ids.
       for issue in issues
+        @logger.info("Found no match for #{issue.id[0,4]}: #{issue.title}")
         rv << [nil,issue]
       end
       rv
@@ -144,7 +151,7 @@
       maybe_create_milestones
       maybe_create_components
       issues.each do |t,i| # t will always be nil
-        tid = @trac.tickets.create( i.title, i.desc, { 
+        attrs = { 
           "created_at" => i.creation_time,
           "type"       => DTYPE_TTYPE[ i.type ],
           "reporter"   => i.reporter || "",
@@ -152,10 +159,19 @@
           "component"  => i.component || "",
           "status"     => DSTATUS_TSTATUS[ i.status ] || "",
           "resolution" => DISPO_RES[ i.disposition ] || ""
-        } )
+        }
+        tid = nil
+        try {
+          tid = @trac.tickets.create( i.title, i.desc, attrs )
+        }
+        @logger.debug("Created ticket #{tid} from #{i.id[0,4]} with #{attrs.inspect}")
         i.trac_id = tid
-        rv[i] = @trac.tickets.get(tid)
+        try {
+          rv[i] = @trac.tickets.get(tid)
+        }
+        raise "Got nil for a ticket we just created!" if rv[i].nil?
       end
+      @logger.info("Created #{rv.size} new tickets")
       rv
     end
 
@@ -167,19 +183,19 @@
       tickets.each do |t,i|   # i will always be nil
         # trac4r doesn't yet support resolution
         resolution = t.status == "closed" ? :fixed : nil
-        maybe_create_release( t.milestone )
+        release = maybe_create_release( t.milestone )
         maybe_create_component( t.component )
 
-        if release.status == :released
-          puts "Orphaned ticket ##{t.id}: milestone #{t.milestone} already released!"
-          puts "\t#{t.summary}"
+        if release and release.status == :released
+          @logger.warn("Orphaned ticket ##{t.id}: milestone #{t.milestone} already released!")
+          @logger.warn("\t#{t.summary}")
         else
           issue = Ditz::Issue.create({:reporter => t.reporter,
                                      :creation_time => t.created_at.to_time,
                                      :title => t.summary,
                                      :type  => TTYPE_DTYPE[ t.type ],
                                      :desc  => t.description,
-                                     :release => t.milestone,
+                                     :release => release,
                                      :component => t.component,
                                      :status => TSTATUS_DSTATUS[ t.status ],
                                      :disposition => resolution,
@@ -188,7 +204,7 @@
           }, [@config, @project])
 
           @project.add_issue( issue )
-          puts "Created issue #{issue.id[0,4]}: #{issue.title}"
+          @logger.info("Created issue #{issue.id[0,4]}: #{issue.title}")
           rv[t] = issue
         end
       end
@@ -203,7 +219,7 @@
     # ticket status if it differs 
     def update_tickets( pairs )
       pairs.each do |ticket, issue|
-        puts "Working on #{ticket.id}/#{issue.id[0,4]}"
+        @logger.info("Working on #{ticket.id}/#{issue.id[0,4]}")
         copy_comments( ticket, issue )
         issue_last_changed = if issue.log_events.size == 0
                                issue.creation_time
@@ -227,8 +243,10 @@
           if DTYPE_TTYPE[issue.type] != ticket.type
             attrs["type"] = DTYPE_TTYPE[issue.type]
           end
-          puts "Updating ticket #{ticket.id} with #{attrs.inspect}"
-          @trac.query( "ticket.update", ticket.id, "Ticket synced from ditz by #{@config.user}", attrs )
+          @logger.info("Updating ticket #{ticket.id} with #{attrs.inspect}")
+          try {
+            @trac.query( "ticket.update", ticket.id, "Ticket synced from ditz by #{@config.user}", attrs )
+          }
         end
       end
     end
@@ -236,7 +254,7 @@
 
     def update_issues( pairs )
       pairs.each do |ticket, issue|
-        puts "Working on #{ticket.id}/#{issue.id[0,4]}"
+        @logger.info( "Working on #{ticket.id}/#{issue.id[0,4]}" )
         copy_comments( issue, ticket )
         issue_last_changed = if issue.log_events.size == 0
                                issue.creation_time
@@ -268,46 +286,88 @@
     # Utility methods used internal to the class
     private
 
+
+    def try
+      tries = 0
+      begin
+        @logger.debug( "Try #{tries}" )
+        yield
+        tries = 0
+      rescue Trac::TracException => err
+        @logger.warn(err.message) if tries == 0
+        case err.message
+        when /Wrong type NilClass/, /end of file reached/
+          @logger.warn("Had to re-connect to Trac")
+          @trac = Trac.new(@config.trac_sync_url, 
+                           @config.trac_sync_user, 
+                           @config.trac_sync_pass)
+        else
+          sleep 0.5
+        end
+        tries += 1
+        if tries <= 5
+          @logger.warn("Retry ##{tries}")
+          retry
+        else
+          raise
+        end
+      end
+    end
+
+
     def copy_comments( a, b )
+      raise "Can't copy to/from nil." if a.nil? or b.nil?
       if a.instance_of? Issue
         issue, ticket = a, b
       else
         ticket, issue = a, b
       end
 
-      cl = @trac.tickets.changelog( ticket.id )
+      cl = nil
+      try {
+        cl = @trac.tickets.changelog( ticket.id )
+      }
       el = issue.log_events
 
       cl_comments = cl.find_all { |c| c[2] == "comment" }
       el_comments = el.find_all { |e| e[2] == "commented" }
 
       cl_comments.reject! do |c| 
-        m = el_comments.find { |e| e[2] == c[3] }
+        @logger.debug("Looking for #{c[4].inspect} in #{el_comments.collect{|m| m[3]}.inspect}")
+        m = el_comments.find { |e| e[3] == c[4] }
         if m
+          @logger.debug("Found it.")
           el_comments.delete(m)
           true
         else
+          @logger.debug("Not found")
           false
         end
       end
 
       cl_comments.each do |c|
-        unless c[3]=="" || c[3].nil?
-          puts "Updating ticket #{ticket.id} with comment #{c[3].inspect}"
-          @trac.query( "ticket.update", ticket.id, c[3] )
+        unless c[4]=="" || c[4].nil?
+          @logger.info( "Updating issue #{issue.id} with comment #{c[4].inspect}" )
+          issue.log_at( c[0].to_time, "commented", c[1], c[4] )
         end
       end
 
-      el_comments.each do |e|
-        unless e[4]=="" || e[4].nil?
-          puts "Updating issue #{issue.id} with comment #{e[4].inspect}"
-          issue.log_at( e[0], "commented", e[1], e[4] )
+      if el_comments.size > 0
+        @logger.debug( "Issue comments =>" )
+        @logger.debug( el_comments.inspect )
+        el_comments.each do |e|
+          unless e[3]=="" || e[3].nil?
+            @logger.info( "Updating ticket #{ticket.id} with comment #{e[3].inspect}" )
+            try {
+              @trac.query( "ticket.update", ticket.id, e[3] )
+            }
+          end
         end
       end
     end
 
     def equal?( ticket, issue )
-      ticket.id == issue.id || ticket.summary == issue.title
+      (ticket.id == issue.trac_id) || (ticket.summary == issue.title)
     end
 
     def change_status(status, issue)
@@ -322,23 +382,28 @@
     # Creates a ditz release, IFF it doesn't exist
     # milestone: the String name of the release to create
     def maybe_create_release( milestone )
+      return nil if milestone.nil? or milestone == ""
       release = @project.releases.find { |r| r.name == milestone }
       unless release 
-        puts "Creating release #{milestone}"
+        @logger.info( "Creating release #{milestone.inspect}" )
         release = Ditz::Release.create({:name=>milestone}, [@config, @project])
         @project.add_release(release)
       end
+      release
     end
 
     # Creates a ditz component, IFF it doesn't already exist
     # comp: the String name of the component to create
     def maybe_create_component( comp )
+      return "" if comp.nil? or comp == ""
+      @logger.debug( @project.components.inspect )
       component = @project.components.find { |r| r.name == comp }
       unless component 
-        puts "Creating component #{comp}"
+        @logger.info( "Creating component #{comp}" )
         component = Ditz::Component.create({:name=>comp}, [@config, @project])
         @project.add_component(component)
       end
+      component
     end
 
     def group_by_time(changelog)
@@ -355,10 +420,15 @@
     # in Trac
     # trac: the trac4r object to create the components in
     def maybe_create_components
-      components = @trac.query("ticket.component.getAll")
+      components = nil
+      try {
+        components = @trac.query("ticket.component.getAll")
+      }
       @project.components.each do |component|
         next if components.include? component.name
-        @trac.query("ticket.component.create", component.name, {})
+        try {
+          @trac.query("ticket.component.create", component.name, {})
+        }
       end
     end
 
@@ -366,23 +436,50 @@
     # Trac
     # trac: the trac4r object to create the milestones in
     def maybe_create_milestones
-      milestones = @trac.query("ticket.milestone.getAll")
+      milestones = nil
+      try {
+        milestones = @trac.query("ticket.milestone.getAll")
+      }
       @project.releases.each do |release|
         next if milestones.include? release.name
-        desc = rel = ""
+        attrs = {}
         release.log_events.each do |ev| 
           case ev[2]
           when "created"
-            desc = ev[3]
+            attrs["description"] = ev[3]
           when "released"
-            rel = ev[0]
+            attrs["completed"] = ev[0]
           end
         end
+        try {
+          @trac.query("ticket.milestone.create", release.name, attrs)
+        }
+      end
+    end
+
+    def maybe_create_resolutions
+      try {
         @trac.query("ticket.milestone.create", release.name, {
           "completed" => rel,
           "description" => desc
         })
-      end
+      }
+    end
+    def maybe_create_status
+      try {
+        @trac.query("ticket.milestone.create", release.name, {
+          "completed" => rel,
+          "description" => desc
+        })
+      }
+    end
+    def maybe_create_type
+      try {
+        @trac.query("ticket.milestone.create", release.name, {
+          "completed" => rel,
+          "description" => desc
+        })
+      }
     end
   end
 
@@ -401,24 +498,36 @@
 
 
   class Operator
-    operation :trac, "Sync with a Trac repository"
-    def trac( project, config )
+    operation :trac, "Sync with a Trac repository", :maybe_debug, :maybe_verbose, :maybe_version do
+      opt :debug, "Run in debug mode, for very verbose output", :short => 'd', :default => false
+      opt :verbose, "Run in verbose mode", :short => 'v', :default => false
+    end 
+    def trac( project, config, opts, *args )
+      logger = Logger.new(STDERR)
+      logger.level = Logger::WARN
+      logger.level = Logger::DEBUG if opts[:debug]
+      logger.level = Logger::INFO if opts[:verbose]
       unless config.trac_sync_url
-        STDERR.puts( "Please run 'ditz reconfigure' and set the Trac URL" )
+        logger.error( "Please run 'ditz reconfigure' and set the Trac URL" )
         return
       end
       unless config.trac_sync_user
-        STDERR.puts( "Please run 'ditz reconfigure' and set the Trac XMLRPC user name" )
+        logger.error( "Please run 'ditz reconfigure' and set the Trac XMLRPC user name" )
         return
       end
       unless config.trac_sync_pass
-        STDERR.puts( "Please run 'ditz reconfigure' and set the Trac XMLRPC password" )
+        logger.error( "Please run 'ditz reconfigure' and set the Trac XMLRPC password" )
         return
       end
       trac = Trac.new(config.trac_sync_url, config.trac_sync_user, config.trac_sync_pass)
-      util = Ditz::TracUtil.new( project, config, trac )
+      util = Ditz::TracUtil.new( project, config, trac, logger )
 
-      tickets = trac.tickets.get_all.values
+      tickets = trac.query("ticket.query", "status=new&max=1000000&order=id")
+      logger.info("Fetching #{tickets.size} tickets...")
+      tickets.collect! {|id|
+        STDOUT.print(".") ; STDOUT.flush
+        trac.tickets.get(id)
+      }
       changelogs = []
 
       # TODO this is really inefficient.  No need to re-update things that have 
@@ -427,16 +536,27 @@
 
       # Existing [ticket,issue] matches
       pairs = util.pair(tickets)
+      logger.debug( "All pairs: " )
+      logger.debug( pairs.collect {|t,i| [ t ? t.id : nil, i ? i.id[0,4] : nil ]}.inspect )
 
       # Create and update any missing issues.  new_pairs is {ticket=>new_issue} hash
-      issues_only = pairs.find_all {|m| m[1] == nil}
-      new_issues = util.create_issues( issues_only )
-      issues_only.each { |m| m[1] = new_issues[m[0]] }
+      only_tickets = pairs.find_all {|m| m[1] == nil}
+      new_issues = util.create_issues( only_tickets )
+      pairs.each { |m| m[1] = new_issues[m[0]] unless m[1] }
 
       # Create and update any missing tickets. new_tickets is {issue=>new_ticket} hash
-      tickets_only = pairs.find_all {|m| m[0] == nil}
-      new_tickets = util.create_tickets( tickets_only )
-      tickets_only.each { |m| m[0] = new_tickets[m[1]] }
+      only_issues = pairs.find_all {|m| m[0] == nil}
+      new_tickets = util.create_tickets( only_issues )
+      pairs.each { |m| m[0] = new_tickets[m[1]] unless m[0] }
+
+      # We can't create issues for releases that are already released (ditz
+      # limitation), so ignore those.
+      pairs.reject! { |t,i| i.nil? }
+      pairs.each do |t,i| 
+        if t.nil?
+          logger.error("Failed to create a ticket for issue #{i.id[0,4]}, somehow.")
+        end
+      end
 
       # Now, update the issues and tickets with any changes that have occurred since
       # the last change on the partner. We don't need to update objects which caused a
@@ -444,10 +564,15 @@
       # the ticket.
       #
       # Don't update issues that just created a new ticket
-      issues_to_update = pairs.reject {|t,i| !new_tickets[i].nil? }
-      util.update_issues( issues_to_update )
+      issues_to_update = pairs.reject {|t,i| new_tickets[i] }
+      logger.debug("Issues to update:")
+      logger.debug(issues_to_update.collect{|t,i| i.id[0,4] }.inspect)
+      #util.update_issues( issues_to_update )
+
       # Don't update tickets that just created a new issue
-      tickets_to_update = pairs.reject {|t,i| !new_issues[t].nil? }
+      tickets_to_update = pairs.reject {|t,i| new_issues[t] }
+      logger.debug("Tickets to update:")
+      logger.debug(tickets_to_update.collect{|t,i| t.id }.inspect)
       util.update_tickets( tickets_to_update )
     end
   end
diff --git a/xmlrpc_client.patch b/xmlrpc_client.patch
new file mode 100644
--- /dev/null
+++ b/xmlrpc_client.patch
@@ -0,0 +1,11 @@
+--- old/xmlrpc/client.rb	2008-07-16 13:07:44.000000000 -0400
++++ new/xmlrpc/client.rb	2010-01-28 22:35:49.000000000 -0500
+@@ -550,7 +550,7 @@
+       end
+ 
+       ct = parse_content_type(resp["Content-Type"]).first
+-      if ct != "text/xml"
++      if ct != "text/xml" && ct != "application/xml"
+         if ct == "text/html"
+           raise "Wrong content-type (received '#{ct}' but expected 'text/xml'): \n#{data}"
+         else