openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.88k stars 3.58k forks source link

[sonyprojector] SDDP Invalid Characters #16964

Closed morph166955 closed 3 months ago

morph166955 commented 3 months ago

I believe this is related to #16849

Just updated today (on snapshot 4148 now) and I'm getting this at startup.

2024-06-29 16:41:25.724 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: ID segment '70-:2-6:-05-:2-7:-40-:8-0' contains invalid characters. Each segment of the ID must match the pattern [\w-]*.
        at org.openhab.core.common.AbstractUID.validateSegment(AbstractUID.java:105) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:59) ~[?:?]
        at org.openhab.core.thing.UID.<init>(UID.java:57) ~[?:?]
        at org.openhab.core.thing.ThingUID.<init>(ThingUID.java:47) ~[?:?]
        at org.openhab.binding.sonyprojector.internal.discovery.SonyProjectorDiscoveryParticipant.getThingUID(SonyProjectorDiscoveryParticipant.java:78) ~[?:?]
        at org.openhab.binding.sonyprojector.internal.discovery.SonyProjectorDiscoveryParticipant.createResult(SonyProjectorDiscoveryParticipant.java:56) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$10(SddpDiscoveryService.java:372) ~[?:?]
        at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4706) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.processPacket(SddpDiscoveryService.java:371) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.listenActiveScanUnicast(SddpDiscoveryService.java:306) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$18(SddpDiscoveryService.java:430) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
morph166955 commented 3 months ago

A few more similar ones threw

2024-06-29 16:51:05.041 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: ID segment '70-:2-6:-05-:2-7:-40-:8-0' contains invalid characters. Each segment of the ID must match the pattern [\w-]*.
        at org.openhab.core.common.AbstractUID.validateSegment(AbstractUID.java:105) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:59) ~[?:?]
        at org.openhab.core.thing.UID.<init>(UID.java:57) ~[?:?]
        at org.openhab.core.thing.ThingUID.<init>(ThingUID.java:47) ~[?:?]
        at org.openhab.binding.sonyprojector.internal.discovery.SonyProjectorDiscoveryParticipant.getThingUID(SonyProjectorDiscoveryParticipant.java:78) ~[?:?]
        at org.openhab.binding.sonyprojector.internal.discovery.SonyProjectorDiscoveryParticipant.createResult(SonyProjectorDiscoveryParticipant.java:56) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$10(SddpDiscoveryService.java:372) ~[?:?]
        at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4706) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.processPacket(SddpDiscoveryService.java:371) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.listenBackGroundMulticast(SddpDiscoveryService.java:235) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$17(SddpDiscoveryService.java:419) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
2024-06-29 17:24:53.065 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: ID segment '70-:2-6:-05-:2-7:-40-:8-0' contains invalid characters. Each segment of the ID must match the pattern [\w-]*.
        at org.openhab.core.common.AbstractUID.validateSegment(AbstractUID.java:105) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:76) ~[?:?]
        at org.openhab.core.common.AbstractUID.<init>(AbstractUID.java:59) ~[?:?]
        at org.openhab.core.thing.UID.<init>(UID.java:57) ~[?:?]
        at org.openhab.core.thing.ThingUID.<init>(ThingUID.java:47) ~[?:?]
        at org.openhab.binding.sonyprojector.internal.discovery.SonyProjectorDiscoveryParticipant.getThingUID(SonyProjectorDiscoveryParticipant.java:78) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$14(SddpDiscoveryService.java:396) ~[?:?]
        at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4706) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$13(SddpDiscoveryService.java:395) ~[?:?]
        at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
        at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) ~[?:?]
        at java.util.HashMap$KeySpliterator.forEachRemaining(HashMap.java:1707) ~[?:?]
        at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
        at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
        at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
        at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
        at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
        at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.purgeExpiredDevices(SddpDiscoveryService.java:394) ~[?:?]
        at org.openhab.core.config.discovery.sddp.SddpDiscoveryService.lambda$0(SddpDiscoveryService.java:117) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
        at java.lang.Thread.run(Thread.java:840) [?:?]
lolodomo commented 3 months ago

@andrewfg there is a problem with the Mac address provided by the core framework.

andrewfg commented 3 months ago

@morph166955 could you please turn on log:set TRACE org.openhab.core.config.discovery.sddp and show the result?

lolodomo commented 3 months ago

@morph166955 : please also check the new thing property "MAC address" of your existing thing and tell us what value is set. At the very end, we have to be sure this MAC address and the one coming from SDDP stuff (discovery) are identical.

