[InterMine Dev] tomcat restart deletes query templates

Joe Carlson jwcarlson at lbl.gov
Sat Aug 8 00:32:34 BST 2015


Hi Sergio,

I looked at this a little bit more. I haven’t stepped through this in the debugger (yet), but here is what I see in my black box testing.

I checked that the proper number of template queries were in the user profile database:

> userprofile-phytomine-dev=# select count(*) from savedtemplatequery;
>  count
> -------
>     51
> (1 row)

Of these, 47 are owned by the intermine superuser. The others are user templates.

Then, became the intermine superuser and “modified" a template query. I actually did nothing, just hit the ‘edit’, then ‘save and run’. I was monitoring the postgres log files with log_statement set to ‘mod’:


> 2015-08-07 16:00:13.818 PDT,,,98659,"",55c5387d.18163,1,"",2015-08-07 16:00:13 PDT,,0,LOG,00000,"connection received: host=128.55.71.54 port=47823",,,,,,,,,""
> 2015-08-07 16:00:13.820 PDT,"jcarlson","phytomine-dev",98659,"128.55.71.54:47823",55c5387d.18163,2,"authentication",2015-08-07 16:00:13 PDT,25/97515,0,LOG,00000,"connection authorized: user=jcarlson database=phytomine-dev",,,,,,,,,""
> 2015-08-07 16:01:05.619 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,5,"DELETE",2015-08-07 15:59:44 PDT,15/20715,0,LOG,00000,"execute <unnamed>: DELETE FROM SavedTemplateQuery WHERE id IN (1135000000)",,,,,,,,,""
> 2015-08-07 16:01:05.672 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,6,"DELETE",2015-08-07 15:59:44 PDT,15/20716,0,LOG,00000,"execute <unnamed>: DELETE FROM SavedTemplateQuery WHERE id IN (1135000001)",,,,,,,,,""
> 2015-08-07 16:01:05.680 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,7,"DELETE",2015-08-07 15:59:44 PDT,15/20717,0,LOG,00000,"execute <unnamed>: DELETE FROM SavedTemplateQuery WHERE id IN (1135000002)",,,,,,,,,""
> 2015-08-07 16:01:05.689 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,8,"DELETE",2015-08-07 15:59:44 PDT,15/20718,0,LOG,00000,"execute <unnamed>: DELETE FROM SavedTemplateQuery WHERE id IN (1135000003)",,,,,,,,,""
> <lines deleted >
> 2015-08-07 16:01:06.047 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,51,"DELETE",2015-08-07 15:59:44 PDT,15/20761,0,LOG,00000,"execute <unnamed>: DELETE FROM SavedTemplateQuery WHERE id IN (1135000046)",,,,,,,,,""
> 2015-08-07 16:01:06.058 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,52,"idle in transaction",2015-08-07 15:59:44 PDT,15/20762,0,LOG,00000,"statement: COPY SavedTemplateQuery (id, templateQuery, userProfileId) FROM STDIN BINARY",,,,,,,,,""
> 2015-08-07 16:01:06.077 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,53,"DELETE",2015-08-07 15:59:44 PDT,15/20763,0,LOG,00000,"execute <unnamed>: DELETE FROM UserProfile WHERE id IN (1000000)",,,,,,,,,""
> 2015-08-07 16:01:06.078 PDT,"jcarlson","userprofile-phytomine-dev",98620,"128.55.71.54:47757",55c53860.1813c,54,"idle in transaction",2015-08-07 15:59:44 PDT,15/20763,8548697,LOG,00000,"statement: COPY UserProfile (superuser, id, password, username, apiKey, localAccount) FROM STDIN BINARY",,,,,,,,,""
> 2015-08-07 16:01:06.091 PDT,"jcarlson","userprofile-phytomine-dev",98622,"128.55.71.54:47759",55c53860.1813e,3,"UPDATE",2015-08-07 15:59:44 PDT,17/89534,0,LOG,00000,"execute <unnamed>: UPDATE templatetrack SET templatename = 'All_Gene_Homolog' WHERE templatename = 'All_Gene_Homolog'",,,,,,,,,""
> 2015-08-07 16:01:06.118 PDT,"jcarlson","userprofile-phytomine-dev",98621,"128.55.71.54:47758",55c53860.1813d,4,"INSERT",2015-08-07 15:59:44 PDT,16/24559,0,LOG,00000,"execute <unnamed>: INSERT INTO querytrack VALUES ( 'Homolog','jwcarlson at lbl.gov','0DB198E8114D7C8002343A200AE9CBDA','2015-08-07 16:01:06.111')",,,,,,,,,""
> 2015-08-07 16:01:39.083 PDT,,,99209,"",55c538d3.18389,1,"",2015-08-07 16:01:39 PDT,,0,LOG,00000,"connection received: host=128.55.64.67 port=37744",,,,,,,,,""
> 2015-08-07 16:01:39.083 PDT,,,99209,"128.55.64.67:37744",55c538d3.18389,2,"",2015-08-07 16:01:39 PDT,,0,LOG,08P01,"incomplete startup packet",,,,,,,,,""



