Bug: web delete/refresh issues

[jamoore]

Initial error sequence

While testing #5749 I ran into an odd progression of events. I'll try to summarize them here, before I start reproducing (to follow).

Setup

• In the web (using Chris' 7750_web_config branch, just merged into develop), I created two projects and then copied one dataset into both of them.
• I selected both projects and deleted them.
• In the activities window, I saw an error which I wanted to reproduce on the command-line. (See ​this screenshot, taken later)
• I went to the command-line and reproduced, but it was only a warning, not an error (see "Command-line delete" below)
• I went back to the web UI, the error was gone. I.e. the UI had been updated with no more error. (I didn't initially have a screen shot of that, found later)
• Knowing that I had mucked around on the command-line, I refreshed.

What went wrong

• Either just before the refresh, during, or just after (sorry, can't remember), I noticed the "please login" screen in the third panel. (See ​screenshot)
• I then went about trying to reproduce the project/datasets but I had a number of XMLHTTPRequest errors. (see ​non-debug log)
• After those errors ended, I thought things were back to normal, so I tried the delete again. This time, I reproduced the error in #5749 (also captured in log)

My very inexpert thought at the moment is that somewhere a reference is being held to a delete handle, but I'm going to try to reproduce as much of the above as I can now.

After trying to reproduce

After all of the above, I restarted the server with omero.web.debug=true, but I never reproduced the XMLHTTPRequest. I was able, however, to reproduce

• the problem in #3021/#5749, namely the ObjectNotExistException (See ​this screenshot)
• as well as the issues in #3142 (See ​this screenshot),
• and, the error message which is just a warning message, see #6003

Suggestions

There may not be anything that can be done about the XMLHttpRequest. Sorry that I couldn't reproduce, but all of the other issues it would be nice if they could be looked into. i.e.

• prevent the errors from showing up in the activities window. Warnings should not be considered errors in any counts.
• prevent the "sorry, that object does not exist" from showing up in the right panel
• prevent the "please login" from showing up in the right panel (this may be harder, but I understand it's already in progress)
• prevent the ObjectNotExistException from being thrown.

If this would be better suited as a story, feel free.

Also, if from a log file it is not clear at what time certain actions took place, I suggest increasing logging. I'd be glad to re-test once that's in place.

Extra information

Previously filed tickets

• #3021 - ObjectNotExistException on delete.errors()
• #5749 - ObjectNotExistException on delete.errors()
• #3142 - "sorry, dataset does not exist"
• #6003 - warnings v. errors

Command-line delete

This is an example of the warnings typical for #6003:

@7750_web_config ~/git/dist $ bin/omero hql "select p from Project p"
Using session b8f43b0e-5832-4ddd-ace8-58d2137197af (root@gretzky.openmicroscopy.org.uk:4064). Idle timeout: 10.0 min. Current group: system
 # | Class    | Id   | name        | details         
---+----------+------+-------------+-----------------
 0 | ProjectI | 3618 | New project | owner=0;group=0 
 1 | ProjectI | 3619 | New project | owner=0;group=0 
(2 rows)

To see details for object, enter line number.
To move ahead one page, enter 'p'
To re-display list, enter 'r'.
To quit, enter 'q' or just enter.
q
@7750_web_config ~/git/dist $ bin/omero delete /Project:0 /Project:1
Using session b8f43b0e-5832-4ddd-ace8-58d2137197af (root@gretzky.openmicroscopy.org.uk:4064). Idle timeout: 10.0 min. Current group: system
^CCancelled
@7750_web_config ~/git/dist $ bin/omero delete /Project:3618 /Project:3619
Using session b8f43b0e-5832-4ddd-ace8-58d2137197af (root@gretzky.openmicroscopy.org.uk:4064). Idle timeout: 10.0 min. Current group: system
Deleting /Project 3618... ok
	warning: ConstraintViolation: fkprojectdatasetlink_child_dataset
Deleting /Project 3619... ok
@7750_web_config ~/git/dist $ bin/omero hql "select p from Project p"
Using session b8f43b0e-5832-4ddd-ace8-58d2137197af (root@gretzky.openmicroscopy.org.uk:4064). Idle timeout: 10.0 min. Current group: system
 # 
---
(0 rows)

To see details for object, enter line number.
To move ahead one page, enter 'p'
To re-display list, enter 'r'.
To quit, enter 'q' or just enter.
q
@7750_web_config ~/git/dist $ bin/omero hql "select p from Dataset p""
> 
@7750_web_config ~/git/dist $ bin/omero hql "select p from Dataset p"
Using session b8f43b0e-5832-4ddd-ace8-58d2137197af (root@gretzky.openmicroscopy.org.uk:4064). Idle timeout: 10.0 min. Current group: system
 # 
---
(0 rows)

To see details for object, enter line number.
To move ahead one page, enter 'p'
To re-display list, enter 'r'.
To quit, enter 'q' or just enter.

[jmoore]

btw, here are the only entries from the OMEROweb.log after the above xmlerr.log file (i.e. the ObjectNotExist):

@master ~/Pictures $ diff web-jan12-xmlerr.log web-jan12-objnotexist.log 
937a938,953
> Thu, 12 Jan 2012 10:26:46 views-web    ERROR    Failed to delete: {'did': [u'3621', u'3620'], 'dtype': 'project'}
> Traceback (most recent call last):
>   File "/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omeroweb/webclient/views.py", line 1925, in manage_action_containers
>     dMap = {'job_type': 'delete', 'start_time': datetime.datetime.now(),'status':'in progress', 'derrors':handle.errors(),
>   File "/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omero_api_IDelete_ice.py", line 335, in errors
>     return _M_omero.api.delete.DeleteHandle._op_errors.invoke(self, ((), _ctx))
> ObjectNotExistException: exception ::Ice::ObjectNotExistException
> {
>     id = 
>     {
>         name = DeleteHandle51a4417d-0a52-4d89-84ba-bdd93bb252f1
>         category = b8f43b0e-5832-4ddd-ace8-58d2137197af
>     }
>     facet = 
>     operation = errors
> }

[jmoore]

After restart with omero.web.debug=True.

[jmoore]

Error rather than warning on link FK constraint.

[jmoore]

error still printed when marked as "complete"

[jmoore]

error is gone on re-opening the activities window

[jmoore]

Just uploaded 3 screenshots which show the first issue which matches the command-line output. This is closely related to #6003, i.e. a warning is being shown as an error.

[jmoore]

First attempt to reproduce the refresh issues.

[jmoore]

Delete in command-line and then click "new dataset"

[jmoore]

If instead, I try to click on the "new dataset" link after deleting the project from the commandline, then I get this "internal server error" (previous screenshot).

[jmoore]

Reproduced the the "Page not found 404": Request URL: http://localhost:8000/webclient/metadata_details/project/undefined/ by:

• Refresh to remove the delete project (from my previous comment)
• Click on user
• Click on "create project" twice
• Click on the first of the two projects.

There's not much in the debug log:

Thu, 12 Jan 2012 12:01:57 omero.util.TempFileManager DEBUG    Removing tree: /Users/moore/omero/tmp/omero_moore/82132
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103bb1790>)]
Thu, 12 Jan 2012 11:02:08 views-web    ERROR    Traceback (most recent call last):
  File "/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omeroweb/webclient/views.py", line 1501, in manage_action_containers
    manager = BaseContainer(conn, **kw)
  File "/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omeroweb/webclient/controller/container.py", line 67, in __init__
    raise AttributeError("We are sorry, but that project (id:%s) does not exist, or if it does, you have no permission to see it.  Contact the user you think might share that data with you." % str(project))
AttributeError: We are sorry, but that project (id:3626) does not exist, or if it does, you have no permission to see it.  Contact the user you think might share that data with you.

Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c50>)]
Thu, 12 Jan 2012 11:03:41 views-web    DEBUG    TEMPLATE: webclient/data/containers_tree.html
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c90>)]
Thu, 12 Jan 2012 11:03:46 views-web    DEBUG    TEMPLATE: webclient/data/containers_icon.html
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c90>)]
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c50>)]
Thu, 12 Jan 2012 11:03:52 views-web    DEBUG    Create new: {'name': 'New project', 'description': u''}
Thu, 12 Jan 2012 11:03:52 views-web    DEBUG    Create new: {'name': 'New project', 'description': u''}

