random crashes during await Pool.acquire from an async function

[nmalenovic]

Hello @bsrdjan,

I get random crashes (or not) when executing await on Pool.acquire in an async function. I am running up-to-date Window 10 x64, latest SAP NWRFC SDK 7.50 PL6 (rfcexec.exe works correctly), latest node v14.5.0, and latest node-rfc module v1.2.0. I created a short crash3.js to demo the problem, and you can run it like this:

node crash3 & echo node process exit code: %errorlevel%

crash3.js:

// npm -g i rfc-node p-queue; npm link rfc-node p-queue

const rfc = require ('node-rfc');
const {default: PQueue} = require('p-queue');

const rfcPool = new rfc.Pool({ user: '...', passwd: '...', ashost: '...', sysid: '...', sysnr: '00', client: '100' });
const queue = new PQueue({concurrency: 3, autoStart: false});
var count = 0;

(async function() {
  for(i=0; i<10; ++i) {
    queue.add(async () => {
      const rfcClient = await rfcPool.acquire();
      const result = await rfcClient.call("STFC_STRUCTURE", { IMPORTSTRUCT: { RFCDATA1: ''+(++count) } });
      console.log("response: %s", result && result.IMPORTSTRUCT && result.IMPORTSTRUCT.RFCDATA1 ?
        result.IMPORTSTRUCT.RFCDATA1 : undefined);
      if (rfcClient && rfcPool) rfcPool.release(rfcClient); 
    });
  }
  queue.start();
  await queue.onIdle();
})();

When I don't use pooling but straight up Client, things work like a charm.

Here's npm install log:

C:\temp>npm -g i node-rfc --s
...
+ prebuild-install@5.3.5
+ prebuild@10.0.0
+ cmake-js@6.1.0
+ node-addon-api@3.0.1
updated 10 packages in 60.401s
+ node-rfc@1.2.0
updated 1 package in 70.571s

I've attached a crash3.txt output from multiple repeated runs showing randomness of crashes, exit codes, and output sequences if any.

thanks,

Nik

[bsrdjan]

Could you please test with v2.0 ? I tested only on Darwin, no errors.

If build from source complicated in your environment, I will can provide you a Windows binary.

[nmalenovic]

No worries @bsrdjan - it's nothing that choco install visualstudio2019buildtools --package-parameters "--allWorkloads --includeRecommended --includeOptional --passive --locale en-US" and choco install cmake --installargs 'ADD_CMAKE_TO_PATH=System' couldn't fix in a hurry.

Unfortunately v2.0's CMakeLists.txt assumes tar groks --force-local - Windows OS' tar.exe doesn't. build reports:

Downloading node-v14.5.0-headers.tar.gz to C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/build/node-v14.5.0-headers.tar.gz ...
tar: Option --force-local is not supported
...
CMake Error at CMakeLists.txt:74 (file):
  file RENAME failed to rename
...

I fork-fixed it by removing --force-local - please see submitted PR#154.

Here's a log of successful v2-pre build with PR#154:

