Deleted tickets in query cache cause traceback

[anonymous]

Oops…
Trac detected an internal error:

TypeError: can't compare datetime.datetime to int

If you think this should work you can reproduce the problem, you should consider reporting this to the Trac team.

Before you do that, though, please first try searching for similar issues, as it is quite likely that this problem has been reported before. For questions about installation and configuration of Trac, please try the mailing list instead of filing a ticket.

Otherwise, please ==== How to Reproduce ==== While doing a GET operation on `/query`, Trac issued an internal error. ''(please provide additional details here)'' Request parameters: {{{ {'milestone': u'Untriaged', 'order': u'priority', 'status': [u'new', u'assigned', u'reopened']} }}} ==== System Information ==== || '''Trac''' || `0.11dev-r5992` || || '''Python''' || `2.5.1 (r251:54863, May 2 2007, 16:27:44) ` [[br]] `[GCC 4.1.2 (Ubuntu 4.1.2-0ubuntu4)]` || || '''setuptools''' || `0.6c7` || || '''SQLite''' || `3.3.13` || || '''pysqlite''' || `2.3.2` || || '''Genshi''' || `0.4.4` || ==== Python Traceback ==== {{{ Traceback (most recent call last): File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/web/main.py", line 381, in dispatch_request dispatcher.dispatch(req) File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/web/main.py", line 191, in dispatch resp = chosen_handler.process_request(req) File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 638, in process_request return self.display_html(context, query) File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 720, in display_html data = query.template_data(context, tickets, orig_list, orig_time) File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 506, in template_data if ticket['time'] > orig_time: TypeError: can't compare datetime.datetime to int }}} a new ticket at the Trac project site, where you can describe the problem and explain how to reproduce it.
Python Traceback
Most recent call last:

    * File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/web/main.py", line 381, in dispatch_request
      Code fragment:
       376. if not env and env_error:
       377. raise HTTPInternalError(env_error)
       378. try:
       379. try:
       380. dispatcher = RequestDispatcher(env)
       381. dispatcher.dispatch(req)
       382. except RequestDone:
       383. pass
       384. return req._response or []
       385. finally:
       386. if not run_once:
      Local variables:
      Name	Value
      after 	[' except RequestDone:', ' pass', ' ...
      before 	[' if not env and env_error:', ' raise ...
      dispatcher 	<trac.web.main.RequestDispatcher object at 0x121e0d0>
      e 	TypeError("can't compare datetime.datetime to int",)
      env 	<trac.env.Environment object at 0xd26cd0>
      env_error 	None
      env_path 	'/home/olpc-code/newtrac'
      environ 	{'trac.base_url': u'https://dev.laptop.org/', 'wsgi.multiprocess': True, ...
      exc_info 	(<type 'exceptions.TypeError'>, TypeError("can't compare datetime.datetime ...
      filename 	'/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.eg ...
      frames 	[{'function': 'dispatch_request', 'lines_before': [' if not env and ...
      has_admin 	True
      line 	' dispatcher.dispatch(req)'
      lineno 	380
      message 	u"TypeError: can't compare datetime.datetime to int"
      path_info 	'/query'
      req 	<Request "GET u'/query'">
      run_once 	False
      script_url 	'/query'
      start_response 	<function start_response at 0x44bf050>
      tb 	<traceback object at 0x2fd6b48>
      tb_hide 	None
      traceback 	'Traceback (most recent call last):\n File ...
    * File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/web/main.py", line 191, in dispatch
      Code fragment:
       186. 'Do you have cookies enabled?')
       187.  
       188. # Process the request and render the template
       189. try:
       190. try:
       191. resp = chosen_handler.process_request(req)
       192. if resp:
       193. if len(resp) == 2: # Clearsilver
       194. chrome.populate_hdf(req)
       195. template, content_type = \
       196. self._post_process_request(req, *resp)
      Local variables:
      Name	Value
      chosen_handler 	<trac.ticket.query.QueryModule object at 0x1267910>
      chrome 	<trac.web.chrome.Chrome object at 0x110f490>
      err 	(<type 'exceptions.TypeError'>, TypeError("can't compare datetime.datetime ...
      handler 	<trac.ticket.query.QueryModule object at 0x1267910>
      req 	<Request "GET u'/query'">
      self 	<trac.web.main.RequestDispatcher object at 0x121e0d0>
    * File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 638, in process_request
      Code fragment:
       633. format = req.args.get('format')
       634. if format:
       635. Mimeview(self.env).send_converted(req, 'trac.ticket.Query', query,
       636. format, 'query')
       637.  
       638. return self.display_html(context, query)
       639.  
       640. # Internal methods
       641.  
       642. def _get_constraints(self, req):
       643. constraints = {}
      Local variables:
      Name	Value
      cols 	None
      constraints 	{'status': [u'new', u'assigned', u'reopened'], 'milestone': ...
      context 	<Context '[root]' <Request "GET u'/query'">>
      conversion 	('tab', 'Tab-delimited Text', 'tsv', 'trac.ticket.Query', ...
      format 	None
      query 	<trac.ticket.query.Query object at 0x1c322d0>
      req 	<Request "GET u'/query'">
      rows 	[]
      self 	<trac.ticket.query.QueryModule object at 0x1267910>
    * File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 720, in display_html
      Code fragment:
       715. except TracError, e:
       716. data = {'id': rest_id, 'time': 0, 'changetime': 0,
       717. 'summary': tag.em(e)}
       718. tickets.insert(orig_list.index(rest_id), data)
       719.  
       720. data = query.template_data(context, tickets, orig_list, orig_time)
       721.  
       722. # For clients without JavaScript, we add a new constraint here if
       723. # requested
       724. constraints = data['constraints']
       725. if 'add' in req.args:
      Local variables:
      Name	Value
      context 	<Context '[root]' <Request "GET u'/query'">>
      data 	{'changetime': 0, 'summary': <Element "em">, 'id': 3863, 'time': 0}
      db 	<trac.db.pool.PooledConnection object at 0x44bae60>
      e 	ResourceNotFound('Ticket 3863 does not exist.',)
      id 	u'3863'
      orig_list 	[3813, 3830, 2448, 2651, 2712, 2717, 2837, 2839, 2926, 2973, 3117, 3782, ...
      orig_time 	datetime.datetime(2007, 9, 26, 17, 26, 2, tzinfo=<FixedOffset "UTC" ...
      query 	<trac.ticket.query.Query object at 0x1c322d0>
      query_constraints 	u"{'status': [u'new', u'assigned', u'reopened'], 'milestone': ...
      query_time 	datetime.datetime(2007, 9, 26, 17, 26, 2, tzinfo=<FixedOffset "UTC" ...
      req 	<Request "GET u'/query'">
      rest_id 	3863
      rest_list 	[3813, 2448, 2651, 2712, 3825, 3826, 3827, 3828, 3829, 3831, 3832, 3833, ...
      self 	<trac.ticket.query.QueryModule object at 0x1267910>
      t 	{u'status': u'new', u'changetime': datetime.datetime(2007, 9, 26, 17, 9, ...
      ticket 	<trac.ticket.model.Ticket object at 0x345c5d0>
      tickets 	[{'status': u'new', 'changetime': datetime.datetime(2007, 9, 26, 17, 27, ...
      tid 	3821
    * File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 506, in template_data
      Code fragment:
       501. groupsequence = []
       502. for ticket in tickets:
       503. if orig_list:
       504. # Mark tickets added or changed since the query was first
       505. # executed
       506. if ticket['time'] > orig_time:
       507. ticket['added'] = True
       508. elif ticket['changetime'] > orig_time:
       509. ticket['changed'] = True
       510. if self.group:
       511. group_key = ticket[self.group]
      Local variables:
      Name	Value
      col 	'component'
      cols 	['id', 'summary', 'status', 'owner', 'type', 'priority', 'component']
      constraint 	{'values': [u'Untriaged'], 'mode': ''}
      constraints 	{'status': {'values': [u'new', u'assigned', u'reopened'], 'mode': ''}, ...
      context 	<Context '[root]' <Request "GET u'/query'">>
      f 	{'name': 'verified', 'value': u'', 'custom': True, 'label': u'Verified', ...
      field 	{'name': 'verified', 'value': u'', 'custom': True, 'label': u'Verified', ...
      field_data 	{'label': u'Verified', 'type': u'checkbox', 'order': 0, 'value': u'', ...
      fields 	{'status': {'optional': True, 'type': 'radio', 'options': [u'assigned', ...
      groups 	{}
      groupsequence 	[]
      headers 	[{'href': ...
      k 	'milestone'
      labels 	{'status': 'Status', 'changetime': 'Modified', 'verified': u'Verified', ...
      mode 	''
      modes 	{'text': [{'name': 'contains', 'value': '~'}, {'name': "doesn't contain", ...
      neg 	False
      orig_list 	[3813, 3830, 2448, 2651, 2712, 2717, 2837, 2839, 2926, 2973, 3117, 3782, ...
      orig_time 	datetime.datetime(2007, 9, 26, 17, 26, 2, tzinfo=<FixedOffset "UTC" ...
      self 	<trac.ticket.query.Query object at 0x1c322d0>
      ticket 	{'changetime': 0, 'summary': <Element "em">, 'id': 3825, 'time': 0}
      tickets 	[{'status': u'new', 'changetime': datetime.datetime(2007, 9, 26, 17, 27, ...
      v 	[u'Untriaged']
      val 	u'Untriaged'

File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/web/main.py", line 381, in dispatch_request
  dispatcher.dispatch(req)
File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/web/main.py", line 191, in dispatch
  resp = chosen_handler.process_request(req)
File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 638, in process_request
  return self.display_html(context, query)
File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 720, in display_html
  data = query.template_data(context, tickets, orig_list, orig_time)
File "/home/coderanger/local-trac-0.11/lib/python2.5/Trac-0.11dev_r5992-py2.5.egg/trac/ticket/query.py", line 506, in template_data
  if ticket['time'] > orig_time:

System Information:

User Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.6) Gecko/20061201 Firefox/2.0.0.6 (Ubuntu-feisty)
Trac: 	0.11dev-r5992
Python: 	2.5.1 (r251:54863, May 2 2007, 16:27:44) [GCC 4.1.2 (Ubuntu 4.1.2-0ubuntu4)]
setuptools: 	0.6c7
SQLite: 	3.3.13
pysqlite: 	2.3.2
Genshi: 	0.4.4
jQuery:	1.1.3.1

TracGuide — The Trac User and Administration Guide
Trac Powered

Powered by Trac 0.11dev-r5992

[Noah Kantrowitz]

The problem is if a ticket in the cached query list doesn't exist, its time is 0, not a null datetime object.

[anonymous]

Does anyone have a workaround for this?

[Noah Kantrowitz]

Replying to anonymous:

Does anyone have a workaround for this?

Just view another query and it will reset the cache.

[osimons]

Replying to nkantrowitz:

The problem is if a ticket in the cached query list doesn't exist, its time is 0, not a null datetime object.

Right, was the first problem. However, once that is fixed there are more issues as we set such a limited number of dummy values. Any further values needed will also lead to complications - not for display in the list, but if they are needed for instance in 'group by'.

I've tried various ideas, but it gets quite complicated to present something useful to the user - sorted and grouped correctly for values that no longer exists. And, as the ticket is actually deleted, I actually think that expected behaviour should be that the ticket is in fact removed from the list.

This solution does just that in a brutal manner:

trac/ticket/query.py

@@ -728 +731 @@
                             'changetime': ticket.time_changed, 'removed': True,
                             'href': req.href.ticket(ticket.id)}
                     data.update(ticket.values)
+                    tickets.insert(orig_list.index(rest_id), data)
                 except TracError, e:
-                    data = {'id': rest_id, 'time': 0, 'changetime': 0,
-                            'summary': tag.em(e)}
-                tickets.insert(orig_list.index(rest_id), data)
+                    pass
 
         context = Context.from_request(req, 'query')
         data = query.template_data(context, tickets, orig_list, orig_time)

The only issue I might not quite be grasping in this is why we would want include 'dummy' entries for tickets that raise an exception when trying to access them. Are there other use-cases other than deleted tickets?

Comments please, and I'll commit if this is an OK solution.

[osimons]

See also #5653 that proposes using a strikeout display (in some form) for closed tickets. Suppose we need to decide on what visualisations to use for the various use-cases.

[Christian Boos]

#6990 and #7041 closed as duplicate.

I'm OK with the proposed patch (comment:7). A deleted ticket is gone for real, there's no point in showing dummy content for such deleted tickets that were once part of a saved query result, as there's nothing to be gained from showing that partial information.

[osimons]

Replying to cboos:

I'm OK with the proposed patch (comment:7).

Ok, committed in [6748].

[zakness@…]

I'm encountering a different flavor of the same problem in 0.12.

TypeError: can't compare datetime.datetime to str

File "/usr/lib/python2.4/site-packages/trac/ticket/query.py", line 732, in template_data
  elif ticket['changetime'] > orig_time:

Seems that ticket['changetime'] is set to '--'

Going to a different query does not seem to clear the cache, either.

[Remy Blank]

Can you please show us the full traceback, possibly including the local data? Also, please check in your database if the ticket exists, and what the content of the changetime column is. If going to a different query doesn't clear the cache, it might be a different issue.

[Zak Linder <zakness@…>]

Full traceback:

File "/usr/lib/python2.4/site-packages/trac/web/main.py", line 513, in _dispatch_request
  dispatcher.dispatch(req)
File "/usr/lib/python2.4/site-packages/trac/web/main.py", line 235, in dispatch
  resp = chosen_handler.process_request(req)
File "/usr/lib/python2.4/site-packages/trac/ticket/query.py", line 933, in process_request
  return self.display_html(req, query)
File "/usr/lib/python2.4/site-packages/trac/ticket/query.py", line 1052, in display_html
  data = query.template_data(context, tickets, orig_list, orig_time, req)
File "/usr/lib/python2.4/site-packages/trac/ticket/query.py", line 732, in template_data
  elif ticket['changetime'] > orig_time:

Local data (see how changetime is '--'?):

clause 	{'status': [u'in_progress', u'new']}
clauses 	[{'status': {'values': [u'in_progress', u'new'], 'mode': ''}}]
col 	u'time'
cols 	[u'id', u'summary', u'type', u'status', u'priority', u'reporter', ...
constraint 	{'values': [u'in_progress', u'new'], 'mode': ''}
constraints 	{'status': {'values': [u'in_progress', u'new'], 'mode': ''}}
context 	<Context <Resource 'query'>>
field 	{'name': u'deadline', 'type': u'select', 'value': u'', 'custom': True, ...
fields 	{'status': {'name': 'status', 'type': 'radio', 'value': '', 'label': ...
group_key 	u'zlinder'
groups 	{u'kimberly': [{u'status': u'new', u'changetime': datetime.datetime(2010, ...
groupsequence 	[u'ewolk', u'fanying', u'jordan', u'kimberly', u'zlinder']
headers 	[{'wikify': False, 'href': ...
k 	'status'
labels 	{'status': 'Status', 'changetime': 'Modified', 'description': ...
mode 	''
name 	u'deadline'
neg 	False
orig_list 	[578, 738, 745, 771, 463, 494, 504, 546, 678, 684, 688, 689, 691, 695, ...
orig_time 	datetime.datetime(2010, 11, 17, 1, 41, 40, tzinfo=<FixedOffset "UTC" ...
req 	<Request "GET '/query'">
self 	<trac.ticket.query.Query object at 0x2af3e50540d0>
ticket 	{u'status': u'new', u'changetime': '--', u'reporter': u'zlinder', ...
tickets 	[{u'status': u'new', u'changetime': datetime.datetime(2010, 4, 15, 20, 5, ...
v 	[u'in_progress', u'new']
val 	u'new'
wikify 	set([u'parent'])

I'm not sure how to find the precise ticket(s) that causes the error. The simplest way for me to reproduce is to query for all tickets and sort by most recently modified first. I deleted tickets for the first time about a week ago, and it was then that I started seeing this error. FWIW, other users of our trac instance have reported the error as well.

[osimons]

What plugins do you have installed? Could you please add the system + plugin info from 'About Trac' (as admin)?

[Zak Linder <zakness@…>]

System Information

Trac 		 0.12
CustomFieldAdmin 0.2.5
Docutils 	 0.7
Genshi 		 0.6
mod_python 	 3.2.8
psycopg2 	 2.0.12 (dt dec ext pq3)
Pygments 	 1.3.1
Python 		 2.4.3 (#1, Sep 3 2009, 15:37:37) [GCC 4.1.2 20080704 (Red Hat 4.1.2-46)]
RPC 		 1.1.0
setuptools 	 0.6c7
Subversion 	 1.6.13 (r1002816)
jQuery:		 1.4.2

Installed Plugins (all compiled from source on the server)

AutocompleteUsers		0.4.1
nevernotifyupdaterplugin	0.0.9
TracAddCommentMacro		0.3
TracAdvParseArgsPlugin		0.4
Tracchildtickets		1.0.5
TracCustomFieldAdmin		0.2.5
TracListOfWikiPagesMacro	0.4
TracMacroPost			0.2
TracNumberedHeadlinesPlugin	0.4
TracTags			0.6
TracXMLRPC			1.1.0

[Remy Blank]

Replying to Zak Linder <zakness@…>:

Local data (see how changetime is '--'?):

This is a strong indication that the changetime column is NULL for that particular ticket. This shouldn't happen as a result of deleting tickets. Try the following in psql:

SELECT id FROM ticket WHERE changetime = NULL;

Then set the changetime column of the resulting tickets to a non-NULL value, possibly the current time (as a number of microseconds since the 1970-01-01).

[Zak Linder <zakness@…>]

Thanks rblank, that was it. Your query did not return any rows, but I just sifted thru a dump of the entire tickets table and found the issue with a blank changetime:

SELECT id, changetime FROM tickets;

 id    changetime
-----+-----------------
 ...
 336 | 1289606973887904
 480 | 1289607715289206
 445 | 
 505 | 1289607775407712
 585 | 1289607819790514
 ...

I'm not sure why selecting changetime = null did not return this row. I'm going to chalk this up to user error unless it happens again. In any case, this turned out to be unrelated to this issue, so I'll re-close. Thanks for the help!