Edgewall Software
Modify

Opened 9 years ago

Closed 9 years ago

Last modified 9 years ago

#9176 closed defect (fixed)

TypeError with mod_wsgi 3 and unicode cookies

Reported by: Gluzskiy Alexandr <sss@…> Owned by: Remy Blank
Priority: high Milestone: 0.11.8
Component: general Version: 0.12dev
Severity: blocker Keywords:
Cc: Branch:
Release Notes:
API Changes:

Description

look in log in attachment

Attachments (1)

trac_err.gz (2.2 KB ) - added by Gluzskiy Alexandr <sss@…> 9 years ago.
trac log with debug turned on

Download all attachments as: .zip

Change History (30)

by Gluzskiy Alexandr <sss@…>, 9 years ago

Attachment: trac_err.gz added

trac log with debug turned on

comment:1 by Remy Blank, 9 years ago

When I said "compress the file" on #9138, it was only because I expected the file to be large. For small files, you can attach them as plain text, or even paste the error directly.

Here's the error, which seems to happen for most URLs:

Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/trac/web/main.py", line 514, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.6/site-packages/trac/web/main.py", line 260, in dispatch
    req.send(output, content_type or 'text/html')
  File "/usr/lib/python2.6/site-packages/trac/web/api.py", line 412, in send
    self.write(content)
  File "/usr/lib/python2.6/site-packages/trac/web/api.py", line 532, in write
    self._write(data)
TypeError: expected byte string object for header value, value of type unicode found

It seems like Chrome.render_template() returns unicode content instead of a str. This doesn't normally happen. I strongly suspect that this is due to a plugin. Please try disabling them all and see if the issue persists. If it doesn't, re-add them one by one to isolate the faulty plugin.

comment:2 by Gluzskiy Alexandr <sss@…>, 9 years ago

disabled all plugins, and still have same problem

