So does that mean that the logging works now? That would be a good outcome in
itself :)
> Before I deleted the log file, I noticed an entry that said something about
> not properly closing the JDBC something-R-other. But it has not re-appeared.
> This is curious because I had theorized that the weirdo Exception was from a
> cached INSERT that was erroneously re-submitted to MySQL.
Tomcat 6 and 7 have this cool functionality detecting resource leaks during app
undeploy. It is absolutely important to clean up all those if you are doing hot
redeploys (swapping apps without restarting Tomcat), or otherwise Tomcat will
crash with OutOfMemory at some point. If you restart Tomcat every time, it is
less important, but still a good practice never the less.
As far as Cayenne is concerned, it needs to shut down the connection pool if
Cayenne started it (i.e. if it is not JNDI), shut down EventManager threads,
etc. WebApplicationContextFilter in 3.0.1 does all this in 'destroy' method:
public void destroy() {
Configuration config = Configuration.getSharedConfiguration();
if (config != null) {
config.shutdown();
}
}
But there is a chance that we overlooked proper shutdown hooks in certain
configurations. So if you get those messages again, please let us know here or
open a Jira with details.
Thanks,
Andrus
On Feb 8, 2012, at 2:03 AM, Joe Baldwin wrote:
> Hey Andrus,
>
> Did you ever see the Twilight Zone? Well get ready for this one.
>
> 1. It took me a while to figure out out to get the logging running, and it
> turns out the the webhost already has it in the tomcat path (but it is sort
> of hidden, and they don't, of course, tell you anything about it).
> 2. So I found their log4j.properties file and inserted
> "log4j.logger.org.apache.cayenne.access.QueryLogger=DEBUG" (I hope this is
> what you were thinking of)
> 3. So then I deleted the logfile and restart tomcat
> 4. Rod Serling moment: when I tried to add the Product entity - for the first
> time it did not fail
> - detail: it added the Product, there was no Exception
> - I verified the Product by listing all of my products
>
> So, is this 1. Insane, or 2. totally Insane?
>
> NOTE:
> Before I deleted the log file, I noticed an entry that said something about
> not properly closing the JDBC something-R-other. But it has not re-appeared.
> This is curious because I had theorized that the weirdo Exception was from a
> cached INSERT that was erroneously re-submitted to MySQL.
>
> So, I am voting for "totally insane". If you have any ideas I would LOVE to
> hear them - and would like to know what to do. :) Am I going to have to run
> the app in debug mode to get it to work?
>
> Thanks,
> Joe
>
>
>
>
>
>
>
> On Feb 7, 2012, at 2:28 PM, Andrus Adamchik wrote:
>
>> The simplest thing you can do is add log4J jar to your app, and add this
>> somewhere on app startup (e.g. a filter or servlet init method, etc) :
>>
>> BasicConfigurator.configure();
>>
>> To fine-tune logging you may switch to PropertyConfigurator. But start with
>> BasicConfigurator - it should log everything and give you an idea what's
>> going on.
>>
>> Andrus
>>
>> On Feb 7, 2012, at 9:07 PM, Joe Baldwin wrote:
>>> I would do it, if I understood it. However, I tried to tackle Cayenne
>>> logging about a year ago and could never figure it out. I couldn't even
>>> figure out how to turn it off. It just continued to perform the default
>>> behavior.
>>>
>>> If you give me the exact commands and tell me exactly where to place those
>>> commands, I will follow your directions.
>>>
>>>
>>> On Feb 7, 2012, at 1:00 PM, Andrus Adamchik wrote:
>>>
>>>> Can you enable Cayenne SQL logging? You'll see all the SQL executed prior
>>>> to the exception.
>>>>
>>>> http://cayenne.apache.org/doc30/configuring-logging.html
>>>>
>>>>
>>>> On Feb 7, 2012, at 8:49 PM, Joe Baldwin wrote:
>>>>
>>>>> Michael,
>>>>>
>>>>> I have new info that makes this problem look even screwier. (Please
>>>>> refer to the error msgs below).
>>>>>
>>>>> So, you might say: "so what, ... this looks like the same error". Yes,
>>>>> it does! However, I just got this error after I restarted tomcat and
>>>>> tried to login to my app. There is ABSOLUTELY no code that attempts to
>>>>> add/update a Product entity during a login.
>>>>>
>>>>> Is it possible, that there is a cached operation that is attempting to be
>>>>> committed? (Sort of like a printer trying to print a job that you have
>>>>> already deleted.)
>>>>>
>>>>> I have never heard of a DBMS/JDBC-lib/ORM attempting to do this, but then
>>>>> again, I do not have control over the server and the techsupport dudes
>>>>> sound like they are very inexeprienced.
>>>>>
>>>>> Joe
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> Stacktrace:
>>>>>
>>>>> org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:510)
>>>>>
>>>>> org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:419)
>>>>> org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
>>>>> org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
>>>>> javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
>>>>>
>>>>> org.apache.cayenne.conf.WebApplicationContextFilter.doFilter(WebApplicationContextFilter.java:93)
>>>>>
>>>>> root cause
>>>>>
>>>>> org.apache.cayenne.CayenneRuntimeException: [v.3.0.1 Aug 25 2010
>>>>> 19:42:04] Commit Exception
>>>>>
>>>>> org.apache.cayenne.access.DataContext.flushToParent(DataContext.java:1134)
>>>>>
>>>>> org.apache.cayenne.access.DataContext.commitChanges(DataContext.java:1045)
>>>>> cms.SessionLogger.log(Unknown Source)
>>>>> cms.SessionLogger.log(Unknown Source)
>>>>>
>>>>> org.apache.jsp.staff.admin.main.AdminLoginVerify_jsp._jspService(AdminLoginVerify_jsp.java:85)
>>>>> org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
>>>>> javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
>>>>>
>>>>> org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
>>>>> org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
>>>>> org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
>>>>> javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
>>>>>
>>>>> org.apache.cayenne.conf.WebApplicationContextFilter.doFilter(WebApplicationContextFilter.java:93)
>>>>>
>>>>> root cause
>>>>>
>>>>> com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
>>>>> Cannot add or update a child row: a foreign key constraint fails
>>>>> (`eagle1_om28`.`product`, CONSTRAINT `product_ibfk_2` FOREIGN KEY
>>>>> (`packageTypeOid`) REFERENCES `packagetype` (`oid`))
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On Feb 7, 2012, at 11:48 AM, Michael Gentry wrote:
>>>>>
>>>>>> Hi Bryan,
>>>>>>
>>>>>> I can confirm that the commit order varies. We were seeing the issue
>>>>>> on the same environment, though. When the AshwoodEntitySorter built
>>>>>> the object graph, it would vary from run-to-run. Once built, it is
>>>>>> cached. If it happens to build a proper order, you are good to go at
>>>>>> least until you restart. For our particular issue, we had a deep
>>>>>> object graph cycle that didn't throw any exceptions. The
>>>>>> AshwoodEntitySorter doesn't work so well with cycles. Once we removed
>>>>>> that relationship, the problem went away.
>>>>>>
>>>>>> mrg
>>>>>>
>>>>>>
>>>>>> On Mon, Feb 6, 2012 at 7:18 AM, Bryan Lewis <[email protected]>
>>>>>> wrote:
>>>>>>> This error reminds me of something we see in our shop. If multiple
>>>>>>> related
>>>>>>> entities are being committed together, Cayenne can sometimes commit them
>>>>>>> out of order which can cause FK constraint violations. The commit order
>>>>>>> seems to be indeterminate; it can work as expected on a dev machine and
>>>>>>> fail in production.
>>>>>>>
>>>>>>> Look at the SQL issued just before the error. On one server you might
>>>>>>> see
>>>>>>> the packagetype being inserted before the product, but the other way
>>>>>>> around
>>>>>>> on the other server. If this is the problem, the fix is to subclass the
>>>>>>> AshwoodEntitySorter as has been discussed a couple of times in the list.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> On Sun, Feb 5, 2012 at 6:48 PM, Joe Baldwin <[email protected]>
>>>>>>> wrote:
>>>>>>>
>>>>>>>>
>>>>>>>> Here is the current error (which is really odd because it is working
>>>>>>>> just
>>>>>>>> fine on my dev server)
>>>>>>>>
>>>>>>>> com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
>>>>>>>> Cannot add or update a child row: a foreign key constraint fails
>>>>>>>> (`eagle1_om28`.`product`, CONSTRAINT `product_ibfk_2` FOREIGN KEY
>>>>>>>> (`packageTypeOid`) REFERENCES `packagetype` (`oid`))
>>>>>>>>
>>>>>
>>>>
>>>
>>>
>>
>
>
