diff --git a/client/alsaPlayer.cpp b/client/alsaPlayer.cpp index 2678861a..2f238440 100644 --- a/client/alsaPlayer.cpp +++ b/client/alsaPlayer.cpp @@ -1,4 +1,5 @@ #include "alsaPlayer.h" +#include "common/log.h" #include #include @@ -22,10 +23,8 @@ void Player::start() channels = stream_->format.channels; /* Open the PCM device in playback mode */ - if ((pcm = snd_pcm_open(&pcm_handle, pcmDevice_.name.c_str(), - SND_PCM_STREAM_PLAYBACK, 0)) < 0) - cout << "ERROR: Can't open " << pcmDevice_.name << " PCM device. " - << snd_strerror(pcm) << "\n"; + if ((pcm = snd_pcm_open(&pcm_handle, pcmDevice_.name.c_str(), SND_PCM_STREAM_PLAYBACK, 0)) < 0) + logE << "ERROR: Can't open " << pcmDevice_.name << " PCM device. " << snd_strerror(pcm) << "\n"; /* struct snd_pcm_playback_info_t pinfo; if ( (pcm = snd_pcm_playback_info( pcm_handle, &pinfo )) < 0 ) @@ -38,23 +37,17 @@ void Player::start() snd_pcm_hw_params_any(pcm_handle, params); /* Set parameters */ - if ((pcm = snd_pcm_hw_params_set_access(pcm_handle, params, - SND_PCM_ACCESS_RW_INTERLEAVED)) < 0) - cout << "ERROR: Can't set interleaved mode. " << snd_strerror(pcm) - << "\n"; + if ((pcm = snd_pcm_hw_params_set_access(pcm_handle, params, SND_PCM_ACCESS_RW_INTERLEAVED)) < 0) + logE << "ERROR: Can't set interleaved mode. " << snd_strerror(pcm) << "\n"; - if ((pcm = snd_pcm_hw_params_set_format(pcm_handle, params, - SND_PCM_FORMAT_S16_LE)) < 0) - cout << "ERROR: Can't set format. " << snd_strerror(pcm) << "\n"; + if ((pcm = snd_pcm_hw_params_set_format(pcm_handle, params, SND_PCM_FORMAT_S16_LE)) < 0) + logE << "ERROR: Can't set format. " << snd_strerror(pcm) << "\n"; - if ((pcm = snd_pcm_hw_params_set_channels(pcm_handle, params, channels)) - < 0) - cout << "ERROR: Can't set channels number. " << snd_strerror(pcm) - << "\n"; + if ((pcm = snd_pcm_hw_params_set_channels(pcm_handle, params, channels)) < 0) + logE << "ERROR: Can't set channels number. " << snd_strerror(pcm) << "\n"; - if ((pcm = snd_pcm_hw_params_set_rate_near(pcm_handle, params, &rate, 0)) - < 0) - cout << "ERROR: Can't set rate. " << snd_strerror(pcm) << "\n"; + if ((pcm = snd_pcm_hw_params_set_rate_near(pcm_handle, params, &rate, 0)) < 0) + logE << "ERROR: Can't set rate. " << snd_strerror(pcm) << "\n"; unsigned int buffer_time; snd_pcm_hw_params_get_buffer_time_max(params, &buffer_time, 0); @@ -68,37 +61,30 @@ void Player::start() // long unsigned int periodsize = stream_->format.msRate() * 50;//2*rate/50; // if ((pcm = snd_pcm_hw_params_set_buffer_size_near(pcm_handle, params, &periodsize)) < 0) -// cout << "Unable to set buffer size " << (long int)periodsize << ": " << snd_strerror(pcm) << "\n"; +// logE << "Unable to set buffer size " << (long int)periodsize << ": " << snd_strerror(pcm) << "\n"; /* Write parameters */ if ((pcm = snd_pcm_hw_params(pcm_handle, params)) < 0) - cout << "ERROR: Can't set harware parameters. " << snd_strerror(pcm) - << "\n"; + logE << "ERROR: Can't set harware parameters. " << snd_strerror(pcm) << "\n"; /* Resume information */ - cout << "PCM name: " << snd_pcm_name(pcm_handle) << "\n"; - cout << "PCM state: " << snd_pcm_state_name(snd_pcm_state(pcm_handle)) - << "\n"; + logD << "PCM name: " << snd_pcm_name(pcm_handle) << "\n"; + logD << "PCM state: " << snd_pcm_state_name(snd_pcm_state(pcm_handle)) << "\n"; snd_pcm_hw_params_get_channels(params, &tmp); - cout << "channels: " << tmp << "\n"; - - if (tmp == 1) - printf("(mono)\n"); - else if (tmp == 2) - printf("(stereo)\n"); + logD << "channels: " << tmp << "\n"; snd_pcm_hw_params_get_rate(params, &tmp, 0); - cout << "rate: " << tmp << " bps\n"; + logD << "rate: " << tmp << " bps\n"; /* Allocate buffer to hold single period */ snd_pcm_hw_params_get_period_size(params, &frames, 0); - cout << "frames: " << frames << "\n"; + logD << "frames: " << frames << "\n"; buff_size = frames * channels * 2 /* 2 -> sample size */; buff = (char *) malloc(buff_size); snd_pcm_hw_params_get_period_time(params, &tmp, NULL); - cout << "period time: " << tmp << "\n"; + logD << "period time: " << tmp << "\n"; snd_pcm_sw_params_t *swparams; snd_pcm_sw_params_alloca(&swparams); @@ -144,27 +130,27 @@ void Player::stop() { } -void Player::worker() { +void Player::worker() +{ unsigned int pcm; snd_pcm_sframes_t framesAvail; snd_pcm_sframes_t framesDelay; -// active_ = true; while (active_) { snd_pcm_avail_delay(pcm_handle, &framesAvail, &framesDelay); chronos::usec delay((chronos::usec::rep) (1000 * (double) framesDelay / stream_->format.msRate())); -// cout << "Avail: " << framesAvail << ", delay: " << framesDelay << ", delay[ms]: " << delay.count() / 1000 << "\n"; + logD << "Avail: " << framesAvail << ", delay: " << framesDelay << ", delay[ms]: " << delay.count() / 1000 << "\n"; if (stream_->getPlayerChunk(buff, delay, frames)) { if ((pcm = snd_pcm_writei(pcm_handle, buff, frames)) == -EPIPE) { - printf("XRUN.\n"); + logE << "XRUN\n"; snd_pcm_prepare(pcm_handle); } else if (pcm < 0) { - printf("ERROR. Can't write to PCM device. %s\n", snd_strerror(pcm)); + logE << "ERROR. Can't write to PCM device: " << snd_strerror(pcm) << "\n"; } } else @@ -183,7 +169,8 @@ vector Player::pcm_list(void) { return result; n = hints; size_t idx(0); - while (*n != NULL) { + while (*n != NULL) + { name = snd_device_name_get_hint(*n, "NAME"); descr = snd_device_name_get_hint(*n, "DESC"); io = snd_device_name_get_hint(*n, "IOID"); diff --git a/client/clientConnection.cpp b/client/clientConnection.cpp index 23c8d70f..0f899ee8 100644 --- a/client/clientConnection.cpp +++ b/client/clientConnection.cpp @@ -46,7 +46,7 @@ void ClientConnection::start() tcp::resolver resolver(io_service); tcp::resolver::query query(tcp::v4(), ip, boost::lexical_cast(port)); iterator = resolver.resolve(query); - cout << "connecting\n"; + logO << "connecting\n"; socket.reset(new tcp::socket(io_service)); // struct timeval tv; // tv.tv_sec = 5; @@ -55,10 +55,9 @@ void ClientConnection::start() // setsockopt(socket->native(), SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv)); // setsockopt(socket->native(), SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)); socket->connect(*iterator); - cout << "MAC: \"" << getMacAddress(socket->native()) << "\"\n"; + logO << "MAC: \"" << getMacAddress(socket->native()) << "\"\n"; connected_ = true; - cout << "connected\n"; - std::clog << kLogNotice << "connected\n";// to " << ip << ":" << port << std::endl; + logS(kLogNotice) << "connected" << endl; active_ = true; readerThread = new thread(&ClientConnection::reader, this); } @@ -74,13 +73,13 @@ void ClientConnection::stop() if (socket) { socket->shutdown(boost::asio::ip::tcp::socket::shutdown_both, ec); - if (ec) cout << "Error in socket shutdown: " << ec << "\n"; + if (ec) logE << "Error in socket shutdown: " << ec << "\n"; socket->close(ec); - if (ec) cout << "Error in socket close: " << ec << "\n"; + if (ec) logE << "Error in socket close: " << ec << "\n"; } if (readerThread) { - cout << "joining readerThread\n"; + logD << "joining readerThread\n"; readerThread->join(); delete readerThread; } @@ -89,17 +88,17 @@ void ClientConnection::stop() { } readerThread = NULL; - cout << "readerThread terminated\n"; + logD << "readerThread terminated\n"; } bool ClientConnection::send(msg::BaseMessage* message) { // std::unique_lock mlock(mutex_); -//cout << "send: " << message->type << ", size: " << message->getSize() << "\n"; +//logD << "send: " << message->type << ", size: " << message->getSize() << "\n"; if (!connected()) return false; -//cout << "send: " << message->type << ", size: " << message->getSize() << "\n"; +//logD << "send: " << message->type << ", size: " << message->getSize() << "\n"; boost::asio::streambuf streambuf; std::ostream stream(&streambuf); tv t; @@ -116,7 +115,7 @@ shared_ptr ClientConnection::sendRequest(msg::BaseMessag if (++reqId == 10000) reqId = 1; message->id = reqId; -//cout << "Req: " << reqId << "\n"; +//logD << "Req: " << reqId << "\n"; shared_ptr pendingRequest(new PendingRequest(reqId)); { @@ -129,12 +128,12 @@ shared_ptr ClientConnection::sendRequest(msg::BaseMessag { response = pendingRequest->response; sumTimeout = chronos::msec(0); -//cout << "Resp: " << pendingRequest->id << "\n"; +//logD << "Resp: " << pendingRequest->id << "\n"; } else { sumTimeout += timeout; - cout << "timeout while waiting for response to: " << reqId << ", timeout " << sumTimeout.count() << "\n"; + logO << "timeout while waiting for response to: " << reqId << ", timeout " << sumTimeout.count() << "\n"; if (sumTimeout > chronos::sec(5)) throw SnapException("sum timeout exceeded 10s"); } @@ -153,7 +152,7 @@ void ClientConnection::getNextMessage() vector buffer(baseMsgSize); socketRead(&buffer[0], baseMsgSize); baseMessage.deserialize(&buffer[0]); -//cout << "getNextMessage: " << baseMessage.type << ", size: " << baseMessage.size << ", id: " << baseMessage.id << ", refers: " << baseMessage.refersTo << "\n"; +//logD << "getNextMessage: " << baseMessage.type << ", size: " << baseMessage.size << ", id: " << baseMessage.id << ", refers: " << baseMessage.refersTo << "\n"; if (baseMessage.size > buffer.size()) buffer.resize(baseMessage.size); socketRead(&buffer[0], baseMessage.size); diff --git a/client/controller.cpp b/client/controller.cpp index 339a4960..4f714fe4 100644 --- a/client/controller.cpp +++ b/client/controller.cpp @@ -7,6 +7,7 @@ #include "pcmDecoder.h" #include "alsaPlayer.h" #include "timeProvider.h" +#include "common/log.h" #include "message/serverSettings.h" #include "message/time.h" #include "message/request.h" @@ -23,7 +24,7 @@ Controller::Controller() : MessageReceiver(), active_(false), sampleFormat(NULL) void Controller::onException(ClientConnection* connection, const std::exception& exception) { - cout << "onException: " << exception.what() << "\n"; + logE << "onException: " << exception.what() << "\n"; } @@ -35,11 +36,11 @@ void Controller::onMessageReceived(ClientConnection* connection, const msg::Base { msg::PcmChunk* pcmChunk = new msg::PcmChunk(*sampleFormat, 0); pcmChunk->deserialize(baseMessage, buffer); -//cout << "chunk: " << pcmChunk->payloadSize; +//logD << "chunk: " << pcmChunk->payloadSize; if (decoder->decode(pcmChunk)) { stream->addChunk(pcmChunk); -//cout << ", decoded: " << pcmChunk->payloadSize << ", Duration: " << pcmChunk->getDuration() << ", sec: " << pcmChunk->timestamp.sec << ", usec: " << pcmChunk->timestamp.usec/1000 << ", type: " << pcmChunk->type << "\n"; +//logD << ", decoded: " << pcmChunk->payloadSize << ", Duration: " << pcmChunk->getDuration() << ", sec: " << pcmChunk->timestamp.sec << ", usec: " << pcmChunk->timestamp.usec/1000 << ", type: " << pcmChunk->type << "\n"; } else delete pcmChunk; @@ -60,7 +61,7 @@ void Controller::start(const PcmDevice& pcmDevice, const std::string& _ip, size_ void Controller::stop() { - cout << "Stopping\n"; + logD << "Stopping\n"; active_ = false; controllerThread->join(); clientConnection->stop(); @@ -84,16 +85,16 @@ void Controller::worker() msg::Request requestMsg(kServerSettings); shared_ptr serverSettings(NULL); while (active_ && !(serverSettings = clientConnection->sendReq(&requestMsg))); - cout << "ServerSettings buffer: " << serverSettings->bufferMs << "\n"; + logO << "ServerSettings buffer: " << serverSettings->bufferMs << "\n"; requestMsg.request = kSampleFormat; while (active_ && !(sampleFormat = clientConnection->sendReq(&requestMsg))); - cout << "SampleFormat rate: " << sampleFormat->rate << ", bits: " << sampleFormat->bits << ", channels: " << sampleFormat->channels << "\n"; + logO << "SampleFormat rate: " << sampleFormat->rate << ", bits: " << sampleFormat->bits << ", channels: " << sampleFormat->channels << "\n"; requestMsg.request = kHeader; shared_ptr headerChunk(NULL); while (active_ && !(headerChunk = clientConnection->sendReq(&requestMsg))); - cout << "Codec: " << headerChunk->codec << "\n"; + logO << "Codec: " << headerChunk->codec << "\n"; if (headerChunk->codec == "ogg") decoder = new OggDecoder(); else if (headerChunk->codec == "pcm") @@ -111,7 +112,7 @@ void Controller::worker() usleep(1000); } } - cout << "diff to server [ms]: " << TimeProvider::getInstance().getDiffToServer().count() << "\n"; + logO << "diff to server [ms]: " << TimeProvider::getInstance().getDiffToServer().count() << "\n"; stream = new Stream(*sampleFormat); stream->setBufferLen(serverSettings->bufferMs - latency_); @@ -137,22 +138,22 @@ void Controller::worker() } catch (const std::exception& e) { - cout << "Exception in Controller::worker(): " << e.what() << "\n"; - cout << "Deleting stream\n"; + logS(kLogErr) << "Exception in Controller::worker(): " << e.what() << endl; + logD << "Deleting stream\n"; if (stream != NULL) delete stream; stream = NULL; if (decoder != NULL) delete decoder; decoder = NULL; - cout << "Stopping clientConnection\n"; + logD << "Stopping clientConnection\n"; clientConnection->stop(); - cout << "done\n"; + logD << "done\n"; if (active_) usleep(500*1000); } } - cout << "Thread stopped\n"; + logD << "Thread stopped\n"; } diff --git a/client/snapClient.cpp b/client/snapClient.cpp index 3486f293..cabfc857 100644 --- a/client/snapClient.cpp +++ b/client/snapClient.cpp @@ -59,8 +59,9 @@ int main (int argc, char *argv[]) po::options_description desc("Allowed options"); desc.add_options() ("help,h", "produce help message") + ("version,v", "show version number") ("list,l", po::bool_switch(&listPcmDevices)->default_value(false), "list pcm devices") - ("ip,i", po::value(&ip)->default_value("192.168.0.2"), "server IP") + ("ip,i", po::value(&ip)->default_value("localhost"), "server IP") ("port,p", po::value(&port)->default_value(98765), "server port") ("soundcard,s", po::value(&soundcard)->default_value("default"), "index or name of the soundcard") ("daemon,d", po::bool_switch(&runAsDaemon)->default_value(false), "daemonize") @@ -71,9 +72,22 @@ int main (int argc, char *argv[]) po::store(po::parse_command_line(argc, argv, desc), vm); po::notify(vm); + std::clog.rdbuf(new Log("snapclient", LOG_DAEMON)); + if (vm.count("help")) { - cout << desc << "\n"; + logO << desc << "\n"; + return 1; + } + + if (vm.count("version")) + { + logO << "snapclient v" << VERSION << "\n" + << "Copyright (C) 2014 BadAix (snapcast@badaix.de).\n" + << "License GPLv3+: GNU GPL version 3 or later .\n" + << "This is free software: you are free to change and redistribute it.\n" + << "There is NO WARRANTY, to the extent permitted by law.\n\n" + << "Written by Johannes M. Pohl.\n"; return 1; } @@ -82,8 +96,8 @@ int main (int argc, char *argv[]) vector pcmDevices = Player::pcm_list(); for (auto dev: pcmDevices) { - cout << dev.idx << ": " << dev.name << "\n"; - cout << dev.description << "\n\n"; + logO << dev.idx << ": " << dev.name << "\n" + << dev.description << "\n\n"; } return 1; } @@ -92,22 +106,16 @@ int main (int argc, char *argv[]) signal(SIGTERM, signal_handler); signal(SIGINT, signal_handler); - std::clog.rdbuf(new Log("snapclient", LOG_DAEMON)); if (runAsDaemon) { daemonize("/var/run/snapclient.pid"); - std::clog << kLogNotice << "daemon started" << std::endl; + logS(kLogNotice) << "daemon started" << std::endl; } - logS(kLogNotice) << "daemon started" << std::endl; - logD << "debug test" << std::endl; - logO << "out test" << std::endl; - logE << "error test" << std::endl; - log << "test" << std::endl; PcmDevice pcmDevice = getPcmDevice(soundcard); if (pcmDevice.idx == -1) { - cout << "soundcard \"" << soundcard << "\" not found\n"; + logO << "soundcard \"" << soundcard << "\" not found\n"; return 1; } diff --git a/client/stream.cpp b/client/stream.cpp index 8c65daff..1d5336b5 100644 --- a/client/stream.cpp +++ b/client/stream.cpp @@ -33,7 +33,7 @@ void Stream::setRealSampleRate(double sampleRate) correctAfterXFrames = 0; else correctAfterXFrames = round((format.rate / sampleRate) / (format.rate / sampleRate - 1.)); -// cout << "Correct after X: " << correctAfterXFrames << " (Real rate: " << sampleRate << ", rate: " << format.rate << ")\n"; +// logD << "Correct after X: " << correctAfterXFrames << " (Real rate: " << sampleRate << ", rate: " << format.rate << ")\n"; } @@ -56,7 +56,7 @@ void Stream::addChunk(msg::PcmChunk* chunk) while (chunks.size() * chunk->duration().count() > 10000) chunks.pop(); chunks.push(shared_ptr(chunk)); -// cout << "new chunk: " << chunk->getDuration() << ", Chunks: " << chunks.size() << "\n"; +// logD << "new chunk: " << chunk->getDuration() << ", Chunks: " << chunks.size() << "\n"; } @@ -80,8 +80,8 @@ time_point_ms Stream::seekTo(const time_point_ms& to) while (to > chunk->timePoint())// + std::chrono::milliseconds((long int)chunk->getDuration()))// { chunk = chunks.pop(); - cout << "\nto: " << Chunk::getAge(to) << "\t chunk: " << Chunk::getAge(chunk->timePoint()) << "\n"; - cout << "diff: " << std::chrono::duration_cast((to - chunk->timePoint())).count() << "\n"; + logD << "\nto: " << Chunk::getAge(to) << "\t chunk: " << Chunk::getAge(chunk->timePoint()) << "\n"; + logD << "diff: " << std::chrono::duration_cast((to - chunk->timePoint())).count() << "\n"; } chunk->seek(std::chrono::duration_cast(to - chunk->timePoint()).count() * format.msRate()); return chunk->timePoint(); @@ -138,7 +138,7 @@ time_point_hrc Stream::getNextPlayerChunk(void* outputBuffer, const chronos::use float factor = (float)toRead / framesPerBuffer;//(float)(framesPerBuffer*channels_); if (abs(framesCorrection) > 1) - std::cout << "correction: " << framesCorrection << ", factor: " << factor << "\n"; + logO << "correction: " << framesCorrection << ", factor: " << factor << "\n"; float idx = 0; for (size_t n=0; n(TimeProvider::serverNow() - chunk->start() - bufferMs + outputBufferDacTime); if ((sleep.count() == 0) && (chronos::abs(age) > chronos::msec(200))) { - cout << "age > 200: " << age.count() << "\n"; + logO << "age > 200: " << age.count() << "\n"; sleep = age; } try { - //cout << "framesPerBuffer: " << framesPerBuffer << "\tms: " << framesPerBuffer*2 / PLAYER_CHUNK_MS_SIZE << "\t" << PLAYER_CHUNK_SIZE << "\n"; + //logD << "framesPerBuffer: " << framesPerBuffer << "\tms: " << framesPerBuffer*2 / PLAYER_CHUNK_MS_SIZE << "\t" << PLAYER_CHUNK_SIZE << "\n"; chronos::nsec bufferDuration = chronos::nsec(chronos::usec::rep(framesPerBuffer / format_.nsRate())); -// cout << "buffer duration: " << bufferDuration.count() << "\n"; +// logD << "buffer duration: " << bufferDuration.count() << "\n"; chronos::usec correction = chronos::usec(0); if (sleep.count() != 0) @@ -202,7 +202,7 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe { // We're early: not enough chunks. play silence. Reference chunk is the oldest (front) one sleep = chrono::duration_cast(TimeProvider::serverNow() - getSilentPlayerChunk(outputBuffer, framesPerBuffer) - bufferMs + outputBufferDacTime); -//cout << "-sleep: " << sleep.count() << " " << -bufferDuration.count() / 2000 << "\n"; +//logD << "-sleep: " << sleep.count() << " " << -bufferDuration.count() / 2000 << "\n"; if (sleep < -bufferDuration/2) return true; } @@ -211,11 +211,11 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe // We're late: discard oldest chunks while (sleep > chunk->duration()) { - cout << "sleep > chunk->getDuration(): " << sleep.count() << " > " << chunk->duration().count() << ", chunks: " << chunks.size() << ", out: " << outputBufferDacTime.count() << ", needed: " << bufferDuration.count() << "\n"; + logO << "sleep > chunk->getDuration(): " << sleep.count() << " > " << chunk->duration().count() << ", chunks: " << chunks.size() << ", out: " << outputBufferDacTime.count() << ", needed: " << bufferDuration.count() << "\n"; sleep = std::chrono::duration_cast(TimeProvider::serverNow() - chunk->start() - bufferMs + outputBufferDacTime); if (!chunks.try_pop(chunk, outputBufferDacTime)) { - cout << "no chunks available\n"; + logO << "no chunks available\n"; chunk = NULL; sleep = chronos::usec(0); return false; @@ -236,7 +236,7 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe } else { - cout << "Sleep " << sleep.count() << "\n"; + logO << "Sleep " << sleep.count() << "\n"; correction = sleep; sleep = chronos::usec(0); } @@ -258,7 +258,7 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe { if (chronos::usec(abs(median)) > chronos::msec(1)) { - cout << "pBuffer->full() && (abs(median) > 1): " << median << "\n"; + logO << "pBuffer->full() && (abs(median) > 1): " << median << "\n"; sleep = chronos::usec(shortMedian); } /* else if (chronos::usec(median) > chronos::usec(300)) @@ -274,7 +274,7 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe { if (chronos::usec(abs(shortMedian)) > chronos::msec(5)) { - cout << "pShortBuffer->full() && (abs(shortMedian) > 5): " << shortMedian << "\n"; + logO << "pShortBuffer->full() && (abs(shortMedian) > 5): " << shortMedian << "\n"; sleep = chronos::usec(shortMedian); } /* else @@ -284,13 +284,13 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe */ } else if (miniBuffer.full() && (chronos::usec(abs(miniBuffer.median())) > chronos::msec(50))) { - cout << "pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 50): " << miniBuffer.median() << "\n"; + logO << "pMiniBuffer->full() && (abs(pMiniBuffer->mean()) > 50): " << miniBuffer.median() << "\n"; sleep = chronos::usec((chronos::msec::rep)miniBuffer.mean()); } } if (sleep.count() != 0) - std::cerr << "Sleep: " << sleep.count() << "\n"; + logO << "Sleep: " << sleep.count() << "\n"; else if (shortBuffer.full()) { if (chronos::usec(shortMedian) > chronos::usec(100)) @@ -308,7 +308,7 @@ bool Stream::getPlayerChunk(void* outputBuffer, const chronos::usec& outputBuffe lastUpdate = now; median = buffer.median(); shortMedian = shortBuffer.median(); - std::cerr << "Chunk: " << age.count()/100 << "\t" << miniBuffer.median()/100 << "\t" << shortMedian/100 << "\t" << median/100 << "\t" << buffer.size() << "\t" << outputBufferDacTime.count() << "\n"; + logO << "Chunk: " << age.count()/100 << "\t" << miniBuffer.median()/100 << "\t" << shortMedian/100 << "\t" << median/100 << "\t" << buffer.size() << "\t" << outputBufferDacTime.count() << "\n"; } return true; } diff --git a/common/log.cpp b/common/log.cpp index 307575ba..be5740a6 100644 --- a/common/log.cpp +++ b/common/log.cpp @@ -5,7 +5,7 @@ Log::Log(std::string ident, int facility) { facility_ = facility; - priority_ = LOG_DEBUG; + priority_ = kLogDebug; strncpy(ident_, ident.c_str(), sizeof(ident_)); ident_[sizeof(ident_)-1] = '\0'; @@ -13,19 +13,6 @@ Log::Log(std::string ident, int facility) } -std::string Log::LogPriorityToString(const LogPriority& priority) -{ - switch(priority) - { - case kLog: return "dbg"; - case kOut: return "out"; - case kErr: return "err"; - default: return std::to_string((int)priority); - } - return std::to_string((int)priority); -} - - std::string Log::Timestamp() { struct tm * dt; @@ -41,15 +28,23 @@ int Log::sync() { if (buffer_.length()) { -// if (priority_ == kLog) -// std::cout << Timestamp() << " [" << LogPriorityToString(priority_) << "] " << buffer_.c_str(); -// else + if (priority_ == kDbg) +#ifdef DEBUG_LOG + std::cout << Timestamp() << " [dbg] " << buffer_.c_str() << std::flush; +#else + ; +#endif + else if (priority_ == kOut) + std::cout << Timestamp() << " [out] " << buffer_.c_str() << std::flush; + else if (priority_ == kErr) + std::cerr << Timestamp() << " [err] " << buffer_.c_str() << std::flush; + else { - std::cout << Timestamp() << " [" << LogPriorityToString((LogPriority)priority_) << "] " << buffer_.c_str(); + std::cout << Timestamp() << " [" << std::to_string(priority_) << "] " << buffer_.c_str() << std::flush; syslog(priority_, "%s", buffer_.c_str()); } buffer_.erase(); - priority_ = LOG_DEBUG; // default to debug for each message + priority_ = kLogDebug; // default to debug for each message } return 0; } @@ -60,6 +55,8 @@ int Log::overflow(int c) if (c != EOF) { buffer_ += static_cast(c); + if (c == '\n') + sync(); } else { @@ -68,11 +65,10 @@ int Log::overflow(int c) return c; } + std::ostream& operator<< (std::ostream& os, const LogPriority& log_priority) { - static_cast(os.rdbuf())->priority_ = (int)log_priority; -// if (log_priority == dbg) -// os.flush(); + static_cast(os.rdbuf())->priority_ = log_priority; return os; } diff --git a/common/log.h b/common/log.h index 4bb8b865..269115f2 100644 --- a/common/log.h +++ b/common/log.h @@ -5,7 +5,7 @@ #include #include -#define logD std::clog << kLog +#define logD std::clog << kDbg #define logO std::clog << kOut #define logE std::clog << kErr #define logS(P) std::clog << P @@ -21,7 +21,7 @@ enum LogPriority kLogNotice = LOG_NOTICE, // normal, but significant, condition kLogInfo = LOG_INFO, // informational message kLogDebug = LOG_DEBUG, // debug-level message - kLog, kOut, kErr + kDbg, kOut, kErr }; std::ostream& operator<< (std::ostream& os, const LogPriority& log_priority); @@ -38,10 +38,9 @@ protected: private: friend std::ostream& operator<< (std::ostream& os, const LogPriority& log_priority); std::string Timestamp(); - std::string LogPriorityToString(const LogPriority& priority); std::string buffer_; int facility_; - int priority_; + LogPriority priority_; char ident_[50]; }; diff --git a/common/snapException.h b/common/snapException.h index c306ed73..d54bb8c2 100644 --- a/common/snapException.h +++ b/common/snapException.h @@ -33,6 +33,21 @@ public: }; + +class ServerException : public SnapException +{ +public: + ServerException(const char* text) : SnapException(text) + { + } + + virtual ~ServerException() throw() + { + } +}; + + + #endif diff --git a/server/controlServer.cpp b/server/controlServer.cpp index 1523f20c..127c4acf 100644 --- a/server/controlServer.cpp +++ b/server/controlServer.cpp @@ -3,6 +3,7 @@ #include "message/ack.h" #include "message/request.h" #include "message/command.h" +#include "common/log.h" #include @@ -20,7 +21,7 @@ void ControlServer::send(shared_ptr message) { if (!(*it)->active()) { - cout << "Session inactive. Removing\n"; + logO << "Session inactive. Removing\n"; (*it)->stop(); sessions.erase(it++); } @@ -35,12 +36,12 @@ void ControlServer::send(shared_ptr message) void ControlServer::onMessageReceived(ServerSession* connection, const msg::BaseMessage& baseMessage, char* buffer) { -// cout << "onMessageReceived: " << baseMessage.type << ", size: " << baseMessage.size << ", sent: " << baseMessage.sent.sec << "," << baseMessage.sent.usec << ", recv: " << baseMessage.received.sec << "," << baseMessage.received.usec << "\n"; +// logD << "onMessageReceived: " << baseMessage.type << ", size: " << baseMessage.size << ", sent: " << baseMessage.sent.sec << "," << baseMessage.sent.usec << ", recv: " << baseMessage.received.sec << "," << baseMessage.received.usec << "\n"; if (baseMessage.type == message_type::kRequest) { msg::Request requestMsg; requestMsg.deserialize(baseMessage, buffer); -// cout << "request: " << requestMsg.request << "\n"; +// logD << "request: " << requestMsg.request << "\n"; if (requestMsg.request == kTime) { // timeMsg.latency = (timeMsg.received.sec - timeMsg.sent.sec) * 1000000 + (timeMsg.received.usec - timeMsg.sent.usec); @@ -48,7 +49,7 @@ void ControlServer::onMessageReceived(ServerSession* connection, const msg::Base timeMsg.refersTo = requestMsg.id; timeMsg.latency = (requestMsg.received.sec - requestMsg.sent.sec) + (requestMsg.received.usec - requestMsg.sent.usec) / 1000000.; // tv diff = timeMsg.received - timeMsg.sent; -// cout << "Latency: " << diff.sec << "." << diff.usec << "\n"; +// logD << "Latency: " << diff.sec << "." << diff.usec << "\n"; connection->send(&timeMsg); } else if (requestMsg.request == kServerSettings) @@ -94,7 +95,7 @@ void ControlServer::acceptor() a.accept(*sock); setsockopt(sock->native(), SOL_SOCKET, SO_RCVTIMEO, &tv, sizeof(tv)); setsockopt(sock->native(), SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)); - cout << "ControlServer::NewConnection: " << sock->remote_endpoint().address().to_string() << "\n"; + logS(kLogNotice) << "ControlServer::NewConnection: " << sock->remote_endpoint().address().to_string() << endl; ServerSession* session = new ServerSession(this, sock); { std::unique_lock mlock(mutex); diff --git a/server/controlServer.h b/server/controlServer.h index 1085a133..2a86292c 100644 --- a/server/controlServer.h +++ b/server/controlServer.h @@ -49,27 +49,6 @@ private: }; -class ServerException : public std::exception -{ -public: - ServerException(const std::string& what) : what_(what) - { - } - - virtual ~ServerException() throw() - { - } - - virtual const char* what() const throw() - { - return what_.c_str(); - } - -private: - std::string what_; -}; - - #endif diff --git a/server/flacEncoder.cpp b/server/flacEncoder.cpp index a24779e8..7c20ffe4 100644 --- a/server/flacEncoder.cpp +++ b/server/flacEncoder.cpp @@ -1,4 +1,5 @@ #include "flacEncoder.h" +#include "common/log.h" #include using namespace std; diff --git a/server/oggEncoder.cpp b/server/oggEncoder.cpp index 0db01dd4..c0a4dc48 100644 --- a/server/oggEncoder.cpp +++ b/server/oggEncoder.cpp @@ -1,4 +1,5 @@ #include "oggEncoder.h" +#include "common/log.h" #include #include @@ -21,7 +22,7 @@ double OggEncoder::encode(msg::PcmChunk* chunk) tv_sec = chunk->timestamp.sec; tv_usec = chunk->timestamp.usec; } -//cout << "-> pcm: " << wireChunk->length << endl; +//logD << "-> pcm: " << wireChunk->length << endl; int bytes = chunk->payloadSize / 4; float **buffer=vorbis_analysis_buffer(&vd, bytes); @@ -173,7 +174,7 @@ void OggEncoder::init() break; headerChunk->payloadSize += og.header_len + og.body_len; headerChunk->payload = (char*)realloc(headerChunk->payload, headerChunk->payloadSize); - cout << "HeadLen: " << og.header_len << ", bodyLen: " << og.body_len << ", result: " << result << "\n"; + logD << "HeadLen: " << og.header_len << ", bodyLen: " << og.body_len << ", result: " << result << "\n"; memcpy(headerChunk->payload + pos, og.header, og.header_len); pos += og.header_len; memcpy(headerChunk->payload + pos, og.body, og.body_len); diff --git a/server/serverSession.cpp b/server/serverSession.cpp index de3ac691..a9c52a4c 100644 --- a/server/serverSession.cpp +++ b/server/serverSession.cpp @@ -39,19 +39,19 @@ void ServerSession::stop() if (socket) { socket->shutdown(boost::asio::ip::tcp::socket::shutdown_both, ec); - if (ec) cout << "Error in socket shutdown: " << ec << "\n"; + if (ec) logE << "Error in socket shutdown: " << ec << "\n"; socket->close(ec); - if (ec) cout << "Error in socket close: " << ec << "\n"; + if (ec) logE << "Error in socket close: " << ec << "\n"; } if (readerThread) { - cout << "joining readerThread\n"; + logD << "joining readerThread\n"; readerThread->join(); delete readerThread; } if (writerThread) { - cout << "joining readerThread\n"; + logD << "joining readerThread\n"; writerThread->join(); delete writerThread; } @@ -61,7 +61,7 @@ void ServerSession::stop() } readerThread = NULL; writerThread = NULL; - cout << "ServerSession stopped\n"; + logD << "ServerSession stopped\n"; } @@ -106,13 +106,13 @@ bool ServerSession::send(msg::BaseMessage* message) void ServerSession::getNextMessage() { -//cout << "getNextMessage\n"; +//logD << "getNextMessage\n"; msg::BaseMessage baseMessage; size_t baseMsgSize = baseMessage.getSize(); vector buffer(baseMsgSize); socketRead(&buffer[0], baseMsgSize); baseMessage.deserialize(&buffer[0]); -//cout << "getNextMessage: " << baseMessage.type << ", size: " << baseMessage.size << ", id: " << baseMessage.id << ", refers: " << baseMessage.refersTo << "\n"; +//logD << "getNextMessage: " << baseMessage.type << ", size: " << baseMessage.size << ", id: " << baseMessage.id << ", refers: " << baseMessage.refersTo << "\n"; if (baseMessage.size > buffer.size()) buffer.resize(baseMessage.size); socketRead(&buffer[0], baseMessage.size); @@ -137,7 +137,7 @@ void ServerSession::reader() } catch (const std::exception& e) { - cout << kLogNotice << "Exception: " << e.what() << ", trying to reconnect" << std::endl; + logS(kLogErr) << "Exception: " << e.what() << ", trying to reconnect" << endl; } active_ = false; } @@ -160,7 +160,7 @@ void ServerSession::writer() } catch (std::exception& e) { - std::cerr << "Exception in thread: " << e.what() << "\n"; + logE << "Exception in thread: " << e.what() << "\n"; } active_ = false; } diff --git a/server/snapServer.cpp b/server/snapServer.cpp index 431d7a39..5b181e7f 100644 --- a/server/snapServer.cpp +++ b/server/snapServer.cpp @@ -4,6 +4,8 @@ #include "common/timeDefs.h" #include "common/signalHandler.h" #include "common/daemon.h" +#include "common/log.h" +#include "common/snapException.h" #include "message/sampleFormat.h" #include "message/message.h" #include "pcmEncoder.h" @@ -35,6 +37,7 @@ int main(int argc, char* argv[]) po::options_description desc("Allowed options"); desc.add_options() ("help,h", "produce help message") + ("version,v", "show version number") ("port,p", po::value(&port)->default_value(98765), "server port") ("sampleformat,s", po::value(&sampleFormat)->default_value("48000:16:2"), "sample format") ("codec,c", po::value(&codec)->default_value("ogg"), "transport codec [ogg|pcm]") @@ -49,18 +52,28 @@ int main(int argc, char* argv[]) if (vm.count("help")) { - cout << desc << "\n"; + logO << desc << "\n"; return 1; } + if (vm.count("version")) + { + logO << "snapserver " << VERSION << "\n" + << "Copyright (C) 2014 BadAix (snapcast@badaix.de).\n" + << "License GPLv3+: GNU GPL version 3 or later .\n" + << "This is free software: you are free to change and redistribute it.\n" + << "There is NO WARRANTY, to the extent permitted by law.\n\n" + << "Written by Johannes Pohl.\n"; + return 1; + } if (runAsDaemon) { daemonize("/var/run/snapserver.pid"); - syslog (LOG_NOTICE, "First daemon started."); + logS(kLogNotice) << "daemon started." << endl; } - openlog("firstdaemon", LOG_PID, LOG_DAEMON); + std::clog.rdbuf(new Log("snapserver", LOG_DAEMON)); using namespace std; // For atoi. @@ -79,12 +92,12 @@ int main(int argc, char* argv[]) encoder.reset(new PcmEncoder(sampleFormat)); else if (codec == "flac") { - cout << "Not yet supported\n"; + logO << "Not yet supported\n"; return 1; } else { - cout << "unknown codec: " << codec << "\n"; + logO << "unknown codec: " << codec << "\n"; return 1; } @@ -129,7 +142,7 @@ int main(int argc, char* argv[]) double chunkDuration = encoder->encode(chunk.get()); if (chunkDuration > 0) controlServer->send(chunk); -//cout << chunk->tv_sec << ", " << chunk->tv_usec / 1000 << "\n"; +//logD << chunk->tv_sec << ", " << chunk->tv_usec / 1000 << "\n"; // addUs(tvChunk, 1000*chunk->getDuration()); chronos::addUs(tvChunk, chunkDuration * 1000); nextTick += duration; @@ -152,16 +165,14 @@ int main(int argc, char* argv[]) close(fd); } -// server->stop(); } catch (const std::exception& e) { - std::cerr << "Exception: " << e.what() << std::endl; + logS(kLogErr) << "Exception: " << e.what() << std::endl; } - syslog(LOG_NOTICE, "First daemon terminated."); + logS(kLogNotice) << "daemon terminated." << endl; daemonShutdown(); - closelog(); }