TypeError: expected byte string object for header value, value of type unicode found                                                                                                
2010-03-26 16:39:38,150 Trac[env] INFO: -------------------------------- environment startup [Trac 0.12dev] --------------------------------                                        
2010-03-26 16:39:38,336 Trac[loader] DEBUG: Loading trac.about from /usr/lib/python2.6/site-packages                                                                                
2010-03-26 16:39:38,359 Trac[loader] DEBUG: Loading trac.admin.console from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 16:39:38,423 Trac[loader] DEBUG: Loading trac.admin.web_ui from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 16:39:38,435 Trac[loader] DEBUG: Loading trac.attachment from /usr/lib/python2.6/site-packages                                                                           
2010-03-26 16:39:38,439 Trac[loader] DEBUG: Loading trac.db.mysql from /usr/lib/python2.6/site-packages                                                                             
2010-03-26 16:39:38,484 Trac[loader] DEBUG: Loading trac.db.postgres from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 16:39:38,491 Trac[loader] DEBUG: Loading trac.db.sqlite from /usr/lib/python2.6/site-packages                                                                            
2010-03-26 16:39:38,525 Trac[loader] DEBUG: Loading trac.mimeview.patch from /usr/lib/python2.6/site-packages                                                                       
2010-03-26 16:39:38,533 Trac[loader] DEBUG: Loading trac.mimeview.pygments from /usr/lib/python2.6/site-packages                                                                    
2010-03-26 16:39:38,714 Trac[loader] DEBUG: Loading trac.mimeview.rst from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 16:39:39,750 Trac[loader] DEBUG: Loading trac.mimeview.silvercity from /usr/lib/python2.6/site-packages                                                                  
2010-03-26 16:39:39,805 Trac[loader] DEBUG: Skipping "trac.mimeview.silvercity = trac.mimeview.silvercity [silvercity]": ("DistributionNotFound: SilverCity>=0.9.4" not found)      
2010-03-26 16:39:39,807 Trac[loader] DEBUG: Loading trac.mimeview.txtl from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 16:39:39,864 Trac[loader] DEBUG: Skipping "trac.mimeview.txtl = trac.mimeview.txtl [textile]": ("DistributionNotFound: textile>=2.0" not found)                          
2010-03-26 16:39:39,866 Trac[loader] DEBUG: Loading trac.prefs from /usr/lib/python2.6/site-packages                                                                                
2010-03-26 16:39:39,874 Trac[loader] DEBUG: Loading trac.search from /usr/lib/python2.6/site-packages                                                                               
2010-03-26 16:39:39,882 Trac[loader] DEBUG: Loading trac.ticket.admin from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 16:39:39,900 Trac[loader] DEBUG: Loading trac.ticket.query from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 16:39:39,934 Trac[loader] DEBUG: Loading trac.ticket.report from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 16:39:39,944 Trac[loader] DEBUG: Loading trac.ticket.roadmap from /usr/lib/python2.6/site-packages                                                                       
2010-03-26 16:39:39,961 Trac[loader] DEBUG: Loading trac.ticket.web_ui from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 16:39:39,997 Trac[loader] DEBUG: Loading trac.timeline from /usr/lib/python2.6/site-packages                                                                             
2010-03-26 16:39:40,044 Trac[loader] DEBUG: Loading trac.versioncontrol.admin from /usr/lib/python2.6/site-packages                                                                 
2010-03-26 16:39:40,051 Trac[loader] DEBUG: Loading trac.versioncontrol.svn_authz from /usr/lib/python2.6/site-packages                                                             
2010-03-26 16:39:40,060 Trac[loader] DEBUG: Loading trac.versioncontrol.svn_fs from /usr/lib/python2.6/site-packages                                                                
2010-03-26 16:39:40,073 Trac[loader] DEBUG: Loading trac.versioncontrol.svn_prop from /usr/lib/python2.6/site-packages                                                              
2010-03-26 16:39:40,142 Trac[loader] DEBUG: Loading trac.versioncontrol.web_ui from /usr/lib/python2.6/site-packages                                                                
2010-03-26 16:39:40,148 Trac[loader] DEBUG: Loading trac.web.auth from /usr/lib/python2.6/site-packages                                                                             
2010-03-26 16:39:40,184 Trac[loader] DEBUG: Loading trac.web.session from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 16:39:40,188 Trac[loader] DEBUG: Loading trac.wiki.admin from /usr/lib/python2.6/site-packages                                                                           
2010-03-26 16:39:40,193 Trac[loader] DEBUG: Loading trac.wiki.interwiki from /usr/lib/python2.6/site-packages                                                                       
2010-03-26 16:39:40,209 Trac[loader] DEBUG: Loading trac.wiki.macros from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 16:39:40,214 Trac[loader] DEBUG: Loading trac.wiki.web_api from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 16:39:40,220 Trac[loader] DEBUG: Loading trac.wiki.web_ui from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 16:39:40,233 Trac[loader] DEBUG: Loading tracopt.mimeview.enscript from /usr/lib/python2.6/site-packages                                                                 
2010-03-26 16:39:40,242 Trac[loader] DEBUG: Loading tracopt.mimeview.php from /usr/lib/python2.6/site-packages                                                                      
2010-03-26 16:39:40,249 Trac[loader] DEBUG: Loading tracopt.perm.authz_policy from /usr/lib/python2.6/site-packages                                                                 
2010-03-26 16:39:40,256 Trac[loader] DEBUG: Loading tracopt.perm.config_perm_provider from /usr/lib/python2.6/site-packages                                                         
2010-03-26 16:39:40,262 Trac[loader] DEBUG: Loading tracopt.ticket.commit_updater from /usr/lib/python2.6/site-packages                                                             
2010-03-26 16:39:40,278 Trac[loader] DEBUG: Loading tracopt.ticket.deleter from /usr/lib/python2.6/site-packages                                                                    
2010-03-26 16:39:40,438 Trac[default_workflow] DEBUG: Workflow actions at initialization: {u'resolve': {u'operations': [u'set_resolution'], 'name': u'resolve', 'default': 0, 'newst
ate': u'closed', 'oldstates': [u'new', u'assigned', u'accepted', u'reopened'], u'permissions': [u'TICKET_MODIFY']}, u'accept': {u'operations': [u'set_owner_to_self'], 'name': u'acc
ept', 'default': 0, 'newstate': u'accepted', 'oldstates': [u'new', u'assigned', u'accepted', u'reopened'], u'permissions': [u'TICKET_MODIFY']}, u'leave': {u'operations': [u'leave_s
tatus'], 'name': u'leave', u'default': 1, 'newstate': u'*', 'oldstates': [u'*'], 'permissions': []}, u'reopen': {u'operations': [u'del_resolution'], 'name': u'reopen', 'default': 0
, 'newstate': u'reopened', 'oldstates': [u'closed'], u'permissions': [u'TICKET_CREATE']}, u'reassign': {u'operations': [u'set_owner'], 'name': u'reassign', 'default': 0, 'newstate'
: u'assigned', 'oldstates': [u'new', u'assigned', u'accepted', u'reopened'], u'permissions': [u'TICKET_MODIFY']}, '_reset': {'operations': ['reset_workflow'], 'name': 'reset', 'def
ault': 0, 'newstate': 'new', 'oldstates': [], 'permissions': []}}          

2010-03-26 16:39:40,449 Trac[env] WARNING: base_url option not set in configuration, generated links may be incorrect                                                               
2010-03-26 16:39:40,451 Trac[main] DEBUG: Dispatching <Request "GET '/'">                                                                                                           
2010-03-26 16:39:40,535 Trac[session] DEBUG: Retrieving session for ID '44d3af230e001a5f4356d374'                                                                                   
2010-03-26 16:39:40,553 Trac[api] DEBUG: action controllers for ticket workflow: ['ConfigurableTicketWorkflow']                                                                     
2010-03-26 16:39:40,569 Trac[chrome] DEBUG: Prepare chrome data for request                                                                                                         
2010-03-26 16:39:40,587 Trac[perm] DEBUG: No policy allowed anonymous performing TRAC_ADMIN on None                                                                                 
2010-03-26 16:39:40,590 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_GRANT on None                                                                           
2010-03-26 16:39:40,593 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_REVOKE on None                                                                          
2010-03-26 16:39:40,595 Trac[perm] DEBUG: No policy allowed anonymous performing TICKET_ADMIN on None                                                                               
2010-03-26 16:39:40,600 Trac[perm] DEBUG: No policy allowed anonymous performing VERSIONCONTROL_ADMIN on None                                                                       
2010-03-26 16:39:40,915 Trac[svn_fs] DEBUG: Subversion bindings imported                                                                                                            
2010-03-26 16:39:40,996 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_MODIFY on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 16:39:40,998 Trac[attachment] DEBUG: LegacyAttachmentPolicy denied anonymous access to <Resource u'wiki:WikiStart, attachment'>. User needs WIKI_MODIFY                  
2010-03-26 16:39:41,001 Trac[perm] DEBUG: LegacyAttachmentPolicy denies anonymous performing ATTACHMENT_CREATE on <Resource u'wiki:WikiStart, attachment'>                          
2010-03-26 16:39:41,198 Trac[perm] DEBUG: No policy allowed anonymous performing EMAIL_VIEW on None                                                                                 
2010-03-26 16:39:43,921 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_DELETE on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 16:39:43,923 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_ADMIN on <Resource u'wiki:WikiStart'>                                                         
2010-03-26 16:39:43,927 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_RENAME on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 16:39:43,983 Trac[main] ERROR: Internal Server Error:                                                                                                                    
Traceback (most recent call last):                                                                                                                                                  
  File "/usr/lib/python2.6/site-packages/trac/web/main.py", line 514, in _dispatch_request                                                                                          
    dispatcher.dispatch(req)                                                                                                                                                        
  File "/usr/lib/python2.6/site-packages/trac/web/main.py", line 260, in dispatch                                                                                                   
    req.send(output, content_type or 'text/html')                                                                                                                                   
  File "/usr/lib/python2.6/site-packages/trac/web/api.py", line 412, in send                                                                                                        
    self.write(content)                                                                                                                                                             
  File "/usr/lib/python2.6/site-packages/trac/web/api.py", line 532, in write                                                                                                       
    self._write(data)                                                                                                                                                               
TypeError: expected byte string object for header value, value of type unicode found                                                                                                
2010-03-26 16:39:44,865 Trac[main] DEBUG: Dispatching <Request "GET '/wiki'">                                                                                                       
2010-03-26 16:39:44,917 Trac[session] DEBUG: Retrieving session for ID 'dae8ce64b9ee8cb4584efb9d'                                                                                   
2010-03-26 16:39:44,966 Trac[chrome] DEBUG: Prepare chrome data for request                                                                                                         
2010-03-26 16:39:44,993 Trac[perm] DEBUG: No policy allowed anonymous performing TRAC_ADMIN on None                                                                                 
2010-03-26 16:39:45,006 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_GRANT on None                                                                           
2010-03-26 16:39:45,015 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_REVOKE on None                                                                          
2010-03-26 16:39:45,034 Trac[perm] DEBUG: No policy allowed anonymous performing TICKET_ADMIN on None                                                                               
2010-03-26 16:39:45,041 Trac[perm] DEBUG: No policy allowed anonymous performing VERSIONCONTROL_ADMIN on None                                                                       
2010-03-26 16:39:45,205 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_MODIFY on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 16:39:45,207 Trac[attachment] DEBUG: LegacyAttachmentPolicy denied anonymous access to <Resource u'wiki:WikiStart, attachment'>. User needs WIKI_MODIFY                  
2010-03-26 16:39:45,215 Trac[perm] DEBUG: LegacyAttachmentPolicy denies anonymous performing ATTACHMENT_CREATE on <Resource u'wiki:WikiStart, attachment'>                          
2010-03-26 16:39:45,229 Trac[perm] DEBUG: No policy allowed anonymous performing EMAIL_VIEW on None                                                                                 
2010-03-26 16:39:46,502 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_DELETE on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 16:39:46,505 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_ADMIN on <Resource u'wiki:WikiStart'>                                                         
2010-03-26 16:39:46,508 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_RENAME on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 16:39:46,556 Trac[session] INFO: Refreshing session dae8ce64b9ee8cb4584efb9d                                                                                             
2010-03-26 16:39:46,592 Trac[session] DEBUG: Purging old, expired, sessions.

comment:3 by Remy Blank, 9 years ago

Oh wait, it's complaining about the header fields, not the content. I need to check how this can happen…

comment:4 by Gluzskiy Alexandr <sss@…>, 9 years ago

i can provide any additional info which can help

comment:5 by Remy Blank, 9 years ago

Could you please add the following snippet to the end of Request.end_headers() in trac/web/api.py? You may have to run the site with tracd, as the values are printed to stdout (we don't have access to a logger in Request).

for k, v in self._outheaders:
    print repr(k), repr(v)

This should show the headers for each request, and hopefully the problematic headers.

comment:6 by Gluzskiy Alexandr <sss@…>, 9 years ago

trac working well from tracd, i using apache2 + mod_wsgi to serve trac, here my .wsgi script:

cat trac.wsgi 
import os

os.environ['TRAC_ENV_PARENT_DIR'] = '/home/www/site/tracker'
os.environ['PYTHON_EGG_CACHE'] = '/home/www/site/tracker/.egg-cache'

import trac.web.main
application = trac.web.main.dispatch_request

comment:7 by Gluzskiy Alexandr <sss@…>, 9 years ago

any ideas ?

comment:8 by Remy Blank, 9 years ago

What version of mod_wsgi? Can give me the headers for a few requests as shown in comment:5 (even if it works with tracd)?

comment:9 by Gluzskiy Alexandr <sss@…>, 9 years ago

mod_wsgi version 3.2, log fragment with modified code:

TypeError: expected byte string object for header value, value of type unicode found                                                                                                
2010-03-26 20:01:30,462 Trac[env] INFO: -------------------------------- environment startup [Trac 0.12dev] --------------------------------                                        
2010-03-26 20:01:30,528 Trac[loader] DEBUG: Loading trac.about from /usr/lib/python2.6/site-packages                                                                                
2010-03-26 20:01:30,533 Trac[loader] DEBUG: Loading trac.admin.console from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 20:01:30,536 Trac[loader] DEBUG: Loading trac.admin.web_ui from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 20:01:30,540 Trac[loader] DEBUG: Loading trac.attachment from /usr/lib/python2.6/site-packages                                                                           
2010-03-26 20:01:30,548 Trac[loader] DEBUG: Loading trac.db.mysql from /usr/lib/python2.6/site-packages                                                                             
2010-03-26 20:01:30,552 Trac[loader] DEBUG: Loading trac.db.postgres from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 20:01:30,557 Trac[loader] DEBUG: Loading trac.db.sqlite from /usr/lib/python2.6/site-packages                                                                            
2010-03-26 20:01:30,560 Trac[loader] DEBUG: Loading trac.mimeview.patch from /usr/lib/python2.6/site-packages                                                                       
2010-03-26 20:01:30,564 Trac[loader] DEBUG: Loading trac.mimeview.pygments from /usr/lib/python2.6/site-packages                                                                    
2010-03-26 20:01:30,568 Trac[loader] DEBUG: Loading trac.mimeview.rst from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 20:01:30,572 Trac[loader] DEBUG: Loading trac.mimeview.silvercity from /usr/lib/python2.6/site-packages                                                                  
2010-03-26 20:01:30,631 Trac[loader] DEBUG: Skipping "trac.mimeview.silvercity = trac.mimeview.silvercity [silvercity]": ("DistributionNotFound: SilverCity>=0.9.4" not found)      
2010-03-26 20:01:30,632 Trac[loader] DEBUG: Loading trac.mimeview.txtl from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 20:01:30,769 Trac[loader] DEBUG: Skipping "trac.mimeview.txtl = trac.mimeview.txtl [textile]": ("DistributionNotFound: textile>=2.0" not found)                          
2010-03-26 20:01:30,772 Trac[loader] DEBUG: Loading trac.prefs from /usr/lib/python2.6/site-packages                                                                                
2010-03-26 20:01:30,776 Trac[loader] DEBUG: Loading trac.search from /usr/lib/python2.6/site-packages                                                                               
2010-03-26 20:01:30,781 Trac[loader] DEBUG: Loading trac.ticket.admin from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 20:01:30,784 Trac[loader] DEBUG: Loading trac.ticket.query from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 20:01:30,788 Trac[loader] DEBUG: Loading trac.ticket.report from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 20:01:30,792 Trac[loader] DEBUG: Loading trac.ticket.roadmap from /usr/lib/python2.6/site-packages                                                                       
2010-03-26 20:01:30,796 Trac[loader] DEBUG: Loading trac.ticket.web_ui from /usr/lib/python2.6/site-packages                                                                        
2010-03-26 20:01:30,799 Trac[loader] DEBUG: Loading trac.timeline from /usr/lib/python2.6/site-packages                                                                             
2010-03-26 20:01:30,804 Trac[loader] DEBUG: Loading trac.versioncontrol.admin from /usr/lib/python2.6/site-packages                                                                 
2010-03-26 20:01:30,807 Trac[loader] DEBUG: Loading trac.versioncontrol.svn_authz from /usr/lib/python2.6/site-packages                                                             
2010-03-26 20:01:30,811 Trac[loader] DEBUG: Loading trac.versioncontrol.svn_fs from /usr/lib/python2.6/site-packages                                                                
2010-03-26 20:01:30,814 Trac[loader] DEBUG: Loading trac.versioncontrol.svn_prop from /usr/lib/python2.6/site-packages                                                              
2010-03-26 20:01:30,818 Trac[loader] DEBUG: Loading trac.versioncontrol.web_ui from /usr/lib/python2.6/site-packages                                                                
2010-03-26 20:01:30,822 Trac[loader] DEBUG: Loading trac.web.auth from /usr/lib/python2.6/site-packages                                                                             
2010-03-26 20:01:30,827 Trac[loader] DEBUG: Loading trac.web.session from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 20:01:30,831 Trac[loader] DEBUG: Loading trac.wiki.admin from /usr/lib/python2.6/site-packages                                                                           
2010-03-26 20:01:30,835 Trac[loader] DEBUG: Loading trac.wiki.interwiki from /usr/lib/python2.6/site-packages                                                                       
2010-03-26 20:01:30,839 Trac[loader] DEBUG: Loading trac.wiki.macros from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 20:01:30,843 Trac[loader] DEBUG: Loading trac.wiki.web_api from /usr/lib/python2.6/site-packages                                                                         
2010-03-26 20:01:30,847 Trac[loader] DEBUG: Loading trac.wiki.web_ui from /usr/lib/python2.6/site-packages                                                                          
2010-03-26 20:01:30,851 Trac[loader] DEBUG: Loading tracopt.mimeview.enscript from /usr/lib/python2.6/site-packages                                                                 
2010-03-26 20:01:30,855 Trac[loader] DEBUG: Loading tracopt.mimeview.php from /usr/lib/python2.6/site-packages                                                                      
2010-03-26 20:01:30,858 Trac[loader] DEBUG: Loading tracopt.perm.authz_policy from /usr/lib/python2.6/site-packages                                                                 
2010-03-26 20:01:30,862 Trac[loader] DEBUG: Loading tracopt.perm.config_perm_provider from /usr/lib/python2.6/site-packages                                                         
2010-03-26 20:01:30,866 Trac[loader] DEBUG: Loading tracopt.ticket.commit_updater from /usr/lib/python2.6/site-packages                                                             
2010-03-26 20:01:30,869 Trac[loader] DEBUG: Loading tracopt.ticket.deleter from /usr/lib/python2.6/site-packages                                                                    
2010-03-26 20:01:30,924 Trac[default_workflow] DEBUG: Workflow actions at initialization: {u'resolve': {u'operations': [u'set_resolution'], 'name': u'resolve', 'default': 0, 'newst
ate': u'closed', 'oldstates': [u'new', u'assigned', u'accepted', u'reopened'], u'permissions': [u'TICKET_MODIFY']}, u'accept': {u'operations': [u'set_owner_to_self'], 'name': u'acc
ept', 'default': 0, 'newstate': u'accepted', 'oldstates': [u'new', u'assigned', u'accepted', u'reopened'], u'permissions': [u'TICKET_MODIFY']}, u'leave': {u'operations': [u'leave_s
tatus'], 'name': u'leave', u'default': 1, 'newstate': u'*', 'oldstates': [u'*'], 'permissions': []}, u'reopen': {u'operations': [u'del_resolution'], 'name': u'reopen', 'default': 0
, 'newstate': u'reopened', 'oldstates': [u'closed'], u'permissions': [u'TICKET_CREATE']}, u'reassign': {u'operations': [u'set_owner'], 'name': u'reassign', 'default': 0, 'newstate'
: u'assigned', 'oldstates': [u'new', u'assigned', u'accepted', u'reopened'], u'permissions': [u'TICKET_MODIFY']}, '_reset': {'operations': ['reset_workflow'], 'name': 'reset', 'def
ault': 0, 'newstate': 'new', 'oldstates': [], 'permissions': []}}                                                                          

2010-03-26 20:01:33,116 Trac[env] WARNING: base_url option not set in configuration, generated links may be incorrect                                                               
2010-03-26 20:01:33,120 Trac[main] DEBUG: Dispatching <Request "GET '/'">                                                                                                           
2010-03-26 20:01:33,157 Trac[api] DEBUG: action controllers for ticket workflow: ['ConfigurableTicketWorkflow']                                                                     
2010-03-26 20:01:33,169 Trac[chrome] DEBUG: Prepare chrome data for request                                                                                                         
2010-03-26 20:01:33,187 Trac[perm] DEBUG: No policy allowed anonymous performing TRAC_ADMIN on None                                                                                 
2010-03-26 20:01:33,190 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_GRANT on None                                                                           
2010-03-26 20:01:33,192 Trac[perm] DEBUG: No policy allowed anonymous performing PERMISSION_REVOKE on None                                                                          
2010-03-26 20:01:33,195 Trac[perm] DEBUG: No policy allowed anonymous performing TICKET_ADMIN on None                                                                               
2010-03-26 20:01:33,200 Trac[perm] DEBUG: No policy allowed anonymous performing VERSIONCONTROL_ADMIN on None                                                                       
2010-03-26 20:01:33,245 Trac[svn_fs] DEBUG: Subversion bindings imported                                                                                                            
2010-03-26 20:01:33,316 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_MODIFY on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 20:01:33,318 Trac[attachment] DEBUG: LegacyAttachmentPolicy denied anonymous access to <Resource u'wiki:WikiStart, attachment'>. User needs WIKI_MODIFY                  
2010-03-26 20:01:33,320 Trac[perm] DEBUG: LegacyAttachmentPolicy denies anonymous performing ATTACHMENT_CREATE on <Resource u'wiki:WikiStart, attachment'>                          
2010-03-26 20:01:33,523 Trac[perm] DEBUG: No policy allowed anonymous performing EMAIL_VIEW on None                                                                                 
2010-03-26 20:01:35,686 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_DELETE on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 20:01:35,688 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_ADMIN on <Resource u'wiki:WikiStart'>                                                         
2010-03-26 20:01:35,691 Trac[perm] DEBUG: No policy allowed anonymous performing WIKI_RENAME on <Resource u'wiki:WikiStart'>                                                        
2010-03-26 20:01:35,744 Trac[main] ERROR: Internal Server Error:                                                                                                                    
Traceback (most recent call last):                                                                                                                                                  
  File "/usr/lib/python2.6/site-packages/trac/web/main.py", line 514, in _dispatch_request                                                                                          
    dispatcher.dispatch(req)                                                                                                                                                        
  File "/usr/lib/python2.6/site-packages/trac/web/main.py", line 260, in dispatch                                                                                                   
    req.send(output, content_type or 'text/html')                                                                                                                                   
  File "/usr/lib/python2.6/site-packages/trac/web/api.py", line 424, in send                                                                                                        
    self.write(content)                                                                                                                                                             
  File "/usr/lib/python2.6/site-packages/trac/web/api.py", line 553, in write                                                                                                       
    self._write(data)                                                                                                                                                               
TypeError: expected byte string object for header value, value of type unicode found  

but i do not see any difference

comment:10 by Gluzskiy Alexandr <sss@…>, 9 years ago

and one question, where exactly i should modify code, i modified already installed package in /usr/lib/python2.6/site/package, or i need to modify source before installing it ?

comment:11 by Remy Blank, 9 years ago

You can modify it in site-packages directly. The output is on the terminal where you started tracd, not in the log. That's why I suggested to use tracd even if it is working correctly, at least we should get the header values.

comment:12 by Gluzskiy Alexandr <sss@…>, 9 years ago

ok, but tracd not failing, wait a minute

comment:13 by Gluzskiy Alexandr <sss@…>, 9 years ago

tracd -p 9988 .                   
Server starting in PID 2005.
Serving on 0.0.0.0:9988 view at http://127.0.0.1:9988/
Using HTTP/1.1 protocol version
'Cache-Control' 'must-revalidate'
'Content-Type' 'text/html;charset=utf-8'
'Content-Length' '423'
192.168.0.2 - - [26/Mar/2010 20:45:55] "GET / HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:45:55] "GET /favicon.ico HTTP/1.1" 404 -
192.168.0.2 - - [26/Mar/2010 20:45:58] "GET /favicon.ico HTTP/1.1" 404 -
'Cache-Control' 'must-revalidate'
'Content-Type' 'text/html;charset=utf-8'
'Content-Length' '9767'
192.168.0.2 - - [26/Mar/2010 20:46:07] "GET /icqjplus HTTP/1.1" 200 -
'Content-Type' 'text/css'
'Content-Length' '2365'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:08] "GET /icqjplus/chrome/common/css/wiki.css HTTP/1.1" 200 -
'Content-Type' 'text/css'
'Content-Length' '17745'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:08] "GET /icqjplus/chrome/common/css/trac.css HTTP/1.1" 200 -
'Content-Type' 'image/x-icon'
'Content-Length' '3638'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'application/javascript'
 'Content-Type''Content-Length' '2929'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'application/javascript'
'Content-Length' '72174'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
 'application/javascript'
'Content-Length' '2248'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:09] "GET /icqjplus/chrome/common/trac.ico HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:09] "GET /icqjplus/chrome/common/js/jquery.js HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:09] "GET /icqjplus/chrome/common/js/trac.js HTTP/1.1" 200 -
'Content-Type' 'application/javascript'
'Content-Length' '2829'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:09] "GET /icqjplus/chrome/common/js/search.js HTTP/1.1" 200 -
'Content-Type' 'text/css'
'Content-Length' '4672'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:10] "GET /icqjplus/chrome/common/js/folding.js HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:10] "GET /icqjplus/chrome/common/css/code.css HTTP/1.1" 200 -
'Content-Type' 'image/png'
'Content-Length' '3281'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:10] "GET /icqjplus/chrome/common/trac_banner.png HTTP/1.1" 200 -
'Content-Type' 'image/x-icon'
'Content-Length' '3638'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:11] "GET /icqjplus/chrome/common/trac.ico HTTP/1.1" 200 -
'Content-Type' 'image/png'
'Content-Length' '1687'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:11] "GET /icqjplus/chrome/common/trac_logo_mini.png HTTP/1.1" 200 -
'Content-Type' 'image/gif'
'Content-Length' '50'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'image/png'
'Content-Length' '457'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:11] "GET /icqjplus/chrome/common/dots.gif HTTP/1.1" 200 -
'Content-Type' 'image/png'
'Content-Length' '248'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:11] "GET /icqjplus/chrome/common/topbar_gradient2.png HTTP/1.1" 200 -
'Content-Type' 'image/gif'
'Content-Length' '90'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:12] "GET /icqjplus/chrome/common/topbar_gradient.png HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:12] "GET /icqjplus/chrome/common/extlink.gif HTTP/1.1" 200 -
'Cache-Control' 'must-revalidate'
'Content-Type' 'text/html;charset=utf-8'
'Content-Length' '26586'
192.168.0.2 - - [26/Mar/2010 20:46:50] "GET /icqjplus/timeline HTTP/1.1" 200 -
'Content-Type' 'text/css'
'Content-Length' '2672'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:50] "GET /icqjplus/chrome/common/css/timeline.css HTTP/1.1" 200 -
'Content-Type' 'image/png'
'Content-Length' '233'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'image/png'
'Content-Length' '297'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'image/png'
'Content-Length' '294'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'image/png'
'Content-Length' '227'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
'Content-Type' 'image/png'
'Content-Length' '638'
'Last-Modified' 'Fri, 26 Mar 2010 12:57:22 GMT'
192.168.0.2 - - [26/Mar/2010 20:46:52] "GET /icqjplus/chrome/common/wiki.png HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:52] "GET /icqjplus/chrome/common/closedticket.png HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:52] "GET /icqjplus/chrome/common/changeset.png HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:52] "GET /icqjplus/chrome/common/feed.png HTTP/1.1" 200 -
192.168.0.2 - - [26/Mar/2010 20:46:52] "GET /icqjplus/chrome/common/newticket.png HTTP/1.1" 200 -

