Merge branch 'master' of github.com:worklist/hifi

This commit is contained in:
Stephen Birarda 2013-09-09 16:19:47 -07:00
commit 0f988b1a61
12 changed files with 226 additions and 120 deletions

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 = {};
@ -29,6 +32,9 @@ int numForks = 0;
void childClient() {
// this is one of the child forks or there is a single assignment client, continue assignment-client execution
// set the logging target to the the CHILD_TARGET_NAME
Logging::setTargetName(CHILD_TARGET_NAME);
// create a NodeList as an unassigned client
NodeList* nodeList = NodeList::createInstance(NODE_TYPE_UNASSIGNED);
@ -58,17 +64,19 @@ void childClient() {
if (nodeList->getNodeSocket()->receive(packetData, &receivedBytes) &&
packetData[0] == PACKET_TYPE_DEPLOY_ASSIGNMENT && packetVersionMatch(packetData)) {
// construct the deployed assignment from the packet data
Assignment deployedAssignment(packetData, receivedBytes);
qDebug() << "Received an assignment - " << deployedAssignment << "\n";
qDebug() << "Received an assignment -" << deployedAssignment << "\n";
// 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);
qDebug("Changed Domain IP to %s\n", inet_ntoa(domainSocketAddr));
}
if (deployedAssignment.getType() == Assignment::AudioMixer) {
@ -77,11 +85,14 @@ void childClient() {
AvatarMixer::run();
}
qDebug() << "Assignment finished or never started - waiting for new assignment";
qDebug("Assignment finished or never started - waiting for new assignment\n");
// reset our NodeList by switching back to unassigned and clearing the list
nodeList->setOwnerType(NODE_TYPE_UNASSIGNED);
nodeList->clear();
// reset the logging target to the the CHILD_TARGET_NAME
Logging::setTargetName(CHILD_TARGET_NAME);
}
}
}
@ -96,14 +107,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 +123,9 @@ void sigchldHandler(int sig) {
} else {
// this is the parent, replace the dead process with the new one
::childForks[i] = newForkProcessID;
qDebug("Replaced dead %d with new fork %d\n", processID, newForkProcessID);
break;
}
}
@ -148,6 +159,12 @@ int main(int argc, const char* argv[]) {
setvbuf(stdout, NULL, _IOLBF, 0);
// use the verbose message handler in Logging
qInstallMessageHandler(Logging::verboseMessageHandler);
// start the Logging class with the parent's target name
Logging::setTargetName(PARENT_TARGET_NAME);
// grab the overriden assignment-server hostname from argv, if it exists
const char* customAssignmentServer = getCmdOption(argc, argv, "-a");
if (customAssignmentServer) {
@ -165,12 +182,12 @@ int main(int argc, const char* argv[]) {
if (numForksString) {
::numForks = atoi(numForksString);
qDebug() << "Starting" << numForks << "assignment clients.";
qDebug("Starting %d assignment clients\n", ::numForks);
::childForks = new pid_t[numForks];
::childForks = new pid_t[::numForks];
// fire off as many children as we need (this is one less than the parent since the parent will run as well)
for (int i = 0; i < numForks; i++) {
for (int i = 0; i < ::numForks; i++) {
processID = fork();
if (processID == 0) {
@ -183,7 +200,7 @@ int main(int argc, const char* argv[]) {
}
}
if (processID == 0 || numForks == 0) {
if (processID == 0 || ::numForks == 0) {
childClient();
} else {
parentMonitor();

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);
}

View file

@ -48,7 +48,7 @@
#include <NodeTypes.h>
#include <AudioInjectionManager.h>
#include <AudioInjector.h>
#include <Logstash.h>
#include <Logging.h>
#include <OctalCode.h>
#include <PacketHeaders.h>
#include <PairingHandler.h>
@ -318,7 +318,7 @@ void Application::initializeGL() {
const char LOGSTASH_INTERFACE_START_TIME_KEY[] = "interface-start-time";
// ask the Logstash class to record the startup time
Logstash::stashValue(STAT_TYPE_TIMER, LOGSTASH_INTERFACE_START_TIME_KEY, startupTime);
Logging::stashValue(STAT_TYPE_TIMER, LOGSTASH_INTERFACE_START_TIME_KEY, startupTime);
}
// update before the first render

View file

@ -102,8 +102,7 @@ static Closure cmakeBuild(srcDir, instCommand) {
def targets = [
'animation-server':true,
'assignment-server':true,
'audio-mixer':true,
'avatar-mixer':true,
'assignment-client':true,
'domain-server':true,
'eve':true,
'pairing-server':true,
@ -188,4 +187,4 @@ doxygenJob.with {
}
}
queue doxygenJob
queue doxygenJob

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>
@ -57,6 +57,8 @@ const unsigned int BUFFER_SEND_INTERVAL_USECS = floorf((BUFFER_LENGTH_SAMPLES_PE
const int MAX_SAMPLE_VALUE = std::numeric_limits<int16_t>::max();
const int MIN_SAMPLE_VALUE = std::numeric_limits<int16_t>::min();
const char AUDIO_MIXER_LOGGING_TARGET_NAME[] = "audio-mixer";
void attachNewBufferToNode(Node *newNode) {
if (!newNode->getLinkedData()) {
if (newNode->getType() == NODE_TYPE_AGENT) {
@ -68,6 +70,8 @@ void attachNewBufferToNode(Node *newNode) {
}
void AudioMixer::run() {
// change the logging target name while this is running
Logging::setTargetName(AUDIO_MIXER_LOGGING_TARGET_NAME);
NodeList *nodeList = NodeList::getInstance();
nodeList->setOwnerType(NODE_TYPE_AUDIO_MIXER);
@ -105,8 +109,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 +118,7 @@ void AudioMixer::run() {
break;
}
if (Logstash::shouldSendStats()) {
if (Logging::shouldSendStats()) {
gettimeofday(&beginSendTime, NULL);
}
@ -123,12 +127,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 +402,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)

View file

@ -10,6 +10,7 @@
// The avatar mixer receives head, hand and positional data from all connected
// nodes, and broadcasts that data back to them, every BROADCAST_INTERVAL ms.
#include <Logging.h>
#include <NodeList.h>
#include <PacketHeaders.h>
#include <SharedUtil.h>
@ -18,6 +19,8 @@
#include "AvatarMixer.h"
const char AVATAR_MIXER_LOGGING_NAME[] = "avatar-mixer";
unsigned char* addNodeToBroadcastPacket(unsigned char *currentPosition, Node *nodeToAdd) {
currentPosition += packNodeId(currentPosition, nodeToAdd->getNodeID());
@ -81,6 +84,9 @@ void broadcastAvatarData(NodeList* nodeList, sockaddr* nodeAddress) {
}
void AvatarMixer::run() {
// change the logging target name while AvatarMixer is running
Logging::setTargetName(AVATAR_MIXER_LOGGING_NAME);
NodeList* nodeList = NodeList::getInstance();
nodeList->setOwnerType(NODE_TYPE_AVATAR_MIXER);

View file

@ -0,0 +1,118 @@
//
// Logging.cpp
// hifi
//
// Created by Stephen Birarda on 6/11/13.
// Copyright (c) 2013 HighFidelity, Inc. All rights reserved.
//
#include <cstring>
#include <cstdio>
#include <iostream>
#include <netdb.h>
#include "SharedUtil.h"
#include "NodeList.h"
#include "Logging.h"
sockaddr_in Logging::logstashSocket = {};
char* Logging::targetName = NULL;
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);
}
}
void Logging::setTargetName(const char* targetName) {
// remove the old target name, if it exists
delete Logging::targetName;
// copy over the new target name
Logging::targetName = new char[strlen(targetName)];
strcpy(Logging::targetName, targetName);
}
const char* stringForLogType(QtMsgType msgType) {
switch (msgType) {
case QtDebugMsg:
return "DEBUG";
case QtCriticalMsg:
return "CRITICAL";
case QtFatalMsg:
return "FATAL";
case QtWarningMsg:
return "WARNING";
}
}
// the following will produce 2000-10-02 13:55:36 -0700
const char DATE_STRING_FORMAT[] = "%F %H:%M:%S %z";
void Logging::verboseMessageHandler(QtMsgType type, const QMessageLogContext& context, const QString& message) {
// log prefix is in the following format
// [DEBUG] [TIMESTAMP] [PID:PARENT_PID] [TARGET] logged string
QString prefixString = QString("[%1]").arg(stringForLogType(type));
time_t rawTime;
time(&rawTime);
struct tm* localTime = localtime(&rawTime);
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("]");
}
if (Logging::targetName) {
prefixString.append(QString(" [%1]").arg(Logging::targetName));
}
fprintf(stdout, "%s %s", prefixString.toLocal8Bit().constData(), message.toLocal8Bit().constData());
}

View file

@ -0,0 +1,51 @@
//
// Logging.h
// hifi
//
// Created by Stephen Birarda on 6/11/13.
// Copyright (c) 2013 HighFidelity, Inc. All rights reserved.
//
#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";
const char STAT_TYPE_TIMER = 't';
const char STAT_TYPE_COUNTER = 'c';
const char STAT_TYPE_GAUGE = 'g';
/// Handles custom message handling and sending of stats/logs to Logstash instance
class Logging {
public:
/// \return the socket used to send stats to logstash
static sockaddr* socket();
/// checks if this target should send stats to logstash, given its current environment
/// \return true if the caller should send stats to logstash
static bool shouldSendStats();
/// stashes a float value to Logstash instance
/// \param statType a stat type from the constants in this file
/// \param key the key at which to store the stat
/// \param value the value to store
static void stashValue(char statType, const char* key, float value);
/// sets the target name to output via the verboseMessageHandler, called once before logging begins
/// \param targetName the desired target name to output in logs
static void setTargetName(const char* targetName);
/// a qtMessageHandler that can be hooked up to a target that links to Qt
/// prints various process, message type, and time information
static void verboseMessageHandler(QtMsgType type, const QMessageLogContext& context, const QString &message);
private:
static sockaddr_in logstashSocket;
static char* targetName;
};
#endif /* defined(__hifi__Logstash__) */

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);
}
}

View file

@ -1,30 +0,0 @@
//
// Logstash.h
// hifi
//
// Created by Stephen Birarda on 6/11/13.
// Copyright (c) 2013 HighFidelity, Inc. All rights reserved.
//
#ifndef __hifi__Logstash__
#define __hifi__Logstash__
#include <netinet/in.h>
const int LOGSTASH_UDP_PORT = 9500;
const char LOGSTASH_HOSTNAME[] = "graphite.highfidelity.io";
const char STAT_TYPE_TIMER = 't';
const char STAT_TYPE_COUNTER = 'c';
const char STAT_TYPE_GAUGE = 'g';
class Logstash {
public:
static sockaddr* socket();
static bool shouldSendStats();
static void stashValue(char statType, const char* key, float value);
private:
static sockaddr_in logstashSocket;
};
#endif /* defined(__hifi__Logstash__) */

View file

@ -14,6 +14,7 @@
#include <QtCore/QDebug>
#include "Assignment.h"
#include "Logging.h"
#include "NodeList.h"
#include "NodeTypes.h"
#include "PacketHeaders.h"
@ -43,7 +44,7 @@ NodeList* NodeList::createInstance(char ownerType, unsigned short int socketList
if (!_sharedInstance) {
_sharedInstance = new NodeList(ownerType, socketListenPort);
} else {
qDebug("NodeList createInstance called with existing instance.\n");
qDebug("NodeList createInstance called with existing instance.");
}
return _sharedInstance;
@ -51,7 +52,7 @@ NodeList* NodeList::createInstance(char ownerType, unsigned short int socketList
NodeList* NodeList::getInstance() {
if (!_sharedInstance) {
qDebug("NodeList getInstance called before call to createInstance. Returning NULL pointer.\n");
qDebug("NodeList getInstance called before call to createInstance. Returning NULL pointer.");
}
return _sharedInstance;
@ -278,7 +279,6 @@ void NodeList::sendDomainServerCheckIn() {
sockaddr_in tempAddress;
memcpy(&tempAddress.sin_addr, pHostInfo->h_addr_list[0], pHostInfo->h_length);
strcpy(_domainIP, inet_ntoa(tempAddress.sin_addr));
qDebug("Domain Server: %s\n", _domainHostname);
} else {
qDebug("Failed domain server lookup\n");
@ -516,7 +516,7 @@ void* removeSilentNodes(void *args) {
if ((checkTimeUSecs - node->getLastHeardMicrostamp()) > NODE_SILENCE_THRESHOLD_USECS) {
qDebug() << "Killed" << *node << "\n";
qDebug() << "Killed " << *node << "\n";
nodeList->notifyHooksOfKilledNode(&*node);

View file

@ -23,6 +23,7 @@
#include <QtCore/QDebug>
#include "Logging.h"
#include "UDPSocket.h"
sockaddr_in destSockaddr, senderAddress;
@ -170,7 +171,7 @@ UDPSocket::UDPSocket(unsigned short int listeningPort) :
const int DEFAULT_BLOCKING_SOCKET_TIMEOUT_USECS = 0.5 * 1000000;
setBlockingReceiveTimeoutInUsecs(DEFAULT_BLOCKING_SOCKET_TIMEOUT_USECS);
qDebug("Created UDP socket listening on port %hu.\n", _listeningPort);
qDebug("Created UDP Socket listening on %hd\n", _listeningPort);
}
UDPSocket::~UDPSocket() {