Building DOM object from multiple threads

[gdev]

My multi threaded application processes and loads records into an ECM repository. For reconcliation purposes , I am trying to build an XML format report with the results of the processing per record, while processing is underway per thread. The method below is called from every thread wvery time its ready to append an element to the DOM with the status.

	public void writeReportLine(Element rptLine) {
		// Write output to report file
		synchronized (XMLReportHandler.class) {
			reportOutput.getDocumentElement().appendChild(rptLine);
		}
	}

After all priocessing completes, the below method is called only once by every thread to write to the File on the file system:

 
	public void writeToReportFile() {
		synchronized (XMLReportHandler.class) {
				try{
				  //write the content into xml file
				  TransformerFactory transformerFactory = TransformerFactory.newInstance();
				  Transformer transformer = transformerFactory.newTransformer();
				  DOMSource source = new DOMSource(reportOutput);
 
				  StreamResult result =  new StreamResult(f);
				  transformer.transform(source, result);
 
				}catch(TransformerConfigurationException e){
					logger.error("** Error getting xml report document object: " + e);
					e.printStackTrace();
				}catch(TransformerException e){
					logger.error("** Error getting xml report document object: " + e);
					e.printStackTrace();
				}
			}
	}

The problem is that when under load, the threads just seem to hang while the transformer.transform(source, result) call keeps getting executed until there is an interrupt of some sort. I was able to examine a section of what was appended and it was status for records that had finished processing very early in the process based on my application logs. Once an interrupt is recieved , it looks like the threads recover.

Any idea whats wrong in here ? Thanks in advance for your advice - I have been stuck trying to figure out where the problem out for days! Now that I know where the problem is , I cant figure out a solution. Looking for multi threading gurus..

[aussiemcgr]

A little bit of Q&A:
Why are you synchronizing the XMLReportHandler class?
Do you fully understand what the synchronized keyword does? (just making sure this was your intention)

[gdev]

I am synchronizing the XMLReportHandler because multiple threads are writing to the same object in memory in the writeReportLine method. Also multiple threads are writing to the same file object on the file system in the writeReportFile method. My understandding is that synchronizing will help make sure that the access to the I al ts is exclusively availble to one thread at a time.
I alos chose to use synchronized because I have a text format report in the same application and it executes this code - works perfectly:

public void writeReportLine(String rptLine) {
// Write output to report file, reportOutput is object of PrintWriter
synchronized (ReportHandler.class) {
reportOutput.println(rptLine);
}
}

Hopefully , this isnt causing a side-effect leading to this. Is that where you are going ?

[aussiemcgr]

To my understanding of synchronization in java, any thread which attempts to access a synchronized block of code will get put into a "holding pattern" (of sorts) until any other threads have cleared the block.
For synchronized statements (which is what you are using), the lock is applied to the object inside the parentheses, and released when the synchronized block finishes. Every other thread which attempts to access the locked object will get placed in the "holding pattern" until the lock is released (even if the other threads are trying to access the object without a synchronized block) and it can continue.

I'm not sure if it will matter, but: are they writing to the same instance of XMLReportHandler? I ask because:

// Synchronizes ALL instances across all threads of the XMLReportHandler class
synchronized (XMLReportHandler.class) {...}
 
// Synchronizes just the reportOutput instance of the XMLReportHandler class across all threads
synchronized (reportOutput) {...}

If you can use the second for your purposes, give it a try and tell me if anything changes.

[gdev]

Thanks for the suggestion. I tried synchronizing on reportOutput - didnt resolve the issue.
On your question if they are writing to the same instance of XMLReportHandler - They are not. Below is the codet hats called from run()

			// create XML report file
			this.xmlReporter = new XMLReportHandler();
			createStatus = this.xmlReporter.createReport(iDir, fileExt, "xml");
			if (createStatus[1].equals("OK")) {
				this.xmlReporter = new XMLReportHandler();
				logger.info("Opening XML report ");
				status = this.xmlReporter.openReport(createStatus[0]);
				this.xmlReporterName = createStatus[0];
				this.xmlReporterNameBase = createStatus[2];
			} else {
				return false;
			}

