voice shenanigans

.gitignore

@@ -128,3 +128,25 @@ package.dir
 
 # Archives
 *.bz2
+
+# Devenv
+.devenv*
+devenv.local.nix
+devenv.local.yaml
+
+# direnv
+.direnv
+
+# pre-commit
+.pre-commit-config.yaml
+
+# Devenv
+.devenv*
+devenv.local.nix
+devenv.local.yaml
+
+# direnv
+.direnv
+
+# pre-commit
+.pre-commit-config.yaml

CMakeLists.txt

@@ -248,6 +248,11 @@ endif()
 #
 find_package(Qt6 6.5 COMPONENTS Core Widgets Gui LinguistTools Svg Multimedia Qml QuickControls2 REQUIRED)
 find_package(Qt6DBus)
+find_package(Qt6QmlPrivate REQUIRED NO_MODULE)
+
+if(UNIX)
+    find_package(Qt6GuiPrivate REQUIRED NO_MODULE)
+endif()
 
 if(USE_BUNDLED_QTKEYCHAIN)
     include(FetchContent)

README.md

@@ -417,6 +417,51 @@ cmake -S. -Bbuild -DCMAKE_BUILD_TYPE=Release
 cmake --build build
 ```
 
+#### direnv + devenv
+
+If you want a reproducible Nix-based development shell for building and smoke-testing the local
+binary, this repo now includes `devenv.nix` and `.envrc`.
+
+Requirements:
+
+- `nix` with the `nix-command` and `flakes` features enabled
+- `devenv` 2.x
+- `direnv` with its shell hook enabled in your shell rc file
+- network access on the first run so `devenv` can resolve the `devenv.yaml` nixpkgs input and
+  fetch any missing Nix store paths
+- acceptance of the current `olm` insecurity override shipped in `devenv.nix`, since nheko still
+  depends on `libolm` and recent nixpkgs revisions block it by default
+
+Usage:
+
+```bash
+direnv allow
+```
+
+If you don't want automatic shell activation, you can enter the same environment manually:
+
+```bash
+devenv shell
+```
+
+Inside the shell, use the provided helper commands:
+
+```bash
+configure-nheko
+build-nheko
+test-nheko
+run-nheko
+```
+
+`test-nheko` builds the project, runs `ctest --output-on-failure`, and then performs a headless
+smoke check by running the built `nheko` binary with `--help`.
+
+You can also run the same test flow through `devenv` directly:
+
+```bash
+devenv test
+```
+
 To use bundled dependencies you can use hunter, i.e.:
 
 ```bash

src/voip/CallManager.cpp

@@ -7,6 +7,7 @@
 #include <chrono>
 #include <cstdint>
 #include <cstdlib>
+#include <exception>
 
 #include <QAudioOutput>
 #include <QGuiApplication>
@@ -56,6 +57,67 @@ typedef RTCSessionDescriptionInit SDO;
 namespace {
 std::vector<std::string>
 getTurnURIs(const mtx::responses::TurnServer &turnServer);
+
+const char *
+callStateString(webrtc::State state)
+{
+    switch (state) {
+    case webrtc::State::DISCONNECTED:
+        return "DISCONNECTED";
+    case webrtc::State::ICEFAILED:
+        return "ICEFAILED";
+    case webrtc::State::INITIATING:
+        return "INITIATING";
+    case webrtc::State::INITIATED:
+        return "INITIATED";
+    case webrtc::State::OFFERSENT:
+        return "OFFERSENT";
+    case webrtc::State::ANSWERSENT:
+        return "ANSWERSENT";
+    case webrtc::State::CONNECTING:
+        return "CONNECTING";
+    case webrtc::State::CONNECTED:
+        return "CONNECTED";
+    }
+
+    return "UNKNOWN";
+}
+
+void
+logCallException(const char *context,
+                 const QString &roomid,
+                 const std::string &callid,
+                 const std::exception &e)
+{
+    nhlog::ui()->warn("WebRTC: {} failed: {} (room id: {}, call id: {})",
+                      context,
+                      e.what(),
+                      roomid.isEmpty() ? "<none>" : roomid.toStdString(),
+                      callid.empty() ? "<none>" : callid);
+}
+
+void
+logUnknownCallException(const char *context, const QString &roomid, const std::string &callid)
+{
+    nhlog::ui()->warn("WebRTC: {} failed with an unknown exception (room id: {}, call id: {})",
+                      context,
+                      roomid.isEmpty() ? "<none>" : roomid.toStdString(),
+                      callid.empty() ? "<none>" : callid);
+}
+
+std::string
+requestErrorString(const mtx::http::RequestErr &err)
+{
+    if (!err)
+        return "unknown request error";
+
+    std::string details = "status=" + std::to_string(static_cast<int>(err->status_code));
+    if (!err->matrix_error.error.empty())
+        details += ", matrix_error=" + err->matrix_error.error;
+    if (!err->parse_error.empty())
+        details += ", parse_error=" + err->parse_error;
+    return details;
+}
 }
 
 CallManager *
@@ -145,6 +207,18 @@ CallManager::CallManager(QObject *parent)
                           CallCandidates{callid_, partyid_, candidates, callPartyVersion_});
       });
 
