Mirrors/overte
3
0
Fork 0
mirror of https://github.com/overte-org/overte.git synced 2025-04-07 17:52:26 +02:00
Code Issues Projects Releases Packages Wiki Activity Actions 2

add standardized logging and leverage forked assignment clients

Browse source
This commit is contained in:
Stephen Birarda 2013-09-09 14:21:33 -07:00
parent 361c8b8cd0
commit 8077963bb1
8 changed files with 150 additions and 82 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

20
assignment-client/src/main.cpp
View file

@ -15,11 +15,14 @@
#include <Assignment.h>
#include <AudioMixer.h>
#include <AvatarMixer.h>
#include <Logging.h>
#include <NodeList.h>
#include <PacketHeaders.h>
#include <SharedUtil.h>
const long long ASSIGNMENT_REQUEST_INTERVAL_USECS = 1 * 1000 * 1000;
const char PARENT_TARGET_NAME[] = "assignment-client-monitor";
const char CHILD_TARGET_NAME[] = "assignment-client";
pid_t* childForks = NULL;
sockaddr_in customAssignmentSocket = {};
@ -61,14 +64,15 @@ void childClient() {
// construct the deployed assignment from the packet data
Assignment deployedAssignment(packetData, receivedBytes);
qDebug() << "Received an assignment - " << deployedAssignment << "\n";
Logging::standardizedLog(QString("Received an assignment - %1").arg(deployedAssignment.toString()),
CHILD_TARGET_NAME);
// switch our nodelist DOMAIN_IP to the ip receieved in the assignment
if (deployedAssignment.getDomainSocket()->sa_family == AF_INET) {
in_addr domainSocketAddr = ((sockaddr_in*) deployedAssignment.getDomainSocket())->sin_addr;
nodeList->setDomainIP(inet_ntoa(domainSocketAddr));
qDebug() << "Changed domain IP to " << inet_ntoa(domainSocketAddr);
Logging::standardizedLog(QString("Changed Domain IP to %1").arg(inet_ntoa(domainSocketAddr)), CHILD_TARGET_NAME);
}
if (deployedAssignment.getType() == Assignment::AudioMixer) {
@ -77,7 +81,8 @@ void childClient() {
AvatarMixer::run();
}
qDebug() << "Assignment finished or never started - waiting for new assignment";
Logging::standardizedLog(QString("Assignment finished or never started - waiting for new assignment"),
CHILD_TARGET_NAME);
// reset our NodeList by switching back to unassigned and clearing the list
nodeList->setOwnerType(NODE_TYPE_UNASSIGNED);
@ -96,14 +101,11 @@ void sigchldHandler(int sig) {
break;
}
qDebug() << "Handling death of" << processID;
int newForkProcessID = 0;
// find the dead process in the array of child forks
for (int i = 0; i < ::numForks; i++) {
if (::childForks[i] == processID) {
qDebug() << "Matched" << ::childForks[i] << "with" << processID;
newForkProcessID = fork();
if (newForkProcessID == 0) {
@ -115,6 +117,10 @@ void sigchldHandler(int sig) {
} else {
// this is the parent, replace the dead process with the new one
::childForks[i] = newForkProcessID;
Logging::standardizedLog(QString("Repleaced dead %1 with new fork %2").arg(processID).arg(newForkProcessID),
PARENT_TARGET_NAME);
break;
}
}
@ -165,7 +171,7 @@ int main(int argc, const char* argv[]) {
if (numForksString) {
::numForks = atoi(numForksString);
qDebug() << "Starting" << numForks << "assignment clients.";
Logging::standardizedLog(QString("Starting %1 assignment clients").arg(numForks), PARENT_TARGET_NAME);
::childForks = new pid_t[numForks];

6
domain-server/src/main.cpp
View file

@ -28,7 +28,7 @@
#include "Assignment.h"
#include "NodeList.h"
#include "NodeTypes.h"
#include "Logstash.h"
#include "Logging.h"
#include "PacketHeaders.h"
#include "SharedUtil.h"
@ -234,12 +234,12 @@ int main(int argc, const char* argv[]) {
}
}
if (Logstash::shouldSendStats()) {
if (Logging::shouldSendStats()) {
if (usecTimestampNow() - usecTimestamp(&lastStatSendTime) >= (NODE_COUNT_STAT_INTERVAL_MSECS * 1000)) {
// time to send our count of nodes and servers to logstash
const char NODE_COUNT_LOGSTASH_KEY[] = "ds-node-count";
Logstash::stashValue(STAT_TYPE_TIMER, NODE_COUNT_LOGSTASH_KEY, nodeList->getNumAliveNodes());
Logging::stashValue(STAT_TYPE_TIMER, NODE_COUNT_LOGSTASH_KEY, nodeList->getNumAliveNodes());
gettimeofday(&lastStatSendTime, NULL);
}

14
libraries/audio/src/AudioMixer.cpp
View file

@ -32,7 +32,7 @@
#include <glm/gtx/norm.hpp>
#include <glm/gtx/vector_angle.hpp>
#include <Logstash.h>
#include <Logging.h>
#include <NodeList.h>
#include <Node.h>
#include <NodeTypes.h>
@ -105,8 +105,8 @@ void AudioMixer::run() {
stk::StkFrames stkFrameBuffer(BUFFER_LENGTH_SAMPLES_PER_CHANNEL, 1);
// if we'll be sending stats, call the Logstash::socket() method to make it load the logstash IP outside the loop
if (Logstash::shouldSendStats()) {
Logstash::socket();
if (Logging::shouldSendStats()) {
Logging::socket();
}
while (true) {
@ -114,7 +114,7 @@ void AudioMixer::run() {
break;
}
if (Logstash::shouldSendStats()) {
if (Logging::shouldSendStats()) {
gettimeofday(&beginSendTime, NULL);
}
@ -123,12 +123,12 @@ void AudioMixer::run() {
gettimeofday(&lastDomainServerCheckIn, NULL);
NodeList::getInstance()->sendDomainServerCheckIn();
if (Logstash::shouldSendStats() && numStatCollections > 0) {
if (Logging::shouldSendStats() && numStatCollections > 0) {
// if we should be sending stats to Logstash send the appropriate average now
const char MIXER_LOGSTASH_METRIC_NAME[] = "audio-mixer-frame-time-usage";
float averageFrameTimePercentage = sumFrameTimePercentages / numStatCollections;
Logstash::stashValue(STAT_TYPE_TIMER, MIXER_LOGSTASH_METRIC_NAME, averageFrameTimePercentage);
Logging::stashValue(STAT_TYPE_TIMER, MIXER_LOGSTASH_METRIC_NAME, averageFrameTimePercentage);
sumFrameTimePercentages = 0.0f;
numStatCollections = 0;
@ -398,7 +398,7 @@ void AudioMixer::run() {
}
}
if (Logstash::shouldSendStats()) {
if (Logging::shouldSendStats()) {
// send a packet to our logstash instance
// calculate the percentage value for time elapsed for this send (of the max allowable time)

6
libraries/shared/src/Assignment.cpp
View file

@ -130,7 +130,11 @@ int Assignment::packToBuffer(unsigned char* buffer) {
return numPackedBytes;
}
QString Assignment::toString() const {
return QString("T:%1 P:%2").arg(_type).arg(_pool);
}
QDebug operator<<(QDebug debug, const Assignment &assignment) {
debug << "T:" << assignment.getType() << "P:" << assignment.getPool();
debug << assignment.toString().toStdString().c_str();
return debug.nospace();
}

2
libraries/shared/src/Assignment.h
View file

@ -54,6 +54,8 @@ public:
/// Sets _time to the current time given by gettimeofday
void setCreateTimeToNow() { gettimeofday(&_time, NULL); }
QString toString() const;
private:
Assignment::Direction _direction; /// the direction of the assignment (Create, Deploy, Request)
Assignment::Type _type; /// the type of the assignment, defines what the assignee will do

106
libraries/shared/src/Logging.cpp Normal file
View file

@ -0,0 +1,106 @@
//
// Logging.cpp
// hifi
//
// Created by Stephen Birarda on 6/11/13.
// Copyright (c) 2013 HighFidelity, Inc. All rights reserved.
//
#include <cstring>
#include <cstdio>
#include <netdb.h>
#include "SharedUtil.h"
#include "NodeList.h"
#include "Logging.h"
sockaddr_in Logging::logstashSocket = {};
sockaddr* Logging::socket() {
if (logstashSocket.sin_addr.s_addr == 0) {
// we need to construct the socket object
// assume IPv4
logstashSocket.sin_family = AF_INET;
// use the constant port
logstashSocket.sin_port = htons(LOGSTASH_UDP_PORT);
// lookup the IP address for the constant hostname
struct hostent* logstashHostInfo;
if ((logstashHostInfo = gethostbyname(LOGSTASH_HOSTNAME))) {
memcpy(&logstashSocket.sin_addr, logstashHostInfo->h_addr_list[0], logstashHostInfo->h_length);
} else {
printf("Failed to lookup logstash IP - will try again on next log attempt.\n");
}
}
return (sockaddr*) &logstashSocket;
}
bool Logging::shouldSendStats() {
static bool shouldSendStats = isInEnvironment("production");
return shouldSendStats;
}
void Logging::stashValue(char statType, const char* key, float value) {
static char logstashPacket[MAX_PACKET_SIZE];
// load up the logstash packet with the key and the passed float value
// send it to 4 decimal places
int numPacketBytes = sprintf(logstashPacket, "%c %s %.4f", statType, key, value);
NodeList *nodeList = NodeList::getInstance();
if (nodeList) {
nodeList->getNodeSocket()->send(socket(), logstashPacket, numPacketBytes);
}
}
const QString DEBUG_STRING = "DEBUG";
const QString WARN_STRING = "WARN";
const QString ERROR_STRING = "ERROR";
const QString& stringForLogType(Logging::Type logType) {
if (logType == Logging::Debug) {
return DEBUG_STRING;
} else if (logType == Logging::Warn) {
return WARN_STRING;
} else {
return ERROR_STRING;
}
}
// the following will produce 2000-10-02 13:55:36 -0700
const char DATE_STRING_FORMAT[] = "%F %H:%M:%S %z";
void Logging::standardizedLog(const QString &output, const char* targetName, Logging::Type logType) {
time_t rawTime;
time(&rawTime);
struct tm* localTime = localtime(&rawTime);
// log prefix is in the following format
// [DEBUG] [TIMESTAMP] [PID:PARENT_PID] [TARGET] logged string
QString prefixString = QString("[%1] ").arg(stringForLogType(logType));
char dateString[100];
strftime(dateString, sizeof(dateString), DATE_STRING_FORMAT, localTime);
prefixString.append(QString("[%1] ").arg(dateString));
prefixString.append(QString("[%1").arg(getpid()));
pid_t parentProcessID = getppid();
if (parentProcessID != 0) {
prefixString.append(QString(":%1] ").arg(parentProcessID));
} else {
prefixString.append("]");
}
prefixString.append(QString("[%1]").arg(targetName));
qDebug("%s %s", prefixString.toStdString().c_str(), output.toStdString().c_str());
}

18
libraries/shared/src/Logstash.h → libraries/shared/src/Logging.h
View file

@ -1,16 +1,18 @@
//
// Logstash.h
// Logging.h
// hifi
//
// Created by Stephen Birarda on 6/11/13.
// Copyright (c) 2013 HighFidelity, Inc. All rights reserved.
//
#ifndef __hifi__Logstash__
#define __hifi__Logstash__
#ifndef __hifi__Logging__
#define __hifi__Logging__
#include <netinet/in.h>
#include <QtCore/QString>
const int LOGSTASH_UDP_PORT = 9500;
const char LOGSTASH_HOSTNAME[] = "graphite.highfidelity.io";
@ -18,11 +20,19 @@ const char STAT_TYPE_TIMER = 't';
const char STAT_TYPE_COUNTER = 'c';
const char STAT_TYPE_GAUGE = 'g';
class Logstash {
class Logging {
public:
enum Type {
Error,
Warn,
Debug
};
static sockaddr* socket();
static bool shouldSendStats();
static void stashValue(char statType, const char* key, float value);
static void standardizedLog(const QString& output, const char* targetName, Logging::Type logType = Logging::Debug);
private:
static sockaddr_in logstashSocket;
};

60
libraries/shared/src/Logstash.cpp
View file

@ -1,60 +0,0 @@
//
// Logstash.cpp
// hifi
//
// Created by Stephen Birarda on 6/11/13.
// Copyright (c) 2013 HighFidelity, Inc. All rights reserved.
//
#include <cstring>
#include <cstdio>
#include <netdb.h>
#include "SharedUtil.h"
#include "NodeList.h"
#include "Logstash.h"
sockaddr_in Logstash::logstashSocket = {};
sockaddr* Logstash::socket() {
if (logstashSocket.sin_addr.s_addr == 0) {
// we need to construct the socket object
// assume IPv4
logstashSocket.sin_family = AF_INET;
// use the constant port
logstashSocket.sin_port = htons(LOGSTASH_UDP_PORT);
// lookup the IP address for the constant hostname
struct hostent* logstashHostInfo;
if ((logstashHostInfo = gethostbyname(LOGSTASH_HOSTNAME))) {
memcpy(&logstashSocket.sin_addr, logstashHostInfo->h_addr_list[0], logstashHostInfo->h_length);
} else {
printf("Failed to lookup logstash IP - will try again on next log attempt.\n");
}
}
return (sockaddr*) &logstashSocket;
}
bool Logstash::shouldSendStats() {
static bool shouldSendStats = isInEnvironment("production");
return shouldSendStats;
}
void Logstash::stashValue(char statType, const char* key, float value) {
static char logstashPacket[MAX_PACKET_SIZE];
// load up the logstash packet with the key and the passed float value
// send it to 4 decimal places
int numPacketBytes = sprintf(logstashPacket, "%c %s %.4f", statType, key, value);
NodeList *nodeList = NodeList::getInstance();
if (nodeList) {
nodeList->getNodeSocket()->send(socket(), logstashPacket, numPacketBytes);
}
}