Re: strange behavior with saveChanges
Re: strange behavior with saveChanges
- Subject: Re: strange behavior with saveChanges
- From: Chuck Hill <email@hidden>
- Date: Wed, 10 Jul 2013 12:29:12 -0700
The best thing to do is to cause a deadlock and then get a thread dump with
sudo jstack -F <process ID>
That should make it much faster to track down.
Chuck
On 2013-07-10, at 12:23 PM, Jérémy DE ROYER wrote:
> Hi all,
>
> Following a case that hang my application which blocks all transactions until we restart. I just managed to reproduce the case study below that hangs my application too.
>
> Case : I have to update objects outside the user request/response loop.
>
> Code A
> ===
>
> I use an action inside a component (live process) : everything works great.
>
> public WOComponent myAction() {
>
> EOEditingContext _localContext = new EOEditingContext();
> _localContext.setUndoManager(null);
> _localContext.lock();
>
> EOCompany currentCompany;
>
> NSArray<EOEnterpriseObject> _localCompanies = EOCompany.fetchEOCompanies(_localContext,
> new EOKeyValueQualifier(EOCompany.CONTACT_KEY, EOQualifier.QualifierOperatorEqual, null),
> new NSArray<EOSortOrdering>(new EOSortOrdering(EOCompany.TITLE_KEY, EOSortOrdering.CompareAscending)));
>
> for (int i=0 ; i<_localObjects.count() ; i++)
> {
> currentCompany = _localCompanies.objectAtIndex(i);
>
> if (currentCompany.headquarter() != null)
> {
> currentCompany.setContactRelationship(currentCompany.headquarter().contact());
> }
>
> try {
> log.info("start saveChanges");
> _localContext.saveChanges();
> log.info("end saveChanges");
> }
> catch (Exception e) {
>
> e.printStackTrace();
>
> _localContext.revert();
> }
> }
> }
>
> }
> catch (Exception e) {
>
> e.printStackTrace();
> }
> finally {
>
> _localContext.unlock();
> _localContext.dispose();
> }
> }
>
> (SQL log below)
>
> 2013-07-10 20:53:03,462 INFO [IndeXysMatchingPageParametres] - <start saveChanges>
> [...]
> [2013-7-10 20:53:3 CEST] <WorkerThread10> 0 row(s) processed
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Commit Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Begin Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT t0."ADRESSE", t0."ADRESSE_2", t0."CODE_ACTION", t0."CODE_POSTAL", t0."DATE_CLOTURE", t0."DATE_CREATION", t0."DATE_DEBUT", t0."DATE_DERNIERE_MODIFICATION", t0."DATE_DERNIERE_MODIFICATION_ACTEUR", t0."DATE_FIN", t0."DATE_FIN_REPETITION", t0."DUREE_CONSTATEE", t0."EST_INTERNE", t0."EST_PRIVE", t0."EST_TERMINE", t0."ID", t0."ID_ACTEUR", t0."ID_ACTEUR_CLOTURE", t0."ID_AUTEUR", t0."ID_AUTEUR_DERNIERE_MODIFICATION", t0."ID_CAMPAGNE", t0."ID_COMPTE_RENDU_CLOTURE", t0."ID_CONTACT", t0."ID_ENTREE_ORGANISATEUR", t0."ID_ENTREE_ORIGINALE_REPETITION", t0."ID_ENTREPRISE", t0."ID_EVENEMENT", t0."ID_RESSOURCE", t0."IS_VALID", t0."PRIORITE", t0."REFERENCE", t0."STATUT", t0."TITRE", t0."TYPE_ACTIVITE", t0."VILLE" FROM "INDEXYS_GESTION_ACTIVITE_ABSTRACT_ACTION" t0 WHERE t0."ID_CONTACT" = 1000034" withBindings: >
> [2013-7-10 20:53:3 CEST] <WorkerThread10> 0 row(s) processed
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Commit Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Begin Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT t0."CODE_NOTE_DE_FRAIS", t0."DATE_CREATION", t0."DATE_DECISION", t0."DATE_DERNIERE_MODIFICATION", t0."DATE_NOTE_DE_FRAIS", t0."EST_SOLDEE", t0."ID", t0."ID_ACTEUR", t0."ID_ACTEUR_SOLDE", t0."ID_ACTION", t0."ID_AFFAIRE", t0."ID_AUTEUR", t0."ID_AUTEUR_DECISION", t0."ID_AUTEUR_DERNIERE_MODIFICATION", t0."ID_CAMPAGNE", t0."ID_CLASSE_NOTE_DE_FRAIS", t0."ID_COMMANDE", t0."ID_CONTACT", t0."ID_DEVIS", t0."ID_ENTREPRISE", t0."ID_EVENEMENT", t0."ID_FACTURE", t0."ID_FORFAIT_NOTE_DE_FRAIS", t0."ID_OPPORTUNITE", t0."ID_ORGANISATION", t0."ID_PARTITION", t0."ID_PROJET", t0."ID_TYPE", t0."IS_VALID", t0."MONTANT_HT", t0."MONTANT_TTC", t0."NOMBRE_KILOMETRE", t0."NOMBRE_PERSONNE", t0."REFERENCE", t0."STATUT", t0."TITRE", t0."TYPE_DECISION" FROM "INDEXYS_CRM_GESTION_ACTIVITE_NOTE_DE_FRAIS" t0 WHERE t0."ID_ENTREPRISE" = 1000034" withBindings: >
> [2013-7-10 20:53:3 CEST] <WorkerThread10> 0 row(s) processed
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Commit Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Begin Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT t0."EST_INACTIVE", t0."ID", t0."ID_ABONNE", t0."ID_ADRESSE_EMAIL", t0."ID_CAMPAGNE", t0."ID_CONTACT", t0."ID_DERNIER_ENVOI", t0."ID_DERNIER_ENVOI_ACCESSED", t0."ID_DERNIER_ENVOI_ACCESSED_SINCE_LAST_RESET", t0."ID_DERNIER_ENVOI_DOWNLOADED", t0."ID_DERNIER_ENVOI_DOWNLOADED_SINCE_LAST_RESET", t0."ID_DERNIER_ENVOI_READ", t0."ID_DERNIER_ENVOI_READ_SINCE_LAST_RESET", t0."ID_DERNIER_ENVOI_SINCE_LAST_RESET", t0."ID_DERNIER_ENVOI_UNSUBSCRIBE", t0."ID_DERNIER_ENVOI_UNSUBSCRIBE_SINCE_LAST_RESET", t0."ID_DERNIER_ERREUR", t0."ID_DERNIER_ERREUR_SINCE_LAST_RESET", t0."ID_ENTREPRISE", t0."ID_UTILISATEUR", t0."LAST_ACCESSED", t0."LAST_DOWNLOADED", t0."LAST_READ", t0."LAST_UNSUBSCRIBE", t0."NOMBRE_CONSULTATION", t0."NOMBRE_CONSULTATION_SINCE_LAST_RESET", t0."NOMBRE_LIEN_INTERNET", t0."NOMBRE_LIEN_INTERNET_SINCE_LAST_RESET" FROM "INDEXYS_EMAILING_PARTICIPATION" t0 WHERE t0."ID_CONTACT" = 1000034" withBindings: >
> [2013-7-10 20:53:3 CEST] <WorkerThread10> 0 row(s) processed
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Commit Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Begin Internal Transaction
> [2013-7-10 20:53:3 CEST] <WorkerThread10> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "UPDATE "INDEXYS_MATCHING_COMMANDE_CLIENT" SET "ID_CONTACT" = 1000034, "ID_ENTREPRISE_CLIENT" = 1000027 WHERE ("ID" = 1000526 AND "CODE_COMMANDE" = 'MON-CODE' AND "CODE_CONFIRMATION_PAIEMENT" = 830 AND "CODE_PARRAINAGE" is NULL AND "CODE_PROMOTION" is NULL AND "DATE_ANNULATION" is NULL AND "DATE_COMMANDE" = TIMESTAMP '2013-03-21 18:31:03.000' AND "DATE_CONFIRMATION_FACTURATION" = TIMESTAMP '2013-03-21 18:59:23.000' AND "DATE_CONFIRMATION_PAIEMENT" = TIMESTAMP '2013-03-21 18:52:13.000' AND "DATE_CREATION" = TIMESTAMP '2013-03-21 18:31:02.000' AND "DATE_DEBUT" is NULL AND "DATE_DERNIERE_FACTURE_CLI" = TIMESTAMP '2013-03-21 18:59:23.000' AND "DATE_DERNIERE_FACTURE_FOU" is NULL AND "DATE_DERNIERE_MODIFICATION" = TIMESTAMP '2013-03-21 18:59:18.000' AND "DATE_FIN" is NULL AND "DATE_SOLDE" = TIMESTAMP '2013-03-21 18:52:13.000' AND "DATE_VALIDATION" = TIMESTAMP '2013-03-21 18:50:58.000' AND "DEVISE" = '€' AND "EST_SOLDEE" is NULL AND "ETAT_COMMANDE" is NULL AND "ID_ACTEUR" is NULL AND "ID_AFFAIRE" is NULL AND "ID_AUTEUR" = 1000215 AND "ID_AUTEUR_ANNULATION" = 1000002 AND "ID_AUTEUR_COMMANDE" = 1000215 AND "ID_AUTEUR_CONFIRMATION_FACTURATION" is NULL AND "ID_AUTEUR_CONFIRMATION_PAIEMENT" is NULL AND "ID_AUTEUR_DERNIERE_MODIFICATION" = 1000002 AND "ID_AUTEUR_SOLDE" is NULL AND "ID_AUTEUR_VALIDATION" = 1000002 AND "ID_AUTORISATION" is NULL AND "ID_CAMPAGNE" is NULL AND "ID_CLIENT" = 1000215 AND "ID_CLIENT_PARRAIN" is NULL AND "ID_CONTACT" is NULL AND "ID_DEVIS" is NULL AND "ID_ENTREPRISE_CLIENT" is NULL AND "ID_EVENEMENT" = 1000044 AND "ID_OPPORTUNITE" is NULL AND "MODE_PAIEMENT" = 2 AND "POINTS_AJOUTES_FILLEUL" is NULL AND "POINTS_AJOUTES_PARRAIN" is NULL AND "POINTS_CONSOMMES_PARRAIN" is NULL AND "PRIX_AVEC_TVA" = 0 AND "REFERENCE" = 'da615844-3dd0-4a51-8201-4d7fd217548e' AND "REFERENCE_AFFILIE" is NULL AND "REFERENCE_PROCESS" is NULL AND "STATUT" is NULL AND "TITRE" is NULL AND "TYPE_COMMAND
E" = 1 AND "TYPE_PAIEMENT" = 2)" withBindings: >
> [2013-7-10 20:53:3 CEST] <WorkerThread10> === Commit Internal Transaction
> 2013-07-10 20:53:03,462 INFO [IndeXysMatchingPageParametres] - <end saveChanges>
>
>
> Code B
> ===
>
> I use the same action but include my process inside a thread (used to display a AjaxProgessBar), the process never save the changes and my application hangs… and the SQL log show it never updates
>
> public WOComponent myAction() {
>
> Thread _localThread = new Thread(new Runnable()
> {
> public void run() {
>
> EOEditingContext _localContext = new EOEditingContext();
> _localContext.setUndoManager(null);
> _localContext.lock();
>
> EOCompany currentCompany;
>
> NSArray<EOEnterpriseObject> _localCompanies = EOCompany.fetchEOObjects(_localContext,
> new EOKeyValueQualifier(EOCompany.CONTACT_KEY, EOQualifier.QualifierOperatorEqual, null),
> new NSArray<EOSortOrdering>(new EOSortOrdering(EOCompany.TITLE_KEY, EOSortOrdering.CompareAscending)));
>
> for (int i=0 ; i<_localObjects.count() ; i++)
> {
> currentCompany = _localCompanies.objectAtIndex(i);
>
> currentCompany.setContactRelationship(_localCompanies.headquarter().contact());
>
> try {
> log.info("start saveChanges");
> _localContext.saveChanges();
> log.info("end saveChanges");
> }
> catch (Exception e) {
>
> e.printStackTrace();
>
> _localContext.revert();
> }
> }
> }
>
> }
> catch (Exception e) {
>
> e.printStackTrace();
> }
> finally {
>
> _localContext.unlock();
> _localContext.dispose();
> }
> }
> });
>
> _localThread.start();
>
> return null;
> }
>
> 2013-07-10 20:53:03,462 INFO [IndeXysMatchingPageParametres] - <start saveChanges>
> [...]
> [2013-7-10 20:58:3 CEST] <Thread-18> 0 row(s) processed
> [2013-7-10 20:58:3 CEST] <Thread-18> === Commit Internal Transaction
> [2013-7-10 20:58:3 CEST] <Thread-18> === Begin Internal Transaction
> [2013-7-10 20:58:3 CEST] <Thread-18> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT t0."DATE_CREATION", t0."DATE_DERNIERE_MODIFICATION", t0."DATE_INSCRIPTION", t0."EMAIL_INSCRIPTION_HAS_BEEN_SENT", t0."ID", t0."ID_ACTEUR", t0."ID_AUTEUR", t0."ID_AUTEUR_DERNIERE_MODIFICATION", t0."ID_COMMANDE_CLIENT", t0."ID_CONTACT", t0."ID_ENTREPRISE", t0."ID_EVENEMENT", t0."ID_PARTITION", t0."ID_PERIODE_PRESENCE", t0."ID_PROFIL_PROPOSE", t0."ID_PROFIL_INSCRIPTION", t0."ID_PROFIL_INSCRIPTION_TARIF", t0."ID_PROFIL_PARTICIPATION", t0."ID_PROFIL_RECHERCHE", t0."ID_TYPE", t0."ID_UTILISATEUR", t0."IS_VALID", t0."LAST_LOGIN", t0."LAST_NOTIFICATION_CONTACTS", t0."LAST_NOTIFICATION_INSCRIPTIONS", t0."LAST_UPDATE_JE_PROPOSE", t0."LAST_UPDATE_JE_RECHERCHE", t0."LAST_UPDATE_JE_SUIS", t0."LAST_UPDATE_VOEUX_EMIS", t0."NOTE", t0."REFERENCE", t0."STATUT" FROM "INDEXYS_MATCHING_PARTICIPATION" t0 WHERE t0."ID_COMMANDE_CLIENT" = 1000509" withBindings: >
> [2013-7-10 20:58:3 CEST] <Thread-18> 1 row(s) processed
> [2013-7-10 20:58:3 CEST] <Thread-18> === Commit Internal Transaction
> [2013-7-10 20:58:3 CEST] <Thread-18> === Begin Internal Transaction
> [2013-7-10 20:58:3 CEST] <Thread-18> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT t0."CREDIT_TTC", t0."DATE_CREATION", t0."DATE_DERNIERE_MODIFICATION", t0."DATE_REGLEMENT", t0."DEBIT_TTC", t0."DEVISE", t0."ID", t0."ID_AUTEUR", t0."ID_AUTEUR_DERNIERE_MODIFICATION", t0."ID_CLIENT", t0."ID_COMMANDE", t0."ID_CONTACT", t0."ID_ENTREPRISE", t0."ID_FACTURE", t0."ID_LETTRAGE", t0."ID_MODE_REGLEMENT", t0."ID_ORGANISATION", t0."ID_PARTITION", t0."REFERENCE" FROM "INDEXYS_GESTION_COMMERCIALE_REGLEMENT" t0 WHERE t0."ID_COMMANDE" = 1000509" withBindings: >
> [2013-7-10 20:58:3 CEST] <Thread-18> 0 row(s) processed
> [2013-7-10 20:58:3 CEST] <Thread-18> === Commit Internal Transaction
> [2013-7-10 20:58:3 CEST] <Thread-18> === Begin Internal Transaction
> [2013-7-10 20:58:3 CEST] <Thread-18> evaluateExpression: <com.webobjects.jdbcadaptor.FrontbasePlugIn$FrontbaseExpression: "SELECT t0."CODE_NOTE_DE_FRAIS", t0."DATE_CREATION", t0."DATE_DECISION", t0."DATE_DERNIERE_MODIFICATION", t0."DATE_NOTE_DE_FRAIS", t0."EST_SOLDEE", t0."ID", t0."ID_ACTEUR", t0."ID_ACTEUR_SOLDE", t0."ID_ACTION", t0."ID_AFFAIRE", t0."ID_AUTEUR", t0."ID_AUTEUR_DECISION", t0."ID_AUTEUR_DERNIERE_MODIFICATION", t0."ID_CAMPAGNE", t0."ID_CLASSE_NOTE_DE_FRAIS", t0."ID_COMMANDE", t0."ID_CONTACT", t0."ID_DEVIS", t0."ID_ENTREPRISE", t0."ID_EVENEMENT", t0."ID_FACTURE", t0."ID_FORFAIT_NOTE_DE_FRAIS", t0."ID_OPPORTUNITE", t0."ID_ORGANISATION", t0."ID_PARTITION", t0."ID_PROJET", t0."ID_TYPE", t0."IS_VALID", t0."MONTANT_HT", t0."MONTANT_TTC", t0."NOMBRE_KILOMETRE", t0."NOMBRE_PERSONNE", t0."REFERENCE", t0."STATUT", t0."TITRE", t0."TYPE_DECISION" FROM "INDEXYS_CRM_GESTION_ACTIVITE_NOTE_DE_FRAIS" t0 WHERE t0."ID_ENTREPRISE" = 1000509" withBindings: >
> [2013-7-10 20:58:3 CEST] <Thread-18> 0 row(s) processed
> [2013-7-10 20:58:3 CEST] <Thread-18> === Commit Internal Transaction
>
> Code C
> ===
>
> I include a loop that prints each objects that will be updated : works quite great (some few times, my app hangs).
>
> public WOComponent myAction() {
>
> Thread _localThread = new Thread(new Runnable()
> {
> public void run() {
>
> EOEditingContext _localContext = new EOEditingContext();
> _localContext.setUndoManager(null);
> _localContext.lock();
>
> EOCompany currentCompany;
>
> NSArray<EOEnterpriseObject> _localCompanies = EOCompany.fetchEOObjects(_localContext,
> new EOKeyValueQualifier(EOCompany.CONTACT_KEY, EOQualifier.QualifierOperatorEqual, null),
> new NSArray<EOSortOrdering>(new EOSortOrdering(EOCompany.TITLE_KEY, EOSortOrdering.CompareAscending)));
>
> for (int i=0 ; i<_localObjects.count() ; i++)
> {
> currentCompany = _localCompanies.objectAtIndex(i);
>
> currentCompany.setContactRelationship(_localCompanies.headquarter().contact());
>
> try {
> for (int j=0 ; j<_localContext.updatedObjects().count() ; j++) {
> log.info("_localContext.updatedObjects().objectAtIndex(j) >" + _localContext.updatedObjects().objectAtIndex(j));
> }
>
> log.info("start saveChanges");
> _localContext.saveChanges();
> log.info("end saveChanges");
> }
> catch (Exception e) {
>
> e.printStackTrace();
>
> _localContext.revert();
> }
> }
> }
>
> }
> catch (Exception e) {
>
> e.printStackTrace();
> }
> finally {
>
> _localContext.unlock();
> _localContext.dispose();
> }
> }
> });
>
> _localThread.start();
>
> return null;
> }
>
> What's wrong with my code ?
>
>
>
> Thank's for any help, these random deadlocks are very uncomfortable
>
> Jérémy
> _______________________________________________
> Do not post admin requests to the list. They will be ignored.
> Webobjects-dev mailing list (email@hidden)
> Help/Unsubscribe/Update your Subscription:
>
> This email sent to email@hidden
--
Chuck Hill
Executive Managing Partner, VP Development and Technical Services
Practical WebObjects - for developers who want to increase their overall knowledge of WebObjects or who are trying to solve specific problems.
http://www.global-village.net/gvc/practical_webobjects
Global Village Consulting ranks 13th in 2012 in BIV's Top 100 Fastest Growing Companies in B.C!
Global Village Consulting ranks 44th in 25th annual PROFIT 500 ranking of Canada’s Fastest-Growing Companies by PROFIT Magazine!
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden