bugCERTI - Bugs: bug #55747, Behavior of JCERTI demo...

 
 

bug #55747: Behavior of JCERTI demo (UAVSend-run, UAVReceive-run)

Submitter:  janette cardoso <cardoso>
Submitted:  Wed 20 Feb 2019 01:21:37 PM UTC
   
 
Category:  JavaCERTI Severity:  * 2 - Minor
Item Group:  Action request Status:  Fixed
Privacy:  Public Assigned to:  jb_ch
Open/Closed:  Open Release:  * GIT-master
Reproducibility:  Once Fixed Release:  * GIT-master
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Fri 08 Mar 2019 11:07:36 AM UTC, comment #6: 

Hello,
I pushed a small fix on  branch br_ptII_berkeley, commit cdfc1c42f08. Could someone test and provide a feedback?

    Adding rtia.closeConnexion() after rtia.destroyFederationExecution in Jcerti
    demo; rtia processes are not alive and federates stop their running.

janette cardoso <cardoso>
Group Member
Fri 01 Mar 2019 08:47:49 AM UTC, comment #5: 

Hello,
May be some fixes that you made could be pushed to the master. I also suggest the fixed introduced in 7e6d443b225c82e br_ptII_berkeley (about the way the fed file is passed to createFederation).

Before close this ticket, could you please take a look in the question 2 of this ticket, concerning the destruction of the rtia?

janette cardoso <cardoso>
Group Member
Fri 01 Mar 2019 08:36:30 AM UTC, comment #4: 

I am closing this ticket, considering as fixed.

I will soon have to do a clean-up of jcerti branches because it's getting messy.



JbCh <jb_ch>
Group administrator
Thu 28 Feb 2019 01:20:43 PM UTC, comment #3: 

Hello JB,
Thanks a lot. I applied the patch to the branch br_ptII_berkeley.

So now, this branch has the patches from br_bug_53878 and br_bug_55747. The difference is the way the fed file is passed in createFederationExecution().

janette cardoso <cardoso>
Group Member
Thu 28 Feb 2019 12:15:44 AM UTC, comment #2: 

Hello,

There is no problem in the demo, the destruction of the federation works fine but as already discussed, there is (I think) an issue with the LOGGER which has strange behaviour when the RTIA process is launched.

I have implemented a new branch br_bug_55747 which:
- Remove the usage of the LOGGER, replaced per system prints.
- Add time management and sync points mechanisms for the Java demo
- Note: there is NO CHANGE of the previous hla usage for create/join/resign/destroy calls.

In this new demo, federates are going from Logical Time 0.0 to 20.0 per increment of 1.0 using TAR mechanism.

You will see that the federation is perfectly terminated with:
 --> 8 Destroy federation execution - nofail


JbCh <jb_ch>
Group administrator
Thu 21 Feb 2019 09:15:48 AM UTC, comment #1: 

CERTI 4.0.0 : master:d6b48f36d81
JCERTI: br_ptII_berkeley

Adding some additional information running the rtig with debug:
RTIG=ACDEGIMPRSTWXZ rtig

When the federation is blocked, I did: kill -3 15989
With
15989 ttys005    0:00.48 /Library/Java/JavaVirtualMachines/jdk1.8.0_144.jdk/Contents/Home/jre/bin/java -classpath /Users/j.cardoso/logiciels/jcerti/br_ptII_berkeley/jcerti/build/jar/jcerti.jar:/Users/j.cardoso/logiciels/jcerti/br_ptII_berkeley/jcerti/build/class_test certi.UavSend  1

Then there is in the trace:
     [java] - locked <0x000000076b1666f0> (a java.io.InputStreamReader)
     [java] at java.io.BufferedReader.readLine(BufferedReader.java:389)
     [java] at certi.logging.StreamListener.run(StreamListener.java:44)

The log of the rtig is:
(...)
HLALOG - 1550739721.159903  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:203 > Incoming message on socket 7
HLALOG - 1550739721.160203  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:480 > Caught Exception: DeletePrivilegeNotHeld -
HLALOG - 1550739721.160332  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:494 > RTIG caught exception 19 and sent it back to federate 2
HLALOG - 1550739721.160548  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:203 > Incoming message on socket 7
HLALOG - 1550739721.160664  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/MessageProcessor.cc:228 > Federate (2) leaves federation (1)
HLALOG - 1550739721.160729  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/MessageProcessor.cc:233 > Federate 2 is resigning from federation 1

