search

nwhetsell / csound-api

Node.js bindings to Csound’s API
https://www.npmjs.com/package/csound-api
MIT License
32 stars 6 forks source link

Throttling in `.GetControlChannel()` method? #22

Closed jasonhallen closed 2 years ago

jasonhallen commented 2 years ago

Hi Nate!

I've got an issue for you, though it might be a Node issue rather than csound-api. I'm on an Mac with an M1 processor.

Issue

When I call .GetControlChannel() when running .PerformAsync() in Node I'm getting repeated values from Csound. I would expect the values to be changing each time the method is called. It's like there's some kind of throttling that is limiting the output of .GetControlChannel(). I'm hoping to find out what the underlying issue is.

Code Example

const csound = require('csound-api')

const Csound = csound.Create()
csound.SetOption(Csound, '--output=dac')
csound.CompileOrc(Csound, `
  0dbfs = 1
  instr 1
    kenv line 0, p3, 1
    asig oscil kenv, 220

    ktrig metro 20
    kmeter max_k asig, ktrig, 1
    printk2 kmeter
    chnset kmeter, "meter"
  endin
`)
csound.ReadScore(Csound, `
  i 1 0 1
  i 1 1 1
  i 1 2 1
  e
`)
if (csound.Start(Csound) === csound.SUCCESS) {
  csound.PerformAsync(Csound, () => csound.Destroy(Csound))
}

function readCsoundValues(){
    let amplitude = csound.GetControlChannel(Csound, "meter")
    console.log(amplitude)
    setTimeout(readCsoundValues, 50)
}
readCsoundValues()

Here's a quick overview of what's happening.

Csound

An oscillator outputs an oscillator signal (asig) with an amplitude that ramps up from 0 to 1. A metronome triggers max_k to read the amplitude of asig 20 times a second. Csound then sends the amplitude value out to the "meter" channel. printk2 shows that the amplitude increases incrementally for each k-cycle as expected. Here's the output.

i1     0.00000
i1     0.04875
i1     0.09887
i1     0.14875
i1     0.19886
i1     0.24875
i1     0.29886
i1     0.34875
i1     0.39886
i1     0.44875
i1     0.49886
i1     0.54875
i1     0.59886
i1     0.64874
i1     0.69886
i1     0.74874
i1     0.79885
i1     0.84874
i1     0.89885
i1     0.94874

Node

A function calls .GetControlChannel() 20 times per second and prints the output. I would expect the output to similarly increase each time the function is called, but it repeats the values twice. Here's the output.

0.09886562427796818
0.09886562427796818
0.19886475080527538
0.19886475080527538
0.29886355394942954
0.29886355394942954
0.34874973139167503
0.44874884162817624
0.44874884162817624
0.5487470237683278
0.5487470237683278
0.6487447722417382
0.6487447722417382
0.7487435295149353
0.7487435295149353
0.848740601660029
0.9487391603915499
0.9487391603915499

Investigation

I tried to increase the resolution on both sides to fix the problem, but it didn't change anything. For example, I increased the Csound metronome to send the amplitude 100 times per second, but it didn't change the output in Node. When I increased the .GetControlChannel() calls in Node to 100 times per second I just got more repeated values like this.

0.09886562427796818
0.09886562427796818
0.09886562427796818
0.09886562427796818
0.09886562427796818
0.09886562427796818
0.09886562427796818
0.09886562427796818
0.19886475080527538
0.19886475080527538
0.19886475080527538
0.19886475080527538
0.19886475080527538
0.19886475080527538
0.19886475080527538
0.19886475080527538
0.29886355394942954
0.29886355394942954
0.29886355394942954
etc

In fact, Node only ever outputs 10 to 11 different values per second no matter how many times the function is called per second, as though it is throttled to reading .GetControlChannel() around 10 times per second. When I time how long it takes Node to get a result from .GetControlChannel() I get an average of about 0.015ms, which seems fast enough to be called 100 times per second.

I understand that the timing between .GetControlChannel() calls in Node won't be consistent, but timing doesn't matter as much as resolution in this case.

