Unhandled Ack messages

[matthewgkerr]

When calling a command function (e.g setUART1Output) which results in the ublox module sending a response followed immediately by an ACK, I assume it is the intent of the library to process both the response and ACK before returning from the command function.
The function waitForResponse appears to exit as soon as either the expected ACK is received, or if the expected response is received.

I am seeing an issue where specific orders of commands is resulting in commands failing.
In my case, I'm calling setUART1Output then saveConfiguration. The second call is failing.

I'll do more testing tomorrow and add further details when I work out the cause of the issue.

[matthijskooijman]

When calling a command function (e.g setUART1Output) which results in the ublox module sending a response followed immediately by an ACK,

Are you sure this happens? I've seen that setUART1Output() first requests the current configuration, so maybe that is the response you see, followed by an ACK for the configuration set? I couldn't figure this out directly from my testing, due to below problem.

I see a related problem, which is that any ack is treated as a valid ack, even if it was for a different command. Combined with what you've already reported, wich leaves unprocessed acks in the buffer (or maybe due to some other cause), this can cause a disconnect between commands sent and replies received. I suspect this even causes my port to be reconfigured and break, since I/O starts running into timeouts:

SparkFun Ublox Example
GPS: trying 9600 baud
Sending: CLS:6 ID:8 Len: 0x0 Payload:
waitForResponse timeout
GPS: trying 9600 baud
Sending: CLS:6 ID:8 Len: 0x0 Payload:
Size: 6 Received: CLS:6 ID:8 Len: 0x6 Payload: E8 3 1 0 1 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 8
Command sent/ack'd successfully
GPS serial connected
Sending: CLS:6 ID:0 Len: 0x1 Payload: 1
Size: 6 Received: CLS:6 ID:8 Len: 0x6 Payload: E8 3 1 0 1 0
Packet didn't match CLS/IDCLS:6 ID:8 Len: 0x6 Payload: E8 3 1 0 1 0
Packet didn't match CLS/IDCLS:6 ID:8 Len: 0x6 Payload: E8 3 1 0 1 0
Packet didn't match CLS/IDCLS:6 ID:8 Len: 0x6 Payload: E8 3 1 0 1 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 8
Command sent/ack'd successfully
Sending: CLS:6 ID:0 Len: 0x14 Payload: E8 3 1 0 1 0 0 0 B5 62 0 0 0 0 1 0 0 0 0 0
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 1 0 0 0 C0 8 0 0 80 25 0 0 7 0 3 0 0 0 0 0
CLS/ID match!
Sending: CLS:6 ID:0 Len: 0x1 Payload: 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Sending: CLS:6 ID:0 Len: 0x14 Payload: 0 0 0 0 C0 8 0 0 80 25 0 0 7 0 1 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Version: Sending: CLS:A ID:4 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 0 0 B5 62 C0 8 0 0 80 25 0 0 7 0 1 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 0 0 B5 62 C0 8 0 0 80 25 0 0 7 0 1 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 0 0 B5 62 C0 8 0 0 80 25 0 0 7 0 1 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 0: 
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 1: 
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 160 Received: CLS:A ID:4 Len: 0xA0 Payload: 47 50 53 3B 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 53 42 41 53 3B 49 4D 45 53 3B 51 5A 53 53 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 5 1 2 0 0 0 0 0 C6 1 0 20 E 37 0 0 A 4 A0 0 A5 0 64 0 C8 1 0 20 41 D2 0 0
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 53 3B 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 2: GPS;GLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 3: GPS;GLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 4: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 5: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 6: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 7: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 8: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 9: GP⸮bGLO;GAL;BDS
0.Sending: CLS:A ID:4 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 0: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 1: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 2: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 3: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 4: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 5: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 6: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 7: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Extension 8: GP⸮bGLO;GAL;BDS
Sending: CLS:6 ID:0 Len: 0x0 Payload:
Size: 160 Received: CLS:A ID:4 Len: 0xA0 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 53 42 41 53 3B 49 4D 45 53 3B 51 5A 53 53 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 B5 62 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 5 1 2 0 0 0 0 0 C6 1 0 20 E 37 0 0 A 4 A0 0 A5 0 36 1 C8 1 0 20 41 D2 0 0
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
CLS/ID match!
Extension 9: GP⸮bGLO;GAL;BDS
0Sending: CLS:1 ID:7 Len: 0x0 Payload:
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Lat: 0Sending: CLS:1 ID:7 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
 Long: 0 (degrees * 10^-7)Sending: CLS:1 ID:7 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
 Alt: 0 (mm)Sending: CLS:1 ID:7 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Packet didn't match CLS/IDCLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
 SIV: 0
