-
1. Re: Help building blacktie.
1 of 1 people found this helpfulHi Francis,
The most up-to-date instructions for building BlackTie can be interred from the CI script we have checked into the source repo:
narayana/narayana.sh at master · jbosstm/narayana · GitHub
Those are run successfully with every build so it should work fine.
Please also note a facility of Maven is to be able to build without running the tests. You can do this with -DskipTests on the ./build.sh command lines. So for example:
./build.sh -f blacktie/wildfly-blacktie/pom.xml clean install -DskipTests
./build.sh -f blacktie/pom.xml clean install -Dbpa=<e.g. centos55x32> -DskipTests
In terms of the APR issue hopefuly zhfeng can answer that one.
Thanks,
Tom
-
2. Re: Help building blacktie.
Also, once its building fine please do run quickstart/blacktie/xatmi/fooapp at master · jbosstm/quickstart · GitHub to verify that you have a functioning server.
-
3. Re: Help building blacktie.
Hi Francis,
In the term of the c++ build errors, I think we had met it with [JBTM-2260] BlackTie does not build on CentOS 7 - JBoss Issue Tracker. So it looks like you needs to rebuild all of the third dependencies by the new bpa with "centos70x32" since you want to create 32bit XATMI servers on a 64bit Centos 7 server. I think we only have the "centos70x64" in the repo.
you can refer to the Building Thirdparty Dependencies and it might be out of date as it builds on the CentOS 5. I will check them on the CentOS 7 and update it.
-
4. Re: Help building blacktie.
I removed the platform apr and apr-util's and replaced then with the specific version mentioned in the 3rd party dependencies (1.2.12) and rebuilt blacktie and it was successful.
I'm still having issues with build for the wildflly-blacktie, the activemq pom download is failing...
[INFO] Installing /opt/narayana/blacktie/wildfly-blacktie/pom.xml to /root/.m2/repository/org/jboss/narayana/blacktie/wildfly-blacktie-parent/5.3.4.Final-SNAPSHOT/wildfly-blacktie-parent-5.3.4.Final-SNAPSHOT.pom
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] Building WildFly: Blacktie Subsystem 5.3.4.Final-SNAPSHOT
[INFO] ------------------------------------------------------------------------
Downloading: http://download.java.net/maven/2/org/jboss/narayana/rts/restat-bridge/5.3.4.Final-SNAPSHOT/maven-metadata.xml
Downloading: http://download.java.net/maven/2/org/jboss/narayana/rts/restat/5.3.4.Final-SNAPSHOT/maven-metadata.xml
Downloading: http://download.java.net/maven/2/org/jboss/narayana/rts/rest-tx/5.3.4.Final-SNAPSHOT/maven-metadata.xml
Downloading: http://download.java.net/maven/2/org/jboss/narayana/narayana-all/5.3.4.Final-SNAPSHOT/maven-metadata.xml
Downloading: http://download.java.net/maven/2/org/wildfly/wildfly-messaging-activemq/11.0.0.Alpha1-SNAPSHOT/maven-metadata.xml
[WARNING] The POM for org.wildfly:wildfly-messaging-activemq:jar:11.0.0.Alpha1-SNAPSHOT is missing, no dependency information available
-
5. Re: Help building blacktie.
Hi Francis,
It is not one I have seen before, but our CI box builds WildFly itself rather than using the nexus repo. Perhaps they are not pushing that module out to nexus for some reason yet? They certainly had the previous release as uploaded on April 12th: Index of /groups/public/org/wildfly/wildfly-messaging-activemq
Anyway, you can circumvent the issue by downloading and building wildfly locally:
git clone git@github.com:wildfly/wildfly.git
cd wildfly
./build.sh clean install -DskipTests
Hope that helps,
Tom
-
6. Re: Help building blacktie.
Thanks, I will try that later, right now I just changed the wildfly version to 10.
So I have it up and running at last. Pfew.
root 1 0 0 Aug01 ? 00:00:01 /bin/bash
root 30857 1 0 17:40 ? 00:00:00 /bin/sh ./standalone.sh -c standalone-blacktie.xml -Djboss.bind.address=172.17.0.5 -Djboss.bind.address.unsecure=172.17.0.5
root 30917 30857 72 17:40 ? 00:00:34 /usr/java/latest/bin/java -D[Standalone] -server -Xms64m -Xmx512m -XX:MetaspaceSize=96M -XX:MaxMetaspaceSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -DOrbP
root 31230 1 0 17:41 ? 00:00:00 ./server -i 1 -s fooapp -p 12341 -t 127.0.0.1:8881
root 31267 1 0 17:41 ? 00:00:00 ./server -i 2 -s fooapp -p 12342 -t 127.0.0.1:8882
One thing I notice right away with the client program, the timings are very jittery. The bold example below has a 3 second delay on the response. I don't see any random sleep in the code and I have reduced the logging verbosity. Any idea what could be causing the variation in response times?
regards, Francis.
2016-08-03 18:00:40,571 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:40,762 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:40,764 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:40,946 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:40,947 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:43,725 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:43,726 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:43,912 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:43,913 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:46,728 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:46,731 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:46,914 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:46,915 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:49,730 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:49,731 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:49,917 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:49,918 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:52,734 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
2016-08-03 18:00:52,736 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
2016-08-03 18:00:52,922 [0xf6a3e700] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
-
7. Re: Help building blacktie.
Hi Francis,
Do you run the xatmi client and the server on the same machine ? also the wildfly server ?
I noticed that you start the wildfly on the address "172.17.0.5" and start the xatmi server with "./server -i 1 -s fooapp -p 12341 -t 127.0.0.1:8881" that means the default address is "localhost"
can you run the wildfly with the localhost and try the tests again please ?
if it happens again, it could be helpful to send me the blacktie.log and server.log for checking.
Thanks,
Amos
-
8. Re: Help building blacktie.
Hi Francis,
This is what we are getting on the latest CI run:
[exec] Quickstart: Running fooapp
[exec]
[exec] BUILD SUCCESSFUL
[exec] Total time: 3 seconds
[exec] Checking for host: lancel.eng.hst.ams2.redhat.com or ip: 10.39.168.26
[exec] [33m03:23:36,697 WARN [org.jboss.as.ejb3] (Thread-6 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [0m03:23:36,827 INFO [org.apache.activemq.artemis.core.server] (ServerService Thread Pool -- 101) AMQ221003: trying to deploy queue jms.queue.BTR_.fooapp1
[exec] [0m2016-08-04 03:23:37,222 [0x2afd45a392b0] INFO (AtmiBrokerServer :938 ) - advertised service .fooapp1
[exec] [33m03:23:37,292 WARN [org.jboss.as.ejb3] (Thread-1 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [0m03:23:37,400 INFO [org.apache.activemq.artemis.core.server] (ServerService Thread Pool -- 103) AMQ221003: trying to deploy queue jms.queue.BTR_FOOAPP
[exec] [0m [31m03:23:37,651 ERROR [org.jboss.narayana.blacktie.jatmibroker.core.transport.hybrid.SocketReceiverImpl] (Thread-197) receiver Socket[addr=localhost/127.0.0.1,port=12341,localport=51287] run failed with java.io.IOException: Socket Closed
[exec] [0m2016-08-04 03:23:37,699 [0x2afd45a392b0] INFO (AtmiBrokerServer :938 ) - advertised service FOOAPP
[exec] 2016-08-04 03:23:37,699 [0x2afd45a392b0] INFO (AtmiBrokerServer :243 ) - Server 1 Running
[exec] 2016-08-04 03:23:37,700 [0x2afd45a392b0] INFO (AtmiBrokerServer :645 ) - Server waiting for requests...
[exec] [33m03:23:37,975 WARN [org.jboss.as.ejb3] (Thread-5 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [0m03:23:38,040 INFO [org.apache.activemq.artemis.core.server] (ServerService Thread Pool -- 101) AMQ221003: trying to deploy queue jms.queue.BTR_.fooapp2
[exec] [0m2016-08-04 03:23:38,305 [0x2af88a7972b0] INFO (AtmiBrokerServer :938 ) - advertised service .fooapp2
[exec] [33m03:23:38,626 WARN [org.jboss.as.ejb3] (Thread-3 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m2016-08-04 03:23:38,897 [0x2af88a7972b0] INFO (AtmiBrokerServer :938 ) - advertised service FOOAPP
[exec] 2016-08-04 03:23:38,897 [0x2af88a7972b0] INFO (AtmiBrokerServer :243 ) - Server 2 Running
[exec] 2016-08-04 03:23:38,897 [0x2af88a7972b0] INFO (AtmiBrokerServer :645 ) - Server waiting for requests...
[exec]
[exec] BUILD SUCCESSFUL
[exec] Total time: 3 seconds
[exec] 2016-08-04 03:23:42,780 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:43,011 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:43,016 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:43,273 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:43,277 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:43,509 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:43,514 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:43,733 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:43,738 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:43,960 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:43,968 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:44,180 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:44,185 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:44,416 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:44,421 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:44,634 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:44,638 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:44,857 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] 2016-08-04 03:23:44,861 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Calling tpcall with input: THIS IS YOUR CLIENT SPEAKING
[exec] 2016-08-04 03:23:45,084 [0x2abecbbaf2b0] INFO (AtmiBrokerLogc :60 ) - Called tpcall with length: 15 output: BAR SAYS HELLO and status: 0 and tperrno: 0
[exec] Checking for host: lancel.eng.hst.ams2.redhat.com or ip: 10.39.168.26
[exec] [33m03:23:46,480 WARN [org.jboss.as.ejb3] (Thread-5 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieAdminServiceXATMI message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [33m03:23:46,802 WARN [org.jboss.as.ejb3] (Thread-6 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [33m03:23:47,094 WARN [org.jboss.as.ejb3] (Thread-3 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0mServer shutdown successfully: fooapp with id: 1
[exec] waiting for fooapp:1 shutdown complete
[exec] fooapp:1 shutdown complete
[exec] [33m03:23:50,412 WARN [org.jboss.as.ejb3] (Thread-7 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieAdminServiceXATMI message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [33m03:23:51,437 WARN [org.jboss.as.ejb3] (Thread-4 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0m [33m03:23:51,783 WARN [org.jboss.as.ejb3] (Thread-2 (ActiveMQ-client-global-threads-1010832249)) WFLYEJB0485: Transaction type NEVER is unspecified for the onMessage method of the BlacktieStompAdministrationService message-driven bean. It will be handled as NOT_SUPPORTED.
[exec] [0mServer shutdown successfully: fooapp with id: 2
[exec] waiting for fooapp:2 shutdown complete
[exec] fooapp:2 shutdown complete
That box is not particularly overpowered from what I know of it. It is a virtual machine running on old hardware.
I agree with Amos' recommendation. If not done so already, please enable some additional trace logging in the WildFly server:
-
9. Re: Help building blacktie.
Looking at the server.log I noticed that wildfly was complaining about libaio not being installed which I did thinking that using native IO was the reason the fooapp client throughput was so choppy.
Didn't make any difference even though I am still seeing this trace message
2016-08-04 21:38:55,559 DEBUG [org.apache.activemq.artemis.jlibaio] (MSC service thread 1-2) artemis-native-64 -> error loading the native library: java.lang.UnsatisfiedLinkError: no artemis-native-64 in java.library.path
at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1867)
at java.lang.Runtime.loadLibrary0(Runtime.java:870)
at java.lang.System.loadLibrary(System.java:1122)
at org.apache.activemq.artemis.jlibaio.LibaioContext.loadLibrary(LibaioContext.java:68)
at org.apache.activemq.artemis.jlibaio.LibaioContext.<clinit>(LibaioContext.java:88)
at org.apache.activemq.artemis.core.io.aio.AIOSequentialFileFactory.isSupported(AIOSequentialFileFactory.java:107)
at org.wildfly.extension.messaging.activemq.ActiveMQServerService.start(ActiveMQServerService.java:155)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.startService(ServiceControllerImpl.java:1948)
at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1881)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-08-04 21:38:55,563 DEBUG [org.apache.activemq.artemis.jlibaio] (MSC service thread 1-2) Library artemis-native-64 not found!
I am running a 32bit server and pldd shows that I have all the native io libs loaded...
pldd 76
76: /usr/java/jdk1.8.0_101/bin/java
/lib/libpthread.so.0
/usr/java/jdk1.8.0_101/bin/../lib/i386/jli/libjli.so
/lib/libdl.so.2
/lib/libc.so.6
/lib/ld-linux.so.2
/usr/java/jdk1.8.0_101/jre/lib/i386/server/libjvm.so
/lib/libm.so.6
/lib/librt.so.1
/usr/java/jdk1.8.0_101/jre/lib/i386/libverify.so
/usr/java/jdk1.8.0_101/jre/lib/i386/libjava.so
/lib/libnss_files.so.2
/usr/java/jdk1.8.0_101/jre/lib/i386/libzip.so
/usr/java/jdk1.8.0_101/jre/lib/i386/libmanagement.so
/usr/java/jdk1.8.0_101/jre/lib/i386/libnet.so
/usr/java/jdk1.8.0_101/jre/lib/i386/libnio.so
/opt/wildfly/modules/system/layers/base/org/apache/activemq/artemis/main/lib/linux-i686/libartemis-native-32.so
/lib/libaio.so.1
/usr/java/jdk1.8.0_101/jre/lib/i386/libsunec.so
/lib/libgcc_s.so.1
So I am a bit stuck right now.
I must confess that I am running it in a docker container, but it is on a powerful 8 core 2.6 GHz VM and I have comparable TUXEDO containers which are blazingly fast on the same server.
I have also turned all the logging down to INFO, but that made no difference.
I modified the client to loop once, twice and ran it repeatedly, the response times were fine. As soon as I went to three iterations, it started to pause for 3 seconds on the third tpcall. It looks like there is a big pause after the third tpcall, then after that every other call pauses. I have no idea what could be causing this behaviour.
regards, Francis.
-
10. Re: Help building blacktie.
It looks strange. I had checked our CI server.log and it was missing the artemis-native-64 also. So it might not be the issue. Can you send us all of the blacktie.log and server.log ? I could look into what causes the 3 seconds delay after the third tpcall.
Thanks
-
11. Re: Help building blacktie.
I checked the source for Artemis in WildFly 10. It tries to load the library from a list and the 64 bit one is first:
It should be fine so long as you are not getting the warning for artemis-native-32 as well (or this message: https://github.com/rh-messaging/jboss-activemq-artemis/blob/1.1.0.wildfly-011/artemis-native/src/main/java/org/apache/activemq/artemis/jlibaio/LibaioContext.java#L104)
However NIO or AIO, neither should have a 3 second pause in them. Our CI nodes are not overpowered at all and as I mentioned are on aging hardware.
As Amos says we need the blacktie.log and blacktie-J.log from the fooapp folder and the server.log from the wildfly/standalone/logs folder (with at least trace in the components I mentioned earlier).
What happens if you run the app for a single interction but scripted in a tight loop for say 100 iterations, do any of those exhibit a delay? Anyway, the logs should help clear up where the delay is coming from.
-
12. Re: Help building blacktie.
Here you go.
Pattern is first two fast 3rd iteration slow then after that every other iteration is slow.
regards, Francis.
-
13. Re: Help building blacktie.
The cause of the hang is due to a session map lock:
The map is locked while we delete the session so other threads can't create sessions. We could look at doing the "delete session;" after the "sessionMapLock->unlock();" However I think in this circumstance I am not sure it can help as the thread that is waiting is used again later and so all that will actually happen is you are likely to get a delay slightly later. That said Francis perhaps you can you try a patch for that please to see if it addresses your problem?
So as to where the delay is coming from I see these log lines for thread 0xf42ffb40 (which has the lock on the map I was mentioning):
2016-08-05 13:08:55,426 [0xf42ffb40] TRACE (HybridSocketSessionImpl :221 ) - delete codec (https://github.com/jbosstm/narayana/blob/master/blacktie/hybrid/src/main/cpp/HybridSocketSessionImpl.cxx#L221)
2016-08-05 13:08:55,426 [0xf42ffb40] DEBUG (HybridSocketEndpointQueue:201 ) - disconnect (narayana/HybridSocketEndpointQueue.cxx at master · jbosstm/narayana · GitHub)
2016-08-05 13:08:58,424 [0xf42ffb40] DEBUG (HybridSocketEndpointQueue:97 ) - destroy called: 0xf3900638 (narayana/HybridSocketSessionImpl.cxx at master · jbosstm/narayana · GitHub
The line I can attribute the delay to is:
narayana/HybridSocketSessionImpl.cxx at master · jbosstm/narayana · GitHub
Unfortunately we don't log the queue's thread name in the Session CTOR but based on the timings I expect this is the background thread we are waiting for:
2016-08-05 13:08:58,423 [0xf1affb40] DEBUG (HybridSocketEndpointQueue:448 ) - from HybridSocketEndpointQueue closing socket
It previously reported:
2016-08-05 13:08:55,600 [0xf1affb40] DEBUG (HybridSocketEndpointQueue:437 ) - add socket in pollset
Which leads me to conclude it is blocked here:
Now, DEF_POLL_TIMEOUT is defined here (no prizes for guessing three seconds):
narayana/HttpServer.h at master · jbosstm/narayana · GitHub
All this leads me to conclude that the poll is timing out rather than getting woken during a shutdown. Hopefully Amos can identify the cause from there. I am not seeing calls to apr_pollset_wakeup in our code (bottom of Apache Portable Runtime: Poll Routines) but maybe the apr_pollset_remove can do that somehow on some platforms.
-
14. Re: Help building blacktie.
Just to mention that zhfeng is still looking at this. We don't see it happen on CI and I don't see it on my box (Windows) but we don't build 32bit Centos7. Amos, can you try that too please?