Espeasy: event->TaskIndex not correctly initialized during PLUGIN_WRITE state

[thomastech]

If you self compile, please state this and PLEASE try to ONLY REPORT ISSUES WITH OFFICIAL BUILDS!

Self Compile Build using latest Official GitHub Release. Build type: test_ESP8266_4M1M_VCC

Summarize of the problem/feature request

The event->TaskIndex value is not correct during the PLUGIN_WRITE state. It works fine in the other PLUGIN_ states.

The reason this is an issue is because it makes it impossible to get settings that rely on the TaskIndex in the PLUGIN_WRITE state. For example, I would like to check Settings.TaskDeviceEnabled[ ]. No problem doing that in the other PLUGIN_ states, just the PLUGIN_WRITE state is broken.

Expected behavior

The event->TaskIndex should contain the index value that is the plugin device's task entry number. For example, the second task in the webform device listing should be: event->TaskIndex = 1.

Actual behavior

In the PLUGIN_WRITE state, event->TaskIndex does not contain the correct value. Normally 0-11 are allowed values, but is usually set to 12. BTW, one time I saw it set to 0.

Steps to reproduce

1. Pick a plugin that performs commands. For example, _P079_Wemos_Motorshield.ino
2. Add the following code directly after the "_case PLUGIN_WRITE:_ " statement:
   addLog(LOG_LEVEL_INFO, String(F("TaskIndex = ")) + String(event->TaskIndex));
