From 43b1e219f386139e6646a12353680e7a64916daf Mon Sep 17 00:00:00 2001 From: Eric House Date: Tue, 13 Nov 2012 06:14:36 -0800 Subject: [PATCH 1/5] add a bit more logging to comms --- xwords4/common/comms.c | 28 +++++++++++++++++++++------- xwords4/common/movestak.c | 2 +- 2 files changed, 22 insertions(+), 8 deletions(-) diff --git a/xwords4/common/comms.c b/xwords4/common/comms.c index 600dc88a4..2aa3a33e5 100644 --- a/xwords4/common/comms.c +++ b/xwords4/common/comms.c @@ -785,9 +785,11 @@ comms_saveSucceeded( CommsCtxt* comms, XP_U16 saveToken ) XP_LOGF( "%s(saveToken=%d)", __func__, saveToken ); XP_ASSERT( !!comms ); if ( saveToken == comms->lastSaveToken ) { - XP_LOGF( "%s: lastSave matches", __func__ ); AddressRecord* rec; for ( rec = comms->recs; !!rec; rec = rec->next ) { + XP_LOGF( "%s: lastSave matches; updating lastMsgSaved %ld to " + "lastMsgRcd %ld", __func__, rec->lastMsgSaved, + rec->lastMsgRcd ); rec->lastMsgSaved = rec->lastMsgRcd; } #ifdef XWFEATURE_COMMSACK @@ -1037,9 +1039,10 @@ addToQueue( CommsCtxt* comms, MsgQueueElem* newMsgElem ) XP_ASSERT( comms->queueLen > 0 ); } ++comms->queueLen; - XP_LOGF( "%s: queueLen now %d after channelNo: %d; msgID: " XP_LD, - __func__, comms->queueLen, - newMsgElem->channelNo & CHANNEL_MASK, newMsgElem->msgID ); + XP_LOGF( "%s: queueLen now %d after channelNo: %d; msgID: " XP_LD + "; len: %d", __func__, comms->queueLen, + newMsgElem->channelNo & CHANNEL_MASK, newMsgElem->msgID, + newMsgElem->len ); } /* addToQueue */ #ifdef DEBUG @@ -1244,14 +1247,25 @@ comms_resendAll( CommsCtxt* comms ) void comms_ackAny( CommsCtxt* comms ) { +#ifdef DEBUG + XP_Bool noneSent = XP_TRUE; +#endif AddressRecord* rec; for ( rec = comms->recs; !!rec; rec = rec->next ) { if ( rec->lastMsgAckd < rec->lastMsgRcd ) { - XP_LOGF( "%s: %ld < %ld: rec needs ack", __func__, - rec->lastMsgAckd, rec->lastMsgRcd ); +#ifdef DEBUG + noneSent = XP_FALSE; +#endif + XP_LOGF( "%s: channel %x; %ld < %ld: rec needs ack", __func__, + rec->channelNo, rec->lastMsgAckd, rec->lastMsgRcd ); sendEmptyMsg( comms, rec ); } } +#ifdef DEBUG + if ( noneSent ) { + XP_LOGF( "%s: nothing to send", __func__ ); + } +#endif } #endif @@ -1845,7 +1859,7 @@ sendEmptyMsg( CommsCtxt* comms, AddressRecord* rec ) 0 /*rec? rec->lastMsgRcd : 0*/, rec, rec? rec->channelNo : 0, NULL ); - sendMsg( comms, elem ); + (void)sendMsg( comms, elem ); freeElem( comms, elem ); } /* sendEmptyMsg */ #endif diff --git a/xwords4/common/movestak.c b/xwords4/common/movestak.c index 140da1fb4..984d43795 100644 --- a/xwords4/common/movestak.c +++ b/xwords4/common/movestak.c @@ -147,7 +147,7 @@ stack_getHash( const StackCtxt* stack ) stream_copyBits( stack->data, 0, stack->top, buf, &len ); // LOG_HEX( buf, len, __func__ ); hash = finishHash( augmentHash( 0L, buf, len ) ); - LOG_RETURNF( "%.8X", (unsigned int)hash ); + // LOG_RETURNF( "%.8X", (unsigned int)hash ); return hash; } /* stack_getHash */ #endif From 2908802017d789cf08e4aff45c8997013ee082ed Mon Sep 17 00:00:00 2001 From: Eric House Date: Tue, 13 Nov 2012 06:15:36 -0800 Subject: [PATCH 2/5] try to make linux client mimic Android a bit better in saving after any network activity so messages get acked more quickly. --- xwords4/linux/Makefile | 1 + xwords4/linux/cursesmain.c | 8 ++++++-- 2 files changed, 7 insertions(+), 2 deletions(-) diff --git a/xwords4/linux/Makefile b/xwords4/linux/Makefile index fe0af91a2..05543eeee 100644 --- a/xwords4/linux/Makefile +++ b/xwords4/linux/Makefile @@ -111,6 +111,7 @@ DEFINES += -DXWFEATURE_HILITECELL # allow change dict inside running game DEFINES += -DXWFEATURE_CHANGEDICT DEFINES += -DXWFEATURE_DEVID +DEFINES += -DXWFEATURE_COMMSACK # MAX_ROWS controls STREAM_VERS_BIGBOARD and with it move hashing DEFINES += -DMAX_ROWS=32 diff --git a/xwords4/linux/cursesmain.c b/xwords4/linux/cursesmain.c index 42529981c..945719aa0 100644 --- a/xwords4/linux/cursesmain.c +++ b/xwords4/linux/cursesmain.c @@ -474,6 +474,7 @@ onetime_idle( gpointer data ) if ( !!globals->cGlobals.game.board ) { board_draw( globals->cGlobals.game.board ); } + saveGame( &globals->cGlobals ); } return FALSE; } @@ -1219,7 +1220,7 @@ static XP_Bool blocking_gotEvent( CursesAppGlobals* globals, int* ch ) { XP_Bool result = XP_FALSE; - int numEvents; + int numEvents, ii; short fdIndex; XP_Bool redraw = XP_FALSE; @@ -1334,12 +1335,15 @@ blocking_gotEvent( CursesAppGlobals* globals, int* ch ) } } - redraw = server_do( globals->cGlobals.game.server, NULL ) || redraw; + for ( ii = 0; ii < 5; ++ii ) { + redraw = server_do( globals->cGlobals.game.server, NULL ) || redraw; + } if ( redraw ) { /* messages change a lot */ board_invalAll( globals->cGlobals.game.board ); board_draw( globals->cGlobals.game.board ); } + saveGame( globals->cGlobals ); } return result; } /* blocking_gotEvent */ From c4f5b4522ecf72c6621c5bb14a1aaa95eae437a7 Mon Sep 17 00:00:00 2001 From: Eric House Date: Tue, 13 Nov 2012 07:17:56 -0800 Subject: [PATCH 3/5] minor printing tweaks --- xwords4/relay/scripts/gcm_loop.py | 17 +++++++++-------- 1 file changed, 9 insertions(+), 8 deletions(-) diff --git a/xwords4/relay/scripts/gcm_loop.py b/xwords4/relay/scripts/gcm_loop.py index 61c5fe253..d1877bc67 100755 --- a/xwords4/relay/scripts/gcm_loop.py +++ b/xwords4/relay/scripts/gcm_loop.py @@ -81,7 +81,9 @@ def notifyGCM( devids, typ ): for error, reg_ids in response.items(): print error else: - print 'no errors' + print 'no errors', + if g_debug: print ':', response + else: print else: print "not sending to", len(devids), "devices because typ ==", typ @@ -176,15 +178,14 @@ def main(): print "devices needing notification:", targets notifyGCM( asGCMIds( g_con, targets, typ ), typ ) pruneSent( devids ) - else: - if not g_debug: - sys.stdout.write('.') - sys.stdout.flush() - emptyCount = emptyCount + 1 - if 0 == (emptyCount % LINE_LEN): print "" + else: + emptyCount += 1 + if not g_debug: + sys.stdout.write('.') + sys.stdout.flush() + if 0 == (emptyCount % LINE_LEN): print "" if 0 == loopInterval: break time.sleep( loopInterval ) - if not g_debug: print cleanup() From 57ea768aaf34dd7000df2748536bb17b5870aaad Mon Sep 17 00:00:00 2001 From: Eric House Date: Tue, 13 Nov 2012 07:22:48 -0800 Subject: [PATCH 4/5] refuse to send 0-length messages. That may happen only when the stupid curses client calls server_initClientConnection over and over, but reduces unnecessary messaging in that case at least. --- xwords4/common/comms.c | 32 ++++++++++++++++++-------------- 1 file changed, 18 insertions(+), 14 deletions(-) diff --git a/xwords4/common/comms.c b/xwords4/common/comms.c index 2aa3a33e5..319a5e1fc 100644 --- a/xwords4/common/comms.c +++ b/xwords4/common/comms.c @@ -998,24 +998,28 @@ comms_getChannelSeed( CommsCtxt* comms ) XP_S16 comms_send( CommsCtxt* comms, XWStreamCtxt* stream ) { - XP_PlayerAddr channelNo = stream_getAddress( stream ); - XP_LOGF( "%s: channelNo=%x", __func__, channelNo ); - AddressRecord* rec = getRecordFor( comms, NULL, channelNo, XP_FALSE ); - MsgID msgID = (!!rec)? ++rec->nextMsgID : 0; - MsgQueueElem* elem; XP_S16 result = -1; + if ( 0 == stream_getSize(stream) ) { + XP_LOGF( "%s: dropping 0-len message", __func__ ); + } else { + XP_PlayerAddr channelNo = stream_getAddress( stream ); + XP_LOGF( "%s: channelNo=%x", __func__, channelNo ); + AddressRecord* rec = getRecordFor( comms, NULL, channelNo, XP_FALSE ); + MsgID msgID = (!!rec)? ++rec->nextMsgID : 0; + MsgQueueElem* elem; - if ( 0 == channelNo ) { - channelNo = comms_getChannelSeed(comms) & ~CHANNEL_MASK; - } + if ( 0 == channelNo ) { + channelNo = comms_getChannelSeed(comms) & ~CHANNEL_MASK; + } - XP_DEBUGF( "%s: assigning msgID=" XP_LD " on chnl %x", __func__, - msgID, channelNo ); + XP_DEBUGF( "%s: assigning msgID=" XP_LD " on chnl %x", __func__, + msgID, channelNo ); - elem = makeElemWithID( comms, msgID, rec, channelNo, stream ); - if ( NULL != elem ) { - addToQueue( comms, elem ); - result = sendMsg( comms, elem ); + elem = makeElemWithID( comms, msgID, rec, channelNo, stream ); + if ( NULL != elem ) { + addToQueue( comms, elem ); + result = sendMsg( comms, elem ); + } } return result; } /* comms_send */ From 093fc4d1faae01e759a7da13e75b2da8a4b0e63d Mon Sep 17 00:00:00 2001 From: Eric House Date: Tue, 13 Nov 2012 07:23:07 -0800 Subject: [PATCH 5/5] cleanup --- xwords4/linux/cursesmain.c | 29 ++++------------------------- xwords4/linux/gtkmain.c | 28 +++++++--------------------- xwords4/linux/linuxmain.c | 8 ++++++++ xwords4/linux/linuxmain.h | 2 ++ 4 files changed, 21 insertions(+), 46 deletions(-) diff --git a/xwords4/linux/cursesmain.c b/xwords4/linux/cursesmain.c index 945719aa0..1cebe705d 100644 --- a/xwords4/linux/cursesmain.c +++ b/xwords4/linux/cursesmain.c @@ -1490,25 +1490,15 @@ curses_util_remSelected( XW_UtilCtxt* uc ) } #ifndef XWFEATURE_STANDALONE_ONLY -static void -cursesSendOnClose( XWStreamCtxt* stream, void* closure ) -{ - CursesAppGlobals* globals = (CursesAppGlobals*)closure; - - XP_LOGF( "cursesSendOnClose called" ); - (void)comms_send( globals->cGlobals.game.comms, stream ); -} /* cursesSendOnClose */ - static XWStreamCtxt* curses_util_makeStreamFromAddr(XW_UtilCtxt* uc, XP_PlayerAddr channelNo ) { CursesAppGlobals* globals = (CursesAppGlobals*)uc->closure; LaunchParams* params = globals->cGlobals.params; - XWStreamCtxt* stream = mem_stream_make( MPPARM(uc->mpool) - params->vtMgr, - uc->closure, channelNo, - cursesSendOnClose ); + XWStreamCtxt* stream = mem_stream_make( MPPARM(uc->mpool) params->vtMgr, + &globals->cGlobals, channelNo, + sendOnClose ); return stream; } /* curses_util_makeStreamFromAddr */ #endif @@ -1548,17 +1538,6 @@ setupCursesUtilCallbacks( CursesAppGlobals* globals, XW_UtilCtxt* util ) util->closure = globals; } /* setupCursesUtilCallbacks */ -#ifndef XWFEATURE_STANDALONE_ONLY -static void -sendOnClose( XWStreamCtxt* stream, void* closure ) -{ - CursesAppGlobals* globals = closure; - XP_LOGF( "curses sendOnClose called" ); - XP_ASSERT( !!globals->cGlobals.game.comms ); - comms_send( globals->cGlobals.game.comms, stream ); -} /* sendOnClose */ -#endif - static CursesMenuHandler getHandlerForKey( const MenuList* list, char ch ) { @@ -1875,7 +1854,7 @@ cursesmain( XP_Bool isServer, LaunchParams* params ) server_initClientConnection( g_globals.cGlobals.game.server, mem_stream_make( MEMPOOL params->vtMgr, - &g_globals, + &g_globals.cGlobals, (XP_PlayerAddr)0, sendOnClose ) ); } else { diff --git a/xwords4/linux/gtkmain.c b/xwords4/linux/gtkmain.c index 0567410f7..6b7278f50 100644 --- a/xwords4/linux/gtkmain.c +++ b/xwords4/linux/gtkmain.c @@ -65,9 +65,6 @@ #include "filestream.h" /* static guint gtkSetupClientSocket( GtkAppGlobals* globals, int sock ); */ -#ifndef XWFEATURE_STANDALONE_ONLY -static void sendOnCloseGTK( XWStreamCtxt* stream, void* closure ); -#endif static void setCtrlsForTray( GtkAppGlobals* globals ); static void new_game( GtkWidget* widget, GtkAppGlobals* globals ); static void new_game_impl( GtkAppGlobals* globals, XP_Bool fireConnDlg ); @@ -508,8 +505,8 @@ createOrLoadObjects( GtkAppGlobals* globals ) #ifndef XWFEATURE_STANDALONE_ONLY } else if ( !isServer ) { XWStreamCtxt* stream = - mem_stream_make( MEMPOOL params->vtMgr, globals, CHANNEL_NONE, - sendOnCloseGTK ); + mem_stream_make( MEMPOOL params->vtMgr, &globals->cGlobals, CHANNEL_NONE, + sendOnClose ); server_initClientConnection( globals->cGlobals.game.server, stream ); #endif @@ -814,11 +811,9 @@ new_game_impl( GtkAppGlobals* globals, XP_Bool fireConnDlg ) if ( isClient ) { XWStreamCtxt* stream = - mem_stream_make( MEMPOOL - globals->cGlobals.params->vtMgr, - globals, - CHANNEL_NONE, - sendOnCloseGTK ); + mem_stream_make( MEMPOOL globals->cGlobals.params->vtMgr, + &globals->cGlobals, CHANNEL_NONE, + sendOnClose ); server_initClientConnection( globals->cGlobals.game.server, stream ); } @@ -1747,8 +1742,8 @@ gtk_util_makeStreamFromAddr(XW_UtilCtxt* uc, XP_PlayerAddr channelNo ) XWStreamCtxt* stream = mem_stream_make( MEMPOOL globals->cGlobals.params->vtMgr, - uc->closure, channelNo, - sendOnCloseGTK ); + &globals->cGlobals, channelNo, + sendOnClose ); return stream; } /* gtk_util_makeStreamFromAddr */ @@ -2270,15 +2265,6 @@ gtk_socket_acceptor( int listener, Acceptor func, CommonGlobals* globals, } } /* gtk_socket_acceptor */ -static void -sendOnCloseGTK( XWStreamCtxt* stream, void* closure ) -{ - GtkAppGlobals* globals = closure; - - XP_LOGF( "sendOnClose called" ); - (void)comms_send( globals->cGlobals.game.comms, stream ); -} /* sendOnClose */ - static void drop_msg_toggle( GtkWidget* toggle, GtkAppGlobals* globals ) { diff --git a/xwords4/linux/linuxmain.c b/xwords4/linux/linuxmain.c index 1dd97388d..82b7d5c04 100644 --- a/xwords4/linux/linuxmain.c +++ b/xwords4/linux/linuxmain.c @@ -196,6 +196,14 @@ catOnClose( XWStreamCtxt* stream, void* XP_UNUSED(closure) ) free( buffer ); } /* catOnClose */ +void +sendOnClose( XWStreamCtxt* stream, void* closure ) +{ + CommonGlobals* cGlobals = (CommonGlobals*)closure; + XP_LOGF( "%s called with msg of len %d", __func__, stream_getSize(stream) ); + (void)comms_send( cGlobals->game.comms, stream ); +} + void catGameHistory( CommonGlobals* cGlobals ) { diff --git a/xwords4/linux/linuxmain.h b/xwords4/linux/linuxmain.h index bae629d47..44cf263e5 100644 --- a/xwords4/linux/linuxmain.h +++ b/xwords4/linux/linuxmain.h @@ -60,6 +60,8 @@ XP_UCHAR* strFromStream( XWStreamCtxt* stream ); void catGameHistory( CommonGlobals* cGlobals ); void catOnClose( XWStreamCtxt* stream, void* closure ); +void sendOnClose( XWStreamCtxt* stream, void* closure ); + void catFinalScores( const CommonGlobals* cGlobals, XP_S16 quitter ); XP_Bool file_exists( const char* fileName ); XWStreamCtxt* streamFromFile( CommonGlobals* cGlobals, char* name,