android-basic-samples OnRoomCreated is failing

OnRoomCreated is failing

Open HAL9000Thomas opened this issue 8 years ago • 4 comments

Hello

when I create a new room, the callback onRoomCreated() returns STATUS_NETWORK_ERROR_NO_DATA 5% of the times. I dont know why I get this error sporadic. Some people mentioned that you have to close an room before creating a new one. I always leave my rooms before super.onstop() is called. I also wait for the callback onLeftRoom() before creating a new room. After the error has occurred I have 2 minutes to wait until it works again. Does anyone know why this error occurs?

Steps to reproduce:

Unfortunately I found no way to reproduce it on a specific way. I figured out:

It also happens when I just booted the device.
It can affect just one device or multiple devices at once per game.
It doesn't matter if I play on an emulator or on a real device.
It doesn't matter if I play a automatch-game or a invitation-game.
If i run several emulators at the same time (game-start), it can affect only one emulator (even if they have the same network connection).

Expected behavior

Successfully created a new room.

Relevant logs/screenshots Here is the logcat: (onRoomCreated status:4 = STATUS_NETWORK_ERROR_NO_DATA )

02-21 13:53:31.386: D/MMC(1598): debug onConnected()
02-21 13:53:31.386: D/MMC(1598): debug startgame()
02-21 13:53:31.386: D/MMC(1598): debug makeBasicRoomConfigBuilder()
02-21 13:53:31.558: D/dalvikvm(554): GC_CONCURRENT freed 848K, 15% free 10493K/12295K, paused 15ms+2ms, total 56ms
02-21 13:53:31.594: D/webviewglue(753): nativeDestroy view: 0xb8e21368
02-21 13:53:31.754: I/Ads(1598): Scheduling ad refresh 60000 milliseconds from now.
02-21 13:53:31.762: I/Ads(1598): Ad finished loading.
02-21 13:53:32.258: I/libjingle(1733): Token type:OAuth2
02-21 13:53:32.258: I/libjingle(1733): Final XMPP server hostname talk.google.com port to 5222
02-21 13:53:32.350: I/libjingle(1733): OpenSSLAdapter::OnConnectEvent
02-21 13:53:32.406: D/dalvikvm(554): GC_CONCURRENT freed 776K, 15% free 10467K/12295K, paused 21ms+8ms, total 39ms
02-21 13:53:32.446: I/libjingle(1733): BeginSSL: talk.google.com
02-21 13:53:32.498: W/libjingle(1733): Warning(openssladapter.cc:388): ContinueSSL -- error -1
02-21 13:53:32.498: W/libjingle(1733): Warning(openssladapter.cc:397): OpenSSLAdapter::Error(ContinueSSL, -1)
02-21 13:53:32.518: I/libjingle(1733): SSL Cleanup
02-21 13:53:32.530: I/libjingle(1733): Token type:OAuth2
02-21 13:53:32.530: I/libjingle(1733): Final XMPP server hostname talk.google.com port to 5222
02-21 13:53:32.642: I/libjingle(1733): OpenSSLAdapter::OnConnectEvent
02-21 13:53:32.766: I/libjingle(1733): BeginSSL: talk.google.com
02-21 13:53:32.818: W/libjingle(1733): Warning(openssladapter.cc:388): ContinueSSL -- error -1
02-21 13:53:32.822: W/libjingle(1733): Warning(openssladapter.cc:397): OpenSSLAdapter::Error(ContinueSSL, -1)
02-21 13:53:32.830: D/MMC(1598): debug onRoomCreated status:4
02-21 13:53:32.838: D/Games1pServiceBroker(753): client connected with version: 8283000
02-21 13:53:32.850: D/ChimeraCfgMgr(753): Loading module com.google.android.gms.games from APK com.google.android.play.games
02-21 13:53:32.850: D/ChimeraModuleLdr(753): Module APK com.google.android.play.games already loaded
02-21 13:53:32.858: I/libjingle(1733): SSL Cleanup
02-21 13:53:33.462: I/Ads(1598): Ad is not visible. Not refreshing ad.
02-21 13:53:33.462: I/Ads(1598): Scheduling ad refresh 60000 milliseconds from now.
02-21 13:53:37.874: D/PlayGamesService(753): Unbinding from games service: Intent { act=com.google.android.play.games.service.START_1P pkg=com.google.android.gms }
02-21 13:53:37.874: D/PlayGamesService(753): Removing intent: Intent { act=com.google.android.play.games.service.START_1P pkg=com.google.android.gms }

