Miroirs/xwords
1
0
Fork 0
mirror of git://xwords.git.sourceforge.net/gitroot/xwords/xwords synced 2025-02-01 19:57:11 +01:00
Code Issues Projects Releases Packages Wiki Activity

more reducing logging

Browse source
This commit is contained in:
Eric House 2024-02-10 20:38:27 -08:00
parent 8487d212a3
commit 01bbee3a8c
2 changed files with 37 additions and 30 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

4
xwords4/common/comms.c
View file

@ -4105,11 +4105,11 @@ relayConnect( CommsCtxt* comms, XWEnv xwe )
static void static void
listRecs( const CommsCtxt* comms, const char* msg ) listRecs( const CommsCtxt* comms, const char* msg )
{ {
COMMS_LOGFF( "nrecs: %d", countAddrRecs( comms ) ); COMMS_LOGFFV( "nrecs: %d", countAddrRecs( comms ) );
int ii = 0; int ii = 0;
for ( AddressRecord* rec = comms->recs; !!rec; rec = rec->next ) { for ( AddressRecord* rec = comms->recs; !!rec; rec = rec->next ) {
CNO_FMT( cbuf, rec->channelNo ); CNO_FMT( cbuf, rec->channelNo );
COMMS_LOGFF( "%s: rec[%d]: %s", msg, ii, cbuf ); COMMS_LOGFFV( "%s: rec[%d]: %s", msg, ii, cbuf );
++ii; ++ii;
} }
} }

63
xwords4/common/server.c
View file

