Link to home
Start Free TrialLog in
Avatar of alcani
alcani

asked on

How to find performance bottlenecks in java processes running on Linux?

I have a Java Soap Client that send some xml files to a remote server to be processed.

It uses java 1.7's java.nio.file.WatchEvent<Path> (almost just like it's explained here) to monitor new files added to a directory.

It is processing about 2 or 3 files per minute.

Looking for a way to increase the speed of files sent and processed I decided to start the same jar twice, monitoring different directories of course.

I can't explain why both processes are still processing about 2 or 3 files per minute. I doubt the problem is in the remote server, since I have a log showing the moment when each file begins and ends it's processing, and it shows almost the same behavior when using only one linux process than when using two.

I mean the total throughput is the same when using only one linux process than when using two.

The size of the xml's are almost always about 8KB.

I'm guessing there should be a bottleneck somewhere other than CPU.

Any suggestions on what tool or tools should I use to find it and how to use them? (Remember, it's a Java application)

I would prefer to use free or openSource tools, but I could consider using a paid one.

Thanks
Avatar of Gerwin Jansen
Gerwin Jansen
Flag of Netherlands image

How are the files getting into the input directory?

Can you have your code write the xml to a new file instead of posting it as as soap message? Can you process more files then?
Netbeans has a very nice profiler that works with both your client application and integrates easily with some application servers: Tomcat, Glassfish, or JBoss.  It is possible to use the NetBeans profiler with other application servers, but it is more complicated.

https://profiler.netbeans.org/

Can you tell us more about your server environment - what AS is it running?
Also might help if you post your code - might be something obvious to someone here.
also what OS is the watcher running on?
Avatar of alcani
alcani

ASKER

The application is rutting standalone.

The server is a virtual web hosting running CentOS release 5.8 (Final)

and using:

java version "1.7.0_07"
Java(TM) SE Runtime Environment (build 1.7.0_07-b10)
Java HotSpot(TM) Server VM (build 23.3-b01, mixed mode)
Avatar of alcani

ASKER

About the source code, here is how the files are been read:

Please bear with me.. must of it was created about 5 or 6 years ago, with much less experience in Java. Also, there is always room for improvement and learning, I know :)

Note: In fact the files read contain parameters, not the actual xml to be sent. The sent xml comes from an absolute path contained in one of those parameters.

(Hope you understand Spanish :) )

						File dir = new File(directoryToMonitor);

						if ((! dir.exists()) || (! dir.isDirectory())) {
							String msg = "Directory ["+directoryToMonitor+"] does not exist. (Parameter ["+Grales.PARAMETER_NAME_DIRECTORIO_A_MONITOREAR+"]).";
							argsKeepRunning.addException(Grales.PARAMETER_NAME_DIRECTORIO_A_MONITOREAR, new ParseException(msg, -1));
							agregaMensajeError(msg, msgErr, /*pMsgDeExterno*/ false, /*pConSaltoLinea*/ true);
							exitApplication = Boolean.TRUE;
						} else {

//							//monitor directory. Process a file and rename it after that.
//							TimerTask task1 = new DirectoryWatcher(dir, extensionToProcess, processedSuffix, processedOutputSuffix) {
							DirectoryWatcher7 watcher = new DirectoryWatcher7(dir, extensionToProcess, processedSuffix, processedOutputSuffix, /*recursive*/ false) {

								@Override
								protected BooleanStringResult onNewFile(File pFile) {
									String argsFromFileStr = null;
									String commandOutput = "";
									
									MitalCFDIsTimbradoFel.processing = Boolean.TRUE;
									try {
									
										try {
											int cnt = 0;
											while (((argsFromFileStr == null) || (argsFromFileStr.length() == 0)) && (cnt < 6)) {
												if (cnt > 0) {
													try {
													    Thread.sleep(500);                 //1000 milliseconds is one second.
													} catch(InterruptedException ex) {
													    Thread.currentThread().interrupt();
													}
												}
												cnt++;
											    argsFromFileStr = StrUtil.utf8FileToString(pFile.getPath()).replace("\n", "").replace("\r", "");
											}
	
////											String[] argsFromFile = argsFromFileStr.split(" ");
//											List<String> argsFromFileList = StrUtil.splitQuotedString(argsFromFileStr);
//											String[] argsFromFile = argsFromFileList.toArray(new String[0]);
											String argsFromFile = argsFromFileStr;
	
											MitalCFDIsTimbradoFelParamsTimbrado jsapTimbradoFromFile = new MitalCFDIsTimbradoFelParamsTimbrado();	
											MitalCFDIsTimbradoFelParamsCancelacion jsapCancelacionFromFile = new MitalCFDIsTimbradoFelParamsCancelacion();	
											MitalCFDIsTimbradoFelParamsTimbradoRetencion jsapTimbradoRetencionFromFile = new MitalCFDIsTimbradoFelParamsTimbradoRetencion();	
											MitalCFDIsTimbradoFelParamsCancelacionRetenciones jsapCancelacionRetenciones = new MitalCFDIsTimbradoFelParamsCancelacionRetenciones();	
											JSAPResult argsTimbradoFromFile = jsapTimbradoFromFile.parse(argsFromFile);
											JSAPResult argsCancelacionFromFile = jsapCancelacionFromFile.parse(argsFromFile);
											JSAPResult argsTimbradoRetencionFromFile = jsapTimbradoRetencionFromFile.parse(argsFromFile);
											JSAPResult argsCancelacionRetencionesFromFile = jsapCancelacionRetenciones.parse(argsFromFile);
											boolean modoTimbradoFromFile = argsTimbradoFromFile.success();
											boolean modoCancelacionFromFile = argsCancelacionFromFile.success();
											boolean modoTimbradoRetencionFromFile = argsTimbradoRetencionFromFile.success();
											boolean modoCancelacionRetencionesFromFile = argsCancelacionRetencionesFromFile.success();
	
											String verificacion = (modoTimbradoFromFile ? "1" : "0");
											verificacion += (modoCancelacionFromFile ? "1" : "0");
											verificacion += (modoTimbradoRetencionFromFile ? "1" : "0");
											verificacion += (modoCancelacionRetencionesFromFile ? "1" : "0");
											
											String[] arrTmp = ("*" + verificacion + "*").split("1");
											
//											if (modoTimbradoFromFile && modoTimbradoPruebaFromFile) { 
//												String msg = "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. No puede ser al mismo tiempo timbrado de prueba y en producción";
//												logger.error(msg);
//												StrUtil.writeToSimpleLog(Level.ERROR , msg);
//											} else if ((! modoTimbradoFromFile) && (! modoTimbradoPruebaFromFile) && (! modoCancelacion)) {asdf
											if (arrTmp.length > 2) { // Hay más de un modo activado
												String msg = "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. No puede ser al mismo tiempo más de uno de estos: timbrado de prueba,  en producción y cancelación";
												logger.error(msg);
												StrUtil.writeToSimpleLog(Level.ERROR , msg);
											} else if (arrTmp.length < 2) {// No hay algún modo activado
												String msg = "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. No se está trabajando en modo timbrado ni en modo timbrado de prueba ni en modo cancelación (de CFDIs o Retenciones)";
												logger.error(msg);
												StrUtil.writeToSimpleLog(Level.ERROR , msg);
											} else {
												JSAPResult argsTimbradoTmp = null; // Garantizado que se inicializa con base en el modo

												boolean retenciones = false;
												if (modoTimbradoFromFile) {
													argsTimbradoTmp = argsTimbradoFromFile;
												} else if (modoCancelacionFromFile) {
													argsTimbradoTmp = argsCancelacionFromFile;
												} else if (modoTimbradoRetencionFromFile) {
													argsTimbradoTmp = argsTimbradoRetencionFromFile;
													retenciones = true;
												} else if (modoCancelacionRetencionesFromFile) {
													argsTimbradoTmp = argsCancelacionRetencionesFromFile;
													retenciones = true;
												}
												
												char[] decryptPassword = getDecryptPassword(argsTimbradoTmp);
	
												MitalCFDIsTimbradoFel timbradoCancelacionObj = new MitalCFDIsTimbradoFel(); 
	
												StringBuilder msgErr = new StringBuilder();
	
												Boolean exitApplication = Boolean.FALSE;
												MutableInt exitStatus = new MutableInt(Grales.EXIT_STATUS_NORMAL);
												
												String outputFileNameForErrors = argsTimbradoTmp.getString(Grales.PARAMETER_NAME_OUTPUT_FILE_NAME_FOR_ERRORS);

//												if (argsTimbradoTmp.getBoolean(Grales.PARAMETER_NAME_KEEP_RUNNING)) {
//													logger.error("Error en parametros. Desde un archivo no se permite el parámetro ["+Grales.PARAMETER_NAME_KEEP_RUNNING+"]");
//													StrUtil.writeToSimpleLog(Level.ERROR , "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]");
//												} else {
												System.out.println("=="+StrUtil.getDateTimeStringForFileName(XMLUtil.createXMLGregorianCalendar())+"==");
												System.out.println(pFile.getName());
												
												boolean doRemoveBom = Boolean.FALSE;
												boolean pruebas = argsTimbradoTmp.getBoolean(Grales.PARAMETER_NAME_AMBIENTE_PRUEBAS);
												
										        Boolean useTimbradoDePruebaPreviousValue = ConfiguracionTimbrado.getInstance().useTimbradoDePrueba(); 
										        try {
										        	ConfiguracionTimbrado.getInstance().setTimbradoDePruebaOverrideValue(Boolean.FALSE);
										        	if (pruebas) {
										        		ConfiguracionTimbrado.getInstance().setTimbradoDePruebaOverrideValue(Boolean.TRUE);
										        	}
										        	
													if (! retenciones) {
														if (! modoCancelacionFromFile) {
															
															doRemoveBom = argsTimbradoTmp.getBoolean(Grales.PARAMETER_NAME_REMOVE_BOM);

															try {
																BooleanStringResult result = doTimbrar(argsTimbradoTmp, timbradoCancelacionObj,
																		decryptPassword, doRemoveBom,
																	/*pruebas,*/ /*pMostrarNombreArchivo*/ Boolean.TRUE, 
																	msgErr, exitApplication, exitStatus);
	
																exitApplication = result != null && result.isSuccess();
																commandOutput = (result != null ? result.getOutput() : ""); 
	
																if (exitApplication && exitStatus.intValue() == Grales.EXIT_STATUS_ERROR_PARAMETROS_RECIBIDOS) {
																	logger.error("Error en parametros");
																	StrUtil.writeToSimpleLog(Level.ERROR , "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]");
																} else if (msgErr.length() > 0) {
																	logger.error(msgErr);
																	mensajeError(outputFileNameForErrors, msgErr.toString(), ""); 
																}
															} catch (UnsupportedEncodingException e) {
																logger.error("UnsupportedEncodingException: " + e.getMessage());
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															} catch (FileNotFoundException e) {
																logger.error("FileNotFoundException: " + e.getMessage());
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															} catch (IOException e) {
																logger.error("IOException: " + e.getMessage());
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															} catch (javax.xml.ws.WebServiceException e) {
																logger.error("WebServiceException");
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															}
															//												}
	
														} else {
															//cancelacion aquí
															BooleanStringResult result = doCancelar(argsTimbradoTmp, timbradoCancelacionObj,
																	decryptPassword, msgErr, exitApplication,
																	exitStatus, /*pMostrarNombreArchivo*/ Boolean.TRUE);
	
															exitApplication = result != null && result.isSuccess();
															commandOutput = (result != null ? result.getOutput() : ""); 
	
															if (msgErr.length() > 0) {
																logger.error(msgErr);
																mensajeError(outputFileNameForErrors, msgErr.toString(), ""); 
															}
	
														}
													} else { // RETENCIONES
														if (! modoCancelacionRetencionesFromFile) {

															doRemoveBom = argsTimbradoTmp.getBoolean(Grales.PARAMETER_NAME_REMOVE_BOM);

															try {
																BooleanStringResult result = doTimbrarRetencion(argsTimbradoTmp, timbradoCancelacionObj,
																		decryptPassword, doRemoveBom,
																		/*pruebas,*/ /*pMostrarNombreArchivo*/ Boolean.TRUE, 
																	msgErr, exitApplication, exitStatus);
	
																exitApplication = result != null && result.isSuccess();
																commandOutput = (result != null ? result.getOutput() : ""); 
	
																if (exitApplication && exitStatus.intValue() == Grales.EXIT_STATUS_ERROR_PARAMETROS_RECIBIDOS) {
																	logger.error("Error en parametros");
																	StrUtil.writeToSimpleLog(Level.ERROR , "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]");
																} else if (msgErr.length() > 0) {
																	logger.error(msgErr);
																	mensajeError(outputFileNameForErrors, msgErr.toString(), ""); 
																}
															} catch (UnsupportedEncodingException e) {
																logger.error("UnsupportedEncodingException: " + e.getMessage());
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															} catch (FileNotFoundException e) {
																logger.error("FileNotFoundException: " + e.getMessage());
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															} catch (IOException e) {
																logger.error("IOException: " + e.getMessage());
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															} catch (javax.xml.ws.WebServiceException e) {
																logger.error("WebServiceException");
																mensajeError(outputFileNameForErrors, e.getMessage(), ""); 
															}
															//												}
	
														} else {
															//cancelacion aquí
															BooleanStringResult result = doCancelarRetenciones(argsTimbradoTmp, timbradoCancelacionObj,
																	decryptPassword, msgErr, exitApplication,
																	exitStatus, /*pMostrarNombreArchivo*/ Boolean.TRUE);
	
															exitApplication = result != null && result.isSuccess();
															commandOutput = (result != null ? result.getOutput() : ""); 
	
															if (msgErr.length() > 0) {
																logger.error(msgErr);
																mensajeError(outputFileNameForErrors, msgErr.toString(), ""); 
															}
	
														}
													}
										        } finally {
										        	ConfiguracionTimbrado.getInstance().setTimbradoDePruebaOverrideValue(useTimbradoDePruebaPreviousValue);
										        }
											}
										} catch (ConfigurationException e) {
											logger.fatal(e.getMessage(), e);
											StrUtil.writeToSimpleLog(Level.FATAL , e.getMessage());
											System.exit(Grales.EXIT_STATUS_ERROR_EN_CONFIGURACION);
										} catch (IOException e) {
											logger.error("Error de Entrada/Salida. Parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. Mensaje: " + e.getMessage());
											StrUtil.writeToSimpleLog(Level.ERROR , "Error de Entrada/Salida. Parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. Mensaje: " + e.getMessage());
										} catch (JSAPException e) {
											logger.error("Error en parametros");
											StrUtil.writeToSimpleLog(Level.ERROR , "Error en parametros ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. Mensaje: " + e.getMessage());
										} catch (DatatypeConfigurationException e) {
											logger.error("DatatypeConfigurationException: " + e.getMessage());
											StrUtil.writeToSimpleLog(Level.ERROR , "DatatypeConfigurationException ["+argsFromFileStr+"] desde archivo ["+pFile.getPath()+"]. Mensaje: " + e.getMessage());
										}
//										return true; // Always rename properties file
										return new BooleanStringResult(true, commandOutput); // Always rename properties file
									
									} finally {
										MitalCFDIsTimbradoFel.processing = Boolean.FALSE;
									}
								}

							};

							String StopMonitoringFile = Grales.STOP_PROCESSING_FILE_NAME; 
							if ((argsKeepRunning.getString(Grales.PARAMETER_NAME_STOP_MONITORING_FILE) != null) && (argsTimbrado.getString(Grales.PARAMETER_NAME_STOP_MONITORING_FILE).length() > 0)) {
								StopMonitoringFile = argsKeepRunning.getString(Grales.PARAMETER_NAME_STOP_MONITORING_FILE);
							} 
							
							File salida1 = new File(StopMonitoringFile);
							File salida2 = new File(dir.getPath() + File.separator + StopMonitoringFile);
							
							TimerTask task2 = new FileWatcher( salida1 , 
									/*pValidateExternalGenerationTimestamp*/ Boolean.FALSE ) {
								protected void onChange( File pFile ){
									Grales.doExitApplication = Boolean.TRUE;
//									if (! CFDUtil.processing) {
									if (! MitalCFDIsTimbradoFel.processing) {
										pFile.delete();
										logger.info("###################################");
										logger.info("Terminada la ejecución del programa");
										//loggerSimple.info("Terminada la ejecución del programa");
										StrUtil.writeToSimpleLog(Level.INFO , "Terminada la ejecución del programa");
										Grales.doExitApplication = Boolean.TRUE; 
										System.exit(Grales.EXIT_STATUS_NORMAL);
									}
								}
							};
							TimerTask task3 = new FileWatcher( salida2, 
									/*pValidateExternalGenerationTimestamp*/ Boolean.FALSE ) {
								protected void onChange( File pFile ){
									Grales.doExitApplication = Boolean.TRUE;
//									if (! CFDUtil.processing) {
									if (! MitalCFDIsTimbradoFel.processing) {
										pFile.delete();
										logger.info("###################################");
										logger.info("Terminada la ejecución del programa");
										//loggerSimple.info("Terminada la ejecución del programa");
										StrUtil.writeToSimpleLog(Level.INFO , "Terminada la ejecución del programa");
										Grales.doExitApplication = Boolean.TRUE; 
										System.exit(Grales.EXIT_STATUS_NORMAL);
									}
								}
							};


							Timer timer = new Timer();
							// repeat the check every second
//							timer.schedule( task1 , new Date(), 1000 );
							timer.schedule( task2 , new Date(), 1000 );
							timer.schedule( task3 , new Date(), 1000 );
							
							logger.info("Salir con: "+salida1.getAbsolutePath());
							logger.info("Salir con: "+salida2.getAbsolutePath());

							logger.info("Listo para procesar cambios en el directorio: "+directoryToMonitor);
							
							watcher.processEvents();
						}
					

Open in new window


I also attached the DirectoryWatcher7 class, that almost entirely comes from http://docs.oracle.com/javase/tutorial/essential/io/examples/WatchDir.java

Please note:
Methods doTimbrar and doCancelar are the methods that in fact are doing the soap calls. The first one take the xml file and send it, the later only send some string parameters

Thank you for your help
DirectoryWatcher7.java
This is a perfect candidate for the Netbeans Profilier I mentioned above.  

It'll give you a beautiful call-by call breakdown of CPU utilization, runtime, memory, locks, the whole bit.  Once once you figure out where the problem is, post back if you need help actually fixing the problem.
methods_index.png
This question needs an answer!
Become an EE member today
7 DAY FREE TRIAL
Members can start a 7-Day Free trial then enjoy unlimited access to the platform.
View membership options
or
Learn why we charge membership fees
We get it - no one likes a content blocker. Take one extra minute and find out why we block content.