I am using the code from: https://developers.google.com/games/services/android/realtimeMultiplayer

Excerpt:

private GoogleApiClient mGoogleApiClient;
private String mRoomId;
private final static int RC_WAITING_ROOM = 10002;

@Override
public void onCreate(Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    setContentView(R.layout.activity_multiplayer);
    // Create the Google Api Client with access to Plus and Games
    mGoogleApiClient = new GoogleApiClient.Builder(this)
        .addConnectionCallbacks(this)
        .addOnConnectionFailedListener(this)
        .addApi(Plus.API).addScope(Plus.SCOPE_PLUS_LOGIN)
        .addApi(Games.API).addScope(Games.SCOPE_GAMES)
        .build();
}

private void startQuickGame() {
    Log.d("MMC", "debug startgame()");
    // auto-match criteria to invite one random automatch opponent.
    // You can also specify more opponents (up to 3).
    Bundle am = RoomConfig.createAutoMatchCriteria(2, 6, 0);

    // build the room config:
    RoomConfig.Builder roomConfigBuilder = makeBasicRoomConfigBuilder();
    roomConfigBuilder.setAutoMatchCriteria(am);
    RoomConfig roomConfig = roomConfigBuilder.build();

    // create room:
    Games.RealTimeMultiplayer.create(mGoogleApiClient, roomConfig);

    // prevent screen from sleeping during handshake
    getWindow().addFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);

    // go to game screen
}

// create a RoomConfigBuilder that's appropriate for your implementation
private RoomConfig.Builder makeBasicRoomConfigBuilder() {
    Log.d("MMC", "debug makeBasicRoomConfigBuilder()");
    return RoomConfig.builder(this)
        .setMessageReceivedListener(this)
        .setRoomStatusUpdateListener(this);
}


@Override
public void onRoomCreated(int statusCode, Room room) {
    Log.d("MMC", "debug onRoomCreated status:" + statusCode);
    if (statusCode != GamesStatusCodes.STATUS_OK) {
        // let screen go to sleep
        getWindow().clearFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);
        return;
        // show error message, return to main screen.
    }
    mRoomId = room.getRoomId();
    // get waiting room intent
    Intent i = Games.RealTimeMultiplayer.getWaitingRoomIntent(mGoogleApiClient, room, Integer.MAX_VALUE);
    startActivityForResult(i, RC_WAITING_ROOM);
}

@Override
public void onRoomConnected(int statusCode, Room room) {
    Log.d("MMC", "debug onRoomConnected status:" + statusCode);
    if (statusCode != GamesStatusCodes.STATUS_OK) {
        Log.d("MMC", "debug onRoomConnected error");
        // let screen go to sleep
        getWindow().clearFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);
        // show error message, return to main screen.
    }
}

boolean mPlaying = false;

// at least 2 players required for our game
final static int MIN_PLAYERS = 2;

@Override
public void onActivityResult(int request, int response, Intent intent) {
    Log.d("MMC", "debug onActivityResult()");
    if (request == RC_WAITING_ROOM) {
        if (response == Activity.RESULT_OK) {
            // (start game)         
        }
        else if (response == Activity.RESULT_CANCELED) {
            // in this example, we take the simple approach and just leave the room:
            Games.RealTimeMultiplayer.leave(mGoogleApiClient, this, mRoomId);
            getWindow().clearFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);
        }
        else if (response == GamesActivityResultCodes.RESULT_LEFT_ROOM) {
            // player wants to leave the room.
            Games.RealTimeMultiplayer.leave(mGoogleApiClient, this, mRoomId);
            getWindow().clearFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);
        }
    }
}