Do you know if there is some kind of throttling happening within csound-api that is limiting the .GetControlChannel() to sending 10 times per second? Otherwise, the problem might be within Node. I'm admittedly new to Node, so I could also be misunderstanding how it works.

Thanks as always for your guidance!

Jason

nwhetsell commented 2 years ago

This does not appear to be an issue with csound-api. If I run this C program (which, of course, doesn’t depend on csound-api)—

#include <csound/csound.h>
#include <assert.h>

uintptr_t perform(void *data)
{
    return csoundPerform((CSOUND *)data);
}

int main(int argc, char *argv[])
{
    CSOUND *Csound = csoundCreate(NULL);
    assert(csoundSetOption(Csound, "--output=dac") == CSOUND_SUCCESS);
    char *orchestra =
        "0dbfs = 1\n"
        "instr 1\n"
        "    kenv line 0, p3, 1\n"
        "    asig oscil kenv, 220\n"

        "    ktrig metro 20\n"
        "    kmeter max_k asig, ktrig, 1\n"
        "    printk2 kmeter\n"
        "    chnset kmeter, \"meter\"\n"
        "endin\n";
    assert(csoundCompileOrc(Csound, orchestra) == CSOUND_SUCCESS);
    char *score =
        "i 1 0 1\n"
        "i 1 1 1\n"
        "i 1 2 1\n"
        "e\n";
    assert(csoundReadScore(Csound, score) == CSOUND_SUCCESS);
    assert(csoundStart(Csound) == CSOUND_SUCCESS);

    void *threadID = csoundCreateThread(perform, (void *)Csound);

    size_t timeInterval = 50;
    size_t maxTime = 3000;
    for (unsigned int i = 0; i < maxTime / timeInterval; i++) {
        MYFLT meterValue = csoundGetControlChannel(Csound, "meter", NULL);
        printf("%.17f\n", meterValue);
        csoundSleep(timeInterval);
    }

    csoundStop(Csound);
    csoundJoinThread(threadID);
    csoundDestroy(Csound);

    return 0;
}

—I get, for all practical purposes, the same output that you get when running csound-api. From printk2:

 i1     0.00000
 i1     0.04875
 i1     0.09887
 i1     0.14875
 i1     0.19887
 i1     0.24875
 i1     0.29886
 i1     0.34875
 i1     0.39886
 i1     0.44875
 i1     0.49886
 i1     0.54875
 i1     0.59886
 i1     0.64875
 i1     0.69886
 i1     0.74875
 i1     0.79886
 i1     0.84875
 i1     0.89886
 i1     0.94875

From logging the result of chnset:

0.00000000000000000
0.00000000000000000
0.09886562427796818
0.09886562427796818
0.19886502865086275
0.19886502865086275
0.29886443302376170
0.29886443302376170
0.34875075720072124
0.39886383739666692
0.44875016157362646
0.54874956594653168
0.54874956594653168
0.64874897031943690
0.64874897031943690
0.74874837469234212
0.84874777906524734
0.84874777906524734
0.94874718343815256
0.94874718343815256

In addition, you can see how csound-api calls the underlying csoundGetControlChannel function:

https://github.com/nwhetsell/csound-api/blob/1d7e67e5abae1e7a938d84837f633c353c7cf96f/src/csound-api.cc#L1151-L1157

There is no throttling of the output of csoundGetControlChannel. The complexity of this function is from setting a JavaScript return value and an input object property.

My guess at the underlying issue is that csoundGetControlChannel is (as the name suggests) for getting values of control signals, not volume metering, but as this issue appears to be independent of csound-api, there isn’t much that can be done about this in Node.js.

jasonhallen commented 2 years ago

Thank you SO MUCH, Nate! I really appreciate you taking the time to walk me through this even though it was totally independent of csound-api. This is fascinating that this is the actual behavior of the Csound API. It still strikes me as surprising that outbound control signals can't be sent faster than 10 times per second. I'll take this issue to the Csound community for their comments.

Thanks again! Jason

nwhetsell commented 2 years ago

I'll take this issue to the Csound community for their comments.

Good luck!

One more thing; your code example contains:

if (csound.Start(Csound) === csound.SUCCESS) {
  csound.PerformAsync(Csound, () => csound.Destroy(Csound))
}

function readCsoundValues(){
    let amplitude = csound.GetControlChannel(Csound, "meter")
    console.log(amplitude)
    setTimeout(readCsoundValues, 50)
}
readCsoundValues()

Doing this is risky. After the performance ends and csound.Destroy(Csound) is called, you’ll be repeatedly passing a destroyed Csound object to csound.GetControlChannel, which will eventually lead to a segfault. You should probably do something like this (not tested):

if (csound.Start(Csound) === csound.SUCCESS) {
  const intervalObj = setInterval(() => {
    const amplitude = csound.GetControlChannel(Csound, 'meter')
    console.log(amplitude)
  }, 50)

  csound.PerformAsync(Csound, () => {
    clearInterval(intervalObj)
    csound.Destroy(Csound)
  })
}
jasonhallen commented 2 years ago

Hi Nate,

I posted about this on the Csound Forum, and Rory suggested this could be addressed with performKsmps. Since I needed this to be non-blocking in Node.js I decided to try .PerformKsmpsAsync() from csound-api. Here's how I rewrote the program:

const csound = require('csound-api')

const Csound = csound.Create()
csound.SetOption(Csound, '--output=dac')
csound.CompileOrc(Csound, `
  0dbfs = 1
  ksmps = 50
  instr 1
    kenv line 0, p3, 1
    asig oscil kenv, 220

    ktrig metro 20
    kmeter max_k asig, ktrig, 1
    printk2 kmeter
    chnset kmeter, "meter"
  endin
`)
csound.ReadScore(Csound, `
  i 1 0 1
  i 1 1 1
  i 1 2 1
  e
`)

if (csound.Start(Csound) === csound.SUCCESS) {
  csound.PerformKsmpsAsync(Csound, () => {
    testKsmpsAsync()
  }, () => {csound.Destroy(Csound)})
}

function testKsmpsAsync() {
  let amplitude = csound.GetControlChannel(Csound, "meter")
  console.log(amplitude)
}

With the metro set to 20 times per second I got these results when calling .GetControlChannel() and printing console.log(amplitude). There are still repeated values but the resolution is better.

0.051020104271887
0.051020104271887
0.15079275262579955
0.15079275262579955
0.2006790768027554
0.2006790768027554
0.25056571420852136
0.25056571420852136
0.30045210074777545
0.35033848728702954
0.4002253152814872
0.45011175684631904
0.5011319811739879
0.5510184227388174
0.5510184227388174
0.6009054387375272
0.6009054387375272
0.6507919279912071
0.7006784172448869
0.7006784172448869
0.8004520432202912
0.8004520432202912
0.9002256982093464
0.9002256982093464
0.9501122608305181
0.9501122608305181

Then when I set metro to 100 I get these results which have the best resolution yet.

0.04027285494939373
0.0600906852729396
0.08049865311389513
0.15079275262579955
0.1802717774391319
0.25056571420852136
0.27097218735666745
0.3390020432191236
0.37074500053666504
0.4297047098505638
0.47051735542115114
0.5306118937342816
0.5510184227388174
0.6190439318322294
0.6394546067652224
0.6893411363710183
0.7097503581294351
0.7301585153919423
0.8004520432202912
0.850338572826087
0.9002256982093464
0.9297051470542858
0.9909208882845262
0.9909208882845262

Maybe you can help me understand one thing though. My understanding of .PerformKsmpsAsync() is that every control cycle it yields control to the controlPeriodFunction, in this case testKsmpsAsync(). With sr = 41000 and ksmps = 50 that would mean there are 820 control cycles per second. However, console.log(amplitude) only logs about 26 values per second on average.

Can you help me understand why the number of console logs is so much smaller than the number of control cycles? Is this just the inherent latency of the Node.js event loop? Or perhaps this is another case where this is actually the behavior of the Csound API and nothing to do with Node.js or csound-api.

