bugCERTI - Bugs: bug #55592, Open a branch for test problems...

 
 

bug #55592: Open a branch for test problems found using Ptolemy

Submitted by:  janette cardoso <cardoso>
Submitted on:  Mon 28 Jan 2019 04:48:47 PM UTC  
 
Category:  JavaCERTI Severity:  4 - Important
Item Group:  Action request Status:  Need Info
Privacy:  Public Assigned to:  janette cardoso <cardoso>
Open/Closed:  Open Release:  GIT-master
Reproducibility:  Intermittent Fixed Release:  GIT-master

Add a New Comment (Rich Markup)
   

You are not logged in

Please log in, so followups can be emailed to you.

 

( Jump to the original submission)

Wed 05 Jun 2019 11:33:08 AM UTC, comment #6:

Hello,
The title for this ticket would be "JCERTI deadlocks, blocked waiting for a message on a socket where the message never comes from CERTI."

I did tests with br_ptII_bug_55592 also the demo shipped with jcerti and used: export RTIG_MSG=D ; export RTIA_MSG=D

The results are even worst using the branch br_ptII_bug_55592, see comment #4 (Four RAV where expected, but only 2 are received).

janette cardoso <cardoso>
Project MemberIn charge of this item.
Thu 21 Feb 2019 01:36:22 PM UTC, comment #5:

Updating this ticket with new information:

- We confirm that the problem arrives in other places in the execution of a
federation, not only resignFederationExecution().

- After launching 50 federations successfully, the rtig loose the connexion
with socket 6 of the rtia (federate 1, consTT).
See RTIG.cc:452 > to nullptr in the log bellow (with RTIG=ACDEGIMPRSTWXZ rtig):

RTIG.cc:446 > Send back NM_Join_Federation_Execution to 1 federates
RTIG.cc:449 > to 6
RTIG.cc:203 > Incoming message on socket 6
MessageProcessor.cc:729 > Federate 1 of Federation 51 subscribed to object class 3
RTIG.cc:444 > 2 responses
RTIG.cc:446 > Send back NM_Start_Registration_For_Object_Class to 0 federates
RTIG.cc:446 > Send back NM_Subscribe_Object_Class to 1 federates
RTIG.cc:452 > to nullptr
RTIG.cc:228 > New client
RTIG.cc:513 > Accepting new connection
RTIG.cc:203 > Incoming message on socket 7

janette cardoso <cardoso>
Project MemberIn charge of this item.
Mon 18 Feb 2019 05:04:19 PM UTC, comment #4:

Hello,

A small reminder: we have automatic tests that launches several federates, with un interval of 5s between the running. Our first goal is described in the ticket (each test run a rtig then kill it). But I made new test launching the rtig by hand before the tests. Here the result:

1. Using br_ptII_bug_55592:
=======================
a. Ptolemy:
There is an error for the first federation in the test sequence. Four RAV where expected, but only 2 are received. Here the error in the terminal where the make is running:

at certi.communication.MessageBuffer.readInt(MessageBuffer.java:182)
at certi.communication.messages.ResignFederationExecution.readMessage(ResignFederationExecution.java:43)
at certi.communication.MessageFactory.readMessage(MessageFactory.java:313)
at certi.rti.impl.CertiRtiAmbassador.processRequest(CertiRtiAmbassador.java:3820)
at certi.rti.impl.CertiRtiAmbassador.resignFederationExecution(CertiRtiAmbassador.java:476)
at org.hlacerti.lib.HlaManager.wrapup(HlaManager.java:1361)

b. jcerti demo (I will joint the RTIG.log if it can help):
Then I run the demo coming with jcerti. And here is the error message for UAVReceive-run:
[java] Reflect: text 7
[java] Reflect: 3.1415927
[java] Exception in thread "main" java.util.NoSuchElementException
[java] at java.util.Vector$Itr.next(Vector.java:1140)
[java] at certi.communication.MessageBuffer.readInt(MessageBuffer.java:182)
[java] at certi.communication.messages.ResignFederationExecution.readMessage(ResignFederationExecution.java:43)
[java] at certi.communication.MessageFactory.readMessage(MessageFactory.java:313)
[java] at certi.rti.impl.CertiRtiAmbassador.processRequest(CertiRtiAmbassador.java:3820)
[java] at certi.rti.impl.CertiRtiAmbassador.resignFederationExecution(CertiRtiAmbassador.java:476)
[java] at certi.UavReceive.runFederate(UavReceive.java:67)
[java] at certi.UavReceive.main(UavReceive.java:80)