comment:14 by Remy Blank, 9 years ago

Blast, those are all correct strings. Unfortunately, I don't have a WSGI setup to test, so it will take me some time to get going. And even then, I'm not sure to reproduce the issue, as it hasn't been reported before. The good news is, I'm on Gentoo as well, so we might just be lucky.

comment:15 by Gluzskiy Alexandr <sss@…>, 9 years ago

i can provide ssh acces, but i do not have external ip and can do it only through vpn (openvpn for example)

comment:16 by mrelbe <mikael@…>, 9 years ago

I think I can confirm this problem.

My setup (for this presentation) is the following:

  • Trac 0.12dev-r9405 without any plugin!
  • Python/2.6.4
  • Apache/2.2.14 (Win32)
  • mod_wsgi/3.0
  • mod_ssl/2.2.14
  • OpenSSL/0.9.8k

I get this output in Apaches error log, in which I have added presentation of headers (in line with suggestion stated in comment:5). (Output below is manually cleaned for your convenience.)

Header 'Cache-Control':
'must-revalidate'

Header 'Expires':
'Fri, 01 Jan 1999 00:00:00 GMT'

Header 'Content-Type':
'text/html;charset=utf-8'

Header 'Content-Length':
'21519'

Header 'Set-Cookie':
u'trac_form_token=78b4a6fe751fc55396b9f81b; Path=/trac/support; secure'

