{"action":"created","issue":{"url":"https://api.github.com/repos/RestComm/RestComm-Core/issues/788","labels_url":"https://api.github.com/repos/RestComm/RestComm-Core/issues/788/labels{/name}","comments_url":"https://api.github.com/repos/RestComm/RestComm-Core/issues/788/comments","events_url":"https://api.github.com/repos/RestComm/RestComm-Core/issues/788/events","html_url":"https://github.com/RestComm/RestComm-Core/issues/788","id":126465598,"number":788,"title":"Using conference-app.zip application with Dialogic JSR 309 Connector and XMS error in a play: cant perform play no MIXER or NC found associated to this IVR container","user":{"login":"RomanDS","id":10065295,"avatar_url":"https://avatars.githubusercontent.com/u/10065295?v=3","gravatar_id":"","url":"https://api.github.com/users/RomanDS","html_url":"https://github.com/RomanDS","followers_url":"https://api.github.com/users/RomanDS/followers","following_url":"https://api.github.com/users/RomanDS/following{/other_user}","gists_url":"https://api.github.com/users/RomanDS/gists{/gist_id}","starred_url":"https://api.github.com/users/RomanDS/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/RomanDS/subscriptions","organizations_url":"https://api.github.com/users/RomanDS/orgs","repos_url":"https://api.github.com/users/RomanDS/repos","events_url":"https://api.github.com/users/RomanDS/events{/privacy}","received_events_url":"https://api.github.com/users/RomanDS/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/RestComm/RestComm-Core/labels/1.%20Bug","name":"1. Bug","color":"fc2929"},{"url":"https://api.github.com/repos/RestComm/RestComm-Core/labels/XMS-1.0.0","name":"XMS-1.0.0","color":"006b75"}],"state":"open","locked":false,"assignee":{"login":"hrosa","id":7796608,"avatar_url":"https://avatars.githubusercontent.com/u/7796608?v=3","gravatar_id":"","url":"https://api.github.com/users/hrosa","html_url":"https://github.com/hrosa","followers_url":"https://api.github.com/users/hrosa/followers","following_url":"https://api.github.com/users/hrosa/following{/other_user}","gists_url":"https://api.github.com/users/hrosa/gists{/gist_id}","starred_url":"https://api.github.com/users/hrosa/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/hrosa/subscriptions","organizations_url":"https://api.github.com/users/hrosa/orgs","repos_url":"https://api.github.com/users/hrosa/repos","events_url":"https://api.github.com/users/hrosa/events{/privacy}","received_events_url":"https://api.github.com/users/hrosa/received_events","type":"User","site_admin":false},"milestone":{"url":"https://api.github.com/repos/RestComm/RestComm-Core/milestones/8","html_url":"https://github.com/RestComm/RestComm-Core/milestones/7.5.0","labels_url":"https://api.github.com/repos/RestComm/RestComm-Core/milestones/8/labels","id":1211253,"number":8,"title":"7.5.0","description":"","creator":{"login":"deruelle","id":54279,"avatar_url":"https://avatars.githubusercontent.com/u/54279?v=3","gravatar_id":"","url":"https://api.github.com/users/deruelle","html_url":"https://github.com/deruelle","followers_url":"https://api.github.com/users/deruelle/followers","following_url":"https://api.github.com/users/deruelle/following{/other_user}","gists_url":"https://api.github.com/users/deruelle/gists{/gist_id}","starred_url":"https://api.github.com/users/deruelle/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/deruelle/subscriptions","organizations_url":"https://api.github.com/users/deruelle/orgs","repos_url":"https://api.github.com/users/deruelle/repos","events_url":"https://api.github.com/users/deruelle/events{/privacy}","received_events_url":"https://api.github.com/users/deruelle/received_events","type":"User","site_admin":false},"open_issues":41,"closed_issues":70,"state":"open","created_at":"2015-07-16T13:41:29Z","updated_at":"2016-01-14T10:49:42Z","due_on":"2016-01-28T22:00:00Z","closed_at":null},"comments":13,"created_at":"2016-01-13T17:02:19Z","updated_at":"2016-01-14T18:47:53Z","closed_at":null,"body":"Issue seems to be related to the fact that conference application issues playAsync before the join between MG and NC is completed. The Join (unlike JoinInitiate) is blocking function so it should hold until it completes. The question seems to be around a play which seems to be executed on a different thread. \r\nQ: How are the two synchronized to make sure play request does not get called before Join completes?\r\n\r\nBellow is an extract with timestamps of the analysis of the logs which are attached:\r\n\r\n[server.zip](https://github.com/RestComm/RestComm-Core/files/89217/server.zip)\r\n\r\n09:58:30,276 ERROR [com.vendor.dialogic.javax.media.mscontrol.mediagroup.DlgcPlayer - 117] \r\n(MSS-Executor-Thread-9) \r\nDlgcPlayer::play cant perform play no MIXER or NC found associated to this IVR containe\r\n\r\nXNC-2b99d4c75f1f4 join with XMG-2b99d49565235\r\n\r\n\r\nMSS-Executor-Thread-0 (join)\r\nTimeline:\r\n\r\n09:58:30,247    line 6147 - XNC-2b99d4c75f1f4 Enter join with XMG-2b99d49565235 - Executor-Thread-0\r\n\r\n09:58:30,261      line 6283 - request to playAsync Proxy (XMG-2b99d49565235) MSS-Executor-Thread-9\r\n\r\n09:58:30,265      line 6365 -  DlgcProxyHelper joinAsyncWithValidation :326 - Executor-Thread-0\r\n\r\n09:58:30,276      line 6547 - Play Starts Error reported - MSS-Executor-Thread-9\r\n\r\n09:58:30,323      line 7068 - Join returns complete - MSS-Executor-Thread-0\r\n\r\n09:58:30,339    line 7072 - WARN  [org.mobicents.servlet.sip.core.session.SipApplicationSessionImpl - 1390] \r\n(MSS-Executor-Thread-0) \r\nAbout to release semaphore but we expected permits = 0. \r\nWe will adjust to normal java.util.concurrent.Semaphore@2256eb0f[Permits = 1] \r\napp session=ba2a3a01;RestComm\r\n"},"comment":{"url":"https://api.github.com/repos/RestComm/RestComm-Core/issues/comments/171736114","html_url":"https://github.com/RestComm/RestComm-Core/issues/788#issuecomment-171736114","issue_url":"https://api.github.com/repos/RestComm/RestComm-Core/issues/788","id":171736114,"user":{"login":"RomanDS","id":10065295,"avatar_url":"https://avatars.githubusercontent.com/u/10065295?v=3","gravatar_id":"","url":"https://api.github.com/users/RomanDS","html_url":"https://github.com/RomanDS","followers_url":"https://api.github.com/users/RomanDS/followers","following_url":"https://api.github.com/users/RomanDS/following{/other_user}","gists_url":"https://api.github.com/users/RomanDS/gists{/gist_id}","starred_url":"https://api.github.com/users/RomanDS/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/RomanDS/subscriptions","organizations_url":"https://api.github.com/users/RomanDS/orgs","repos_url":"https://api.github.com/users/RomanDS/repos","events_url":"https://api.github.com/users/RomanDS/events{/privacy}","received_events_url":"https://api.github.com/users/RomanDS/received_events","type":"User","site_admin":false},"created_at":"2016-01-14T18:47:52Z","updated_at":"2016-01-14T18:47:52Z","body":"Hi Henrique,\r\nI added John Cruz who is our JSR 309 developer as he has been working with me on these issues in a back end.\r\n\r\nFrom what we see, it is a join between NC to MG. Here is the timeline which I had referenced before. Take a look at the timeline were showed before:\r\n\r\n\r\nTimeline:\r\n\r\na)\r\n\r\n09:58:30,247 line 6147 - XNC-2b99d4c75f1f4 Enter join with XMG-2b99d49565235 - Executor-Thread-0\r\n\r\nb)\r\n\r\n09:58:30,261 line 6283 - request to playAsync Proxy (XMG-2b99d49565235) MSS-Executor-Thread-9\r\n\r\nc)\r\n\r\n09:58:30,265 line 6365 - DlgcProxyHelper joinAsyncWithValidation :326 - Executor-Thread-0\r\n\r\nd)\r\n\r\n09:58:30,276 line 6547 - Play Starts Error reported - MSS-Executor-Thread-9\r\n\r\ne)\r\n\r\n09:58:30,323 line 7068 - Join returns complete - MSS-Executor-Thread-0\r\n\r\nf)\r\n\r\n09:58:30,339 line 7072 - WARN org.mobicents.servlet.sip.core.session.SipApplicationSessionImpl - 1390<https://github.com/RestComm/RestComm-Core/issues/MSS-Executor-Thread-0>\r\nAbout to release semaphore but we expected permits = 0.\r\nWe will adjust to normal java.util.concurrent.Semaphore@2256eb0<https://github.com/java.util.concurrent.Semaphore/RestComm-Core/commit/2256eb0f>[Permits = 1]\r\napp session=ba2a3a01;RestComm\r\n\r\na) is when a join gets called by an application. Note the Thread ID\r\nb) is where a play request is executed by an application. Here note a different Thread ID\r\nc) is where join is executed by connector and it should  be blocking the application join method\r\nd) is where play error is reported\r\ne) is where the join is actually completed\r\nf) we spotted some WARN message – not sure if that has any bearing on the situation.\r\n\r\nPlease review the above.\r\n\r\nIs there a way to enable logging for the application so we can track the state transition from before join to after join before the play? I think we need to make sure that play for sure does not get ran before join completes. Otherwise there is an issue with a lock where it sometimes does not work… I would hate to think that this is where the problem lies.\r\n\r\nBest regards,\r\nRoman\r\n\r\nFrom: Henrique Rosa [mailto:notifications@github.com]\r\nSent: Thursday, January 14, 2016 1:29 PM\r\nTo: RestComm/RestComm-Core <RestComm-Core@noreply.github.com>\r\nCc: Roman Stobnicki <Roman.Stobnicki@dialogic.com>\r\nSubject: Re: [RestComm-Core] Using conference-app.zip application with Dialogic JSR 309 Connector and XMS error in a play: cant perform play no MIXER or NC found associated to this IVR container (#788)\r\n\r\n\r\nJust thinking out loud here: is it possible this issue can happen when you ask the conference to play the beep and one of the call legs is in the process of unjoining from the conference mixer? In that particular case, the call connection isn't joined to a mixer nor a media group.\r\n\r\nIt's the only scenario I can think of at the moment.\r\n\r\n—\r\nReply to this email directly or view it on GitHub<https://github.com/RestComm/RestComm-Core/issues/788#issuecomment-171731435>.\r\n"}}