For the purposes of animating a volume meter 26 values per second is probably fine, but clearly I don't have a good mental model of how this is all supposed to work. I can also bring these questions to the Csound Forum going forward because I don't want to take too much of your time.

Thanks, Jason

nwhetsell commented 2 years ago

Can you help me understand why the number of console logs is so much smaller than the number of control cycles?

I’ll give it my best shot!

This does have something to do with Node.js, but it seems to be a general limitation, not something specific to csound-api.

First, while your math is correct, Csound’s default sample rate is 44,100 Hz, not 41,000 Hz. This means there are in fact 882 control cycles per second (that is, kr is 882) when ksmps is 50. Thus, it seems reasonable to expect the progress function passed as the second argument to csound.PerformKsmpsAsync to be called 882 times per second, after every 50 samples.

If you change your score to—

i 1 0 1
e

—so that Csound performs for 1 second, and the Csound performance section of your code to—

if (csound.Start(Csound) === csound.SUCCESS) {
  let count = 0;
  while (!csound.PerformKsmps(Csound)) {
    count++;
  }
  csound.Destroy(Csound);
  console.log(count);
}

—882 is logged, as expected. This at least tells us that csound-api is doing what it’s supposed to when csound.PerformKsmps is used, but that function blocks the main thread.

If you change the Csound performance section to—

if (csound.Start(Csound) === csound.SUCCESS) {
  let count = 0;
  csound.PerformKsmpsAsync(
    Csound,
    () => { count++; },
    () => {
      csound.Destroy(Csound);
      console.log(count);
    }
  );
}

—you should see that not only is a number (much) less than 882 logged, the number isn’t the same each time you run that code.

Here is where csound.PerformKsmpsAsync runs csoundPerformKsmps (the C function) in a loop:

https://github.com/nwhetsell/csound-api/blob/1d7e67e5abae1e7a938d84837f633c353c7cf96f/src/csound-api.cc#L678-L686

We can modify this code to log a count of control cycles without too much difficulty:

  void Execute(const Nan::AsyncProgressWorker::ExecutionProgress& executionProgress) {
    unsigned int count = 0;
    while (!csoundPerformKsmps(wrapper->Csound)) {
      count++;
      executionProgress.Signal();
      if (wrapper->eventHandler->CsoundDidPerformKsmps(wrapper->Csound))
        break;
      if (raisedSignal)
        break;
    }
    printf("\n==> %u\n\n", count);
  }

If you then rebuild csound-api (node-gyp rebuild) and re-run the JavaScript code in Node.js, you should see towards the end of the output:

==> 882

This means that 882 control cycles really are being processed by csound-api. So what’s happening?

The “gotcha” seems to be this line:

https://github.com/nwhetsell/csound-api/blob/1d7e67e5abae1e7a938d84837f633c353c7cf96f/src/csound-api.cc#L680

This effectively tells Node.js to run the progress function passed as the second argument to csound.PerformKsmpsAsync at some point; NAN’s documentation calls this “best-effort delivery”. So, if executionProgress.Signal() runs after every 50 samples, that does not mean the progress function will actually run that often. It just means that Node.js has been told to run the progress function that often. How often the progress function actually runs is up to Node.js’ internals (specifically the libuv threading library, if memory serves).

jasonhallen commented 2 years ago

Hi Nate,

My apologies for my delayed response. Thank you again for taking the time to carefully explain all of this to me. I've learned a lot from you.

As an experiment, I used the OSCsend opcode in my Csound instrument to send out amplitude values every k-cycle. I then ran an OSC server in the main process in Electron. I got beautiful high resolution values from that, easily 100+ values per second though I didn't test out the ceiling on that. Awesome!

All I had to do was pass the OSC values from the main process in Electron to the renderer process via inter-process communication. And there I got stuck with the same old bottleneck of 10 values/second. [face-palm]

So the quest continues, but this is clearly in the realm of Electron and nothing to do with csound-api. I appreciate all your help and all the work you've put into the API! Thanks very much,

Jason

nwhetsell commented 2 years ago

No worries!

I appreciate all your help and all the work you've put into the API!

Thank you!