I'm experiencing what seems to be a deadlock/synch problem with my
DataContexts.
Specs of what I'm running:
Linux / Java 1.4.2_06 / MySql v 4.1.9
Libraries I'm using:
cayenne1.2M2.jar, mysql-connector-java-3.0.11-stable-bin.jar as well as
a couple of unrelated proprietary jar files.
I have the server setup as a standalone app which opens up a
serversocket and just listens. New requests are spawned on a new thread
which takes the requesting socket and a couple of params.
To obtain the data context for each of the Worker Threads, I use the
following code.
**************************************************************************************************
private static DataContext createCayenneDataContext()
{
if (!CONFIG_CREATED)
{
createConfiguration();
}
return Configuration.getSharedConfiguration().getDomain()
.createDataContext();
}
public static void bindTheadDataContext()
{
DataContext.bindThreadDataContext(createCayenneDataContext());
}
public static void createConfiguration()
{
if (!CONFIG_CREATED)
{
FileConfiguration confFile = new FileConfiguration();
confFile.addFilesystemPath("cayenne/");
Configuration.setLoggingLevel(Level.WARN);
Configuration.initializeSharedConfiguration(confFile);
CONFIG_CREATED = true;
}
}
**************************************************************************************************
In the run method of the Worker Threads, the first item called is:
**************************************************************************************************
General_Utils.bindTheadDataContext();
**************************************************************************************************
Any calls in the program to access the DataContext use the
DataContext.getThreadDataContext(). This always works fine, and it
always reports success binding the data context. However, every now and
then (about every 5 days, w/the server prcoessing an average of 200
requests each day.), the server experiences problems with the data context.
New requests are still received, however, in the log files I generate,
something funky is happening. Below is what a normal Worker Thread will
spew out in the log files. Maybe I access the DataContext in an illegal
way, or maybe creating the context isn't advisable for threaded apps?
**************************************************************************************************
DEBUG [Thread-799 02-22 19:22:54] : DataRowStore property
cayenne.DataRowStore.snapshot.expiration = 7200
DEBUG [Thread-799 02-22 19:22:54] : DataRowStore property
cayenne.DataRowStore.snapshot.size = 500
DEBUG [Thread-799 02-22 19:22:54] : DataRowStore property
cayenne.DataRowStore.remote.notify = false
DEBUG [Thread-799 02-22 19:22:54] : DataRowStore property
cayenne.DataRowStore.EventBridge.factory =
org.objectstyle.cayenne.event.JavaGroupsBridgeFactory
INFO [Thread-799 02-22 19:22:54] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:54] : SELECT t0.display_order,
t0.game_category_id, t0.graphics_category_id, t0.id, t0.name,
t0.phonevendor_id, t0.realtone_category_id, t0.ringtone_class FROM
uphonia.phone t0 WHERE t0.id = ? [bind: '155']
INFO [Thread-799 02-22 19:22:54] : === returned 1 row. - took 3 ms.
INFO [Thread-799 02-22 19:22:54] : +++ no commit - transaction
controlled externally.
INFO [Thread-799 02-22 19:22:54] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:54] : SELECT t0.deliveryagent_id,
t0.externalasset_id, t0.nreach_product_id, t0.product_id,
t0.producttype_id, t0.supplier_id FROM uphonia.producttype_product t0
WHERE t0.nreach_product_id = ? [bind: '8784']
INFO [Thread-799 02-22 19:22:54] : === returned 1 row. - took 2 ms.
INFO [Thread-799 02-22 19:22:54] : +++ no commit - transaction
controlled externally.
DEBUG [Thread-799 02-22 19:22:54] : no cached snapshot for ObjectId:
com.smartserv.delivengine.cayenne.Producttype: <id: 4>
INFO [Thread-799 02-22 19:22:54] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:54] : SELECT t0.display_order,
t0.left_num, t0.level, t0.name, t0.parent_id, t0.right_num, t0.id FROM
uphonia.producttype t0 WHERE t0.id = ? [bind: 4]
INFO [Thread-799 02-22 19:22:54] : === returned 1 row. - took 3 ms.
INFO [Thread-799 02-22 19:22:54] : +++ no commit - transaction
controlled externally.
INFO [Thread-799 02-22 19:22:54] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:54] : INSERT INTO uphonia.smsorders
(carrier_id, date, phone_id, pos_id, product_id, statuscode) VALUES (?,
?, ?, ?, ?, ?)
INFO [Thread-799 02-22 19:22:54] : [bind: 23, '2005-02-22
19:22:54.449', 155, '56', 8784, 0]
INFO [Thread-799 02-22 19:22:54] : === updated 1 row.
INFO [Thread-799 02-22 19:22:54] : +++ no commit - transaction
controlled externally.
DEBUG [Thread-799 02-22 19:22:54] : no cached snapshot for ObjectId:
com.smartserv.delivengine.cayenne.GraphicsCategory: <id: 10>
INFO [Thread-799 02-22 19:22:54] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:54] : SELECT t0.depth, t0.filestub,
t0.filetype, t0.format, t0.height, t0.is_cod, t0.is_gcd, t0.is_wml,
t0.maxfilesize, t0.name, t0.purpose, t0.source, t0.width, t0.id FROM
uphonia.graphics_category t0 WHERE t0.id = ? [bind: 10]
INFO [Thread-799 02-22 19:22:54] : === returned 1 row. - took 4 ms.
INFO [Thread-799 02-22 19:22:54] : +++ no commit - transaction
controlled externally.
INFO [Thread-799 02-22 19:22:55] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:55] : SELECT t0.carrier_id,
t0.delivery_method, t0.phone_id, t0.id FROM uphonia.carrier_phone t0
WHERE (t0.carrier_id = ?) AND (t0.phone_id = ?) [bind: '23', '155']
INFO [Thread-799 02-22 19:22:55] : === returned 1 row. - took 3 ms.
INFO [Thread-799 02-22 19:22:55] : +++ no commit - transaction
controlled externally.
INFO [Thread-799 02-22 19:22:55] : --- will run 1 query.
INFO [Thread-799 02-22 19:22:55] : UPDATE uphonia.smsorders SET
statuscode = ? WHERE id = ?
INFO [Thread-799 02-22 19:22:55] : [bind: 1, 31451]
INFO [Thread-799 02-22 19:22:55] : === updated 1 row.
INFO [Thread-799 02-22 19:22:55] : +++ no commit - transaction
controlled externally.
DEBUG [Thread-799 02-22 19:22:55] : postSnapshotsChangeEvent:
[SnapshotEvent] source:
org.objectstyle.cayenne.access.ObjectStor..18565, modified 1 id(s)
DEBUG [Thread-799 02-22 19:22:55] : Failed invocation, removing:
snapshotsChanged
**************************************************************************************************
Cool, and fortunately enough, I get a lot of those. (The more w/out
errors, the better).
However, like I said before, about every five days the server seems to
lock up. Requests are still made, DataContexts are still bound, but
queries to the database don't happen. Below is one example of the
output of one such Worker Thread:
**************************************************************************************************
DEBUG [Thread-802 02-22 19:24:20] : DataRowStore property
cayenne.DataRowStore.snapshot.expiration = 7200
DEBUG [Thread-802 02-22 19:24:20] : DataRowStore property
cayenne.DataRowStore.snapshot.size = 500
DEBUG [Thread-802 02-22 19:24:20] : DataRowStore property
cayenne.DataRowStore.remote.notify = false
DEBUG [Thread-802 02-22 19:24:20] : DataRowStore property
cayenne.DataRowStore.EventBridge.factory =
org.objectstyle.cayenne.event.JavaGroupsBridgeFactory
INFO [Thread-802 02-22 19:24:20] : --- will run 1 query.
INFO [Thread-802 02-22 19:24:20] : SELECT t0.display_order,
t0.game_category_id, t0.graphics_category_id, t0.id, t0.name,
t0.phonevendor_id, t0.realtone_category_id, t0.ringtone_class FROM
uphonia.phone t0 WHERE t0.id = ? [bind: '147']
INFO [Thread-802 02-22 19:24:20] : === returned 1 row. - took 3 ms.
INFO [Thread-802 02-22 19:24:20] : +++ no commit - transaction
controlled externally.
INFO [Thread-802 02-22 19:24:20] : --- will run 1 query.
INFO [Thread-802 02-22 19:24:20] : SELECT t0.deliveryagent_id,
t0.externalasset_id, t0.nreach_product_id, t0.product_id,
t0.producttype_id, t0.supplier_id FROM uphonia.producttype_product t0
WHERE t0.nreach_product_id = ? [bind: '1654']
INFO [Thread-802 02-22 19:24:20] : === returned 1 row. - took 2 ms.
INFO [Thread-802 02-22 19:24:20] : +++ no commit - transaction
controlled externally.
DEBUG [Thread-802 02-22 19:24:20] : no cached snapshot for ObjectId:
com.smartserv.delivengine.cayenne.Producttype: <id: 21>
INFO [Thread-802 02-22 19:24:20] : --- will run 1 query.
INFO [Thread-802 02-22 19:24:20] : SELECT t0.display_order,
t0.left_num, t0.level, t0.name, t0.parent_id, t0.right_num, t0.id FROM
uphonia.producttype t0 WHERE t0.id = ? [bind: 21]
INFO [Thread-802 02-22 19:24:20] : === returned 1 row. - took 2 ms.
INFO [Thread-802 02-22 19:24:20] : +++ no commit - transaction
controlled externally.
DEBUG [Thread-802 02-22 19:24:20] : no cached snapshot for ObjectId:
com.smartserv.delivengine.cayenne.Producttype: <id: 3>
INFO [Thread-802 02-22 19:24:20] : --- will run 1 query.
INFO [Thread-802 02-22 19:24:20] : SELECT t0.display_order,
t0.left_num, t0.level, t0.name, t0.parent_id, t0.right_num, t0.id FROM
uphonia.producttype t0 WHERE t0.id = ? [bind: 3]
INFO [Thread-802 02-22 19:24:20] : === returned 1 row. - took 3 ms.
INFO [Thread-802 02-22 19:24:20] : +++ no commit - transaction
controlled externally.
INFO [Thread-802 02-22 19:24:20] : --- will run 1 query.
INFO [Thread-802 02-22 19:24:20] : INSERT INTO uphonia.smsorders
(carrier_id, date, phone_id, pos_id, product_id, statuscode) VALUES (?,
?, ?, ?, ?, ?)
INFO [Thread-802 02-22 19:24:20] : [bind: 23, '2005-02-22
19:24:20.114', 147, '56', 1654, 0]
**************************************************************************************************
And that's all Thread-802 spits out. I assume Thread-802 is having some
db troubles, as the next thread adds a new database connection, but does
not do anything with it:
**************************************************************************************************
DEBUG [Thread-803 02-22 19:24:54] : DataRowStore property
cayenne.DataRowStore.snapshot.expiration = 7200
DEBUG [Thread-803 02-22 19:24:54] : DataRowStore property
cayenne.DataRowStore.snapshot.size = 500
DEBUG [Thread-803 02-22 19:24:54] : DataRowStore property
cayenne.DataRowStore.remote.notify = false
DEBUG [Thread-803 02-22 19:24:54] : DataRowStore property
cayenne.DataRowStore.EventBridge.factory =
org.objectstyle.cayenne.event.JavaGroupsBridgeFactory
INFO [Thread-803 02-22 19:24:54] : --- will run 1 query.
INFO [Thread-803 02-22 19:24:54] : Opening connection:
jdbc:mysql://lnphldb01/uphonia?autoReconnect=true
Login: deliv_engine
Password: *******
**************************************************************************************************
From there on out, all Worker Threads have issues executing queries:
**************************************************************************************************
DEBUG [Thread-804 02-22 19:25:32] : DataRowStore property
cayenne.DataRowStore.snapshot.expiration = 7200
DEBUG [Thread-804 02-22 19:25:32] : DataRowStore property
cayenne.DataRowStore.snapshot.size = 500
DEBUG [Thread-804 02-22 19:25:32] : DataRowStore property
cayenne.DataRowStore.remote.notify = false
DEBUG [Thread-804 02-22 19:25:32] : DataRowStore property
cayenne.DataRowStore.EventBridge.factory =
org.objectstyle.cayenne.event.JavaGroupsBridgeFactory
INFO [Thread-804 02-22 19:25:32] : --- will run 1 query.
**************************************************************************************************
Any ideas what might be causing this?
I have a similar server that's processed over a million requests using
this same technique, and it never locks up. Admittedly, it is running
the stable version of cayenne (1.1). I'm using the latest version of
cayenne as it has support for autoincrement in MySQL, which is a hellla
nice thing.
I've tried stress testing on my Windows box, to no avail.
Any questions as to how I set up to, remarks, or whatever are certainly
welcome.
The database it connects to is up and chugging along w/out problems. (I
checked out the error logs and there are no errors)
Orion
This archive was generated by hypermail 2.0.0 : Wed Feb 23 2005 - 15:05:59 EST