Cannot update a ticket using trac.ticket.model.save_changes with both a 'comment' and a 'when' field.

[François Granade]

This was found in the TicketImportPlugin, see #10188, and took me some time to debug. The following piece of code (given an env environment):

from trac.ticket.web_ui import Ticket 
from datetime import datetime 
from trac.util.datefmt import utc 
ticket = Ticket(env) 
ticket['summary'] = 'The summary' 
ticket.insert() 
ticket['blockedby'] = str(ticket.id) 
ticket.save_changes('someone', comment='Some comments',
                    when=datetime.now(utc)) 

will work if the MasterTicketsPlugin is not installed, but will fail if it is installed, with the following error:

ticket.save_changes('someone', 'Some comments',
                    when=datetime.now(utc))
  File "/Users/francois/ticketimportplugin/0.11/env2.5/lib/python2.5/site-packages/Trac-0.12-py2.5.egg/trac/ticket/model.py", line 353, in save_changes
    listener.ticket_changed(self, comment, author, old_values)
  File "build/bdist.macosx-10.7-x86_64/egg/mastertickets/api.py", line 111, in ticket_changed
    links.save(author, comment, tkt.time_changed, db)
  File "build/bdist.macosx-10.7-x86_64/egg/mastertickets/model.py", line 76, in save
    (n, when_ts, author, 'comment', '', '(In #%s) %s'%(self.tkt.id, comment)))
  File "/Users/francois/ticketimportplugin/0.11/env2.5/lib/python2.5/site-packages/Trac-0.12-py2.5.egg/trac/db/util.py", line 65, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "/Users/francois/ticketimportplugin/0.11/env2.5/lib/python2.5/site-packages/Trac-0.12-py2.5.egg/trac/db/sqlite_backend.py", line 79, in execute
    result = PyFormatCursor.execute(self, *args)
  File "/Users/francois/ticketimportplugin/0.11/env2.5/lib/python2.5/site-packages/Trac-0.12-py2.5.egg/trac/db/sqlite_backend.py", line 57, in execute
    args or [])
  File "/Users/francois/ticketimportplugin/0.11/env2.5/lib/python2.5/site-packages/Trac-0.12-py2.5.egg/trac/db/sqlite_backend.py", line 48, in _rollbac\
k_on_error
    return function(self, *args, **kwargs)
IntegrityError: columns ticket, time, field are not unique

See browser:ticketimportplugin/0.11/talm_importer/test.py@11805#L460​

[falkb]

Any progress or patches I could test?

[Ryan J Ollos]

Yeah, I'll be pushing some changes shortly.

[falkb]

Replying to rjollos:

Yeah, I'll be pushing some changes shortly.

Do you know now when "shortly" is?

[Ryan J Ollos]

#10207 closed as a duplicate.

[Ryan J Ollos]

I'm not sure why the issue was occurring here, but I could reproduce the same traceback by moving a ticket number between the blocking and blocked by field while also adding a comment. Please let me know if the issue is fixed in 3.0.4 (see ​fa5464a5).

[falkb]

Sorry, I tried the latest version of masterticketsplugin from ​here but importing my simple bug.xls with the ticketimportplugin plugin (latest svn revision ) still fails on my Trac-1.0.1 with that internal error IntegrityError: columns ticket, time, field are not unique :

File "build/bdist.win32/egg/trac/web/main.py", line 497, in _dispatch_request
  dispatcher.dispatch(req)
File "build/bdist.win32/egg/trac/web/main.py", line 214, in dispatch
  resp = chosen_handler.process_request(req)
File "build/bdist.win32/egg/talm_importer/importer.py", line 86, in process_request
  encoding=req.session['importer.encoding'])
File "build/bdist.win32/egg/talm_importer/importer.py", line 130, in _do_import
  return self._process(filereader, get_reporter_id(req), ImportProcessor(self.env, req, uploadedfilename, tickettime))
File "build/bdist.win32/egg/talm_importer/importer.py", line 401, in _process
  processor.end_process_row()
File "build/bdist.win32/egg/talm_importer/processors.py", line 133, in end_process_row
  self.ticket.insert(when=self._tickettime(), db=self.db)
File "build/bdist.win32/egg/trac/ticket/model.py", line 256, in insert
  listener.ticket_created(self)
