TG commit failing with Exception: Problems handling commit history for ontology

[dosumis]

Term Genie commit is now failing with the following error message:

"The commit operation did not succeed, exception: Problems handling commit history for ontology: GeneOntology. Cause: Could not execute db update."

[nathandunn]

GoYamlPermissionsTool returning data:  {allow-management=true, allow-freeform=false, allow-freeform-litxref-optional=true, allow-review=true, allow-write=true}
GoYamlUserPermissionsImpl has flag? allow-write value true
org.bbop.termgenie.services.DefaultTermCommitServiceImpl name from userData: UserDataImpl {screenname=David Osumi-Sutherland, guid=dosumis, email=null, xref=GOC:dos, scmAlias=dosumis, orcid=http://orcid.org/0000-0002-7073-9172} yields scm dosumis
org.bbop.termgenie.services.DefaultTermCommitServiceImpl name from guid: dosumis
org.bbop.termgenie.services.DefaultTermCommitServiceImpl name from screen: dosumis
org.bbop.termgenie.services.DefaultTermCommitServiceImpl name from email: dosumis
[GO WARN] 2016-12-05 02:57:20 (OntologyCommitReviewPipeline:498) Problems handling commit history for ontology: GeneOntology
org.bbop.termgenie.ontology.CommitHistoryStore$CommitHistoryStoreException: Could not execute db update
        at org.bbop.termgenie.ontology.CommitHistoryStoreImpl.add(CommitHistoryStoreImpl.java:71)
        at org.bbop.termgenie.ontology.OntologyCommitReviewPipeline.commit(OntologyCommitReviewPipeline.java:88)
        at org.bbop.termgenie.services.DefaultTermCommitServiceImpl$CommitTask.runSimple(DefaultTermCommitServiceImpl.java:426)
        at org.bbop.termgenie.ontology.OntologyIdManager$OntologyIdManagerTask.run(OntologyIdManager.java:62)
        at org.bbop.termgenie.ontology.OntologyIdManager$OntologyIdManagerTask.run(OntologyIdManager.java:58)
        at org.bbop.termgenie.core.management.GenericTaskManager.runManagedTask(GenericTaskManager.java:295)
        at org.bbop.termgenie.services.DefaultTermCommitServiceImpl.commitTerms(DefaultTermCommitServiceImpl.java:188)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.json.rpc.server.InjectingJsonRpcExecutor.executeMethod(InjectingJsonRpcExecutor.java:264)
        at org.json.rpc.server.InjectingJsonRpcExecutor.execute(InjectingJsonRpcExecutor.java:171)
        at org.bbop.termgenie.servlets.TermGenieJsonRPCServlet.doPost(TermGenieJsonRPCServlet.java:43)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:648)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
        at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:287)
        at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:277)
        at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:182)
        at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91)
        at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85)
        at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:119)
        at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:133)
        at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:130)
        at com.google.inject.servlet.GuiceFilter$Context.call(GuiceFilter.java:203)
        at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:130)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
        at org.eclipse.jetty.server.Server.handle(Server.java:499)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
        at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
        at java.lang.Thread.run(Thread.java:745)
Caused by: <openjpa-2.2.2-r422266:1468616 fatal user error> org.apache.openjpa.persistence.InvalidStateException: The field "email" of instance "org.bbop.termgenie.ontology.entities.CommitHistoryItem@3cd8f045" contained a null value; the metadata for this field specifies that nulls are illegal.
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:567)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:505)
        at org.apache.openjpa.kernel.StateManagerImpl.preFlush(StateManagerImpl.java:3018)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlushPC(SingleFieldManager.java:808)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlushPCs(SingleFieldManager.java:762)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:656)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:589)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldManager.java:505)
        at org.apache.openjpa.kernel.StateManagerImpl.preFlush(StateManagerImpl.java:3018)
        at org.apache.openjpa.kernel.PDirtyState.beforeFlush(PDirtyState.java:39)
        at org.apache.openjpa.kernel.StateManagerImpl.beforeFlush(StateManagerImpl.java:1034)
        at org.apache.openjpa.kernel.BrokerImpl.flush(BrokerImpl.java:2122)
        at org.apache.openjpa.kernel.BrokerImpl.flushSafe(BrokerImpl.java:2082)
        at org.apache.openjpa.kernel.BrokerImpl.beforeCompletion(BrokerImpl.java:2000)
        at org.apache.openjpa.kernel.LocalManagedRuntime.commit(LocalManagedRuntime.java:81)
        at org.apache.openjpa.kernel.BrokerImpl.commit(BrokerImpl.java:1524)
        at org.apache.openjpa.kernel.DelegatingBroker.commit(DelegatingBroker.java:933)
        at org.apache.openjpa.persistence.EntityManagerImpl.commit(EntityManagerImpl.java:570)
        at org.bbop.termgenie.ontology.CommitHistoryStoreImpl.add(CommitHistoryStoreImpl.java:67)
        ... 45 more
