Unable to configure MQTT when active on an interface

[GeneRisi]

I am getting this error in my config.g file from the line that defines the MQTT client ID. Has anyone seen this error?

I did a custom firmware build so it's possible that something isn't quite right with it.

 Configuration file for Duet WiFi / Ethernet
; executed by the firmware on start-up
 
; *** General preferences ***
;
M111 S0 						; Debugging off
M550 P"ToolChanger" 			; Set machine name
G21 							; Work in millimetres
G90 							; Send absolute coordinates...
M83 							; ...but relative extruder moves
M555 P2 						; Set firmware compatibility to look like Marlin
;
; *** Network ***
;
M552 S0							; disable network interface
M586.4 C"ToolChanger"           ; Set client ID
M586.4 S"printing3d" O2         ; Subscribe to topic
;
M552 S1							; Enable Networking
M586 P0 S1 						; Enable HTTP
M586 P1 S1 						; Enable FTP
M586 P2 S0 						; Disable Telnet
M586 P4 R1884 H10.0.0.66 S1    							; Enable MQTT protocol/client
;
M118 P6 S"Starting MQTT on ToolChanger" T"printing3d"   ; Publish message (See M118 for more details)
;
M586 P4 S0                          					; Disable MQTT protocol/client; disconnects from broker gracefully. (for now)
;
 

Strangely, it accepts the command when entered into the web console

[droftarts]

@GeneRisi When the board starts up, WiFi is disabled. When you send M552 S0, it changes to the idle state. I think it may still be turning on when you send the M586.4 commands. Try adding a pause between the M552 S0 and M586.4 commands, eg G4 S2.

Ian

[GeneRisi]

@droftarts Hi Ian,

Even waiting 20 seconds isn't enough to make it work in config.g. I wrote a macro and that didn't work either (when called from config.g at power on/reset). I also included a M586 P4 S0 before trying to establish the client ID

I added a debug output statement to MqttClient::Configure. When it runs as a part of config.g after machine reset, I get:

HTTP is enabled on port 80
power up + 00:00:00 [debug] FTP is enabled on port 21
power up + 00:00:00 [debug] TELNET is disabled
power up + 00:00:00 [debug] MQTT is disabled
power up + 00:00:00 [debug] Configuring MQTT; responder state: 4391195
power up + 00:00:00 [warn] Error: Unable to configure MQTT when active on an interface 
power up + 00:00:00 [debug] Configuring MQTT; responder state: 4391195
power up + 00:00:00 [warn] Error: Unable to configure MQTT when active on an interface 
power up + 00:00:00 [debug] Configuring MQTT; responder state: 4391195
power up + 00:00:00 [warn] Error: Unable to configure MQTT when active on an interface 
power up + 00:00:00 [debug] MQTT is enabled on port 1884
power up + 00:00:00 [debug] Failed to publish MQTT message, client not active
power up + 00:00:00 [debug] Starting MQTT on ToolChanger
power up + 00:00:00 [info] Event logging stopped
 

Running this after config.g has completed, from the web console, says that responder state is 0:

024-05-08 22:07:28 [debug] Configuring MQTT; responder state: 0
2024-05-08 22:07:28 [debug] Configuring MQTT; responder state: 0
2024-05-08 22:07:28 [debug] Configuring MQTT; responder state: 0
2024-05-08 22:07:28 [debug] MQTT is enabled on port 1884
2024-05-08 22:07:28 [debug] Failed to publish MQTT message, client not active
2024-05-08 22:07:28 [debug] Starting MQTT on ToolChanger
2024-05-08 22:07:28 [debug] ... ending mqtt.g

Is it possible that responder state is uninitialized in the first scenario and initialized in the second?

Gene

[GeneRisi]

@droftarts , @rechrtb
I think I found the problem. in "Network.cpp" there is the following:

// This is called at the end of config.g processing. It must only be called once.
// Start the network if it was enabled
void Network::Activate() noexcept
{
#if HAS_NETWORKING
	// Allocate network buffers
	NetworkBuffer::AllocateBuffers(NetworkBufferCount);
 
	// Activate the interfaces
	for (NetworkInterface *iface : interfaces)
	{
		if (iface != nullptr)
		{
			iface->Activate();
		}
	}
 
	// Create the network responders
# if SUPPORT_TELNET
	for (size_t i = 0; i < NumTelnetResponders; ++i)
	{
		responders = new TelnetResponder(responders);
	}
# endif
 
# if SUPPORT_FTP
	for (size_t i = 0; i < NumFtpResponders; ++i)
	{
		responders = new FtpResponder(responders);
	}
# endif
 
# if SUPPORT_HTTP
	for (size_t i = 0; i < NumHttpResponders; ++i)
	{
		responders = new HttpResponder(responders);
	}
# endif
 
#if SUPPORT_MULTICAST_DISCOVERY
	MulticastResponder::Init();
#endif
 
#if SUPPORT_MQTT
	responders = clients = MqttClient::Init(responders, clients);
#endif
 
	// Finally, create the network task
	networkTask.Create(NetworkLoop, "NETWORK", nullptr, TaskPriority::SpinPriority);
#endif
}
 

In MqttClient.cpp is this routine:

MqttClient *MqttClient::Init(NetworkResponder *n, NetworkClient *c) noexcept
{
	instance = new MqttClient(n, c);
	return instance;
}
 