[(time)] [error] [(ip)] mod_wsgi (pid=8320): Exception occurred processing WSGI script 'C:/Program/Apache Software Foundation/Apache2.2/cgi-bin/trac.wsgi'.
[(time)] [error] [(ip)] Traceback (most recent call last):
[(time)] [error] [(ip)]   File "build\\bdist.win32\\egg\\trac\\web\\main.py", line 482, in dispatch_request
[(time)] [error] [(ip)]     return _dispatch_request(req, env, env_error)
[(time)] [error] [(ip)]   File "build\\bdist.win32\\egg\\trac\\web\\main.py", line 598, in _dispatch_request
[(time)] [error] [(ip)]     req.send_error(exc_info, status=500, env=env, data=data)
[(time)] [error] [(ip)]   File "build\\bdist.win32\\egg\\trac\\web\\api.py", line 466, in send_error
[(time)] [error] [(ip)]     self.write(data)
[(time)] [error] [(ip)]   File "build\\bdist.win32\\egg\\trac\\web\\api.py", line 537, in write
[(time)] [error] [(ip)]     self._write(data)
[(time)] [error] [(ip)] TypeError: expected byte string object for header value, value of type unicode found

The header 'Set-Cookie' is unicode…

Comment: I did the following (ugly) modification to get this into the Apache log:

  • api.py

     
    457457        self._write = self._start_response(self._status, self._outheaders,
    458458                                           exc_info)
    459459
     460        for k, v in self._outheaders:
     461            _myfp = open('<apache-server-root>\logs\error.log', 'a')
     462            _myfp.write(('Header %s:\n%s\n\n' % (repr(k), repr(v))))
     463            _myfp.close()
     464
    460465        if self.method != 'HEAD':
    461466            self.write(data)
    462467        raise RequestDone