File "build/bdist.win32/egg/mastertickets/api.py", line 115, in ticket_created
  self.ticket_changed(tkt, '', tkt['reporter'], {})
File "build/bdist.win32/egg/mastertickets/api.py", line 120, in ticket_changed
  links.save(author, comment, tkt.time_changed, db)
File "build/bdist.win32/egg/mastertickets/model.py", line 82, in save
  (n, when_ts, author, field, old_value, new_value))
File "build/bdist.win32/egg/trac/db/util.py", line 65, in execute
  return self.cursor.execute(sql_escape_percent(sql), args)
File "build/bdist.win32/egg/trac/db/sqlite_backend.py", line 78, in execute
  result = PyFormatCursor.execute(self, *args)
File "build/bdist.win32/egg/trac/db/sqlite_backend.py", line 56, in execute
  args or [])
File "build/bdist.win32/egg/trac/db/sqlite_backend.py", line 48, in _rollback_on_error
  return function(self, *args, **kwargs)

It's at that cursor.execute('INSERT INTO ticket_change (ticket, time, author, field, oldvalue, newvalue) VALUES (%s, %s, %s, %s, %s, %s)', (n, when_ts, author, field, old_value, new_value))

[Ryan J Ollos]

This traceback looks like it may have a different cause. What you are showing now is that it's failing while creating a ticket (i.e. on the call to insert, whereas the original reporter showed a problem when calling save_changes).

  self.ticket.insert(when=self._tickettime(), db=self.db)
File "build/bdist.win32/egg/trac/ticket/model.py", line 256, in insert
  listener.ticket_created(self)
File "build/bdist.win32/egg/mastertickets/api.py", line 115, in ticket_created
  self.ticket_changed(tkt, '', tkt['reporter'], {})
File "build/bdist.win32/egg/mastertickets/api.py", line 120, in ticket_changed
  links.save(author, comment, tkt.time_changed, db)
File "build/bdist.win32/egg/mastertickets/model.py", line 82, in save
  (n, when_ts, author, field, old_value, new_value))
File "build/bdist.win32/egg/trac/db/util.py", line 65, in execute

I'll take a look later today.

[falkb]

rjollos, I think I see the mistake, just look at ​your given diff. That cursor.execute( INSERT INTO ticket_change ... -thingy is called twice now. I bet your diff is wrong and the first call of INSERT INTO must be removed, right?

[Ryan J Ollos]

That code also confused me when first studying it. The first INSERT INTO updates the ticket links (or relations). The second one adds a "tracback" (ala TracBacksPlugin) comment into the ticket that is referenced. What my change there did was to make sure that there was never an attempt to insert the "tracback" comment more than once, which was leading to the same error reported in this ticket.

It will be easy enough to locate the issue you are seeing by setting up a unit test. I plan to spend some more time looking at it this evening. I actually fixed a few issues over the weekend so you could test again, but I doubt the issues I fixed this weekend were in any way related to your issue.

[Ryan J Ollos]

(In [12936]) Refs #10194: Fixed Traceback when moving a ticket number between the blocking and blocked by field and also adding a comment.

[Ryan J Ollos]

(In [12950]) Refs #10194: Implemented a fix for the IntegrityError when importing tickets with the TicketImportPlugin and not defining a changetime in the dataset (or in some cases of using the same changetime for multiple tickets).

The ticket id, time and field columns must be unique in the ticket_change table. Importing a set of tickets that are all assigned a changetime of "now" will result in an IntegrityError whenever two or more ticket share a relation with a single other ticket.

This feels like more of a workaround than a solution, but it will hopefully do for now.

[falkb]

Please, could you try attachment importtest2.xls of #10118? There are still errors you can reproduce with that test file.

[falkb]

I found out it's the combination of #BlockedBy and #Blocking that causes the error in importtest2.xls. If I remove one of both table columns, it works fine. Hoping this helps you to find the bug.

[Cinc-th]

Just as a piece of information. I've seen similar IntegrityError: columns ticket, time, field are not unique errors when importing ticket data with some private plugin in the past.

The culprit was the coarse timer resolution on my Windows system for the timestamp. I solved this by just adding a microsecond (iirc) to the .now()-time on subsequent inserts.