Teiid doesn't respond when simultaneous threads request data from vdb

[guidolomb]

Hi, I'm using teiid 8.10.0. I've developed a web application that runs on it. This app uses spring and hibernate, technologies that I think are important for you to know because they get involved with the vdb.

When I use the app it works fine, but when I made a concurrency basic test the vdb gets messy. I open two different browser (chrome, firefox) and make in both browsers the same action (really basic concurrency test). This action make five queries to the vdb.

I'm attaching logs (server and log4j) for when I use only one browser and when I use two browsers.

If you need more info of the app, please let me know.

[rareddy]

Define messy. Also note that JDBC connections can not be shared.

[shawkins]

It's not clear what your are describing.  The title says "Teiid doesn't respond when simultaneous threads request data from vdb" - however the logs simply show a succession of queries being issued at two different times.  Can you show or describe more clearly what behavior you are seeing?  It may also be relevant to describe the Teiid/AS configuration - are you simply using default values?

Some concurrency considerations that may be of interest include:

- max-active-plans - defines the amount of parallel plans that can be actively processed (the default is fine for this scenario)

- thread-count-for-source-concurrency - can control the number of source request spawned by a plan concurrently (the default is fine for this scenario)

- it doesn't appear from the log that a transaction is involved, but of course that can have concurrency ramifications depending on the source

- the various AS datasources that are used need to provide enough concurrent connections to the consuming plans, so make sure the max size is appropriate

And in general you can look at:  Administrator's Guide - Teiid 8.10 - Project Documentation Editor

[guidolomb]

I will try to be clearer.

I open chrome, load my aplication, then I submit values through a rest service. This goes to the controller which excecute a query to TEIID through Hibernate.

This returns values without problem.

If I run the same actions from two browsers (chrome and firefox), without waiting the response of the first petition, TEIID doesn't response and freezes. So I have to kill the process and run TEIID again.

It also happens if I make the same petitions, both from a same javascript block. This means that I run an ajax request and inmediatly after, run another one. TEIID just freezes.

In the logs I don't see anything strange, or any errors...

I'm running this test from my own computer.

I'm attaching my standalone-teiid.xml

[rareddy]

We need to see your browser client program. I am pretty confident that the issue lies in the Client. If you can not attach the whole program, do a small testcase and show us that.

[guidolomb]

Thanks for your respons.

The ajax call from the client is:

var prospectos = new ProspectosCollection();

  prospectos.fetch({ data : { acuerdo : 1, base : 201408},

  async : true,

  type: 'GET',

  success : function(data) {

   var responseProspectos = data.models;

   var todos = responseProspectos[6];

   var listaProspectos = new ListaProspectosView();

   $("#tablaProspectos").empty();

   $("#tablaProspectos").append(listaProspectos.render(responseProspectos,todos).el);

   $("HTML").unblock();

  },

   error:function(collection, response, options){

   Utils.showInternalErrorModal(response);

   $("HTML").unblock();

   }

  });

We use backbone, ProspectosCollection consumes a restful service. This service (stepping some layers) hit the vdb with this method:

public Long getCantProspectosByBaseAnio(String baseID, String acuerdoID,int cantidad){

    log.info("Estoy en getProspectos");

    String hql = " SELECT count(*) FROM ProspectoAcuerdoBase prospecto ";  

    hql +=" WHERE prospecto.acuerdoBase.baseID = :baseID ";

    hql +=" AND prospecto.acuerdo.id = :acuerdoID ";

    if(cantidad >= 5)

    {

    hql +=" AND prospecto.vecesReciclado >= :cantidad ";

    }

    else

    {

    hql +=" AND prospecto.vecesReciclado = :cantidad ";

    }

    Query query = this.getEm().createQuery(hql);

    query.setParameter("baseID", Integer.parseInt(baseID));

    query.setParameter("acuerdoID", new Long(acuerdoID));

    query.setParameter("cantidad", cantidad);

    log.info("va 1, parametros: acuerdo=" + acuerdoID + " base=" + baseID + " cantidad=" + cantidad);

    Long result = (Long) query.getSingleResult();

    log.info("vuelve 1, resultado=" + result + " cantidad=" + cantidad);

    return result;

   }

Hope this info helps!

[shawkins]

From the config you have all the thread pools with a max thread count of 1.  This is certainly not recommended, but I'm not aware of it causing a deadlock.  Is there a reason for that?

> If I run the same actions from two browsers (chrome and firefox), without waiting the response of the first petition, TEIID doesn't response and freezes. So I have to kill the process and run TEIID again.

Ideally you could validate this using another JDBC client if Teiid is still accepting connections and executing queries.   If it's an issue with restricting the available threads it would be good to have the thread dump from the server and from the hibernate vm (if different and making remote connections to Teiid).

[guidolomb]

- From the config you have all the thread pools with a max thread count of 1.  This is certainly not recommended, but I'm not aware of it causing a deadlock.  Is there a reason for that?