[HP INFO] 2016-12-05 03:03:04 (ReloadingOntologyLoader:56) Scheduled Event - Start reloading ontologies
[HP INFO] 2016-12-05 03:03:04 (GitTool:223) Start git pull for URL: https://github.com/obophenotype/human-phenotype-ontology.git

[nathandunn]

Caused by: <openjpa-2.2.2-r422266:1468616 fatal user error> org.apache.openjpa.persistence.InvalidStateException: The field "email" of instance "org.bbop.termgenie.ontology.entities.CommitHistoryItem@3cd8f045" contained a null value; the metadata for this field specifies that nulls are illegal.

I think we just set optional to "true", but I'm not sure of the side-effects:

    /**
     * @return the email
     */
    @Column(length=1023) // increase default length from 255
    @Basic(optional=false)
    public String getEmail() {
        return email;
    }

    /**
     * @param email the email to set
     */
    public void setEmail(String email) {
        this.email = email;
    }

@kltm and @cmungall Any knowledge of the backing database?

[nathandunn]

@kltm @cmungall I'm happy to make this one-line change (changing optional=true). My only worry is that the back-end has a null constraint, but maybe this just goes into the SVN code (in which case it would not matter). However, I don't see PostgreSQL or MySQL running on it.

Conversely, I could just fudge something in there like githubcommitter@github.com, etc. Let me know what makes the most sense.

[kltm]

I didn't know a database was back there--I always figured he just had structures in memory.

I'm not sure where email is in the loop. We had email-md5s taken for auth, but then maybe he was taking the email addresses returned from Persona and using them for some other important part of the process. If that's the case, we'll need to find a source of email addresses (possibly the curator TSV).

The first thing then would to trace what email addresses are being used for.

[cmungall]

uses either sqlite or hsql

[nathandunn]

@cmungall @kltm Thanks. This was my fear. Looks like it uses hsql on further inspection. Actually, this is kind of moot, as going from not-null to null is pretty straightforward (unlike the other way).

More importantly: is this supposed to get email users about commits or anything else?

If not, I can stub something in there, or just remove the functionality. If so, I think a better solution, since we are using github is that I can grab the github email and assign it. Adding more users.yaml stuff would be superfluous since we can already get that data.

[kltm]

I would hope (and believe--Heiko liked to separate out functionality where possible too) that it's not trying to do email stuff on its own. It should hopefully be producing files for the pipeline to inspect and warn about.

Given all this. if we still have the changes by person captured, it might not be a problem to just substitute a generic email address in there if it requires something, as long as it doesn't leak out.

[nathandunn]

@kltm I was thinking of putting in a generic email address as well. That is why I was wondering if it gets used for something else by TermeGenie.

Would @mcourtot or @cmungall or @dosumis know? Otherwise I'll patch this fix in momentarily.

[kltm]

Reopened for completion of testing--accidentally closed from merge commit message.

[nathandunn]

restart is starting

[nathandunn]

should be back up in about 20 minutes

[nathandunn]

@dosumis ready for review.

[dosumis]

Same error,

[nathandunn]

Okay . . same error because it was incorrectly setting the email.