And here for UAVSend-run:
[java] févr. 18, 2019 5:31:19 PM certi.UavSend runFederate
[java] INFOS: 1. Get a link to the RTI
[java] Object class: 3
[java] Object class: 3
[java] Object handle: 1
[java] Attributes:0
[java] Exception in thread "main" java.util.NoSuchElementException
[java] at java.util.Vector$Itr.next(Vector.java:1140)
[java] at certi.communication.MessageBuffer.readInt(MessageBuffer.java:182)
[java] at certi.communication.messages.ResignFederationExecution.readMessage(ResignFederationExecution.java:43)
[java] at certi.communication.MessageFactory.readMessage(MessageFactory.java:313)
[java] at certi.rti.impl.CertiRtiAmbassador.processRequest(CertiRtiAmbassador.java:3820)
[java] at certi.rti.impl.CertiRtiAmbassador.resignFederationExecution(CertiRtiAmbassador.java:476)
[java] at certi.UavSend.runFederate(UavSend.java:85)
[java] at certi.UavSend.main(UavSend.java:98)
[java] Java Result: 1

The terminal were the rtig is runnig has:
HLALOG - 1550507631.021266 - NetworkMessage::116 > Sending <NM_Resign_Federation_Execution> whose buffer has <24> bytes
RTIG dropping client connection 8.
TCP Socket 8 : total = 401 Bytes sent
TCP Socket 8 : total = 264 Bytes received
UDP Socket 4 : total = 0 Bytes sent
UDP Socket 4 : total = 0 Bytes received
HLALOG - 1550507631.119844 - NetworkMessage::42 > Serialize <NM_Resign_Federation_Execution>
HLALOG - 1550507631.119860 - NetworkMessage::116 > Sending <NM_Resign_Federation_Execution> whose buffer has <24> bytes

^CCERTI RTIG exiting.

2. Using br_ptII_berkeley:
======================
a. Ptolemy: I can run 2 complete test sequence, but in 3rd one, there is an error. It is blocked in:
(terminal where the rtig was launched with export RTIG_MSG=D ; export RTIA_MSG=D):

HLALOG - 1550502974.291999 - NetworkMessage::63 > Deserialize <NM_Synchronization_Point_Achieved>

And in the terminal where the make (for the test) was running before the "kill -3 JUnitTclTest" :
at certi.communication.MessageBuffer.receiveData(MessageBuffer.java:303)
- locked <0x00000006c027c3b0> (a certi.communication.MessageBuffer)
at certi.communication.MessageFactory.readMessage(MessageFactory.java:309)
at certi.rti.impl.CertiRtiAmbassador.processRequest(CertiRtiAmbassador.java:3820)
- locked <0x00000006c027c3b0> (a certi.communication.MessageBuffer)
at certi.rti.impl.CertiRtiAmbassador.subscribeObjectClassAttributes(CertiRtiAmbassador.java:954)

b. jcerti demo (I will joint the RTIG.log if it can help):
When I run the demo coming with jcerti, the msg for UAVReceive-run is (the run is blocked):
[java] Reflect: text 8
[java] Reflect: 3.1415927
[java] févr. 18, 2019 5:34:43 PM certi.rti.impl.CertiRtiAmbassador translateException
[java] AVERTISSEMENT: Throwing exception: FEDERATES_CURRENTLY_JOINED
[java] févr. 18, 2019 5:34:43 PM certi.UavReceive runFederate
[java] AVERTISSEMENT: Federates currently joined - can't destroy the execution.

And here for UAVSend-run
[java] INFOS: 1. Get a link to the RTI
[java] Object class: 3
[java] Object class: 3
[java] Object handle: 1
[java] Attributes:0

The terminal with the rtig runnig has these last msgs (I killed the rtig):
HLALOG - 1550507701.066498 - NetworkMessage::63 > Deserialize <NM_Destroy_Federation_Execution>
HLALOG - 1550507701.066661 - NetworkMessage::42 > Serialize <NM_Destroy_Federation_Execution>
HLALOG - 1550507701.066694 - NetworkMessage::116 > Sending <NM_Destroy_Federation_Execution> whose buffer has <31> bytes
^CCERTI RTIG exiting.

Do you have any idea which other test, or choice of debug could be done?
I do not know jcerti, so any help will be welcome.

Thank you in advance