which initializes "instance". "Instance" is used in the firmware that is called when M586.4 is seen. So, any use of M586.4 before the completion of the first call to config.g after reset should be unsuccessful. The error message is misleading; the problem is not that transactions are occurring but that the data structure hasn't been allocated yet.

I can apply your patch and test it out in my custom firmware build.

Gene

[rechrtb]

@GeneRisi Hi there. Sorry for the late reply. Yes, you are correct as to the cause of this issue. Will be currently working on a fix for this.

In the meantime, are you familiar with daemon.g and variables? You should be able to do something like this as a workaround while the fix is being developed:

In config.g:

global mqttInited = 0

and in daemon.g:

if global.mqttInited = 0:
    ; Do MQTT init here
    set global.mqttInited = 1

[GeneRisi]

@rechrtb Thanks for your help!

I think a small change to your config.g suggestion works slightly better. If instead, I use

if !exists(global.mqttInited)
	global mqttInited = false

then config.g can be run without a machine reset preceding it (which is possible if config.g is edited)

[GeneRisi]

@rechrtb Now, I get this in my trace file:

2024-05-10 21:55:14 [debug] starting mqtt.g ...
2024-05-10 21:55:14 [debug] Configuring MQTT; responder state: 0
2024-05-10 21:55:14 [debug] Configuring MQTT; responder state: 0
2024-05-10 21:55:14 [debug] Configuring MQTT; responder state: 0
2024-05-10 21:55:14 [debug] MQTT is enabled on port 1884
2024-05-10 21:55:14 [debug] Failed to publish MQTT message, client not active
2024-05-10 21:55:14 [debug] Starting MQTT on ToolChanger
2024-05-10 21:55:14 [debug] ... ending mqtt.g

from this gcode:

M929 P"eventlog.txt" S3 		; start logging warnings to file eventlog.txt
;
M111 P1 S1              ; traces turned on
M111 P2 S1
;
M118 P1 S"starting mqtt.g ..."
;
M586.4 C"ToolChanger"           ; Set client ID
M586.4 U"TC" K"wHg@tc"    	; Set authentication credentials
M586.4 S"printing3d" O2         ; Subscribe to topic
;
M586 P4 R1884 H10.0.0.103 S1    ; this should initialize the responder
;
M118 P6 S"Starting MQTT on ToolChanger" T"printing3d"   ; Publish message (See M118 for more details)
;
M118 P1 S"... ending mqtt.g"
;
M111 P1 S0                 ; traces turned off
M111 P2 S0
;
M929 S0                     ; tracing truned off
;
; finis
 

What does "client not active" mean in this case? Is "client" the Duet3d firmware?

Gene

[GeneRisi]

@rechrtb I figured it out. The port has to be activated first (using M586) and then the initialization (M586.4) steps should occur, and then a message (M118) can be sent.

[droftarts]

@GeneRisi could you post the commands that work for you? Is this in config.g, or using the daemon.g workaround?

Ian

[rechrtb]

@GeneRisi Yes, the client is the board running RRF.

Actually, configuration (M586.4) is recommended before enabling the protocol (M586). I'm guessing since M118 is immediately after M586, it is still establishing connection when the publish is attempted. The configuration in between buys enough time. However, if you had more configuration lines, the first few might succeed, but once that connection goes through - the rest will fail - hence the recommendation to do all config before M586.

You should be able to add a delay after M586 in lieu of inserting the config in between.

[rechrtb]

I can apply your patch and test it out in my custom firmware build.

@GeneRisi The PR to fix the issue is in: https://github.com/Duet3D/RepRapFirmware/pull/1001
I was able to test it in my own setup and I can now do MQTT on config.g, but if you're able to verify it as well on your setup that would be much appreciated.

Here is the patch file with the same changes as the PR: mqtt_config_g.txt

rechrtb opened this pull request 13 May 2024, 14:25 in Duet3D/RepRapFirmware

closed Fix issue with MQTT config on config.g #1001

[GeneRisi]

@rechrtb First, I will try adding the delay after rearranging the gcode such that configuration happens first. I'll post what happens here. Then I will add the patch and try it out.
Gene

1. Adding delay between

M586.4 C"ToolChanger"           ; Set client ID
M586.4 U"TC" K"xxxxxxx"        ; Set authentication credentials
M586.4 S"printing3d" O2         ; Subscribe to topic
 
M586 P4 R1883 H10.0.0.103 T0 S1

and

M118 P6 S"MQTT message from ToolChanger" T"printing3d"

works !

And using the new MqttClient.cpp also works !

Thank you!

Gene

[GeneRisi]

@droftarts Hi Ian, the daemon.g file was just a work around because initializing MQTT in config.g doesn't work in the current release. The patch mentioned above works for my and @rechrtb systems and with the patch, it isn't necessary to use the daemon.g approach.

Gene

[droftarts]

@GeneRisi Great, thanks for testing. @rechrtb please can you update the documentation here, and show a config.g example? https://github.com/Duet3D/MQTT-WPA2-Enterprise-Demo
Maybe explain the daemon.g workaround? As I expect the fix won't be released before RRF 3.5.2, so for all those on earlier versions.

Ian

[rechrtb]

@droftarts Copy @droftarts