[atarkowska]

Replying to jmoore:

Reproduced the the "Page not found 404": Request URL: http://localhost:8000/webclient/metadata_details/project/undefined/ by:

• Refresh to remove the delete project (from my previous comment)
• Click on user
• Click on "create project" twice
• Click on the first of the two projects.

There's not much in the debug log:

Thu, 12 Jan 2012 12:01:57 omero.util.TempFileManager DEBUG    Removing tree: /Users/moore/omero/tmp/omero_moore/82132
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:02:07 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103bb1790>)]
Thu, 12 Jan 2012 11:02:08 views-web    ERROR    Traceback (most recent call last):
  File "/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omeroweb/webclient/views.py", line 1501, in manage_action_containers
    manager = BaseContainer(conn, **kw)
  File "/Users/moore/GlencoeSoftware.git/git/omero.git/dist/lib/python/omeroweb/webclient/controller/container.py", line 67, in __init__
    raise AttributeError("We are sorry, but that project (id:%s) does not exist, or if it does, you have no permission to see it.  Contact the user you think might share that data with you." % str(project))
AttributeError: We are sorry, but that project (id:3626) does not exist, or if it does, you have no permission to see it.  Contact the user you think might share that data with you.

Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:40 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c50>)]
Thu, 12 Jan 2012 11:03:41 views-web    DEBUG    TEMPLATE: webclient/data/containers_tree.html
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:45 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c90>)]
Thu, 12 Jan 2012 11:03:46 views-web    DEBUG    TEMPLATE: webclient/data/containers_icon.html
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:51 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c90>)]
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    :: (session) root gretzky.openmicroscopy.org.uk 4064
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    :: (request) None None None
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    trying stored connection with userAgent: OMERO.web  ckey: S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1
Thu, 12 Jan 2012 11:03:52 webgateway   DEBUG    [('S:4d7d8252-a074-487b-95cb-5e7bf7dd33b7#1', <webclient.webclient_gateway.OmeroWebGateway object at 0x103ba7c50>)]
Thu, 12 Jan 2012 11:03:52 views-web    DEBUG    Create new: {'name': 'New project', 'description': u''}
Thu, 12 Jan 2012 11:03:52 views-web    DEBUG    Create new: {'name': 'New project', 'description': u''}

