RTCAudioSink ondata event never fires

[om2kw]

While using programmatic audio from non-standard api, ondata event in RTCAudioSink is never fired.
It is working in original source where this was forked from.

let sink= new RTCAudioSink(track);
sink.ondata= (data)=> {...}; //never fired

MacOS x64, node 18 lts, tested both installed from npm and local build

[duvallj]

@om2kw Do you have a minimal reproducible example? I'd like to add a testcase for this so this regression doesn't happen again.

[om2kw]

to my surprise minimal example works (not including network, ...)

let source= new RTCAudioSource();
let track= source.createTrack();
let sink= new RTCAudioSink(track);

sink.ondata= (data)=> console.log('Sink onData: ', data);

let sampleRate= 8000;
let samples= new Int16Array(sampleRate / 100);
source.onData({samples, sampleRate});

I will reduce my code and post not working example soon.

[om2kw]

ok, this is example which IS NOT working with current version (0.7.0) and IS working with original version.
Unfortunately it is quite long and complex for minimal example.
EDIT: removed ICE, bit smaller example

const { RTCAudioSource, RTCAudioSink }= require('wrtc').nonstandard;
const RTCIceCandidate= require('wrtc').RTCIceCandidate;
const RTCPeerConnection = require('wrtc').RTCPeerConnection;
const RTCSessionDescription= require('wrtc').RTCSessionDescription;

let pcA= new RTCPeerConnection();
let pcB= new RTCPeerConnection();

pcA.onconnectionstatechange=   (evt_)=> {console.log('pcA: onConStateChange:', pcA.connectionState);};
pcA.onsignalingstatechange=    (evt_)=> {console.log('pcA: onSigStateCHange:', pcA.signalingState);};
pcA.onicegatheringstatechange= (evt_)=> {console.log('pcA: onGatStateChange:', evt_.target.iceGatheringState);};
pcA.ontrack=                   (evt_)=> {console.log('pcA: onTrack');};

pcB.onconnectionstatechange=   (evt_)=> {console.log('pcB: onConStateChange:', pcB.connectionState);};
pcB.onsignalingstatechange=    (evt_)=> {console.log('pcB: onSigStateCHange:', pcB.signalingState);};
pcB.onicegatheringstatechange= (evt_)=> {console.log('pcB: onGatStateChange:', evt_.target.iceGatheringState);};
pcB.ontrack=                   (evt_)=> {
  console.log('pcB: onTrack');
  let track= evt_.track;
  let sink= new RTCAudioSink(track);
  sink.ondata= (data)=> {                     //here we are getting audio data from rtc
    console.log('sinkOnData: ', data);
  };
};

let source= new RTCAudioSource();
let track= source.createTrack();
pcA.addTrack(track);

let sampleRate= 8000;
let samples= new Int16Array(sampleRate/ 100);
for(let n= 0; n< samples.length; n++)
  samples[n]= Math.random()* 0xffff;
let data= {samples, sampleRate};
let interval= setInterval(()=> {source.onData(data);}); //feed source audio with noise data


pcA.createOffer()
    .then((offer)=> pcA.setLocalDescription(offer))  //this.setStereo(offer)))
    .then(()=> {
      let desc= new RTCSessionDescription(pcA.localDescription);
      pcB.setRemoteDescription(desc)
        .then(()=> pcB.createAnswer())
        .then((answer)=> pcB.setLocalDescription(answer))  //this.setStereo(answer)))
        .then(()=> {
          pcA.setRemoteDescription(pcB.localDescription);
        })
      .catch((e_)=> {
        console.log('pcB: create Answer catch:', e_);
      });
  
    })
  .catch((e_)=> {
    console.log('pcA: createOffer: catch:', e_);
  })

[duvallj]

@om2kw I can confirm this example has different behavior on the old and new versions, thank you! The new version does get to connectionState connected with the remote track added, but the data is not flowing all the way to the sink, which is a bug, so I'll work on fixing it.

However, on wrtc 0.4.7, Node 14.21.3, Linux x64, I am also seeing that the sink onData is getting called much more often than it should be; it both got called before the first time source pushed any data, as well as at a higher frequency than when the source is called (slowed down the interval to a more reasonable amount). Are you observing this too?

[duvallj]

(my updated example, btw)

const { RTCAudioSource, RTCAudioSink } = require("@roamhq/wrtc").nonstandard;
const { RTCPeerConnection } = require("@roamhq/wrtc");

const pcA = new RTCPeerConnection();
const pcB = new RTCPeerConnection();

pcA.onconnectionstatechange = () => {
  console.log("pcA: onconnectionstatechange:", pcA.connectionState);
};
pcA.onsignalingstatechange = () => {
  console.log("pcA: onsignalingstatechange:", pcA.signalingState);
};
pcA.onicegatheringstatechange = (e) => {
  console.log("pcA: onicegatheringstatechange:", e.target.iceGatheringState);
};
pcA.ontrack = () => {
  console.log("pcA: onTrack");
};

pcB.onconnectionstatechange = () => {
  console.log("pcB: onconnectionstatechange:", pcB.connectionState);
};
pcB.onsignalingstatechange = () => {
  console.log("pcB: onsignalingstatechange:", pcB.signalingState);
};
pcB.onicegatheringstatechange = (e) => {
  console.log("pcB: onicegatheringstatechange:", e.target.iceGatheringState);
};
pcB.ontrack = (e) => {
  console.log("pcB: onTrack");
  const sink = new RTCAudioSink(e.track);
  sink.ondata = (data) => {
    console.log("sink: ondata: ", data);
  };
};

/**
 * See https://developer.mozilla.org/en-US/docs/Web/API/WebRTC_API/Perfect_negotiation
 * @param {RTCPeerConnection} local
 * @param {RTCPeerConnection} remote
 * @param {boolean} polite
 */
const setupPerfectNegotiation = (local, remote, polite) => {
  let makingOffer = false;
  local.onnegotiationneeded = async () => {
    try {
      makingOffer = true;
      await local.setLocalDescription(await local.createOffer());
      await remote.receivedescription(local.localDescription);
    } catch (err) {
      console.error(err);
    } finally {
      makingOffer = false;
    }
  };

  /**
   * @param {RTCSessionDescription} description
   */
  local.receivedescription = async (description) => {
    if (description.type === "offer") {
      if (!polite && local.signalingState !== "stable") return;
      await Promise.all([
        async () => {
          if (local.signalingState !== "stable") {
            await local.setLocalDescription({ type: "rollback" });
          }
        },
        local.setRemoteDescription(description),
      ]);
      await local.setLocalDescription(await local.createAnswer());
      await remote.receivedescription(local.localDescription);
    } else {
      await local.setRemoteDescription(description);
    }
  };
};

setupPerfectNegotiation(pcA, pcB, true);
setupPerfectNegotiation(pcB, pcA, false);

const inspect = () => {
  console.log("pcA: connectionState: ", pcA.connectionState);
  console.log("pcA: signalingState: ", pcA.signalingState);
  console.log("pcA: iceGatheringState: ", pcA.iceGatheringState);
  console.log("pcB: connectionState: ", pcB.connectionState);
  console.log("pcB: signalingState: ", pcB.signalingState);
  console.log("pcB: iceGatheringState: ", pcB.iceGatheringState);
};

const source = new RTCAudioSource();
const track = source.createTrack();
pcA.addTrack(track);

const sampleRate = 8000;
const samples = new Int16Array(sampleRate / 100);
for (let n = 0; n < samples.length; n++) {
  samples[n] = Math.random() * 0xffff;
}
const data = { samples, sampleRate };
const interval = setInterval(() => {
  console.log("source: onData");
  inspect();
  source.onData(data);
}, 1000);

const waitingKeypress = () => {
  process.stdin.setRawMode(true);
  return new Promise((resolve) =>
    process.stdin.once("data", () => {
      process.stdin.setRawMode(false);
      resolve();
    })
  );
};

(async () => {
  await waitingKeypress();
})()
  .then(() => {
    console.log("complete");
    clearInterval(interval);
  })
  .catch((e) => {
    console.log("error:", e);
  });

[om2kw]

My example is not exact in data timing. I made some changes in example so i am sending new data to source each 10ms
and it looks like i am also getting sink data each 10ms.
Each 10ms i am getting 480 frames which corresponds with my sampling rate.
Tested on MacOS x64, node 18LTS, wrtc 0.4.7

[MatthD]

Hello ! We did encounter the issue while using your version of WRTC.
Thank you very much for you hard work making this lib working node 18/20.

Do you think there is a workaround for this event no firing data ?

[duvallj]

Hi @MatthD,

Sorry to hear this bug is impacting you. I don't currently have a workaround for this, it's likely something that needs to get fixed in the library internals. It was pretty tricky to trace last time I looked, and it's been a while since then...

Work hasn't allocated me any cycles to work on this, so I'd need to get this done in my (limited) free time. Again, sorry.

[MatthD]

Thanks @duvallj , I am familiar with native node_module not a lot with webrtc procotol , i means even after working in production it's still a blackbox for me. 😆
I can try to work on it in the lib, did not see anything related to RTCAudioSink changed in your lib (when pointing the pr to master of base lib). So not sure where to start.

[MatthD]

Trying to compile to debug the library, I am facing 5 errors at the end.
Macos 14.4 Mac Pro M2, xcode 15.3 available, value of SDKROOT=/Users/dieudonn/Documents/mac-sdk/MacOSX14.4.sdk in zshrc, Node 20
Did you face those ?

[duvallj]

@MatthD You'll need MacOSX11.3.sdk, see https://github.com/WonderInventions/node-webrtc/blob/develop/docs/build-from-source.md

[MatthD]

Yes thanks I saw this after my message , I did remove node_modules and build-*
And point to the right MacOSX11.3.sdk and still same issue

[duvallj]

hmm, I think it's the case that the WebRTC build system isn't respecting SDKROOT for whatever reason. I have been building with a symlinked folder inside /Applications/Xcode.app/Contents/Developer/Platforms/MacOSX.platform/Developer/SDKs, that is, running

sudo ln -s /Users/dieudonn/Dev/MacOSX-SDKs/MacOSX11.3.sdk /Applications/Xcode.app/Contents/Developer/Platforms/MacOSX.platform/Developer/SDKs/MacOSX11.3.sdk

deleting the build folder, and trying the build again?

@MatthD

[MatthD]

That did the trick thanks will update doc and try debug

[MatthD]

Quick update, setting the ondata property outside of the ontrack event is working, trying to understand why.
Setting the property inside any eventlistener is not working

'use strict';

const test = require('tape');

const { getUserMedia, RTCPeerConnection } = require('..');
const { RTCAudioSink, RTCAudioSource } = require('..').nonstandard;

test('RTCAudioSink', t => {
  return getUserMedia({ audio: true }).then(stream => {
    const track = stream.getAudioTracks()[0];
    const sink = new RTCAudioSink(track);
    t.ok(!sink.stopped, 'RTCAudioSink initially is not stopped');
    sink.stop();
    t.ok(sink.stopped, 'RTCAudioSink is finally stopped');
    track.stop();
    t.end();
  });
});

test('RTCAudioSink should send even ondata on SIMPLE situation', t=>{
  const source = new RTCAudioSource();
  const track = source.createTrack();
  const sink = new RTCAudioSink(track);

  sink.ondata = (data)=> {
    console.log('Sink onData SIMPLE: ', data);
    t.ok(sink.da, 'RTCAudioSink fired ondata');
  };

  const sampleRate = 8000;
  const samples = new Int16Array(sampleRate / 100);
  source.onData({ samples, sampleRate });
  setTimeout(() => {    
    sink.stop();
    track.stop();
    t.end();
  }, 150);
});

