Jump to content

Welcome to Smart Home Forum by FIBARO

Dear Guest,

 

as you can notice parts of Smart Home Forum by FIBARO is not available for you. You have to register in order to view all content and post in our community. Don't worry! Registration is a simple free process that requires minimal information for you to sign up. Become a part of of Smart Home Forum by FIBARO by creating an account.

 

As a member you can:

  •     Start new topics and reply to others
  •     Follow topics and users to get email updates
  •     Get your own profile page and make new friends
  •     Send personal messages
  •     ... and learn a lot about our system!

 

Regards,

Smart Home Forum by FIBARO Team


Recommended Posts

Guest kallecux

Good Morning,

without an event i get this error:

Please login or register to see this code.

Do you have any hint.

Thanks!

 

 

Link to comment
Share on other sites

Today I noticed some 'dropped events', maybe due to slow mailbox. Is it possible to make the waiting time for response longer?

 

[DEBUG] 10:29:08: moln= 40

[DEBUG] 10:30:10: 2019-08-21 10:30:10.132214 [ error] timer handler failed with error: /opt/fibaro/scenes/401.lua:2317: No response from Node-red, '{"type":"wetter","_transID":"NR8611a10","_from":401}'
[DEBUG] 10:31:07: Slow mailbox watch:0.77033699999993s

[DEBUG] 10:31:08: moln= 40

 

[DEBUG] 10:59:08: moln= 40

[DEBUG] 11:00:10: 2019-08-21 11:00:10.164607 [ error] timer handler failed with error: /opt/fibaro/scenes/401.lua:2317: No response from Node-red, '{"type":"wetter","_transID":"NR86035a8","_from":401}'
[DEBUG] 11:01:07: Slow mailbox watch:0.76986600000009s

[DEBUG] 11:01:08: moln= 40
 

