connection issue on OMEROweb

[jennBakal]

hi,

we recently started having trouble when logging in to OMERO.web. typing in a valid username and password results in an Internal Server Error page; when the page is refreshed it goes to the home page as usual after login. it doesn't happen all the time. running 4.3.3. i'm attaching the relevant part of OMEROweb.log for a time that it failed.

thanks,
jenn

Code: Select all

Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:cf25863c-1a71-4a47-9ee3-e789331eb239#1
Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    []
Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    creating new connection with ckey "S:", sUuid "cf25863c-1a71-4a47-9ee3-e789331eb239" (False)
Thu, 19 Jul 2012 02:56:23 blitz_gateway DEBUG    Connect attempt, sUuid=cf25863c-1a71-4a47-9ee3-e789331eb239, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:56:23 blitz_gateway DEBUG    connected? False
Thu, 19 Jul 2012 02:56:23 blitz_gateway DEBUG    Error: exception ::Glacier2::PermissionDeniedException
Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    created new connection <webclient.webclient_gateway.OmeroWebGateway object at 0x2865090>
Thu, 19 Jul 2012 02:56:23 webgateway   DEBUG    connection failed with provided login information, bail out
Thu, 19 Jul 2012 02:56:24 views-admin  INFO     INIT '26370'
Thu, 19 Jul 2012 02:56:24 webgateway   DEBUG    Traceback (most recent call last):
Thu, 19 Jul 2012 02:56:24 webgateway   ERROR    Critical error during connect, retrying after _purge
Thu, 19 Jul 2012 02:56:24 webgateway   DEBUG    Traceback (most recent call last):
Thu, 19 Jul 2012 02:56:24 webgateway   INFO     reached connector_pool_size (70), size after purge: (0)
Thu, 19 Jul 2012 02:56:24 webgateway   DEBUG    Traceback (most recent call last):
Thu, 19 Jul 2012 02:56:24 admin-utils  INFO     Open connection is not available
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    Connect attempt, sUuid=None, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    Creating Session...
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    Session created with timeout: 600000 & timeToLive: 0
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    ## Creating proxies
Thu, 19 Jul 2012 02:56:38 blitz_gateway INFO     created connection (uuid=66ed5643-a3c8-4ff5-8713-5ada50ee2c87)
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    .. connected!
Thu, 19 Jul 2012 02:56:38 admin-utils  INFO     Have connection as Guest
Thu, 19 Jul 2012 02:56:38 admin-utils  INFO     Client version: '4.3.3-00d1137e-b2894'; Server version: '4.3.3-00d1137e-b2894'
Thu, 19 Jul 2012 02:56:38 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:56:38 webgateway   DEBUG    :: (request) demo_nm None None
Thu, 19 Jul 2012 02:56:38 webgateway   INFO     getBlitzConnection(host=localhost, port=14064, ssl=False, username=demo_nm)
Thu, 19 Jul 2012 02:56:38 webgateway   DEBUG    k=cuuid#1
Thu, 19 Jul 2012 02:56:38 webgateway   DEBUG    creating new connection with ckey "S:", sUuid "None" (False)
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    Connect attempt, sUuid=None, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:56:38 blitz_gateway DEBUG    Creating Session...
Thu, 19 Jul 2012 02:56:39 blitz_gateway DEBUG    ## Creating proxies
Thu, 19 Jul 2012 02:56:39 blitz_gateway DEBUG    Session created with timeout: 600000 & timeToLive: 0
Thu, 19 Jul 2012 02:56:39 blitz_gateway DEBUG    ## Reusing proxies
Thu, 19 Jul 2012 02:56:39 blitz_gateway DEBUG    ## - refreshing getQueryService
Thu, 19 Jul 2012 02:56:39 blitz_gateway DEBUG    ## - refreshing getAdminService
Thu, 19 Jul 2012 02:56:39 blitz_gateway INFO     created connection (uuid=49a7c021-1b77-41e9-95bd-88853261943b)
Thu, 19 Jul 2012 02:56:39 blitz_gateway DEBUG    .. connected!
Thu, 19 Jul 2012 02:56:39 webgateway   DEBUG    created new connection <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>
Thu, 19 Jul 2012 02:56:39 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259aed0>), ('S:\
49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>)]
Thu, 19 Jul 2012 02:56:39 webgateway   DEBUG    blitz session key: 49a7c021-1b77-41e9-95bd-88853261943b
Thu, 19 Jul 2012 02:56:39 webgateway   DEBUG    stored as session.S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:56:39 omero.util.UpgradeCheck DEBUG    Attempting to connect to http://upgrade.openmicroscopy.org.uk/?os.version=%231+SMP+PREEMPT+Fri+Jul+3+20%3A2\
8%3A31+EDT+2009&os.arch=x86_64&version=4.3.3-00d1137e-b2894&python.compiler=GCC+4.3.2+20080917+%28Red+Hat+4.3.2-4%29&python.build=%28%27r252%3A60911%27%2C+%27Sep+30+2\
008+15%3A42%3A03%27%29&os.name=Linux&python.version=2.5.2
Thu, 19 Jul 2012 02:57:09 omero.util.UpgradeCheck WARNING  UPGRADE AVAILABLE:Please upgrade to 4.4.0 See http://trac.openmicroscopy.org.uk/omero for the latest version
Thu, 19 Jul 2012 02:57:09 admin-utils  ERROR    Upgrade is available. Please visit http://trac.openmicroscopy.org.uk/omero/wiki/MilestoneDownloads.
Thu, 19 Jul 2012 02:57:20 omero.util.TempFileManager DEBUG    Added file /usr0/local/omero.server/OMERO.server-Beta-4.3.3/tmp/.lock_test9r7Wp5.tmp
Thu, 19 Jul 2012 02:57:20 omero.util.TempFileManager DEBUG    Chose gloabl tmpdir: /usr0/local/omero.server/OMERO.server-Beta-4.3.3/tmp
Thu, 19 Jul 2012 02:57:20 omero.util.TempFileManager DEBUG    Using temp dir: /usr0/local/omero.server/OMERO.server-Beta-4.3.3/tmp/omero/tmp/omero_omero_user/26368
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    INIT
Thu, 19 Jul 2012 02:57:20 views-web    INFO     INIT '26368'
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    []
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    creating new connection with ckey "S:", sUuid "49a7c021-1b77-41e9-95bd-88853261943b" (False)
Thu, 19 Jul 2012 02:57:20 blitz_gateway DEBUG    Connect attempt, sUuid=49a7c021-1b77-41e9-95bd-88853261943b, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:57:20 blitz_gateway DEBUG    connected? False
Thu, 19 Jul 2012 02:57:20 blitz_gateway DEBUG    Joined Session OK with Uuid: 49a7c021-1b77-41e9-95bd-88853261943b and timeToIdle: 600000, timeToLive: 0
Thu, 19 Jul 2012 02:57:20 blitz_gateway DEBUG    ## Creating proxies
Thu, 19 Jul 2012 02:57:20 blitz_gateway INFO     created connection (uuid=49a7c021-1b77-41e9-95bd-88853261943b)
Thu, 19 Jul 2012 02:57:20 blitz_gateway DEBUG    .. connected!
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    created new connection <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    blitz session key: 49a7c021-1b77-41e9-95bd-88853261943b
Thu, 19 Jul 2012 02:57:20 webgateway   DEBUG    stored as session.S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:57:20 views-admin  INFO     INIT '26368'
Thu, 19 Jul 2012 02:57:20 views-web    DEBUG    TEMPLATE: webclient/data/containers.html
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    []
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    creating new connection with ckey "S:", sUuid "49a7c021-1b77-41e9-95bd-88853261943b" (False)
Thu, 19 Jul 2012 02:57:21 blitz_gateway DEBUG    Connect attempt, sUuid=49a7c021-1b77-41e9-95bd-88853261943b, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:57:21 blitz_gateway DEBUG    connected? False
Thu, 19 Jul 2012 02:57:21 blitz_gateway DEBUG    Joined Session OK with Uuid: 49a7c021-1b77-41e9-95bd-88853261943b and timeToIdle: 600000, timeToLive: 0
Thu, 19 Jul 2012 02:57:21 blitz_gateway DEBUG    ## Creating proxies
Thu, 19 Jul 2012 02:57:21 blitz_gateway INFO     created connection (uuid=49a7c021-1b77-41e9-95bd-88853261943b)
Thu, 19 Jul 2012 02:57:21 blitz_gateway DEBUG    .. connected!
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    created new connection <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>)]
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    blitz session key: 49a7c021-1b77-41e9-95bd-88853261943b
Thu, 19 Jul 2012 02:57:21 webgateway   DEBUG    stored as session.S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:57:26 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:57:26 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:57:26 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:57:26 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:57:27 views-web    DEBUG    TEMPLATE: webclient/data/containers_tree.html
Thu, 19 Jul 2012 02:58:36 omero.util.TempFileManager DEBUG    Added file /usr0/local/omero.server/OMERO.server-Beta-4.3.3/tmp/.lock_test-q5SQs.tmp
Thu, 19 Jul 2012 02:58:36 omero.util.TempFileManager DEBUG    Chose gloabl tmpdir: /usr0/local/omero.server/OMERO.server-Beta-4.3.3/tmp
Thu, 19 Jul 2012 02:58:36 omero.util.TempFileManager DEBUG    Using temp dir: /usr0/local/omero.server/OMERO.server-Beta-4.3.3/tmp/omero/tmp/omero_omero_user/26371
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    INIT
Thu, 19 Jul 2012 02:58:36 views-web    INFO     INIT '26371'
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    []
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    creating new connection with ckey "S:", sUuid "49a7c021-1b77-41e9-95bd-88853261943b" (False)
Thu, 19 Jul 2012 02:58:36 blitz_gateway DEBUG    Connect attempt, sUuid=49a7c021-1b77-41e9-95bd-88853261943b, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:58:36 blitz_gateway DEBUG    connected? False
Thu, 19 Jul 2012 02:58:36 blitz_gateway DEBUG    Joined Session OK with Uuid: 49a7c021-1b77-41e9-95bd-88853261943b and timeToIdle: 600000, timeToLive: 0
Thu, 19 Jul 2012 02:58:36 blitz_gateway DEBUG    ## Creating proxies
Thu, 19 Jul 2012 02:58:36 blitz_gateway INFO     created connection (uuid=49a7c021-1b77-41e9-95bd-88853261943b)
Thu, 19 Jul 2012 02:58:36 blitz_gateway DEBUG    .. connected!
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    created new connection <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    blitz session key: 49a7c021-1b77-41e9-95bd-88853261943b
Thu, 19 Jul 2012 02:58:36 webgateway   DEBUG    stored as session.S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:58:36 views-admin  INFO     INIT '26371'
Thu, 19 Jul 2012 02:58:36 views-web    DEBUG    TEMPLATE: webclient/data/containers.html
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:58:37 views-web    INFO     INIT '26369'
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95\
bd-88853261943b#1
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    []
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    creating new connection with ckey "S:", sUuid "49a7c021-1b77-41e9-95bd-88853261943b" (False)
Thu, 19 Jul 2012 02:58:37 blitz_gateway DEBUG    Connect attempt, sUuid=49a7c021-1b77-41e9-95bd-88853261943b, group=None, self.sUuid=None
Thu, 19 Jul 2012 02:58:37 blitz_gateway DEBUG    connected? False
Thu, 19 Jul 2012 02:58:37 blitz_gateway DEBUG    Joined Session OK with Uuid: 49a7c021-1b77-41e9-95bd-88853261943b and timeToIdle: 600000, timeToLive: 0
Thu, 19 Jul 2012 02:58:37 blitz_gateway DEBUG    ## Creating proxies
Thu, 19 Jul 2012 02:58:37 blitz_gateway INFO     created connection (uuid=49a7c021-1b77-41e9-95bd-88853261943b)
Thu, 19 Jul 2012 02:58:37 blitz_gateway DEBUG    .. connected!
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    created new connection <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>)]
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    blitz session key: 49a7c021-1b77-41e9-95bd-88853261943b
Thu, 19 Jul 2012 02:58:37 webgateway   DEBUG    stored as session.S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:58:37 views-admin  INFO     INIT '26369'
Thu, 19 Jul 2012 02:58:41 views-web    DEBUG    TEMPLATE: webclient/data/containers_tree.html
Thu, 19 Jul 2012 02:58:42 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:58:42 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:58:42 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:58:42 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:59:14 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:14 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:14 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:14 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:59:14 views-web    DEBUG    TEMPLATE: webclient/data/container_subtree.html
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>)]
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259aed0>), ('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>)]
Thu, 19 Jul 2012 02:59:18 views-web    DEBUG    TEMPLATE: webclient/annotations/metadata_general.html
Thu, 19 Jul 2012 02:59:18 views-web    DEBUG    TEMPLATE: webclient/data/containers_icon.html
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:59:18 cache        DEBUG      fail: thumb_user_1/77177/252/80
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>)]
Thu, 19 Jul 2012 02:59:18 cache        DEBUG      fail: thumb_user_1/77174/252/80
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259aed0>), ('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object\
at 0x329d390>)]
Thu, 19 Jul 2012 02:59:18 cache        DEBUG      fail: thumb_user_1/77180/252/80
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:18 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:59:18 cache        DEBUG      fail: thumb_user_1/77183/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77186/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77174/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77183/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77177/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77180/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroW\
ebGateway object at 0x259aed0>), ('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77189/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77192/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77195/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77198/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77186/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77201/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77189/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259aed0>), ('S:49a\
7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77204/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77192/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77207/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77195/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77201/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77198/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77210/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77212/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77214/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77204/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259aed0>), ('S:49a\
7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77218/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77207/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77221/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77210/252/80
Thu, 19 Jul 2012 02:59:20 cache        DEBUG       set: thumb_user_1/77212/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77223/252/80
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:20 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x10457850>)]
Thu, 19 Jul 2012 02:59:20 cache        DEBUG      fail: thumb_user_1/77226/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77214/252/80
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x2598b50>)]
Thu, 19 Jul 2012 02:59:21 cache        DEBUG      fail: thumb_user_1/77229/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77218/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77221/252/80
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    [('S:cf25863c-1a71-4a47-9ee3-e789331eb239#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259aed0>), ('S:49a\
7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x329d390>)]
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x3012bd0>)]
Thu, 19 Jul 2012 02:59:21 cache        DEBUG      fail: thumb_user_1/77232/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG      fail: thumb_user_1/77235/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77223/252/80
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:21 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]
Thu, 19 Jul 2012 02:59:21 cache        DEBUG      fail: thumb_user_1/77238/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77229/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77226/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77232/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77235/252/80
Thu, 19 Jul 2012 02:59:21 cache        DEBUG       set: thumb_user_1/77238/252/80
Thu, 19 Jul 2012 02:59:28 webgateway   DEBUG    :: (session) demo_nm localhost 14064
Thu, 19 Jul 2012 02:59:28 webgateway   DEBUG    :: (request) None None None
Thu, 19 Jul 2012 02:59:28 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:49a7c021-1b77-41e9-95bd-88853261943b#1
Thu, 19 Jul 2012 02:59:28 webgateway   DEBUG    [('S:49a7c021-1b77-41e9-95bd-88853261943b#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x259ac90>)]


[wmoore]

Hi Jenn,

When you say "recently", do you mean since last Friday (or before)? If it's since last friday, then it may be something in the Upgrade Check, which will be telling you there's a new release. This shouldn't be causing any problems, but you could try to disable it and see if that helps - see http://trac.openmicroscopy.org.uk/ome/wiki/UpgradeCheck.

Do you see anything useful on the Internal Server Error page? Stack trace etc?

There's a couple of other ERRORs in the logs, but no reason that they should start causing problems recently. I can try to track them down, but if you can give us any more info in the meantime, that would be great,

Thanks,

Will.

[jennBakal]

When you say "recently", do you mean since last Friday (or before)?

no, it's been happening for a few weeks. on closer look, the 500 Internal Server error is being generated by apache (no traceback - it just says Internal Server Error... contact administrator...) . when i look at the apache log files, the only errors are fastcgi ones:

Code: Select all

[Thu Jul 19 01:38:31 2012] [error] [client 114.248.122.165] (111)Connection refused: FastCGI: failed to connect to server "/usr0/local/omero.server/OMERO.server-Beta-4.2.1/var/omero.fcgi": connect() failed
[Thu Jul 19 01:38:31 2012] [error] [client 114.248.122.165] FastCGI: incomplete headers (0 bytes) received from server "/usr0/local/omero.server/OMERO.server-Beta-4.2.1/var/omero.fcgi"


(i wasn't able to get the login error to happen again just now and i wasn't able to find errors from the same timepoint as the login issue i quoted originally, so i'm not sure these are related to the issue, but they're the main ones being generated. the other fastcgi error that was generated in that log is quoted below and definitely relates to a different action.)

we've been having a similar issue on a couple other pages:

* with our content search page - sometimes it works, sometimes it returns the apache 500 Internal Server Error page. refreshing page does not usually help. sometimes restarting omero server fixes it.
i was able to generate this one again and got the following in the apache error log:

Code: Select all

[Thu Jul 19 12:00:15 2012] [error] [client 108.17.80.96] FastCGI: comm with server "/usr0/local/omero.server/OMERO.server-Beta-4.3.3/var/omero.fcgi" aborted: idle timeout (30 sec), referer: http://omepslid2.compbio.cs.cmu.edu/webclient/userdata/
[Thu Jul 19 12:00:15 2012] [error] [client 108.17.80.96] FastCGI: incomplete headers (0 bytes) received from server "/usr0/local/omero.server/OMERO.server-Beta-4.3.3/var/omero.fcgi", referer: http://omepslid2.compbio.cs.cmu.edu/webclient/userdata/


* going to the Data page - sometimes datasets load, sometimes the little loading clock just sits and spins. refreshing the page sometimes helps.

let me know if you need more info,

thanks,
jenn

[jennBakal]

* with our content search page - sometimes it works, sometimes it returns the apache 500 Internal Server Error page. refreshing page does not usually help. sometimes restarting omero server fixes it.
i was able to generate this one again and got the following in the apache error log:

Code: Select all

[Thu Jul 19 12:00:15 2012] [error] [client 108.17.80.96] FastCGI: comm with server "/usr0/local/omero.server/OMERO.server-Beta-4.3.3/var/omero.fcgi" aborted: idle timeout (30 sec), referer: http://omepslid2.compbio.cs.cmu.edu/webclient/userdata/
[Thu Jul 19 12:00:15 2012] [error] [client 108.17.80.96] FastCGI: incomplete headers (0 bytes) received from server "/usr0/local/omero.server/OMERO.server-Beta-4.3.3/var/omero.fcgi", referer: http://omepslid2.compbio.cs.cmu.edu/webclient/userdata/


okay, i guess if i'd actually read this error before posting.... the content search usually does take longer than 30 secs, so i guess the timeout would account for why it sometimes works but most times doesn't. is the fastcgi timeout something that should be set via omero or via our apache2/httpd.conf file? in either case, i don't think we changed anything, so any idea why/how it would suddenly become an issue?

thanks again,
jenn

[wmoore]

Hi Jenn,

I think you are right about the nginx timeout. Unfortunately I'm not an expert on nginx, but this looks like the kind of problem you're seeing: http://stackoverflow.com/questions/5619 ... with-nginx which concludes that it's the fastcgi_read_timeout you need to set.

See: http://wiki.nginx.org/HttpFastcgiModule ... ad_timeout — for fastcgi_read_timeout (Also fastcgi_connect_timeout?).

You can see where to put this on our example at https://www.openmicroscopy.org/site/sup ... nstall_web

Hope that helps,

Will.