@Override
public void onDisconnectedFromRoom(Room room) {
    Log.d("MMC", "debug onDisconnectedFromRoom()");
    // leave the room
    Games.RealTimeMultiplayer.leave(mGoogleApiClient, this, mRoomId);

    // clear the flag that keeps the screen on
    getWindow().clearFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);

    // show error message and return to main screen
}

@Override
public void onLeftRoom(int arg0, String arg1) {
    Log.d("MMC", "debug onLeftRoom() code:" + arg0);
    if(arg1!=null)
        Log.d("MMC", "debug roomId:" + arg1);
    if(!isFinishing())
        finish();       
}

@Override
public void onConnectedToRoom(Room arg0) {
    Log.d("MMC", "debug onConnectedToRoom()");
    Toast.makeText(this, "debug onConnectedToRoom", Toast.LENGTH_SHORT).show();         

}

@Override
public void onConnected(Bundle arg0) {
    // TODO Auto-generated method stub
    Log.d("MMC", "debug onConnected()");
    startQuickGame();
}

@Override
public void onStart() {
    Log.d("MMC", "debug onStart()");
    mGoogleApiClient.connect();
    super.onStart();
}

@Override
public void onStop() {
    Log.d("MMC", "debug onStop()");
    // if we're in a room, leave it.
    leave();
    mGoogleApiClient.disconnect();
    super.onStop();
  }

private void leave(){
    Log.d("MMC", "debug leave()");
    Games.RealTimeMultiplayer.leave(mGoogleApiClient, this, mRoomId);
    getWindow().clearFlags(WindowManager.LayoutParams.FLAG_KEEP_SCREEN_ON);
}

Feb 21 '16 14:02 HAL9000Thomas

With ButtonClicker (unchanged code) i get this error too. I am thankful for each hint why this error occurs.

