huhamhire / node-co2-monitor

Node.JS library for reading CO2 concentration and indoor temperature from TFA Dostmann AirCO2NTROL Mini.
MIT License
16 stars 9 forks source link

LIBUSB_ERROR_BUSY #6

Open realwax opened 3 years ago

realwax commented 3 years ago

Hi,

I think some hotplug functionality changed on USB. There are warning when installing as well as crashes when using it. (using it in iobroker via javascript)

host.ioBrokerPIB32 2020-10-15 13:24:05.141 error instance system.adapter.javascript.2 terminated with code 1 (JS_CONTROLLER_STOPPED)
host.ioBrokerPIB32 2020-10-15 13:24:05.141 error Caught by controller[0]: at Transfer.transferDone (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:454:10)
host.ioBrokerPIB32 2020-10-15 13:24:05.141 error Caught by controller[0]: at InEndpoint.EventEmitter.emit (domain.js:482:12)
host.ioBrokerPIB32 2020-10-15 13:24:05.140 error Caught by controller[0]: at InEndpoint.emit (events.js:310:20)
host.ioBrokerPIB32 2020-10-15 13:24:05.140 error Caught by controller[0]: at Object.onceWrapper (events.js:416:28)
host.ioBrokerPIB32 2020-10-15 13:24:05.140 error Caught by controller[0]: at InEndpoint. (/opt/iobroker/node_modules/iobroker.javascript/node_modules/node-co2-monitor/co2_monitor.js:90:33)
host.ioBrokerPIB32 2020-10-15 13:24:05.139 error Caught by controller[0]: at Interface.attachKernelDriver (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:330:21)
host.ioBrokerPIB32 2020-10-15 13:24:05.138 error Caught by controller[0]: Error: LIBUSB_ERROR_BUSY
javascript.2 2020-10-15 13:24:04.099 error at Transfer.transferDone (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:454:10)
javascript.2 2020-10-15 13:24:04.099 error at InEndpoint.EventEmitter.emit (domain.js:482:12)
javascript.2 2020-10-15 13:24:04.099 error at InEndpoint.emit (events.js:310:20)
javascript.2 2020-10-15 13:24:04.099 error at Object.onceWrapper (events.js:416:28)
javascript.2 2020-10-15 13:24:04.099 error at InEndpoint. (/opt/iobroker/node_modules/iobroker.javascript/node_modules/node-co2-monitor/co2_monitor.js:90:33)
javascript.2 2020-10-15 13:24:04.099 error at Interface.attachKernelDriver (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:330:21)
javascript.2 2020-10-15 13:24:04.099 error (1829) Error: LIBUSB_ERROR_BUSY
javascript.2 2020-10-15 13:24:04.099 error (1829) Error: LIBUSB_ERROR_BUSY
javascript.2 2020-10-15 13:24:04.098 error (1829) An error happened which is most likely from one of your scripts, but the originating script could not be detected.
javascript.2 2020-10-15 13:24:04.091 error at Transfer.transferDone (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:441:9)
javascript.2 2020-10-15 13:24:04.091 error at InEndpoint.EventEmitter.emit (domain.js:482:12)
javascript.2 2020-10-15 13:24:04.091 error at InEndpoint.emit (events.js:310:20)
javascript.2 2020-10-15 13:24:04.091 error at InEndpoint. (/opt/iobroker/node_modules/iobroker.javascript/node_modules/node-co2-monitor/co2_monitor.js:127:34)
javascript.2 2020-10-15 13:24:04.091 error (1829) script.js.garden.CO2_Monitor_Gästezimmer: Error: Checksum Error.

pi@ioBrokerPIB32:/opt/iobroker $ npm install node-co2-monitor [..................] | loadIdealTree:loadAllDepsIntoIdealTree: sill install load [..................] - fetchMetadata: sill removeObsoleteDep removing nan@2.13.2

usb@1.6.3 install /opt/iobroker/node_modules/usb prebuild-install --verbose || node-gyp rebuild

