From 59e512175aaf2d6d1f2f98c0fb6519e60b84bf67 Mon Sep 17 00:00:00 2001 From: Dmytro Bogovych Date: Thu, 19 Jul 2018 09:52:51 +0300 Subject: [PATCH] - logging improved --- src/engine/agent/Agent_AudioManager.cpp | 2 +- src/engine/agent/Agent_Impl.cpp | 2 +- src/engine/audio/Audio_CoreAudio.cpp | 40 ++++---- src/engine/audio/Audio_DirectSound.cpp | 4 +- src/engine/audio/Audio_Mixer.cpp | 8 +- src/engine/audio/Audio_WavFile.cpp | 2 +- src/engine/endpoint/EP_Account.cpp | 8 +- src/engine/endpoint/EP_Engine.cpp | 27 ++--- src/engine/endpoint/EP_Session.cpp | 10 +- src/engine/helper/HL_Log.h | 3 + src/engine/media/MT_AmrCodec.cpp | 2 +- src/engine/media/MT_AudioCodec.cpp | 10 +- src/engine/media/MT_AudioReceiver.cpp | 2 +- src/engine/media/MT_AudioStream.cpp | 2 +- src/engine/media/MT_SevanaMos.cpp | 42 ++++---- src/engine/media/MT_SingleAudioStream.cpp | 2 +- src/libs/ice/ICEAuthTransaction.cpp | 4 +- src/libs/ice/ICEBinding.cpp | 4 +- src/libs/ice/ICECandidate.cpp | 8 +- src/libs/ice/ICELog.cpp | 43 ++++++++ src/libs/ice/ICELog.h | 117 +++++++++++++--------- src/libs/ice/ICENetworkHelper.cpp | 2 +- src/libs/ice/ICERelaying.cpp | 4 +- src/libs/ice/ICESession.cpp | 2 +- 24 files changed, 208 insertions(+), 142 deletions(-) diff --git a/src/engine/agent/Agent_AudioManager.cpp b/src/engine/agent/Agent_AudioManager.cpp index 9bd3c74a..92aef81c 100644 --- a/src/engine/agent/Agent_AudioManager.cpp +++ b/src/engine/agent/Agent_AudioManager.cpp @@ -164,7 +164,7 @@ void AudioManager::startPlayFile(int usageId, const std::string& path, AudioTarg #endif if (!r->isOpened()) { - ICELogCritical(<< "Cannot open file to play"); + ICELogError(<< "Cannot open file to play"); return; } diff --git a/src/engine/agent/Agent_Impl.cpp b/src/engine/agent/Agent_Impl.cpp index 1205c8fd..f827554b 100644 --- a/src/engine/agent/Agent_Impl.cpp +++ b/src/engine/agent/Agent_Impl.cpp @@ -313,7 +313,7 @@ void AgentImpl::processStartSession(Json::Value& request, Json::Value& answer) if (!mAudioManager) { // Agent was not started - ICELogCritical(<< "No audio manager installed."); + ICELogError(<< "No audio manager installed."); answer["status"] = "Audio manager not started. Most probably agent is not started."; return; } diff --git a/src/engine/audio/Audio_CoreAudio.cpp b/src/engine/audio/Audio_CoreAudio.cpp index a6547bd6..02e9aed0 100644 --- a/src/engine/audio/Audio_CoreAudio.cpp +++ b/src/engine/audio/Audio_CoreAudio.cpp @@ -89,7 +89,7 @@ void CoreAudioUnit::open(bool voice) &audioCategory); if (ostatus != kAudioSessionNoError) { - ICELogCritical(<< "Cannot set audio session to PlaybackAndRecord category, error" << ostatus); + ICELogError(<< "Cannot set audio session to PlaybackAndRecord category, error" << ostatus); throw AudioException(ERR_COREAUDIO, ostatus); } #endif @@ -110,7 +110,7 @@ void CoreAudioUnit::open(bool voice) AudioComponent component = AudioComponentFindNext(NULL, &desc); if (component == NULL) { - ICELogCritical(<< "Cannot find audio component, error " << int(ostatus)); + ICELogError(<< "Cannot find audio component, error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } @@ -118,7 +118,7 @@ void CoreAudioUnit::open(bool voice) ostatus = AudioComponentInstanceNew(component, &mUnit); if (ostatus != noErr) { - ICELogCritical(<< "Cannot create audio component, error " << int(ostatus)); + ICELogError(<< "Cannot create audio component, error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } } @@ -145,7 +145,7 @@ AudioStreamBasicDescription CoreAudioUnit::getFormat(int scope, int bus) OSStatus ostatus = AudioUnitGetProperty(mUnit, kAudioUnitProperty_StreamFormat, scope, bus, &result, &size); if (ostatus != noErr) { - ICELogCritical(<< "Cannot obtain stream format, error " << int(ostatus)); + ICELogError(<< "Cannot obtain stream format, error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } return result; @@ -161,7 +161,7 @@ void CoreAudioUnit::setFormat(AudioStreamBasicDescription& format, int scope, in sizeof(format)); if (ostatus != noErr) { - ICELogCritical(<< "Cannot set stream format, error " << int(ostatus)); + ICELogError(<< "Cannot set stream format, error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } } @@ -173,7 +173,7 @@ bool CoreAudioUnit::getEnabled(int scope, int bus) OSStatus ostatus = AudioUnitGetProperty(mUnit, kAudioOutputUnitProperty_EnableIO, scope, bus, &wasEnabled, &sizeWe); if (ostatus != noErr) { - ICELogCritical(<< "Failed to get if input is already enabled on audio device"); + ICELogError(<< "Failed to get if input is already enabled on audio device"); } return wasEnabled != 0; } @@ -190,7 +190,7 @@ void CoreAudioUnit::setEnabled(bool enabled, int scope, int bus) if (ostatus != noErr) { - ICELogCritical(<< "Cannot enable input on audio device , error " << int(ostatus)); + ICELogError(<< "Cannot enable input on audio device , error " << int(ostatus)); //throw AudioException(ERR_COREAUDIO, ostatus); } } @@ -205,7 +205,7 @@ void CoreAudioUnit::makeCurrent(AudioDeviceID deviceId, int scope, int bus) sizeof(deviceId)); if (ostatus != noErr) { - ICELogCritical(<< "Cannot make device " << int(deviceId) << " current, error " << ostatus); + ICELogError(<< "Cannot make device " << int(deviceId) << " current, error " << ostatus); throw AudioException(ERR_COREAUDIO, ostatus); } } @@ -221,7 +221,7 @@ void CoreAudioUnit::setCallback(AURenderCallbackStruct cb, int callbackType, int sizeof(cb)); if (ostatus != noErr) { - ICELogCritical(<< "Cannot set callback pointer, error " << int(ostatus)); + ICELogError(<< "Cannot set callback pointer, error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } } @@ -233,7 +233,7 @@ void CoreAudioUnit::setBufferFrameSizeInMilliseconds(int ms) OSStatus ostatus = AudioSessionSetProperty(kAudioSessionProperty_PreferredHardwareIOBufferDuration, sizeof(preferredBufferSize), &preferredBufferSize); if (ostatus != noErr) { - ICELogCritical(<< "Cannot set audio buffer length to " << ms << " milliseconds"); + ICELogError(<< "Cannot set audio buffer length to " << ms << " milliseconds"); } #endif #ifdef TARGET_OSX @@ -253,7 +253,7 @@ int CoreAudioUnit::getBufferFrameSize() &size); if (ostatus != noErr) { - ICELogCritical(<< "Cannot obtain input buffer size , error " << int(ostatus)); + ICELogError(<< "Cannot obtain input buffer size , error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } return int(bufsize); @@ -264,7 +264,7 @@ void CoreAudioUnit::initialize() OSStatus ostatus = AudioUnitInitialize(mUnit); if (ostatus != noErr) { - ICELogCritical(<< "Cannot initialize AudioUnit, error " << int(ostatus)); + ICELogError(<< "Cannot initialize AudioUnit, error " << int(ostatus)); throw AudioException(ERR_COREAUDIO, ostatus); } } @@ -355,7 +355,7 @@ OSStatus MacDevice::inputCallback(void *inRefCon, if (ostatus != noErr) { - ICELogCritical(<< "Cannot render input audio data, error " << int(ostatus)); + ICELogError(<< "Cannot render input audio data, error " << int(ostatus)); } else { @@ -414,7 +414,7 @@ void MacDevice::interruptionListener(void *inClientData, UInt32 inInterruption) &audioCategory); if (ostatus != kAudioSessionNoError) { - ICELogCritical(<<"Cannot set the audio session category, error " << ostatus); + ICELogError(<<"Cannot set the audio session category, error " << ostatus); } // Start stream @@ -477,7 +477,7 @@ bool MacDevice::open() { if (!createUnit(true)) { - ICELogCritical(<< "Unable to create&adjust AudioUnit"); + ICELogError(<< "Unable to create&adjust AudioUnit"); return false; // TODO - enable stub for iOS } @@ -609,7 +609,7 @@ bool MacDevice::createUnit(bool voice) mInputBufferList = (AudioBufferList*)malloc(sizeof(AudioBufferList) + sizeof(AudioBuffer)); if (!mInputBufferList) { - ICELogCritical(<< "No memory for buffer list"); + ICELogError(<< "No memory for buffer list"); return false; } mInputBufferList->mNumberBuffers = 1; @@ -619,7 +619,7 @@ bool MacDevice::createUnit(bool voice) ab->mData = NULL;//malloc(ab->mDataByteSize); if (!ab->mData) { - //ICELogCritical(<< "No memory for capture buffer"); + //ICELogError(<< "No memory for capture buffer"); } #endif #ifdef TARGET_IOS @@ -629,7 +629,7 @@ bool MacDevice::createUnit(bool voice) mInputBufferList = (AudioBufferList*)malloc(sizeof(AudioBufferList) + sizeof(AudioBuffer)); if (!mInputBufferList) { - ICELogCritical(<< "No memory for buffer list"); + ICELogError(<< "No memory for buffer list"); return false; } mInputBufferList->mNumberBuffers = 1; @@ -675,7 +675,7 @@ void MacDevice::startStream() ostatus = AudioOutputUnitStart(mAudioUnit.getHandle()); if (ostatus != noErr) { - ICELogCritical(<< "Failed to start audio unit, error " << int(ostatus)); + ICELogError(<< "Failed to start audio unit, error " << int(ostatus)); return; } } @@ -690,7 +690,7 @@ void MacDevice::stopStream() ostatus = AudioOutputUnitStop(mAudioUnit.getHandle()); if (ostatus != noErr) { - ICELogCritical(<< "Failed to stop audio unit, error " << int(ostatus)); + ICELogError(<< "Failed to stop audio unit, error " << int(ostatus)); } #ifdef TARGET_IOS diff --git a/src/engine/audio/Audio_DirectSound.cpp b/src/engine/audio/Audio_DirectSound.cpp index 05462417..7ac2455c 100644 --- a/src/engine/audio/Audio_DirectSound.cpp +++ b/src/engine/audio/Audio_DirectSound.cpp @@ -886,12 +886,12 @@ void DSoundOutputDevice::threadProc(void* arg) } catch(const Exception& e) { - ICELogCritical(<< "DirectSound output failed with code = " << e.code() << ", subcode = " << e.subcode()); + ICELogError(<< "DirectSound output failed with code = " << e.code() << ", subcode = " << e.subcode()); impl->setSimulate(true); } catch(...) { - ICELogCritical(<< "DirectSound output failed due to unexpected exception."); + ICELogError(<< "DirectSound output failed due to unexpected exception."); impl->setSimulate(true); } } diff --git a/src/engine/audio/Audio_Mixer.cpp b/src/engine/audio/Audio_Mixer.cpp index a4a2138b..5f092941 100644 --- a/src/engine/audio/Audio_Mixer.cpp +++ b/src/engine/audio/Audio_Mixer.cpp @@ -191,7 +191,7 @@ void Mixer::addPcm(void* context, unsigned ssrc, Audio::DataWindow& w, int rate, } channel->addPcm(rate, w.data(), w.filled()); - //ICELogCritical(<<"Mixer stream " << int(this) << " has " << w.filled() << " bytes"); + //ICELogSpecial(<<"Mixer stream " << int(this) << " has " << w.filled() << " bytes"); } void Mixer::mix() @@ -218,7 +218,7 @@ void Mixer::mix() // No active channels - nothing to mix - exit if (!activeCounter) { - //ICELogCritical(<< "No active channel"); + //ICELogDebug(<< "No active channel"); return; } @@ -229,7 +229,7 @@ void Mixer::mix() Stream& audio = *channelList[0]; mOutput.add(audio.data().data(), audio.data().filled()); audio.data().erase(audio.data().filled()); - //ICELogCritical(<<"Length of mixer stream " << audio.data().filled()); + //ICELogSpecial(<<"Length of mixer stream " << audio.data().filled()); } else if (activeCounter == 2) @@ -309,7 +309,7 @@ int Mixer::getPcm(void* outputData, int outputLength) if (mOutput.filled() < outputLength) mix(); - //ICELogCritical(<<"Mixer has " << mOutput.filled() << " available bytes"); + //ICELogSpecial(<<"Mixer has " << mOutput.filled() << " available bytes"); memset(outputData, 0, outputLength); return mOutput.read(outputData, outputLength); } diff --git a/src/engine/audio/Audio_WavFile.cpp b/src/engine/audio/Audio_WavFile.cpp index f96560c4..58197f82 100644 --- a/src/engine/audio/Audio_WavFile.cpp +++ b/src/engine/audio/Audio_WavFile.cpp @@ -276,7 +276,7 @@ bool WavFileWriter::open(const std::tstring& filename, int rate, int channels) #endif if (NULL == mHandle) { - ICELogCritical(<< "Failed to create .wav file: filename = " << StringHelper::makeUtf8(filename) << " , error = " << errno); + ICELogError(<< "Failed to create .wav file: filename = " << StringHelper::makeUtf8(filename) << " , error = " << errno); return false; } diff --git a/src/engine/endpoint/EP_Account.cpp b/src/engine/endpoint/EP_Account.cpp index 23604b22..8f69ab7a 100644 --- a/src/engine/endpoint/EP_Account.cpp +++ b/src/engine/endpoint/EP_Account.cpp @@ -626,7 +626,7 @@ void Account::onDnsResult(const resip::DNSResult& result) if (result.status == 0) { resip::Data foundAddress = result.records.front().host(); - ICELogCritical( << "Success to resolve STUN/TURN address to " << foundAddress.c_str()); + ICELogInfo( << "Success to resolve STUN/TURN address to " << foundAddress.c_str()); mConfig->at(CONFIG_STUNSERVER_IP) = std::string(foundAddress.c_str()); // Here the IP address of STUN/TURN server is found. If account is registered already - it means account is ready. @@ -635,7 +635,7 @@ void Account::onDnsResult(const resip::DNSResult& result) } else { - ICELogCritical( << "Failed to resolve STUN or TURN server IP address."); + ICELogError( << "Failed to resolve STUN or TURN server IP address."); if (mRegistrationState == RegistrationState::Registered) { int startCode = mConfig->at(CONFIG_STUNSERVER_NAME).asStdString().empty() ? 0 : 503; @@ -675,7 +675,7 @@ void Account::onDnsResult(const resip::DNSResult& result) const char* host = result.records[index].target().c_str(); - ICELogCritical( << "Success to find STUN/TURN server on " << result.records[index].target().c_str() << + ICELogInfo( << "Success to find STUN/TURN server on " << result.records[index].target().c_str() << ":" << (int)result.records[index].port()); @@ -692,7 +692,7 @@ void Account::onDnsResult(const resip::DNSResult& result) } else { - ICELogCritical( << "Failed to find STUN or TURN service for specified domain."); + ICELogError( << "Failed to find STUN or TURN service for specified domain."); //mAgent::shutdown(); } diff --git a/src/engine/endpoint/EP_Engine.cpp b/src/engine/endpoint/EP_Engine.cpp index e359d16c..8500b9cc 100644 --- a/src/engine/endpoint/EP_Engine.cpp +++ b/src/engine/endpoint/EP_Engine.cpp @@ -88,7 +88,7 @@ void UserAgent::start() LOCK; if (mStack) { - ICELogCritical(<<"Endpoint is started already."); + ICELogError(<<"Endpoint is started already."); return; } @@ -138,7 +138,7 @@ void UserAgent::start() } catch(resip::BaseException& /*e*/) { - ICELogCritical(<< "Failed to preload root certificate"); + ICELogError(<< "Failed to preload root certificate"); } } @@ -554,13 +554,13 @@ bool UserAgent::compareSipAddresses(std::string sip1, std::string sip2) void UserAgent::onGathered(PSession s) { - ICELogCritical(<< "Session " << s->sessionId() << " gathered candidates"); + ICELogInfo(<< "Session " << s->sessionId() << " gathered candidates"); } // Called when new candidate is gathered void UserAgent::onCandidateGathered(PSession s, const char* address) { - ICELogCritical(<< "Session " << s->sessionId() << " gathered new candidate " << address); + ICELogInfo(<< "Session " << s->sessionId() << " gathered new candidate " << address); } @@ -604,7 +604,7 @@ void UserAgent::sendOffer(Session* session) if (h) h->provideOffer(sdp); else - ICELogCritical(<< "No cast to InviteSession"); + ICELogError(<< "No cast to InviteSession"); } } @@ -662,8 +662,11 @@ bool UserAgent::operator()(resip::Log::Level level, const resip::Subsystem& subs std::stringstream ss; ss << "File " << StringHelper::extractFilename(filename).c_str() << ", line " << line << ": " << message.c_str(); + if (level <= resip::Log::Crit) + ICELogCritical(<< ss.str()); + else if (level <= resip::Log::Warning) - ICELogCritical(<< ss.str().c_str()) + ICELogError(<< ss.str().c_str()) else if (level < resip::Log::Debug) ICELogInfo(<< ss.str().c_str()) @@ -859,7 +862,7 @@ void UserAgent::onAnswer(resip::InviteSessionHandle h, const resip::SipMessage& if (s->mStreamList.size() < sdp.session().media().size()) { - ICELogCritical( << "Answer has wrong number of streams"); + ICELogError( << "SDP answer has wrong number of streams"); h->end(); return; } @@ -971,7 +974,7 @@ void UserAgent::onAnswer(resip::InviteSessionHandle h, const resip::SipMessage& // Reject session if there is no media if (!mediasupported) { - ICELogCritical(<< "Session " << s->mSessionId << ": no supported media."); + ICELogError(<< "Session " << s->mSessionId << ": no supported media. Ending the session."); h->end(); return; } @@ -1125,13 +1128,13 @@ void UserAgent::onDnsResult(const resip::DNSResult& result if (result.status == 0) { resip::Data foundAddress = result.records.front().host(); - ICELogCritical( << "Success to resolve STUN/TURN address to " << foundAddress.c_str()); + ICELogInfo( << "Success to resolve STUN/TURN address to " << foundAddress.c_str()); mConfig[CONFIG_STUNSERVER_IP] = std::string(foundAddress.c_str()); onStart(0); } else { - ICELogCritical( << "Failed to resolve STUN or TURN server IP address."); + ICELogError( << "Failed to resolve STUN or TURN server IP address."); int startCode = mConfig[CONFIG_STUNSERVER_NAME].asStdString().empty() ? 0 : 503; onStart(startCode); } @@ -1322,7 +1325,7 @@ void UserAgent::onUpdate(resip::ClientSubscriptionHandle h, const resip::SipMess resip::Data tag = c.getTag(); if (tag != "list") { - ICELogCritical( << "Failed to find tag in rlmi"); + ICELogError( << "Failed to find tag in rlmi"); } else { @@ -1330,7 +1333,7 @@ void UserAgent::onUpdate(resip::ClientSubscriptionHandle h, const resip::SipMess { if (c.getTag() != "resource") { - ICELogCritical( << "Failed to find tag in rlmi"); + ICELogError( << "Failed to find tag in rlmi"); } else { diff --git a/src/engine/endpoint/EP_Session.cpp b/src/engine/endpoint/EP_Session.cpp index ad3ef54b..59df0c3d 100644 --- a/src/engine/endpoint/EP_Session.cpp +++ b/src/engine/endpoint/EP_Session.cpp @@ -306,7 +306,7 @@ void Session::start(const std::string& peer) if (mResipSession) { - ICELogCritical(<< "Session " << mSessionId << " is already started."); + ICELogError(<< "Session " << mSessionId << " is already started."); return; } @@ -415,7 +415,7 @@ void Session::reject(int code) ICELogInfo(<< "Session " << mSessionId << " is rejected."); } else - ICELogCritical(<< "Session " << mSessionId << " has not valid invite handle."); + ICELogError(<< "Session " << mSessionId << " has not valid invite handle."); } AudioProvider* Session::findProviderForActiveAudio() @@ -652,7 +652,7 @@ void Session::onSuccess(ice::Stack* stack, void* tag) void Session::onFailed(ice::Stack* stack, void* tag) { - ICELogCritical(<< "ICE connectivity check failed for session " << mSessionId); + ICELogError(<< "ICE connectivity check failed for session " << mSessionId); mUserAgent->onConnectivityFailed(mUserAgent->getUserSession(mSessionId)); //if (mInviteHandle.isValid()) @@ -661,7 +661,7 @@ void Session::onFailed(ice::Stack* stack, void* tag) void Session::onNetworkChange(ice::Stack *stack, void *tag) { - ICELogCritical(<< "Network change detected by ICE stack for session " << mSessionId); + ICELogInfo(<< "Network change detected by ICE stack for session " << mSessionId); mUserAgent->onNetworkChange(mUserAgent->getUserSession(mSessionId)); } @@ -981,7 +981,7 @@ int Session::processSdp(UInt64 version, bool iceAvailable, std::string icePwd, s } catch(...) { - ICELogCritical( << "Cannot create media socket."); + ICELogError( << "Cannot create media socket."); return 503; } diff --git a/src/engine/helper/HL_Log.h b/src/engine/helper/HL_Log.h index 01eb0ffc..d594d3bf 100644 --- a/src/engine/helper/HL_Log.h +++ b/src/engine/helper/HL_Log.h @@ -16,5 +16,8 @@ using ice::LL_DEBUG; using ice::LL_INFO; using ice::LL_CRITICAL; using ice::LL_NONE; +using ice::LL_SPECIAL; +using ice::LL_ERROR; +using ice::LogLevelHelper; #endif diff --git a/src/engine/media/MT_AmrCodec.cpp b/src/engine/media/MT_AmrCodec.cpp index 71a7c7fd..0386aec6 100644 --- a/src/engine/media/MT_AmrCodec.cpp +++ b/src/engine/media/MT_AmrCodec.cpp @@ -417,7 +417,7 @@ int AmrNbCodec::decode(const void* input, int inputBytes, void* output, int outp if (ap.mFrames.empty()) { - ICELogCritical(<< "No AMR frames"); + ICELogError(<< "No AMR frames"); } short* dataOut = (short*)output; for (AmrFrame& frame: ap.mFrames) diff --git a/src/engine/media/MT_AudioCodec.cpp b/src/engine/media/MT_AudioCodec.cpp index 2c333109..80512364 100644 --- a/src/engine/media/MT_AudioCodec.cpp +++ b/src/engine/media/MT_AudioCodec.cpp @@ -412,7 +412,7 @@ OpusCodec::OpusCodec(int samplerate, int channels, int ptime) int status; mEncoderCtx = opus_encoder_create(48000, mChannels, OPUS_APPLICATION_VOIP, &status); if (OPUS_OK != opus_encoder_ctl(mEncoderCtx, OPUS_SET_COMPLEXITY(OPUS_CODEC_COMPLEXITY))) - ICELogCritical(<< "Failed to set encoder complexity"); + ICELogError(<< "Failed to set Opus encoder complexity"); //if (OPUS_OK != opus_encoder_ctl(mEncoderCtx, OPUS_SET_FORCE_CHANNELS(AUDIO_CHANNELS))) // ICELogCritical(<<"Failed to set channel number in Opus encoder"); mDecoderCtx = opus_decoder_create(48000, mChannels, &status); @@ -422,16 +422,16 @@ void OpusCodec::applyParams(const Params ¶ms) { int error; if (OPUS_OK != (error = opus_encoder_ctl(mEncoderCtx, OPUS_SET_DTX(params.mUseDtx ? 1 : 0)))) - ICELogCritical(<< "Failed to (un)set DTX mode in Opus encoder. Error " << opus_strerror(error)); + ICELogError(<< "Failed to (un)set DTX mode in Opus encoder. Error " << opus_strerror(error)); if (OPUS_OK != (error = opus_encoder_ctl(mEncoderCtx, OPUS_SET_INBAND_FEC(params.mUseInbandFec ? 1 : 0)))) - ICELogCritical(<< "Failed to (un)set FEC mode in Opus encoder. Error " << opus_strerror(error)); + ICELogError(<< "Failed to (un)set FEC mode in Opus encoder. Error " << opus_strerror(error)); if (OPUS_OK != (error = opus_encoder_ctl(mEncoderCtx, OPUS_SET_BITRATE(params.mTargetBitrate ? params.mTargetBitrate : OPUS_AUTO)))) - ICELogCritical(<< "Failed to (un)set target bandwidth. Error " << opus_strerror(error)); + ICELogError(<< "Failed to (un)set target bandwidth. Error " << opus_strerror(error)); if (OPUS_OK != (error = opus_encoder_ctl(mEncoderCtx, OPUS_SET_PACKET_LOSS_PERC(params.mExpectedPacketLoss)))) - ICELogCritical(<< "Failed to (un)set expected packet loss. Error " << opus_strerror(error)); + ICELogError(<< "Failed to (un)set expected packet loss. Error " << opus_strerror(error)); mDecodeResampler.start(channels(), 48000, mSamplerate); } diff --git a/src/engine/media/MT_AudioReceiver.cpp b/src/engine/media/MT_AudioReceiver.cpp index f1b1994e..ef8e1390 100644 --- a/src/engine/media/MT_AudioReceiver.cpp +++ b/src/engine/media/MT_AudioReceiver.cpp @@ -151,7 +151,7 @@ bool RtpBuffer::add(std::shared_ptr packet, int timelength, while (available > mHigh && mPacketList.size()) { - //ICELogCritical( << "Dropping RTP packet from jitter"); + //ICELogMedia( << "Dropping RTP packet from jitter"); available -= mPacketList.front().timelength(); mPacketList.erase(mPacketList.begin()); } diff --git a/src/engine/media/MT_AudioStream.cpp b/src/engine/media/MT_AudioStream.cpp index fbb3fb3a..24708fca 100644 --- a/src/engine/media/MT_AudioStream.cpp +++ b/src/engine/media/MT_AudioStream.cpp @@ -309,7 +309,7 @@ void AudioStream::dataArrived(PDatagramSocket s, const void* buffer, int length, srtpResult = mSrtpSession.unprotectRtcp(mReceiveBuffer, &receiveLength); if (!srtpResult) { - ICELogCritical(<<"Cannot decrypt SRTP packet."); + ICELogError(<<"Cannot decrypt SRTP packet."); return; } } diff --git a/src/engine/media/MT_SevanaMos.cpp b/src/engine/media/MT_SevanaMos.cpp index b3055840..4c80e783 100644 --- a/src/engine/media/MT_SevanaMos.cpp +++ b/src/engine/media/MT_SevanaMos.cpp @@ -94,7 +94,7 @@ void SevanaMosUtility::run(const std::string& pcmPath, const std::string& interv if (!estimation.size()) { // Dump utility output if estimation failed - ICELogCritical(<< "PVQA failed with message: " << output); + ICELogError(<< "PVQA failed with message: " << output); return; } @@ -123,7 +123,7 @@ float getSevanaMos(const std::string& audioPath, const std::string& intervalRepo } catch(std::exception& e) { - ICELogCritical( << "MOS utility failed on PCM file " << audioPath << ". Error msg: " << e.what() ); + ICELogError( << "MOS utility failed on PCM file " << audioPath << ". Error msg: " << e.what() ); return 0.0; } } @@ -160,7 +160,7 @@ bool SevanaPVQA::initializeLibrary(const std::string& pathToLicenseFile, const s mLibraryErrorCode = PVQA_InitLib(const_cast(pathToLicenseFile.c_str())); if (mLibraryErrorCode) { - ICELogCritical(<< "Problem when initializing PVQA library. Error code: " << mLibraryErrorCode + ICELogError(<< "Problem when initializing PVQA library. Error code: " << mLibraryErrorCode << ". Path to license file is " << pathToLicenseFile << ". Path to config file is " << pathToConfigFile); return false; @@ -170,7 +170,7 @@ bool SevanaPVQA::initializeLibrary(const std::string& pathToLicenseFile, const s if (!mLibraryConfiguration) { PVQA_ReleaseLib(); - ICELogCritical(<< "Problem with PVQA configuration file."); + ICELogError(<< "Problem with PVQA configuration file."); return false; } mPvqaLoaded = true; @@ -206,19 +206,19 @@ void SevanaPVQA::open(double interval, Model model) { if (!isInitialized()) { - ICELogCritical(<< "PVQA library is not initialized."); + ICELogError(<< "PVQA library is not initialized."); return; } if (mOpenFailed) { - ICELogCritical(<< "Open failed already, reject this attempt."); + ICELogError(<< "Open failed already, reject this attempt."); return; } if (mContext) { - ICELogCritical(<< "Already opened (context is not nullptr)."); + ICELogError(<< "Already opened (context is not nullptr)."); return; } @@ -231,7 +231,7 @@ void SevanaPVQA::open(double interval, Model model) mContext = PVQA_CreateAudioQualityAnalyzer(mLibraryConfiguration); if (!mContext) { - ICELogCritical(<< "Failed to create PVQA instance. Instance counter: " << mInstanceCounter); + ICELogError(<< "Failed to create PVQA instance. Instance counter: " << mInstanceCounter); mOpenFailed = true; return; } @@ -242,7 +242,7 @@ void SevanaPVQA::open(double interval, Model model) rescode = PVQA_AudioQualityAnalyzerSetIntervalLength(mContext, interval); if (rescode) { - ICELogCritical(<< "Failed to set interval length on PVQA instance. Result code: " << rescode); + ICELogError(<< "Failed to set interval length on PVQA instance. Result code: " << rescode); close(); mOpenFailed = true; return; @@ -253,7 +253,7 @@ void SevanaPVQA::open(double interval, Model model) rescode = PVQA_OnStartStreamData(mContext); if (rescode) { - ICELogCritical(<< "Failed to start streaming analysis on PVQA instance. Result code: " << rescode); + ICELogError(<< "Failed to start streaming analysis on PVQA instance. Result code: " << rescode); close(); mOpenFailed = true; return; @@ -284,7 +284,7 @@ void SevanaPVQA::update(int samplerate, int channels, const void *pcmBuffer, int { if (!mContext) { - ICELogCritical(<< "No PVQA context."); + ICELogError(<< "No PVQA context."); return; } // Model is assert here as it can be any if context is not created. @@ -298,7 +298,7 @@ void SevanaPVQA::update(int samplerate, int channels, const void *pcmBuffer, int int rescode = PVQA_OnAddStreamAudioData(mContext, &item); if (rescode) { - ICELogCritical(<< "Failed to stream data to PVQA instance. Result code: " << rescode); + ICELogError(<< "Failed to stream data to PVQA instance. Result code: " << rescode); } int milliseconds = pcmLength / 2 / channels / (samplerate / 1000); mProcessedMilliseconds += milliseconds; @@ -335,7 +335,7 @@ float SevanaPVQA::getResults(std::string& report, EchoData** echo, int samplerat { if (!mContext) { - ICELogCritical(<< "No PVQA context."); + ICELogError(<< "No PVQA context."); return 0.0; } @@ -343,13 +343,13 @@ float SevanaPVQA::getResults(std::string& report, EchoData** echo, int samplerat { if (mProcessedMilliseconds == 0) { - ICELogCritical(<< "No audio in PVQA."); + ICELogError(<< "No audio in PVQA."); return -1; } if (PVQA_OnFinalizeStream(mContext, (long)samplerate)) { - ICELogCritical(<< "Failed to finalize results from PVQA."); + ICELogError(<< "Failed to finalize results from PVQA."); return -1; } ICELogInfo(<< "Processed " << mProcessedMilliseconds << " milliseconds."); @@ -358,7 +358,7 @@ float SevanaPVQA::getResults(std::string& report, EchoData** echo, int samplerat TPVQA_Results results; if (PVQA_FillQualityResultsStruct(mContext, &results)) { - ICELogCritical(<< "Failed to get results from PVQA."); + ICELogError(<< "Failed to get results from PVQA."); return -1; } @@ -368,7 +368,7 @@ float SevanaPVQA::getResults(std::string& report, EchoData** echo, int samplerat char* buffer = (char*)alloca(reportLength + 1); if (PVQA_FillQualityString(mContext, buffer)) { - ICELogCritical(<< "Failed to fill intervals report."); + ICELogError(<< "Failed to fill intervals report."); } else report = buffer; @@ -448,7 +448,7 @@ float SevanaPVQA::process(int samplerate, int channels, const void *pcmBuffer, i { mAudioLineInitialized = true; if (PVQA_AudioQualityAnalyzerCreateDelayLine(mContext, samplerate, channels, 20)) - ICELogCritical(<< "Failed to create delay line."); + ICELogError(<< "Failed to create delay line."); }*/ TPVQA_AudioItem item; @@ -466,20 +466,20 @@ float SevanaPVQA::process(int samplerate, int channels, const void *pcmBuffer, i writer.open(mDumpWavPath, samplerate, channels); writer.write(item.pSamples, item.dNSamples * 2 * channels); writer.close(); - ICELogCritical(<< "Sending chunk of audio with rate = " << samplerate << ", channels = " << channels << ", number of samples " << item.dNSamples); + ICELogError(<< "Sending chunk of audio with rate = " << samplerate << ", channels = " << channels << ", number of samples " << item.dNSamples); } */ int code = PVQA_OnTestAudioData(mContext, &item); if (code) { - ICELogCritical(<< "Failed to run PVQA on audio buffer with code " << code); + ICELogError(<< "Failed to run PVQA on audio buffer with code " << code); return 0.0; } /* if (item.pSamples != pcmBuffer || item.dNSamples != pcmLength / 2 / channels || item.dSampleRate != samplerate || item.dNChannels != channels) { - ICELogCritical(<< "PVQA changed input parameters!!!!"); + ICELogError(<< "PVQA changed input parameters!!!!"); } */ // Increase counter of processed samples diff --git a/src/engine/media/MT_SingleAudioStream.cpp b/src/engine/media/MT_SingleAudioStream.cpp index 48570dfc..ed828b10 100644 --- a/src/engine/media/MT_SingleAudioStream.cpp +++ b/src/engine/media/MT_SingleAudioStream.cpp @@ -37,6 +37,6 @@ void SingleAudioStream::copyPcmTo(Audio::DataWindow& output, int needed) break; if (output.filled() < needed) - ICELogCritical(<< "Not enough data for speaker's mixer"); + ICELogError(<< "Not enough data for speaker's mixer"); } diff --git a/src/libs/ice/ICEAuthTransaction.cpp b/src/libs/ice/ICEAuthTransaction.cpp index efbf36c1..9c37f299 100644 --- a/src/libs/ice/ICEAuthTransaction.cpp +++ b/src/libs/ice/ICEAuthTransaction.cpp @@ -126,7 +126,7 @@ bool AuthTransaction::processData(StunMessage& msg, NetworkAddress& address) mState = Transaction::Failed; processError(); - ICELogCritical(<<"Stack ID " << mStackID << ". Got error code " << mErrorCode << " for STUN transaction. Error message: " << ec.errorPhrase()); + ICELogError(<<"Stack ID " << mStackID << ". Got error code " << mErrorCode << " for STUN transaction. Error message: " << ec.errorPhrase()); } } else @@ -135,7 +135,7 @@ bool AuthTransaction::processData(StunMessage& msg, NetworkAddress& address) mErrorCode = 0; mState = Transaction::Failed; processError(); - ICELogCritical(<<"Stack ID " << mStackID << ". Got ErrorClass response."); + ICELogError(<<"Stack ID " << mStackID << ". Got ErrorClass response."); } else { diff --git a/src/libs/ice/ICEBinding.cpp b/src/libs/ice/ICEBinding.cpp index b4b64eb3..141904d8 100644 --- a/src/libs/ice/ICEBinding.cpp +++ b/src/libs/ice/ICEBinding.cpp @@ -347,7 +347,7 @@ bool ServerBinding::processData(StunMessage& msg, NetworkAddress& address) if (!msg.hasAttribute(StunAttribute::Username) || !msg.hasAttribute(StunAttribute::MessageIntegrity)) { - ICELogCritical(<< "There is no Username or MessageIntegrity attributes in Binding required. Error 400 will be generated."); + ICELogError(<< "There is no Username or MessageIntegrity attributes in Binding required. Error 400 will be generated."); // Send 400 error mGenerate400 = true; @@ -423,7 +423,7 @@ ByteBuffer* ServerBinding::generateData(bool force) // Do not create username attribute here - response does not need it // msg.usernameAttr().setValue(mUsername); - //ICELogCritical(<< "Using password " << mPassword); + //ICELogMedia(<< "Using password " << mPassword); // Add message integrity attribute msg.setAttribute(new MessageIntegrity()); diff --git a/src/libs/ice/ICECandidate.cpp b/src/libs/ice/ICECandidate.cpp index a4b37763..41a70e3e 100644 --- a/src/libs/ice/ICECandidate.cpp +++ b/src/libs/ice/ICECandidate.cpp @@ -62,7 +62,7 @@ const char* Candidate::type() return "prflx"; default: - ICELogCritical(<< "Bad candidate type, reverted to Host."); + ICELogError(<< "Bad candidate type, reverted to Host."); return "host"; } } @@ -144,7 +144,7 @@ Candidate::Type Candidate::typeFromString(const char* candtype) return Candidate::ServerRelayed; else { - ICELogCritical(<< "Bad candidate type in parser. Reverted to Host"); + ICELogError(<< "Bad candidate type in parser. Reverted to Host"); return Candidate::Host; } } @@ -166,7 +166,7 @@ bool Candidate::equal(Candidate& cand1, Candidate& cand2) } - ICELogCritical(<< "Bad candidate type, comparing as Host"); + ICELogError(<< "Bad candidate type, comparing as Host"); return cand1.mLocalAddr == cand2.mLocalAddr; } @@ -185,4 +185,4 @@ void Candidate::dump(std::ostream& output) int Candidate::component() { return mComponentId; -} \ No newline at end of file +} diff --git a/src/libs/ice/ICELog.cpp b/src/libs/ice/ICELog.cpp index eb21b2de..125f4afa 100644 --- a/src/libs/ice/ICELog.cpp +++ b/src/libs/ice/ICELog.cpp @@ -16,6 +16,49 @@ using namespace ice; + +LogLevel LogLevelHelper::parse(const std::string& t) +{ + if (t == "none") + return LL_NONE; + else + if (t == "debug") + return LL_DEBUG; + else + if (t == "critical") + return LL_CRITICAL; + else + if (t == "info") + return LL_INFO; + else + if (t == "media") + return LL_MEDIA; + else + if (t == "critical") + return LL_CRITICAL; + else + if (t == "special") + return LL_SPECIAL; + + throw std::runtime_error("Bad log param string value."); +} + +std::string LogLevelHelper::toString(LogLevel level) +{ + switch (level) + { + case LL_NONE: return "none"; + case LL_CRITICAL: return "critical"; + case LL_DEBUG: return "debug"; + case LL_ERROR: return "error"; + case LL_INFO: return "info"; + case LL_MEDIA: return "media"; + case LL_SPECIAL: return "special"; + } + + throw std::runtime_error("Bad log param value."); +} + ice::Logger ice::GLogger; const char* ice::Logger::TabPrefix = " "; diff --git a/src/libs/ice/ICELog.h b/src/libs/ice/ICELog.h index 6932fbbf..d0f0af0f 100644 --- a/src/libs/ice/ICELog.h +++ b/src/libs/ice/ICELog.h @@ -20,72 +20,83 @@ namespace ice { - // Defines log levels - enum LogLevel - { - LL_NONE = -1, - LL_CRITICAL = 0, - LL_INFO = 1, - LL_DEBUG = 2, - LL_MEDIA = 3 - }; - class LogHandler - { - public: +// Defines log levels +enum LogLevel +{ + LL_NONE = -1000, + LL_SPECIAL = 0, + LL_CRITICAL = 1, + LL_ERROR = 2, + LL_INFO = 3, + LL_DEBUG = 4, + LL_MEDIA = 5 +}; + +// Helper function to convert log level text parameter to enum value +class LogLevelHelper +{ +public: + static LogLevel parse(const std::string& t); + static std::string toString(LogLevel level); +}; + +class LogHandler +{ +public: virtual void onIceLog(LogLevel level, const std::string& filename, int line, const std::string& subsystem, const std::string& msg) = 0; - }; - +}; + #ifdef _WIN32 - class LogGuard - { - public: +class LogGuard +{ +public: LogGuard() { ::InitializeCriticalSection(&mCS); } ~LogGuard() { ::DeleteCriticalSection(&mCS); } void Lock() { ::EnterCriticalSection(&mCS); } void Unlock() { ::LeaveCriticalSection(&mCS); } - protected: +protected: CRITICAL_SECTION mCS; - }; +}; - class LogLock - { - public: +class LogLock +{ +public: LogLock(LogGuard& g) :mGuard(g) { mGuard.Lock(); } ~LogLock() { mGuard.Unlock(); } - protected: +protected: LogGuard& mGuard; - }; +}; #else - class LogGuard - { - public: +class LogGuard +{ +public: LogGuard() { ::pthread_mutex_init(&mMutex, NULL); } ~LogGuard() { ::pthread_mutex_destroy(&mMutex); } void Lock() { ::pthread_mutex_lock(&mMutex); } void Unlock() { ::pthread_mutex_unlock(&mMutex); } - protected: +protected: pthread_mutex_t mMutex; - }; +}; - class LogLock - { - public: +class LogLock +{ +public: LogLock(LogGuard& g) :mGuard(g) { mGuard.Lock(); } ~LogLock() { mGuard.Unlock(); } - protected: +protected: LogGuard& mGuard; - }; +}; #endif - class Logger - { - public: +class Logger +{ +public: static const char* TabPrefix; Logger(); @@ -113,7 +124,7 @@ namespace ice Logger& operator << (const unsigned int data); Logger& operator << (const uint64_t data); - protected: +protected: LogGuard mGuard; FILE* mFile; std::string mLogPath; @@ -127,40 +138,46 @@ namespace ice std::string mFilename; int mLine; std::string mSubsystem; - }; +}; extern Logger GLogger; #define ICELog(level_, subsystem_, args_)\ - {do\ - {\ - if (GLogger.level() >= level_)\ - {\ - LogLock l(GLogger.mutex());\ - GLogger.beginLine(level_, __FILE__, __LINE__, subsystem_);\ - GLogger args_;\ - GLogger.endLine();\ - }\ - } while (false);} +{do\ +{\ + if (GLogger.level() >= level_)\ +{\ + LogLock l(GLogger.mutex());\ + GLogger.beginLine(level_, __FILE__, __LINE__, subsystem_);\ + GLogger args_;\ + GLogger.endLine();\ +}\ +} while (false);} #define ICELogCritical(args_) ICELog(LL_CRITICAL, LOG_SUBSYSTEM, args_) #define ICELogInfo(args_) ICELog(LL_INFO, LOG_SUBSYSTEM, args_) #define ICELogDebug(args_) ICELog(LL_DEBUG, LOG_SUBSYSTEM, args_) #define ICELogMedia(args_) ICELog(LL_MEDIA, LOG_SUBSYSTEM, args_) +#define ICELogError(args_) ICELog(LL_ERROR, LOG_SUBSYSTEM, args_) +#define ICELogSpecial(args_) ICELog(LL_SPECIAL, LOG_SUBSYSTEM, args_) #define ICELogCritical2(args_) ICELog(LogLevel_Critical, LogSubsystem.c_str(), args_) #define ICELogInfo2(args_) ICELog(LogLevel_Info, LogSubsystem.c_str(), args_) #define ICELogDebug2(args_) ICELog(LogLevel_Debug, LogSubsystem.c_str(), args_) #define ICELogMedia2(args_) ICELog(LogLevel_Media, LogSubsystem.c_str(), args_) +#define ICELogError2(args_) ICELog(LogLevel_Error, LogSubsystem.c_str(), args_) +#define ICELogSpecial2(args_) ICELog(LogLevel_Special, LogSubsystem.c_str(), args_) #define DEFINE_LOGGING(subsystem) \ static std::string LogSubsystem = subsystem; \ static ice::LogLevel LogLevel_Critical = LL_CRITICAL; \ static ice::LogLevel LogLevel_Info = LL_INFO; \ static ice::LogLevel LogLevel_Debug = LL_DEBUG; \ - static ice::LogLevel LogLevel_Media = LL_MEDIA + static ice::LogLevel LogLevel_Media = LL_MEDIA; \ + static ice::LogLevel LogLevel_Error = LL_ERROR; \ + static ice::LogLevel LogLevel_Special = LL_SPECIAL /* diff --git a/src/libs/ice/ICENetworkHelper.cpp b/src/libs/ice/ICENetworkHelper.cpp index 2fd29183..74569ecc 100644 --- a/src/libs/ice/ICENetworkHelper.cpp +++ b/src/libs/ice/ICENetworkHelper.cpp @@ -399,7 +399,7 @@ NetworkHelper& NetworkHelper::instance() } catch(...) { - ICELogCritical(<< "Failed to create NetworkHelper instance"); + ICELogError(<< "Failed to create NetworkHelper instance"); } mGuard.unlock(); diff --git a/src/libs/ice/ICERelaying.cpp b/src/libs/ice/ICERelaying.cpp index bb48ec91..0e6612c3 100644 --- a/src/libs/ice/ICERelaying.cpp +++ b/src/libs/ice/ICERelaying.cpp @@ -201,10 +201,10 @@ void ClientRefresh::processError() { if (mStream->mTurnAllocated > 0) mStream->mTurnAllocated--; - ICELogCritical(<< "TURN allocation is not deleted due to error " << errorCode() << " " << errorResponse()); + ICELogError(<< "TURN allocation is not deleted due to error " << errorCode() << " " << errorResponse()); } else - ICELogDebug(<< "ClientRefresh failed due to error " << errorCode() << " " << errorResponse()); + ICELogError(<< "ClientRefresh failed due to error " << errorCode() << " " << errorResponse()); } } diff --git a/src/libs/ice/ICESession.cpp b/src/libs/ice/ICESession.cpp index 4cacd648..c6be056a 100644 --- a/src/libs/ice/ICESession.cpp +++ b/src/libs/ice/ICESession.cpp @@ -96,7 +96,7 @@ int Session::addComponent(int streamID, void* tag, unsigned short port4, unsigne if (mStreamMap.find(streamID) == mStreamMap.end()) { - ICELogCritical(<< "Cannot find stream " << streamID << " to add new component."); + ICELogError(<< "Cannot find stream " << streamID << " to add new component."); return -1; }