02-27 10:55:44.343: W/libjingle(1626): Warning(callregistry.cpp:27): void games_rtmp::CallRegistry::UnregisterCall(const string&, const string&): Attempting to erase non-existent session:1153730894
02-27 10:55:44.343: I/libjingle(1626): worker_thread:0xb7bdd4e0 initialized=1
02-27 10:55:44.355: I/libjingle(1626): Channel disabled
02-27 10:55:44.355: I/libjingle(1626): Changing data state, recv=0 send=0
02-27 10:55:44.363: I/libjingle(1626): Destroyed channel
02-27 10:55:44.383: V/GLSActivity(537): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService }
02-27 10:55:44.391: V/GLSActivity(537): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService }
02-27 10:55:44.719: I/libjingle(1626): Parsing Jingle data content
02-27 10:55:44.719: I/libjingle(1626): void gtalk::LibjingleClient::OnCallCreate(cricket::Call*): Connecting to OnAddSession
02-27 10:55:44.719: I/libjingle(1626): Calling Call::IncomingSession()
02-27 10:55:44.719: I/libjingle(1626): AddSession() called. has_data = 1
02-27 10:55:44.719: I/libjingle(1626): Creating data channel.
02-27 10:55:44.719: I/libjingle(1626): Is worker current:0
02-27 10:55:44.719: I/libjingle(1626): Current thread:0xb7c3f920
02-27 10:55:44.719: I/libjingle(1626): worker_thread:0xb7bdd4e0 initialized=1
02-27 10:55:44.719: I/libjingle(1626): Created channel for data
02-27 10:55:44.719: I/libjingle(1626): DataChannel::Init() called
02-27 10:55:44.719: I/libjingle(1626): Setting remote data description
02-27 10:55:44.719: I/libjingle(1626): Added data recv stream '' with ssrc=3755036348
02-27 10:55:44.719: I/libjingle(1626): Add remote ssrc: 3755036348
02-27 10:55:44.719: I/libjingle(1626): DataMediaChannel::SetSendBandwidth to 10485000bps.
02-27 10:55:44.719: I/libjingle(1626): Changing data state, recv=0 send=0
02-27 10:55:44.719: I/libjingle(1626): result = 1
02-27 10:55:44.719: I/libjingle(1626): void gtalk::LibjingleClient::OnAddSession(cricket::Call*, cricket::Session*): OnAddSession called.
02-27 10:55:44.723: I/libjingle(1626): Setting local data description
02-27 10:55:44.723: I/libjingle(1626): Added data send stream '' with ssrc=2649333871
02-27 10:55:44.723: I/libjingle(1626): Add send ssrc: 2649333871
02-27 10:55:44.723: I/libjingle(1626): SRTP reset to init state
02-27 10:55:44.723: I/libjingle(1626): Changing data state, recv=0 send=0
02-27 10:55:44.731: E/libjingle(1626): Error(latencyprober.cpp:83): Peer already added for reliable latency metrics.
02-27 10:55:44.731: I/libjingle(1626): Channel enabled
02-27 10:55:44.731: I/libjingle(1626): Changing data state, recv=1 send=0
02-27 10:55:44.735: I/libjingle(1626): Network Information: All networks
02-27 10:55:44.735: I/libjingle(1626): Name, Description, Prefix, Prefix Length, IP, ignored
02-27 10:55:44.735: I/libjingle(1626): ipv4-default default IPV4 network 0.0.0.0 32 10.0.3.15 0
02-27 10:55:44.735: I/libjingle(1626): eth0 eth0 192.168.169.0 24 192.168.169.101 0
02-27 10:55:44.735: I/libjingle(1626): eth1 eth1 10.0.3.0 24 10.0.3.15 0
02-27 10:55:44.735: I/libjingle(1626): eth0 eth0 fe80:: 64 fe80::a00:27ff:feff:300e 0
02-27 10:55:44.735: I/libjingle(1626): eth1 eth1 fe80:: 64 fe80::a00:27ff:fe12:f895 0
02-27 10:55:44.735: I/libjingle(1626): HttpRequest start: relay.google.com/create_session?username=s%2fLrJfwdW0xfJRKz&password=gdqF%2fWLjK3W2AZA18pjyiIj3&sn=3
02-27 10:55:44.735: I/libjingle(1626): SSL Cleanup
02-27 10:55:44.739: E/libjingle(1626): Error(basicpacketsocketfactory.cc:67): UDP bind failed with error 22
02-27 10:55:44.743: E/libjingle(1626): Error(basicpacketsocketfactory.cc:67): UDP bind failed with error 22
02-27 10:55:44.751: E/libjingle(1626): Error(basicpacketsocketfactory.cc:67): UDP bind failed with error 22
02-27 10:55:44.755: E/libjingle(1626): Error(basicpacketsocketfactory.cc:67): UDP bind failed with error 22
02-27 10:55:44.767: I/libjingle(1626): OpenSSLAdapter::OnConnectEvent
02-27 10:55:44.767: I/libjingle(1626): BeginSSL: relay.google.com
02-27 10:55:44.843: D/ButtonClicker2000(1573): onLeftRoom, code 0
02-27 10:55:44.847: I/libjingle(1626): virtual int games_rtmp::BuzzSubscriptionsTask::SetOnDisconnectTask::ProcessStart(): Send-on-disconnect: <cli:message to="[email protected]" type="headline" xmlns:cli="jabber:client"><push xmlns="google:push" channel="games.google.com/buzzbot" sendOnDisconnect="true"><recipient to="[email protected]" remove="true"/></push></cli:message>
02-27 10:55:44.855: W/libjingle(1626): Warning(libjingleclient.cpp:1175): void gtalk::LibjingleClient::TerminateAllCalls_w(): Terminating call for session:425669904
02-27 10:55:44.867: W/libjingle(1626): Warning(callregistry.cpp:27): void games_rtmp::CallRegistry::UnregisterCall(const string&, const string&): Attempting to erase non-existent session:425669904
02-27 10:55:44.867: I/libjingle(1626): worker_thread:0xb7bdd4e0 initialized=1
02-27 10:55:44.867: I/libjingle(1626): Channel disabled
02-27 10:55:44.867: I/libjingle(1626): Changing data state, recv=0 send=0
02-27 10:55:44.871: I/libjingle(1626): HttpRequest cancelled
02-27 10:55:44.871: I/libjingle(1626): SSL Cleanup
02-27 10:55:44.871: I/libjingle(1626): SSL Cleanup
02-27 10:55:44.871: I/libjingle(1626): Destroyed channel
02-27 10:55:44.875: I/libjingle(1626): worker_thread:0xb7bdd4e0 initialized=1
02-27 10:55:44.875: I/libjingle(1626): SSL Cleanup
02-27 10:55:44.987: D/dalvikvm(735): GC_CONCURRENT freed 1707K, 13% free 13343K/15303K, paused 14ms+1ms, total 165ms
02-27 10:55:50.007: W/genymotion_audio(133): out_write() limiting sleep time 46802 to 39909
02-27 10:55:50.019: V/GLSActivity(537): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService }
02-27 10:55:50.019: V/GLSActivity(537): AuthDelegateWrapperCreated with selected intent: Intent { cmp=com.google.android.gms/.auth.DefaultAuthDelegateService }
02-27 10:55:50.267: D/dalvikvm(537): GC_CONCURRENT freed 927K, 11% free 10835K/12039K, paused 13ms+7ms, total 41ms
02-27 10:55:50.639: I/libjingle(1626): Token type:OAuth2
02-27 10:55:50.639: I/libjingle(1626): Final XMPP server hostname talk.google.com port to 5222
02-27 10:55:50.683: D/dalvikvm(277): GC_CONCURRENT freed 954K, 10% free 12351K/13703K, paused 14ms+1ms, total 79ms
02-27 10:55:50.723: I/libjingle(1626): OpenSSLAdapter::OnConnectEvent
02-27 10:55:50.779: I/libjingle(1626): BeginSSL: talk.google.com
02-27 10:55:50.811: W/libjingle(1626): Warning(openssladapter.cc:388): ContinueSSL -- error -1
02-27 10:55:50.811: W/libjingle(1626): Warning(openssladapter.cc:397): OpenSSLAdapter::Error(ContinueSSL, -1)
02-27 10:55:50.827: I/libjingle(1626): Token type:OAuth2
02-27 10:55:50.827: I/libjingle(1626): Final XMPP server hostname talk.google.com port to 5222
02-27 10:55:50.831: I/libjingle(1626): SSL Cleanup
02-27 10:55:50.863: I/libjingle(1626): OpenSSLAdapter::OnConnectEvent
02-27 10:55:50.915: I/libjingle(1626): BeginSSL: talk.google.com
02-27 10:55:50.943: W/libjingle(1626): Warning(openssladapter.cc:388): ContinueSSL -- error -1
02-27 10:55:50.943: W/libjingle(1626): Warning(openssladapter.cc:397): OpenSSLAdapter::Error(ContinueSSL, -1)
02-27 10:55:50.943: D/ButtonClicker2000(1573): onRoomCreated(4, null)
02-27 10:55:50.943: E/ButtonClicker2000(1573): *** Error: onRoomCreated, status 4
02-27 10:55:50.951: D/dalvikvm(735): WAIT_FOR_CONCURRENT_GC blocked 0ms
02-27 10:55:50.955: I/libjingle(1626): SSL Cleanup
02-27 10:55:50.995: D/dalvikvm(735): GC_EXPLICIT freed 239K, 14% free 13186K/15303K, paused 2ms+1ms, total 45ms
02-27 10:55:51.011: D/ChimeraCfgMgr(735): Loading module com.google.android.gms.games from APK com.google.android.play.games
02-27 10:55:51.011: D/ChimeraModuleLdr(735): Module APK com.google.android.play.games already loaded
02-27 10:55:53.243: I/libjingle(1626): Token type:OAuth2
02-27 10:55:53.243: I/libjingle(1626): Final XMPP server hostname talk.google.com port to 5222
02-27 10:55:53.275: I/libjingle(1626): OpenSSLAdapter::OnConnectEvent
02-27 10:55:53.327: I/libjingle(1626): BeginSSL: talk.google.com
02-27 10:55:53.351: W/libjingle(1626): Warning(openssladapter.cc:388): ContinueSSL -- error -1
02-27 10:55:53.351: W/libjingle(1626): Warning(openssladapter.cc:397): OpenSSLAdapter::Error(ContinueSSL, -1)
02-27 10:55:53.363: I/libjingle(1626): SSL Cleanup
02-27 10:55:53.371: I/libjingle(1626): Token type:OAuth2
02-27 10:55:53.371: I/libjingle(1626): Final XMPP server hostname talk.google.com port to 5222
02-27 10:55:53.403: I/libjingle(1626): OpenSSLAdapter::OnConnectEvent
02-27 10:55:53.459: I/libjingle(1626): BeginSSL: talk.google.com
02-27 10:55:53.487: W/libjingle(1626): Warning(openssladapter.cc:388): ContinueSSL -- error -1
02-27 10:55:53.487: W/libjingle(1626): Warning(openssladapter.cc:397): OpenSSLAdapter::Error(ContinueSSL, -1)
02-27 10:55:53.487: D/ButtonClicker2000(1573): onRoomCreated(4, null)
02-27 10:55:53.487: E/ButtonClicker2000(1573): *** Error: onRoomCreated, status 4
02-27 10:55:53.495: D/ChimeraCfgMgr(735): Loading module com.google.android.gms.games from APK com.google.android.play.games
02-27 10:55:53.495: D/ChimeraModuleLdr(735): Module APK com.google.android.play.games already loaded
02-27 10:55:53.515: I/libjingle(1626): SSL Cleanup
02-27 10:55:59.319: I/GLSUser(848): GLS error: BadAuthentication 191152222268 oauth2:https://www.googleapis.com/auth/games
02-27 10:55:59.319: V/GoogleLoginService(848): Returning error intent with: ComponentInfo{com.google.android.gsf.login/com.google.android.gsf.login.LoginActivity}
02-27 10:55:59.331: W/PlayEventLogger(735): deferring log upload because couldn't retrieve auth token
02-27 10:55:59.343: D/SizeAdaptiveLayout(399): com.android.internal.widget.SizeAdaptiveLayout@53a619b8child view android.widget.FrameLayout@53a6290c measured out of bounds at 95px clamped to 96px

