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_COMMANDE" = 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      (Webobjects-dev@lists.apple.com)
> Help/Unsubscribe/Update your Subscription:
> https://lists.apple.com/mailman/options/webobjects-dev/chill%40global-village.net
> 
> This email sent to ch...@global-village.net

-- 
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      (Webobjects-dev@lists.apple.com)
Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/webobjects-dev/archive%40mail-archive.com

This email sent to arch...@mail-archive.com

Reply via email to