+    connect(
+      &session_,
+      &WebRTCSession::negotiationCreated,
+      this,
+      [this](const std::string &sdp, const std::vector<CallCandidates::Candidate> &candidates) {
+          nhlog::ui()->debug("WebRTC: call id: {} - sending negotiation answer", callid_);
+          emit newMessage(
+            roomid_, CallNegotiate{callid_, partyid_, timeoutms_, SDO{sdp, SDO::Type::Answer}});
+          emit newMessage(roomid_,
+                          CallCandidates{callid_, partyid_, candidates, callPartyVersion_});
+      });
+
     connect(&session_,
             &WebRTCSession::newICECandidate,
             this,
@@ -158,19 +232,25 @@ CallManager::CallManager(QObject *parent)
 
     connect(
       this, &CallManager::turnServerRetrieved, this, [this](const mtx::responses::TurnServer &res) {
-          nhlog::net()->info("TURN server(s) retrieved from homeserver:");
-          nhlog::net()->info("username: {}", res.username);
-          nhlog::net()->info("ttl: {} seconds", res.ttl);
-          for (const auto &u : res.uris)
-              nhlog::net()->info("uri: {}", u);
+          try {
+              nhlog::net()->info("TURN server(s) retrieved from homeserver:");
+              nhlog::net()->info("username: {}", res.username);
+              nhlog::net()->info("ttl: {} seconds", res.ttl);
+              for (const auto &u : res.uris)
+                  nhlog::net()->info("uri: {}", u);
 
-          // Request new credentials close to expiry
-          // See https://tools.ietf.org/html/draft-uberti-behave-turn-rest-00
-          turnURIs_    = getTurnURIs(res);
-          uint32_t ttl = std::max(res.ttl, std::uint32_t{3600});
-          if (res.ttl < 3600)
-              nhlog::net()->warn("Setting ttl to 1 hour");
-          turnServerTimer_.setInterval(std::chrono::seconds(ttl) * 10 / 9);
+              // Request new credentials close to expiry
+              // See https://tools.ietf.org/html/draft-uberti-behave-turn-rest-00
+              turnURIs_    = getTurnURIs(res);
+              uint32_t ttl = std::max(res.ttl, std::uint32_t{3600});
+              if (res.ttl < 3600)
+                  nhlog::net()->warn("Setting ttl to 1 hour");
+              turnServerTimer_.setInterval(std::chrono::seconds(ttl) * 10 / 9);
+          } catch (const std::exception &e) {
+              nhlog::net()->warn("Failed to process TURN server response: {}", e.what());
+          } catch (...) {
+              nhlog::net()->warn("Failed to process TURN server response: unknown exception");
+          }
       });
 
     connect(&session_, &WebRTCSession::stateChanged, this, [this](webrtc::State state) {
@@ -237,90 +317,125 @@ void
 CallManager::sendInvite(const QString &roomid, CallType callType, unsigned int windowIndex)
 {
     if (isOnCall() || isOnCallOnOtherDevice()) {
+        nhlog::ui()->debug("WebRTC: refusing outbound invite in state {} (call id: {}, other device call id: {})",
+                           callStateString(session_.state()),
+                           callid_,
+                           isOnCallOnOtherDevice_);
         if (isOnCallOnOtherDevice_ != "")
             emit ChatPage::instance()->showNotification(
               QStringLiteral("User is already in a call"));
         return;
     }
 
-    auto roomInfo = cache::singleRoomInfo(roomid.toStdString());
+    try {
+        auto roomInfo = cache::singleRoomInfo(roomid.toStdString());
 
-    std::string errorMessage;
+        callType_ = callType;
+        roomid_   = roomid;
+        generateCallID();
+        std::vector<RoomMember> members(cache::getMembers(roomid.toStdString()));
+        if (members.empty()) {
+            nhlog::ui()->warn("WebRTC: no room members available for outbound invite in room {}",
+                              roomid.toStdString());
+            emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
+            clear();
+            return;
+        }
 
-    callType_ = callType;
-    roomid_   = roomid;
-    generateCallID();
-    std::vector<RoomMember> members(cache::getMembers(roomid.toStdString()));
-    const RoomMember *callee;
-    if (roomInfo.member_count == 1)
-        callee = &members.front();
-    else if (roomInfo.member_count == 2)
-        callee = members.front().user_id == utils::localUser() ? &members.back() : &members.front();
-    else {
-        emit ChatPage::instance()->showNotification(
-          QStringLiteral("Calls are limited to rooms with less than two members"));
-        return;
-    }
+        const RoomMember *callee = nullptr;
+        if (roomInfo.member_count == 1)
+            callee = &members.front();
+        else if (roomInfo.member_count == 2)
+            callee =
+              members.front().user_id == utils::localUser() ? &members.back() : &members.front();
+        else {
+            emit ChatPage::instance()->showNotification(
+              QStringLiteral("Calls are limited to rooms with less than two members"));
+            clear();
+            return;
+        }
+        if (!callee) {
+            nhlog::ui()->warn("WebRTC: failed to resolve callee for outbound invite in room {}",
+                              roomid.toStdString());
+            emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
+            clear();
+            return;
+        }
 
 #ifdef GSTREAMER_AVAILABLE
-    if (callType == CallType::SCREEN) {
-        if (screenShareType_ == ScreenShareType::X11 ||
-            screenShareType_ == ScreenShareType::D3D11) {
-            if (windows_.empty() || windowIndex >= windows_.size()) {
-                nhlog::ui()->error("WebRTC: window index out of range");
-                return;
-            }
-        } else {
-            ScreenCastPortal &sc_portal = ScreenCastPortal::instance();
-            if (sc_portal.getStream() == nullptr) {
-                nhlog::ui()->error("xdg-desktop-portal stream not started");
-                return;
+        if (callType == CallType::SCREEN) {
+            if (screenShareType_ == ScreenShareType::X11 ||
+                screenShareType_ == ScreenShareType::D3D11) {
+                if (windows_.empty() || windowIndex >= windows_.size()) {
+                    nhlog::ui()->error("WebRTC: window index out of range");
+                    clear();
+                    return;
+                }
+            } else {
+                ScreenCastPortal &sc_portal = ScreenCastPortal::instance();
+                if (sc_portal.getStream() == nullptr) {
+                    nhlog::ui()->error("xdg-desktop-portal stream not started");
+                    clear();
+                    return;
+                }
             }
         }
-    }
 #endif
 
-    if (haveCallInvite_) {
-        nhlog::ui()->debug("WebRTC: Discarding outbound call for inbound call. "
-                           "localUser is polite party");
-        if (callParty_ == callee->user_id) {
-            if (callType == callType_)
-                acceptInvite();
-            else {
+        if (haveCallInvite_) {
+            nhlog::ui()->debug("WebRTC: discarding outbound call for inbound call; localUser is polite party");
+            if (callParty_ == callee->user_id) {
+                if (callType == callType_)
+                    acceptInvite();
+                else {
+                    emit ChatPage::instance()->showNotification(
+                      QStringLiteral("Can't place call. Call types do not match"));
+                    emit newMessage(
+                      roomid_,
+                      CallHangUp{callid_, partyid_, callPartyVersion_, CallHangUp::Reason::UserBusy});
+                }
+            } else {
                 emit ChatPage::instance()->showNotification(
-                  QStringLiteral("Can't place call. Call types do not match"));
+                  QStringLiteral("Already on a call with a different user"));
                 emit newMessage(
                   roomid_,
                   CallHangUp{callid_, partyid_, callPartyVersion_, CallHangUp::Reason::UserBusy});
             }
-        } else {
-            emit ChatPage::instance()->showNotification(
-              QStringLiteral("Already on a call with a different user"));
-            emit newMessage(
-              roomid_,
-              CallHangUp{callid_, partyid_, callPartyVersion_, CallHangUp::Reason::UserBusy});
+            return;
         }
-        return;
-    }
 
-    session_.setTurnServers(turnURIs_);
-    std::string strCallType =
-      callType_ == CallType::VOICE ? "voice" : (callType_ == CallType::VIDEO ? "video" : "screen");
+        session_.setTurnServers(turnURIs_);
+        std::string strCallType = callType_ == CallType::VOICE
+                                    ? "voice"
+                                    : (callType_ == CallType::VIDEO ? "video" : "screen");
 
-    nhlog::ui()->debug("WebRTC: call id: {} - creating {} invite", callid_, strCallType);
-    callParty_            = callee->user_id;
-    callPartyDisplayName_ = callee->display_name.isEmpty() ? callee->user_id : callee->display_name;
-    callPartyAvatarUrl_   = QString::fromStdString(roomInfo.avatar_url);
-    invitee_              = callParty_.toStdString();
-    emit newInviteState();
-    playRingtone(QUrl(QStringLiteral("qrc:/media/media/ringback.ogg")), true);
+        nhlog::ui()->debug("WebRTC: call id: {} - creating {} invite", callid_, strCallType);
+        callParty_            = callee->user_id;
+        callPartyDisplayName_ =
+          callee->display_name.isEmpty() ? callee->user_id : callee->display_name;
+        callPartyAvatarUrl_ = QString::fromStdString(roomInfo.avatar_url);
+        invitee_            = callParty_.toStdString();
+        emit newInviteState();
+        playRingtone(QUrl(QStringLiteral("qrc:/media/media/ringback.ogg")), true);
 
-    uint32_t shareWindowId =
-      callType == CallType::SCREEN &&
-          (screenShareType_ == ScreenShareType::X11 || screenShareType_ == ScreenShareType::D3D11)
-        ? windows_[windowIndex].second
-        : 0;
-    if (!session_.createOffer(callType, screenShareType_, shareWindowId)) {
+        uint32_t shareWindowId =
+          callType == CallType::SCREEN &&
+              (screenShareType_ == ScreenShareType::X11 || screenShareType_ == ScreenShareType::D3D11)
+            ? windows_[windowIndex].second
+            : 0;
+        if (!session_.createOffer(callType, screenShareType_, shareWindowId)) {
+            nhlog::ui()->warn("WebRTC: call id: {} - failed to create offer in state {}",
+                              callid_,
+                              callStateString(session_.state()));
+            emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
+            endCall();
+        }
+    } catch (const std::exception &e) {
+        logCallException("sendInvite", roomid, callid_, e);
+        emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
+        endCall();
+    } catch (...) {
+        logUnknownCallException("sendInvite", roomid, callid_);
         emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
         endCall();
     }
@@ -366,11 +481,17 @@ void
 CallManager::syncEvent(const mtx::events::collections::TimelineEvents &event)
 {
 #ifdef GSTREAMER_AVAILABLE
-    if (handleEvent<CallInvite>(event) || handleEvent<CallCandidates>(event) ||
-        handleEvent<CallNegotiate>(event) || handleEvent<CallSelectAnswer>(event) ||
-        handleEvent<CallAnswer>(event) || handleEvent<CallReject>(event) ||
-        handleEvent<CallHangUp>(event))
-        return;
+    try {
+        if (handleEvent<CallInvite>(event) || handleEvent<CallCandidates>(event) ||
+            handleEvent<CallNegotiate>(event) || handleEvent<CallSelectAnswer>(event) ||
+            handleEvent<CallAnswer>(event) || handleEvent<CallReject>(event) ||
+            handleEvent<CallHangUp>(event))
+            return;
+    } catch (const std::exception &e) {
+        logCallException("syncEvent", roomid_, callid_, e);
+    } catch (...) {
+        logUnknownCallException("syncEvent", roomid_, callid_);
+    }
 #else
     (void)event;
 #endif
@@ -405,8 +526,11 @@ CallManager::handleEvent(const RoomEvent<CallInvite> &callInviteEvent)
                        callInviteEvent.sender,
                        callInviteEvent.content.party_id);
 
-    if (callInviteEvent.content.call_id.empty())
+    if (callInviteEvent.content.call_id.empty()) {
+        nhlog::ui()->debug("WebRTC: ignoring CallInvite without call id from {}",
+                           callInviteEvent.sender);
         return;
+    }
 
     if (callInviteEvent.sender == utils::localUser().toStdString()) {
         if (callInviteEvent.content.party_id == partyid_)
@@ -421,103 +545,133 @@ CallManager::handleEvent(const RoomEvent<CallInvite> &callInviteEvent)
         }
     }
 
-    auto roomInfo     = cache::singleRoomInfo(callInviteEvent.room_id);
-    callPartyVersion_ = callInviteEvent.content.version;
+    try {
+        auto roomInfo     = cache::singleRoomInfo(callInviteEvent.room_id);
+        callPartyVersion_ = callInviteEvent.content.version;
 
-    const QString &ringtone = UserSettings::instance()->ringtone();
-    bool sharesRoom         = true;
+        const QString &ringtone = UserSettings::instance()->ringtone();
+        bool sharesRoom         = true;
 
-    std::vector<RoomMember> members(cache::getMembers(callInviteEvent.room_id));
-    const RoomMember &caller =
-      *std::find_if(members.begin(), members.end(), [&](RoomMember member) {
-          return member.user_id.toStdString() == callInviteEvent.sender;
-      });
-    if (isOnCall() || isOnCallOnOtherDevice()) {
-        if (isOnCallOnOtherDevice_ != "")
-            return;
-        if (callParty_.toStdString() == callInviteEvent.sender) {
-            if (session_.state() == webrtc::State::OFFERSENT) {
-                if (callid_ > callInviteEvent.content.call_id) {
-                    endCall();
-                    callParty_ = caller.user_id;
-                    callPartyDisplayName_ =
-                      caller.display_name.isEmpty() ? caller.user_id : caller.display_name;
-                    callPartyAvatarUrl_ = QString::fromStdString(roomInfo.avatar_url);
-
-                    roomid_ = QString::fromStdString(callInviteEvent.room_id);
-                    callid_ = callInviteEvent.content.call_id;
-                    remoteICECandidates_.clear();
-                    haveCallInvite_ = true;
-                    callType_       = isVideo ? CallType::VIDEO : CallType::VOICE;
-                    inviteSDP_      = callInviteEvent.content.offer.sdp;
-                    emit newInviteState();
-                    acceptInvite();
-                }
-                return;
-            } else if (session_.state() < webrtc::State::OFFERSENT)
-                endCall();
-            else
-                return;
-        } else
-            return;
-    }
-
-    if (callPartyVersion_ == "0") {
-        if (roomInfo.member_count != 2) {
-            emit newMessage(QString::fromStdString(callInviteEvent.room_id),
-                            CallHangUp{callInviteEvent.content.call_id,
-                                       partyid_,
-                                       callPartyVersion_,
-                                       CallHangUp::Reason::InviteTimeOut});
+        std::vector<RoomMember> members(cache::getMembers(callInviteEvent.room_id));
+        auto callerIt = std::find_if(members.begin(), members.end(), [&](const RoomMember &member) {
+            return member.user_id.toStdString() == callInviteEvent.sender;
+        });
+        if (callerIt == members.end()) {
+            nhlog::ui()->warn("WebRTC: ignoring CallInvite from unknown member {} in room {}",
+                              callInviteEvent.sender,
+                              callInviteEvent.room_id);
             return;
         }
-    } else {
-        if (caller.user_id == utils::localUser() &&
-            callInviteEvent.content.party_id == partyid_) // remote echo
-            return;
+        const RoomMember &caller = *callerIt;
 
-        if (roomInfo.member_count == 2 || // general call in room with two members
-            (roomInfo.member_count == 1 &&
-             partyid_ !=
-               callInviteEvent.content.party_id) ||  // self call, ring if not the same party_id
-            callInviteEvent.content.invitee == "" || // empty, meant for everyone
-            callInviteEvent.content.invitee ==
-              utils::localUser().toStdString()) // meant specifically for local user
-        {
-            if (roomInfo.member_count > 2) {
-                // check if shares room
-                sharesRoom = checkSharesRoom(QString::fromStdString(callInviteEvent.room_id),
-                                             callInviteEvent.content.invitee);
+        if (isOnCall() || isOnCallOnOtherDevice()) {
+            if (isOnCallOnOtherDevice_ != "") {
+                nhlog::ui()->debug("WebRTC: ignoring CallInvite while another device is active");
+                return;
+            }
+            if (callParty_.toStdString() == callInviteEvent.sender) {
+                if (session_.state() == webrtc::State::OFFERSENT) {
+                    if (callid_ > callInviteEvent.content.call_id) {
+                        endCall();
+                        callParty_ = caller.user_id;
+                        callPartyDisplayName_ =
+                          caller.display_name.isEmpty() ? caller.user_id : caller.display_name;
+                        callPartyAvatarUrl_ = QString::fromStdString(roomInfo.avatar_url);
+
+                        roomid_ = QString::fromStdString(callInviteEvent.room_id);
+                        callid_ = callInviteEvent.content.call_id;
+                        remoteICECandidates_.clear();
+                        haveCallInvite_ = true;
+                        callType_       = isVideo ? CallType::VIDEO : CallType::VOICE;
+                        inviteSDP_      = callInviteEvent.content.offer.sdp;
+                        emit newInviteState();
+                        acceptInvite();
+                    } else {
+                        nhlog::ui()->debug(
+                          "WebRTC: ignoring polite glare invite with newer local call id {}",
+                          callid_);
+                    }
+                    return;
+                } else if (session_.state() < webrtc::State::OFFERSENT)
+                    endCall();
+                else {
+                    nhlog::ui()->debug("WebRTC: ignoring CallInvite in active state {}",
+                                       callStateString(session_.state()));
+                    return;
+                }
+            } else {
+                nhlog::ui()->debug("WebRTC: ignoring CallInvite from {} while in call with {}",
+                                   callInviteEvent.sender,
+                                   callParty_.toStdString());
+                return;
+            }
+        }
+
+        if (callPartyVersion_ == "0") {
+            if (roomInfo.member_count != 2) {
+                nhlog::ui()->debug("WebRTC: rejecting v0 CallInvite in room with {} members",
+                                   roomInfo.member_count);
+                emit newMessage(QString::fromStdString(callInviteEvent.room_id),
+                                CallHangUp{callInviteEvent.content.call_id,
+                                           partyid_,
+                                           callPartyVersion_,
+                                           CallHangUp::Reason::InviteTimeOut});
+                return;
             }
         } else {
-            emit newMessage(QString::fromStdString(callInviteEvent.room_id),
-                            CallHangUp{callInviteEvent.content.call_id,
-                                       partyid_,
-                                       callPartyVersion_,
-                                       CallHangUp::Reason::InviteTimeOut});
-            return;
+            if (caller.user_id == utils::localUser() &&
+                callInviteEvent.content.party_id == partyid_) {
+                nhlog::ui()->debug("WebRTC: ignoring echoed CallInvite from this device");
+                return;
+            }
+
+            if (roomInfo.member_count == 2 ||
+                (roomInfo.member_count == 1 && partyid_ != callInviteEvent.content.party_id) ||
+                callInviteEvent.content.invitee == "" ||
+                callInviteEvent.content.invitee == utils::localUser().toStdString()) {
+                if (roomInfo.member_count > 2) {
+                    sharesRoom = checkSharesRoom(QString::fromStdString(callInviteEvent.room_id),
+                                                 callInviteEvent.content.invitee);
+                }
+            } else {
+                nhlog::ui()->debug("WebRTC: rejecting CallInvite not addressed to this device/user");
+                emit newMessage(QString::fromStdString(callInviteEvent.room_id),
+                                CallHangUp{callInviteEvent.content.call_id,
+                                           partyid_,
+                                           callPartyVersion_,
+                                           CallHangUp::Reason::InviteTimeOut});
+                return;
+            }
         }
+
+        if (ringtone != QLatin1String("Mute") && sharesRoom)
+            playRingtone(ringtone == QLatin1String("Default")
+                           ? QUrl(QStringLiteral("qrc:/media/media/ring.ogg"))
+                           : QUrl::fromLocalFile(ringtone),
+                         true);
+
+        callParty_            = caller.user_id;
+        callPartyDisplayName_ = caller.display_name.isEmpty() ? caller.user_id : caller.display_name;
+        callPartyAvatarUrl_   = QString::fromStdString(roomInfo.avatar_url);
+
+        roomid_ = QString::fromStdString(callInviteEvent.room_id);
+        callid_ = callInviteEvent.content.call_id;
+        remoteICECandidates_.clear();
+
+        haveCallInvite_ = true;
+        callType_       = isVideo ? CallType::VIDEO : CallType::VOICE;
+        inviteSDP_      = callInviteEvent.content.offer.sdp;
+        emit newInviteState();
+    } catch (const std::exception &e) {
+        logCallException("handleEvent(CallInvite)",
+                         QString::fromStdString(callInviteEvent.room_id),
+                         callInviteEvent.content.call_id,
+                         e);
+    } catch (...) {
+        logUnknownCallException("handleEvent(CallInvite)",
+                                QString::fromStdString(callInviteEvent.room_id),
+                                callInviteEvent.content.call_id);
     }
-
-    // ring if not mute or does not have direct message room
-    if (ringtone != QLatin1String("Mute") && sharesRoom)
-        playRingtone(ringtone == QLatin1String("Default")
-                       ? QUrl(QStringLiteral("qrc:/media/media/ring.ogg"))
-                       : QUrl::fromLocalFile(ringtone),
-                     true);
-
-    callParty_            = caller.user_id;
-    callPartyDisplayName_ = caller.display_name.isEmpty() ? caller.user_id : caller.display_name;
-    callPartyAvatarUrl_   = QString::fromStdString(roomInfo.avatar_url);
-
-    roomid_ = QString::fromStdString(callInviteEvent.room_id);
-    callid_ = callInviteEvent.content.call_id;
-    remoteICECandidates_.clear();
-
-    haveCallInvite_ = true;
-    callType_       = isVideo ? CallType::VIDEO : CallType::VOICE;
-    inviteSDP_      = callInviteEvent.content.offer.sdp;
-    emit newInviteState();
 }
 
 void
@@ -525,8 +679,10 @@ CallManager::acceptInvite()
 {
     // if call was accepted/rejected elsewhere and m.call.select_answer is
     // received before acceptInvite
-    if (!haveCallInvite_)
+    if (!haveCallInvite_) {
+        nhlog::ui()->debug("WebRTC: acceptInvite ignored without a pending invite");
         return;
+    }
 
     stopRingtone();
     std::string errorMessage;
@@ -541,6 +697,9 @@ CallManager::acceptInvite()
 
     session_.setTurnServers(turnURIs_);
     if (!session_.acceptOffer(inviteSDP_)) {
+        nhlog::ui()->warn("WebRTC: call id: {} - failed to accept offer in state {}",
+                          callid_,
+                          callStateString(session_.state()));
         emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
         hangUp();
         return;
@@ -570,8 +729,11 @@ void
 CallManager::handleEvent(const RoomEvent<CallCandidates> &callCandidatesEvent)
 {
     if (callCandidatesEvent.sender == utils::localUser().toStdString() &&
-        callCandidatesEvent.content.party_id == partyid_)
+        callCandidatesEvent.content.party_id == partyid_) {
+        nhlog::ui()->debug("WebRTC: ignoring echoed CallCandidates for call id {}",
+                           callCandidatesEvent.content.call_id);
         return;
+    }
     nhlog::ui()->debug("WebRTC: call id: {} - incoming CallCandidates from ({}, {})",
                        callCandidatesEvent.content.call_id,
                        callCandidatesEvent.sender,
@@ -583,9 +745,16 @@ CallManager::handleEvent(const RoomEvent<CallCandidates> &callCandidatesEvent)
         else {
             // CallInvite has been received and we're awaiting localUser to accept or
             // reject the call
+            nhlog::ui()->debug("WebRTC: queueing {} ICE candidates for pending invite {}",
+                               callCandidatesEvent.content.candidates.size(),
+                               callCandidatesEvent.content.call_id);
             for (const auto &c : callCandidatesEvent.content.candidates)
                 remoteICECandidates_.push_back(c);
         }
+    } else {
+        nhlog::ui()->debug("WebRTC: ignoring CallCandidates for inactive call id {} (active: {})",
+                           callCandidatesEvent.content.call_id,
+                           callid_);
     }
 }
 
@@ -596,8 +765,11 @@ CallManager::handleEvent(const RoomEvent<CallAnswer> &callAnswerEvent)
                        callAnswerEvent.content.call_id,
                        callAnswerEvent.sender,
                        callAnswerEvent.content.party_id);
-    if (answerSelected_)
+    if (answerSelected_) {
+        nhlog::ui()->debug("WebRTC: ignoring duplicate CallAnswer for call id {}",
+                           callAnswerEvent.content.call_id);
         return;
+    }
 
     if (callAnswerEvent.sender == utils::localUser().toStdString() &&
         callid_ == callAnswerEvent.content.call_id) {
@@ -622,9 +794,19 @@ CallManager::handleEvent(const RoomEvent<CallAnswer> &callAnswerEvent)
     if (isOnCall() && callid_ == callAnswerEvent.content.call_id) {
         stopRingtone();
         if (!session_.acceptAnswer(callAnswerEvent.content.answer.sdp)) {
+            nhlog::ui()->warn("WebRTC: call id: {} - failed to accept answer in state {}",
+                              callid_,
+                              callStateString(session_.state()));
             emit ChatPage::instance()->showNotification(QStringLiteral("Problem setting up call."));
             hangUp();
+            return;
         }
+    } else {
+        nhlog::ui()->debug("WebRTC: ignoring CallAnswer for inactive call id {} (active: {}, state: {})",
+                           callAnswerEvent.content.call_id,
+                           callid_,
+                           callStateString(session_.state()));
+        return;
     }
     emit newMessage(
       roomid_,
@@ -645,6 +827,11 @@ CallManager::handleEvent(const RoomEvent<CallHangUp> &callHangUpEvent)
     if (callid_ == callHangUpEvent.content.call_id ||
         isOnCallOnOtherDevice_ == callHangUpEvent.content.call_id)
         endCall();
+    else
+        nhlog::ui()->debug("WebRTC: ignoring CallHangUp for inactive call id {} (active: {}, other device: {})",
+                           callHangUpEvent.content.call_id,
+                           callid_,
+                           isOnCallOnOtherDevice_);
 }
 
 void
@@ -657,7 +844,7 @@ CallManager::handleEvent(const RoomEvent<CallSelectAnswer> &callSelectAnswerEven
     if (callSelectAnswerEvent.sender == utils::localUser().toStdString()) {
         if (callSelectAnswerEvent.content.party_id != partyid_) {
             if (std::find(rejectCallPartyIDs_.begin(),
-                          rejectCallPartyIDs_.begin(),
+                          rejectCallPartyIDs_.end(),
                           callSelectAnswerEvent.content.selected_party_id) !=
                 rejectCallPartyIDs_.end())
                 endCall();
@@ -675,7 +862,7 @@ CallManager::handleEvent(const RoomEvent<CallSelectAnswer> &callSelectAnswerEven
         if (callSelectAnswerEvent.content.selected_party_id != partyid_) {
             bool endAllCalls = false;
             if (std::find(rejectCallPartyIDs_.begin(),
-                          rejectCallPartyIDs_.begin(),
+                          rejectCallPartyIDs_.end(),
                           callSelectAnswerEvent.content.selected_party_id) !=
                 rejectCallPartyIDs_.end())
                 endAllCalls = true;
@@ -686,6 +873,10 @@ CallManager::handleEvent(const RoomEvent<CallSelectAnswer> &callSelectAnswerEven
             endCall(endAllCalls);
         } else if (session_.state() == webrtc::State::DISCONNECTED)
             endCall();
+    } else {
+        nhlog::ui()->debug("WebRTC: ignoring CallSelectAnswer for inactive call id {} (active: {})",
+                           callSelectAnswerEvent.content.call_id,
+                           callid_);
     }
 }
 
@@ -696,8 +887,11 @@ CallManager::handleEvent(const RoomEvent<CallReject> &callRejectEvent)
                        callRejectEvent.content.call_id,
                        callRejectEvent.sender,
                        callRejectEvent.content.party_id);
-    if (answerSelected_)
+    if (answerSelected_) {
+        nhlog::ui()->debug("WebRTC: ignoring CallReject after answer selection for call id {}",
+                           callRejectEvent.content.call_id);
         return;
+    }
 
     rejectCallPartyIDs_.push_back(callRejectEvent.content.party_id);
     // check remote echo
@@ -719,6 +913,10 @@ CallManager::handleEvent(const RoomEvent<CallReject> &callRejectEvent)
                 callid_, partyid_, callPartyVersion_, callRejectEvent.content.party_id});
             endCall();
         }
+    } else {
+        nhlog::ui()->debug("WebRTC: ignoring CallReject for inactive call id {} (active: {})",
+                           callRejectEvent.content.call_id,
+                           callid_);
     }
 }
 
@@ -730,8 +928,24 @@ CallManager::handleEvent(const RoomEvent<CallNegotiate> &callNegotiateEvent)
                        callNegotiateEvent.sender,
                        callNegotiateEvent.content.party_id);
 
+    if (callNegotiateEvent.sender == utils::localUser().toStdString() &&
+        callNegotiateEvent.content.party_id == partyid_) {
+        nhlog::ui()->debug("WebRTC: ignoring echoed CallNegotiate for call id {}",
+                           callNegotiateEvent.content.call_id);
+        return;
+    }
+    if (callNegotiateEvent.content.call_id != callid_) {
+        nhlog::ui()->debug("WebRTC: ignoring CallNegotiate for inactive call id {} (active: {})",
+                           callNegotiateEvent.content.call_id,
+                           callid_);
+        return;
+    }
+
     std::string negotiationSDP_ = callNegotiateEvent.content.description.sdp;
     if (!session_.acceptNegotiation(negotiationSDP_)) {
+        nhlog::ui()->warn("WebRTC: call id: {} - failed to accept renegotiation in state {}",
+                          callid_,
+                          callStateString(session_.state()));
         emit ChatPage::instance()->showNotification(QStringLiteral("Problem accepting new SDP"));
         hangUp();
         return;
@@ -848,6 +1062,8 @@ CallManager::retrieveTurnServer()
       [this](const mtx::responses::TurnServer &res, mtx::http::RequestErr err) {
           if (err) {
               turnServerTimer_.setInterval(5000);
+              nhlog::net()->warn("Failed to retrieve TURN server, retrying in 5s: {}",
+                                 requestErrorString(err));
               return;
           }
           emit turnServerRetrieved(res);

src/voip/WebRTCSession.cpp

@@ -206,6 +206,9 @@ iceGatheringStateChanged(GstElement *webrtc,
         if (WebRTCSession::instance().isOffering()) {
             emit WebRTCSession::instance().offerCreated(localsdp_, localcandidates_);
             emit WebRTCSession::instance().stateChanged(State::OFFERSENT);
+        } else if (WebRTCSession::instance().isNegotiating()) {
+            emit WebRTCSession::instance().negotiationCreated(localsdp_, localcandidates_);
+            WebRTCSession::instance().finishNegotiation();
         } else {
             emit WebRTCSession::instance().answerCreated(localsdp_, localcandidates_);
             emit WebRTCSession::instance().stateChanged(State::ANSWERSENT);
@@ -765,6 +768,12 @@ WebRTCSession::createOffer(CallType callType,
                            ScreenShareType screenShareType,
                            uint32_t shareWindowId)
 {
+    if (state_ != State::DISCONNECTED) {
+        nhlog::ui()->warn("WebRTC: createOffer ignored in state {}",
+                          static_cast<int>(state_));
+        return false;
+    }
+
     clear();
     isOffering_      = true;
     callType_        = callType;
@@ -783,8 +792,11 @@ bool
 WebRTCSession::acceptOffer(const std::string &sdp)
 {
     nhlog::ui()->debug("WebRTC: received offer:\n{}", sdp);
-    if (state_ != State::DISCONNECTED)
+    if (state_ != State::DISCONNECTED) {
+        nhlog::ui()->warn("WebRTC: acceptOffer ignored in state {}",
+                          static_cast<int>(state_));
         return false;
+    }
 
     clear();
     GstWebRTCSessionDescription *offer = parseSDP(sdp, GST_WEBRTC_SDP_TYPE_OFFER);
@@ -839,17 +851,61 @@ bool
 WebRTCSession::acceptNegotiation(const std::string &sdp)
 {
     nhlog::ui()->debug("WebRTC: received negotiation offer:\n{}", sdp);
-    if (state_ == State::DISCONNECTED)
+    if (state_ < State::INITIATED) {
+        nhlog::ui()->warn("WebRTC: acceptNegotiation ignored in state {}",
+                          static_cast<int>(state_));
         return false;
-    return false;
+    }
+    if (!pipe_ || !webrtc_) {
+        nhlog::ui()->error("WebRTC: acceptNegotiation called without an active pipeline");
+        return false;
+    }
+
+    GstWebRTCSessionDescription *offer = parseSDP(sdp, GST_WEBRTC_SDP_TYPE_OFFER);
+    if (!offer)
+        return false;
+
+    int opusPayloadType;
+    bool recvOnly;
+    bool sendOnly;
+    if (getMediaAttributes(offer->sdp, "audio", "opus", opusPayloadType, recvOnly, sendOnly)) {
+        if (opusPayloadType == -1) {
+            nhlog::ui()->error("WebRTC: remote negotiation offer - no opus encoding");
+            gst_webrtc_session_description_free(offer);
+            return false;
+        }
+    } else {
+        nhlog::ui()->error("WebRTC: remote negotiation offer - no audio media");
+        gst_webrtc_session_description_free(offer);
+        return false;
+    }
+
+    int unusedPayloadType;
+    bool isVideo = getMediaAttributes(
+      offer->sdp, "video", "vp8", unusedPayloadType, isRemoteVideoRecvOnly_, isRemoteVideoSendOnly_);
+    if (isVideo && unusedPayloadType == -1) {
+        nhlog::ui()->error("WebRTC: remote negotiation offer - no vp8 encoding");
+        gst_webrtc_session_description_free(offer);
+        return false;
+    }
+
+    localsdp_.clear();
+    localcandidates_.clear();
+    isNegotiating_ = true;
+    GstPromise *promise = gst_promise_new_with_change_func(createAnswer, webrtc_, nullptr);
+    g_signal_emit_by_name(webrtc_, "set-remote-description", offer, promise);
+    gst_webrtc_session_description_free(offer);
+    return true;
 }
 
 bool
 WebRTCSession::acceptAnswer(const std::string &sdp)
 {
     nhlog::ui()->debug("WebRTC: received answer:\n{}", sdp);
-    if (state_ != State::OFFERSENT)
+    if (state_ != State::OFFERSENT) {
+        nhlog::ui()->warn("WebRTC: acceptAnswer ignored in state {}", static_cast<int>(state_));
         return false;
+    }
 
     GstWebRTCSessionDescription *answer = parseSDP(sdp, GST_WEBRTC_SDP_TYPE_ANSWER);
     if (!answer) {
@@ -873,14 +929,19 @@ void
 WebRTCSession::acceptICECandidates(
   const std::vector<mtx::events::voip::CallCandidates::Candidate> &candidates)
 {
-    if (state_ >= State::INITIATED) {
-        for (const auto &c : candidates) {
-            nhlog::ui()->debug(
-              "WebRTC: remote candidate: (m-line:{}):{}", c.sdpMLineIndex, c.candidate);
-            if (!c.candidate.empty()) {
-                g_signal_emit_by_name(
-                  webrtc_, "add-ice-candidate", c.sdpMLineIndex, c.candidate.c_str());
-            }
+    if (state_ < State::INITIATED || !webrtc_) {
+        nhlog::ui()->debug("WebRTC: ignoring {} remote ICE candidates in state {}",
+                           candidates.size(),
+                           static_cast<int>(state_));
+        return;
+    }
+
+    for (const auto &c : candidates) {
+        nhlog::ui()->debug("WebRTC: remote candidate: (m-line:{}):{}",
+                           c.sdpMLineIndex,
+                           c.candidate);
+        if (!c.candidate.empty()) {
+            g_signal_emit_by_name(webrtc_, "add-ice-candidate", c.sdpMLineIndex, c.candidate.c_str());
         }
     }
 }
@@ -888,8 +949,10 @@ WebRTCSession::acceptICECandidates(
 bool
 WebRTCSession::startPipeline(int opusPayloadType, int vp8PayloadType)
 {
-    if (state_ != State::DISCONNECTED)
+    if (state_ != State::DISCONNECTED) {
+        nhlog::ui()->warn("WebRTC: startPipeline ignored in state {}", static_cast<int>(state_));
         return false;
+    }
 
     emit stateChanged(State::INITIATING);
 
@@ -956,8 +1019,10 @@ bool
 WebRTCSession::createPipeline(int opusPayloadType, int vp8PayloadType)
 {
     GstDevice *device = devices_.audioDevice();
-    if (!device)
+    if (!device) {
+        nhlog::ui()->error("WebRTC: no audio input device available");
         return false;
+    }
 
     GstElement *source     = gst_device_create_element(device, nullptr);
     GstElement *volume     = gst_element_factory_make("volume", "srclevel");
@@ -1039,8 +1104,10 @@ WebRTCSession::addVideoPipeline(int vp8PayloadType)
         std::pair<int, int> resolution;
         std::pair<int, int> frameRate;
         GstDevice *device = devices_.videoDevice(resolution, frameRate);
-        if (!device)
+        if (!device) {
+            nhlog::ui()->error("WebRTC: no video input device available");
             return false;
+        }
 
         GstElement *camera = gst_device_create_element(device, nullptr);
         GstCaps *caps      = gst_caps_new_simple("video/x-raw",
@@ -1305,6 +1372,7 @@ WebRTCSession::clear()
 {
     callType_              = webrtc::CallType::VOICE;
     isOffering_            = false;
+    isNegotiating_         = false;
     isRemoteVideoRecvOnly_ = false;
     isRemoteVideoSendOnly_ = false;
     videoItem_             = nullptr;

src/voip/WebRTCSession.h

@@ -70,6 +70,8 @@ public:
     webrtc::State state() const { return state_; }
     bool haveLocalPiP() const;
     bool isOffering() const { return isOffering_; }
+    bool isNegotiating() const { return isNegotiating_; }
+    void finishNegotiation() { isNegotiating_ = false; }
     bool isRemoteVideoRecvOnly() const { return isRemoteVideoRecvOnly_; }
     bool isRemoteVideoSendOnly() const { return isRemoteVideoSendOnly_; }
 
@@ -94,6 +96,8 @@ signals:
                       const std::vector<mtx::events::voip::CallCandidates::Candidate> &);
     void answerCreated(const std::string &sdp,
                        const std::vector<mtx::events::voip::CallCandidates::Candidate> &);
+    void negotiationCreated(const std::string &sdp,
+                            const std::vector<mtx::events::voip::CallCandidates::Candidate> &);
     void newICECandidate(const mtx::events::voip::CallCandidates::Candidate &);
     void stateChanged(webrtc::State);
 
@@ -111,6 +115,7 @@ private:
     webrtc::ScreenShareType screenShareType_ = webrtc::ScreenShareType::X11;
     webrtc::State state_                     = webrtc::State::DISCONNECTED;
     bool isOffering_                         = false;
+    bool isNegotiating_                      = false;
     bool isRemoteVideoRecvOnly_              = false;
     bool isRemoteVideoSendOnly_              = false;
     QQuickItem *videoItem_                   = nullptr;