test('RTCAudioSink should send even ondata on COMPLEXE situation', t=>{

  const pcA = new RTCPeerConnection();
  const pcB = new RTCPeerConnection();
  let ondataDidFired = false;
  let sink;


  pcA.onconnectionstatechange = () => {
    console.log('pcA: onconnectionstatechange:', pcA.connectionState);
  };
  pcA.onsignalingstatechange = () => {
    console.log('pcA: onsignalingstatechange:', pcA.signalingState);
  };
  pcA.onicegatheringstatechange = (e) => {
    console.log('pcA: onicegatheringstatechange:', e.target.iceGatheringState);
  };
  pcA.ontrack = (e) => {
    console.log('pcA: onTrack');
  };

  pcB.onconnectionstatechange = () => {
    console.log('pcB: onconnectionstatechange:', pcB.connectionState);
  };
  pcB.onsignalingstatechange = (e) => {
    if (pcB.signalingState === 'stable') {
      pcB.getReceivers()[0].track.id
      console.log('pcB: onsignalingstatechange:', pcB.signalingState);
    }
  };
  pcB.onicegatheringstatechange = (e) => {
    console.log('pcB: onicegatheringstatechange:', e.target.iceGatheringState);
  };
  pcB.ontrack = function(e) {
    console.log('track B linked !---------');
    e.track.id;
    // This is NOT working 
    // sink = new RTCAudioSink(track);
    // sink.addEventListener('data', data => {
    //   console.log('Sink onData COMPLEXE: ', data);
    //   ondataDidFired = true;
    // });
  };

  setupPerfectNegotiation(pcA, pcB, true);
  setupPerfectNegotiation(pcB, pcA, false);

  const source = new RTCAudioSource();
  const track = source.createTrack();
  track.id;
  pcA.addTrack(track);

  // This is working 
  sink = new RTCAudioSink(track);
  sink.addEventListener('data', data => {
    console.log('Sink onData COMPLEXE: ', data);
    ondataDidFired = true;
  });

  const sampleRate = 8000;
  const samples = new Int16Array(sampleRate / 100);
  for (let n = 0; n < samples.length; n++) {
    samples[n] = Math.random() * 0xffff;
  }
  const data = { samples, sampleRate };
  source.onData({ samples, sampleRate });

  // const interval = setInterval(() => {
  //   console.log('source: onData');
  //   inspect(pcA, pcB);
  //   source.onData({ samples, sampleRate });
  // }, 10);

  setTimeout(()=>{
    // clearInterval(interval);
    // console.log('ondataDidFired', ondataDidFired);
    t.ok(ondataDidFired, 'RTCAudioSink should have fired');
    sink.stop();
    track.stop();
    pcA.close();
    pcB.close();
    t.end();
  }, 200);

});

/**
 * See https://developer.mozilla.org/en-US/docs/Web/API/WebRTC_API/Perfect_negotiation
 * @param {RTCPeerConnection} local
 * @param {RTCPeerConnection} remote
 * @param {boolean} polite
 */
function setupPerfectNegotiation(local, remote, polite) {
  let makingOffer = false;
  local.onnegotiationneeded = async () => {
    try {
      makingOffer = true;
      await local.setLocalDescription(await local.createOffer());
      await remote.receivedescription(local.localDescription);
    } catch (err) {
      console.error(err);
    } finally {
      makingOffer = false;
    }
  };

  /**
   * @param {RTCSessionDescription} description
   */
  local.receivedescription = async (description) => {
    if (description.type === 'offer') {
      if (!polite && local.signalingState !== 'stable') return;
      await Promise.all([
        async () => {
          if (local.signalingState !== 'stable') {
            await local.setLocalDescription({ type: 'rollback' });
          }
        },
        local.setRemoteDescription(description),
      ]);
      await local.setLocalDescription(await local.createAnswer());
      await remote.receivedescription(local.localDescription);
    } else {
      await local.setRemoteDescription(description);
    }
  };
}

function inspect(pcA, pcB) {
  console.log('pcA: connectionState: ', pcA.connectionState);
  console.log('pcA: signalingState: ', pcA.signalingState);
  console.log('pcA: iceGatheringState: ', pcA.iceGatheringState);
  console.log('pcB: connectionState: ', pcB.connectionState);
  console.log('pcB: signalingState: ', pcB.signalingState);
  console.log('pcB: iceGatheringState: ', pcB.iceGatheringState);
}

[duvallj]

oh weird!! I could imagine it might have something to do with the callback's execution context as recorded by the library? And somehow getting a bad execution context is preventing the callback from running. This is a good find, thanks!

[MatthD]

No problem, I hope to find a solution of this, will prepare a branch people can help on.
I assume if we even do not enter the OnData c++ method (I debug that), the problem is earlier, so you might be right !

[nakagawa424]

Reverting db08592 works fine for my use case.

[duvallj]

@nakagawa424 Thanks for bisecting this! Seems like my quick fix at the time was only quick and not a real fix, we'll need proper locking there I think.

[MatthD]

This is the pull request !

#10

I don't know you do to publish for all prebuilds. that are not my platform :s

[nakagawa424]

#11 also works fine.