yellow team mailing list archive

[Gary Poster <gary.poster@xxxxxxxxxxxxx>]

Hey Stuart.  We finally are getting around to trying some of the
approaches and diagnostics from the last time we spoke about bug 974617.
 We did see one new interesting thing and I wanted to see if it gave you
any ideas about what we could investigate.

Here's the last bit of the error information from the failure.

Traceback (most recent call last):
  Module zope.publisher.publish, line 134, in publish
    result = publication.callObject(request, obj)
  Module lp.services.webapp.publication, line 499, in callObject
    return mapply(ob, request.getPositionalArguments(), request)
  Module zope.publisher.publish, line 109, in mapply
    return debug_call(obj, args)
   - __traceback_info__: <security proxied
zope.browserpage.metaconfigure.SimpleViewClass from
/var/lib/buildbot/slaves/slave/lucid-db-devel/build/lib/lp/app/browser/../templates/root-index.pt
instance at 0x106f882c>
  Module zope.publisher.publish, line 115, in debug_call
    return obj(*args)
  Module lp.services.webapp.publisher, line 425, in __call__
    return self.render()
  Module lp.services.webapp.publisher, line 410, in render
    return self.template()
  Module zope.app.pagetemplate.viewpagetemplatefile, line 83, in __call__
    return self.im_func(im_self, *args, **kw)
  Module zope.app.pagetemplate.viewpagetemplatefile, line 51, in __call__
    sourceAnnotations=getattr(debug_flags, 'sourceAnnotations', 0),
  Module zope.pagetemplate.pagetemplate, line 113, in pt_render
    strictinsert=0, sourceAnnotations=sourceAnnotations)()
  Module zope.tal.talinterpreter, line 271, in __call__
    self.interpret(self.program)
  Module zope.tal.talinterpreter, line 343, in interpret
    handlers[opcode](self, args)
  Module zope.tal.talinterpreter, line 888, in do_useMacro
    self.interpret(macro)
  Module zope.tal.talinterpreter, line 343, in interpret
    handlers[opcode](self, args)
  Module zope.tal.talinterpreter, line 533, in do_optTag_tal
    self.do_optTag(stuff)
  Module zope.tal.talinterpreter, line 518, in do_optTag
    return self.no_tag(start, program)
  Module zope.tal.talinterpreter, line 513, in no_tag
    self.interpret(program)
  Module zope.tal.talinterpreter, line 343, in interpret
    handlers[opcode](self, args)
  Module zope.tal.talinterpreter, line 531, in do_optTag_tal
    self.no_tag(stuff[-2], stuff[-1])
  Module zope.tal.talinterpreter, line 513, in no_tag
    self.interpret(program)
  Module zope.tal.talinterpreter, line 343, in interpret
    handlers[opcode](self, args)
  Module zope.tal.talinterpreter, line 583, in do_setLocal_tal
    self.engine.setLocal(name, self.engine.evaluateValue(expr))
  Module zope.tales.tales, line 696, in evaluate
    return expression(self)
   -
/var/lib/buildbot/slaves/slave/lucid-db-devel/build/lib/lp/app/browser/../templates/base-layout.pt
   - Line 128, Column 14
   - Expression: <PathExpr standard:u'request/notifications'>
   - Names:
      {'args': (),
       'context': <lp.services.webapp.publisher.RootObject object at
0x9f3ef6c>,
       'default': <object object at 0xf7377700>,
       'loop': {},
       'nothing': None,
       'options': {},
       'repeat': {},
       'request': <lp.services.webapp.servers.LaunchpadBrowserRequest
instance URL=http://launchpad.dev/index.html>,
       'template': <z3c.ptcompat.ViewPageTemplateFile object at 0x1297512c>,
       'view': <zope.browserpage.metaconfigure.SimpleViewClass from
/var/lib/buildbot/slaves/slave/lucid-db-devel/build/lib/lp/app/browser/../templates/root-index.pt
object at 0x106f882c>,
       'views': <zope.app.pagetemplate.viewpagetemplatefile.ViewMapper
object at 0x146147cc>}
  Module zope.tales.expressions, line 217, in __call__
    return self._eval(econtext)
  Module zope.tales.expressions, line 194, in _eval
    ob = self._subexprs[-1](econtext)
  Module zope.tales.expressions, line 124, in _eval
    ob = self._traverser(ob, element, econtext)
  Module zope.pagetemplate.engine, line 66, in __call__
    request=request)
  Module zope.traversing.adapters, line 138, in traversePathElement
    return traversable.traverse(nm, further_path)
   - __traceback_info__:
(<lp.services.webapp.servers.LaunchpadBrowserRequest instance
URL=http://launchpad.dev/index.html>, 'notifications')
  Module zope.traversing.adapters, line 44, in traverse
    attr = getattr(subject, name, _marker)
   - __traceback_info__:
(<lp.services.webapp.servers.LaunchpadBrowserRequest instance
URL=http://launchpad.dev/index.html>, 'notifications', [])
  Module lp.services.webapp.notifications, line 75, in notifications
    return INotificationResponse(self).notifications
  Module lp.services.webapp.notifications, line 195, in notifications
    session = ISession(self)[SESSION_KEY]
  Module zope.session.session, line 433, in __getitem__
    sd = sdc[self.client_id]
  Module lp.services.webapp.pgsession, line 74, in __getitem__
    return PGSessionData(self, client_id)
  Module lp.services.webapp.pgsession, line 104, in __init__
    self.store.execute(query, (self.client_id,), noresult=True)
  Module storm.store, line 108, in execute
    return self._connection.execute(statement, params, noresult)
  Module storm.databases.postgres, line 266, in execute
    return Connection.execute(self, statement, params, noresult)
  Module storm.database, line 230, in execute
    self._ensure_connected()
  Module storm.database, line 352, in _ensure_connected
    raise DisconnectionError(str(exc))
DisconnectionError: could not connect to server: No such file or directory
	Is the server running locally and accepting
	connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.40879"?
}}}

output: {{{
2012-07-25 23:48:49.840 6053 LOG File descriptor limit: 1024 (H:1024),
max_client_conn: 100, max fds possible: 15950
2012-07-25 23:48:49.840 6053 LOG listening on 127.0.0.1:40879
2012-07-25 23:48:49.840 6053 LOG listening on unix:/tmp/.s.PGSQL.40879
2012-07-25 23:48:49.939 6053 LOG C-0x993d530:
(nodb)/(nouser)@127.0.0.1:35562 closing because: client unexpected eof
(age=0)
2012-07-25 23:48:49.945 6053 LOG C-0x993d530:
launchpad_ftest_5461/launchpad_main@127.0.0.1:35564 login successful:
db=launchpad_ftest_5461 user=launchpad_main
2012-07-25 23:48:49.945 6053 LOG S-0x995a768:
launchpad_ftest_5461/launchpad_main@127.0.0.1:5432 new connection to server
2012-07-25 23:48:50.210 6053 LOG C-0x993d620:
launchpad_ftest_5461/launchpad_main@127.0.0.1:35580 login successful:
db=launchpad_ftest_5461 user=launchpad_main
2012-07-25 23:48:50.211 6053 LOG S-0x995a858:
launchpad_ftest_5461/launchpad_main@127.0.0.1:5432 new connection to server
2012-07-25 23:49:49.841 6053 LOG Stats: 2 req/s, in 28598 b/s, out 53844
b/s,query 153821 us
2012-07-25 23:50:49.842 6053 LOG Stats: 2 req/s, in 29419 b/s, out 55394
b/s,query 158439 us
}}}

Notice that the DisconnectionError is for
/var/run/postgresql/.s.PGSQL.40879" but the subsequent log (of what?
pgbouncer?) says that something or other is running on
/tmp/.s.PGSQL.40879 .  Does that discrepency possibly give you an
"ah-ha" moment?

Thanks

Gary