Caused by: <openjpa-2.2.2-r422266:1468616 fatal user error> org.apache.openjpa.p
ersistence.InvalidStateException: The field "email" of instance "org.bbop.termge
nie.ontology.entities.CommitHistoryItem@947e3a4" contained a null value; the met
adata for this field specifies that nulls are illegal.
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldMana
ger.java:567)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFieldMana
ger.java:505)
        at org.apache.openjpa.kernel.StateManagerImpl.preFlush(StateManagerImpl.
java:3018)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlushPC(SingleFieldMa
nager.java:808)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlushPCs(SingleFieldM
anager.java:762)
        at org.apache.openjpa.kernel.SingleFieldManager.preFlush(SingleFie

[nathandunn]

Will remove the constraint on email.

[nathandunn]

Try it again. I removed one of the constraints.

Nathan

On Dec 5, 2016, at 6:31 PM, David Osumi-Sutherland notifications@github.com wrote:

Same error,

https://cloud.githubusercontent.com/assets/112839/20910860/14b4c062-bb5c-11e6-847b-64993407434a.png — You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/geneontology/termgenie/issues/105#issuecomment-265043270, or mute the thread https://github.com/notifications/unsubscribe-auth/AAt2qnkNwkPon8aeLLaxVLakJxdTo02tks5rFMkBgaJpZM4LEGTV.

[mcourtot]

AFAIK, it uses the email address to send notification to submitter. I dont think it uses the committer email to do anything. @dosumis, @ukemi - do you remember getting notifications from TG when you commit terms?

[dosumis]

Now failing earlier:

On pressing "Verify Input", nothing happened. Coming back a short while later I got the message: Could not verify session on server, please reload page.

Feels like you need a test case you can work with directly.

I'm trying to add:

The two terms are:

• mitochondrial calcium release
• positive regulation of presynaptic cytosolic calcium concentration

[dosumis]

Scratch that. Tried 2 more times and finally got it to work. May have been something to do with being confused about my login status. Perhaps something to down to memory of session by my browser across restarts?

[dosumis]

But now getting similar errors when I try to accept new terms via TermGenie Review:

2016-12-06 10:09:55 Could not commit terms. Error: jsonrpc error[-32000] : Caused by java.lang.NullPointerException at javax.mail.internet.InternetAddress.parse(InternetAddress.java:679) at javax.mail.internet.InternetAddress.parse(InternetAddress.java:638) at javax.mail.internet.InternetAddress.(InternetAddress.java:111) at org.apache.commons.mail.Email.createInternetAddress(Email.java:578) at org.apache.commons.mail.Email.addTo(Email.java:727) at org.apache.commons.mail.Email.addTo(Email.java:710) at org.apache.commons.mail.Email.addTo(Email.java:689) at org.bbop.termgenie.mail.SimpleMailHandler.sendEmail(SimpleMailHandler.java:38) at org.bbop.termgenie.mail.SimpleMailHandler.sendEmail(SimpleMailHandler.java:59) at org.bbop.termgenie.mail.review.DefaultReviewMailHandler.handleReviewMail(DefaultReviewMailHandler.java:106) at org.bbop.termgenie.ontology.OntologyCommitReviewPipeline$CommittingNameProviderTask.run(OntologyCommitReviewPipeline.java:302) at org.bbop.termgenie.ontology.OntologyCommitReviewPipeline$CommittingNameProviderTask.run(OntologyCommitReviewPipeline.java:247) at org.bbop.termgenie.core.management.GenericTaskManager.runManagedTask(GenericTaskManager.java:295) at org.bbop.termgenie.ontology.OntologyCommitReviewPipeline.commitInternal(OntologyCommitReviewPipeline.java:236) at org.bbop.termgenie.ontology.OntologyCommitReviewPipeline.commitInternal(OntologyCommitReviewPipeline.java:179) at org.bbop.termgenie.ontology.OntologyCommitReviewPipeline.commit(OntologyCommitReviewPipeline.java:134) at org.bbop.termgenie.services.review.TermCommitReviewServiceImpl$CommitTask.run(TermCommitReviewServiceImpl.java:424) at org.bbop.termgenie.services.review.TermCommitReviewServiceImpl$CommitTask.run(TermCommitReviewServiceImpl.java:383) at org.bbop.termgenie.core.management.GenericTaskManager.runManagedTask(GenericTaskManager.java:295) at org.bbop.termgenie.services.review.TermCommitReviewServiceImpl.commit(TermCommitReviewServiceImpl.java:371) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.json.rpc.server.InjectingJsonRpcExecutor.executeMethod(InjectingJsonRpcExecutor.java:264) at org.json.rpc.server.InjectingJsonRpcExecutor.execute(InjectingJsonRpcExecutor.java:171) at org.bbop.termgenie.servlets.TermGenieJsonRPCServlet.doPost(TermGenieJsonRPCServlet.java:43) at javax.servlet.http.HttpServlet.service(HttpServlet.java:648) at javax.servlet.http.HttpServlet.service(HttpServlet.java:729) at com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:287) at com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:277) at com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:182) at com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91) at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85) at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:119) at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:133) at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:130) at com.google.inject.servlet.GuiceFilter$Context.call(GuiceFilter.java:203) at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:130) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215) at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) at org.eclipse.jetty.server.Server.handle(Server.java:499) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) at java.lang.Thread.run(Thread.java:745)

[dosumis]

Update: SVN logs show that the commit worked, even though the error message says otherwise. Tried on a different browser in case the problem was some flakiness caused by local caching of session cookie. Same result: commit works fine even though exception suggests otherwise.

[ukemi]

As best I can remember, I think we only got emails if we ticked the option box at the bottom of the submission form and we were the submitter.

We got emails for both the submission and after the term had been reviewed and approved.

[ukemi]

As a test, I just tired to commit the term requested by Rob. I got the same error message, however when I reload the reviewer's page, the request is no longer there.

The build-GO job7380 seems fine and the term is in a newly updated version of the ontology.

[kltm]

@ukemi Just to clarify, AFAYCT, the ontology produced by TG looks fine, it's just the error during the attempt?

[ukemi]

Yup. When I check Jenkins and the ontology, it all looks good.

[ukemi]

I got the same nullpointer exception as above when I tried to do the commit.

[nathandunn]

@mcourtot @ukemi @dosumis Its choking on the lack of email. If this is important I can probably figure out a way to add it back, though my preference is just to make sure it never tries to send the email if everything else is working.

Let me know what you think.

[mcourtot]

Removing email sounds ok to me.

[ukemi]

It sounds ok to me too. All I ever used them for was a sanity check to go back and be sure I had requested the term. It is interesting that it is choking on the 'reviewed' email, but didn't seem to choke on the 'request' email. Or maybe it is choking on the request email, but it is just hidden in the background somewhere?

[nathandunn]

@mcourtot @ukemi @dosumis K. It should stop trying to send email and thus not throw an error due to email. Please re-open if it is still causing a problem (should be about 20 minutes). Apologies in advance for the hacky nature of all of this.

[mcourtot]

Hacky and working is way better than error throwing ;) Thanks for fixing.