C:\Temp>npm -g i github:nmalenovic/node-rfc#v2-pre-win1909buildfix --s
C:\Users\********\AppData\Roaming\npm\cmake-js -> C:\Users\********\AppData\Roaming\npm\node_modules\cmake-js\bin\cmake-js
C:\Users\********\AppData\Roaming\npm\prebuild -> C:\Users\********\AppData\Roaming\npm\node_modules\prebuild\bin.js
C:\Users\********\AppData\Roaming\npm\prebuild-install -> C:\Users\********\AppData\Roaming\npm\node_modules\prebuild-install\bin.js
+ prebuild@10.0.0
+ prebuild-install@5.3.5
+ node-addon-api@3.0.1
+ cmake-js@6.1.0
added 1 package from 61 contributors and updated 3 packages in 55.045s
[
  'C:\\Program Files\\nodejs\\node.exe',
  'C:\\Users\\********\\AppData\\Roaming\\npm\\node_modules\\cmake-js\\bin\\cmake-js',
  'rebuild'
]
info TOOL Using Visual Studio 16 2019 generator.
info CMD CLEAN
info RUN cmake -E remove_directory "C:\Users\********\AppData\Roaming\npm\node_modules\node-rfc\build"
info CMD CONFIGURE
info RUN cmake "C:\Users\********\AppData\Roaming\npm\node_modules\node-rfc" --no-warn-unused-cli -G"Visual Studio 16 2019" -A"x64" -DCMAKE_JS_VERSION="6.1.0" -DCMAKE_BUILD_TYPE="Release" -DCMAKE_RUNTIME_OUTPUT_DIRECTORY="C:\Users\********\AppData\Roaming\npm\node_modules\node-rfc\build" -DCMAKE_JS_INC="C:\Users\********\.cmake-js\node-x64\v14.5.0\include\node" -DCMAKE_JS_SRC="C:/Users/********/AppData/Roaming/npm/node_modules/cmake-js/lib/cpp/win_delay_load_hook.cc" -DNODE_RUNTIME="node" -DNODE_RUNTIMEVERSION="14.5.0" -DNODE_ARCH="x64" -DCMAKE_JS_LIB="C:\Users\********\.cmake-js\node-x64\v14.5.0\win-x64\node.lib" -DCMAKE_SHARED_LINKER_FLAGS="/DELAYLOAD:NODE.EXE"
Not searching for unused variables given on the command line.
-- Selecting Windows SDK version 10.0.18362.0 to target Windows 10.0.19041.
-- The C compiler identification is MSVC 19.26.28806.0
-- The CXX compiler identification is MSVC 19.26.28806.0
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Check for working C compiler: C:/Program Files (x86)/Microsoft Visual Studio/2019/BuildTools/VC/Tools/MSVC/14.26.28801/bin/Hostx64/x64/cl.exe - skipped
-- Detecting C compile features
-- Detecting C compile features - done
-- Detecting CXX compiler ABI info
-- Detecting CXX compiler ABI info - done
-- Check for working CXX compiler: C:/Program Files (x86)/Microsoft Visual Studio/2019/BuildTools/VC/Tools/MSVC/14.26.28801/bin/Hostx64/x64/cl.exe - skipped
-- Detecting CXX compile features
-- Detecting CXX compile features - done
SAP NWRFC SDK:
-- Configuring done
-- Generating done
-- Build files have been written to: C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/build
info CMD BUILD
info RUN cmake --build "C:\Users\********\AppData\Roaming\npm\node_modules\node-rfc\build" --config Release
Microsoft (R) Build Engine version 16.6.0+5ff7b0c9e for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.

  Checking Build System
  Building Custom Rule C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/CMakeLists.txt
  Client.cc
  clientio.cc
  Pool.cc
  Throughput.cc
  nwrfcsdk.cc
     Creating library C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/build/Release/sapnwrfc.lib and object C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/build/Release/sapnwrfc.exp
  Generating code
  Finished generating code
  sapnwrfc.vcxproj -> C:\Users\********\AppData\Roaming\npm\node_modules\node-rfc\build\Release\sapnwrfc.node
  C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/lib/binding/
  Building Custom Rule C:/Users/********/AppData/Roaming/npm/node_modules/node-rfc/CMakeLists.txt
+ node-rfc@2.0.0
added 3 packages from 63 contributors in 124.073s

C:\Temp>

and here's the updated code using v2 Pool with a lot more concurrency (as in infinite!):

// npm -g i github:nmalenovic/node-rfc#v2-pre-win1909buildfix p-queue; npm link rfc-node p-queue

const rfc = require ('node-rfc');
const {default: PQueue} = require('p-queue');

const rfcPool = new rfc.Pool({connectionParameters: { user: '***...*', passwd: '***...*', ashost: '***...*', sysid: '***', sysnr: '**', client: '***' }, 
  clientOptions: { stateless: true }, poolOptions: { low: 2, high: 5 }});
const queue = new PQueue({ autoStart: false }); // concurrency default Infinity
var count = 0;

(async function() {
  for(i=0; i<100; ++i) {
    queue.add(async () => {
      const rfcClient = await rfcPool.acquire();
      const result = await rfcClient.call("STFC_STRUCTURE", { IMPORTSTRUCT: { RFCDATA1: ''+(++count) } });
      console.log("response: %s", result && result.IMPORTSTRUCT && result.IMPORTSTRUCT.RFCDATA1 ? result.IMPORTSTRUCT.RFCDATA1 : undefined);
      if (rfcClient && rfcPool) rfcPool.release(rfcClient); 
    });
  }
  queue.start();
  await queue.onIdle();
})();

And here's the successful test run:

C:\Temp>node crash4 & echo node process exit code: %errorlevel%
response: 1
response: 2
response: 4
response: 3
response: 5
response: 6
response: 8
response: 7
response: 9
...
response: 100
node process exit code: 0

C:\Temp

Really thank you for your work on this library - one of the most useful things out there.

I am closing the issue as it's fixed in v2.