I was trying to see if this property makes any difference, but it doesn't.

[guidolomb]

- Ideally you could validate this using another JDBC client if Teiid is still accepting connections and executing queries.   If it's an issue with restricting the available threads it would be good to have the thread dump from the server and from the hibernate vm (if different and making remote connections to Teiid).

I tried this. First made the first scenario (two different browsers), so the app freezes. Then, from a sql client (SQuirreL), I connect to the vdb, and when I make a query I get the result. So the vdb works fine after the app freezes.

By the other way, if I try to run again the app, it doesn't respond.

[shawkins]

> I was trying to see if this property makes any difference, but it doesn't.

You should revert these settings back to their defaults as you haven't determined what is occurring.

> So the vdb works fine after the app freezes.

So this seems like we're looking at a broader issue than just Teiid.  You'll need to start by taking thread dumps when your app appears to be freezing from the relevant vms.  This may show that you have a deadlock or other issue higher up in your application - which would be likely given that Teiid is still responsive in this scenario.

[guidolomb]

Hi steven, thanks for your answer.

I do not know how to take thread dumps from the vms. Can you help me with this? maybe there are some tools to do this.

[shawkins]

Thread dumps can be obtained from the shell, using jstack (part of the JRE), visualvm, or many other tools.  For example:

jstack {pid} > stack-trace.log

or Monitoring Application Threads — Project Kenai

[guidolomb]

Thanks Steven for your answer, I downloded VisualVM, great tool!

When monitoring with VisualVM, I followed the steps that make the app freeze, and this tool detected a deadlock!

I`m attaching the thread dump so you can see what is the problem, because I can't figure it out.

Thanks again for your help.

Guido

[shawkins]

The relevant section is:

Found one Java-level deadlock:

=============================

"http-localhost/127.0.0.1:8080-5":

  waiting to lock monitor 0x00000000588ffdb0 (object 0x000000001af812d0, a org.apache.log4j.ConsoleAppender),

  which is held by "http-localhost/127.0.0.1:8080-3"

"http-localhost/127.0.0.1:8080-3":

  waiting to lock monitor 0x0000000057d74c78 (object 0x000000001af8c408, a java.io.PrintStream),

  which is held by "http-localhost/127.0.0.1:8080-5"

Java stack information for the threads listed above:

===================================================

"http-localhost/127.0.0.1:8080-5":

  at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:231)

  - waiting to lock <0x000000001af812d0> (a org.apache.log4j.ConsoleAppender)

  at org.apache.log4j.JBossAppenderHandler.doPublish(JBossAppenderHandler.java:42)

  at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:79)

  at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:296)

  at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:304)

  at org.jboss.logmanager.Logger.logRaw(Logger.java:721)

  at org.jboss.logmanager.Logger.log(Logger.java:506)

  at org.jboss.stdio.AbstractLoggingWriter.write(AbstractLoggingWriter.java:71)

  - locked <0x000000001af8c4b0> (a java.lang.StringBuilder)

  at org.jboss.stdio.WriterOutputStream.finish(WriterOutputStream.java:143)

  at org.jboss.stdio.WriterOutputStream.flush(WriterOutputStream.java:164)

  - locked <0x000000001af8c548> (a sun.nio.cs.MS1252$Decoder)

  at java.io.PrintStream.write(PrintStream.java:432)

  - locked <0x000000001af8c408> (a java.io.PrintStream)

  at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)

...

"http-localhost/127.0.0.1:8080-3":

  at java.io.PrintStream.write(PrintStream.java:429)

  - waiting to lock <0x000000001af8c408> (a java.io.PrintStream)

  at org.jboss.stdio.StdioContext$DelegatingPrintStream.write(StdioContext.java:264)

  at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)

  at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)

  at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:276)

  at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:122)

  - locked <0x000000001af81f08> (a java.io.OutputStreamWriter)

  at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:212)

  at org.apache.log4j.helpers.QuietWriter.flush(QuietWriter.java:59)

  at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:324)

  at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)

  at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)

  - locked <0x000000001af812d0> (a org.apache.log4j.ConsoleAppender)

  at org.apache.log4j.JBossAppenderHandler.doPublish(JBossAppenderHandler.java:42)

...

As you can see each thread is holding a lock that the other is waiting on.  This seems similar to EAP 6 deadlocks on a ConsoleHandler and java.io.PrintStream - Red Hat Customer Portal which recommends removing the application level console logging.  See also [LOGMGR-117] Fork Log4J ConosleAppender to simply handling of calls to System.out - JBoss Issue Tracker

[guidolomb]

Steven you are right! I erased the subsystem xmlns="urn:jboss:domain:logging:1.4" just to see if this is the problem and the app doesn't freeze!!!

Now I will try to configure this subsystem right.

Thanks a lot for your help, you made my day