comment:17 by Remy Blank, 9 years ago

Milestone: 0.12
Owner: set to Remy Blank

Ok, that helps a lot. I'll check that.

comment:18 by Remy Blank, 9 years ago

The cookies are indeed the only headers that are not explicitly converted to utf-8. I'm not sure where the unicode cookies come from, it seems that it's related to mod_wsgi. Can you please test the following patch?

  • trac/web/api.py

    diff --git a/trac/web/api.py b/trac/web/api.py
    a b  
    628628                           .replace(',', '%3C')
    629629            self.outcookie[name]['path'] = path
    630630
    631         cookies = self.outcookie.output(header='')
     631        cookies = unicode(self.outcookie.output(header='')).encode('utf-8')
    632632        for cookie in cookies.splitlines():
    633633            self._outheaders.append(('Set-Cookie', cookie.strip()))
    634634

comment:19 by Christian Boos, 9 years ago

Seems to be a duplicate of #9054?

comment:20 by Remy Blank, 9 years ago

Indeed, and all instances of the issue are running mod_wsgi 3. I'll close #9054 as a duplicate of this one.

comment:21 by Remy Blank, 9 years ago

Also, if the fix works, do you want it applied on 0.11-stable?

in reply to:  21 ; comment:22 by Christian Boos, 9 years ago

