void CDirectoryRateStat::display(NLMISC::CLog& log)
{
uint pathsize = 0;
TDirectoryMap::iterator first = _DirectoryMap.begin(), last = _DirectoryMap.end();
for (; first != last; ++first)
if ((*first).first.size() > pathsize)
pathsize = (uint)(*first).first.size();
NLMISC::TTime limit = NLMISC::CTime::getLocalTime()-60*1000;
std::string format = "%-"+NLMISC::toString(pathsize)+"s %6s %10s %6s %10s";
log.displayNL(format.c_str(), "directory", "rdfile", "read", "wrfile", "write");
for (first=_DirectoryMap.begin(); first != last; ++first)
{
(*first).second.updateTime(limit);
uint64 rdrate = (*first).second.ReadBytes/60;
uint64 wrrate = (*first).second.WrittenBytes/60;
log.displayNL(format.c_str(),
(*first).first.c_str(),
NLMISC::toString((*first).second.ReadFiles).c_str(),
(NLMISC::bytesToHumanReadable(uint32(rdrate))+"/s").c_str(),
NLMISC::toString((*first).second.WrittenFiles).c_str(),
(NLMISC::bytesToHumanReadable(uint32(wrrate))+"/s").c_str());
}
}
void CFileReceiver::dump(NLMISC::CLog& log) const
{
log.displayNL("-----------------------------------");
log.displayNL("File requests");
log.displayNL("-----------------------------------");
for (TFileRequests::const_iterator fit= _FileRequests.begin(); fit!= _FileRequests.end(); ++fit)
{
SFileRequest& request= *(*fit);
log.displayNL("- File: '%s' %s (%d..%d/%d)",
request.FileName.c_str(),
(request.Emitter==NULL)? "No emitter": request.Emitter->getModuleName().c_str(),
request.DataSoFar.size(),
request.TotalDataRequested,
request.ExpectedFileSize );
}
log.displayNL("-----------------------------------");
log.displayNL("Connected proxies");
log.displayNL("-----------------------------------");
for (TProxies::const_iterator pit= _Proxies.begin(); pit!= _Proxies.end(); ++pit)
{
log.displayNL("- Repository %s (%d files): Current Request: %s",
pit->second.Proxy->getModuleName().c_str(),
pit->second.FileInfo.size(),
(pit->second.CurrentRequest==NULL)? "None": pit->second.CurrentRequest->FileName.c_str());
}
log.displayNL("-----------------------------------");
}
virtual void run()
{
NLMISC::CLog taskLog;
CStrDisplayer taskDisplayer(&(Query->Result));
taskLog.addDisplayer(&taskDisplayer);
ICommand::execute(Query->Query, taskLog);
Query->Timeout = NLMISC::CTime::getLocalTime();
Query->Finished = true;
Query = NULL;
}
//----------------------------------------------------------------------------
void CBuildingPhysicalPlayer::dumpBuilding(NLMISC::CLog & log) const
{
log.displayNL("<BUILDING_DUMP> CBuildingPhysicalPlayer");
log.displayNL("Name: %s, alias: %s", _Name.c_str(), CPrimitivesParser::aliasToString( _Alias ).c_str());
for (uint i = 0; i < _UsersInside.size(); i++)
{
const TDataSetRow rowId = _UsersInside[i];
CCharacter * c = PlayerManager.getChar( rowId );
if ( !c )
{
log.displayNL("\tError: cannot find character with row id: %s", rowId.toString().c_str());
continue;
}
const string charName = c->getName().toUtf8();
const string charEId = c->getId().toString();
CMirrorPropValueRO<TYPE_CELL> mirrorCell(TheDataset, rowId, DSPropertyCELL);
const sint32 cell = mirrorCell;
IRoomInstance * room = CBuildingManager::getInstance()->getRoomInstanceFromCell( cell );
if ( !room )
{
log.displayNL("\tError: character %s %s is in cell %d but no room was found", charName.c_str(), charEId.c_str(), cell);
continue;
}
CRoomInstancePlayer * playerRoom = dynamic_cast<CRoomInstancePlayer *>(room);
if ( !playerRoom )
{
log.displayNL("\tError: character %s %s is in cell %d but room is not a player room but a %s",
charName.c_str(), charEId.c_str(), cell, room->getRoomDescription().c_str()
);
continue;
}
log.displayNL("\tCharacter %s %s is in cell %d, room desc: %s",
charName.c_str(), charEId.c_str(), cell, room->getRoomDescription().c_str()
);
}
for (uint i = 0; i < _Players.size(); i++)
{
CEntityId id = _Players[i];
CCharacter * c = PlayerManager.getChar( id );
if ( !c )
{
log.displayNL("\tError: cannot find character with eid: %s", id.toString().c_str());
continue;
}
const string charName = c->getName().toUtf8();
const string charEId = c->getId().toString();
log.displayNL("\t> Player registered in building at index %u: %s %s", i, charName.c_str(), charEId.c_str());
}
}
void CTickProxy::receiveTockFromClient( CMessage& msgin, TServiceId senderId, bool real )
{
// Receive measures of client service
TimeMeasures.ServiceMeasures.push_back( CServiceGameCycleTimeMeasure() );
CServiceGameCycleTimeMeasure& stm = TimeMeasures.ServiceMeasures.back();
stm.ClientServiceId = senderId;
if ( real )
{
stm.ServiceMeasure[TickTockInterval] = accTimeToMs( getAccurateTime() - _BeginOfTickTime );
msgin.serial( stm.ServiceMeasure[TickUpdateDuration] );
msgin.serial( stm.ServiceMeasure[PrevProcessMirrorUpdateDuration] );
msgin.serial( stm.ServiceMeasure[PrevReceiveMsgsViaMirrorDuration] );
msgin.serial( stm.ServiceMeasure[PrevTotalGameCycleDuration] );
}
else
{
for ( uint i=0; i!=NbServiceTimeMeasureTypes; ++i )
stm.ServiceMeasure[i] = 0;
}
//nldebug( "TCK-%u: %hu tocking", getGameCycle(), senderId );
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: %hu tocking", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, getGameCycle(), senderId.get() );
++_NbTocked;
_TockedServices.push_back( senderId );
cbDoNextTask();
}
void CFileReceiver::dumpFileInfo(const std::string &fileSpec,NLMISC::CLog& log) const
{
// setup a vector to hold fileInfo results and call getFileInfo() to fill it in
TFileInfoVector result;
getFileInfo(fileSpec,result);
// display a summary info message
log.displayNL("Result of info request '%s': %d matches",fileSpec.c_str(),result.size());
log.displayNL("- %-32s %10s %10s %s","checksum","time","size","name");
// iterate over results, displaying the info
for (TFileInfoVector::iterator it= result.begin(); it!=result.end(); ++it)
{
log.displayNL("- %-32s %10u %10u %s",it->Checksum.toString().c_str(),it->FileTime,it->FileSize,it->FileName.c_str());
}
}
//---------------------------------------------------
// dumpUnaffectedFaunaDesc
//---------------------------------------------------
void CCreatureManager::dumpUnaffectedFaunaGroups(NLMISC::CLog & log)
{
for (uint i = 0; i < _UnaffectedFaunaGroups.size(); i++ )
{
log.displayNL("row %d, group %d",_UnaffectedFaunaGroups[i].EntityIndex.getIndex(),_UnaffectedFaunaGroups[i].GroupAlias);
}
} // dumpUnaffectedFaunaDesc
void CInterShardExchangeValidator::displayAllLevelCaps(NLMISC::CLog& log) const
{
log.displayNL("Level Caps:");
// iterate over the set of level caps in our singleton
TLevelCaps::const_iterator it= LevelCaps.begin();
TLevelCaps::const_iterator itEnd= LevelCaps.end();
for (;it!=itEnd;++it)
{
log.displayNL("- shard: %3u levelCap: %3u",it->first,it->second);
}
if (CInterShardExchangeValidator::getInstance()->LevelCaps.empty())
{
log.displayNL("- none");
}
}
// display stacked accesses
void CFileAccessManager::displayFileAccesses(NLMISC::CLog& log)
{
uint i;
for (i=0; i<_Accesses.size(); ++i)
{
log.displayRawNL("%2d %08p %s %s %s", i, _Accesses[i], _Accesses[i]->Requester.toString().c_str(), _Accesses[i]->Filename.c_str(), _Accesses[i]->FailureReason.c_str());
}
}
//----------------------------------------------------------------------------
void COutpostManager::dumpOutpostList(NLMISC::CLog & log) const
{
for (uint i = 0; i < _Outposts.size(); i++)
{
const CSmartPtr<COutpost> & outpost = _Outposts[i];
if (outpost != NULL)
log.displayNL("%u: %s", i, outpost->toString().c_str());
}
}
/// Display contents
void display( NLMISC::CLog& log = *NLMISC::DebugLog )
{
CInstances::const_iterator ici;
for ( ici=_Instances.begin(); ici!=_Instances.end(); ++ici )
{
log.displayNL( "%s: %s (%u expected, %u running)",
(*ici).first.c_str(),
(*ici).second.Expected ? ((*ici).second.isOnlineAsExpected() ? "ONLINE" : "MISSING") : "OPTIONAL",
(*ici).second.Expected, (*ici).second.Running );
}
}
void CTickProxy::sendSyncToClient( TServiceId serviceId )
{
CMessage msgout( "REGISTERED" );
msgout.serial( _GameTime );
msgout.serial( _GameTimeStep );
msgout.serial( _GameCycle );
CUnifiedNetwork::getInstance()->send( serviceId, msgout );
//nldebug( "TCK-%u: Sync %hu", getGameCycle(), serviceId );
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: Sync %hu", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, getGameCycle(), serviceId.get() );
}
LOG_ANALYSER_PLUGIN_API bool doAnalyse( const std::vector<const char *>& vec, std::string& res, std::string& log )
{
// ---
// Optional: Demo of how to get NeL logs (1/2)
// Outside this function, include <nel/misc/debug.h> and use namespace NLMISC.
//NLMISC::createDebug();
//CMemDisplayer memdisp;
//NLMISC::DebugLog->addDisplayer( &memdisp );
//NLMISC::InfoLog->addDisplayer( &memdisp );
//NLMISC::WarningLog->addDisplayer( &memdisp );
// ErrorLog and AssertLog not needed, they stop the application.
// ---
// Analyse warnings from vec
CLogReport MainLogReport;
MainLogReport.reset();
int nb = 0;
string line;
vector<const char *>::const_iterator iv;
for ( iv=vec.begin(); iv!=vec.end(); ++iv )
{
line = string(*iv);
MainLogReport.pushLine( line );
}
log = "Log report done.\nUse Right-Click > Select All then Copy (Ctrl+C) to copy the report from the top window.\n \n";
// Fill report to res
NLMISC::CLightMemDisplayer disp;
NLMISC::CLog reportLog;
reportLog.addDisplayer( &disp );
MainLogReport.report( &reportLog, true );
disp.write( res, true );
disp.write( log, false );
// ---
// Optional: Demo of how to get all NeL logs (2/2)
//memdisp.write( log );
// ---
return true;
}
void CTickProxy::sendSyncs()
{
vector<TServiceId>::const_iterator its;
for ( its=_Services.begin(); its!=_Services.end(); ++its )
{
CMessage msgout( "REGISTERED" );
msgout.serial( _GameTime );
msgout.serial( _GameTimeStep );
msgout.serial( _GameCycle );
CUnifiedNetwork::getInstance()->send( (*its), msgout );
//nldebug( "TCK-%u: Sync %hu", getGameCycle(), *its );
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: Sync %hu", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, getGameCycle(), its->get());
}
}
void CTickProxy::sendTicks()
{
nlassert( CTickProxy::State == ExpectingMasterTick );
vector<TServiceId>::const_iterator its;
for ( its=_Services.begin(); its!=_Services.end(); ++its )
{
CMessage msgout( "TICK" );
CUnifiedNetwork::getInstance()->send( (*its), msgout ); // can produce the warning "Can't find selected connection id 0 to send message to METS because connection is not valid or connected, find a valid connection id", if the service is disconnecting but we aren't aware yet
//nldebug( "TCK-%u: Tick %hu", getGameCycle(), *its );
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: Tick %hu", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, getGameCycle(), its->get() );
}
// nldebug( "Now expecting local tocks" );
State = ExpectingLocalTocks;
}
//-----------------------------------------------
// cbRegistered
//
//-----------------------------------------------
static void cbSyncFromMaster(CMessage& msgin, const std::string &serviceName, TServiceId serviceId)
{
TGameTime gameTime = 0;
msgin.serial( gameTime );
CTickProxy::setGameTime( gameTime );
TGameTime gameTimeStep = 0;
msgin.serial( gameTimeStep );
CTickProxy::setGameTimeStep( gameTimeStep );
TGameCycle gameCycle = 0;
msgin.serial( gameCycle );
CTickProxy::setGameCycle( gameCycle );
//nldebug( "TCK-%u: Master Sync", gameCycle );
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: Master Sync", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, gameCycle );
// user callback
onSync();
} // cbRegistered //
void CTickProxy::masterTickUpdate( TServiceId serviceId )
{
H_AUTO(masterTickUpdate);
// increment the time and the number of cycles
_GameTime += (TGameTime)_GameTimeStep;
_GameCycle++;
CTickEventHandler::setGameCycle( _GameCycle ); // set it for shared code
//nldebug( "TCK-%u: Master Tick", getGameCycle() );
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: Master Tick", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, getGameCycle() );
//nldebug( "--GC-%u-->", _GameCycle );
TimeMeasures.ServiceMeasures.clear();
_BeginOfTickTime = getAccurateTime();
{
H_AUTO(TickUpdate);
onTick();
}
}
//-----------------------------------------------
// sendTockBack
//
//-----------------------------------------------
void CTickProxy::sendTockBack( TServiceId serviceId )
{
// send back a tock
CMessage msgout( "TOCK" );
msgout.serial( TimeMeasures );
CUnifiedNetwork::getInstance()->send( serviceId, msgout );
TSockId host;
CCallbackNetBase *cnb;
cnb = CUnifiedNetwork::getInstance()->getNetBase((TServiceId)serviceId, host);
if( cnb )
{
cnb->flush( host );
//nlinfo( "TOCK sent at %.6f", CTime::ticksToSecond( CTime::getPerformanceTime() ) );
}
//nldebug( "TCK-%u: Tocked Master", getGameCycle() );
static uint32 prev = 0;
if ( getGameCycle() == prev )
nlwarning( "Tocked master twice in the same tick!" );
prev = getGameCycle();
//time_t t; time( &t );
_QuickLog.displayNL( "%"NL_I64"u: TCK-%u: Tocked Master", getPerfTime() /*IDisplayer::dateToHumanString( t )*/, getGameCycle() );
}
//--------------------------------------------------------------
// init
//
//--------------------------------------------------------------
void CTickProxy::init( void (*updateFunc)(),
void (*syncFunc)() )
{
// set the callbacks
onTick = updateFunc;
onSync = syncFunc;
nlassert( updateFunc );
nlassert( syncFunc );
// Hide tick messages to avoid flooding
DebugLog->addNegativeFilter ("TICK");
DebugLog->addNegativeFilter ("TOCK");
DebugLog->addNegativeFilter ("14+5");
CUnifiedNetwork::getInstance()->addCallbackArray(cbTickProxyArray,sizeof(cbTickProxyArray)/sizeof(cbTickProxyArray[0]));
CUnifiedNetwork::getInstance()->setServiceUpCallback ("TICKS", cbTPTicksUp, NULL);
CUnifiedNetwork::getInstance()->setServiceDownCallback ("TICKS", cbTPTicksDown, NULL);
RecentHistory.setParam( 100 );
_QuickLog.addDisplayer( &RecentHistory, false );
} // init
// ****************************************************************************
void CInventoryBase::dumpInventory(NLMISC::CLog & log, bool dumpItems) const
{
// inventory description
log.displayNL("Inventory: %s", INVENTORIES::toString(_InventoryId).c_str());
log.displayRawNL("Slots: max=%u, count=%u, free=%u", getMaxSlot(), _SlotCount, _FreeSlotCount);
log.displayRawNL("Weight: %u", _InventoryWeight);
log.displayRawNL("Bulk: %u", _InventoryBulk);
log.displayRawNL("Nb views: %u", _InventoryViews.size());
log.displayNL("(DEBUG) _Items.size() = %u", _Items.size());
if (dumpItems)
{
for (uint i = 0; i < _Items.size(); i++)
{
CGameItemPtr item = _Items[i];
if (item == NULL)
continue;
// short display of the item description
log.displayRawNL( "%u: ", i );
item->displayInLog( log );
}
}
}
bool forageTestDoExtract(
NLMISC::CLog& log,
uint nbIterations,
float reqPeriod,
float reqA,
float reqQ,
float absorption,
float successFactor )
{
CHarvestSource *testSource = CHarvestSourceManager::getInstance()->getEntity( TestSourceRow );
if ( ! testSource )
{
log.displayNL( "Call forageTestBegin first" );
return true;
}
// Request and output results
FILE *f = fopen( std::string(getLogDirectory() + "forage_test.csv").c_str(), "at" );
FILE *f2 = fopen( std::string(getLogDirectory() + "forage_test.log").c_str(), "at" );
float reqS = 1.0f / (reqPeriod * 10.0f);
float req [CHarvestSource::NbPosRTProps];
float abs [CHarvestSource::NbPosRTProps];
float res [CHarvestSource::NbPosRTProps];
static bool FirstTime = true;
req[CHarvestSource::S] = reqS;
req[CHarvestSource::A] = reqA;
req[CHarvestSource::Q] = reqQ;
abs[CHarvestSource::S] = absorption;
abs[CHarvestSource::A] = absorption;
abs[CHarvestSource::Q] = absorption;
res[CHarvestSource::S] = 0.025f;
res[CHarvestSource::A] = 0.0f;
res[CHarvestSource::Q] = 0.0f;
if ( FirstTime )
{
FirstTime = false;
fprintf( f, "A;Q;D;E;C;reqS;reqA;reqQ;qty;scheme;limit;\n" );
}
testSource->beginExtraction( TDataSetRow::createFromRawIndex( INVALID_DATASET_INDEX ), false );
bool eventD = false, eventE = false, eventC = false;
for ( uint i=0; i!=nbIterations; ++i )
{
TDataSetRow row;
CHarvestSource::TRealTimeProp propDrop;
testSource->extractMaterial( req, abs, ForageQualityCeilingFactor.get(), ForageQualitySlowFactor.get(), res, successFactor, 0, row, propDrop );
fprintf( f, "%g;%g;%g;%g;%g;%g;%g;%g;%g;%u;%u;\n",
res[CHarvestSource::A], res[CHarvestSource::Q],
testSource->getD(), testSource->getE(), 0.f /*testSource->getC()*/,
reqS, reqA, reqQ,
testSource->quantity(), testSource->getImpactScheme()*5, 127 );
if ( (!eventD) && (testSource->getD() > 127) )
{
fprintf( f2, "D: %u\n", i );
eventD = true;
}
if ( (!eventE) && (testSource->getE() > 127) )
{
fprintf( f2, "E: %u\n", i );
eventE = true;
}
/*if ( (!eventC) && (testSource->getC() > 127) )
{
fprintf( f2, "C: %u\n", i );
eventC = true;
}*/
}
if ( !eventD )
fprintf( f2, "D---\n" );
if ( !eventE )
fprintf( f2, "E---\n" );
if ( !eventC )
fprintf( f2, "C---\n" );
fclose( f );
fclose( f2 );
return true;
}
void CMirrorService::receiveDeltaFromRemoteMS( CMessage& msgin, TServiceId senderMSId )
{
H_AUTO(receiveDeltaFromRemoteMS);
// 2b. Receive delta updates from remote MSs => store them in pending deltas
_PendingDeltas.push_back( make_pair( senderMSId, msgin ) ); // warning: msgin must be copied because below we advance the reading position of msgin
//nldebug( "Received delta from %s", servStr(senderMSId).c_str() );
// Get the "wait for" mode of this remote MS delta
bool waitForIt;
msgin.serial( waitForIt );
if ( waitForIt ) // we assume it does not change during the lifetime of a particular remote MS
{
// Check if the sender is a new remote MS (search in the "delta update expectation list")
std::list< TServiceId >::const_iterator it = find( _RemoteMSToWaitForDelta.begin(), _RemoteMSToWaitForDelta.end(), senderMSId );
if ( it == _RemoteMSToWaitForDelta.end() )
{
_RemoteMSToWaitForDelta.push_back( senderMSId ); // _RemoteMSToWaitForDelta will not contain remote MSes for which we don't have to wait
++_NbExpectedDeltaUpdates;
}
}
TGameCycle gamecycle;
msgin.serial( gamecycle );
//nldebug( "%u: Rcvd Delta %u", CTickProxy::getGameCycle(), gamecycle );
_QuickLog.displayNL( "TCK-%u: Rcvd Delta %u from MS-%hu (NbExpectedDelta=%hd)", CTickProxy::getGameCycle(), gamecycle, senderMSId.get(), _NbExpectedDeltaUpdates );
// Count this delta update for the wait test only if its tick is the current tick or +1 (see explanation below)
// Explanation: possibles cases:
//
// MS1 MS2
// | |
// Tick1>| Tick1>|
// Delta>|>Delta <====> Delta>|>Delta
// |>Tock1 |>Tock1
// | |
// | Tick2>|
// Delta>| <----- |>Delta
// Tick2>|>Delta -----> Delta>|>Tock2
// |>Tock2 |
//
if ( CTickProxy::State == ExpectingMasterTick )
{
// If sync not received yet, defer possible incrementation of _NbDeltaUpdatesReceived
// because we can't compare now the gamecycle of the delta update with the current gamecycle
// (see examineDeltaUpdatesReceivedBeforeSync() called when receiving the sync)
if ( CTickProxy::getGameCycle() == 0 )
{
if ( waitForIt )
_GameCyclesOfDeltaReceivedBeforeSync.push_back( gamecycle );
return;
}
// Accept +1 only if received by advance (before the tick update)
// Forbid >+1
// Discard <=
else if ( gamecycle > CTickProxy::getGameCycle() )
{
nlassert( gamecycle == CTickProxy::getGameCycle() + 1 );
if ( waitForIt )
++_NbDeltaUpdatesReceived;
}
}
else
{
// Accept == if received in the same tick
// Forbid >
// Discard <
if ( gamecycle >= CTickProxy::getGameCycle() )
{
nlassert( gamecycle == CTickProxy::getGameCycle() );
if ( waitForIt )
++_NbDeltaUpdatesReceived;
}
}
doNextTask();
}