prebuild-install info begin Prebuild-install version 5.3.3 prebuild-install info looking for cached prebuild @ /home/iobroker/.npm/_prebuilds/470134-usb-v1.6.3-node-v72-linux-arm.tar.gz prebuild-install http request GET https://github.com/tessel/node-usb/releases/download/v1.6.3/usb-v1.6.3-node-v72-linux-arm.tar.gz prebuild-install http 404 https://github.com/tessel/node-usb/releases/download/v1.6.3/usb-v1.6.3-node-v72-linux-arm.tar.gz prebuild-install WARN install No prebuilt binaries found (target=12.16.3 runtime=node arch=arm libc= platform=linux) make: Verzeichnis „/opt/iobroker/node_modules/usb/build“ wird betreten CC(target) Release/obj.target/libusb/libusb/libusb/core.o CC(target) Release/obj.target/libusb/libusb/libusb/descriptor.o CC(target) Release/obj.target/libusb/libusb/libusb/hotplug.o CC(target) Release/obj.target/libusb/libusb/libusb/io.o CC(target) Release/obj.target/libusb/libusb/libusb/strerror.o CC(target) Release/obj.target/libusb/libusb/libusb/sync.o CC(target) Release/obj.target/libusb/libusb/libusb/os/poll_posix.o CC(target) Release/obj.target/libusb/libusb/libusb/os/threads_posix.o CC(target) Release/obj.target/libusb/libusb/libusb/os/linux_usbfs.o CC(target) Release/obj.target/libusb/libusb/libusb/os/linux_udev.o AR(target) Release/obj.target/usb.a COPY Release/usb.a CXX(target) Release/obj.target/usb_bindings/src/node_usb.o ../src/node_usb.cc: In function ‘void handleHotplug(std::pair<libusb_device, libusb_hotplug_event>)’: ../src/node_usb.cc:151:58: warning: ‘v8::Local Nan::MakeCallback(v8::Local, const char, int, v8::Local)’ is deprecated [-Wdeprecated-declarations] Nan::MakeCallback(Nan::New(hotplugThis), "emit", 2, argv); ^ In file included from ../src/helpers.h:3:0, from ../src/node_usb.h:21, from ../src/node_usb.cc:1: ../node_modules/nan/nan.h:1001:46: note: declared here NAN_DEPRECATED inline v8::Local MakeCallback( ^~~~ CXX(target) Release/obj.target/usb_bindings/src/device.o ../src/device.cc: In static member function ‘static void Req::default_after(uv_work_t)’: ../src/device.cc:237:64: warning: ‘v8::Local Nan::MakeCallback(v8::Local, v8::Local, int, v8: :Local)’ is deprecated [-Wdeprecated-declarations] Nan::MakeCallback(device, Nan::New(baton->callback), 1, argv); ^ In file included from ../src/helpers.h:3:0, from ../src/node_usb.h:21, from ../src/device.cc:1: ../node_modules/nan/nan.h:959:46: note: declared here NAN_DEPRECATED inline v8::Local MakeCallback( ^~~~ CXX(target) Release/obj.target/usb_bindings/src/transfer.o ../src/transfer.cc: In function ‘void handleCompletion(Transfer)’: ../src/transfer.cc:126:72: warning: ‘v8::Local Nan::MakeCallback(v8::Local, v8::Local, int, v 8::Local*)’ is deprecated [-Wdeprecated-declarations] Nan::MakeCallback(self->handle(), Nan::New(self->v8callback), 3, argv); ^ In file included from ../src/helpers.h:3:0, from ../src/node_usb.h:21, from ../src/transfer.cc:1: ../node_modules/nan/nan.h:959:46: note: declared here NAN_DEPRECATED inline v8::Local MakeCallback( ^~~~ SOLINK_MODULE(target) Release/obj.target/usb_bindings.node COPY Release/usb_bindings.node make: Verzeichnis „/opt/iobroker/node_modules/usb/build“ wird verlassen npm WARN optional SKIPPING OPTIONAL DEPENDENCY: fsevents@~2.1.2 (node_modules/chokidar/node_modules/fsevents): npm WARN notsup SKIPPING OPTIONAL DEPENDENCY: Unsupported platform for fsevents@2.1.3: wanted {"os":"darwin","arch":"any"} (current: {"os":"linux","arch":"arm"})

Thank you

Cheers!

realwax commented 3 years ago

Dmesh output while using node-co2-monitor via javascripts adapter out of iobroker: 38.413305] usb 1-1.1.2: usbfs: process 639 (io.javascript.2) did not claim interface 0 before use

realwax commented 3 years ago

@slauber Wie besprochen - Danke falls Du Zeit hast!

realwax commented 3 years ago

Hi @huhamhire and @slauber ,