Replying to rblank:

Also, if the fix works, do you want it applied on 0.11-stable?

Yes, I think it would be worth doing so.

However, we should rather use to_unicode() here instead of unicode() as the latter would fail in case the cookie contains 8-bit latin1 characters.

in reply to:  22 ; comment:23 by Remy Blank, 9 years ago

Replying to cboos:

However, we should rather use to_unicode() here instead of unicode() as the latter would fail in case the cookie contains 8-bit latin1 characters.

Should we also use to_unicode() in Request.send_header(), then?

in reply to:  23 comment:24 by Christian Boos, 9 years ago

Replying to rblank:

Should we also use to_unicode() in Request.send_header(), then?

I don't think it's necessary there, as the API doc is pretty clear about what's allowed:

 `value` must either be an `unicode` string or can be converted to one
        (e.g. numbers, ...)

in reply to:  18 comment:25 by Gluzskiy Alexandr <sss@…>, 9 years ago

Replying to rblank:

The cookies are indeed the only headers that are not explicitly converted to utf-8. I'm not sure where the unicode cookies come from, it seems that it's related to mod_wsgi. Can you please test the following patch?

  • trac/web/api.py

    diff --git a/trac/web/api.py b/trac/web/api.py
    a b  
    628628                           .replace(',', '%3C')
    629629            self.outcookie[name]['path'] = path
    630630
    631         cookies = self.outcookie.output(header='')
     631        cookies = unicode(self.outcookie.output(header='')).encode('utf-8')
    632632        for cookie in cookies.splitlines():
    633633            self._outheaders.append(('Set-Cookie', cookie.strip()))
    634634