@ -204,6 +204,12 @@ struct RematchInfo {
# define dupe_timerRunning() server_canPause(server) # define dupe_timerRunning() server_canPause(server)
# ifdef ENABLE_LOGFFV
# define SRVR_LOGFFV SRVR_LOGFF
# else
# define SRVR_LOGFFV(...)
# endif
#ifdef DEBUG #ifdef DEBUG
# define SRVR_LOGFF( ... ) { \ # define SRVR_LOGFF( ... ) { \
XP_U32 gameID = server->vol.gi->gameID; \ XP_U32 gameID = server->vol.gi->gameID; \
@ -956,15 +962,15 @@ addGuestAddrsIf( const ServerCtxt* server, XP_U16 sendee, XWStreamCtxt* stream )
static void static void
readGuestAddrs( ServerCtxt* server, XWStreamCtxt* stream, XP_U8 streamVersion ) readGuestAddrs( ServerCtxt* server, XWStreamCtxt* stream, XP_U8 streamVersion )
{ {
SRVR_LOGFF( "version: 0x%X", streamVersion ); SRVR_LOGFFV( "version: 0x%X", streamVersion );
if ( STREAM_VERS_REMATCHADDRS <= streamVersion && 0 < stream_getSize(stream) ) { if ( STREAM_VERS_REMATCHADDRS <= streamVersion && 0 < stream_getSize(stream) ) {
XP_U16 len = server->nv.rematch.addrsLen = stream_getU32VL( stream ); XP_U16 len = server->nv.rematch.addrsLen = stream_getU32VL( stream );
SRVR_LOGFF( "rematch.addrsLen: %d", server->nv.rematch.addrsLen ); SRVR_LOGFFV( "rematch.addrsLen: %d", server->nv.rematch.addrsLen );
if ( 0 < len ) { if ( 0 < len ) {
XP_ASSERT( !server->nv.rematch.addrs ); XP_ASSERT( !server->nv.rematch.addrs );
server->nv.rematch.addrs = XP_MALLOC( server->mpool, len ); server->nv.rematch.addrs = XP_MALLOC( server->mpool, len );
stream_getBytes( stream, server->nv.rematch.addrs, len ); stream_getBytes( stream, server->nv.rematch.addrs, len );
SRVR_LOGFF( "loaded %d bytes of rematch.addrs", len ); SRVR_LOGFFV( "loaded %d bytes of rematch.addrs", len );
#ifdef DEBUG #ifdef DEBUG
XWStreamCtxt* tmpStream = mkServerStream( server, streamVersion ); XWStreamCtxt* tmpStream = mkServerStream( server, streamVersion );
stream_putBytes( tmpStream, server->nv.rematch.addrs, stream_putBytes( tmpStream, server->nv.rematch.addrs,
@ -974,14 +980,14 @@ readGuestAddrs( ServerCtxt* server, XWStreamCtxt* stream, XP_U8 streamVersion )
RematchInfo ri; RematchInfo ri;
ri_fromStream( &ri, tmpStream, server ); ri_fromStream( &ri, tmpStream, server );
for ( int ii = 0; ii < ri.nAddrs; ++ii ) { for ( int ii = 0; ii < ri.nAddrs; ++ii ) {
SRVR_LOGFF( "got an address" ); SRVR_LOGFFV( "got an address" );
logAddr( server->vol.dutil, &ri.addrs[ii], __func__ ); logAddr( server->vol.dutil, &ri.addrs[ii], __func__ );
} }
} else { } else {
while ( 0 < stream_getSize(tmpStream) ) { while ( 0 < stream_getSize(tmpStream) ) {
CommsAddrRec addr = {0}; CommsAddrRec addr = {0};
addrFromStream( &addr, tmpStream ); addrFromStream( &addr, tmpStream );
SRVR_LOGFF( "got an address" ); SRVR_LOGFFV( "got an address" );
logAddr( server->vol.dutil, &addr, __func__ ); logAddr( server->vol.dutil, &addr, __func__ );
} }
} }
@ -996,7 +1002,7 @@ XP_Bool
server_initClientConnection( ServerCtxt* server, XWEnv xwe ) server_initClientConnection( ServerCtxt* server, XWEnv xwe )
{ {
XP_Bool result; XP_Bool result;
SRVR_LOGFF( "gameState: %s; ", getStateStr(server->nv.gameState) ); SRVR_LOGFFV( "gameState: %s; ", getStateStr(server->nv.gameState) );
CurGameInfo* gi = server->vol.gi; CurGameInfo* gi = server->vol.gi;
XP_U16 nPlayers; XP_U16 nPlayers;
LocalPlayer* lp; LocalPlayer* lp;
@ -1038,7 +1044,7 @@ server_initClientConnection( ServerCtxt* server, XWEnv xwe )
} }
stream_putBits( stream, NAME_LEN_NBITS, len ); stream_putBits( stream, NAME_LEN_NBITS, len );
stream_putBytes( stream, name, len ); stream_putBytes( stream, name, len );
SRVR_LOGFF( "wrote local name %s", name ); SRVR_LOGFFV( "wrote local name %s", name );
} }
#ifdef STREAM_VERS_BIGBOARD #ifdef STREAM_VERS_BIGBOARD
stream_putU8( stream, CUR_STREAM_VERS ); stream_putU8( stream, CUR_STREAM_VERS );
@ -1140,7 +1146,7 @@ setStreamVersion( ServerCtxt* server )
streamVersion = devVersion; streamVersion = devVersion;
} }
} }
SRVR_LOGFF( "setting streamVersion: 0x%x", streamVersion ); SRVR_LOGFFV( "setting streamVersion: 0x%x", streamVersion );
server->nv.streamVersion = streamVersion; server->nv.streamVersion = streamVersion;
CurGameInfo* gi = server->vol.gi; CurGameInfo* gi = server->vol.gi;
@ -1926,7 +1932,7 @@ server_do( ServerCtxt* server, XWEnv xwe )
} else { } else {
XP_Bool moreToDo = XP_FALSE; XP_Bool moreToDo = XP_FALSE;
server->serverDoing = XP_TRUE; server->serverDoing = XP_TRUE;
SRVR_LOGFF( "gameState: %s", getStateStr(server->nv.gameState) ); SRVR_LOGFFV( "gameState: %s", getStateStr(server->nv.gameState) );
switch( server->nv.gameState ) { switch( server->nv.gameState ) {
case XWSTATE_BEGIN: case XWSTATE_BEGIN:
if ( server->nv.pendingRegistrations == 0 ) { /* all players on if ( server->nv.pendingRegistrations == 0 ) { /* all players on
@ -2031,7 +2037,7 @@ getIndexForDevice( const ServerCtxt* server, XP_PlayerAddr channelNo )
} }
} }
SRVR_LOGFF( "(%x)=>%d", channelNo, result ); SRVR_LOGFFV( "(%x)=>%d", channelNo, result );
return result; return result;
} /* getIndexForDevice */ } /* getIndexForDevice */
@ -2206,7 +2212,7 @@ client_readInitialMessage( ServerCtxt* server, XWEnv xwe, XWStreamCtxt* stream )
/* never seems to replace anything -- gi is already correct on guests /* never seems to replace anything -- gi is already correct on guests
apparently. How? Will have come in with invitation, of course. */ apparently. How? Will have come in with invitation, of course. */
SRVR_LOGFF( "read gameID of %08X; calling comms_setConnID (replacing %08X)", SRVR_LOGFFV( "read gameID of %08X; calling comms_setConnID (replacing %08X)",
gameID, gi->gameID ); gameID, gi->gameID );
XP_ASSERT( gi->gameID == gameID ); XP_ASSERT( gi->gameID == gameID );
gi->gameID = gameID; gi->gameID = gameID;
@ -2240,7 +2246,7 @@ client_readInitialMessage( ServerCtxt* server, XWEnv xwe, XWStreamCtxt* stream )
model_setSize( model, localGI.boardSize ); model_setSize( model, localGI.boardSize );
XP_U16 nPlayers = localGI.nPlayers; XP_U16 nPlayers = localGI.nPlayers;
SRVR_LOGFF( "reading in %d players", localGI.nPlayers ); SRVR_LOGFFV( "reading in %d players", localGI.nPlayers );
gi->nPlayers = nPlayers; gi->nPlayers = nPlayers;
model_setNPlayers( model, nPlayers ); model_setNPlayers( model, nPlayers );
@ -2281,7 +2287,7 @@ client_readInitialMessage( ServerCtxt* server, XWEnv xwe, XWStreamCtxt* stream )
later. */ later. */
pool_removeTiles( pool, &tiles ); pool_removeTiles( pool, &tiles );
} }
SRVR_LOGFF( "got %d tiles for player %d", tiles.nTiles, ii ); SRVR_LOGFFV( "got %d tiles for player %d", tiles.nTiles, ii );
if ( inDuplicateMode(server ) ) { if ( inDuplicateMode(server ) ) {
model_assignDupeTiles( model, xwe, &tiles ); model_assignDupeTiles( model, xwe, &tiles );
@ -2329,7 +2335,7 @@ makeSendableGICopy( ServerCtxt* server, CurGameInfo* giCopy,
} }
giCopy->forceChannel = deviceIndex; giCopy->forceChannel = deviceIndex;
SRVR_LOGFF( "assigning forceChannel from deviceIndex: %d", SRVR_LOGFFV( "assigning forceChannel from deviceIndex: %d",
giCopy->forceChannel ); giCopy->forceChannel );
giCopy->dictName = (XP_UCHAR*)NULL; /* so we don't sent the bytes */ giCopy->dictName = (XP_UCHAR*)NULL; /* so we don't sent the bytes */
@ -2371,7 +2377,7 @@ sendInitialMessage( ServerCtxt* server, XWEnv xwe )
const DictionaryCtxt* dict = model_getDictionary( model ); const DictionaryCtxt* dict = model_getDictionary( model );
if ( streamVersion < STREAM_VERS_NOEMPTYDICT ) { if ( streamVersion < STREAM_VERS_NOEMPTYDICT ) {
SRVR_LOGFF( "writing dict to stream" ); SRVR_LOGFFV( "writing dict to stream" );
dict_writeToStream( dict, stream ); dict_writeToStream( dict, stream );
} }
#ifdef STREAM_VERS_BIGBOARD #ifdef STREAM_VERS_BIGBOARD
@ -2727,7 +2733,7 @@ trayAllowsMoves( ServerCtxt* server, XWEnv xwe, XP_U16 turn,
&& canMove; && canMove;
if ( result ) { if ( result ) {
SRVR_LOGFF( "first move found has score of %d", score ); SRVR_LOGFFV( "first move found has score of %d", score );
} else { } else {
SRVR_LOGFF( "no moves found for tray!!!" ); SRVR_LOGFF( "no moves found for tray!!!" );
} }
@ -2926,7 +2932,7 @@ getPlayerTime( ServerCtxt* server, XWStreamCtxt* stream, XP_U16 turn )
static void static void
nextTurn( ServerCtxt* server, XWEnv xwe, XP_S16 nxtTurn ) nextTurn( ServerCtxt* server, XWEnv xwe, XP_S16 nxtTurn )
{ {
SRVR_LOGFF( "(nxtTurn=%d)", nxtTurn ); SRVR_LOGFFV( "(nxtTurn=%d)", nxtTurn );
CurGameInfo* gi = server->vol.gi; CurGameInfo* gi = server->vol.gi;
XP_S16 currentTurn = server->nv.currentTurn; XP_S16 currentTurn = server->nv.currentTurn;
XP_Bool moreToDo = XP_FALSE; XP_Bool moreToDo = XP_FALSE;
@ -3099,8 +3105,8 @@ sendMoveTo( ServerCtxt* server, XWEnv xwe, XP_U16 devIndex, XP_U16 turn,
if ( gi->timerEnabled ) { if ( gi->timerEnabled ) {
stream_putU16( stream, gi->players[turn].secondsUsed ); stream_putU16( stream, gi->players[turn].secondsUsed );
SRVR_LOGFF( "wrote secondsUsed for player %d: %d", SRVR_LOGFFV( "wrote secondsUsed for player %d: %d",
turn, gi->players[turn].secondsUsed ); turn, gi->players[turn].secondsUsed );
} else { } else {
XP_ASSERT( gi->players[turn].secondsUsed == 0 ); XP_ASSERT( gi->players[turn].secondsUsed == 0 );
} }
@ -3152,7 +3158,7 @@ readMoveInfo( ServerCtxt* server, XWEnv xwe, XWStreamCtxt* stream,
if ( isTrade ) { if ( isTrade ) {
traySetFromStream( stream, tradedTiles ); traySetFromStream( stream, tradedTiles );
SRVR_LOGFF( "got trade of %d tiles", tradedTiles->nTiles ); SRVR_LOGFFV( "got trade of %d tiles", tradedTiles->nTiles );
} else { } else {
legalMove = stream_getBits( stream, 1 ); legalMove = stream_getBits( stream, 1 );
success = model_makeTurnFromStream( server->vol.model, success = model_makeTurnFromStream( server->vol.model,
@ -4146,8 +4152,8 @@ server_getOpenChannel( const ServerCtxt* server, XP_U16* channel )
XP_Bool XP_Bool
server_canRematch( const ServerCtxt* server, XP_Bool* canOrderP ) server_canRematch( const ServerCtxt* server, XP_Bool* canOrderP )
{ {
/* SRVR_LOGFF( "nDevices: %d; nPlayers: %d", */ SRVR_LOGFFV( "nDevices: %d; nPlayers: %d",
/* server->nv.nDevices, server->vol.gi->nPlayers ); */ server->nv.nDevices, server->vol.gi->nPlayers );
const CurGameInfo* gi = server->vol.gi; const CurGameInfo* gi = server->vol.gi;
XP_Bool result; XP_Bool result;
XP_Bool canOrder = XP_TRUE; XP_Bool canOrder = XP_TRUE;
@ -4246,7 +4252,7 @@ sortByRandom( const ServerCtxt* server, NewOrder* nop )
int nLeft = gi->nPlayers - ii; int nLeft = gi->nPlayers - ii;
int indx = XP_RANDOM() % nLeft; int indx = XP_RANDOM() % nLeft;
nop->order[ii] = src[indx]; nop->order[ii] = src[indx];
SRVR_LOGFF( "set result[%d] to %d", ii, nop->order[ii] ); SRVR_LOGFFV( "set result[%d] to %d", ii, nop->order[ii] );
/* now swap the last down */ /* now swap the last down */
src[indx] = src[nLeft-1]; src[indx] = src[nLeft-1];
} }
@ -4422,7 +4428,7 @@ server_getRematchInfo( const ServerCtxt* server, XW_UtilCtxt* newUtil,
void void
server_disposeRematchInfo( ServerCtxt* server, RematchInfo** ripp ) server_disposeRematchInfo( ServerCtxt* server, RematchInfo** ripp )
{ {
SRVR_LOGFF( "(%p)", *ripp ); SRVR_LOGFFV( "(%p)", *ripp );
if ( !!*ripp ) { if ( !!*ripp ) {
LOG_RI( *ripp ); LOG_RI( *ripp );
} }
@ -4511,7 +4517,8 @@ static void
log_ri( const ServerCtxt* server, const RematchInfo* rip, log_ri( const ServerCtxt* server, const RematchInfo* rip,
const char* caller, int line ) const char* caller, int line )
{ {
SRVR_LOGFF( "called from line %d of %s() with ptr %p", line, caller, rip ); XP_USE(line);
SRVR_LOGFFV( "called from line %d of %s() with ptr %p", line, caller, rip );
if ( !!rip ) { if ( !!rip ) {
char buf[64] = {0}; char buf[64] = {0};
int offset = 0; int offset = 0;
@ -4523,7 +4530,7 @@ log_ri( const ServerCtxt* server, const RematchInfo* rip,
maxIndx = indx; maxIndx = indx;
} }
} }
SRVR_LOGFF( "%d players (and %d addrs): [%s]", rip->nPlayers, rip->nAddrs, buf ); SRVR_LOGFFV( "%d players (and %d addrs): [%s]", rip->nPlayers, rip->nAddrs, buf );
for ( int ii = 0; ii < rip->nAddrs; ++ii ) { for ( int ii = 0; ii < rip->nAddrs; ++ii ) {
XP_SNPRINTF( buf, VSIZE(buf), "[%d of %d]: %s from %s", XP_SNPRINTF( buf, VSIZE(buf), "[%d of %d]: %s from %s",
@ -4996,7 +5003,7 @@ server_receiveMessage( ServerCtxt* server, XWEnv xwe, XWStreamCtxt* incoming )
XP_Bool accepted = XP_FALSE; XP_Bool accepted = XP_FALSE;
XP_Bool isHost = amHost( server ); XP_Bool isHost = amHost( server );
const XW_Proto code = readProto( server, incoming ); const XW_Proto code = readProto( server, incoming );
SRVR_LOGFF( "code=%s", codeToStr(code) ); SRVR_LOGFFV( "code=%s", codeToStr(code) );
switch ( code ) { switch ( code ) {
case XWPROTO_DEVICE_REGISTRATION: case XWPROTO_DEVICE_REGISTRATION:
@ -5032,7 +5039,7 @@ server_receiveMessage( ServerCtxt* server, XWEnv xwe, XWStreamCtxt* incoming )
case XWPROTO_MOVEMADE_INFO_SERVER: /* server telling me about a move */ case XWPROTO_MOVEMADE_INFO_SERVER: /* server telling me about a move */
if ( isHost ) { if ( isHost ) {
SRVR_LOGFF( "%s received by server!", codeToStr(code) ); SRVR_LOGFFV( "%s received by server!", codeToStr(code) );
accepted = XP_FALSE; accepted = XP_FALSE;
} else { } else {
accepted = reflectMove( server, xwe, incoming ); accepted = reflectMove( server, xwe, incoming );