Here is the complete XMLReportHandler class - hoping this will help:

package com.ibm.p8loader.report;
 
import java.io.File;
 
 
public class XMLReportHandler {
 
	private Logger logger = Logger.getLogger(XMLReportHandler.class);
 
	//private PrintWriter reportOutput;
 
	private Document reportOutput; 
	private File f;
 
	public Document getReportOutput(){
		return reportOutput;
	}
 
	// open report file
	public boolean openReport(String reportFile) {
 
		synchronized (XMLReportHandler.class) {
			boolean succeed = false;
			/*
			 * invoke process to build reportFfile
			 */
			succeed = openIt(reportFile);
			return succeed;
		}
	}
 
	private boolean openIt(String reportFile) {
 
		// try to open the report file
		boolean status = false;
		try {
			f = new File(reportFile);
			if (f.exists()) {
				status = true;
				DocumentBuilderFactory docFactory = DocumentBuilderFactory.newInstance();
				DocumentBuilder docBuilder = docFactory.newDocumentBuilder();
 				reportOutput = docBuilder.parse(f);
 
			} else {
				status = false;
				logger.error("** Report file: " + reportFile
						+ " not located after file creation");
			}
		}catch (ParserConfigurationException e) {
			status = false;
			logger.error("** Error get document builder: " + reportFile);
		}catch (SAXException e) {
			status = false;
			logger.error("** Error getting xml report document object: " + reportFile);
		}catch (IOException e) {
			status = false;
			logger.error("** Error opening Report file: " + reportFile);
		}
		return status;
	}
 
	public void writeReportLine(Element rptLine) {
		// Write output to report file
		synchronized (XMLReportHandler.class) {
			reportOutput.getDocumentElement().appendChild(rptLine);
		}
	}
 
	public void writeToReportFile() {
		synchronized (XMLReportHandler.class) {
				try{
				  //write the content into xml file
				  TransformerFactory transformerFactory = TransformerFactory.newInstance();
				  Transformer transformer = transformerFactory.newTransformer();
				  DOMSource source = new DOMSource(reportOutput);
 
				  StreamResult result =  new StreamResult(f);
				  transformer.transform(source, result);
 
				}catch(TransformerConfigurationException e){
					logger.error("** Error getting xml report document object: " + e);
					e.printStackTrace();
				}catch(TransformerException e){
					logger.error("** Error getting xml report document object: " + e);
					e.printStackTrace();
				}
			}
	}
 
	public void closeReportFile() {
		writeToReportFile();
	}
 
	/*public void flushReportFile() {
 
		reportOutput.flush();
	}*/
 
	// ---
 
	// Create report file if it does not exist
	public String[] createReport(String iDir, String fileExt, String type) {
 
		synchronized (XMLReportHandler.class) {
			String[] returnValues = newReportFile(iDir, fileExt, type);
			return returnValues;
		}
	}
 