ok, this change solve problem, thx.

comment:26 by Remy Blank, 9 years ago

Resolution: fixed
Status: newclosed
Summary: after upgrade from svn revision 9000 to revision 9405 trac do not working at allTypeError with mod_wsgi 3 and unicode cookies

Thanks for testing. Patch (using to_unicode()) applied in [9409] and backported to 0.11-stable in [9410] (I should have done it the other way, but hey…).

comment:27 by Remy Blank, 9 years ago

giulianob has the same issue on Windows with mod_wsgi 3, and has confirmed on IRC that switching back to mod_wsgi 2 also fixed the issue. So there must have been a change in how cookie values are passed (or possibly headers in general).

comment:28 by Christian Boos, 9 years ago

Milestone: 0.120.11.7.1

comment:29 by Christian Boos, 9 years ago

#5636 was closed as duplicate.

Re-reading this ticket, I would just add that the unicode values in the Request.outcookie are generated by us. In source:trunk/trac/web/main.py@10624#L294:

            req.outcookie['trac_form_token']['path'] = req.base_path or '/'

req.base_path is derived from environ['SCRIPT_NAME'], and there are indeed path code paths by which this ends up being unicode.

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Remy Blank.
The resolution will be deleted. Next status will be 'reopened'.
to as closed The owner will be changed from Remy Blank to the specified user.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.