3. Install the modified plugin at the second task location (task # 2). Do not install as the first task.
   Disable the plugin, then save.
4. Send a command to the plugin.
5. Check the event->TaskIndex value in the logs. The value will be incorrect.
   {If the value is correct then move the plugin to another task location and test again.}

• Thomas

[thomastech]

I quickly scanned InternalCommands.cpp and found something interesting. At line 394:

 // FIXME TD-er: Not sure what happens now, but TaskIndex cannot always be set here
  // since commands can originate from anywhere.

Regardless, perhaps there's a workaround? That is to say, can I determine the task number some other way, other than relying on event->TaskIndex value?

• Thomas

[TD-er]

Well a quick hack can be to search the list for the first enabled task with the pluginID you're looking for and just use that one.
That's what's also done for some controllers and maybe also some other plugins. (see findFirstEnabledControllerWithId for the Controller's equivalent)

This can then be fixed along with this PR: https://github.com/letscontrolit/ESPEasy/pull/3198

[TD-er]

Hmm I'm missing the label "Hack required to fix"

[thomastech]

Thanks for the tip. I'll look into using the findFirstEnabledControllerWithId workaround.

• Thomas

[thomastech]

I solved my problem. My goal was to post a webform message (and log an error) whenever the user tried to send a command to a disabled plugin.

My workaround: I added a flag that holds the plugin's enable/disable state. The flag's state is managed by the PLUGIN_INIT and PLUGIN_WEBFORM_SAVE functions. PLUGIN_WRITE checks the flag and warns the user that their commands cannot be executed whenever the plugin is disabled.

BTW, I also found that other PLUGIN_ states are affected too. But most importantly, I found that the event->TaskIndex value is correct when a plugin is enabled. But if the plugin is disabled the value defaults to TASKS_MAX (12). This gets in the way of checking the plugin's Settings.TaskDeviceEnabled[ ] value.

But in retrospect, I think I should have created a different GitHub issue ticket. The underlying problem is that disabled plugins continue to process PLUGIN_WRITE commands. Instead, disabled plugins should ignore them.

Do I need to create a new issue ticket for this?

• Thomas

[tonhuisman]

Hmm, in Plugins.cpp, line 336 there is this check: if (Settings.TaskDeviceEnabled[taskIndex] ... and I took that to #3198, so I'm quite surprised that the plugin's _WRITE function is called when disabled 😮
Also, on line 343 in that source, the TaskIndex value is set for the event struct that is passed to that plugin call, so that's another surprise it's not set as expected...
So it looks like the PLUGIN_WRITE function is called from some other piece of code, but I haven't found that yet.

[TD-er]

Well for the validity of the taskIndex, we have a function: validTaskIndex

See also this code also mentioned by @tonhuisman

https://github.com/letscontrolit/ESPEasy/blob/354e8af0c1704e19288d86d94b97e9cd95ee9ae1/src/src/Globals/Plugins.cpp#L330-L342

As you can see, it never crosses the boundaries of the TaskDeviceEnabled array, or any other with a size based on TASKS_MAX
Also there is a check to see if it is enabled and also if the set task (in the settings file) refers to a plugin that's included in the current build.

[thomastech]

That for-loop function seems to be related to servicing all the installed plugins. It definitely ensures the taskIndex is correctly initialized.

But my issue involves unscheduled PLUGIN_WRITEs. That is to say, I'm sending a command to the plugin via ESPEasy Command console and also by http. So the for-loop example shown above is not involved.

Edit: Rules also exhibit the problem when the plugin is disabled (taskIndex = TASKS_MAX). The value is correct when the plugin is enabled.

• Thomas

[TD-er]

Then I'm really curious to what function you call for the command execution.
Command execution should in the end be handled by ExecuteCommand

Search for bool ExecuteCommand(taskIndex_t taskIndex, EventValueSource::Enum source, const char *Line, bool tryPlugin, bool tryInternal, bool tryRemoteConfig)

[thomastech]

Then I'm really curious to what function you call for the command execution.

I suggest following my "Steps to reproduce" in the first post. You will be able to witness that event->TaskIndex is set to TASKS_MAX when the plugin is disabled, but is fine when it is enabled.

And if you put a few meaningful log statements in the PLUGIN_WRITE section you will also see that Commands are still passed to a disabled plugin. This can cause interesting behavior.

I've noticed that plugins that are not installed will still accept commands. For example, I don't use the P052_SenseAir plugin and have never installed it. But I can execute the "senseair_setrelay" command (from http or command console) and I see the "Ok" reply. Which means the command was received and processed (success flag set). However, I would argue that when a plugin is disabled (or not installed) it should reply "Command unknown" (or some other warning) and ignore the command.

BTW, I changed my workaround and now the PLUGIN_WRITE section checks event->TaskIndex. If its value = TASKS_MAX the commands are not processed since it means the plugin is disabled. I plan to remove all my workaround hacks after the problem is resolved.

EDIT:

Search for bool ExecuteCommand(taskIndex_t taskIndex, EventValueSource::Enum source, const char *Line, bool tryPlugin, bool tryInternal, bool tryRemoteConfig)

Not that it means anything, but that circles back to my earlier observation about line 394 in the ExecuteCommand function:

// FIXME TD-er: Not sure what happens now, but TaskIndex cannot always be set here
  // since commands can originate from anywhere.

We're at a inner working level of ESPEasy that is beyond my pay grade. At this point I'm about as helpful as a monkey throwing poop at the bystanders. Hopefully that changes, but for now don't wear your good shirt around me.

• Thomas

[TD-er]

At this point I'm about as helpful as a monkey throwing poop at the bystanders. Hopefully that changes, but for now don't wear your good shirt around me.

With sentences like these I know Thomas is in da house again 👍

I will be away most of the day today, but I guess I will have a look later this evening as I'm almost out of clean shirts anyway.

[thomastech]

@TD-er, I recommend a good soaking in strong bleach. Both you and the shirt.

I don't know if you recall it, but we worked on a VERY similar bug two years ago. Back then I complained about how ExtraTaskSettings.TaskDeviceName was sometimes wrong in PLUGIN_WRITE.
https://github.com/letscontrolit/ESPEasy/issues/1574

But in reviewing the old dialog, I also see that I mentioned event->TaskIndex was unreliable in PLUGIN_WRITE. Here are the words that have come back to haunt me:

Unfortunately the event->TaskIndex var can't be trusted either since it suffers the same issue as ExtraTaskSettings.TaskDeviceName.

You (TD-er) spent a lot of time helping me out. But the underlying problem went unsolved. I eventually coded around the problem with a roll of duct tape. BTW, that's when the previously mentioned "FIXME TD-er" comment was added to the ExecuteCommand( ) code.

So PLUGIN_WRITE has been a bad boy for a very long time.

• Thomas

[thomastech]

Put on your good shirts! I have some info about the problem. But I don't want to break anything, so I'll share what I know so it can be fixed by the experts.

Here's the code snippet that needs some attention.

https://github.com/letscontrolit/ESPEasy/blob/354e8af0c1704e19288d86d94b97e9cd95ee9ae1/src/src/Globals/Plugins.cpp#L361-L371

Directly before this code there's another loop that performs orderly calls to all the _enabled_ plugin tasks. No complaints there, that code works fine. But then execution moves to the loop shown in the code block above. That's where the problem occurs.

This code loops through all plugin modules, even if they are not enabled. It executes PLUGIN_WRITE or PLUGIN_REQUEST on each plugin. I'm a bit confused why it needs to act on PLUGIN_WRITE, especially if the task is disabled.

Two things that need some investigation by the ESPEasy wizards:

1. The _event_ struct is not correctly initialized. For example, event->TaskIndex is incorrectly set to TASKS_MAX due to the struct's state after exiting from the previous loop.

2. Shouldn't this loop be limited to PLUGIN_REQUEST? That makes the most sense to me, but I'm still dizzy from the bleach.

EDIT: I wrapped the code section with this:

if(Function == PLUGIN_REQUEST) {
}

Now PLUGIN_WRITE works correctly. But there's a lot I don't know about ESPEasy's inner workings. So I've probably broken something related to a controller. Or maybe not.

• Thomas

[TD-er]

I will have a look at it this evening.
The function does look innocent at first sight as it only seems to call the (controller) plugin_acknowledge.
As it is a controller call, it may not know a TaskIndex, but it should not call (from the controller) any plugin that isn't enabled.

[tonhuisman]

It's the if at line 365 that is calling the plugin unconditionally, that'll need an extra condition, and the TaskIndex fixed I think. If it should be called for PLUGIN_WRITE...

[thomastech]

The intended purpose of the code is a mystery to me. It ignores the task list and instead checks ALL the plugins in the firmware build. Even if the plugin is not installed as a task. Seems like an odd thing to do.

Most importantly, the controller acknowledge is handled by the previous loop at line 354. So at face value this block of code appears redundant and unnecessary. But the comment says "_FIXME TD-er: work-around as long as gpio command is still performed in P001_switch._" So it seems to have some secondary purpose that is not immediately clear to a casual bystander.

• Thomas

[TD-er]

Or maybe has become obsolete by some other (recent) change...

[thomastech]

The another thing learned by this discovery is now I know why I can successfully send commands to plugins that aren't installed as a task. But now that strange behavior can be fixed.

• Thomas

[TD-er]

Hmm I am afraid it may be too late already to warn you....
You may already be hooked by the core of ESPEasy.

As the Eagles already tried to warn you... "you can check out but never leave"

[thomastech]

I said:

The intended purpose of the code is a mystery to me. It ignores the task list and instead checks ALL the plugins in the firmware build. Even if the plugin is not installed as a task. Seems like an odd thing to do.

After digging around I found a detailed explanation for it, courtesy of @TD-er .
https://github.com/letscontrolit/ESPEasy/issues/2712#issuecomment-549294948

Hmm I am afraid it may be too late already to warn you.... You may already be hooked by the core of ESPEasy.

Resistance if futile.

• Thomas

[TD-er]

Hmm that may partly be obsolete as it is now split (a bit) to command parsing is now split in plugin calls, internal calls and external calls.
Will have a look tomorrow, if I'm a bit more clear.
Last few days were a bit busy... But they got a new World Record (improved with ~20%) :) at Delsbo Electric.
So it was worth it.

[TD-er]

Hmm it took me a while to understand what you were writing @thomastech but I think I now understand...

    // Call to all plugins. Return at first match
    case PLUGIN_WRITE:
    case PLUGIN_REQUEST:
    {
      for (taskIndex_t taskIndex = 0; taskIndex < TASKS_MAX; taskIndex++)
      {
        if (Settings.TaskDeviceEnabled[taskIndex] && validPluginID_fullcheck(Settings.TaskDeviceNumber[taskIndex]))
        {
          if (Settings.TaskDeviceDataFeed[taskIndex] == 0) // these calls only to tasks with local feed
          {
            const deviceIndex_t DeviceIndex = getDeviceIndex_from_TaskIndex(taskIndex);

            if (validDeviceIndex(DeviceIndex)) {
              TempEvent.setTaskIndex(taskIndex);
              //checkDeviceVTypeForTask(&TempEvent);
              prepare_I2C_by_taskIndex(taskIndex, DeviceIndex);
              checkRAM(F("PluginCall_s"), taskIndex);
              START_TIMER;
              bool retval = (Plugin_ptr[DeviceIndex](Function, &TempEvent, str));
              STOP_TIMER_TASK(DeviceIndex, Function);
              post_I2C_by_taskIndex(taskIndex, DeviceIndex);
              delay(0); // SMY: call delay(0) unconditionally

              if (retval) {
                CPluginCall(CPlugin::Function::CPLUGIN_ACKNOWLEDGE, &TempEvent, str);
                return true;
              }
            }
          }
        }
      }

      // @FIXME TD-er: work-around as long as gpio command is still performed in P001_switch.
      for (deviceIndex_t deviceIndex = 0; deviceIndex < PLUGIN_MAX; deviceIndex++) {
        if (validPluginID(DeviceIndex_to_Plugin_id[deviceIndex])) {
          if (Plugin_ptr[deviceIndex](Function, event, str)) {
            delay(0); // SMY: call delay(0) unconditionally
            CPluginCall(CPlugin::Function::CPLUGIN_ACKNOWLEDGE, event, str);
            return true;
          }
        }
      }
      break;
    }

This last part is indeed a bit fishy and will probably very soon be obsolete (as I merge the long pending GPIO PR)

This last part can be wrapped in a check for PLUGIN_REQUEST as you suggested as there is no reason to try to call the PLUGIN_WRITE again on all present plugins even when not enabled.

So it then becomes:

if(Function == PLUGIN_REQUEST) {
      // @FIXME TD-er: work-around as long as gpio command is still performed in P001_switch.
      for (deviceIndex_t deviceIndex = 0; deviceIndex < PLUGIN_MAX; deviceIndex++) {
        if (validPluginID(DeviceIndex_to_Plugin_id[deviceIndex])) {
          if (Plugin_ptr[deviceIndex](Function, event, str)) {
            delay(0); // SMY: call delay(0) unconditionally
            CPluginCall(CPlugin::Function::CPLUGIN_ACKNOWLEDGE, event, str);
            return true;
          }
        }
      }
}