From e2aea8c21a33bca3c7e01e9c85210541a37f9241 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?S=C3=A9bastien=20Blin?=
<sebastien.blin@savoirfairelinux.com>
Date: Mon, 29 Jun 2020 11:49:49 -0400
Subject: [PATCH] calls: improve logs
Change-Id: I4863d9d781634e3a15d75b030eaa8a0d08925f69
Gitlab: #246
---
src/ice_transport.cpp | 14 +++++++-------
src/jamidht/jamiaccount.cpp | 30 +++++++++++++++++++-----------
2 files changed, 26 insertions(+), 18 deletions(-)
diff --git a/src/ice_transport.cpp b/src/ice_transport.cpp
index 914706f607..732df49978 100644
--- a/src/ice_transport.cpp
+++ b/src/ice_transport.cpp
@@ -214,7 +214,7 @@ add_stun_server(pj_ice_strans_cfg& cfg, int af)
stun.af = af;
stun.conn_type = cfg.stun.conn_type;
- JAMI_DBG("[ice] added host stun server");
+ JAMI_DBG("[ice (%s)] added host stun server", (cfg.protocol == PJ_ICE_TP_TCP? "TCP" : "UDP"));
}
static void
@@ -228,7 +228,7 @@ add_stun_server(pj_pool_t& pool, pj_ice_strans_cfg& cfg, const StunServerInfo& i
// Given URI cannot be DNS resolved or not IPv4 or IPv6?
// This prevents a crash into PJSIP when ip.toString() is called.
if (ip.getFamily() == AF_UNSPEC) {
- JAMI_WARN("[ice] STUN server '%s' not used, unresolvable address", info.uri.c_str());
+ JAMI_DBG("[ice (%s)] STUN server '%s' not used, unresolvable address", (cfg.protocol == PJ_ICE_TP_TCP? "TCP" : "UDP"), info.uri.c_str());
return;
}
@@ -241,7 +241,7 @@ add_stun_server(pj_pool_t& pool, pj_ice_strans_cfg& cfg, const StunServerInfo& i
stun.cfg.max_pkt_size = STUN_MAX_PACKET_SIZE;
stun.conn_type = cfg.stun.conn_type;
- JAMI_DBG("[ice] added stun server '%s', port %u", pj_strbuf(&stun.server), stun.port);
+ JAMI_DBG("[ice (%s)] added stun server '%s', port %u", (cfg.protocol == PJ_ICE_TP_TCP? "TCP" : "UDP"), pj_strbuf(&stun.server), stun.port);
}
static void
@@ -254,7 +254,7 @@ add_turn_server(pj_pool_t& pool, pj_ice_strans_cfg& cfg, const TurnServerInfo& i
// Same comment as add_stun_server()
if (ip.getFamily() == AF_UNSPEC) {
- JAMI_WARN("[ice] TURN server '%s' not used, unresolvable address", info.uri.c_str());
+ JAMI_DBG("[ice (%s)] TURN server '%s' not used, unresolvable address", (cfg.protocol == PJ_ICE_TP_TCP? "TCP" : "UDP"), info.uri.c_str());
return;
}
@@ -276,7 +276,7 @@ add_turn_server(pj_pool_t& pool, pj_ice_strans_cfg& cfg, const TurnServerInfo& i
pj_strset(&turn.auth_cred.data.static_cred.data, (char*)info.password.c_str(), info.password.size());
}
- JAMI_DBG("[ice] added turn server '%s', port %d", pj_strbuf(&turn.server), turn.port);
+ JAMI_DBG("[ice (%s)] added turn server '%s', port %u", (cfg.protocol == PJ_ICE_TP_TCP? "TCP" : "UDP"), pj_strbuf(&turn.server), turn.port);
}
//==============================================================================
@@ -576,7 +576,7 @@ IceTransport::Impl::onComplete(pj_ice_strans* ice_st, pj_ice_strans_op op, pj_st
bool
IceTransport::Impl::setInitiatorSession()
{
- JAMI_DBG("ICE as master");
+ JAMI_DBG("[ice:%p] as master", this);
initiatorSession_ = true;
if (_isInitialized()) {
auto status = pj_ice_strans_change_role(icest_.get(), PJ_ICE_SESS_ROLE_CONTROLLING);
@@ -593,7 +593,7 @@ IceTransport::Impl::setInitiatorSession()
bool
IceTransport::Impl::setSlaveSession()
{
- JAMI_DBG("ICE as slave");
+ JAMI_DBG("[ice:%p] as slave", this);
initiatorSession_ = false;
if (_isInitialized()) {
auto status = pj_ice_strans_change_role(icest_.get(), PJ_ICE_SESS_ROLE_CONTROLLED);
diff --git a/src/jamidht/jamiaccount.cpp b/src/jamidht/jamiaccount.cpp
index b92bceac4b..951e66af23 100644
--- a/src/jamidht/jamiaccount.cpp
+++ b/src/jamidht/jamiaccount.cpp
@@ -580,21 +580,22 @@ JamiAccount::startOutgoingCall(const std::shared_ptr<SIPCall>& call, const std::
[weak_dev_call, ice, ice_tcp, callvid, deviceId] (dht::IceCandidates&& msg) {
if (msg.id != callvid or msg.from.toString() != deviceId)
return true;
+ auto call = weak_dev_call.lock();
+ if (!call)
+ return false;
// remove unprintable characters
auto iceData = std::string(msg.ice_data.cbegin(), msg.ice_data.cend());
iceData.erase(std::remove_if(iceData.begin(), iceData.end(),
[](unsigned char c){ return !std::isprint(c) && !std::isspace(c); }
), iceData.end());
- JAMI_WARN("ICE request replied from DHT peer %s\nData: %s", deviceId.c_str(), iceData.c_str());
- if (auto call = weak_dev_call.lock()) {
- call->setState(Call::ConnectionState::PROGRESSING);
+ JAMI_WARN("ICE request for call %s replied from DHT peer %s\nData: %s", call->getCallId().c_str(), deviceId.c_str(), iceData.c_str());
+ call->setState(Call::ConnectionState::PROGRESSING);
- auto udp_failed = true, tcp_failed = true;
- initICE(msg.ice_data, ice, ice_tcp, udp_failed, tcp_failed);
- if (udp_failed && tcp_failed) {
- call->onFailure();
- return true;
- }
+ auto udp_failed = true, tcp_failed = true;
+ initICE(msg.ice_data, ice, ice_tcp, udp_failed, tcp_failed);
+ if (udp_failed && tcp_failed) {
+ call->onFailure();
+ return true;
}
return false;
}
@@ -643,6 +644,8 @@ JamiAccount::startOutgoingCall(const std::shared_ptr<SIPCall>& call, const std::
}
if (!transport) continue;
+ JAMI_WARN("[call %s] A channeled socket is detected with this peer.", call->getCallId().c_str());
+
auto dev_call = manager.callFactory.newCall<SIPCall, JamiAccount>(*this, manager.getNewCallID(),
Call::CallType::OUTGOING,
call->getDetails());
@@ -675,11 +678,12 @@ JamiAccount::startOutgoingCall(const std::shared_ptr<SIPCall>& call, const std::
}
// Find listening devices for this account
- accountManager_->forEachDevice(peer_account, [this, toUri, devices, sendDhtRequest](const dht::InfoHash& dev)
+ accountManager_->forEachDevice(peer_account, [this, toUri, devices, sendDhtRequest, callId=call->getCallId()](const dht::InfoHash& dev)
{
// Test if already sent via a SIP transport
if (devices.find(dev.toString()) != devices.end()) return;
+ JAMI_WARN("[call %s] No channeled socket with this peer. Send request + DHT request", callId.c_str());
// Else, ask for a channel (for future calls/text messages) and send a DHT message
requestSIPConnection(toUri, dev.toString());
@@ -1525,7 +1529,11 @@ JamiAccount::handlePendingCall(PendingCall& pc, bool incoming)
}
udp_finished = ice && ice->isRunning();
+ if (udp_finished)
+ JAMI_INFO("[call:%s] UDP negotiation is ready", call->getCallId().c_str());
tcp_finished = ice_tcp && ice_tcp->isRunning();
+ if (tcp_finished)
+ JAMI_INFO("[call:%s] TCP negotiation is ready", call->getCallId().c_str());
// If both transport are not running, the negotiation failed
if (not udp_finished and not tcp_finished) {
JAMI_ERR("[call:%s] Both ICE negotations failed", call->getCallId().c_str());
@@ -3315,7 +3323,7 @@ JamiAccount::cacheSIPConnection(std::shared_ptr<ChannelSocket>&& socket, const s
std::move(sip_tr),
socket
});
- JAMI_DBG("New SIP channel opened with %s", deviceId.c_str());
+ JAMI_WARN("New SIP channel opened with %s", deviceId.c_str());
lk.unlock();
// Retry messages
--
GitLab