lots of logging; handle GCM messages for device as well as for a

single game; tweak for more reliable connection or messages to help
diagnose.
This commit is contained in:
Eric House 2013-08-27 07:57:36 -07:00
parent a7d5d261d3
commit 668cc27f35
2 changed files with 88 additions and 47 deletions

View file

@ -59,6 +59,7 @@ public class GCMIntentService extends GCMBaseIntentService {
@Override @Override
protected void onMessage( Context context, Intent intent ) protected void onMessage( Context context, Intent intent )
{ {
DbgUtils.logf( "GCMIntentService.onMessage()" );
String value; String value;
boolean ignoreIt = XWPrefs.getGCMIgnored( this ); boolean ignoreIt = XWPrefs.getGCMIgnored( this );
if ( ignoreIt ) { if ( ignoreIt ) {
@ -79,17 +80,19 @@ public class GCMIntentService extends GCMBaseIntentService {
value = intent.getStringExtra( "msgs64" ); value = intent.getStringExtra( "msgs64" );
if ( null != value ) { if ( null != value ) {
String connname = intent.getStringExtra( "connname" ); String connname = intent.getStringExtra( "connname" );
if ( null != connname ) { try {
try { JSONArray msgs64 = new JSONArray( value );
JSONArray msgs64 = new JSONArray( value ); String[] strs64 = new String[msgs64.length()];
String[] strs64 = new String[msgs64.length()]; for ( int ii = 0; ii < strs64.length; ++ii ) {
for ( int ii = 0; ii < strs64.length; ++ii ) { strs64[ii] = msgs64.optString(ii);
strs64[ii] = msgs64.optString(ii);
}
RelayService.processMsgs( context, connname, strs64 );
} catch (org.json.JSONException jse ) {
DbgUtils.loge( jse );
} }
if ( null == connname ) {
RelayService.processDevMsgs( context, strs64 );
} else {
RelayService.processGameMsgs( context, connname, strs64 );
}
} catch (org.json.JSONException jse ) {
DbgUtils.loge( jse );
} }
} }

View file

@ -64,7 +64,8 @@ public class RelayService extends XWService
// These should be enums // These should be enums
private static enum MsgCmds { INVALID private static enum MsgCmds { INVALID
, PROCESS_MSGS , PROCESS_GAME_MSGS
, PROCESS_DEV_MSGS
, UDP_CHANGED , UDP_CHANGED
, SEND , SEND
, RECEIVE , RECEIVE
@ -92,7 +93,7 @@ public class RelayService extends XWService
private short m_maxIntervalSeconds = 5; // give time to get real value private short m_maxIntervalSeconds = 5; // give time to get real value
private long m_lastGamePacketReceived; private long m_lastGamePacketReceived;
// These must match the enum XWRelayReg in xwrelay.h // These must match the enum XWPDevProto in xwrelay.h
private static enum XWPDevProto { XWPDEV_PROTO_VERSION_INVALID private static enum XWPDevProto { XWPDEV_PROTO_VERSION_INVALID
,XWPDEV_PROTO_VERSION_1 ,XWPDEV_PROTO_VERSION_1
}; };
@ -177,15 +178,23 @@ public class RelayService extends XWService
startService( context ); startService( context );
} }
public static void processMsgs( Context context, String relayId, public static void processGameMsgs( Context context, String relayId,
String[] msgs64 ) String[] msgs64 )
{ {
Intent intent = getIntentTo( context, MsgCmds.PROCESS_MSGS ) DbgUtils.logf( "RelayService.processGameMsgs" );
Intent intent = getIntentTo( context, MsgCmds.PROCESS_GAME_MSGS )
.putExtra( MSGS, msgs64 ) .putExtra( MSGS, msgs64 )
.putExtra( RELAY_ID, relayId ); .putExtra( RELAY_ID, relayId );
context.startService( intent ); context.startService( intent );
} }
public static void processDevMsgs( Context context, String[] msgs64 )
{
Intent intent = getIntentTo( context, MsgCmds.PROCESS_DEV_MSGS )
.putExtra( MSGS, msgs64 );
context.startService( intent );
}
private static Intent getIntentTo( Context context, MsgCmds cmd ) private static Intent getIntentTo( Context context, MsgCmds cmd )
{ {
Intent intent = new Intent( context, RelayService.class ); Intent intent = new Intent( context, RelayService.class );
@ -230,7 +239,7 @@ public class RelayService extends XWService
DbgUtils.logf( "RelayService::onStartCommand: cmd=%s", DbgUtils.logf( "RelayService::onStartCommand: cmd=%s",
cmd.toString() ); cmd.toString() );
switch( cmd ) { switch( cmd ) {
case PROCESS_MSGS: case PROCESS_GAME_MSGS:
String[] relayIDs = new String[1]; String[] relayIDs = new String[1];
relayIDs[0] = intent.getStringExtra( RELAY_ID ); relayIDs[0] = intent.getStringExtra( RELAY_ID );
long[] rowIDs = DBUtils.getRowIDsFor( this, relayIDs[0] ); long[] rowIDs = DBUtils.getRowIDsFor( this, relayIDs[0] );
@ -245,6 +254,9 @@ public class RelayService extends XWService
process( msgs, rowIDs, relayIDs ); process( msgs, rowIDs, relayIDs );
} }
break; break;
case PROCESS_DEV_MSGS:
DbgUtils.logf( "dropping dev msg for now" );
break;
case UDP_CHANGED: case UDP_CHANGED:
startThreads(); startThreads();
break; break;
@ -345,15 +357,19 @@ public class RelayService extends XWService
private void stopFetchThreadIf() private void stopFetchThreadIf()
{ {
if ( null != m_fetchThread ) { while ( null != m_fetchThread ) {
DbgUtils.logf( "2: m_fetchThread NOT NULL; WHAT TO DO???" ); DbgUtils.logf( "2: m_fetchThread NOT NULL; WHAT TO DO???" );
m_fetchThread.stop(); try {
m_fetchThread = null; Thread.sleep( 20 );
} catch( java.lang.InterruptedException ie ) {
DbgUtils.loge( ie );
}
} }
} }
private void startUDPThreadsIfNot() private void startUDPThreadsIfNot()
{ {
DbgUtils.logf( "RelayService.startUDPThreadsIfNot()" );
if ( XWPrefs.getUDPEnabled( this ) ) { if ( XWPrefs.getUDPEnabled( this ) ) {
if ( null == m_UDPReadThread ) { if ( null == m_UDPReadThread ) {
@ -363,7 +379,7 @@ public class RelayService extends XWService
connectSocket(); // block until this is done connectSocket(); // block until this is done
startWriteThread(); startWriteThread();
DbgUtils.logf( "read thread running" ); DbgUtils.logf( "RelayService:read thread running" );
byte[] buf = new byte[1024]; byte[] buf = new byte[1024];
for ( ; ; ) { for ( ; ; ) {
DatagramPacket packet = DatagramPacket packet =
@ -371,13 +387,15 @@ public class RelayService extends XWService
try { try {
m_UDPSocket.receive( packet ); m_UDPSocket.receive( packet );
resetExitTimer(); resetExitTimer();
gotPacket( packet );
} catch ( java.io.InterruptedIOException iioe ) {
DbgUtils.logf( "FYI: udp receive timeout" );
} catch( java.io.IOException ioe ) { } catch( java.io.IOException ioe ) {
DbgUtils.loge( ioe ); DbgUtils.loge( ioe );
break; // ??? break; // ???
} }
gotPacket( packet );
} }
DbgUtils.logf( "read thread exiting" ); DbgUtils.logf( "RelayService:read thread exiting" );
} }
}, getClass().getName() ); }, getClass().getName() );
m_UDPReadThread.start(); m_UDPReadThread.start();
@ -385,6 +403,8 @@ public class RelayService extends XWService
DbgUtils.logf( "m_UDPReadThread not null and assumed to " DbgUtils.logf( "m_UDPReadThread not null and assumed to "
+ "be running" ); + "be running" );
} }
} else {
DbgUtils.logf( "RelayService.startUDPThreadsIfNot(): UDP disabled" );
} }
} // startUDPThreadsIfNot } // startUDPThreadsIfNot
@ -396,6 +416,7 @@ public class RelayService extends XWService
String host = XWPrefs.getDefaultRelayHost( this ); String host = XWPrefs.getDefaultRelayHost( this );
try { try {
m_UDPSocket = new DatagramSocket(); m_UDPSocket = new DatagramSocket();
m_UDPSocket.setSoTimeout(30 * 1000); // timeout so we can log
// put on background thread!! // put on background thread!!
InetAddress addr = InetAddress.getByName( host ); InetAddress addr = InetAddress.getByName( host );
m_UDPSocket.connect( addr, port ); // remember this address m_UDPSocket.connect( addr, port ); // remember this address
@ -416,7 +437,7 @@ public class RelayService extends XWService
if ( null == m_UDPWriteThread ) { if ( null == m_UDPWriteThread ) {
m_UDPWriteThread = new Thread( null, new Runnable() { m_UDPWriteThread = new Thread( null, new Runnable() {
public void run() { public void run() {
DbgUtils.logf( "write thread running" ); DbgUtils.logf( "RelayService: write thread running" );
for ( ; ; ) { for ( ; ; ) {
DatagramPacket outPacket; DatagramPacket outPacket;
try { try {
@ -431,10 +452,11 @@ public class RelayService extends XWService
DbgUtils.logf( "stopping write thread" ); DbgUtils.logf( "stopping write thread" );
break; break;
} }
DbgUtils.logf( "Sending udp packet of length %d",
outPacket.getLength() );
try { try {
m_UDPSocket.send( outPacket ); m_UDPSocket.send( outPacket );
DbgUtils.logf( "Sent udp packet of length %d",
outPacket.getLength() );
resetExitTimer(); resetExitTimer();
ConnStatusHandler.showSuccessOut(); ConnStatusHandler.showSuccessOut();
} catch ( java.io.IOException ioe ) { } catch ( java.io.IOException ioe ) {
@ -443,7 +465,7 @@ public class RelayService extends XWService
DbgUtils.logf( "network problem; dropping packet" ); DbgUtils.logf( "network problem; dropping packet" );
} }
} }
DbgUtils.logf( "write thread exiting" ); DbgUtils.logf( "RelayService: write thread exiting" );
} }
}, getClass().getName() ); }, getClass().getName() );
m_UDPWriteThread.start(); m_UDPWriteThread.start();
@ -484,21 +506,17 @@ public class RelayService extends XWService
DbgUtils.logf( "stopUDPThreadsIf DONE" ); DbgUtils.logf( "stopUDPThreadsIf DONE" );
} }
// Running on reader thread // MIGHT BE Running on reader thread
private void gotPacket( DatagramPacket packet ) private void gotPacket( byte[] data, boolean skipAck )
{ {
ConnStatusHandler.showSuccessIn();
int packetLen = packet.getLength();
byte[] data = new byte[packetLen];
System.arraycopy( packet.getData(), 0, data, 0, packetLen );
DbgUtils.logf( "RelayService::gotPacket: %d bytes of data", packetLen );
ByteArrayInputStream bis = new ByteArrayInputStream( data ); ByteArrayInputStream bis = new ByteArrayInputStream( data );
DataInputStream dis = new DataInputStream( bis ); DataInputStream dis = new DataInputStream( bis );
try { try {
PacketHeader header = readHeader( dis ); PacketHeader header = readHeader( dis );
if ( null != header ) { if ( null != header ) {
sendAckIf( header ); if ( !skipAck ) {
sendAckIf( header );
}
DbgUtils.logf( "gotPacket: cmd=%s", header.m_cmd.toString() ); DbgUtils.logf( "gotPacket: cmd=%s", header.m_cmd.toString() );
switch ( header.m_cmd ) { switch ( header.m_cmd ) {
case XWPDEV_UNAVAIL: case XWPDEV_UNAVAIL:
@ -536,8 +554,6 @@ public class RelayService extends XWService
m_lastGamePacketReceived = Utils.getCurSeconds(); m_lastGamePacketReceived = Utils.getCurSeconds();
int token = dis.readInt(); int token = dis.readInt();
byte[] msg = new byte[dis.available()]; byte[] msg = new byte[dis.available()];
Assert.assertTrue( packet.getLength() >= msg.length );
Assert.assertTrue( packetLen >= msg.length );
dis.read( msg ); dis.read( msg );
postData( RelayService.this, token, msg ); postData( RelayService.this, token, msg );
break; break;
@ -552,19 +568,32 @@ public class RelayService extends XWService
} catch ( java.io.IOException ioe ) { } catch ( java.io.IOException ioe ) {
DbgUtils.loge( ioe ); DbgUtils.loge( ioe );
} }
}
private void gotPacket( DatagramPacket packet )
{
ConnStatusHandler.showSuccessIn();
int packetLen = packet.getLength();
byte[] data = new byte[packetLen];
System.arraycopy( packet.getData(), 0, data, 0, packetLen );
DbgUtils.logf( "RelayService::gotPacket: %d bytes of data", packetLen );
gotPacket( data, false );
} // gotPacket } // gotPacket
private void registerWithRelay() private void registerWithRelay()
{ {
DbgUtils.logf( "registerWithRelay" ); DbgUtils.logf( "registerWithRelay" );
byte[] typ = new byte[1]; DevIDType[] typ = new DevIDType[1];
String devid = getDevID(typ); String devid = getDevID( typ );
ByteArrayOutputStream bas = new ByteArrayOutputStream(); ByteArrayOutputStream bas = new ByteArrayOutputStream();
try { try {
DataOutputStream out = addProtoAndCmd( bas, XWRelayReg.XWPDEV_REG ); DataOutputStream out = addProtoAndCmd( bas, XWRelayReg.XWPDEV_REG );
out.writeByte( typ[0] ); out.writeByte( typ[0].ordinal() );
writeVLIString( out, devid ); writeVLIString( out, devid );
DbgUtils.logf( "registering devID \"%s\" (type=%s)", devid,
typ[0].toString() );
out.writeShort( GitVersion.CLIENT_VERS_RELAY ); out.writeShort( GitVersion.CLIENT_VERS_RELAY );
writeVLIString( out, GitVersion.VERS ); writeVLIString( out, GitVersion.VERS );
@ -580,10 +609,12 @@ public class RelayService extends XWService
{ {
ByteArrayOutputStream bas = new ByteArrayOutputStream(); ByteArrayOutputStream bas = new ByteArrayOutputStream();
try { try {
DataOutputStream out = addProtoAndCmd( bas, reg );
String devid = getDevID( null ); String devid = getDevID( null );
writeVLIString( out, devid ); if ( null != devid ) {
postPacket( bas ); DataOutputStream out = addProtoAndCmd( bas, reg );
writeVLIString( out, devid );
postPacket( bas );
}
} catch ( java.io.IOException ioe ) { } catch ( java.io.IOException ioe ) {
DbgUtils.loge( ioe ); DbgUtils.loge( ioe );
} }
@ -596,11 +627,13 @@ public class RelayService extends XWService
private void sendKeepAlive() private void sendKeepAlive()
{ {
DbgUtils.logf( "sendKeepAlive()" );
requestMessagesImpl( XWRelayReg.XWPDEV_KEEPALIVE ); requestMessagesImpl( XWRelayReg.XWPDEV_KEEPALIVE );
} }
private void sendMessage( long rowid, byte[] msg ) private void sendMessage( long rowid, byte[] msg )
{ {
DbgUtils.logf( "RelayService.sendMessage()" );
ByteArrayOutputStream bas = new ByteArrayOutputStream(); ByteArrayOutputStream bas = new ByteArrayOutputStream();
try { try {
DataOutputStream out = addProtoAndCmd( bas, XWRelayReg.XWPDEV_MSG ); DataOutputStream out = addProtoAndCmd( bas, XWRelayReg.XWPDEV_MSG );
@ -690,9 +723,10 @@ public class RelayService extends XWService
{ {
byte[] data = bas.toByteArray(); byte[] data = bas.toByteArray();
m_queue.add( new DatagramPacket( data, data.length ) ); m_queue.add( new DatagramPacket( data, data.length ) );
DbgUtils.logf( "postPacket() done; %d in queue", m_queue.size() );
} }
private String getDevID( byte[] typp ) private String getDevID( DevIDType[] typp )
{ {
DevIDType typ; DevIDType typ;
String devid = XWPrefs.getRelayDevID( this ); String devid = XWPrefs.getRelayDevID( this );
@ -708,9 +742,9 @@ public class RelayService extends XWService
} }
} }
if ( null != typp ) { if ( null != typp ) {
typp[0] = (byte)typ.ordinal(); typp[0] = typ;
} else { } else if ( typ != DevIDType.ID_TYPE_RELAY ) {
Assert.assertTrue( typ == DevIDType.ID_TYPE_RELAY ); devid = null;
} }
return devid; return devid;
} }
@ -746,9 +780,11 @@ public class RelayService extends XWService
private void process( byte[][][] msgs, long[] rowIDs, String[] relayIDs ) private void process( byte[][][] msgs, long[] rowIDs, String[] relayIDs )
{ {
DbgUtils.logf( "RelayService.process()" );
if ( null != msgs ) { if ( null != msgs ) {
RelayMsgSink sink = new RelayMsgSink(); RelayMsgSink sink = new RelayMsgSink();
int nameCount = relayIDs.length; int nameCount = relayIDs.length;
DbgUtils.logf( "RelayService.process(): nameCount: %d", nameCount );
ArrayList<String> idsWMsgs = new ArrayList<String>( nameCount ); ArrayList<String> idsWMsgs = new ArrayList<String>( nameCount );
for ( int ii = 0; ii < nameCount; ++ii ) { for ( int ii = 0; ii < nameCount; ++ii ) {
@ -951,6 +987,7 @@ public class RelayService extends XWService
private void startThreads() private void startThreads()
{ {
DbgUtils.logf( "RelayService.startThreads()" );
if ( !NetStateCache.netAvail( this ) ) { if ( !NetStateCache.netAvail( this ) ) {
stopThreads(); stopThreads();
} else if ( XWPrefs.getUDPEnabled( this ) ) { } else if ( XWPrefs.getUDPEnabled( this ) ) {
@ -965,6 +1002,7 @@ public class RelayService extends XWService
private void stopThreads() private void stopThreads()
{ {
DbgUtils.logf( "RelayService.stopThreads()" );
stopFetchThreadIf(); stopFetchThreadIf();
stopUDPThreadsIf(); stopUDPThreadsIf();
} }