I had a look into the code though my skills aren't that good.

   // Open device to use control methods.
    this._device.open();
    this._interface = this._device.interfaces[0];
    // Detach linux kernel driver, or won't get endpoint connection.
    if (os.platform() === 'linux' && this._interface.isKernelDriverActive()) {
        this._interface.detachKernelDriver();
    }
    if (!this._interface) {

I see that you are doing a detach. I even modified the script for my Raspberry 3b and remove the if clause so a detach happens a 100%. Even with that I get:

host.ioBrokerPIB3 2020-10-29 10:05:48.954 error instance system.adapter.javascript.1 terminated with code 1 (JS_CONTROLLER_STOPPED)
host.ioBrokerPIB3 2020-10-29 10:05:48.953 error Caught by controller[1]: at Transfer.transferDone (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:454:10)
host.ioBrokerPIB3 2020-10-29 10:05:48.953 error Caught by controller[1]: at InEndpoint.EventEmitter.emit (domain.js:483:12)
host.ioBrokerPIB3 2020-10-29 10:05:48.952 error Caught by controller[1]: at InEndpoint.emit (events.js:314:20)
host.ioBrokerPIB3 2020-10-29 10:05:48.952 error Caught by controller[1]: at Object.onceWrapper (events.js:420:28)
host.ioBrokerPIB3 2020-10-29 10:05:48.951 error Caught by controller[1]: at InEndpoint. (/opt/iobroker/node_modules/iobroker.javascript/node_modules/node-co2-monitor/co2_monitor.js:90:33)
host.ioBrokerPIB3 2020-10-29 10:05:48.950 error Caught by controller[1]: at Interface.attachKernelDriver (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:330:21)
host.ioBrokerPIB3 2020-10-29 10:05:48.949 error Caught by controller[1]: Error: LIBUSB_ERROR_BUSY
javascript.1 2020-10-29 10:05:48.359 error (19545) Error: LIBUSB_ERROR_BUSY at Interface.attachKernelDriver (/opt/iobroker/node_modules/iobroker.javascript/node_modules/usb/usb.js:330:21) at InEndpoint. (/opt/iobroker/node_m
javascript.1 2020-10-29 10:05:48.358 error (19545) Error: LIBUSB_ERROR_BUSY
javascript.1 2020-10-29 10:05:48.356 error (19545) An error happened which is most likely from one of your scripts, but the originating script could not be detected.
javascript.1 2020-10-29 10:05:48.331 error (19545) script.js.climate.CO2_Monitor_Wohnzimmer: Error: LIBUSB_TRANSFER_STALL

So that would mean lib_usb fails with the detach itself? How can I move this forward? Debug further?

Thank you

realwax commented 3 years ago

As far I as got this seems to be an issue on Raspberry pi with node-usb and for them to solve https://github.com/tessel/node-usb/issues/392

realwax commented 3 years ago

@huhamhire May I kindly ask you to check this comment from @Apollon77 from the iobroker core team. He supported me in regard to the javascript adapter crash caused by node-co2-monitor in use of node-usb. Thank you! I also raised tickets at node-usb but no reply yet. Thank you!

Comment from: https://github.com/ioBroker/ioBroker.javascript/issues/710#issuecomment-725663994

In fact your "disconnect" call in the on(error) is the reason for the exception and in fact it is the co2 lib which cases the error because there is no error handled registered for "this._interface" in https://github.com/huhamhire/node-co2-monitor/blob/master/co2_monitor.js#L55 ... but even if there would be one no error would be emitted there ... so I commented one of the node-usb issues ..

realwax commented 3 years ago

As I removed monitor.disconnect(() on the errorhandling it stalls with a transfer stall but does not crash the javascript adapter but also does not reconnect.

Busyrev commented 2 years ago

Experiencing this error

Error: Checksum Error.
    at InEndpoint.<anonymous> (/home/pi/autohome/node_modules/node-co2-monitor/co2_monitor.js:127:34)
    at InEndpoint.emit (events.js:314:20)
    at Transfer.transferDone (/home/pi/autohome/node_modules/usb/usb.js:443:9)
FATAL ERROR:  LIBUSB_ERROR_BUSY
co2-sensor.service: Main process exited, code=killed, status=6/ABRT
co2-sensor.service: Failed with result 'signal'.

node-co2-monitor: 0.3.1, Raspbian GNU/Linux 11 (bullseye) node v12.22.5 raspberry 3b+

The service written by me and works nonstop, bun when co2 level grows over 2000 ppm it restarts several times (around 10), with same error, after that it works correctly and show results more than 2000, and than ppm drops down, around 2000 it falls again, around 10 times, and after that, works good. If 2000 ppm is not achieved it works for a weeks without any errors.

Busyrev commented 2 years ago

Logged data on up front:

2022-02-11 19:09:30, 1920
2022-02-11 19:09:34, 1925
2022-02-11 19:09:40, 1925
2022-02-11 19:09:44, 1929
2022-02-11 19:09:50, 1929
2022-02-11 19:09:54, 1934
2022-02-11 19:10:00, 1934
// 54 seconds of nothing, 10 restarts was here
2022-02-11 19:10:54, 2034
2022-02-11 19:11:00, 2034
2022-02-11 19:11:04, 2038
2022-02-11 19:11:10, 2038
2022-02-11 19:11:16, 2038
2022-02-11 19:11:20, 2038
2022-02-11 19:11:26, 2039
2022-02-11 19:11:30, 2039
2022-02-11 19:11:36, 2041

Logged data on down front:

2022-02-11 19:42:34,2023
2022-02-11 19:42:38,2023
2022-02-11 19:42:44,2019
2022-02-11 19:42:48,2019
// around 2 minutes of nothing, 22 restarts here
2022-02-11 19:44:44,1934
2022-02-11 19:44:50,1934
2022-02-11 19:44:54,1931
2022-02-11 19:45:00,1931

No idea what is it, but it`s totally 2000 ppm problem

realwax commented 2 years ago

@Busyrev I did some mitigation for myself in my script for logging co2 values inside javascript adapter inside iobroker. I noticed these "flaws" on only one unit after same time of usage. I could only help myself with restarting. Maybe if you are using a tostmann co2 meter you experience the same. Bottom line - some behaviour made these libs crash but it seems related to some unexpected faulty behavior as I experienced it only one unit.

Maybe my code helps - maybe not. (i am not a js coder ;) but i can help myself ;) )

` 'use strict'; const CO2Monitor = require('node-co2-monitor');

const monitor = new CO2Monitor();

var logOn = false; // Ausgabe der Messwerte im Log

var pfad = "co2sensor" + "."; // Pfad Systeminfos zur innovaphone

var idCo2 = pfad + "co2"; var idTemp = pfad + "temperatur";

// Datenpunkte anlegen // ----------------------------------------------------------------------------- createState(idCo2, { name: 'CO2', desc: 'CO2', type: 'number', unit: 'ppm', role: 'value' });

createState(idTemp, { name: 'Temperatur', desc: 'Temperatur', type: 'number', unit: '°C', role: 'value' });

// Connect device. monitor.connect((err) => { if (err) { return console.error(err.stack); } log('CO2 Monitor connected.');

// Read data from CO2 monitor.
monitor.transfer();

});

// Get results. try{ monitor.on('temp', (temperature) => { // log(temp: ${ temperature }); setState(idTemp,parseFloat(temperature)); }); } catch (e) { log (e); log("CO2 Monitor: USB Fehler"); }

try{ monitor.on('co2', (co2) => { // log(co2: ${ co2 }); setState(idCo2,parseInt(co2)); }); } catch (e) { log (e); log("CO2 Monitor: USB Fehler"); }

// Error handler monitor.on('error', (err) => { // console.error(err.stack); log("CO2 Monitor: USB Fehler - Selbst Neustart"); setStateDelayed("javascript.1.scriptEnabled.climate.CO2_Monitor_Wohnzimmer"/scriptEnabled.climate.CO2_Monitor_Wohnzimmer/, false, 500, false); setStateDelayed("javascript.1.scriptEnabled.climate.CO2_Monitor_Wohnzimmer"/scriptEnabled.climate.CO2_Monitor_Wohnzimmer/, true, 300000, false); // Disconnect device

// monitor.disconnect(() => { // log('CO2 Monitor disconnected.'); // process.exit(0); // }); });

function stopCo2Monitor() { try{ monitor._endpoint.stopPoll(function(){ log("CO2 Monitor: Polling gestoppt"); monitor._interface.release(true, (error) => { if(error) { monitor.emit('CO2 Monitor error', error); } else { log("CO2 Monitor: Interface released"); monitor._device.close(); log("CO2 Monitor: Device geschlossen"); cb(true); } }); }); } catch (e) { log(e); // hat nicht geklappt log("CO2 Monitor: Fehler beim Beenden des Skripts"); } log("CO2 Monitor: Skript wurde gestoppt"); }

schedule("1,6,11,16,21,26,31,36,41,46,51,56 ", async function () { if (parseFloat((new Date().getTime())) - parseFloat(getDateObject(getState("javascript.1.co2sensor.co2").ts).getTime()) > 200000) { log("CO2 Monitor: Selbst Neustart - Tostmann hängt..."); setStateDelayed("javascript.1.scriptEnabled.climate.CO2_Monitor_Wohnzimmer"/scriptEnabled.climate.CO2_Monitor_Wohnzimmer/, false, 5000, false); setStateDelayed("javascript.1.scriptEnabled.climate.CO2_Monitor_Wohnzimmer"/scriptEnabled.climate.CO2_Monitor_Wohnzimmer/, true, 8000, false); } });

// Wird ausgeführt, wenn das Skript gestoppt wird: // close connection if script stopped onStop(function skriptStop () { stopCo2Monitor(); // Kommunikation zum CO2 Monitor beenden }, 100 /ms/); `