Feb 27 '16 11:02 HAL9000Thomas

My post on stackoverflow got much attention. See: http://stackoverflow.com/q/35531245/4565322 I have not found a solution.

@claywilkinson

Can you explain to me the following error message in more detail?

public static final int STATUS_NETWORK_ERROR_NO_DATA A network error occurred while attempting to retrieve fresh data, and no data was available locally.

THX in advance.

Mar 15 '16 15:03 HAL9000Thomas

I have the same player drop outs as you describe. On a four-player match, I just had one device drop out. The device that dropped out had this in the log:

Warning(libjingleclient.cpp:1175): void gtalk::LibjingleClient::TerminateAllCalls_w(): Terminating call for session:3769222648

This warning is present in your last log as well. I wonder if that's the culprit. Why is libjingle closing down all calls?

Maybe WIFI disconnected, and caused libjingle to close down everything?

Also, are you using the C++ or Java API for Google Play Games? I am on C++.

Jul 05 '17 01:07 stolk

Also, I noticed a suspicious URL:

HttpRequest start: relay.google.com/create_session?username=s%2fLrJfwdW0xfJRKz&password=gdqF%2fWLjK3W2AZA18pjyiIj3&sn=3

The username has a '%2f' in it, and the password too. This is the '/' character. I wonder if the issues in Google Play Games are caused by these invalid username/password values?

Jul 18 '17 01:07 stolk

android-basic-samples android-basic-samples copied to clipboard

OnRoomCreated is failing

android-basic-samples
android-basic-samples copied to clipboard