Sorry but your steps are exactly opposite to what log says. Can you make sure you past matching information from the log file? It which step did you see url ​http://localhost.../project/undefined/?

[atarkowska]

Replying to jmoore:

If instead, I try to click on the "new dataset" link after deleting the project from the commandline, then I get this "internal server error" (previous screenshot).

If object is deleted from other client by clicking on the tree in metadata panel you would just see "We are sorry, but that project (id:xxx) does not exist, or if it does, you have no permission to see it. Contact the user you think might share that data with you."

"Internal server error. Cannot create object" came from the fact you were logged out. We are now in the process of handling it better to give access to the login box.

[jmoore]

Replying to atarkowska:

Replying to jmoore:

Reproduced the the "Page not found 404": Request URL: http://localhost:8000/webclient/metadata_details/project/undefined/ by:

• Refresh to remove the delete project (from my previous comment)
• Click on user
• Click on "create project" twice
• Click on the first of the two projects.

Sorry but your steps are exactly opposite to what log says. Can you make sure you past matching information from the log file? It which step did you see url ​http://localhost.../project/undefined/?

How do you mean, Ola? This is the log which shows the two previous errors. Only the bits from 11:03 are the "Create project twice" steps. I'll attach the entire debug log file now.

[jmoore]

OMEROweb.log file after setting omero.web.debug to true and retrying various things. Part of this log file was pasted into a previous comment.

[jmoore]

Replying to atarkowska:

If object is deleted from other client by clicking on the tree in metadata panel you would just see "We are sorry, but that project (id:xxx) does not exist, or if it does, you have no permission to see it. Contact the user you think might share that data with you."

But that's not what I saw every time. Sometimes definitely.

"Internal server error. Cannot create object" came from the fact you were logged out. We are now in the process of handling it better to give access to the login box.

But why was I logged out? I never logged back in.

[atarkowska]

Replying to jmoore:

"Internal server error. Cannot create object" came from the fact you were logged out. We are now in the process of handling it better to give access to the login box.

But why was I logged out? I never logged back in.

If you do not use web for more then 10 minutes it is obvious. If it happened while you were using application you need to check web/server log what happened.

[atarkowska]

Re: attachment web-jan12-errondelete.png . If there is warning you would see "0 errors (....)". It's strange why

handle = omero.api.delete.DeleteHandlePrx.checkedCast(conn.c.ic.stringToProxy(cbString))
handle.errors()

didn't give any number.

[jmoore]

Replying to atarkowska:

Re: attachment web-jan12-errondelete.png . If there is warning you would see "0 errors (....)". It's strange why
...
didn't give any number.

I would think reports were returned but with warnings only, not errors.