So all 47 template queries are getting deleted one-by-one before COPY to SavedTemplateQuery is getting executed. When I check the db:

> 
> userprofile-phytomine-dev=# select count(*) from savedtemplatequery;
>  count
> -------
>      5
> (1 row)


The 5 queries are the 4 user templates and the one 1 edited. But this isn’t the whole story. Even though the user profile db says I only have 1 template, all 47 template queries still appear on the front page.

But: if I execute a tomcat restart (stopping is done with “$CATALINA_HOME/bin/shutdown.sh -force"), 46 queries are no longer on the front page nor are they in the template page of the superuser MyMine page. Only one remains.

So my questions are: is this to be expected? Are the savedtemplatequeries supposed to be flushed back into the user profile db with some secondary operation? Is there are better way to bring down the web app for a clean shutdown that I need to do?

Thanks,

Joe


On Aug 7, 2015, at 10:01 AM, Joe Carlson <jwcarlson at lbl.gov> wrote:

> Hi Sergio,
> 
> I’m running tomcat 7.0.62 and postgres server 9.4.1 and 9.4.2. I’ve seen the behavior on two different installs.
> 
> I know I have a couple of old templates in the db that do not work anymore. These appear with red lines through them with I become superuser and look at the templates. I was assuming (or maybe just hoping) that this could be ignored. Whether or not this is related, I’m also seeing NotSerializableException from org.intermine.api.template.ApiTemplate in the log files. I’m starting to look into that.
> 
> This morning I’ll try some experiments to see if loosing the templates is reproducible. And if cleaning up the templates helps. Unfortunately I don’t have access to the postgres log files so I cannot track the db activity too closely. (but…I’m begging)
> 
> It is strange since we used to have a problem with tomcat restarts quite often. And did not see the templates disappear then. As I recall, there were bogus template queries at that time.
> 
> Joe
> 
> On Aug 7, 2015, at 4:25 AM, sergio contrino <sergio at modencode.org> wrote:
> 
>> dear Joe,
>> we have not experienced the issue of the disappearance of saved tamplates and it should not be linked to the tomcat restart.
>> could you send us the postgres and tomcat versions, and anything else that seems relevant to you? i can try to replicate it here.
>> thanks
>> sergio
>> 
>> 
>> On 06/08/15 17:42, Joe Carlson wrote:
>>> Hi Julie and others,
>>> 
>>> I've seen a problem the past couple weeks. I'm just starting to figure
>>> out what is going on here. What I'm seeing is that a tomcat restart
>>> causes most of the saved templates to disappear. The savedtemplatequery
>>> table in the userprofile db is almost cleaned out - it looks like there
>>> are still some user-created queries, but only 1 template created by the
>>> superuser. Of course they do not show up on the front page.
>>> 
>>> I think - but I'm not even sure about this - is that it happens with a
>>> tomcat restart.
>>> 
>>> Most curious. Have you ever seen this behavior? I have a backup that I
>>> can restore so it's not a catastrophe but annoying.
>>> 
>>> Thanks,
>>> 
>>> Joe
>>> 
>>> _______________________________________________
>>> dev mailing list
>>> dev at intermine.org
>>> http://mail.intermine.org/cgi-bin/mailman/listinfo/dev
>>> 
>> 
>> -- 
>> sergio contrino                  InterMine, University of Cambridge
>> https://sergiocontrino.github.io           http://www.intermine.org
> 

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.intermine.org/pipermail/dev/attachments/20150807/66a8abca/attachment-0001.html>


More information about the dev mailing list