(...)
HLALOG - 1550739741.249323  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:203 > Incoming message on socket 6
HLALOG - 1550739741.249403  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/MessageProcessor.cc:228 > Federate (1) leaves federation (1)
HLALOG - 1550739741.249462  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/MessageProcessor.cc:233 > Federate 1 is resigning from federation 1
HLALOG - 1550739741.249519  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:444 > 1 responses
HLALOG - 1550739741.249550  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:446 > Send back NM_Resign_Federation_Execution to 1 federates
HLALOG - 1550739741.249583  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:449 > to 6
HLALOG - 1550739741.250515  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:203 > Incoming message on socket 6
HLALOG - 1550739741.250778  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/MessageProcessor.cc:257 > Federation "uav" has been destroyed
HLALOG - 1550739741.250861  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:444 > 1 responses
HLALOG - 1550739741.250892  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:446 > Send back NM_Destroy_Federation_Execution to 1 federates
HLALOG - 1550739741.250926  - /Users/j.cardoso/logiciels/pthla/masterCerti/certi-4.0.0/RTIG/RTIG.cc:449 > to 6



janette cardoso <cardoso>
Group Member
Wed 20 Feb 2019 01:21:37 PM UTC, original submission:  

Dear all,

I have 2 questions concerning the demo shipped with Jcerti:

1. Could someone take a look in  the way the federation is destroyed? It seems
there is a problem. I put at the end the messages received using jcerti master. They
are the same using branch br_bug_53878 and br_ptII_berkeley.
By the way, the LOGGER.info works only for the first step ( 1. Get a link...).

2. Did you already implemented the "deletion" of the rtia? We are using
_rtia.closeConnexion() . Is there another way to implement the destruction?
Is it possible to implement the correct way to disconnect the rtia in this demo?

The reason: I would like to run an automatic test with this demo for checking if
after a big number (~60) of executions, we find the same problem described in
"bug" #55592 (approximately one out of 60 executions, JCERTI
deadlocks, blocked waiting for a message on a socket where the message
never comes from CERTI. In this situation, there are 2 RTIA processes running,
certainly because there are 2 federates.)
This would help to check if this issue is related to Ptolemy, Jcerti, or Java.

Thank you

---- Messages printed in the different terminals ----
Lines printed by RTIA_FM=D are the ones with the date.

1. In the terminal UAVSend-run is running (federate is stuck)   
UAVSend-run:
     [java] févr. 20, 2019 1:05:55 PM certi.UavSend runFederate
     [java] INFOS:         UAV-SEND
     [java] févr. 20, 2019 1:05:55 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   
    
2.  In the terminal UAVReceive-run is running (federate is stuck)
UAVReceive-run:
     [java] févr. 20, 2019 1:06:08 PM certi.UavReceive runFederate
     (...)
     [java] Reflect: text 4
     [java] Reflect: 3.1415927
     [java] févr. 20, 2019 1:06:22 PM certi.rti.impl.CertiRtiAmbassador translateException
     [java] AVERTISSEMENT: Throwing exception: FEDERATES_CURRENTLY_JOINED
     [java] févr. 20, 2019 1:06:22 PM certi.UavReceive runFederate
     [java] AVERTISSEMENT: Federates currently joined - can't destroy the execution.

3. Last messages in the terminal the rtig is running (export RTIG_MSG=D):
HLALOG - 1550664392.807359  - NetworkMessage::116 > Sending <NM_Resign_Federation_Execution> whose buffer has <24> bytes
HLALOG - 1550664392.808266  - NetworkMessage::143 > Got a MsgBuf of size 31 bytes (including  reserved)
HLALOG - 1550664392.808310  - NetworkMessage::63 > Deserialize <NetworkMessage (generic)>
HLALOG - 1550664392.808346  - NetworkMessage::63 > Deserialize <NM_Destroy_Federation_Execution>
HLALOG - 1550664392.808564  - NetworkMessage::42 > Serialize <NM_Destroy_Federation_Execution>
HLALOG - 1550664392.808611  - NetworkMessage::116 > Sending <NM_Destroy_Federation_Execution> whose buffer has <31> bytes

4. In another terminal, we can see there are 2 rtia processes running.
13518 ttys002    0:00.02 rtia -p 52134
13532 ttys003    0:00.01 rtia -p 52141

janette cardoso <cardoso>
Group Member

 

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

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -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
  • -email is unavailable- added by cardoso
  •  

    Follow 9 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2019-03-01 jb_ch Open/ClosedClosed Open
    2019-03-01 jb_ch StatusWorks For Me Fixed
        Open/ClosedOpen Closed
    2019-02-28 jb_ch Severity3 - Normal 2 - Minor
        StatusNone Works For Me
        Assigned toNone jb_ch
        ReproducibilityNone Once
    2019-02-20 cardoso Carbon-Copy- Added -email is unavailable-
        Carbon-Copy- Added -email is unavailable-

    Back to the top

    Powered by Savane 3.13-758e.
    Corresponding source code