(file #46303, file #46304)

janette cardoso <cardoso>
Project MemberIn charge of this item.
Fri 08 Feb 2019 02:24:15 PM UTC, comment #3:

New branch has been created for jcerti.

br_ptII_bug_55592

It contains a patch which correct the usage of short for resign action as mentioned in previous message.

I have only done compilation test therefore, please try with your environment if this fix the problem and report.

to get the branch:
git clone -b br_ptII_bug_55592 <user_name>@git.savannah.nongnu.org:/srv/git/certi/jcerti.git

JbCh <jb_ch>
Project Administrator
Tue 05 Feb 2019 11:17:18 AM UTC, comment #2:

I have found a strange thing in the implementation. Writing this here for documentation.

In jcerti, ResignFederationExecution.java implementation (line 26), the resignAction is set as a "short" entity. In libCERTI, this is an integer.

According to the link below, in Java short is a 2 bytes long entity and int is a 4 bytes long. Can this cause the issue while sending/receiving the resignFederation information/message...I don't know but this can be an issue..?!

http://cs-fundamentals.com/java-programming/java-primitive-data-types.php

JbCh <jb_ch>
Project Administrator
Tue 29 Jan 2019 10:09:03 AM UTC, comment #1:

Hello,

New branch has been created: br_ptII_berkeley

It has been created from previous branch br_ptII_bug_53878. Here you can push all your modifications for this investigation.

JbCh <jb_ch>
Project Administrator
Mon 28 Jan 2019 04:48:47 PM UTC, original submission:

Dear all,

We would like to have a branch in the master for making some test
in JCerti. The reason is the following. I will end with some questions.

The Ptolemy-CERTI framework works well when the models are run (by hand)
by a user.

But we have a problem when we do automatic tests, where 16 federations
are called twice. Approximately one out of 60 executions, JCERTI
deadlocks, blocked waiting for a message on a socket where the message
never comes from CERTI.

Each test that we run launches a new RTIG, creates a federation, creates
one to three federates, runs those federates for some time, checking
that values and time stamps are as expected, then shuts down the
federation and terminates the RTIG. Our test suite has 16 such tests.
Each test, when launched by hand, works fine.

Roughly one out of four runs of the test suite, a federate freezes with
a stack trace like that shown below. Consistently, the freeze occurs at
CertiRtiAmbassador.processRequest(). Interestingly, processRequest()
returns a String that appears to be never used by JCERTI. But JCERTI
nevertheless blocks forever waiting for that string to arrive over the
socket.

Here our questions, if you were patient to read until here:
- Why is the reply to processRequest() never coming over the socket?
- Why is the reply being ignored after it arrives?

In the stack trace below, the freeze happens during
resignFederationExecution(), but we've seen it happen at various other
places in the execution.

"1SubscriberBadAttributeN" #113 prio=1 os_prio=31 tid=0x00007f8567938000
nid=0x8d1b runnable [0x000070000a4ca000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(java.base@10.0.1/Native Method)
at
java.net.SocketInputStream.socketRead(java.base@10.0.1/SocketInputStream.java:116)
at
java.net.SocketInputStream.read(java.base@10.0.1/SocketInputStream.java:171)
at
java.net.SocketInputStream.read(java.base@10.0.1/SocketInputStream.java:141)
at
java.net.SocketInputStream.read(java.base@10.0.1/SocketInputStream.java:224)
at certi.communication.MessageBuffer.receiveData(Unknown Source)
- locked <0x00000006c6f1fb70> (a certi.communication.MessageBuffer)
at certi.communication.MessageFactory.readMessage(Unknown Source)
at certi.rti.impl.CertiRtiAmbassador.processRequest(Unknown Source)
- locked <0x00000006c6f1fb70> (a certi.communication.MessageBuffer)
at certi.rti.impl.CertiRtiAmbassador.resignFederationExecution(Unknown
Source)
at org.hlacerti.lib.HlaManager.wrapup(HlaManager.java:1263)
at ptolemy.actor.CompositeActor.wrapup(CompositeActor.java:2704)
at ptolemy.actor.Manager.wrapup(Manager.java:1512)
at ptolemy.actor.Manager.execute(Manager.java:407)
at ptolemy.actor.Manager.run(Manager.java:1263)
at ptolemy.actor.Manager$PtolemyRunThread.run(Manager.java:1915)

janette cardoso <cardoso>
Project MemberIn charge of this item.

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #46303:  RTIG-br_ptII_berkeley.log added by cardoso (1016B - application/octet-stream - RTIG.log for the jcerti demo)
file #46304:  RTIG-br_ptII_bug_55592.log added by cardoso (1KiB - application/octet-stream - RTIG.log for the jcerti demo)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by cardoso
  • -email is unavailable- added by jb_ch (Posted a comment)
  • -email is unavailable- added by cardoso (Submitted the item)
  • -email is unavailable- added by cardoso
  •  

     

     

    Follow 5 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2019-06-05 cardoso Carbon-Copy- => Added henrick.deschamps@isae-supaero.fr
    2019-02-18 cardoso Attached File- => Added RTIG-br_ptII_berkeley.log, #46303
        Attached File- => Added RTIG-br_ptII_bug_55592.log, #46304
    2019-01-29 jb_ch Assigned toNone => cardoso
    2019-01-28 cardoso Carbon-Copy- => Added eal@berkeley.edu

    Back to the top


    Powered by Savane 3.4