andrewfg commented 3 months ago

See https://github.com/openhab/openhab-core/pull/4284 for solution..

morph166955 commented 3 months ago

@morph166955 : please also check the new thing property "MAC address" of your existing thing and tell us what value is set. At the very end, we have to be sure this MAC address and the one coming from SDDP stuff (discovery) are identical.

I don't have the ability to pull a trace at the moment, but I was able to pull the thing property and it obviously looks odd. I can try to pull the trace this week.

Screenshot 2024-06-30 192321

andrewfg commented 3 months ago

@morph166955 from reverse engineering your error logs our hypothesis is that the mac address part of the host header field of the sddp notification is unexpectedly encoded with colon delimiters rather than without. And based on that, there is an OH core fix in the works. So once that fix is merged, it would be good if you can test the respective latest snapshot.

andrewfg commented 3 months ago

@lolodomo where is the mac address property coming from? I assume it is taken from somewhere else than the sddp discovery because it is also present on manually configured things. If that is the case then there may also be a second issue concerning that property which is binding specific. Or??

lolodomo commented 3 months ago

Yes, it is retrieved using the dedicated protocol. I am going to check if I made a stupid error. If not, the solution would be to remove the representation properly ... at least until a better solution is found.

andrewfg commented 3 months ago

The core PR will provide a dash delimited lowercase hex mac address (the extra colon delimiters are taken out). So the two macs should be normalised to a common format if they will be used as a representation property.

Note: it may be that the OP's projector delivers extra colon delimiters by sddp and by the api, so in any case it would be good practice for the binding to renormalise the casing and the delimiters.

lolodomo commented 3 months ago

Look at the value returned by the API in the screen capture, it looks very strange, kind of encoded.

andrewfg commented 3 months ago

kind of encoded

Indeed.

The log shows a mac address 70:26:05:27:40:80 and the screen shot shows p&☐'@ which is 0x70, 0x26, 0x05, 0x27, 0x40 in ASCII.

This means that the SonyProjectorSdcpConnector.getMacAddress() method is wrongly decoding to UTF8 instead of converting the plain byte values to hex.

I suppose this binding bug has always been present; and certainly predates the issue reported here.

EDIT: @lolodomo I can easily make a PR to fix SonyProjectorSdcpConnector.getMacAddress() if you want me to. However I don't have such a physical device, so if you do have one such device, it may be easier for you to make the change. => WDYT?

EDIT 2: the code is here...

    /**
     * Request the MAC address
     *
     * @return the MAC address
     *
     * @throws SonyProjectorException in case of any problem
     */
    public String getMacAddress() throws SonyProjectorException {
        String macAddress = "";
        byte[] macBytes = getSetting(SonyProjectorItem.MAC_ADDRESS);
        for (byte macByte : macBytes) {
            if (!macAddress.isEmpty()) {
                macAddress = macAddress + "-";
            }
            macAddress = macAddress + Integer.toHexString(macByte);
        }
        return macAddress.toLowerCase();
    }

EDIT 3: see #16972

lolodomo commented 3 months ago

I suppose this binding bug has always been present;

The code is very new and I was not able to test it.

lolodomo commented 3 months ago

The log shows a mac address 70:26:05:27:40:80 and the screen shot shows p&☐'@ which is 0x70, 0x26, 0x05, 0x27, 0x40 in ASCII.

This means that the SonyProjectorSdcpConnector.getMacAddress() method is wrongly decoding to UTF8 instead of converting the plain byte values to hex.

Very interesting, thank you for finding that.

lolodomo commented 3 months ago

@morph166955 : @andrewfg just fixed the bug with the the retrieval of the MAC address. I am asking myself if we don't have the same issue when retrieving the model name. Can you please enable binding DEBUG logs and then set model to "AUTO" in your thing. Please tell us what shows the log starting with "getModelName returned ".

Edit: it is just to be sure, I would be surprised that the current method is not good.

lolodomo commented 3 months ago

Closed by openhab/openhab-core#4284

andrewfg commented 3 months ago

if we don't have the same issue when retrieving the model name

As an outsider it is not obvious that there would be the same issue. A model name is always a text string, so it would always be encoded in one of the existing standard character sets. By contrast a mac address is actually physically an array of bytes, which might be transmitted verbatim as an array of bytes or encoded as a (delimited) array of text characters.

lolodomo commented 3 months ago

@morph166955 : you can try snapshot 4153 that should normally fix all problems discussed in this issue. Let us know your feedback.