Link to comment
Share on other sites

  • Topic Author
  • 13 hours ago, kallecux said:

    Good Morning,

    without an event i get this error:

    Please login or register to see this code.

    Do you have any hint.

    Thanks!

     

    I guess you have setup Hue devices? You do Hue.monitor(...) ? 

    Try _debugFlags.hue=true to see what it is doing and maybe get a debug closer to the error happening.

    Link to comment
    Share on other sites

    Guest kallecux

     

    @jgab

    Yes i monitor in this way:

     

    Hue.monitor(12010,12020,12030,3000)

     

    and now i found the error by myself.

     

    The correct way is:   Hue.monitor({12010,12020,12030},3000)

     

    Edited by kallecux
    Link to comment
    Share on other sites

  • Topic Author
  • On 8/21/2019 at 11:22 AM, FrankT said:

    Today I noticed some 'dropped events', maybe due to slow mailbox. Is it possible to make the waiting time for response longer?

     

    [DEBUG] 10:29:08: moln= 40

    [DEBUG] 10:30:10: 2019-08-21 10:30:10.132214 [ error] timer handler failed with error: /opt/fibaro/scenes/401.lua:2317: No response from Node-red, '{"type":"wetter","_transID":"NR8611a10","_from":401}'
    [DEBUG] 10:31:07: Slow mailbox watch:0.77033699999993s

    [DEBUG] 10:31:08: moln= 40

     

    [DEBUG] 10:59:08: moln= 40

    [DEBUG] 11:00:10: 2019-08-21 11:00:10.164607 [ error] timer handler failed with error: /opt/fibaro/scenes/401.lua:2317: No response from Node-red, '{"type":"wetter","_transID":"NR86035a8","_from":401}'
    [DEBUG] 11:01:07: Slow mailbox watch:0.76986600000009s

    [DEBUG] 11:01:08: moln= 40
     

     

    The default timeout is 5s for Nodered calls which is quite long so I would suspect that call fails on the nodered side - can you see if you get any response in the log on nodered?

    You can increase the timeout to 10s by setting _options.NODEREDTIMEOUT=10000 before main().

    The "slow mailbox" is a warning that the main loop of ER is not fast enough  to poll for incoming events. In your case it's ~0.77s between polls and the normal condition is that it should manage to poll for incoming events every ~250ms. The reason for this is usually that the rest of the ER scene is busy running rules etc leaving little time for the main loop. ( When you don't see the message it means we are back to 250ms again)

    Calls to nodered are asynchronous calls that should give ample time to the main loop to poll for events while waiting for a response so I don't feel that there is a strong connection between your errors - unless something have changed in how the HC2 is doing http requests in the recent FWs. 

    I'm a bit busy these days but I will try to find some time to do some tests on the HC2 and see if I can reproduce it.

    The "dropped events" message I talked about is the "Couldn't post event (dead?), dropping:..." message, that means that the main loop is so busy it can't process messages at all and the incoming "event buffer" is full and we start to discard events. That is often bad and usually mean that the main event loop has crashed,.

    Link to comment
    Share on other sites

    On ‎8‎/‎24‎/‎2019 at 9:28 AM, jgab said:

     

    The default timeout is 5s for Nodered calls which is quite long so I would suspect that call fails on the nodered side - can you see if you get any response in the log on nodered?

    You can increase the timeout to 10s by setting _options.NODEREDTIMEOUT=10000 before main().

    The "slow mailbox" is a warning that the main loop of ER is not fast enough  to poll for incoming events. In your case it's ~0.77s between polls and the normal condition is that it should manage to poll for incoming events every ~250ms. The reason for this is usually that the rest of the ER scene is busy running rules etc leaving little time for the main loop. ( When you don't see the message it means we are back to 250ms again)

    Calls to nodered are asynchronous calls that should give ample time to the main loop to poll for events while waiting for a response so I don't feel that there is a strong connection between your errors - unless something have changed in how the HC2 is doing http requests in the recent FWs. 

    I'm a bit busy these days but I will try to find some time to do some tests on the HC2 and see if I can reproduce it.

    The "dropped events" message I talked about is the "Couldn't post event (dead?), dropping:..." message, that means that the main loop is so busy it can't process messages at all and the incoming "event buffer" is full and we start to discard events. That is often bad and usually mean that the main event loop has crashed,.

    I found out that the problem is in the call to processAll() and can not see a solution. A single call to processOne() does not give this problem.

     

    deviceList =
    {
     temperature = { Altandorrtemp = 85, AltanTemp = 14, 
        ForradsdorrTemp = 231, Balkondorr = 371, Friggebod = 387 },
     energy = { TV = 290},
     motion = { PirAltan = 13, PirTrappa = 439},
     door = { BalkongSov = 370,  AltanVrum = 84, Entre = 92, Tvatt = 34, 
        Forrad = 230, Friggebod = 386},
     light = { Arbetsrum = 309, LillaSovr = 317 },
     markiser = {Sovrum = 262, TVrum = 252, LillaSovrum = 249, Screen = 276, Altanscreen = 467}
    }

    local MAP={}
      local function map(t,r)
        r = r or {}
        if type(t)=='number' then MAP[t]=r
        else for k,v in pairs(t) do map(v,{k,r}) end end
      end
      map(deviceList)

      function processOne(deviceID)
        local d = MAP[deviceID]
        local deviceName = d[1]
        local deviceClass = d[2][1]
        if deviceClass == 'energy' then 
          data = fibaro:getValue(deviceID,'power')
          if fibaro:getModificationTime(deviceID,'power') == nil then
            lastuse = 0
          else 
            lastuse = fibaro:getModificationTime(deviceID,'power')
          end  
        else
          data = fibaro:getValue(deviceID,'value')
          if fibaro:getModificationTime(deviceID,'value') == nil then
            lastuse = 0
          else 
            lastuse = fibaro:getModificationTime(deviceID,'value')
          end  
        end
        if data == 'false' then data = "0" end
        data = tonumber(data)
        Nodered.post{type='device',class=deviceClass, name=deviceName, id=deviceID, data=data, last1 = lastuse}
      end
      
      function processAll()
        for deviceID,_ in pairs(MAP) do processOne(deviceID) end
      end
      
     
      rule("sensors={13,370,84,92,34,230,386,439}")
      rule("sensors:breached => d=env.event.deviceID;processOne(d)") -- för registrering i influxdb 
      rule("@@00:02:00 => processAll()")  --lagra alla värden från devicelistan i influxdb via NodeRed------------------------

     

    Link to comment
    Share on other sites

  • Topic Author
  • On 8/28/2019 at 12:36 PM, FrankT said:

    I found out that the problem is in the call to processAll() and can not see a solution. A single call to processOne() does not give this problem.

     

    deviceList =
    {
     temperature = { Altandorrtemp = 85, AltanTemp = 14, 
        ForradsdorrTemp = 231, Balkondorr = 371, Friggebod = 387 },
     energy = { TV = 290},
     motion = { PirAltan = 13, PirTrappa = 439},
     door = { BalkongSov = 370,  AltanVrum = 84, Entre = 92, Tvatt = 34, 
        Forrad = 230, Friggebod = 386},
     light = { Arbetsrum = 309, LillaSovr = 317 },
     markiser = {Sovrum = 262, TVrum = 252, LillaSovrum = 249, Screen = 276, Altanscreen = 467}
    }

    local MAP={}
      local function map(t,r)
        r = r or {}
        if type(t)=='number' then MAP[t]=r
        else for k,v in pairs(t) do map(v,{k,r}) end end
      end
      map(deviceList)

      function processOne(deviceID)
        local d = MAP[deviceID]
        local deviceName = d[1]
        local deviceClass = d[2][1]
        if deviceClass == 'energy' then 
          data = fibaro:getValue(deviceID,'power')
          if fibaro:getModificationTime(deviceID,'power') == nil then
            lastuse = 0
          else 
            lastuse = fibaro:getModificationTime(deviceID,'power')
          end  
        else
          data = fibaro:getValue(deviceID,'value')
          if fibaro:getModificationTime(deviceID,'value') == nil then
            lastuse = 0
          else 
            lastuse = fibaro:getModificationTime(deviceID,'value')
          end  
        end
        if data == 'false' then data = "0" end
        data = tonumber(data)
        Nodered.post{type='device',class=deviceClass, name=deviceName, id=deviceID, data=data, last1 = lastuse}
      end
      
      function processAll()
        for deviceID,_ in pairs(MAP) do processOne(deviceID) end
      end
      
     
      rule("sensors={13,370,84,92,34,230,386,439}")
      rule("sensors:breached => d=env.event.deviceID;processOne(d)") -- för registrering i influxdb 
      rule("@@00:02:00 => processAll()")  --lagra alla värden från devicelistan i influxdb via NodeRed------------------------

     

     

    This was a tricky bug. It seems like Nodered is sending events too fast back to the HC2 (using the HC2 API) that the HC2 drops events.

    I haven't seen that before so this was new. The only solution I can think of now is to add a delay. 

    We can't use fibaro:sleep in ER so we need to use EventScript for the loop.

    Please login or register to see this code.

    You have to make MAP non-local so that the script can access it,

    See if this works - I need to think if there is a better way to fix this,.

    Link to comment
    Share on other sites

    12 hours ago, jgab said:

     

    This was a tricky bug. It seems like Nodered is sending events too fast back to the HC2 (using the HC2 API) that the HC2 drops events.

    I haven't seen that before so this was new. The only solution I can think of now is to add a delay. 

    We can't use fibaro:sleep in ER so we need to use EventScript for the loop.

    Please login or register to see this code.

    You have to make MAP non-local so that the script can access it,

    See if this works - I need to think if there is a better way to fix this,.

    Working now. I was on the same track but couldn't get this Rule.eval("for id,_ in pairs(MAP) do processOne(id); wait(0.2) end") right. Thank you Jan.

    But I still wonder, it is the same scene I had previously with ER V2. I only changed to V3 and Fibaro 4.550, no changes in NodeRed at all.

    Link to comment
    Share on other sites

  • Topic Author
  • 1 hour ago, FrankT said:

    Working now. I was on the same track but couldn't get this Rule.eval("for id,_ in pairs(MAP) do processOne(id); wait(0.2) end") right. Thank you Jan.

    But I still wonder, it is the same scene I had previously with ER V2. I only changed to V3 and Fibaro 4.550, no changes in NodeRed at all.

    Hmm, also a bit unsure that this is the real problem. I did my stress-test with the "echo" flow when I saw that Nodered dropped messages when sending responses quickly to the HC2.

    However, in your case you just send events to Nodered and don't want any response.

    It seems like no matter how fast I send events from the HC2 to Nodered they all always arrive at Nodered.

     

    In your original log you get

    "No response from Node-red, '{"type":"wetter","_transID":"NR8611a10","_from":401}'"

    and that is only if you do a synchronous post, Nodered.post(<event>,true), second argument to post is 'true'.

    In that case the HC2 will wait for a reponse event from Nodered and if that doesn't arrive in time will log an 'timeout'.

    But you don't do that in the example code so I don't understand how that happens.

     

    How does your Nodered flow look like?

    Link to comment
    Share on other sites

    4 hours ago, jgab said:

    Hmm, also a bit unsure that this is the real problem. I did my stress-test with the "echo" flow when I saw that Nodered dropped messages when sending responses quickly to the HC2.

    However, in your case you just send events to Nodered and don't want any response.

    It seems like no matter how fast I send events from the HC2 to Nodered they all always arrive at Nodered.

     

    In your original log you get

    "No response from Node-red, '{"type":"wetter","_transID":"NR8611a10","_from":401}'"

    and that is only if you do a synchronous post, Nodered.post(<event>,true), second argument to post is 'true'.

    In that case the HC2 will wait for a reponse event from Nodered and if that doesn't arrive in time will log an 'timeout'.

    But you don't do that in the example code so I don't understand how that happens.

     

    How does your Nodered flow look like?

    But #wetter, the second argument ist 'true' , see the rule below.

     

    rule("@@00:01 => moln = Nodered.post(#wetter{},true).data.clouds; lb = tonumber(luxb:value); lf = tonumber(luxf:value); m1=tonumber(screen:value); m2=tonumber(sovm:value); m3=tonumber(tvm:value); m4=tonumber(extram:value);  m2=tonumber(sovm:value); m3=tonumber(tvm:value); m4=tonumber(extram:value); m5=tonumber(altanm:value)") 

    Please login or register to see this attachment.

    Link to comment
    Share on other sites

  • Topic Author
  • 14 hours ago, FrankT said:

    But #wetter, the second argument ist 'true' , see the rule below.

     

    rule("@@00:01 => moln = Nodered.post(#wetter{},true).data.clouds; lb = tonumber(luxb:value); lf = tonumber(luxf:value); m1=tonumber(screen:value); m2=tonumber(sovm:value); m3=tonumber(tvm:value); m4=tonumber(extram:value);  m2=tonumber(sovm:value); m3=tonumber(tvm:value); m4=tonumber(extram:value); m5=tonumber(altanm:value)") 

    Please login or register to see this attachment.

     

    You are right. It's the "rule("@@00:01 => moln = Nodered.post(#wetter{},true).data.clouds;..." that's causes the timeout.

    So, just to be clear:

    1. Every 2 minutes you send data to nodered for some devices.No return value.

    2. Every 1 minute you send a 'wetter' request to nodered and get a value back (synchronous).

    3.1 If you do 'processAll' connected to (1) you got a timeout in the request connected to (2)

    3.2 If you only do 'processOne' connected to (1) you don't get a timeout in the request connected to (2)

    3.3 When you introduced a wait in processAll connected to (1) you also don't get a timeout in the request connected to (2)

     

    I tried to reproduce this and I can't get the timeout - however I use the 'echo' flow as I don't have wetter. Would you expect that 'wetter' can be slow to respond? Did you try to increate the Nodered timeout?

    Link to comment
    Share on other sites

    3 hours ago, jgab said:

     

    You are right. It's the "rule("@@00:01 => moln = Nodered.post(#wetter{},true).data.clouds;..." that's causes the timeout.

    So, just to be clear:

    1. Every 2 minutes you send data to nodered for some devices.No return value.

    2. Every 1 minute you send a 'wetter' request to nodered and get a value back (synchronous).

    3.1 If you do 'processAll' connected to (1) you got a timeout in the request connected to (2)

    3.2 If you only do 'processOne' connected to (1) you don't get a timeout in the request connected to (2)

    3.3 When you introduced a wait in processAll connected to (1) you also don't get a timeout in the request connected to (2)

     

    I tried to reproduce this and I can't get the timeout - however I use the 'echo' flow as I don't have wetter. Would you expect that 'wetter' can be slow to respond? Did you try to increate the Nodered timeout?

    I did increase the NodeRed timeout by setting _options.NODEREDTIMEOUT=10000 but did not help. Then I moved NodeRed, Influx and Grafana to a faster Raspberry PI4 with 2 Gb. Did not help either.

     

    1. processOne sends the value of one sensor which triggered (%%properties) NodeRed for storing in Influxdb

    2. processAll sends the values of all sensors to NodeRed for storing in Influxdb

    3. #wetter receives the weather data from the NodeRed OWM-node and uses the cloud data 

     

    I have been running the scene now for some hours WITHOUT the delay

    function processAll()
       -- Rule.eval("for id,_ in pairs(MAP) do processOne(id); wait(0.2) end")
        Rule.eval("for id,_ in pairs(MAP) do processOne(id) end")
      end

    without this message "No response from Node-red, '{"type":"wetter","_transID":"NR8611a10","_from":401}'" , but again "Slow mailbox watch:0.80662s". So the #wetter problem seems to have gone, but still the problem with 'Slow mailbox'.

    So I think the problem is not the #wetter (OWM node) but processAll via processOne sending data to NodeRed to fast? But there are no error messages in NR, it seems NR does process all data without loosing any.

     

     

     

    Link to comment
    Share on other sites

  • Topic Author
  • 8 minutes ago, FrankT said:

    I did increase the NodeRed timeout by setting _options.NODEREDTIMEOUT=10000 but did not help. Then I moved NodeRed, Influx and Grafana to a faster Raspberry PI4 with 2 Gb. Did not help either.

     

    1. processOne sends the value of one sensor which triggered (%%properties) NodeRed for storing in Influxdb

    2. processAll sends the values of all sensors to NodeRed for storing in Influxdb

    3. #wetter receives the weather data from the NodeRed OWM-node and uses the cloud data 

     

    I have been running the scene now for some hours WITHOUT the delay

    function processAll()
       -- Rule.eval("for id,_ in pairs(MAP) do processOne(id); wait(0.2) end")
        Rule.eval("for id,_ in pairs(MAP) do processOne(id) end")
      end

    without this message "No response from Node-red, '{"type":"wetter","_transID":"NR8611a10","_from":401}'" , but again "Slow mailbox watch:0.80662s". So the #wetter problem seems to have gone, but still the problem with 'Slow mailbox'.

    So I think the problem is not the #wetter (OWM node) but processAll via processOne sending data to NodeRed to fast? But there are no error messages in NR, it seems NR does process all data without loosing any.

     

    Yes, Nodered gets all the messages in al my tests too. However, processOne will not cause a timeout, only the 'wetter' call as it is synchronous so ER will wait for an answer.

     I would keep the 'wait' in processAll as it gives time to the other rules to run (and also give time to the mailbox watch loop).

    Most ER rules are fairly short of type "<trigger> => <action>", but if we start to do more complex ER rules that that takes time it is always good to insert a wait() to not starve the other rules.

    I have pushed V3 B62 that hopefully avoids the slow mailbox message at startup.

    Link to comment
    Share on other sites

    Good morning Jan,

    Is it possible to add Hue.define also in HT?

    Now I have all the HUE lights in one scene and that is not so comfortable, if I want to put them in the scene where they belong I need to ad Hue.define in 3 ER scenes.

    Please advice,

    //Sjakie

    Link to comment
    Share on other sites

  • Topic Author
  • 1 hour ago, Sjakie said:

    Good morning Jan,

    Is it possible to add Hue.define also in HT?

    Now I have all the HUE lights in one scene and that is not so comfortable, if I want to put them in the scene where they belong I need to ad Hue.define in 3 ER scenes.

    Please advice,

    //Sjakie

    There are various ways to make it easier.

    One way is to have a HT with the mapping between Hue names and deviceIDs numbers. Then it' s just a one-line "for loop" to define up the Hue lights.

    Please login or register to see this code.

    I'm looking into how to break out the Hue code to a separate scene (a single place to define them) and leverage the remote events and remote function calls to integrate them in other scenes.

    That way we don't need to poll the Hue lights from multiple scenes, which is a bit wasteful.

    Link to comment
    Share on other sites

    Good morning Jan,

    Just for your information I see also slow mailbox popping up.

    I dont think it will harm me.

     

    Please login or register to see this attachment.

    Link to comment
    Share on other sites

    Jan,

    Is this related? Have never seen this error before.

     

    Please login or register to see this attachment.

     

    Link to comment
    Share on other sites

    Good morning Jan,

    Old error back?

    In Supervisor its not mentioned!

     

    Please login or register to see this attachment.

    Link to comment
    Share on other sites

  • Topic Author
  • 23 hours ago, Sjakie said:

    Jan,

    Is this related? Have never seen this error before.

     

    Please login or register to see this attachment.

     

     

    This means that a Nodered.post(...) call failed. Could be various reasons but somehow the platform where you run Nodered isn't responding.

    Link to comment
    Share on other sites

    Jan,

    mmh probally you are right because in NR there was nothing listed at all. This scene is my arming scene.

    I will convert all Sonos into usage of VD so I dont need NR in this scene and avoid errors..

    I use Sonos here to change volume, play and stop in case of alarm

    Can you refresh my mind cmd in ER to set slider in %?

    445:btn=3 is stop

    Thanks in advance

    Link to comment
    Share on other sites

    Join the conversation

    You can post now and register later. If you have an account, sign in now to post with your account.

    Guest
    Reply to this topic...

    ×   Pasted as rich text.   Paste as plain text instead

      Only 75 emoji are allowed.

    ×   Your link has been automatically embedded.   Display as a link instead

    ×   Your previous content has been restored.   Clear editor

    ×   You cannot paste images directly. Upload or insert images from URL.

    ×
    ×
    • Create New...