Bug fixes, send/receive debug logs and Unsigned 24 support #267
Bug fixes, send/receive debug logs and Unsigned 24 support #267TzviRonen wants to merge 11 commits intocanopen-python:masterfrom
Conversation
canopen/sdo/client.py
Outdated
| PAUSE_BEFORE_SEND = 0.0 | ||
|
|
||
| # Seconds to wait before next read attempt for response in queue. For delayed responses. | ||
| PAUSE_BEFORE_READ = 0.2 |
There was a problem hiding this comment.
Perhaps RETRY_DELAY or something would be more easily understandable.
There was a problem hiding this comment.
What is the benefit of this mechanism? read_response() will already wait up to RESPONSE_TIMEOUT seconds, so this additional delay only slows down communication in case a reply is already available shortly after the first timeout.
If there is a special case that requires such behavior, we should maybe make it optional by defaulting the constant to zero?
There was a problem hiding this comment.
@acolomb If it fails to respond to the send_request that may be a sign that the device isn't ready and not necessarily a communication error.
Why not use RESPONSE_TIMEOUT? I want to know about it in the log's as soon as it happens and yet, wait more time before the next read_response().
I used it only for debugging. I agree with you it should be optional by defaulting it to zero.
And I agree with @christiansandberg about the naming. I changed the name to RETRY_DELAY.
There was a problem hiding this comment.
It's a very slight notion, but time.sleep(0) will allow switching to a different thread AFAIK, while not calling it at all does not. I suppose that doesn't make much difference, but maybe better check the constant first and skip sleep if it's zero?
canopen/sdo/client.py
Outdated
| self.responses = queue.Queue() | ||
|
|
||
| def on_response(self, can_id, data, timestamp): | ||
| logger.debug(f"received response in {can_id} data {data}.") |
There was a problem hiding this comment.
As I understand it, it is preferable to use old-style string interpolation for logging because then the final message will only be constructed if needed.
https://docs.python.org/3/howto/logging.html#logging-variable-data
There was a problem hiding this comment.
I agree, we should keep a consistent style here, meaning %-style format strings and arguments to the debug() function.
acolomb
left a comment
There was a problem hiding this comment.
I wish there was more explanation / better commit messages for these changes. Some cleanup required IMHO and better to keep things separated for different purposes, so I would recommend against squash-merging this as is.
canopen/network.py
Outdated
| if callback in self.subscribers[can_id]: | ||
| self.subscribers[can_id].remove(callback) |
There was a problem hiding this comment.
Can you describe the circumstances where raising a ValueError exception here would have caused problems?
If a non-registered callback is passed, that is clearly the caller's fault and I think it's correct to raise an exception in response. The main place where this function is used is in remove_network() on the nodes, which in turn gets called when deleting it from the network object. If it is part of the network, these callbacks have been recorded in the list previously, so no exception will be raised.
There was a problem hiding this comment.
You're right. I removed this change.
canopen/sdo/client.py
Outdated
| PAUSE_BEFORE_SEND = 0.0 | ||
|
|
||
| # Seconds to wait before next read attempt for response in queue. For delayed responses. | ||
| PAUSE_BEFORE_READ = 0.2 |
There was a problem hiding this comment.
What is the benefit of this mechanism? read_response() will already wait up to RESPONSE_TIMEOUT seconds, so this additional delay only slows down communication in case a reply is already available shortly after the first timeout.
If there is a special case that requires such behavior, we should maybe make it optional by defaulting the constant to zero?
canopen/sdo/client.py
Outdated
| self.responses = queue.Queue() | ||
|
|
||
| def on_response(self, can_id, data, timestamp): | ||
| logger.debug(f"received response in {can_id} data {data}.") |
There was a problem hiding this comment.
I agree, we should keep a consistent style here, meaning %-style format strings and arguments to the debug() function.
canopen/sdo/client.py
Outdated
| if not retries_left: | ||
| self.abort(0x5040000) | ||
| raise | ||
| time.sleep(self.PAUSE_BEFORE_READ) |
There was a problem hiding this comment.
If an additional delay is appropriate here (see above), it should wait after logging, not before.
| data = od_struct.pack(data) | ||
| else: | ||
| data = self.pdo_parent.data[byte_offset:byte_offset + len(self.od) // 8] | ||
| data = self.pdo_parent.data[byte_offset:byte_offset + self.length // 8] |
There was a problem hiding this comment.
Using the cached value here seems like a good idea, but it does change the semantics. That should at least be explained in the commit message.
Why not apply the same treatment in set_data()? Is there maybe some intentional reason len(self.od) and self.length are both used in these functions?
There was a problem hiding this comment.
I couldn't think of any reason len (self. OD) is used here.
Somehow len (self.od) changed during the program execution and wasn't equal to self.length when get_data was called. It made the returned data to be in the wrong size. Changing it to self.length fixed the problem.
There was a problem hiding this comment.
Well, len(self.od) returns the number of bits (rounded up to full bytes) that the object consists of according to the node's object dictionary, which is constant. While self.length starts off with the same value, it might be overridden when adding the Variable to a PDO mapping, where you can e.g. specify to map only (the lower) 16 bits of a 32 bit unsigned object. That difference is adjusted in pdo.Map.add_variable().
I agree there are some corner cases in the code that don't deal well with mapping only some bits of an object. But to fix that properly, each use within get_data() and set_data() should be reconsidered individually. Just changing one instance might fix your problem, but cause issues for other users.
By the way, my (hacky) solution so far was to adjust the ObjectDictionary instance to artificially overwrite the data_type member when using partial objects in PDO mappings. That breaks SDO access though, and doesn't cope well with signed numbers (two's complement requires changing the higher bytes as well when crossing zero).
canopen/objectdictionary/__init__.py
Outdated
|
|
||
| class Unsigned24(struct.Struct): | ||
| def __init__(self, *args, **kwargs): | ||
| super(Unsigned24, self).__init__("<I", *args, **kwargs) |
There was a problem hiding this comment.
Are we still trying to support Python 2? If not, this can be shortened to just super().
Also, why does this use I (unsigned int) whereas regular 32-bit ints use L (unsigned long)?
There was a problem hiding this comment.
Fixed the super thing.
This isn't an attempt to convert the uint24 to a regular 32-bit. The only reason I'm converting it to an I is because that's the closest data types Struct supports.
Then I'm using Struct.unpack("<I) to make that 32-bit int to python int.
There was a problem hiding this comment.
I had to look it up in the Python library docs, but as I see it, the <L and <I formats are equivalent, both using four bytes for the conversion. So your code seems correct, just wondering why not use the same letter when it doesn't really make a difference?
| UNSIGNED8: struct.Struct("B"), | ||
| UNSIGNED16: struct.Struct("<H"), | ||
| UNSIGNED32: struct.Struct("<L"), | ||
| UNSIGNED24: Unsigned24(), |
| __pycache__/ | ||
| *.py[cod] | ||
| *$py.class | ||
| .idea/ |
There was a problem hiding this comment.
There is a separate section for IDE stuff down below, if such things must be collected here.
This change seems unrelated though, so let's keep it in a separate commit / PR.
|
Regarding the additional log messages, I think that's too much verbosity. I sometimes rely on the |
TzviRonen
left a comment
There was a problem hiding this comment.
Regarding the additional log messages, I think that's too much verbosity. I sometimes rely on the
DEBUGlog level setting, but this would really spam the log without much additional gain. Is there some timing issue you're trying to debug? Then maybe having these debug messages locally is better than adding them here for every library user.
This log very helped me debug as they are at the very core of the library.
But you probably know better about the library logging level so I'll remove them to not spam the log's.
They indeed lead to a huge log file..
canopen/network.py
Outdated
| if callback in self.subscribers[can_id]: | ||
| self.subscribers[can_id].remove(callback) |
There was a problem hiding this comment.
You're right. I removed this change.
canopen/objectdictionary/__init__.py
Outdated
|
|
||
| class Unsigned24(struct.Struct): | ||
| def __init__(self, *args, **kwargs): | ||
| super(Unsigned24, self).__init__("<I", *args, **kwargs) |
There was a problem hiding this comment.
Fixed the super thing.
This isn't an attempt to convert the uint24 to a regular 32-bit. The only reason I'm converting it to an I is because that's the closest data types Struct supports.
Then I'm using Struct.unpack("<I) to make that 32-bit int to python int.
| UNSIGNED8: struct.Struct("B"), | ||
| UNSIGNED16: struct.Struct("<H"), | ||
| UNSIGNED32: struct.Struct("<L"), | ||
| UNSIGNED24: Unsigned24(), |
| data = od_struct.pack(data) | ||
| else: | ||
| data = self.pdo_parent.data[byte_offset:byte_offset + len(self.od) // 8] | ||
| data = self.pdo_parent.data[byte_offset:byte_offset + self.length // 8] |
There was a problem hiding this comment.
I couldn't think of any reason len (self. OD) is used here.
Somehow len (self.od) changed during the program execution and wasn't equal to self.length when get_data was called. It made the returned data to be in the wrong size. Changing it to self.length fixed the problem.
acolomb
left a comment
There was a problem hiding this comment.
Could you please still consider breaking up the changes into several commits / PRs with only related changes? I think pinpointing any possible issues will be easier when each commit holds only changes related to the same topic.
| data += b'\x00' | ||
| else: | ||
| logger.error(f"Unsigned24.unpack received wrong type - {type(data)}") | ||
| return super(Unsigned24, self).unpack(data, *args, **kwargs) |
|
|
||
| class Unsigned24(struct.Struct): | ||
| def __init__(self, *args, **kwargs): | ||
| super().__init__("<I", *args, **kwargs) |
There was a problem hiding this comment.
As previously noted, use "<L" for consistency with the UNSIGNED32 type.
| self.abort(0x5040000) | ||
| raise | ||
| logger.warning(str(e)) | ||
| time.sleep(self.RETRY_DELAY) |
There was a problem hiding this comment.
| time.sleep(self.RETRY_DELAY) | |
| if self.RETRY_DELAY: | |
| time.sleep(self.RETRY_DELAY) |
| self.send_response(response) | ||
|
|
||
| def send_response(self, response): | ||
| logger.debug(f"Sending to {self.tx_cobid} data {response}.") |
There was a problem hiding this comment.
Another overly verbose log message.
| while len(data) < 4: | ||
| data += b'\x00' | ||
| else: | ||
| logger.error(f"Unsigned24.unpack received wrong type - {type(data)}") |
There was a problem hiding this comment.
Please use %-style format string.
|
I've skimmed over the changes and converstion again. Not quite sure whether all problems addressed here have been dealt with. One of the main issues was that the PR contains many unrelated changes all-in-one. That now makes it harder to dissect what has already been fixed elsewhere, and where issues remain. @sveinse if you're motivated to check closely, extracting the relevant problem descriptions into separate issues would help. Pointing back at this PR for tentative fixes. I might get to it sometime, but don't hold your breath... |
| data = od_struct.pack(data) | ||
| else: | ||
| data = self.pdo_parent.data[byte_offset:byte_offset + len(self.od) // 8] | ||
| data = self.pdo_parent.data[byte_offset:byte_offset + self.length // 8] |
|
@sveinse That remaining change should definitely go in. I even found it in one of my older branches, just never got around to making a PR. |
|
No, that one is unrelated. I'm currently checking what other fixes I had started to work on about 1.5 years ago and will make a separate PR. |
|
The rework of PDO variable decoding (especially for mapped lengths differing from the OD size) is done in #454. Merging that will make the remaining bit of this PR obsolete I suppose. |
Changes: