Modify

Opened 11 years ago

Closed 9 years ago

#11149 closed defect (cantfix)

IOError: failed to write data

Reported by: Ryan J Ollos Owned by: Ryan J Ollos
Priority: normal Component: TracHacks
Severity: normal Keywords:
Cc: Steffen Hoffmann Trac Release: 1.0

Description

The following is found in the logs after the upgrade to 1.0.1. I'm not yet sure if it belongs to a plugin, or belongs to Trac.

2013-06-06 09:47:16,847 Trac[main] ERROR: Internal Server Error:
Traceback (most recent call last):
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/main.py", line 497, in _dispatch_request
    dispatcher.dispatch(req)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/main.py", line 234, in dispatch
    req.send(output, content_type or 'text/html')
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/api.py", line 498, in send
    self.write(content)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/api.py", line 620, in write
    self._write(data)
IOError: failed to write data

Attachments (0)

Change History (17)

comment:1 Changed 11 years ago by Ryan J Ollos

This is probably a separate issue, but it occurs just prior in the log. Needs more investigation.

2013-06-06 09:45:38,814 Trac[main] WARNING: [218.6.15.69] HTTPInternalError: 500 Trac Error (<div class="message">Submission rejected as potential spam <ul><li>IP 218.6.15.69 blacklisted by list.blogspambl.com [2]</li></ul></div>)
2013-06-06 09:47:05,105 Trac[main] WARNING: [173.44.37.226] HTTPInternalError: 500 Trac Error (<div class="message">Submission rejected as potential spam <ul><li>Content contained these blacklisted patterns: '(?i)(?:diet|penis)[\W_]*(?:pills|enlargement)', '(?i)(?:[ck]asino|gambl(?:e|ing)|poker|(?:texas)?-?hold-?em|black-?jack|baccarr?at?|roulette|lott(?:o|ery)|jackpot|millionaires?|backgammon)', '(?i)&lt;a href=', '(?i)casino', '(?i)\[(?:url|link)=http://'</li><li>Maximum number of external links per post exceeded</li><li>SpamBayes determined spam probability of 88.56%</li></ul></div>)

comment:2 in reply to:  description ; Changed 11 years ago by Jun Omae

Replying to rjollos:

...
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/api.py", line 620, in write
    self._write(data)
IOError: failed to write data

We can ignore the exception.

The exception is raised from mod_wsgi when the client closed the connection. An IOError normally has a pair of errno and a message of the error. However, mod_wsgi raises an IOError with only the message.

https://code.google.com/p/modwsgi/source/browse/mod_wsgi.c?name=mod_wsgi-3.3#3313

comment:3 Changed 11 years ago by Ryan J Ollos

Thanks Jun. I guess we can close this then, after determining whether comment:1 is a problem.

comment:4 Changed 11 years ago by Ryan J Ollos

Here's another I'm unsure of:

2013-06-06 09:37:52,912 Trac[main] ERROR: Internal Server Error:
Traceback (most recent call last):
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/main.py", line 497, in _dispatch_request
    dispatcher.dispatch(req)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/web/main.py", line 214, in dispatch
    resp = chosen_handler.process_request(req)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/search/web_ui.py", line 106, in process_request
    results = self._do_search(req, terms, filters)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/search/web_ui.py", line 214, in _do_search
    or [])
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/wiki/web_ui.py", line 774, in get_search_results
    shorten_result(text, terms))
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/db/api.py", line 182, in __exit__
    self.db.close()
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/db/pool.py", line 50, in close
    self._pool._return_cnx(cnx, self._key, self._tid)
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/db/pool.py", line 163, in _return_cnx
    assert (tid, key) in self._active
AssertionError:

comment:5 in reply to:  4 ; Changed 11 years ago by Jun Omae

Replying to rjollos:

...
  File "/srv/trac-hacks.org/pve/lib/python2.6/site-packages/Trac-1.0.1-py2.6.egg/trac/db/pool.py", line 163, in _return_cnx
    assert (tid, key) in self._active
AssertionError:

I suppose that _fetch_tkt_tags() in tagsplugin leads the assertions when raising an IntegrityError. In this case, db.rollback() doesn't have been called.

  • tractags/ticket.py

     
    4949    use_cache = False
    5050
    5151    def __init__(self):
    52         self._fetch_tkt_tags()
     52        db = self.env.get_db_cnx()
     53        try:
     54            self._fetch_tkt_tags(db)
     55            db.commit()
     56        except:
     57            db.rollback()
     58            raise
    5359        cfg = self.config
    5460        cfg_key = 'permission_policies'
    5561        default_policies = cfg.defaults().get('trac', {}).get(cfg_key)
     
    188194
    189195    # Private methods
    190196
    191     def _fetch_tkt_tags(self):
     197    def _fetch_tkt_tags(self, db):
    192198        """Transfer all relevant ticket attributes to tags db table."""
    193199        # Initial sync is done by forced, stupid one-way mirroring.
    194200        # Data aquisition for this utilizes the known ticket tags query.
    195         db = self.env.get_db_cnx()
    196201        fields = ["COALESCE(%s, '')" % f for f in self.fields]
    197202        ignore = ''
    198203        if self.ignore_closed_tickets:
     
    225230                       (tagspace, name, tag)
    226231                VALUES (%s, %s, %s)
    227232                """, [(self.realm, str(tkt_id), tag) for tag in ticket_tags])
    228         db.commit()
    229233        self.log.debug('EXIT_TAG_SYNC')
    230234
    231235    try:

comment:6 in reply to:  5 ; Changed 11 years ago by Steffen Hoffmann

Replying to jun66j5:

I suppose that _fetch_tkt_tags() in tagsplugin leads the assertions when raising an IntegrityError. In this case, db.rollback() doesn't have been called.

I see, a good idea. I'll do that change shortly.

comment:7 in reply to:  2 ; Changed 11 years ago by Ryan J Ollos

Replying to jun66j5:

We can ignore the exception.

The exception is raised from mod_wsgi when the client closed the connection. An IOError normally has a pair of errno and a message of the error. However, mod_wsgi raises an IOError with only the message.

Is there any way you know of that we could suppress the errors in the logs? The messages tend to appear many times per hour, and fill the logs quite a bit.

Another one that I see many times per hour is:

2013-08-15 23:06:43,923 Trac[patch] WARNING: Invalid unified diff content

comment:8 in reply to:  6 Changed 11 years ago by Ryan J Ollos

Replying to hasienda:

Replying to jun66j5:

I suppose that _fetch_tkt_tags() in tagsplugin leads the assertions when raising an IntegrityError. In this case, db.rollback() doesn't have been called.

I see, a good idea. I'll do that change shortly.

Any chance to push this change soon in case it might help with #11147?

comment:9 in reply to:  7 ; Changed 11 years ago by Jun Omae

Replying to rjollos:

Is there any way you know of that we could suppress the errors in the logs? The messages tend to appear many times per hour, and fill the logs quite a bit.

No way. Trac 1.0.2dev suppresses the noisy logs, see trac:r11842.

Another one that I see many times per hour is:

2013-08-15 23:06:43,923 Trac[patch] WARNING: Invalid unified diff content

Hmm, I don't know why.... It is related to trac:ticket:10840#comment:8?

comment:10 in reply to:  9 ; Changed 11 years ago by Ryan J Ollos

Replying to jun66j5:

Replying to rjollos:

Is there any way you know of that we could suppress the errors in the logs? The messages tend to appear many times per hour, and fill the logs quite a bit.

No way. Trac 1.0.2dev suppresses the noisy logs, see trac:r11842.

Thanks! Good to know that a fix is on the way.

Another one that I see many times per hour is:

2013-08-15 23:06:43,923 Trac[patch] WARNING: Invalid unified diff content

Hmm, I don't know why.... It is related to trac:ticket:10840#comment:8?

It appears that should have been fixed in [t 11319], however it is a good clue. I haven't seen a visible problem on the Trac site with diff file rendering, so I'm thinking the warnings are harmless. I only mentioned because there are so many of them in the logs. I'll send you the most recent log file by email in case you have a chance to take a look.

comment:11 in reply to:  10 ; Changed 11 years ago by Jun Omae

Replying to rjollos:

Another one that I see many times per hour is:

2013-08-15 23:06:43,923 Trac[patch] WARNING: Invalid unified diff content

Hmm, I don't know why.... It is related to trac:ticket:10840#comment:8?

It appears that should have been fixed in [t 11319], however it is a good clue. I haven't seen a visible problem on the Trac site with diff file rendering, so I'm thinking the warnings are harmless. I only mentioned because there are so many of them in the logs. I'll send you the most recent log file by email in case you have a chance to take a look.

Thanks for trac.log! Sorry, my late reply.

I investigated the warnings in trac.log. Probably, we can ignore them. For instance, the following text, a pair of {{{#diff and }}} and a blank line lead the same warning in auto-preview.

{{{#!diff

}}}

Otherwise, incomplete diff text might exist in somewhere, e.g. wiki, ticket comment, etc...

comment:12 Changed 9 years ago by Ryan J Ollos

Status: newaccepted

comment:13 in reply to:  11 Changed 9 years ago by Ryan J Ollos

Replying to jun66j5:

I investigated the warnings in trac.log. Probably, we can ignore them. For instance, the following text, a pair of {{{#diff and }}} and a blank line lead the same warning in auto-preview.

Thanks. I see that was added in [trac 9711]. What do you think about changing the log level to info? To me, a warning is something that the administrator should take notice of, however invalid content in a page or attachment is not really anything that the administrator needs to care about.

comment:14 Changed 9 years ago by Jun Omae

Agreed. However, I think the log level should be debug and log content variable. I don't think current message Invalid unified diff content is useful.

-            self.log.warning('Invalid unified diff content')
+            self.log.debug("Invalid unified diff content: %.40r... (%d "
+                           "characters)", content, len(content))
2015-03-28 05:58:35,257 Trac[patch] DEBUG: Invalid unified diff content: u'asdaddfdfsdf\ndfffffffffffffffsdff\nsd... (67 characters)

comment:15 Changed 9 years ago by Ryan J Ollos

Thanks, Jun. I created trac:#12005.

comment:16 in reply to:  6 Changed 9 years ago by Ryan J Ollos

Replying to hasienda:

Replying to jun66j5:

I suppose that _fetch_tkt_tags() in tagsplugin leads the assertions when raising an IntegrityError. In this case, db.rollback() doesn't have been called.

I see, a good idea. I'll do that change shortly.

JFTR, this was fixed in [13419] / #11147.

comment:17 in reply to:  1 Changed 9 years ago by Ryan J Ollos

Resolution: cantfix
Status: acceptedclosed

Replying to rjollos:

This is probably a separate issue, but it occurs just prior in the log. Needs more investigation.

2013-06-06 09:45:38,814 Trac[main] WARNING: [218.6.15.69] HTTPInternalError: 500 Trac Error (<div class="message">Submission rejected as potential spam <ul><li>IP 218.6.15.69 blacklisted by list.blogspambl.com [2]</li></ul></div>)
2013-06-06 09:47:05,105 Trac[main] WARNING: [173.44.37.226] HTTPInternalError: 500 Trac Error (<div class="message">Submission rejected as potential spam <ul><li>Content contained these blacklisted patterns: '(?i)(?:diet|penis)[\W_]*(?:pills|enlargement)', '(?i)(?:[ck]asino|gambl(?:e|ing)|poker|(?:texas)?-?hold-?em|black-?jack|baccarr?at?|roulette|lott(?:o|ery)|jackpot|millionaires?|backgammon)', '(?i)&lt;a href=', '(?i)casino', '(?i)\[(?:url|link)=http://'</li><li>Maximum number of external links per post exceeded</li><li>SpamBayes determined spam probability of 88.56%</li></ul></div>)

Opened trac:#12006 for this issue.

Everything noted in this ticket has now been addressed in separate tickets.

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Ryan J Ollos.
The resolution will be deleted. Next status will be 'reopened'.

Add Comment


E-mail address and name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.