Sending: CLS:1 ID:7 Len: 0x0 Payload:
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Size: 20 Received: CLS:6 ID:0 Len: 0x14 Payload: 47 50 B5 62 47 4C 4F 3B 47 41 4C 3B 42 44 53 0 0 0 0 0
Size: 2 Received: CLS:5 ID:1 Len: 0x2 Payload: 6 0
Command sent/ack'd successfully
Lat: 0Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout
 Long: 0 (degrees * 10^-7)Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout
 Alt: 0 (mm)Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout
 SIV: 0
Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout
Lat: 0Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout
 Long: 0 (degrees * 10^-7)Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout
 Alt: 0 (mm)Sending: CLS:1 ID:7 Len: 0x0 Payload:
waitForResponse timeout

This log was generated by a modified version of the Uart example (enabling debug output, disabling configuration saving and adding version printing).

[matthijskooijman]

Actually, it seems that the command bytes are checked for an ack:

https://github.com/sparkfun/SparkFun_Ublox_Arduino_Library/blob/master/src/SparkFun_Ublox_Arduino_Library.cpp#L574-L578

However, these are checked against packetCfg, but that is not only the last command sent, but also the last (non-ack) message received:

SparkFun_Ublox_Arduino_Library/src/SparkFun_Ublox_Arduino_Library.cpp

Lines 383 to 386 in 9268475

	if (ubxFrameClass == CLASS_ACK)
	processUBX(incoming, &packetAck);
	else if (ubxFrameClass == CLASS_NOT_AN_ACK)
	processUBX(incoming, &packetCfg);

One further problem I noticed in this area, is that the first two bytes of a received packet might actually be appended to the previous packet, since processUBX is also called when ubxFrameCounter < 2:

SparkFun_Ublox_Arduino_Library/src/SparkFun_Ublox_Arduino_Library.cpp

Lines 362 to 386 in 9268475

	if (ubxFrameCounter == 0 && incoming != 0xB5) //ISO 'μ'
	currentSentence = NONE; //Something went wrong. Reset.
	else if (ubxFrameCounter == 1 && incoming != 0x62) //ASCII 'b'
	currentSentence = NONE; //Something went wrong. Reset.
	else if (ubxFrameCounter == 2) //Class
	{
	packetAck.counter = 0;
	packetAck.valid = false;
	packetCfg.counter = 0;
	packetCfg.valid = false;
	//We can now identify the type of response
	if (incoming == UBX_CLASS_ACK)
	ubxFrameClass = CLASS_ACK;
	else
	ubxFrameClass = CLASS_NOT_AN_ACK;
	}
	ubxFrameCounter++;
	//Depending on this frame's class, pass different structs and payload arrays
	if (ubxFrameClass == CLASS_ACK)
	processUBX(incoming, &packetAck);
	else if (ubxFrameClass == CLASS_NOT_AN_ACK)
	processUBX(incoming, &packetCfg);

Overall, it seems the request/response handling of this library might need an overhaul to make it working...

[nseidle]

I think I've got most of the ACK handled much better now. Please see this [PR}(https://github.com//pull/64) for breakdown of the changes that are rolling out. If you have any input please say so on the PR. If you continue to have problems please open a new issue.

[matthijskooijman]

@nseidle, bit of a late reply, but thanks for fixing this. I haven't had a chance to test yet, but the project I was going to use this for will start moving again soon, so if I find anything else, I'll be sure to report. Thanks!