	private String[] newReportFile(String iDir, String fileExt, String type) {
 
		// try to create the report file for the provided directory and
		// extention, if it already exists more than one Monitor worker is
		// trying to process the same inputDiretory with the same extention
		String filename = "";
		String dirname;
		String basename;
		String[] send = new String[3];
		send[0] = ""; // filename
		send[1] = ""; // status
		send[2] = ""; // basename
			int a = iDir.indexOf(":\\");
			a = a + 2;
			int hl = iDir.length();
			dirname = iDir.substring(a, hl);
			dirname.replaceAll(" ", "_");
			dirname.replaceAll("\\\\", "_");
			dirname.replaceAll(":", "_");
			boolean stay = true;
			while (stay) {
				int d = dirname.indexOf("\\");
				if (d > -1) {
					dirname = dirname.substring(0, d - 1) + "_"
							+ dirname.substring(d + 1, dirname.length());
				} else {
					stay = false;
				}
			}
			// build file name with extention based on request type
			basename = "D_" + dirname + "_E_" + fileExt + "." + type;
			filename = iDir + "\\" + basename;
			logger.debug("Generated report file name: " + filename);
 
			// update filename in return array
			send[0] = filename;
			send[2] = basename;
 
			f = new File(filename);
			if (!f.exists()) {
				try
				{
				  DocumentBuilderFactory docFactory = DocumentBuilderFactory.newInstance();
				  DocumentBuilder docBuilder = docFactory.newDocumentBuilder();
 
				  //root elements
				  reportOutput = docBuilder.newDocument();
 
				  Element rootElement = reportOutput.createElement("IngestionReport");
				  reportOutput.appendChild(rootElement);
 
				  Element createdTimeStamp = reportOutput.createElement("ReportDateTimeStamp");
				  createdTimeStamp.appendChild(reportOutput.createTextNode(new Date().toString()));
				  rootElement.appendChild(createdTimeStamp);
 
				  Element inputDirectory = reportOutput.createElement("InputDirectory");
				  inputDirectory.appendChild(reportOutput.createTextNode(iDir));
				  rootElement.appendChild(inputDirectory);
 
				  writeToReportFile();
 
				}catch(ParserConfigurationException pce){
					  pce.printStackTrace();
				}
 
				// update status of file creation
				send[1] = "OK";
			} else {
				// update status of file creation
				send[1] = "FAIL";
				logger.error("** Report File: " + filename + " already exists");
			}
		return send;
	}
}

Thanks for your help.

[aussiemcgr]

My mistake, I thought the reportOutput variable was an instance of XMLReportHandler.

But I do have a question: Is there any reason that this:

public boolean openReport(String reportFile) {
	synchronized (XMLReportHandler.class) {
		boolean succeed = false;
		/*
		* invoke process to build reportFfile
		*/
		succeed = openIt(reportFile);
		return succeed;
	}
}

Is not:

public synchronized boolean openReport(String reportFile) {
	boolean succeed = false;
	/*
	* invoke process to build reportFfile
	*/
	succeed = openIt(reportFile);
	return succeed;
}

(and the same pattern for all the other methods in the XMLReportHandler method which performs this synchronization)?

[jashburn]

I am trying to build an XML format report with the results of the processing per record, while processing is underway per thread. The method below is called from every thread wvery time its ready to append an element to the DOM with the status.

	public void writeReportLine(Element rptLine) {
		[...]
	}

After all priocessing completes, the below method is called only once by every thread to write to the File on the file system:

	public void writeToReportFile() {
	    [...]
	}

Is the writeToReportFile() method called only once after processing from all the threads (that call writeReportLine() to build up reportOutput) completes? I'm asking because you wrote, "[writeToReportFile()] is called only once by every thread [...]." To put this in another way, is the method called once for each of the thread, or once for all the threads?

The problem is that when under load, the threads just seem to hang while the transformer.transform(source, result) call keeps getting executed until there is an interrupt of some sort. I was able to examine a section of what was appended and it was status for records that had finished processing very early in the process based on my application logs.

By "transformer.transform(source, result) call keeps getting executed", do you mean that the transform() method is being called repeatedly, which would suggest that writeToReportFile() is being called repeatedly?

To further diagnose this, get a thread dump when the problem occurs. On Unix/Linux, a kill -quit <java_pid> would suffice. On Windows (also on Unix/Linux), use jstack. Before you do that, it'll help to name the threads (e.g., create your Threads using the Thread(String name) constructor) to make them more easily identifiable in the thread dump. Once you have the thread dump, you can either eyeball it, or use a tool such as https://java.net/projects/tda or https://www.ibm.com/developerworks/c...1-14c205f7333c (I usually use the latter) to help analyse it.