Jibri SIP Gateway fails to invite

Hello,
I have deployed one vm for jitsi-meet, one for recording and one for JIbri SIP gateway. All is working fine except the SIP gateway. Actually, no invitation is sent. Here is the jibri config:

jibri {
  id = ""
  single-use-mode = false
  api {
    http {
      external-api-port = 2222
      internal-api-port = 3333
    }
    xmpp {
      environments = [
              {
                name = "xmpp environment"
                xmpp-server-hosts = ["conference.mydomain.com"]
                xmpp-domain = "conference.mydomain.com"

                control-muc {
                    domain = "internal.auth.mydomain.com"
                    room-name = "JibriBrewery"
                    nickname = "jibri-sip"
                }

                control-login {
                    domain = "auth.mydomain.com"
                    username = "jibri-sip"
                    password = "SipPassword"
                }

                call-login {
                    domain = "sipgateway.mydomain.com"
                    username = "jibrisip"
                    password = "SipPassword"
                }

                sip-control-muc {
                    domain = "conference.mydomain.com"
                    room-name = "TheSipBrewery"
                    nickname = "jibrisip"
                }

                strip-from-room-domain = "conference."
                usage-timeout = 0
                trust-all-xmpp-certs = true
            }]
    }
  }
  recording {
    # recordings-directory = "/srv/recordings"
    # TODO: make this an optional param and remove the default
    # finalize-script = "/srv/recordings/finalize_recording.sh"
  }
  streaming {
    rtmp-allow-list = [
      ".*"
    ]
  }


  ffmpeg {
    resolution = "1920x1080"
    audio-source = "alsa"
    audio-device = "plug:bsnoop"
  }

  chrome {
    flags = [
      "--use-fake-ui-for-media-stream",
      "--start-maximized",
      "--kiosk",
      "--enabled",
      "--disable-infobars",
      "--autoplay-policy=no-user-gesture-required",
      "–ignore-certificate-errors",
    ]
  }
  stats {
    enable-stats-d = true
  }
  webhook {
    subscribers = []
  }
  call-status-checks {
    no-media-timeout = 3 minutes

    all-muted-timeout = 10 minutes

    default-call-empty-timeout = 30 seconds

    ice-connection-timeout = 30 seconds

  }
}

Jibri log:

2022-11-29 01:00:21.041 INFO: [43] XmppApi.handleJibriIq#236: Received JibriIq <iq xmlns='jabber:client' to='jibri-sip@auth.conference.mydomain.com/T5xDKPL8KEA9' from='thesipbrewery@conference.conference.mydomain.com/focus' id='amlicmktc2lwQGF1dGguY29uZmVyZW5jZS5kZ2hzLmdvdi5iZC9UNXhES1BMOEtFQTkATVk0Rk0tMzIAn7gNgt+lLv8=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com' displayname='testsiproom' sipaddress='7001@10x.xxx.xxx.xxx' session_id='xwusilyzgewqhknx'/></iq> from environment [MucClient id=conference.mydomain.com hostname=conference.mydomain.com]
2022-11-29 01:00:21.042 INFO: [43] XmppApi.handleStartJibriIq#268: Received start request, starting service
2022-11-29 01:00:21.045 INFO: [43] XmppApi.handleStartService#379: Parsed call url info: CallUrlInfo(baseUrl=https://conference.mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[])
2022-11-29 01:00:21.062 INFO: [43] JibriManager.startSipGateway#176: Starting a SIP gateway with params: ServiceParams(usageTimeoutMinutes=0, appData=null) SipGatewayServiceParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://conference.mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[]), email='', passcode=null, callStatsUsernameOverride=, displayName=), callLoginParams=XmppCredentials(domain=sipgateway.mydomain.com, port=null, username=jibrisip, password=*****), sipClientParams=SipClientParams(sipAddress=7001@10x.xxx.xxx.xxx, displayName=testsiproom, autoAnswer=false, userName=null, password=null))
2022-11-29 01:00:21.550 INFO: [43] org.openqa.selenium.remote.ProtocolHandshake.createSession: Detected dialect: OSS
2022-11-29 01:00:21.568 FINE: [43] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: start:sip_gateway
2022-11-29 01:00:21.569 INFO: [43] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: IDLE -> BUSY
2022-11-29 01:00:21.569 FINE: [43] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-29 01:00:21.569 INFO: [43] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-29 01:00:21.571 INFO: [43] XmppApi.handleStartJibriIq#281: Sending 'pending' response to start IQ
2022-11-29 01:00:21.573 INFO: [58] AbstractPageObject.visit#32: Visiting url https://conference.mydomain.com
2022-11-29 01:00:21.837 INFO: [58] AbstractPageObject.visit#38: Waited 260.996945ms for driver to load page
2022-11-29 01:00:21.853 SEVERE: [58] JibriSelenium.joinCall$lambda-3#327: An error occurred while joining the call
org.openqa.selenium.WebDriverException: <unknown>: Failed to read the 'localStorage' property from 'Window': Access is denied for this document.
  (Session info: chrome=107.0.5304.121)
  (Driver info: chromedriver=107.0.5304.62 (1eec40d3a5764881c92085aaee66d25075c159aa-refs/branch-heads/5304@{#942}),platform=Linux 5.4.0-132-generic x86_64) (WARNING: The server did not provide any stacktrace information)
Command duration or timeout: 0 milliseconds
Build info: version: 'unknown', revision: 'unknown', time: 'unknown'
System info: host: 'sipgateway.mydomain.com', ip: '172.16.17.135', os.name: 'Linux', os.arch: 'amd64', os.version: '5.4.0-132-generic', java.version: '11.0.17'
Driver info: org.openqa.selenium.chrome.ChromeDriver
Capabilities {acceptInsecureCerts: false, acceptSslCerts: false, browserConnectionEnabled: false, browserName: chrome, chrome: {chromedriverVersion: 107.0.5304.62 (1eec40d3a576..., userDataDir: /tmp/.com.google.Chrome.gQYS2W}, cssSelectorsEnabled: true, databaseEnabled: false, goog:chromeOptions: {debuggerAddress: localhost:34859}, handlesAlerts: true, hasTouchScreen: false, javascriptEnabled: true, locationContextEnabled: true, mobileEmulationEnabled: false, nativeEvents: true, networkConnectionEnabled: false, pageLoadStrategy: normal, platform: LINUX, platformName: LINUX, proxy: Proxy(), rotatable: false, setWindowRect: true, strictFileInteractability: false, takesHeapSnapshot: true, takesScreenshot: true, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unexpectedAlertBehaviour: ignore, unhandledPromptBehavior: ignore, version: 107.0.5304.121, webStorageEnabled: true, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:virtualAuthenticators: true}
Session ID: e5c2a08ce75dcaaf2f78757195fd315c
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at org.openqa.selenium.remote.ErrorHandler.createThrowable(ErrorHandler.java:214)
        at org.openqa.selenium.remote.ErrorHandler.throwIfResponseFailed(ErrorHandler.java:166)
        at org.openqa.selenium.remote.http.JsonHttpResponseCodec.reconstructValue(JsonHttpResponseCodec.java:40)
        at org.openqa.selenium.remote.http.AbstractHttpResponseCodec.decode(AbstractHttpResponseCodec.java:80)
        at org.openqa.selenium.remote.http.AbstractHttpResponseCodec.decode(AbstractHttpResponseCodec.java:44)
        at org.openqa.selenium.remote.HttpCommandExecutor.execute(HttpCommandExecutor.java:158)
        at org.openqa.selenium.remote.service.DriverCommandExecutor.execute(DriverCommandExecutor.java:83)
        at org.openqa.selenium.remote.RemoteWebDriver.execute(RemoteWebDriver.java:543)
        at org.openqa.selenium.remote.RemoteWebDriver.executeScript(RemoteWebDriver.java:480)
        at org.jitsi.jibri.selenium.JibriSelenium.setLocalStorageValues(JibriSelenium.kt:211)
        at org.jitsi.jibri.selenium.JibriSelenium.joinCall$lambda-3(JibriSelenium.kt:317)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
2022-11-29 01:00:21.862 INFO: [58] JibriSelenium.onSeleniumStateChange#216: Transitioning from state Starting up to Error: FailedToJoinCall SESSION Failed to join the call
2022-11-29 01:00:21.865 INFO: [58] StatefulJibriService.onServiceStateChange#39: SIP gateway service transitioning from state Starting up to Error: FailedToJoinCall SESSION Failed to join the call
2022-11-29 01:00:21.866 INFO: [58] XmppApi$createServiceStatusHandler$1.invoke#317: Current service had an error Error: FailedToJoinCall SESSION Failed to join the call, sending error iq <iq xmlns='jabber:client' to='thesipbrewery@conference.conference.mydomain.com/focus' id='S4S2L-8' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7001@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq>
2022-11-29 01:00:21.868 FINE: [58] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: stop:sip_gateway
2022-11-29 01:00:21.868 INFO: [58] JibriManager.stopService#260: Stopping the current service
2022-11-29 01:00:21.868 INFO: [58] JibriSubprocess.stop#75: Stopping pjsua process
2022-11-29 01:00:21.869 INFO: [58] JibriSubprocess.stop#89: pjsua exited with value null
2022-11-29 01:00:21.869 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#338: Leaving call and quitting browser
2022-11-29 01:00:21.869 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#341: Recurring call status checks cancelled
2022-11-29 01:00:21.882 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#347: Got 3 log entries for type browser
2022-11-29 01:00:21.897 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#347: Got 93 log entries for type driver
2022-11-29 01:00:21.912 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#347: Got 0 log entries for type client
2022-11-29 01:00:21.912 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#356: Leaving web call
2022-11-29 01:00:21.931 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#363: Quitting chrome driver
2022-11-29 01:00:22.000 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#365: Chrome driver quit
2022-11-29 01:00:22.000 INFO: [58] JibriServiceFinalizeCommandRunner.doFinalize#44: Finalizing the jibri service operation using command [/opt/jitsi/jibri/finalize_sip.sh]
2022-11-29 01:00:32.005 SEVERE: [58] JibriServiceFinalizeCommandRunner.doFinalize#54: Timed out waiting for process logger task to complete
2022-11-29 01:00:32.006 INFO: [58] JibriServiceFinalizeCommandRunner.doFinalize#60: Finalize script finished with exit value 0
2022-11-29 01:00:32.007 INFO: [58] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: BUSY -> IDLE
2022-11-29 01:00:32.007 FINE: [58] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-29 01:00:32.008 INFO: [58] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections


Jicofo.log

Jicofo 2022-11-29 01:00:21.011 INFO: [28] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] BaseJibri.handleJibriRequest#75: Accepted jibri request: <iq xmlns='jabber:client' to='focus@auth.conference.mydomain.com/focus' from='a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com/34629e70' id='Zm9jdXNAYXV0aC5jb25mZXJlbmNlLmRnaHMuZ292LmJkL2ZvY3VzAGI2MDliNWRiLTlmM2UtNGI1MS05Zjk3LWU4ZmJmMDFjZDQyMzpzZW5kSVEAXYx8uR7qypg=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' displayname='testsiproom' sipaddress='7001@10x.xxx.xxx.xxx'/></iq>
Jicofo 2022-11-29 01:00:21.017 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.startInternal#316: Starting session with Jibri thesipbrewery@conference.conference.mydomain.com/jibri-sip
Jicofo 2022-11-29 01:00:21.020 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.sendJibriStartIq#470: Starting Jibri thesipbrewery@conference.conference.mydomain.com/jibri-sip for stream ID: null in room: a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com
Jicofo 2022-11-29 01:00:21.561 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.processJibriIqFromJibri#431: Updating status from JIBRI: <iq xmlns='jabber:client' to='focus@auth.conference.mydomain.com/focus' from='thesipbrewery@conference.conference.mydomain.com/jibri-sip' id='MY4FM-32' type='result'><jibri xmlns='http://jitsi.org/protocol/jibri' status='pending' sipaddress='7001@10x.xxx.xxx.xxx'/></iq> for a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com
Jicofo 2022-11-29 01:00:21.566 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.handleJibriStatusUpdate#619: Got Jibri status update: Jibri thesipbrewery@conference.conference.mydomain.com/jibri-sip has status pending and failure reason null, current Jibri jid is thesipbrewery@conference.conference.mydomain.com/jibri-sip
Jicofo 2022-11-29 01:00:21.567 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSipGateway.handleStartRequest#91: Started Jibri session
Jicofo 2022-11-29 01:00:21.854 INFO: [31] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] BaseJibri.handleJibriRequest#75: Accepted jibri request: <iq xmlns='jabber:client' to='focus@auth.conference.mydomain.com/focus' from='thesipbrewery@conference.conference.mydomain.com/jibri-sip' id='Zm9jdXNAYXV0aC5jb25mZXJlbmNlLmRnaHMuZ292LmJkL2ZvY3VzAFM0UzJMLTgADoMJBxkbQcw=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7001@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq>
Jicofo 2022-11-29 01:00:21.854 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.processJibriIqFromJibri#431: Updating status from JIBRI: <iq xmlns='jabber:client' to='focus@auth.conference.mydomain.com/focus' from='thesipbrewery@conference.conference.mydomain.com/jibri-sip' id='Zm9jdXNAYXV0aC5jb25mZXJlbmNlLmRnaHMuZ292LmJkL2ZvY3VzAFM0UzJMLTgADoMJBxkbQcw=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7001@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq> for a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com
Jicofo 2022-11-29 01:00:21.854 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.handleJibriStatusUpdate#619: Got Jibri status update: Jibri thesipbrewery@conference.conference.mydomain.com/jibri-sip has status off and failure reason error, current Jibri jid is thesipbrewery@conference.conference.mydomain.com/jibri-sip
Jicofo 2022-11-29 01:00:21.854 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.clearPendingTimeout#571: Jibri is no longer pending, cancelling pending timeout task
Jicofo 2022-11-29 01:00:21.855 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.handleJibriStatusUpdate#658: Jibri failed, trying to fall back to another Jibri
Jicofo 2022-11-29 01:00:21.855 SEVERE: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.startInternal#304: Unable to find an available Jibri, can't start
Jicofo 2022-11-29 01:00:21.857 WARNING: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.handleJibriStatusUpdate#669: Failed to fall back to another Jibri, this session has now failed: org.jitsi.jicofo.jibri.JibriSession$StartException$AllBusy: All jibri instances are busy
org.jitsi.jicofo.jibri.JibriSession$StartException$AllBusy: All jibri instances are busy
        at org.jitsi.jicofo.jibri.JibriSession.startInternal(JibriSession.java:308)
        at org.jitsi.jicofo.jibri.JibriSession.start(JibriSession.java:282)
        at org.jitsi.jicofo.jibri.JibriSession.retryRequestWithAnotherJibri(JibriSession.java:595)
        at org.jitsi.jicofo.jibri.JibriSession.handleJibriStatusUpdate(JibriSession.java:662)
        at org.jitsi.jicofo.jibri.JibriSession.processJibriIqFromJibri(JibriSession.java:433)
        at org.jitsi.jicofo.jibri.JibriSession.processJibriIqRequestFromJibri(JibriSession.java:417)
        at org.jitsi.jicofo.jibri.BaseJibri.doHandleIQRequest(BaseJibri.kt:156)
        at org.jitsi.jicofo.jibri.BaseJibri.incomingIqQueue$lambda-0(BaseJibri.kt:56)
        at org.jitsi.utils.queue.PacketQueue$HandlerAdapter.handleItem(PacketQueue.java:416)
        at org.jitsi.utils.queue.AsyncQueueHandler$1.run(AsyncQueueHandler.java:136)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Jicofo 2022-11-29 01:00:21.859 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSipGateway.publishJibriSipCallState#143: Publishing new state: 7001@10x.xxx.xxx.xxx <jibri-sip-call-state xmlns='http://jitsi.org/protocol/jibri/call_state' state='off' failure_reason='error' sipaddress='7001@10x.xxx.xxx.xxx' session_id='xwusilyzgewqhknx'/>
Jicofo 2022-11-29 01:00:21.859 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSipGateway.onSessionStateChanged#121: Removing SIP call: 7001@10x.xxx.xxx.xxx
Jicofo 2022-11-29 01:00:21.860 INFO: [29] [room=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com meeting_id=b41973d5-4645-4c28-96fa-af773a224872] JibriSession.cleanupSession#386: Cleaning up current JibriSession
Jicofo 2022-11-29 01:01:15.948 INFO: [15] AbstractAuthAuthority$ExpireTask.run#524: Expiring session:AuthSession[ID=34629e70-7653-4146-9724-2477de2e981c@conference.mydomain.com, JID=34629e70-7653-4146-9724-2477de2e981c@conference.mydomain.com/-8lQjnQkYhy5, SID=e5aaadba-4417-4a7a-ba75-ea18237eb8b9, MUID=a5381fa17754cad90d7b47be59e7b247, LIFE_TM_SEC=63, R=a2038abb86ed4c7db05eed4e5f0bf95c@conference.conference.mydomain.com]@1600000514
Jicofo 2022-11-29 01:01:22.106 INFO: [31] [type=jibri brewery=jibribrewery] BaseBrewery.addInstance#342: Added brewery instance: jibribrewery@internal.auth.conference.mydomain.com/jibri-nickname
Jicofo 2022-11-29 01:01:22.107 INFO: [31] JibriDetector.onInstanceStatusChanged#98: Creating a new instance for jibribrewery@internal.auth.conference.mydomain.com/jibri-nickname, available = true


sudo ngrep -d any -W byline port 5060 shows no activity while making the invitation in jitsi.
When running pjsua directly outside jibri:

01:14:31.079         os_core_unix.c !pjlib 2.10-jitsi3 for POSIX initialized
01:14:31.081         sip_endpoint.c  .Creating endpoint instance...
01:14:31.081                  pjlib  .select() I/O Queue created (0x555d4bfad000)
01:14:31.081         sip_endpoint.c  .Module "mod-msg-print" registered
01:14:31.081        sip_transport.c  .Transport manager created.
01:14:31.081           pjsua_core.c  .PJSUA state changed: NULL --> CREATED
01:14:31.081         sip_endpoint.c  .Module "mod-pjsua-log" registered
01:14:31.081         sip_endpoint.c  .Module "mod-tsx-layer" registered
01:14:31.081         sip_endpoint.c  .Module "mod-stateful-util" registered
01:14:31.081         sip_endpoint.c  .Module "mod-ua" registered
01:14:31.081         sip_endpoint.c  .Module "mod-100rel" registered
01:14:31.081         sip_endpoint.c  .Module "mod-pjsua" registered
01:14:31.081         sip_endpoint.c  .Module "mod-invite" registered
01:14:31.096             alsa_dev.c  ..ALSA driver found 26 devices
01:14:31.096             alsa_dev.c  ..ALSA initialized
01:14:31.096                  pjlib  ..select() I/O Queue created (0x555d4bfc7b48)
01:14:31.097            pjsua_vid.c  ..Initializing video subsystem..
01:14:31.097                  vpx.c  ...VPX codec initialized
01:14:31.097             v4l2_dev.c  ...Video4Linux2 has 0 devices
error: XDG_RUNTIME_DIR not set in the environment.
01:14:31.098              sdl_dev.c !SDL_Init() error: No available video device
01:14:31.098         colorbar_dev.c !...Colorbar video src initialized with 2 device(s):
01:14:31.098         colorbar_dev.c  ... 0: Colorbar generator
01:14:31.098         colorbar_dev.c  ... 1: Colorbar-active
01:14:31.098         sip_endpoint.c  .Module "mod-evsub" registered
01:14:31.098         sip_endpoint.c  .Module "mod-presence" registered
01:14:31.098         sip_endpoint.c  .Module "mod-mwi" registered
01:14:31.098         sip_endpoint.c  .Module "mod-refer" registered
01:14:31.098         sip_endpoint.c  .Module "mod-pjsua-pres" registered
01:14:31.098         sip_endpoint.c  .Module "mod-pjsua-im" registered
01:14:31.098         sip_endpoint.c  .Module "mod-pjsua-options" registered
01:14:31.098           pjsua_core.c  .1 SIP worker threads created
01:14:31.098           pjsua_core.c  .pjsua version 2.10-jitsi3 for Linux-5.4.0.132/x86_64/glibc-2.31 initialized
01:14:31.098           pjsua_core.c  .PJSUA state changed: CREATED --> INIT
01:14:31.098         sip_endpoint.c  Module "mod-default-handler" registered
01:14:31.099           pjsua_core.c  SIP UDP socket reachable at 172.16.17.135:5060
01:14:31.099      udp0x555d4c009680  SIP UDP transport started, published address is 172.16.17.135:5060
01:14:31.099            pjsua_acc.c  Adding account: id=<sip:172.16.17.135:5060>
01:14:31.099            pjsua_acc.c  .Account <sip:172.16.17.135:5060> added with id 0
01:14:31.099            pjsua_acc.c  Modifying account 0
01:14:31.099            pjsua_acc.c  Acc 0: setting online status to 1..
01:14:31.100             tcptp:5060  SIP TCP listener ready for incoming connections at 172.16.17.135:5060
01:14:31.100            pjsua_acc.c  Adding account: id=<sip:172.16.17.135:5060;transport=TCP>
01:14:31.100            pjsua_acc.c  .Account <sip:172.16.17.135:5060;transport=TCP> added with id 1
01:14:31.100            pjsua_acc.c  Modifying account 1
01:14:31.100            pjsua_acc.c  Acc 1: setting online status to 1..
01:14:31.100           pjsua_pres.c  Adding buddy: sip:7001@10x.xxx.xxx.xxx
01:14:31.100           pjsua_pres.c  .Buddy 0 added.
01:14:31.100           pjsua_pres.c  ..Buddy 0: updating presence..
01:14:31.100           pjsua_core.c  PJSUA state changed: INIT --> STARTING
01:14:31.100         sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
01:14:31.100           pjsua_core.c  .PJSUA state changed: STARTING --> RUNNING
01:14:31.100                 main.c  Ready: Success
01:14:31.100           pjsua_call.c  Making call with acc #1 to sip:7001@10x.xxx.xxx.xxx
01:14:31.100            pjsua_aud.c  .Set sound device: capture=-1, playback=-2
01:14:31.100            pjsua_app.c  ..Turning sound device -1 -2 ON
01:14:31.100            pjsua_aud.c  ..Opening sound device (speaker + mic) PCM@16000/1/20ms
01:14:31.101       ec0x555d4bfdb620  ...Speex AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=0 ms
01:14:31.101     tcpc0x555d4c05b568  .TCP client transport created
01:14:31.101     tcpc0x555d4c05b568  .TCP transport 172.16.17.135:50201 is connecting to 172.16.17.135:5060...
01:14:31.101          pjsua_media.c  .Call 0: initializing media..
pjsua: ../src/pjmedia/conference.c:1894: get_frame: Assertion `frame->size == conf->samples_per_frame * conf->bits_per_sample / 8' failed.
Aborted

I’m totally lost for last 7 days. Any help will highly be appreciated. Thanks in advance.

“sip-control-muc.domain” should be "internal.auth.mydomain.com"

THis suggests some problem starting Chromium, any chance you are using a self-signed cert or something?

Resolved the issue. Now jibri log looks like:

2022-11-29 10:32:34.029 INFO: [1] MainKt.handleCommandLineArgs#186: Jibri run with args [--config, /etc/jitsi/jibri/config.json]
2022-11-29 10:32:34.105 INFO: [1] MainKt.setupLegacyConfig#211: Checking legacy config file /etc/jitsi/jibri/config.json
2022-11-29 10:32:34.110 INFO: [1] MainKt.setupLegacyConfig#214: Legacy config file /etc/jitsi/jibri/config.json doesn't exist
2022-11-29 10:32:34.380 INFO: [1] MainKt.main#55: Jibri starting up with id
2022-11-29 10:32:34.693 INFO: [1] JwtInfo$Companion.fromConfig#176: got jwtConfig: {}

2022-11-29 10:32:34.694 INFO: [1] JwtInfo$Companion.fromConfig#186: Unable to create JwtInfo: com.typesafe.config.ConfigException$Missing: reference.conf @ jar:file:/opt/jitsi/jibri/jibri.jar!/reference.conf: 77: No configuration setting found for key 'signing-key-path'
2022-11-29 10:32:34.696 FINE: [1] RefreshingProperty.getValue#47: Refreshing property jwt (not yet initialized or expired)...
2022-11-29 10:32:34.814 INFO: [1] MainKt.main#125: Using port 3333 for internal HTTP API
2022-11-29 10:32:34.818 FINE: [20] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-29 10:32:35.169 INFO: [1] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-29 10:32:35.204 INFO: [1] XmppApi.start#156: Connecting to xmpp environment on mydomain.com with config XmppEnvironmentConfig(name=xmpp environment, xmppServerHosts=[mydomain.com], xmppDomain=mydomain.com, baseUrl=null, controlLogin=XmppCredentials(domain=auth.mydomain.com, port=null, username=jibri-sip, password=*****), controlMuc=XmppMuc(domain=internal.auth.mydomain.com, roomName=JibriBrewery, nickname=jibri-sip), sipControlMuc=XmppMuc(domain=conference.mydomain.com, roomName=TheSipBrewery, nickname=jibrisip), callLogin=XmppCredentials(domain=sipgateway.dghs.gov.bd, port=null, username=jibrisip, password=*****), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true, securityMode=null)
2022-11-29 10:32:35.205 INFO: [1] XmppApi.start#174: The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2022-11-29 10:32:35.230 INFO: [1] MainKt.main#152: Using port 2222 for HTTP API
2022-11-29 10:32:35.241 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient.initializeConnectAndJoin#279: Initializing a new MucClient for [ org.jitsi.xmpp.mucclient.MucClientConfiguration id=mydomain.com domain=auth.mydomain.com hostname=mydomain.com port=null username=jibri-sip mucs=[jibribrewery@internal.auth.mydomain.com, thesipbrewery@conference.mydomain.com] mucNickname=jibri-sip disableCertificateVerification=true]
2022-11-29 10:32:35.258 WARNING: [33] MucClient.createXMPPTCPConnectionConfiguration#115: Disabling certificate verification!
2022-11-29 10:32:35.281 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient.initializeConnectAndJoin#341: Dispatching a thread to connect and login.
2022-11-29 10:32:35.393 FINE: [33] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: xmpp-connected:xmpp_server_host:mydomain.com
2022-11-29 10:32:35.393 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$2.connected#312: Connected.
2022-11-29 10:32:35.393 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient.lambda$getConnectAndLoginCallable$9#637: Logging in.
2022-11-29 10:32:35.462 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$2.authenticated#318: Authenticated, b=false
2022-11-29 10:32:35.480 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$MucWrapper.join#761: Joined MUC: jibribrewery@internal.auth.mydomain.com
2022-11-29 10:32:35.491 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$MucWrapper.join#761: Joined MUC: thesipbrewery@conference.mydomain.com
2022-11-29 10:32:45.776 INFO: [43] XmppApi.handleJibriIq#236: Received JibriIq <iq xmlns='jabber:client' to='jibri-sip@auth.mydomain.com/Qa3fo7ovkR_T' from='thesipbrewery@conference.mydomain.com/focus' id='amlicmktc2lwQGF1dGguY29uZmVyZW5jZS5kZ2hzLmdvdi5iZC9RYTNmbzdvdmtSX1QATVk0Rk0tMTE3ODkAn7gNgt+lLv8=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a2038abb86ed4c7db05eed4e5f0bf95c@conference.mydomain.com' displayname='testsiproom' sipaddress='7001@10x.xxx.xxx.xxx' session_id='ghngmmiowbbpzmbo'/></iq> from environment [MucClient id=mydomain.com hostname=mydomain.com]
2022-11-29 10:32:45.777 INFO: [43] XmppApi.handleStartJibriIq#268: Received start request, starting service
2022-11-29 10:32:45.780 INFO: [43] XmppApi.handleStartService#379: Parsed call url info: CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[])
2022-11-29 10:32:45.797 INFO: [43] JibriManager.startSipGateway#176: Starting a SIP gateway with params: ServiceParams(usageTimeoutMinutes=0, appData=null) SipGatewayServiceParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[]), email='', passcode=null, callStatsUsernameOverride=, displayName=), callLoginParams=XmppCredentials(domain=sipgateway.dghs.gov.bd, port=null, username=jibrisip, password=*****), sipClientParams=SipClientParams(sipAddress=7001@10x.xxx.xxx.xxx, displayName=testsiproom, autoAnswer=false, userName=null, password=null))
2022-11-29 10:32:46.281 INFO: [43] org.openqa.selenium.remote.ProtocolHandshake.createSession: Detected dialect: OSS
2022-11-29 10:32:46.298 FINE: [43] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: start:sip_gateway
2022-11-29 10:32:46.300 INFO: [43] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: IDLE -> BUSY
2022-11-29 10:32:46.300 FINE: [43] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-29 10:32:46.300 INFO: [43] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-29 10:32:46.302 INFO: [43] XmppApi.handleStartJibriIq#281: Sending 'pending' response to start IQ
2022-11-29 10:32:46.306 INFO: [58] AbstractPageObject.visit#32: Visiting url https://mydomain.com
2022-11-29 10:32:47.686 INFO: [58] AbstractPageObject.visit#38: Waited 1.378426907s for driver to load page
2022-11-29 10:32:47.728 INFO: [58] AbstractPageObject.visit#32: Visiting url https://mydomain.com/a2038abb86ed4c7db05eed4e5f0bf95c#config.iAmRecorder=true&config.iAmSipGateway=true&config.ignoreStartMuted=true&config.analytics.disabled=true&config.enableEmailInStats=false&config.p2p.enabled=false&config.prejoinPageEnabled=false&config.prejoinConfig.enabled=false&config.requireDisplayName=false&devices.videoInput="PJSUA"
2022-11-29 10:32:48.267 INFO: [58] AbstractPageObject.visit#38: Waited 538.564663ms for driver to load page
2022-11-29 10:32:48.281 FINE: [58] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-29 10:32:48.788 FINE: [58] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-29 10:32:49.805 INFO: [58] CallPage.visit#71: Waited 1.538164050s to join the conference
2022-11-29 10:32:49.808 INFO: [58] EmptyCallStatusCheck.<init>#26: Starting empty call check with a timeout of PT30M
2022-11-29 10:32:49.812 INFO: [58] LocalParticipantKickedStatusCheck.<init>#14: Starting local participant kicked out call check
2022-11-29 10:32:49.827 INFO: [58] JibriSelenium.onSeleniumStateChange#216: Transitioning from state Starting up to Running
2022-11-29 10:32:49.828 INFO: [58] SipGatewayJibriService$start$2.invoke#139: Selenium joined the call, starting pjsua
2022-11-29 10:32:49.833 INFO: [58] JibriSubprocess.launch#42: Starting pjsua with command /opt/jitsi/jibri/pjsua.sh --id=testsiproom <sip:jibri@127.0.0.1> sip:out_7001@10x.xxx.xxx.xxx ([/opt/jitsi/jibri/pjsua.sh, --id=testsiproom <sip:jibri@127.0.0.1>, sip:out_7001@10x.xxx.xxx.xxx])
2022-11-29 10:32:49.841 INFO: [61] StatefulJibriService.onServiceStateChange#39: SIP gateway service transitioning from state Starting up to Running
2022-11-29 10:32:49.842 INFO: [61] XmppApi$createServiceStatusHandler$1.invoke#334: Current service started up successfully, sending on iq <iq xmlns='jabber:client' to='thesipbrewery@conference.mydomain.com/focus' id='L6MP8-8' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='on' sipaddress='7001@10x.xxx.xxx.xxx'/></iq>
2022-11-29 10:32:54.839 FINE: [20] ProcessStatePublisher$startProcessAliveChecks$1.invoke#86: Process pjsua hasn't written in 2 seconds, publishing periodic update
2022-11-29 10:32:54.847 INFO: [58] StatefulJibriService.onServiceStateChange#39: SIP gateway service transitioning from state Running to Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 1
2022-11-29 10:32:54.847 INFO: [58] XmppApi$createServiceStatusHandler$1.invoke#317: Current service had an error Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 1, sending error iq <iq xmlns='jabber:client' to='thesipbrewery@conference.mydomain.com/focus' id='L6MP8-10' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7001@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq>
2022-11-29 10:32:54.849 FINE: [58] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: stop:sip_gateway
2022-11-29 10:32:54.849 INFO: [58] JibriManager.stopService#260: Stopping the current service
2022-11-29 10:32:54.849 INFO: [58] JibriSubprocess.stop#75: Stopping pjsua process
2022-11-29 10:32:54.853 INFO: [58] JibriSubprocess.stop#89: pjsua exited with value 1
2022-11-29 10:32:54.853 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#338: Leaving call and quitting browser
2022-11-29 10:32:54.853 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#341: Recurring call status checks cancelled
2022-11-29 10:32:54.868 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#347: Got 21 log entries for type browser
2022-11-29 10:32:54.968 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#347: Got 443 log entries for type driver
2022-11-29 10:32:55.019 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#347: Got 0 log entries for type client
2022-11-29 10:32:55.020 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#356: Leaving web call
2022-11-29 10:32:55.085 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#363: Quitting chrome driver
2022-11-29 10:32:55.153 INFO: [58] JibriSelenium.leaveCallAndQuitBrowser#365: Chrome driver quit
2022-11-29 10:32:55.154 INFO: [58] JibriServiceFinalizeCommandRunner.doFinalize#44: Finalizing the jibri service operation using command [/opt/jitsi/jibri/finalize_sip.sh]
2022-11-29 10:32:55.156 INFO: [57] LoggingUtils$Companion$OutputLogger$1.invoke$lambda-0#42: Appending pjsua logs from /var/log/jitsi/jibri/pjsua.log, to /var/log/jitsi/jibri/pjsua_all.log
2022-11-29 10:32:55.157 INFO: [58] JibriServiceFinalizeCommandRunner.doFinalize#60: Finalize script finished with exit value 0
2022-11-29 10:32:55.158 INFO: [58] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: BUSY -> IDLE
2022-11-29 10:32:55.158 FINE: [58] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-29 10:32:55.158 INFO: [58] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections

Direct call from pjsua says:

10:37:08.677         os_core_unix.c !pjlib 2.10-jitsi3 for POSIX initialized
10:37:08.678         sip_endpoint.c  .Creating endpoint instance...
10:37:08.678                  pjlib  .select() I/O Queue created (0x55dddf07cf80)
10:37:08.678         sip_endpoint.c  .Module "mod-msg-print" registered
10:37:08.678        sip_transport.c  .Transport manager created.
10:37:08.678           pjsua_core.c  .PJSUA state changed: NULL --> CREATED
10:37:08.678         sip_endpoint.c  .Module "mod-pjsua-log" registered
10:37:08.678         sip_endpoint.c  .Module "mod-tsx-layer" registered
10:37:08.678         sip_endpoint.c  .Module "mod-stateful-util" registered
10:37:08.678         sip_endpoint.c  .Module "mod-ua" registered
10:37:08.678         sip_endpoint.c  .Module "mod-100rel" registered
10:37:08.678         sip_endpoint.c  .Module "mod-pjsua" registered
10:37:08.678         sip_endpoint.c  .Module "mod-invite" registered
10:37:08.697             alsa_dev.c  ..ALSA driver found 32 devices
10:37:08.697             alsa_dev.c  ..ALSA initialized
10:37:08.697                  pjlib  ..select() I/O Queue created (0x55dddf08ecc8)
10:37:08.698            pjsua_vid.c  ..Initializing video subsystem..
10:37:08.699                  vpx.c  ...VPX codec initialized
10:37:08.699             v4l2_dev.c  ...Video4Linux2 has 0 devices
10:37:08.699              sdl_dev.c !SDL_Init() error: No available video device
10:37:08.699         colorbar_dev.c !...Colorbar video src initialized with 2 device(s):
10:37:08.699         colorbar_dev.c  ... 0: Colorbar generator
10:37:08.699         colorbar_dev.c  ... 1: Colorbar-active
10:37:08.699         sip_endpoint.c  .Module "mod-evsub" registered
10:37:08.699         sip_endpoint.c  .Module "mod-presence" registered
10:37:08.699         sip_endpoint.c  .Module "mod-mwi" registered
10:37:08.699         sip_endpoint.c  .Module "mod-refer" registered
10:37:08.699         sip_endpoint.c  .Module "mod-pjsua-pres" registered
10:37:08.699         sip_endpoint.c  .Module "mod-pjsua-im" registered
10:37:08.699         sip_endpoint.c  .Module "mod-pjsua-options" registered
10:37:08.699           pjsua_core.c  .1 SIP worker threads created
10:37:08.699           pjsua_core.c  .pjsua version 2.10-jitsi3 for Linux-5.4.0.132/x86_64/glibc-2.31 initialized
10:37:08.699           pjsua_core.c  .PJSUA state changed: CREATED --> INIT
10:37:08.699         sip_endpoint.c  Module "mod-default-handler" registered
10:37:08.700           pjsua_core.c  SIP UDP socket reachable at 172.16.17.135:5060
10:37:08.700      udp0x55dddf0a0720  SIP UDP transport started, published address is 172.16.17.135:5060
10:37:08.700            pjsua_acc.c  Adding account: id=<sip:172.16.17.135:5060>
10:37:08.700            pjsua_acc.c  .Account <sip:172.16.17.135:5060> added with id 0
10:37:08.700            pjsua_acc.c  Modifying account 0
10:37:08.700            pjsua_acc.c  Acc 0: setting online status to 1..
10:37:08.700             tcptp:5060  SIP TCP listener ready for incoming connections at 172.16.17.135:5060
10:37:08.700            pjsua_acc.c  Adding account: id=<sip:172.16.17.135:5060;transport=TCP>
10:37:08.700            pjsua_acc.c  .Account <sip:172.16.17.135:5060;transport=TCP> added with id 1
10:37:08.700            pjsua_acc.c  Modifying account 1
10:37:08.700            pjsua_acc.c  Acc 1: setting online status to 1..
10:37:08.700           pjsua_pres.c  Adding buddy: sip:7001@10x.xxx.xxx.xxx
10:37:08.700           pjsua_pres.c  .Buddy 0 added.
10:37:08.700           pjsua_pres.c  ..Buddy 0: updating presence..
10:37:08.700           pjsua_core.c  PJSUA state changed: INIT --> STARTING
10:37:08.700         sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
10:37:08.700           pjsua_core.c  .PJSUA state changed: STARTING --> RUNNING
10:37:08.700                 main.c  Ready: Success
10:37:08.700           pjsua_call.c  Making call with acc #1 to sip:7001@10x.xxx.xxx.xxx
10:37:08.700            pjsua_aud.c  .Set sound device: capture=-1, playback=-2
10:37:08.700            pjsua_app.c  ..Turning sound device -1 -2 ON
10:37:08.700            pjsua_aud.c  ..Opening sound device (speaker + mic) PCM@16000/1/20ms
10:37:08.700             alsa_dev.c  ...ALSA lib pcm_hw.c:1220:(snd_pcm_query_chmaps_from_hw) Cannot read Channel Map TLV
: No such file or directory
10:37:08.701             alsa_dev.c  ...ALSA lib pcm_hw.c:1220:(snd_pcm_query_chmaps_from_hw) Cannot read Channel Map TLV
: No such file or directory
10:37:08.701       ec0x55dddf0e0220  ...Speex AEC created, clock_rate=16000, channel=1, samples per frame=320, tail length=200 ms, latency=0 ms
10:37:08.701     tcpc0x55dddf10f9a8  .TCP client transport created
10:37:08.701     tcpc0x55dddf10f9a8  .TCP transport 172.16.17.135:60249 is connecting to 172.16.17.135:5060...
10:37:08.701          pjsua_media.c  .Call 0: initializing media..
10:37:08.702          pjsua_media.c  ..RTP socket reachable at 172.16.17.135:4000
10:37:08.702          pjsua_media.c  ..RTCP socket reachable at 172.16.17.135:4001
10:37:08.702          pjsua_media.c  ..Media index 0 selected for audio call 0
10:37:08.702     tcpc0x55dddf11fc68  ....TCP client transport created
10:37:08.702     tcpc0x55dddf11fc68  ....TCP transport 172.16.17.135:37293 is connecting to 10x.xxx.xxx.xxx:5060...
10:37:08.702           pjsua_core.c  ....TX 1458 bytes Request msg INVITE/cseq=28979 (tdta0x55dddf11bf38) to TCP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/TCP 172.16.17.135:60249;rport;branch=z9hG4bKPj5ae225a5-4bcc-4ee5-a315-d52dc2631410;alias
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=9d36fe41-9006-45d0-a851-7798188eb50d
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 3f9f7ee2-25ec-41ce-8cbb-c759e4d9ad0a
CSeq: 28979 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878707028 3878707028 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1116726738 cname:51ef87590b8da882
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:37:08.702            pjsua_app.c  .......Call 0 state changed to CALLING
>>>>
Account list:
  [ 0] <sip:172.16.17.135:5060>: does not register
       Online status: Online
 *[ 1] <sip:172.16.17.135:5060;transport=TCP>: does not register
       Online status: Online
Buddy list:
 [ 1] <?>  sip:7001@10x.xxx.xxx.xxx

+=============================================================================+
|       Call Commands:         |   Buddy, IM & Presence:  |     Account:      |
|                              |                          |                   |
|  m  Make new call            | +b  Add new buddy       .| +a  Add new accnt |
|  M  Make multiple calls      | -b  Delete buddy         | -a  Delete accnt. |
|  a  Answer call              |  i  Send IM              | !a  Modify accnt. |
|  h  Hangup call  (ha=all)    |  s  Subscribe presence   | rr  (Re-)register |
|  H  Hold call                |  u  Unsubscribe presence | ru  Unregister    |
|  v  re-inVite (release hold) |  t  ToGgle Online status |  >  Cycle next ac.|
|  U  send UPDATE              |  T  Set online status    |  <  Cycle prev ac.|
| ],[ Select next/prev call    +--------------------------+-------------------+
|  x  Xfer call                |      Media Commands:     |  Status & Config: |
|  X  Xfer with Replaces       |                          |                   |
|  #  Send RFC 2833 DTMF       | cl  List ports           |  d  Dump status   |
|  *  Send DTMF with INFO      | cc  Connect port         | dd  Dump detailed |
| dq  Dump curr. call quality  | cd  Disconnect port      | dc  Dump config   |
|                              |  V  Adjust audio Volume  |  f  Save config   |
|  S  Send arbitrary REQUEST   | Cp  Codec priorities     |                   |
+-----------------------------------------------------------------------------+
| Video: "vid help" for more info                                             |
+-----------------------------------------------------------------------------+
|  q  QUIT   L  ReLoad   sleep MS   echo [0|1|txt]     n: detect NAT type     |
+=============================================================================+
You have 1 active call
Current call id=0 to sip:7001@10x.xxx.xxx.xxx [CALLING]
>>> 10:37:08.710             tcptp:5060 !TCP listener 172.16.17.135:5060: got incoming TCP connection from 172.16.17.135:60249, sock=13
10:37:08.710     tcps0x7f6998001518  TCP server transport created
10:37:08.710            pjsua_app.c  SIP TCP transport is connected to 172.16.17.135:60249
10:37:08.710     tcpc0x55dddf10f9a8  TCP transport 172.16.17.135:60249 is connected to 172.16.17.135:5060
10:37:08.710            pjsua_app.c  SIP TCP transport is connected to 172.16.17.135:5060
10:37:08.710     tcpc0x55dddf11fc68  TCP connect() error: [code=120111]: Connection refused
10:37:08.710      tsx0x55dddf11eea8  Failed to send Request msg INVITE/cseq=28979 (tdta0x55dddf11bf38)! err=120111 (Connection refused)
10:37:08.710            pjsua_app.c  ...Call 0 is DISCONNECTED [reason=503 (Connection refused)]
10:37:08.710     pjsua_app_common.c  ...
  [DISCONNCTD] To: sip:7001@10x.xxx.xxx.xxx
    Call time: 00h:00m:00s, 1st res in 9 ms, conn in 0ms

@emrah and @saghul thanks a lot for your help. Would you please look into the log now?

The SIP server where you are connecting doesn’t seem to be listening on SIP over TCP.

With --no-tcp

You have 1 active call
Current call id=0 to sip:7001@10x.xxx.xxx.xxx [CALLING]
>>> 10:58:11.097           pjsua_core.c  .TX 1451 bytes Request msg INVITE/cseq=16115 (tdta0x563f9005c378) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9d5a565d-7ff7-497f-97d7-1c40c6fc36c2
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=27fd4acd-efb0-4afb-a081-4d6894954cc5
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 8ffc6b0c-1df2-46a6-98b3-27b178726e18
CSeq: 16115 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878708290 3878708290 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1100650013 cname:59c704b40aaadf8a
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:58:12.097           pjsua_core.c  .TX 1451 bytes Request msg INVITE/cseq=16115 (tdta0x563f9005c378) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9d5a565d-7ff7-497f-97d7-1c40c6fc36c2
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=27fd4acd-efb0-4afb-a081-4d6894954cc5
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 8ffc6b0c-1df2-46a6-98b3-27b178726e18
CSeq: 16115 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878708290 3878708290 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1100650013 cname:59c704b40aaadf8a
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:58:14.097           pjsua_core.c  .TX 1451 bytes Request msg INVITE/cseq=16115 (tdta0x563f9005c378) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9d5a565d-7ff7-497f-97d7-1c40c6fc36c2
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=27fd4acd-efb0-4afb-a081-4d6894954cc5
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 8ffc6b0c-1df2-46a6-98b3-27b178726e18
CSeq: 16115 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878708290 3878708290 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1100650013 cname:59c704b40aaadf8a
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:58:15.459           sound_port.c !EC suspended because of inactivity
10:58:18.097           pjsua_core.c  .TX 1451 bytes Request msg INVITE/cseq=16115 (tdta0x563f9005c378) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9d5a565d-7ff7-497f-97d7-1c40c6fc36c2
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=27fd4acd-efb0-4afb-a081-4d6894954cc5
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 8ffc6b0c-1df2-46a6-98b3-27b178726e18
CSeq: 16115 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878708290 3878708290 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1100650013 cname:59c704b40aaadf8a
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:58:26.098           pjsua_core.c  .TX 1451 bytes Request msg INVITE/cseq=16115 (tdta0x563f9005c378) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9d5a565d-7ff7-497f-97d7-1c40c6fc36c2
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=27fd4acd-efb0-4afb-a081-4d6894954cc5
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 8ffc6b0c-1df2-46a6-98b3-27b178726e18
CSeq: 16115 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878708290 3878708290 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1100650013 cname:59c704b40aaadf8a
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:58:42.098           pjsua_core.c  .TX 1451 bytes Request msg INVITE/cseq=16115 (tdta0x563f9005c378) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7001@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9d5a565d-7ff7-497f-97d7-1c40c6fc36c2
Max-Forwards: 70
From: <sip:172.16.17.135>;tag=27fd4acd-efb0-4afb-a081-4d6894954cc5
To: sip:7001@10x.xxx.xxx.xxx
Contact: <sip:172.16.17.135:5060;ob>
Call-ID: 8ffc6b0c-1df2-46a6-98b3-27b178726e18
CSeq: 16115 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   790

v=0
o=- 3878708290 3878708290 IN IP4 172.16.17.135
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 97 98 99 3 0 8 9 100 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 speex/16000
a=rtpmap:97 speex/8000
a=rtpmap:98 speex/32000
a=rtpmap:99 iLBC/8000
a=fmtp:99 mode=30
a=rtpmap:3 GSM/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:100 opus/48000/2
a=fmtp:100 useinbandfec=1
a=rtpmap:120 telephone-event/16000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/48000
a=fmtp:123 0-16
a=ssrc:1100650013 cname:59c704b40aaadf8a
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1

--end msg--
10:58:42.597            pjsua_app.c  ....Call 0 is DISCONNECTED [reason=408 (Request Timeout)]
10:58:42.597     pjsua_app_common.c  ....
  [DISCONNCTD] To: sip:7001@10x.xxx.xxx.xxx
    Call time: 00h:00m:00s, 1st res in 32001 ms, conn in 0ms

I can reach the sip server through soft phone.

I followed the instruction to deploy from here.

What is the caller account?
How do you register it to SIP server?

It is from the jibri instance. I have deployed an asterisk server remotely and tried to connect there.

  • Can you share the content of your dial-plan?

  • Which account do you use while connecting with soft-phone?

Your INVITE is not reaching the server, or the server is not replying.

Now I can call directly from pjsua and the call reaches my soft phone. But not through JItsi Invite.
sudo -u jibri pjsua sip:7001@10x.xxx.xxx.xxx --config-file=/etc/jitsi/jibri/pjsua.config

18:50:39.978      tsx0x555e2a2503d8  .Incoming Response msg 200/INVITE/cseq=21573 (rdata0x7fa260002318) in state Proceeding
18:50:39.978      tsx0x555e2a2503d8  ..State changed from Proceeding to Terminated, event=RX_MSG
18:50:39.978      dlg0x555e2a23f158  ...Received Response msg 200/INVITE/cseq=21573 (rdata0x7fa260002318)
18:50:39.978      dlg0x555e2a23f158  ....Route-set updated
18:50:39.978      dlg0x555e2a23f158  ....Route-set frozen
18:50:39.978      dlg0x555e2a23f158  ...Transaction tsx0x555e2a2503d8 state changed to Terminated
18:50:39.978            pjsua_app.c  .....Call 0 state changed to CONNECTING
18:50:39.978      inv0x555e2a23f158  ....Got SDP answer in Response msg 200/INVITE/cseq=21573 (rdata0x7fa260002318)
18:50:39.978      inv0x555e2a23f158  ....SDP negotiation done: Success
18:50:39.978           pjsua_call.c  .....Call 0: remote NAT type is 0 (Unknown)
18:50:39.978          pjsua_media.c  .....Call 0: updating media..
18:50:39.978          pjsua_media.c  .......Media stream call00:0 is destroyed
18:50:39.978            pjsua_aud.c  ......Audio channel update..
18:50:39.979                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7fa26000bd40, default_pt=0, ssrc=0x623691de
18:50:39.979                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7fa26000c3c0, default_pt=0, ssrc=0x623691de
18:50:39.979      udp0x555e2a240730  .......SO_RCVBUF set to 212992
18:50:39.979      udp0x555e2a240730  .......SO_SNDBUF set to 212992
18:50:39.979               stream.c  .......Stream strm0x7fa260008ed8 created
18:50:39.979     strm0x7fa260008ed8  .......Encoder stream started
18:50:39.979     strm0x7fa260008ed8  .......Decoder stream started
18:50:39.979             resample.c  .......resample created: high qualiy, large filter, in/out rate=8000/16000
18:50:39.979             resample.c  .......resample created: high qualiy, large filter, in/out rate=16000/8000
18:50:39.979          pjsua_media.c  ......Audio updated, stream #0: PCMU (sendrecv)
18:50:39.979          pjsua_media.c  .......Media stream call00:1 is destroyed
18:50:39.979            pjsua_vid.c  ......Video channel update..
18:50:39.985                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7fa260010444, default_pt=97, ssrc=0x328ac695
18:50:39.985   vstdec0x7fa26000f518  .......Decoding channel created 1280x720 I420<-H264 45/1(~45)fps
18:50:39.985                  rtp.c  .......pjmedia_rtp_session_init: ses=0x7fa26000f23c, default_pt=97, ssrc=0x328ac695
18:50:39.985   vstenc0x7fa26000f518  .......Encoding channel created 1280x720 I420->H264 30/1(~30)fps
18:50:39.985      udp0x555e2a2448e0  .......SO_RCVBUF set to 212992
18:50:39.985      udp0x555e2a2448e0  .......SO_SNDBUF set to 212992
18:50:39.985    vstrm0x7fa26000f518  .......Receive RTCP-FB PLI
18:50:39.985           vid_stream.c  .......Video stream vstrm0x7fa26000f518 created
18:50:39.985   vstenc0x7fa26000f518  .......Encoder stream started
18:50:39.985   vstdec0x7fa26000f518  .......Decoder stream started
18:50:39.985            pjsua_vid.c  .......Setting up RX..
18:50:39.985            pjsua_vid.c  ........Creating video window: type=stream, cap_id=-1, rend_id=706510000

Here is the pjsua.config:

--capture-dev=30
--playback-dev=29
--video
--vcapture-dev=1
--no-color
--log-level=5
--app-log-level=5
--auto-update-nat 0
--disable-stun
--no-tcp
--dis-codec GSM
--dis-codec H263
--dis-codec iLBC
--dis-codec G722
--dis-codec speex
--dis-codec pcmu
--dis-codec pcma
--dis-codec opus
--add-codec pcmu
--add-codec pcma
--add-codec speex
--add-codec G722
--add-codec opus
--no-vad
--ec-tail 0
--quality 10
--max-calls=1
--auto-keyframe=30
--no-stderr
--log-file=/var/log/jitsi/jibri/pjsua.log
--id=sip:7003@10x.xxx.xxx.xxx
--registrar=sip:10x.xxx.xxx.xxx
--realm=*
--username=7003
--password=xxxxxx

Asterisk Dial Plan:

[internal]
exten => 7001,1,Answer()
exten => 7001,2,Dial(PJSIP/7001,60)
exten => 7001,3,Hangup()

exten => 7003,1,Answer()
exten => 7003,2,Dial(PJSIP/7003,60)
exten => 7003,3,Hangup()

exten => 777,1,Progress()
exten => 777,2,Wait(1)
exten => 777,3,ConfBridge(1,myconferenceroom,admin_user)

exten => 666,1,Progress()
exten => 666,2,Wait(1)
exten => 666,3,ConfBridge(1,myconferenceroom,default_user)

7001
Current jibri log:

2022-11-30 01:05:35.117 INFO: [1] XmppApi.start#156: Connecting to xmpp environment on mydomain.com with config XmppEnvironmentConfig(name=xmpp environment, xmppServerHosts=[mydomain.com], xmppDomain=mydomain.com, baseUrl=null, controlLogin=XmppCredentials(domain=auth.mydomain.com, port=null, username=jibri-sip, password=*****), controlMuc=XmppMuc(domain=internal.auth.mydomain.com, roomName=JibriBrewery, nickname=jibri-sip), sipControlMuc=XmppMuc(domain=internal.auth.mydomain.com, roomName=TheSipBrewery, nickname=jibrisip), callLogin=XmppCredentials(domain=sipgateway.dghs.gov.bd, port=null, username=jibrisip, password=*****), stripFromRoomDomain=conference., usageTimeoutMins=0, trustAllXmppCerts=true, securityMode=null)
2022-11-30 01:05:35.118 INFO: [1] XmppApi.start#174: The trustAllXmppCerts config is enabled for this domain, all XMPP server provided certificates will be accepted
2022-11-30 01:05:35.146 INFO: [1] MainKt.main#152: Using port 2222 for HTTP API
2022-11-30 01:05:35.156 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient.initializeConnectAndJoin#279: Initializing a new MucClient for [ org.jitsi.xmpp.mucclient.MucClientConfiguration id=mydomain.com domain=auth.mydomain.com hostname=mydomain.com port=null username=jibri-sip mucs=[jibribrewery@internal.auth.mydomain.com, thesipbrewery@internal.auth.mydomain.com] mucNickname=jibri-sip disableCertificateVerification=true]
2022-11-30 01:05:35.181 WARNING: [33] MucClient.createXMPPTCPConnectionConfiguration#115: Disabling certificate verification!
2022-11-30 01:05:35.202 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient.initializeConnectAndJoin#341: Dispatching a thread to connect and login.
2022-11-30 01:05:35.360 FINE: [33] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: xmpp-connected:xmpp_server_host:mydomain.com
2022-11-30 01:05:35.360 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$2.connected#312: Connected.
2022-11-30 01:05:35.360 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient.lambda$getConnectAndLoginCallable$9#637: Logging in.
2022-11-30 01:05:35.439 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$2.authenticated#318: Authenticated, b=false
2022-11-30 01:05:35.456 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$MucWrapper.join#761: Joined MUC: jibribrewery@internal.auth.mydomain.com
2022-11-30 01:05:35.465 INFO: [33] [hostname=mydomain.com id=mydomain.com] MucClient$MucWrapper.join#761: Joined MUC: thesipbrewery@internal.auth.mydomain.com
2022-11-30 01:05:45.095 INFO: [43] XmppApi.handleJibriIq#236: Received JibriIq <iq xmlns='jabber:client' to='jibri-sip@auth.mydomain.com/f3FyX4SQh4a3' from='thesipbrewery@internal.auth.mydomain.com/focus' id='amlicmktc2lwQGF1dGguY29uZmVyZW5jZS5kZ2hzLmdvdi5iZC9mM0Z5WDRTUWg0YTMASElLVDktMTY0MQAg7L0zwfh3OQ==' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a2038abb86ed4c7db05eed4e5f0bf95c@conference.mydomain.com' displayname='testsip' sipaddress='7003@10x.xxx.xxx.xxx' session_id='kyrmpqnvqzuouozn'/></iq> from environment [MucClient id=mydomain.com hostname=mydomain.com]
2022-11-30 01:05:45.096 INFO: [43] XmppApi.handleStartJibriIq#268: Received start request, starting service
2022-11-30 01:05:45.099 INFO: [43] XmppApi.handleStartService#379: Parsed call url info: CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[])
2022-11-30 01:05:45.117 INFO: [43] JibriManager.startSipGateway#176: Starting a SIP gateway with params: ServiceParams(usageTimeoutMinutes=0, appData=null) SipGatewayServiceParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[]), email='', passcode=null, callStatsUsernameOverride=, displayName=), callLoginParams=XmppCredentials(domain=sipgateway.dghs.gov.bd, port=null, username=jibrisip, password=*****), sipClientParams=SipClientParams(sipAddress=7003@10x.xxx.xxx.xxx, displayName=testsip, autoAnswer=false, userName=null, password=null))
2022-11-30 01:05:47.538 INFO: [43] org.openqa.selenium.remote.ProtocolHandshake.createSession: Detected dialect: OSS
2022-11-30 01:05:47.557 FINE: [43] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: start:sip_gateway
2022-11-30 01:05:47.558 INFO: [43] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: IDLE -> BUSY
2022-11-30 01:05:47.559 FINE: [43] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 01:05:47.559 INFO: [43] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-30 01:05:47.561 INFO: [43] XmppApi.handleStartJibriIq#281: Sending 'pending' response to start IQ
2022-11-30 01:05:47.563 INFO: [58] AbstractPageObject.visit#32: Visiting url https://mydomain.com
2022-11-30 01:05:49.151 INFO: [58] AbstractPageObject.visit#38: Waited 1.585928423s for driver to load page
2022-11-30 01:05:49.199 INFO: [58] AbstractPageObject.visit#32: Visiting url https://mydomain.com/a2038abb86ed4c7db05eed4e5f0bf95c#config.iAmRecorder=true&config.iAmSipGateway=true&config.ignoreStartMuted=true&config.analytics.disabled=true&config.enableEmailInStats=false&config.p2p.enabled=false&config.prejoinPageEnabled=false&config.prejoinConfig.enabled=false&config.requireDisplayName=false&devices.videoInput="PJSUA"
2022-11-30 01:05:49.778 INFO: [58] AbstractPageObject.visit#38: Waited 579.025552ms for driver to load page
2022-11-30 01:05:49.805 FINE: [58] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-30 01:05:50.312 FINE: [58] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-30 01:05:51.325 INFO: [58] CallPage.visit#71: Waited 1.546450324s to join the conference
2022-11-30 01:05:51.329 INFO: [58] EmptyCallStatusCheck.<init>#26: Starting empty call check with a timeout of PT30M
2022-11-30 01:05:51.335 INFO: [58] LocalParticipantKickedStatusCheck.<init>#14: Starting local participant kicked out call check
2022-11-30 01:05:51.351 INFO: [58] JibriSelenium.onSeleniumStateChange#216: Transitioning from state Starting up to Running
2022-11-30 01:05:51.352 INFO: [58] SipGatewayJibriService$start$2.invoke#139: Selenium joined the call, starting pjsua
2022-11-30 01:05:51.353 INFO: [58] JibriSubprocess.launch#42: Starting pjsua with command /opt/jitsi/jibri/pjsua.sh --id=testsip <sip:jibri@127.0.0.1> sip:7003@10x.xxx.xxx.xxx ([/opt/jitsi/jibri/pjsua.sh, --id=testsip <sip:jibri@127.0.0.1>, sip:7003@10x.xxx.xxx.xxx])
2022-11-30 01:05:56.361 FINE: [20] ProcessStatePublisher$startProcessAliveChecks$1.invoke#86: Process pjsua hasn't written in 2 seconds, publishing periodic update
2022-11-30 01:05:56.369 INFO: [61] StatefulJibriService.onServiceStateChange#39: SIP gateway service transitioning from state Starting up to Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 134
2022-11-30 01:05:56.370 INFO: [61] XmppApi$createServiceStatusHandler$1.invoke#317: Current service had an error Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 134, sending error iq <iq xmlns='jabber:client' to='thesipbrewery@internal.auth.mydomain.com/focus' id='Z2E1S-8' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7003@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq>
2022-11-30 01:05:56.372 FINE: [61] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: stop:sip_gateway
2022-11-30 01:05:56.373 INFO: [61] JibriManager.stopService#260: Stopping the current service
2022-11-30 01:05:56.373 INFO: [61] JibriSubprocess.stop#75: Stopping pjsua process
2022-11-30 01:05:56.378 INFO: [61] JibriSubprocess.stop#89: pjsua exited with value 134
2022-11-30 01:05:56.378 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#338: Leaving call and quitting browser
2022-11-30 01:05:56.378 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#341: Recurring call status checks cancelled
2022-11-30 01:05:56.392 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#347: Got 10 log entries for type browser
2022-11-30 01:05:56.460 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#347: Got 411 log entries for type driver
2022-11-30 01:05:56.508 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#347: Got 0 log entries for type client
2022-11-30 01:05:56.508 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#356: Leaving web call
2022-11-30 01:05:56.579 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#363: Quitting chrome driver
2022-11-30 01:05:56.648 INFO: [61] JibriSelenium.leaveCallAndQuitBrowser#365: Chrome driver quit
2022-11-30 01:05:56.649 INFO: [61] JibriServiceFinalizeCommandRunner.doFinalize#44: Finalizing the jibri service operation using command [/opt/jitsi/jibri/finalize_sip.sh]
2022-11-30 01:05:56.651 INFO: [58] LoggingUtils$Companion$OutputLogger$1.invoke$lambda-0#42: Appending pjsua logs from /var/log/jitsi/jibri/pjsua.log, to /var/log/jitsi/jibri/pjsua_all.log
2022-11-30 01:05:56.653 INFO: [61] JibriServiceFinalizeCommandRunner.doFinalize#60: Finalize script finished with exit value 0
2022-11-30 01:05:56.655 INFO: [61] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: BUSY -> IDLE
2022-11-30 01:05:56.655 FINE: [61] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 01:05:56.655 INFO: [61] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections

When I invite from JItsi-meet, instantly it shows XX has been invited, then it shows XX has joined and within 2-3 seconds it shows XX has left. But the call was never made to the invitee.

The result of PeopleSearch:
[{“id”:“7001@10x.xxx.xxx.xxx”,“name”:“testsiproom”,“type”:“videosipgw”},{“id”:“666@10x.xxx.xxx.xxx”,“name”:“conference”,“type”:“videosipgw”}]

/opt/jitsi/jibri/pjsua.sh adds “--id” while running /usr/local/bin/pjsua.
Therefore it overwrites “-id” param which comes from pjsua.config

Can you try to change /opt/jitsi/jibri/pjsua.sh like the following:

#exec /usr/local/bin/pjsua --config-file /etc/jitsi/jibri/pjsua.config "$@" > /dev/null
exec /usr/local/bin/pjsua --config-file /etc/jitsi/jibri/pjsua.config "$2" > /dev/null

This is only for testing, not a solution…

Progress. Thank you, guys for giving me your valuable time. Now the call reaches the asterisk and participant can receive the call from soft phone. But still the participant left the room just after joining, though the participant is still on that call on soft phone.

Current jibri log:

2022-11-30 14:40:04.351 INFO: [254] XmppApi.handleJibriIq#236: Received JibriIq <iq xmlns='jabber:client' to='jibri-sip@auth.mydomain.com/f3FyX4SQh4a3' from='thesipbrewery@internal.auth.mydomain.com/focus' id='amlicmktc2lwQGF1dGguY29uZmVyZW5jZS5kZ2hzLmdvdi5iZC9mM0Z5WDRTUWg0YTMASElLVDktMTE1NjIAIOy9M8H4dzk=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a2038abb86ed4c7db05eed4e5f0bf95c@conference.mydomain.com' displayname='testsip' sipaddress='7003@10x.xxx.xxx.xxx' session_id='pshbshvdcctuplcp'/></iq> from environment [MucClient id=mydomain.com hostname=mydomain.com]
2022-11-30 14:40:04.351 INFO: [254] XmppApi.handleStartJibriIq#268: Received start request, starting service
2022-11-30 14:40:04.351 INFO: [254] XmppApi.handleStartService#379: Parsed call url info: CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[])
2022-11-30 14:40:04.351 INFO: [254] JibriManager.startSipGateway#176: Starting a SIP gateway with params: ServiceParams(usageTimeoutMinutes=0, appData=null) SipGatewayServiceParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[]), email='', passcode=null, callStatsUsernameOverride=, displayName=), callLoginParams=XmppCredentials(domain=sipgateway.dghs.gov.bd, port=null, username=jibrisip, password=*****), sipClientParams=SipClientParams(sipAddress=7003@10x.xxx.xxx.xxx, displayName=testsip, autoAnswer=false, userName=null, password=null))
2022-11-30 14:40:04.590 INFO: [254] org.openqa.selenium.remote.ProtocolHandshake.createSession: Detected dialect: OSS
2022-11-30 14:40:04.594 FINE: [254] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: start:sip_gateway
2022-11-30 14:40:04.594 INFO: [254] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: IDLE -> BUSY
2022-11-30 14:40:04.594 FINE: [254] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 14:40:04.594 INFO: [254] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-30 14:40:04.595 INFO: [254] XmppApi.handleStartJibriIq#281: Sending 'pending' response to start IQ
2022-11-30 14:40:04.596 INFO: [265] AbstractPageObject.visit#32: Visiting url https://mydomain.com
2022-11-30 14:40:06.063 INFO: [265] AbstractPageObject.visit#38: Waited 1.467471047s for driver to load page
2022-11-30 14:40:06.100 INFO: [265] AbstractPageObject.visit#32: Visiting url https://mydomain.com/a2038abb86ed4c7db05eed4e5f0bf95c#config.iAmRecorder=true&config.iAmSipGateway=true&config.ignoreStartMuted=true&config.analytics.disabled=true&config.enableEmailInStats=false&config.p2p.enabled=false&config.prejoinPageEnabled=false&config.prejoinConfig.enabled=false&config.requireDisplayName=false&devices.videoInput="PJSUA"
2022-11-30 14:40:06.671 INFO: [265] AbstractPageObject.visit#38: Waited 571.176643ms for driver to load page
2022-11-30 14:40:06.688 FINE: [265] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-30 14:40:07.194 FINE: [265] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-30 14:40:08.218 INFO: [265] CallPage.visit#71: Waited 1.545991044s to join the conference
2022-11-30 14:40:08.218 INFO: [265] EmptyCallStatusCheck.<init>#26: Starting empty call check with a timeout of PT30M
2022-11-30 14:40:08.218 INFO: [265] LocalParticipantKickedStatusCheck.<init>#14: Starting local participant kicked out call check
2022-11-30 14:40:08.230 INFO: [265] JibriSelenium.onSeleniumStateChange#216: Transitioning from state Starting up to Running
2022-11-30 14:40:08.230 INFO: [265] SipGatewayJibriService$start$2.invoke#139: Selenium joined the call, starting pjsua
2022-11-30 14:40:08.231 INFO: [265] JibriSubprocess.launch#42: Starting pjsua with command /opt/jitsi/jibri/pjsua.sh --id=testsip <sip:jibri@127.0.0.1> sip:7003@10x.xxx.xxx.xxx ([/opt/jitsi/jibri/pjsua.sh, --id=testsip <sip:jibri@127.0.0.1>, sip:7003@10x.xxx.xxx.xxx])
2022-11-30 14:40:13.232 FINE: [20] ProcessStatePublisher$startProcessAliveChecks$1.invoke#86: Process pjsua hasn't written in 2 seconds, publishing periodic update
2022-11-30 14:40:13.233 INFO: [269] StatefulJibriService.onServiceStateChange#39: SIP gateway service transitioning from state Starting up to Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 134
2022-11-30 14:40:13.233 INFO: [269] XmppApi$createServiceStatusHandler$1.invoke#317: Current service had an error Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 134, sending error iq <iq xmlns='jabber:client' to='thesipbrewery@internal.auth.mydomain.com/focus' id='Z2E1S-1660' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7003@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq>
2022-11-30 14:40:13.234 FINE: [269] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: stop:sip_gateway
2022-11-30 14:40:13.234 INFO: [269] JibriManager.stopService#260: Stopping the current service
2022-11-30 14:40:13.234 INFO: [269] JibriSubprocess.stop#75: Stopping pjsua process
2022-11-30 14:40:13.235 INFO: [269] JibriSubprocess.stop#89: pjsua exited with value 134
2022-11-30 14:40:13.235 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#338: Leaving call and quitting browser
2022-11-30 14:40:13.235 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#341: Recurring call status checks cancelled
2022-11-30 14:40:13.249 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#347: Got 10 log entries for type browser
2022-11-30 14:40:13.273 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#347: Got 415 log entries for type driver
2022-11-30 14:40:13.297 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#347: Got 0 log entries for type client
2022-11-30 14:40:13.298 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#356: Leaving web call
2022-11-30 14:40:13.368 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#363: Quitting chrome driver
2022-11-30 14:40:13.436 INFO: [269] JibriSelenium.leaveCallAndQuitBrowser#365: Chrome driver quit
2022-11-30 14:40:13.436 INFO: [269] JibriServiceFinalizeCommandRunner.doFinalize#44: Finalizing the jibri service operation using command [/opt/jitsi/jibri/finalize_sip.sh]
2022-11-30 14:40:13.439 INFO: [265] LoggingUtils$Companion$OutputLogger$1.invoke$lambda-0#42: Appending pjsua logs from /var/log/jitsi/jibri/pjsua.log, to /var/log/jitsi/jibri/pjsua_all.log
2022-11-30 14:40:13.439 INFO: [269] JibriServiceFinalizeCommandRunner.doFinalize#60: Finalize script finished with exit value 0
2022-11-30 14:40:13.440 INFO: [269] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: BUSY -> IDLE
2022-11-30 14:40:13.440 FINE: [269] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 14:40:13.440 INFO: [269] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-30 14:40:33.027 INFO: [256] XmppApi.handleJibriIq#236: Received JibriIq <iq xmlns='jabber:client' to='jibri-sip@auth.mydomain.com/f3FyX4SQh4a3' from='thesipbrewery@internal.auth.mydomain.com/focus' id='amlicmktc2lwQGF1dGguY29uZmVyZW5jZS5kZ2hzLmdvdi5iZC9mM0Z5WDRTUWg0YTMASElLVDktMTE1ODUAIOy9M8H4dzk=' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' action='start' recording_mode='file' room='a2038abb86ed4c7db05eed4e5f0bf95c@conference.mydomain.com' displayname='testsip' sipaddress='7003@10x.xxx.xxx.xxx' session_id='bbcamjzteqrztzse'/></iq> from environment [MucClient id=mydomain.com hostname=mydomain.com]
2022-11-30 14:40:33.027 INFO: [256] XmppApi.handleStartJibriIq#268: Received start request, starting service
2022-11-30 14:40:33.027 INFO: [256] XmppApi.handleStartService#379: Parsed call url info: CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[])
2022-11-30 14:40:33.027 INFO: [256] JibriManager.startSipGateway#176: Starting a SIP gateway with params: ServiceParams(usageTimeoutMinutes=0, appData=null) SipGatewayServiceParams(callParams=CallParams(callUrlInfo=CallUrlInfo(baseUrl=https://mydomain.com, callName=a2038abb86ed4c7db05eed4e5f0bf95c, urlParams=[]), email='', passcode=null, callStatsUsernameOverride=, displayName=), callLoginParams=XmppCredentials(domain=sipgateway.dghs.gov.bd, port=null, username=jibrisip, password=*****), sipClientParams=SipClientParams(sipAddress=7003@10x.xxx.xxx.xxx, displayName=testsip, autoAnswer=false, userName=null, password=null))
2022-11-30 14:40:33.270 INFO: [256] org.openqa.selenium.remote.ProtocolHandshake.createSession: Detected dialect: OSS
2022-11-30 14:40:33.274 FINE: [256] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: start:sip_gateway
2022-11-30 14:40:33.274 INFO: [256] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: IDLE -> BUSY
2022-11-30 14:40:33.274 FINE: [256] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 14:40:33.274 INFO: [256] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=BUSY, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections
2022-11-30 14:40:33.275 INFO: [256] XmppApi.handleStartJibriIq#281: Sending 'pending' response to start IQ
2022-11-30 14:40:33.275 INFO: [265] AbstractPageObject.visit#32: Visiting url https://mydomain.com
2022-11-30 14:40:34.583 FINE: [20] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 14:40:34.672 INFO: [265] AbstractPageObject.visit#38: Waited 1.396617711s for driver to load page
2022-11-30 14:40:34.709 INFO: [265] AbstractPageObject.visit#32: Visiting url https://mydomain.com/a2038abb86ed4c7db05eed4e5f0bf95c#config.iAmRecorder=true&config.iAmSipGateway=true&config.ignoreStartMuted=true&config.analytics.disabled=true&config.enableEmailInStats=false&config.p2p.enabled=false&config.prejoinPageEnabled=false&config.prejoinConfig.enabled=false&config.requireDisplayName=false&devices.videoInput="PJSUA"
2022-11-30 14:40:35.262 INFO: [265] AbstractPageObject.visit#38: Waited 553.155424ms for driver to load page
2022-11-30 14:40:35.277 FINE: [265] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-30 14:40:35.787 FINE: [265] CallPage.visit$lambda-2$lambda-1#58: Not joined yet: Cannot read properties of undefined (reading 'isJoined')
2022-11-30 14:40:36.816 INFO: [265] CallPage.visit#71: Waited 1.553960749s to join the conference
2022-11-30 14:40:36.817 INFO: [265] EmptyCallStatusCheck.<init>#26: Starting empty call check with a timeout of PT30M
2022-11-30 14:40:36.817 INFO: [265] LocalParticipantKickedStatusCheck.<init>#14: Starting local participant kicked out call check
2022-11-30 14:40:36.831 INFO: [265] JibriSelenium.onSeleniumStateChange#216: Transitioning from state Starting up to Running
2022-11-30 14:40:36.831 INFO: [265] SipGatewayJibriService$start$2.invoke#139: Selenium joined the call, starting pjsua
2022-11-30 14:40:36.831 INFO: [265] JibriSubprocess.launch#42: Starting pjsua with command /opt/jitsi/jibri/pjsua.sh --id=testsip <sip:jibri@127.0.0.1> sip:7003@10x.xxx.xxx.xxx ([/opt/jitsi/jibri/pjsua.sh, --id=testsip <sip:jibri@127.0.0.1>, sip:7003@10x.xxx.xxx.xxx])
2022-11-30 14:40:41.832 FINE: [20] ProcessStatePublisher$startProcessAliveChecks$1.invoke#86: Process pjsua hasn't written in 2 seconds, publishing periodic update
2022-11-30 14:40:41.833 INFO: [270] StatefulJibriService.onServiceStateChange#39: SIP gateway service transitioning from state Starting up to Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 139
2022-11-30 14:40:41.833 INFO: [270] XmppApi$createServiceStatusHandler$1.invoke#317: Current service had an error Error: PjsuaExitedPrematurely SESSION Pjsua exited with code 139, sending error iq <iq xmlns='jabber:client' to='thesipbrewery@internal.auth.mydomain.com/focus' id='Z2E1S-1664' type='set'><jibri xmlns='http://jitsi.org/protocol/jibri' status='off' sipaddress='7003@10x.xxx.xxx.xxx' failure_reason='error' should_retry='true'/></iq>
2022-11-30 14:40:41.833 FINE: [270] JibriStatsDClient.incrementCounter#38: Incrementing statsd counter: stop:sip_gateway
2022-11-30 14:40:41.833 INFO: [270] JibriManager.stopService#260: Stopping the current service
2022-11-30 14:40:41.833 INFO: [270] JibriSubprocess.stop#75: Stopping pjsua process
2022-11-30 14:40:41.834 INFO: [270] JibriSubprocess.stop#89: pjsua exited with value 139
2022-11-30 14:40:41.834 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#338: Leaving call and quitting browser
2022-11-30 14:40:41.834 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#341: Recurring call status checks cancelled
2022-11-30 14:40:41.847 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#347: Got 12 log entries for type browser
2022-11-30 14:40:41.869 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#347: Got 420 log entries for type driver
2022-11-30 14:40:41.893 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#347: Got 0 log entries for type client
2022-11-30 14:40:41.893 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#356: Leaving web call
2022-11-30 14:40:41.960 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#363: Quitting chrome driver
2022-11-30 14:40:42.028 INFO: [270] JibriSelenium.leaveCallAndQuitBrowser#365: Chrome driver quit
2022-11-30 14:40:42.028 INFO: [270] JibriServiceFinalizeCommandRunner.doFinalize#44: Finalizing the jibri service operation using command [/opt/jitsi/jibri/finalize_sip.sh]
2022-11-30 14:40:42.030 INFO: [265] LoggingUtils$Companion$OutputLogger$1.invoke$lambda-0#42: Appending pjsua logs from /var/log/jitsi/jibri/pjsua.log, to /var/log/jitsi/jibri/pjsua_all.log
2022-11-30 14:40:42.031 INFO: [270] JibriServiceFinalizeCommandRunner.doFinalize#60: Finalize script finished with exit value 0
2022-11-30 14:40:42.031 INFO: [270] JibriStatusManager$special$$inlined$observable$1.afterChange#72: Busy status has changed: BUSY -> IDLE
2022-11-30 14:40:42.032 FINE: [270] WebhookClient$updateStatus$1.invokeSuspend#109: Updating 0 subscribers of status
2022-11-30 14:40:42.032 INFO: [270] XmppApi.updatePresence#209: Jibri reports its status is now JibriStatus(busyStatus=IDLE, health=OverallHealth(healthStatus=HEALTHY, details={})), publishing presence to connections

/var/log/jitsi/jibri/pjsua_all.log:

14:40:08.267         sip_endpoint.c  .Module "mod-pjsua-log" registered
14:40:08.268         sip_endpoint.c  .Module "mod-tsx-layer" registered
14:40:08.268         sip_endpoint.c  .Module "mod-stateful-util" registered
14:40:08.268         sip_endpoint.c  .Module "mod-ua" registered
14:40:08.268         sip_endpoint.c  .Module "mod-100rel" registered
14:40:08.268         sip_endpoint.c  .Module "mod-pjsua" registered
14:40:08.268         sip_endpoint.c  .Module "mod-invite" registered
14:40:08.275             alsa_dev.c  ..Added sound device surround21
14:40:08.275             alsa_dev.c  ..Added sound device surround40
14:40:08.275             alsa_dev.c  ..Added sound device surround41
14:40:08.276             alsa_dev.c  ..Added sound device surround50
14:40:08.276             alsa_dev.c  ..Added sound device surround51
14:40:08.276             alsa_dev.c  ..Added sound device surround71
14:40:08.277             alsa_dev.c  ..Added sound device amix
14:40:08.277             alsa_dev.c  ..Added sound device asnoop
14:40:08.277             alsa_dev.c  ..Added sound device aduplex
14:40:08.277             alsa_dev.c  ..Added sound device bmix
14:40:08.278             alsa_dev.c  ..Added sound device bsnoop
14:40:08.278             alsa_dev.c  ..Added sound device bduplex
14:40:08.279             alsa_dev.c  ..Added sound device pjsua
14:40:08.279             alsa_dev.c  ..Added sound device default
14:40:08.280             alsa_dev.c  ..Added sound device sysdefault:CARD=Loopback
14:40:08.280             alsa_dev.c  ..Added sound device front:CARD=Loopback,DEV=0
14:40:08.281             alsa_dev.c  ..Added sound device surround21:CARD=Loopback,DEV=0
14:40:08.281             alsa_dev.c  ..Added sound device surround40:CARD=Loopback,DEV=0
14:40:08.281             alsa_dev.c  ..Added sound device surround41:CARD=Loopback,DEV=0
14:40:08.281             alsa_dev.c  ..Added sound device surround50:CARD=Loopback,DEV=0
14:40:08.282             alsa_dev.c  ..Added sound device surround51:CARD=Loopback,DEV=0
14:40:08.282             alsa_dev.c  ..Added sound device surround71:CARD=Loopback,DEV=0
14:40:08.282             alsa_dev.c  ..Added sound device dmix:CARD=Loopback,DEV=0
14:40:08.283             alsa_dev.c  ..Added sound device dmix:CARD=Loopback,DEV=1
14:40:08.283             alsa_dev.c  ..Added sound device dsnoop:CARD=Loopback,DEV=0
14:40:08.284             alsa_dev.c  ..Added sound device dsnoop:CARD=Loopback,DEV=1
14:40:08.284             alsa_dev.c  ..Added sound device hw:CARD=Loopback,DEV=0
14:40:08.284             alsa_dev.c  ..Added sound device hw:CARD=Loopback,DEV=1
14:40:08.284             alsa_dev.c  ..Added sound device plughw:CARD=Loopback,DEV=0
14:40:08.284             alsa_dev.c  ..Added sound device plughw:CARD=Loopback,DEV=1
14:40:08.285             alsa_dev.c  ..Added sound device sysdefault:CARD=Loopback_1
14:40:08.285             alsa_dev.c  ..Added sound device front:CARD=Loopback_1,DEV=0
14:40:08.285             alsa_dev.c  ..ALSA driver found 32 devices
14:40:08.285             alsa_dev.c  ..ALSA initialized
14:40:08.285                  pjlib  ..select() I/O Queue created (0x55bd0eecbcf8)
14:40:08.285           conference.c  ..Creating conference bridge with 254 ports
14:40:08.285           Master/sound  ..Using delay buffer with WSOLA.
14:40:08.286            pjsua_vid.c  ..Initializing video subsystem..
14:40:08.286             vid_conf.c  ...Created video conference bridge with 32 ports
14:40:08.287                  vpx.c  ...VPX codec initialized
14:40:08.287             v4l2_dev.c  ...Video4Linux2 has 0 devices
14:40:08.287              sdl_dev.c !SDL_Init() error: No available video device
14:40:08.287         colorbar_dev.c !...Colorbar video src initialized with 2 device(s):
14:40:08.287         colorbar_dev.c  ... 0: Colorbar generator
14:40:08.287         colorbar_dev.c  ... 1: Colorbar-active
14:40:08.287         sip_endpoint.c  .Module "mod-evsub" registered
14:40:08.287         sip_endpoint.c  .Module "mod-presence" registered
14:40:08.287                evsub.c  .Event pkg "presence" registered by mod-presence
14:40:08.287         sip_endpoint.c  .Module "mod-mwi" registered
14:40:08.287                evsub.c  .Event pkg "message-summary" registered by mod-mwi
14:40:08.287         sip_endpoint.c  .Module "mod-refer" registered
14:40:08.287                evsub.c  .Event pkg "refer" registered by mod-refer
14:40:08.287         sip_endpoint.c  .Module "mod-pjsua-pres" registered
14:40:08.287         sip_endpoint.c  .Module "mod-pjsua-im" registered
14:40:08.287         sip_endpoint.c  .Module "mod-pjsua-options" registered
14:40:08.287           pjsua_core.c  .1 SIP worker threads created
14:40:08.287           pjsua_core.c  .pjsua version 2.10-jitsi3 for Linux-5.4.0.132/x86_64/glibc-2.31 initialized
14:40:08.287           pjsua_core.c  .PJSUA state changed: CREATED --> INIT
14:40:08.288         sip_endpoint.c  Module "mod-default-handler" registered
14:40:08.288           pjsua_core.c  SIP UDP socket reachable at 172.16.17.135:5060
14:40:08.288      udp0x55bd0eeb7f10  SIP UDP transport started, published address is 172.16.17.135:5060
14:40:08.288            pjsua_acc.c  Adding account: id=<sip:172.16.17.135:5060>
14:40:08.288            pjsua_acc.c  .Account <sip:172.16.17.135:5060> added with id 0
14:40:08.288            pjsua_acc.c  Modifying account 0
14:40:08.288            pjsua_acc.c  Acc 0: setting online status to 1..
14:40:08.288            pjsua_acc.c  Adding account: id=sip:7001@10x.xxx.xxx.xxx
14:40:08.288            pjsua_acc.c  .Account sip:7001@10x.xxx.xxx.xxx added with id 1
14:40:08.288            pjsua_acc.c  .Acc 1: setting registration..
14:40:08.288               endpoint  ..Request msg REGISTER/cseq=21181 (tdta0x55bd0eebf758) created.
14:40:08.288      tsx0x55bd0eec1718  ...Transaction created for Request msg REGISTER/cseq=21182 (tdta0x55bd0eebf758)
14:40:08.288      tsx0x55bd0eec1718  ..Sending Request msg REGISTER/cseq=21182 (tdta0x55bd0eebf758) in state Null
14:40:08.288          sip_resolve.c  ...Target '10x.xxx.xxx.xxx:0' type=Unspecified resolved to '10x.xxx.xxx.xxx:5060' type=UDP (UDP transport)
14:40:08.288           pjsua_core.c  ...TX 571 bytes Request msg REGISTER/cseq=21182 (tdta0x55bd0eebf758) to UDP 10x.xxx.xxx.xxx:5060:
REGISTER sip:10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPjf54c2791-973a-4b0e-aef7-dd2c4ea82104
Max-Forwards: 70
From: <sip:7001@10x.xxx.xxx.xxx>;tag=bc85c4b5-f986-4111-9a2a-d7bdb50367b9
To: <sip:7001@10x.xxx.xxx.xxx>
Call-ID: 4d8f62b6-a963-4ad2-a46d-9bec210af15f
CSeq: 21182 REGISTER
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Contact: <sip:7001@172.16.17.135:5060;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length:  0


--end msg--
14:40:08.288      tsx0x55bd0eec1718  ...State changed from Null to Calling, event=TX_MSG
14:40:08.288            pjsua_acc.c  ..Acc 1: Registration sent
14:40:08.288            pjsua_acc.c  Acc 1: setting online status to 1..
14:40:08.288           pjsua_pres.c  Adding buddy: sip:7003@10x.xxx.xxx.xxx
14:40:08.288           pjsua_pres.c  .Buddy 0 added.
14:40:08.288           pjsua_pres.c  ..Buddy 0: updating presence..
14:40:08.288            pjsua_aud.c  Set sound device: capture=30, playback=29
14:40:08.288            pjsua_app.c  .Turning sound device 30 29 ON
14:40:08.288            pjsua_aud.c  .Opening sound device (speaker + mic) PCM@16000/1/20ms
14:40:08.288             alsa_dev.c  ..open_playback: Open playback device 'plughw:CARD=Loopback,DEV=1'
14:40:08.288             alsa_dev.c  ..Opened device alsa(plughw:CARD=Loopback,DEV=1) for playing, sample rate=16000, ch=1, bits=16, period size=320 frames, latency=140 ms
14:40:08.288             alsa_dev.c  ..open_capture: Open capture device 'sysdefault:CARD=Loopback_1'
14:40:08.289             alsa_dev.c  ..Opened device alsa(sysdefault:CARD=Loopback_1) for capture, sample rate=16000, ch=1, bits=16, period size=341 frames, latency=106 ms
14:40:08.289           pjsua_core.c  PJSUA state changed: INIT --> STARTING
14:40:08.289         sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
14:40:08.289           pjsua_core.c !.PJSUA state changed: STARTING --> RUNNING
14:40:08.289                 main.c  Ready: Success
14:40:08.289             alsa_dev.c !ca_thread_func(25802): Set thread priority for audio capture thread.
14:40:08.289           pjsua_call.c  Making call with acc #1 to sip:7003@10x.xxx.xxx.xxx
14:40:08.289             alsa_dev.c !Unable to increase thread priority, root access needed.
14:40:08.289      dlg0x55bd0ef12b48 !.UAC dialog created
14:40:08.289      dlg0x55bd0ef12b48  ..Session count inc to 2 by mod-pjsua
14:40:08.289          pjsua_media.c  .Call 0: initializing media..
14:40:08.289          pjsua_media.c  ..RTP socket reachable at 172.16.17.135:4000
14:40:08.289          pjsua_media.c  ..RTCP socket reachable at 172.16.17.135:4001
14:40:08.289     srtp0x55bd0ee9b2d0  ..SRTP keying SDES created
14:40:08.289          pjsua_media.c  ..RTP socket reachable at 172.16.17.135:4002
14:40:08.289          pjsua_media.c  ..RTCP socket reachable at 172.16.17.135:4003
14:40:08.289     srtp0x55bd0ef1aac0  ..SRTP keying SDES created
14:40:08.289          pjsua_media.c  ..Media index 0 selected for audio call 0
14:40:08.289          pjsua_media.c  ..Call 0: media transport initialization complete: Success
14:40:08.289      dlg0x55bd0ef12b48  ..Session count dec to 2 by mod-pjsua
14:40:08.289      dlg0x55bd0ef12b48  .Module mod-invite added as dialog usage, data=0x55bd0ef1d6d8
14:40:08.289      dlg0x55bd0ef12b48  ..Session count inc to 4 by mod-invite
14:40:08.289      dlg0x55bd0ef12b48  .Module mod-100rel added as dialog usage, data=0x55bd0ef204c8
14:40:08.289      dlg0x55bd0ef12b48  .100rel module attached
14:40:08.289      inv0x55bd0ef12b48  .UAC invite session created for dialog dlg0x55bd0ef12b48
14:40:08.289               endpoint  .Request msg INVITE/cseq=3566 (tdta0x55bd0ef20828) created.
14:40:08.289      inv0x55bd0ef12b48  ..Sending Request msg INVITE/cseq=3566 (tdta0x55bd0ef20828)
14:40:08.289      dlg0x55bd0ef12b48  ...Sending Request msg INVITE/cseq=3566 (tdta0x55bd0ef20828)
14:40:08.289      tsx0x55bd0ef23798  ....Transaction created for Request msg INVITE/cseq=3565 (tdta0x55bd0ef20828)
14:40:08.289      tsx0x55bd0ef23798  ...Sending Request msg INVITE/cseq=3565 (tdta0x55bd0ef20828) in state Null
14:40:08.289          sip_resolve.c  ....Target '10x.xxx.xxx.xxx:0' type=Unspecified resolved to '10x.xxx.xxx.xxx:5060' type=UDP (UDP transport)
14:40:08.289               endpoint  ....Request msg INVITE/cseq=3565 (tdta0x55bd0ef20828) exceeds UDP size threshold (1300), sending with TCP
14:40:08.289      tsx0x55bd0ef23798  ....Temporary failure in sending Request msg INVITE/cseq=3565 (tdta0x55bd0ef20828), will try next server: Unsupported transport (PJSIP_EUNSUPTRANSPORT)
14:40:08.289           pjsua_core.c  ....TX 1664 bytes Request msg INVITE/cseq=3565 (tdta0x55bd0ef20828) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7003@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj9f1c1910-c9eb-420e-a468-bc1f7a665a37
Max-Forwards: 70
From: sip:7001@10x.xxx.xxx.xxx;tag=3f8c8fbd-de63-41ae-b775-91b60436dcad
To: sip:7003@10x.xxx.xxx.xxx
Contact: <sip:7001@172.16.17.135:5060;ob>
Call-ID: ccfc987e-664d-4b4c-b4f2-bea98ff3d5e0
CSeq: 3565 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   994

v=0
o=- 3878786408 3878786408 IN IP4 172.16.17.135
s=pjmedia
b=AS:2742
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 9 97 98 99 8 0 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=rtpmap:9 G722/8000
a=rtpmap:97 speex/32000
a=rtpmap:98 speex/16000
a=rtpmap:99 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:120 telephone-event/48000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/16000
a=fmtp:123 0-16
a=ssrc:441678204 cname:2fc134ca678a87a0
m=video 4002 RTP/AVP 97 102
c=IN IP4 172.16.17.135
b=TIAS:2500000
a=rtcp:4003 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:97 H264/90000
a=fmtp:97 profile-level-id=42801f; packetization-mode=1
a=rtpmap:102 VP8/90000
a=fmtp:102 max-fr=30; max-fs=580
a=ssrc:978534435 cname:2fc134ca678a87a0
a=rtcp-fb:* nack pli

--end msg--
14:40:08.289      tsx0x55bd0ef23798  ....State changed from Null to Calling, event=TX_MSG
14:40:08.289      dlg0x55bd0ef12b48  .....Transaction tsx0x55bd0ef23798 state changed to Calling
14:40:08.289            pjsua_app.c  .......Call 0 state changed to CALLING
14:40:08.298         sip_endpoint.c !Processing incoming message: Response msg 200/REGISTER/cseq=21182 (rdata0x55bd0eeb9998)
14:40:08.298           pjsua_core.c  .RX 539 bytes Response msg 200/REGISTER/cseq=21182 (rdata0x55bd0eeb9998) from UDP 10x.xxx.xxx.xxx:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.17.135:5060;rport=5060;received=103.247.238.6;branch=z9hG4bKPjf54c2791-973a-4b0e-aef7-dd2c4ea82104
Call-ID: 4d8f62b6-a963-4ad2-a46d-9bec210af15f
From: <sip:7001@10x.xxx.xxx.xxx>;tag=bc85c4b5-f986-4111-9a2a-d7bdb50367b9
To: <sip:7001@10x.xxx.xxx.xxx>;tag=z9hG4bKPjf54c2791-973a-4b0e-aef7-dd2c4ea82104
CSeq: 21182 REGISTER
Date: Wed, 30 Nov 2022 08:40:08 GMT
Contact: <sip:7001@10x.xxx.xxx.xxx:5060;ob>;expires=299
Expires: 300
Server: Asterisk PBX 16.2.1~dfsg-2ubuntu1
Content-Length:  0


--end msg--
14:40:08.298      tsx0x55bd0eec1718  .Incoming Response msg 200/REGISTER/cseq=21182 (rdata0x55bd0eeb9998) in state Calling
14:40:08.298      tsx0x55bd0eec1718  ..State changed from Calling to Completed, event=RX_MSG
14:40:08.298            pjsua_acc.c  ....SIP outbound status for acc 1 is not active
14:40:08.298            pjsua_acc.c  ....sip:7001@10x.xxx.xxx.xxx: registration success, status=200 (OK), will re-register in 299 seconds
14:40:08.298            pjsua_acc.c  ....Keep-alive timer started for acc 1, destination:10x.xxx.xxx.xxx:5060, interval:15s
14:40:08.298         sip_endpoint.c  Processing incoming message: Response msg 100/INVITE/cseq=3565 (rdata0x7f8058002688)
14:40:08.298           pjsua_core.c  .RX 382 bytes Response msg 100/INVITE/cseq=3565 (rdata0x7f8058002688) from UDP 10x.xxx.xxx.xxx:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.17.135:5060;rport=5060;received=103.247.238.6;branch=z9hG4bKPj9f1c1910-c9eb-420e-a468-bc1f7a665a37
Call-ID: ccfc987e-664d-4b4c-b4f2-bea98ff3d5e0
From: <sip:7001@10x.xxx.xxx.xxx>;tag=3f8c8fbd-de63-41ae-b775-91b60436dcad
To: <sip:7003@10x.xxx.xxx.xxx>
CSeq: 3565 INVITE
Server: Asterisk PBX 16.2.1~dfsg-2ubuntu1
Content-Length:  0


--end msg--
14:40:08.298      tsx0x55bd0ef23798  .Incoming Response msg 100/INVITE/cseq=3565 (rdata0x7f8058002688) in state Calling
14:40:08.298      tsx0x55bd0ef23798  ..State changed from Calling to Proceeding, event=RX_MSG
14:40:08.298      dlg0x55bd0ef12b48  ...Received Response msg 100/INVITE/cseq=3565 (rdata0x7f8058002688)
14:40:08.298      dlg0x55bd0ef12b48  ...Transaction tsx0x55bd0ef23798 state changed to Proceeding
14:40:08.298         sip_endpoint.c  Processing incoming message: Response msg 200/INVITE/cseq=3565 (rdata0x7f8058002688)
14:40:08.298           pjsua_core.c  .RX 1087 bytes Response msg 200/INVITE/cseq=3565 (rdata0x7f8058002688) from UDP 10x.xxx.xxx.xxx:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.17.135:5060;rport=5060;received=103.247.238.6;branch=z9hG4bKPj9f1c1910-c9eb-420e-a468-bc1f7a665a37
Call-ID: ccfc987e-664d-4b4c-b4f2-bea98ff3d5e0
From: <sip:7001@10x.xxx.xxx.xxx>;tag=3f8c8fbd-de63-41ae-b775-91b60436dcad
To: <sip:7003@10x.xxx.xxx.xxx>;tag=4dba6fd4-8263-4b2d-8b2a-a4119af61529
CSeq: 3565 INVITE
Server: Asterisk PBX 16.2.1~dfsg-2ubuntu1
Contact: <sip:10x.xxx.xxx.xxx:5060>
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER
Supported: 100rel, timer, replaces, 14:40:36.871         sip_endpoint.c  .Module "mod-pjsua-log" registered
14:40:36.871         sip_endpoint.c  .Module "mod-tsx-layer" registered
14:40:36.871         sip_endpoint.c  .Module "mod-stateful-util" registered
14:40:36.871         sip_endpoint.c  .Module "mod-ua" registered
14:40:36.871         sip_endpoint.c  .Module "mod-100rel" registered
14:40:36.871         sip_endpoint.c  .Module "mod-pjsua" registered
14:40:36.871         sip_endpoint.c  .Module "mod-invite" registered
14:40:36.878             alsa_dev.c  ..Added sound device surround21
14:40:36.879             alsa_dev.c  ..Added sound device surround40
14:40:36.879             alsa_dev.c  ..Added sound device surround41
14:40:36.879             alsa_dev.c  ..Added sound device surround50
14:40:36.879             alsa_dev.c  ..Added sound device surround51
14:40:36.880             alsa_dev.c  ..Added sound device surround71
14:40:36.880             alsa_dev.c  ..Added sound device amix
14:40:36.880             alsa_dev.c  ..Added sound device asnoop
14:40:36.880             alsa_dev.c  ..Added sound device aduplex
14:40:36.880             alsa_dev.c  ..Added sound device bmix
14:40:36.881             alsa_dev.c  ..Added sound device bsnoop
14:40:36.881             alsa_dev.c  ..Added sound device bduplex
14:40:36.881             alsa_dev.c  ..Added sound device pjsua
14:40:36.882             alsa_dev.c  ..Added sound device default
14:40:36.882             alsa_dev.c  ..Added sound device sysdefault:CARD=Loopback
14:40:36.883             alsa_dev.c  ..Added sound device front:CARD=Loopback,DEV=0
14:40:36.883             alsa_dev.c  ..Added sound device surround21:CARD=Loopback,DEV=0
14:40:36.883             alsa_dev.c  ..Added sound device surround40:CARD=Loopback,DEV=0
14:40:36.883             alsa_dev.c  ..Added sound device surround41:CARD=Loopback,DEV=0
14:40:36.883             alsa_dev.c  ..Added sound device surround50:CARD=Loopback,DEV=0
14:40:36.884             alsa_dev.c  ..Added sound device surround51:CARD=Loopback,DEV=0
14:40:36.884             alsa_dev.c  ..Added sound device surround71:CARD=Loopback,DEV=0
14:40:36.884             alsa_dev.c  ..Added sound device dmix:CARD=Loopback,DEV=0
14:40:36.885             alsa_dev.c  ..Added sound device dmix:CARD=Loopback,DEV=1
14:40:36.885             alsa_dev.c  ..Added sound device dsnoop:CARD=Loopback,DEV=0
14:40:36.886             alsa_dev.c  ..Added sound device dsnoop:CARD=Loopback,DEV=1
14:40:36.886             alsa_dev.c  ..Added sound device hw:CARD=Loopback,DEV=0
14:40:36.886             alsa_dev.c  ..Added sound device hw:CARD=Loopback,DEV=1
14:40:36.886             alsa_dev.c  ..Added sound device plughw:CARD=Loopback,DEV=0
14:40:36.886             alsa_dev.c  ..Added sound device plughw:CARD=Loopback,DEV=1
14:40:36.887             alsa_dev.c  ..Added sound device sysdefault:CARD=Loopback_1
14:40:36.887             alsa_dev.c  ..Added sound device front:CARD=Loopback_1,DEV=0
14:40:36.888             alsa_dev.c  ..ALSA driver found 32 devices
14:40:36.888             alsa_dev.c  ..ALSA initialized
14:40:36.888                  pjlib  ..select() I/O Queue created (0x5558738fecf8)
14:40:36.888           conference.c  ..Creating conference bridge with 254 ports
14:40:36.888           Master/sound  ..Using delay buffer with WSOLA.
14:40:36.889            pjsua_vid.c  ..Initializing video subsystem..
14:40:36.889             vid_conf.c  ...Created video conference bridge with 32 ports
14:40:36.889                  vpx.c  ...VPX codec initialized
14:40:36.889             v4l2_dev.c  ...Video4Linux2 has 0 devices
14:40:36.889              sdl_dev.c !SDL_Init() error: No available video device
14:40:36.890         colorbar_dev.c !...Colorbar video src initialized with 2 device(s):
14:40:36.890         colorbar_dev.c  ... 0: Colorbar generator
14:40:36.890         colorbar_dev.c  ... 1: Colorbar-active
14:40:36.890         sip_endpoint.c  .Module "mod-evsub" registered
14:40:36.890         sip_endpoint.c  .Module "mod-presence" registered
14:40:36.890                evsub.c  .Event pkg "presence" registered by mod-presence
14:40:36.890         sip_endpoint.c  .Module "mod-mwi" registered
14:40:36.890                evsub.c  .Event pkg "message-summary" registered by mod-mwi
14:40:36.890         sip_endpoint.c  .Module "mod-refer" registered
14:40:36.890                evsub.c  .Event pkg "refer" registered by mod-refer
14:40:36.890         sip_endpoint.c  .Module "mod-pjsua-pres" registered
14:40:36.890         sip_endpoint.c  .Module "mod-pjsua-im" registered
14:40:36.890         sip_endpoint.c  .Module "mod-pjsua-options" registered
14:40:36.890           pjsua_core.c  .1 SIP worker threads created
14:40:36.890           pjsua_core.c  .pjsua version 2.10-jitsi3 for Linux-5.4.0.132/x86_64/glibc-2.31 initialized
14:40:36.890           pjsua_core.c  .PJSUA state changed: CREATED --> INIT
14:40:36.890         sip_endpoint.c  Module "mod-default-handler" registered
14:40:36.890           pjsua_core.c  SIP UDP socket reachable at 172.16.17.135:5060
14:40:36.890      udp0x5558738eaf10  SIP UDP transport started, published address is 172.16.17.135:5060
14:40:36.890            pjsua_acc.c  Adding account: id=<sip:172.16.17.135:5060>
14:40:36.890            pjsua_acc.c  .Account <sip:172.16.17.135:5060> added with id 0
14:40:36.890            pjsua_acc.c  Modifying account 0
14:40:36.890            pjsua_acc.c  Acc 0: setting online status to 1..
14:40:36.890            pjsua_acc.c  Adding account: id=sip:7001@10x.xxx.xxx.xxx
14:40:36.890            pjsua_acc.c  .Account sip:7001@10x.xxx.xxx.xxx added with id 1
14:40:36.890            pjsua_acc.c  .Acc 1: setting registration..
14:40:36.890               endpoint  ..Request msg REGISTER/cseq=55851 (tdta0x5558738f2758) created.
14:40:36.890      tsx0x5558738f4718  ...Transaction created for Request msg REGISTER/cseq=55852 (tdta0x5558738f2758)
14:40:36.890      tsx0x5558738f4718  ..Sending Request msg REGISTER/cseq=55852 (tdta0x5558738f2758) in state Null
14:40:36.890          sip_resolve.c  ...Target '10x.xxx.xxx.xxx:0' type=Unspecified resolved to '10x.xxx.xxx.xxx:5060' type=UDP (UDP transport)
14:40:36.890           pjsua_core.c  ...TX 571 bytes Request msg REGISTER/cseq=55852 (tdta0x5558738f2758) to UDP 10x.xxx.xxx.xxx:5060:
REGISTER sip:10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPjbe41ba80-1c0a-45a2-9948-809d6af558e2
Max-Forwards: 70
From: <sip:7001@10x.xxx.xxx.xxx>;tag=32e49c2a-c5d3-4154-8984-5b5e00282a48
To: <sip:7001@10x.xxx.xxx.xxx>
Call-ID: 95f59f25-e941-4acc-b242-9b5f321db014
CSeq: 55852 REGISTER
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Contact: <sip:7001@172.16.17.135:5060;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Length:  0


--end msg--
14:40:36.890      tsx0x5558738f4718  ...State changed from Null to Calling, event=TX_MSG
14:40:36.890            pjsua_acc.c  ..Acc 1: Registration sent
14:40:36.890            pjsua_acc.c  Acc 1: setting online status to 1..
14:40:36.890           pjsua_pres.c  Adding buddy: sip:7003@10x.xxx.xxx.xxx
14:40:36.890           pjsua_pres.c  .Buddy 0 added.
14:40:36.890           pjsua_pres.c  ..Buddy 0: updating presence..
14:40:36.890            pjsua_aud.c  Set sound device: capture=30, playback=29
14:40:36.890            pjsua_app.c  .Turning sound device 30 29 ON
14:40:36.890            pjsua_aud.c  .Opening sound device (speaker + mic) PCM@16000/1/20ms
14:40:36.890             alsa_dev.c  ..open_playback: Open playback device 'plughw:CARD=Loopback,DEV=1'
14:40:36.890             alsa_dev.c  ..Opened device alsa(plughw:CARD=Loopback,DEV=1) for playing, sample rate=16000, ch=1, bits=16, period size=320 frames, latency=140 ms
14:40:36.890             alsa_dev.c  ..open_capture: Open capture device 'sysdefault:CARD=Loopback_1'
14:40:36.891             alsa_dev.c  ..Opened device alsa(sysdefault:CARD=Loopback_1) for capture, sample rate=16000, ch=1, bits=16, period size=341 frames, latency=106 ms
14:40:36.891           pjsua_core.c  PJSUA state changed: INIT --> STARTING
14:40:36.891         sip_endpoint.c  .Module "mod-unsolicited-mwi" registered
14:40:36.891             alsa_dev.c !ca_thread_func(25997): Set thread priority for audio capture thread.
14:40:36.891           pjsua_core.c !.PJSUA state changed: STARTING --> RUNNING
14:40:36.891                 main.c  Ready: Success
14:40:36.891           pjsua_call.c  Making call with acc #1 to sip:7003@10x.xxx.xxx.xxx
14:40:36.891             alsa_dev.c !Unable to increase thread priority, root access needed.
14:40:36.891      dlg0x555873945b48 !.UAC dialog created
14:40:36.891      dlg0x555873945b48  ..Session count inc to 2 by mod-pjsua
14:40:36.891          pjsua_media.c  .Call 0: initializing media..
14:40:36.891          pjsua_media.c  ..RTP socket reachable at 172.16.17.135:4000
14:40:36.891          pjsua_media.c  ..RTCP socket reachable at 172.16.17.135:4001
14:40:36.891     srtp0x5558738ce2d0  ..SRTP keying SDES created
14:40:36.891          pjsua_media.c  ..RTP socket reachable at 172.16.17.135:4002
14:40:36.891          pjsua_media.c  ..RTCP socket reachable at 172.16.17.135:4003
14:40:36.891     srtp0x55587394dac0  ..SRTP keying SDES created
14:40:36.891          pjsua_media.c  ..Media index 0 selected for audio call 0
14:40:36.891          pjsua_media.c  ..Call 0: media transport initialization complete: Success
14:40:36.891      dlg0x555873945b48  ..Session count dec to 2 by mod-pjsua
14:40:36.891      dlg0x555873945b48  .Module mod-invite added as dialog usage, data=0x5558739506d8
14:40:36.891      dlg0x555873945b48  ..Session count inc to 4 by mod-invite
14:40:36.891      dlg0x555873945b48  .Module mod-100rel added as dialog usage, data=0x5558739534c8
14:40:36.891      dlg0x555873945b48  .100rel module attached
14:40:36.891      inv0x555873945b48  .UAC invite session created for dialog dlg0x555873945b48
14:40:36.892               endpoint  .Request msg INVITE/cseq=27443 (tdta0x555873953828) created.
14:40:36.892      inv0x555873945b48  ..Sending Request msg INVITE/cseq=27443 (tdta0x555873953828)
14:40:36.892      dlg0x555873945b48  ...Sending Request msg INVITE/cseq=27443 (tdta0x555873953828)
14:40:36.892      tsx0x555873956798  ....Transaction created for Request msg INVITE/cseq=27442 (tdta0x555873953828)
14:40:36.892      tsx0x555873956798  ...Sending Request msg INVITE/cseq=27442 (tdta0x555873953828) in state Null
14:40:36.892          sip_resolve.c  ....Target '10x.xxx.xxx.xxx:0' type=Unspecified resolved to '10x.xxx.xxx.xxx:5060' type=UDP (UDP transport)
14:40:36.892               endpoint  ....Request msg INVITE/cseq=27442 (tdta0x555873953828) exceeds UDP size threshold (1300), sending with TCP
14:40:36.892      tsx0x555873956798  ....Temporary failure in sending Request msg INVITE/cseq=27442 (tdta0x555873953828), will try next server: Unsupported transport (PJSIP_EUNSUPTRANSPORT)
14:40:36.892           pjsua_core.c  ....TX 1666 bytes Request msg INVITE/cseq=27442 (tdta0x555873953828) to UDP 10x.xxx.xxx.xxx:5060:
INVITE sip:7003@10x.xxx.xxx.xxx SIP/2.0
Via: SIP/2.0/UDP 172.16.17.135:5060;rport;branch=z9hG4bKPj2b4aecc5-d3fc-41b9-a604-1c1bcdf6aed4
Max-Forwards: 70
From: sip:7001@10x.xxx.xxx.xxx;tag=ac9bd83f-3bcc-45b3-a2bc-3a45e5e482be
To: sip:7003@10x.xxx.xxx.xxx
Contact: <sip:7001@172.16.17.135:5060;ob>
Call-ID: 9c48f12f-c254-42b0-914f-1ed64c43e08e
CSeq: 27442 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: PJSUA v2.10-jitsi3 Linux-5.4.0.132/x86_64/glibc-2.31
Content-Type: application/sdp
Content-Length:   995

v=0
o=- 3878786436 3878786436 IN IP4 172.16.17.135
s=pjmedia
b=AS:2742
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 9 97 98 99 8 0 120 121 122 123
c=IN IP4 172.16.17.135
b=TIAS:96000
a=rtcp:4001 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=rtpmap:9 G722/8000
a=rtpmap:97 speex/32000
a=rtpmap:98 speex/16000
a=rtpmap:99 speex/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:120 telephone-event/48000
a=fmtp:120 0-16
a=rtpmap:121 telephone-event/8000
a=fmtp:121 0-16
a=rtpmap:122 telephone-event/32000
a=fmtp:122 0-16
a=rtpmap:123 telephone-event/16000
a=fmtp:123 0-16
a=ssrc:1349421196 cname:37ef4809368a132a
m=video 4002 RTP/AVP 97 102
c=IN IP4 172.16.17.135
b=TIAS:2500000
a=rtcp:4003 IN IP4 172.16.17.135
a=sendrecv
a=rtpmap:97 H264/90000
a=fmtp:97 profile-level-id=42801f; packetization-mode=1
a=rtpmap:102 VP8/90000
a=fmtp:102 max-fr=30; max-fs=580
a=ssrc:832400247 cname:37ef4809368a132a
a=rtcp-fb:* nack pli

--end msg--
14:40:36.892      tsx0x555873956798  ....State changed from Null to Calling, event=TX_MSG
14:40:36.892      dlg0x555873945b48  .....Transaction tsx0x555873956798 state changed to Calling
14:40:36.892            pjsua_app.c  .......Call 0 state changed to CALLING
14:40:36.900         sip_endpoint.c !Processing incoming message: Response msg 200/REGISTER/cseq=55852 (rdata0x5558738ec998)
14:40:36.900           pjsua_core.c  .RX 539 bytes Response msg 200/REGISTER/cseq=55852 (rdata0x5558738ec998) from UDP 10x.xxx.xxx.xxx:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.17.135:5060;rport=5060;received=103.247.238.6;branch=z9hG4bKPjbe41ba80-1c0a-45a2-9948-809d6af558e2
Call-ID: 95f59f25-e941-4acc-b242-9b5f321db014
From: <sip:7001@10x.xxx.xxx.xxx>;tag=32e49c2a-c5d3-4154-8984-5b5e00282a48
To: <sip:7001@10x.xxx.xxx.xxx>;tag=z9hG4bKPjbe41ba80-1c0a-45a2-9948-809d6af558e2
CSeq: 55852 REGISTER
Date: Wed, 30 Nov 2022 08:40:36 GMT
Contact: <sip:7001@10x.xxx.xxx.xxx:5060;ob>;expires=299
Expires: 300
Server: Asterisk PBX 16.2.1~dfsg-2ubuntu1
Content-Length:  0


--end msg--
14:40:36.900      tsx0x5558738f4718  .Incoming Response msg 200/REGISTER/cseq=55852 (rdata0x5558738ec998) in state Calling
14:40:36.900      tsx0x5558738f4718  ..State changed from Calling to Completed, event=RX_MSG
14:40:36.900            pjsua_acc.c  ....SIP outbound status for acc 1 is not active
14:40:36.900            pjsua_acc.c  ....sip:7001@10x.xxx.xxx.xxx: registration success, status=200 (OK), will re-register in 299 seconds
14:40:36.900            pjsua_acc.c  ....Keep-alive timer started for acc 1, destination:10x.xxx.xxx.xxx:5060, interval:15s
14:40:36.900         sip_endpoint.c  Processing incoming message: Response msg 100/INVITE/cseq=27442 (rdata0x7fc5e8002688)
14:40:36.900           pjsua_core.c  .RX 383 bytes Response msg 100/INVITE/cseq=27442 (rdata0x7fc5e8002688) from UDP 10x.xxx.xxx.xxx:5060:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.16.17.135:5060;rport=5060;received=103.247.238.6;branch=z9hG4bKPj2b4aecc5-d3fc-41b9-a604-1c1bcdf6aed4
Call-ID: 9c48f12f-c254-42b0-914f-1ed64c43e08e
From: <sip:7001@10x.xxx.xxx.xxx>;tag=ac9bd83f-3bcc-45b3-a2bc-3a45e5e482be
To: <sip:7003@10x.xxx.xxx.xxx>
CSeq: 27442 INVITE
Server: Asterisk PBX 16.2.1~dfsg-2ubuntu1
Content-Length:  0


--end msg--
14:40:36.900      tsx0x555873956798  .Incoming Response msg 100/INVITE/cseq=27442 (rdata0x7fc5e8002688) in state Calling
14:40:36.900      tsx0x555873956798  ..State changed from Calling to Proceeding, event=RX_MSG
14:40:36.900      dlg0x555873945b48  ...Received Response msg 100/INVITE/cseq=27442 (rdata0x7fc5e8002688)
14:40:36.900      dlg0x555873945b48  ...Transaction tsx0x555873956798 state changed to Proceeding
14:40:36.900         sip_endpoint.c  Processing incoming message: Response msg 200/INVITE/cseq=27442 (rdata0x7fc5e8002688)
14:40:36.900           pjsua_core.c  .RX 1088 bytes Response msg 200/INVITE/cseq=27442 (rdata0x7fc5e8002688) from UDP 10x.xxx.xxx.xxx:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.16.17.135:5060;rport=5060;received=103.247.238.6;branch=z9hG4bKPj2b4aecc5-d3fc-41b9-a604-1c1bcdf6aed4
Call-ID: 9c48f12f-c254-42b0-914f-1ed64c43e08e
From: <sip:7001@10x.xxx.xxx.xxx>;tag=ac9bd83f-3bcc-45b3-a2bc-3a45e5e482be
To: <sip:7003@10x.xxx.xxx.xxx>;tag=722db733-d7ae-4236-a350-0fb6e0e3172d
CSeq: 27442 INVITE
Server: Asterisk PBX 16.2.1~dfsg-2ubuntu1
Contact: <sip:10x.xxx.xxx.xxx:5060>
Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER

Do you have enough resources?
at least 4 CPU cores and at least 8 GB RAM…

Yes. It is vps of 8 core CPU and 16 GB RAM.

**


**

This may be related with audio devices and the device IDs:

--capture-dev=30
--playback-dev=29

How many ALSA loopback do you have?
Do you run pjsua in a desktop environment?

No, pjsua runs on ubuntu server without any desktop environment.

sudo aplay -L

surround21
    2.1 Surround output to Front and Subwoofer speakers
surround40
    4.0 Surround output to Front and Rear speakers
surround41
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50
    5.0 Surround output to Front, Center and Rear speakers
surround51
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
null
    Discard all samples (playback) or generate zero samples (capture)
default:CARD=Loopback
    Loopback, Loopback PCM
    Default Audio Device
sysdefault:CARD=Loopback
    Loopback, Loopback PCM
    Default Audio Device
front:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Front speakers
surround21:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    2.1 Surround output to Front and Subwoofer speakers
surround40:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    4.0 Surround output to Front and Rear speakers
surround41:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    5.0 Surround output to Front, Center and Rear speakers
surround51:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
dmix:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Direct sample mixing device
dmix:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Direct sample mixing device
dsnoop:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Direct sample snooping device
dsnoop:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Direct sample snooping device
hw:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Direct hardware device without any conversions
hw:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Direct hardware device without any conversions
plughw:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Hardware device with all software conversions
plughw:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Hardware device with all software conversions
default:CARD=Loopback_1
    Loopback, Loopback PCM
    Default Audio Device
sysdefault:CARD=Loopback_1
    Loopback, Loopback PCM
    Default Audio Device
front:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Front speakers
surround21:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    2.1 Surround output to Front and Subwoofer speakers
surround40:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    4.0 Surround output to Front and Rear speakers
surround41:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    5.0 Surround output to Front, Center and Rear speakers
surround51:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
dmix:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Direct sample mixing device
dmix:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Direct sample mixing device
dsnoop:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Direct sample snooping device
dsnoop:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Direct sample snooping device
hw:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Direct hardware device without any conversions
hw:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Direct hardware device without any conversions
plughw:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Hardware device with all software conversions
plughw:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Hardware device with all software conversions

sudo arecord -L

surround21
    2.1 Surround output to Front and Subwoofer speakers
surround40
    4.0 Surround output to Front and Rear speakers
surround41
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50
    5.0 Surround output to Front, Center and Rear speakers
surround51
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
null
    Discard all samples (playback) or generate zero samples (capture)
default:CARD=Loopback
    Loopback, Loopback PCM
    Default Audio Device
sysdefault:CARD=Loopback
    Loopback, Loopback PCM
    Default Audio Device
front:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Front speakers
surround21:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    2.1 Surround output to Front and Subwoofer speakers
surround40:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    4.0 Surround output to Front and Rear speakers
surround41:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    5.0 Surround output to Front, Center and Rear speakers
surround51:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
dmix:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Direct sample mixing device
dmix:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Direct sample mixing device
dsnoop:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Direct sample snooping device
dsnoop:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Direct sample snooping device
hw:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Direct hardware device without any conversions
hw:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Direct hardware device without any conversions
plughw:CARD=Loopback,DEV=0
    Loopback, Loopback PCM
    Hardware device with all software conversions
plughw:CARD=Loopback,DEV=1
    Loopback, Loopback PCM
    Hardware device with all software conversions
default:CARD=Loopback_1
    Loopback, Loopback PCM
    Default Audio Device
sysdefault:CARD=Loopback_1
    Loopback, Loopback PCM
    Default Audio Device
front:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Front speakers
surround21:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    2.1 Surround output to Front and Subwoofer speakers
surround40:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    4.0 Surround output to Front and Rear speakers
surround41:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    4.1 Surround output to Front, Rear and Subwoofer speakers
surround50:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    5.0 Surround output to Front, Center and Rear speakers
surround51:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    5.1 Surround output to Front, Center, Rear and Subwoofer speakers
surround71:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    7.1 Surround output to Front, Center, Side, Rear and Woofer speakers
dmix:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Direct sample mixing device
dmix:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Direct sample mixing device
dsnoop:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Direct sample snooping device
dsnoop:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Direct sample snooping device
hw:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Direct hardware device without any conversions
hw:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Direct hardware device without any conversions
plughw:CARD=Loopback_1,DEV=0
    Loopback, Loopback PCM
    Hardware device with all software conversions
plughw:CARD=Loopback_1,DEV=1
    Loopback, Loopback PCM
    Hardware device with all software conversions

There should be at least two ALSA loopback devices and pjsua should run on its own desktop if you need a video SIP call.

I loaded the snd-aloop module with the addition of options: options snd-aloop enable=1,1 index=0,1.
Then I loaded v4l2loopback module with options: options v4l2loopback devices=2 video_nr=0,1 exclusive_caps=1,1 card_label=“PJSUA,Chrome”

Do I need any additional settings?