git.basschouten.com Git - openhab-addons.git/blob

   1 /**
   2  * Copyright (c) 2010-2021 Contributors to the openHAB project
   3  *
   4  * See the NOTICE file(s) distributed with this work for additional
   5  * information.
   6  *
   7  * This program and the accompanying materials are made available under the
   8  * terms of the Eclipse Public License 2.0 which is available at
   9  * http://www.eclipse.org/legal/epl-2.0
  10  *
  11  * SPDX-License-Identifier: EPL-2.0
  12  */
  13 package org.openhab.binding.ihc.internal.handler;
  14
  15 import static org.openhab.binding.ihc.internal.IhcBindingConstants.*;
  16
  17 import java.io.File;
  18 import java.math.BigDecimal;
  19 import java.time.Duration;
  20 import java.time.LocalDateTime;
  21 import java.time.ZoneId;
  22 import java.time.ZonedDateTime;
  23 import java.util.ArrayList;
  24 import java.util.Collections;
  25 import java.util.HashMap;
  26 import java.util.HashSet;
  27 import java.util.List;
  28 import java.util.Map;
  29 import java.util.Set;
  30 import java.util.concurrent.ScheduledFuture;
  31 import java.util.concurrent.TimeUnit;
  32 import java.util.stream.Collectors;
  33
  34 import org.openhab.binding.ihc.internal.ButtonPressDurationDetector;
  35 import org.openhab.binding.ihc.internal.ChannelUtils;
  36 import org.openhab.binding.ihc.internal.EnumDictionary;
  37 import org.openhab.binding.ihc.internal.SignalLevelConverter;
  38 import org.openhab.binding.ihc.internal.config.ChannelParams;
  39 import org.openhab.binding.ihc.internal.config.IhcConfiguration;
  40 import org.openhab.binding.ihc.internal.converters.Converter;
  41 import org.openhab.binding.ihc.internal.converters.ConverterAdditionalInfo;
  42 import org.openhab.binding.ihc.internal.converters.ConverterFactory;
  43 import org.openhab.binding.ihc.internal.ws.IhcClient;
  44 import org.openhab.binding.ihc.internal.ws.IhcClient.ConnectionState;
  45 import org.openhab.binding.ihc.internal.ws.IhcEventListener;
  46 import org.openhab.binding.ihc.internal.ws.datatypes.WSControllerState;
  47 import org.openhab.binding.ihc.internal.ws.datatypes.WSProjectInfo;
  48 import org.openhab.binding.ihc.internal.ws.datatypes.WSRFDevice;
  49 import org.openhab.binding.ihc.internal.ws.datatypes.WSSystemInfo;
  50 import org.openhab.binding.ihc.internal.ws.datatypes.WSTimeManagerSettings;
  51 import org.openhab.binding.ihc.internal.ws.exeptions.ConversionException;
  52 import org.openhab.binding.ihc.internal.ws.exeptions.IhcExecption;
  53 import org.openhab.binding.ihc.internal.ws.exeptions.IhcFatalExecption;
  54 import org.openhab.binding.ihc.internal.ws.projectfile.IhcEnumValue;
  55 import org.openhab.binding.ihc.internal.ws.projectfile.ProjectFileUtils;
  56 import org.openhab.binding.ihc.internal.ws.resourcevalues.WSBooleanValue;
  57 import org.openhab.binding.ihc.internal.ws.resourcevalues.WSEnumValue;
  58 import org.openhab.binding.ihc.internal.ws.resourcevalues.WSResourceValue;
  59 import org.openhab.core.OpenHAB;
  60 import org.openhab.core.library.types.DateTimeType;
  61 import org.openhab.core.library.types.DecimalType;
  62 import org.openhab.core.library.types.OnOffType;
  63 import org.openhab.core.library.types.StringType;
  64 import org.openhab.core.thing.Channel;
  65 import org.openhab.core.thing.ChannelUID;
  66 import org.openhab.core.thing.Thing;
  67 import org.openhab.core.thing.ThingStatus;
  68 import org.openhab.core.thing.ThingStatusDetail;
  69 import org.openhab.core.thing.binding.BaseThingHandler;
  70 import org.openhab.core.types.Command;
  71 import org.openhab.core.types.RefreshType;
  72 import org.openhab.core.types.State;
  73 import org.openhab.core.types.Type;
  74 import org.slf4j.Logger;
  75 import org.slf4j.LoggerFactory;
  76 import org.w3c.dom.Document;
  77
  78 /**
  79  * The {@link IhcHandler} is responsible for handling commands, which are
  80  * sent to one of the channels.
  81  *
  82  * @author Pauli Anttila - Initial contribution
  83  */
  84 public class IhcHandler extends BaseThingHandler implements IhcEventListener {
  85     private final Logger logger = LoggerFactory.getLogger(IhcHandler.class);
  86
  87     /** Maximum pulse width in milliseconds. */
  88     private static final int MAX_PULSE_WIDTH_IN_MS = 4000;
  89
  90     /** Maximum long press time in milliseconds. */
  91     private static final int MAX_LONG_PRESS_IN_MS = 5000;
  92
  93     /** Name of the local IHC / ELKO project file */
  94     private static final String LOCAL_IHC_PROJECT_FILE_NAME_TEMPLATE = "ihc-project-file-%s.xml";
  95
  96     /** Holds runtime notification reorder timeout in milliseconds */
  97     private static final int NOTIFICATIONS_REORDER_WAIT_TIME = 1000;
  98
  99     /** IHC / ELKO LS Controller client */
 100     private IhcClient ihc;
 101
 102     /**
 103      * Reminder to slow down resource value notification ordering from
 104      * controller.
 105      */
 106     private ScheduledFuture<?> notificationsRequestReminder;
 107
 108     /** Holds local IHC / ELKO project file */
 109     private Document projectFile;
 110
 111     /**
 112      * Store current state of the controller, use to recognize when controller
 113      * state is changed
 114      */
 115     private String controllerState = "";
 116
 117     private IhcConfiguration conf;
 118     private final Set<Integer> linkedResourceIds = Collections.synchronizedSet(new HashSet<>());
 119     private Map<Integer, LocalDateTime> lastUpdate = new HashMap<>();
 120     private EnumDictionary enumDictionary;
 121
 122     private boolean connecting = false;
 123     private boolean reconnectRequest = false;
 124     private boolean valueNotificationRequest = false;
 125
 126     private ScheduledFuture<?> controlJob;
 127     private ScheduledFuture<?> pollingJobRf;
 128
 129     private Map<String, ScheduledFuture<?>> longPressFutures = new HashMap<>();
 130
 131     public IhcHandler(Thing thing) {
 132         super(thing);
 133     }
 134
 135     protected boolean isValueNotificationRequestActivated() {
 136         synchronized (this) {
 137             return valueNotificationRequest;
 138         }
 139     }
 140
 141     protected void setValueNotificationRequest(boolean valueNotificationRequest) {
 142         synchronized (this) {
 143             this.valueNotificationRequest = valueNotificationRequest;
 144         }
 145     }
 146
 147     protected boolean isReconnectRequestActivated() {
 148         synchronized (this) {
 149             return reconnectRequest;
 150         }
 151     }
 152
 153     protected void setReconnectRequest(boolean reconnect) {
 154         synchronized (this) {
 155             this.reconnectRequest = reconnect;
 156         }
 157     }
 158
 159     protected boolean isConnecting() {
 160         synchronized (this) {
 161             return connecting;
 162         }
 163     }
 164
 165     protected void setConnectingState(boolean value) {
 166         synchronized (this) {
 167             this.connecting = value;
 168         }
 169     }
 170
 171     private String getFilePathInUserDataFolder(String fileName) {
 172         return OpenHAB.getUserDataFolder() + File.separator + fileName;
 173     }
 174
 175     @Override
 176     public void initialize() {
 177         conf = getConfigAs(IhcConfiguration.class);
 178         logger.debug("Using configuration: {}", conf);
 179
 180         linkedResourceIds.clear();
 181         linkedResourceIds.addAll(getAllLinkedChannelsResourceIds());
 182         logger.debug("Linked resources {}: {}", linkedResourceIds.size(), linkedResourceIds);
 183
 184         if (controlJob == null || controlJob.isCancelled()) {
 185             logger.debug("Start control task, interval={}sec", 1);
 186             controlJob = scheduler.scheduleWithFixedDelay(this::reconnectCheck, 0, 1, TimeUnit.SECONDS);
 187         }
 188     }
 189
 190     @Override
 191     public void dispose() {
 192         logger.debug("Stopping thing");
 193         if (controlJob != null && !controlJob.isCancelled()) {
 194             controlJob.cancel(true);
 195             controlJob = null;
 196         }
 197         disconnect();
 198     }
 199
 200     @Override
 201     public void handleCommand(ChannelUID channelUID, Command command) {
 202         logger.debug("Received channel: {}, command: {}", channelUID, command);
 203
 204         if (ihc == null) {
 205             logger.warn("Connection is not initialized, abort resource value update for channel '{}'!", channelUID);
 206             return;
 207         }
 208
 209         if (ihc.getConnectionState() != ConnectionState.CONNECTED) {
 210             logger.warn("Connection to controller is not open, abort resource value update for channel '{}'!",
 211                     channelUID);
 212             return;
 213         }
 214
 215         switch (channelUID.getId()) {
 216             case CHANNEL_CONTROLLER_STATE:
 217                 if (command.equals(RefreshType.REFRESH)) {
 218                     updateControllerStateChannel();
 219                 }
 220                 break;
 221
 222             case CHANNEL_CONTROLLER_UPTIME:
 223                 if (command.equals(RefreshType.REFRESH)) {
 224                     updateControllerInformationChannels();
 225                 }
 226                 break;
 227
 228             case CHANNEL_CONTROLLER_TIME:
 229                 if (command.equals(RefreshType.REFRESH)) {
 230                     updateControllerTimeChannels();
 231                 }
 232                 break;
 233
 234             default:
 235                 if (command.equals(RefreshType.REFRESH)) {
 236                     refreshChannel(channelUID);
 237                 } else {
 238                     updateResourceChannel(channelUID, command);
 239                 }
 240                 break;
 241         }
 242     }
 243
 244     private void refreshChannel(ChannelUID channelUID) {
 245         logger.debug("REFRESH channel {}", channelUID);
 246         Channel channel = thing.getChannel(channelUID.getId());
 247         if (channel != null) {
 248             try {
 249                 ChannelParams params = new ChannelParams(channel);
 250                 logger.debug("Channel params: {}", params);
 251                 if (params.isDirectionWriteOnly()) {
 252                     logger.warn("Write only channel, skip refresh command to {}", channelUID);
 253                     return;
 254                 }
 255                 WSResourceValue value = ihc.resourceQuery(params.getResourceId());
 256                 resourceValueUpdateReceived(value);
 257             } catch (IhcExecption e) {
 258                 logger.warn("Can't update channel '{}' value, reason: {}", channelUID, e.getMessage(), e);
 259             } catch (ConversionException e) {
 260                 logger.warn("Channel param error, reason: {}.", e.getMessage(), e);
 261             }
 262         }
 263     }
 264
 265     private void updateControllerStateChannel() {
 266         try {
 267             String state = ihc.getControllerState().getState();
 268             String value;
 269
 270             switch (state) {
 271                 case IhcClient.CONTROLLER_STATE_INITIALIZE:
 272                     value = "Initialize";
 273                     break;
 274                 case IhcClient.CONTROLLER_STATE_READY:
 275                     value = "Ready";
 276                     break;
 277                 default:
 278                     value = "Unknown state: " + state;
 279             }
 280
 281             updateState(new ChannelUID(getThing().getUID(), CHANNEL_CONTROLLER_STATE), new StringType(value));
 282         } catch (IhcExecption e) {
 283             logger.warn("Controller state information fetch failed, reason: {}", e.getMessage(), e);
 284         }
 285     }
 286
 287     private void updateControllerProperties() {
 288         try {
 289             WSSystemInfo systemInfo = ihc.getSystemInfo();
 290             logger.debug("Controller information: {}", systemInfo);
 291             WSProjectInfo projectInfo = ihc.getProjectInfo();
 292             logger.debug("Project information: {}", projectInfo);
 293
 294             Map<String, String> properties = editProperties();
 295             properties.put(PROPERTY_MANUFACTURER, systemInfo.getBrand());
 296             properties.put(PROPERTY_SERIALNUMBER, systemInfo.getSerialNumber());
 297             properties.put(PROPERTY_SW_VERSION, systemInfo.getVersion());
 298             properties.put(PROPERTY_FW_VERSION, systemInfo.getHwRevision());
 299             properties.put(PROPERTY_APP_WITHOUT_VIEWER, Boolean.toString(systemInfo.getApplicationIsWithoutViewer()));
 300             properties.put(PROPERTY_SW_DATE,
 301                     systemInfo.getSwDate().withZoneSameInstant(ZoneId.systemDefault()).toString());
 302             properties.put(PROPERTY_PRODUCTION_DATE, systemInfo.getProductionDate());
 303             if (!systemInfo.getDatalineVersion().isEmpty()) {
 304                 properties.put(PROPERTY_DATALINE_VERSION, systemInfo.getDatalineVersion());
 305             }
 306             if (!systemInfo.getRfModuleSerialNumber().isEmpty()) {
 307                 properties.put(PROPERTY_RF_MODULE_SERIALNUMBER, systemInfo.getRfModuleSerialNumber());
 308             }
 309             if (!systemInfo.getRfModuleSoftwareVersion().isEmpty()) {
 310                 properties.put(PROPERTY_RF_MODULE_VERSION, systemInfo.getRfModuleSoftwareVersion());
 311             }
 312             properties.put(PROPERTY_PROJECT_DATE,
 313                     projectInfo.getLastmodified().getAsLocalDateTime().atZone(ZoneId.systemDefault()).toString());
 314             properties.put(PROPERTY_PROJECT_NUMBER, projectInfo.getProjectNumber());
 315             updateProperties(properties);
 316         } catch (IhcExecption e) {
 317             logger.warn("Controller information fetch failed, reason:  {}", e.getMessage(), e);
 318         }
 319     }
 320
 321     private void updateControllerInformationChannels() {
 322         try {
 323             WSSystemInfo systemInfo = ihc.getSystemInfo();
 324             logger.debug("Controller information: {}", systemInfo);
 325
 326             updateState(new ChannelUID(getThing().getUID(), CHANNEL_CONTROLLER_UPTIME),
 327                     new DecimalType((double) systemInfo.getUptime() / 1000));
 328         } catch (IhcExecption e) {
 329             logger.warn("Controller uptime information fetch failed, reason: {}.", e.getMessage(), e);
 330         }
 331     }
 332
 333     private void updateControllerTimeChannels() {
 334         try {
 335             WSTimeManagerSettings timeSettings = ihc.getTimeSettings();
 336             logger.debug("Controller time settings: {}", timeSettings);
 337
 338             ZonedDateTime time = timeSettings.getTimeAndDateInUTC().getAsZonedDateTime(ZoneId.of("Z"))
 339                     .withZoneSameInstant(ZoneId.systemDefault());
 340             updateState(new ChannelUID(getThing().getUID(), CHANNEL_CONTROLLER_TIME), new DateTimeType(time));
 341         } catch (IhcExecption e) {
 342             logger.warn("Controller uptime information fetch failed, reason: {}.", e.getMessage(), e);
 343         }
 344     }
 345
 346     private void updateResourceChannel(ChannelUID channelUID, Command command) {
 347         Channel channel = thing.getChannel(channelUID.getId());
 348         if (channel != null) {
 349             try {
 350                 ChannelParams params = new ChannelParams(channel);
 351                 logger.debug("Channel params: {}", params);
 352                 if (params.isDirectionReadOnly()) {
 353                     logger.debug("Read only channel, skip the update to {}", channelUID);
 354                     return;
 355                 }
 356                 updateChannel(channelUID, params, command);
 357             } catch (IhcExecption e) {
 358                 logger.warn("Can't update channel '{}' value, cause {}", channelUID, e.getMessage());
 359             } catch (ConversionException e) {
 360                 logger.debug("Conversion error for channel {}, reason: {}", channelUID, e.getMessage());
 361             }
 362         }
 363     }
 364
 365     private void updateChannel(ChannelUID channelUID, ChannelParams params, Command command)
 366             throws IhcExecption, ConversionException {
 367         if (params.getCommandToReact() != null) {
 368             if (command.toString().equals(params.getCommandToReact())) {
 369                 logger.debug("Command '{}' equal to channel reaction parameter '{}', execute it", command,
 370                         params.getCommandToReact());
 371             } else {
 372                 logger.debug("Command '{}' doesn't equal to reaction trigger parameter '{}', skip it", command,
 373                         params.getCommandToReact());
 374                 return;
 375             }
 376         }
 377         WSResourceValue value = ihc.getResourceValueInformation(params.getResourceId());
 378         if (value != null) {
 379             if (params.getPulseWidth() != null) {
 380                 sendPulseCommand(channelUID, params, value, Math.min(params.getPulseWidth(), MAX_PULSE_WIDTH_IN_MS));
 381             } else {
 382                 sendNormalCommand(channelUID, params, command, value);
 383             }
 384         }
 385     }
 386
 387     private void sendNormalCommand(ChannelUID channelUID, ChannelParams params, Command command, WSResourceValue value)
 388             throws IhcExecption, ConversionException {
 389         logger.debug("Send command '{}' to resource '{}'", command, value.resourceID);
 390         ConverterAdditionalInfo converterAdditionalInfo = new ConverterAdditionalInfo(getEnumValues(value),
 391                 params.isInverted(), getCommandLevels(params));
 392         Converter<WSResourceValue, Type> converter = ConverterFactory.getInstance().getConverter(value.getClass(),
 393                 command.getClass());
 394         if (converter != null) {
 395             WSResourceValue val = converter.convertFromOHType(command, value, converterAdditionalInfo);
 396             logger.debug("Update resource value (inverted output={}): {}", params.isInverted(), val);
 397             if (!updateResource(val)) {
 398                 logger.warn("Channel {} update to resource '{}' failed.", channelUID, val);
 399             }
 400         } else {
 401             logger.debug("No converter implemented for {} <-> {}", value.getClass(), command.getClass());
 402         }
 403     }
 404
 405     private List<IhcEnumValue> getEnumValues(WSResourceValue value) {
 406         if (value instanceof WSEnumValue) {
 407             return enumDictionary.getEnumValues(((WSEnumValue) value).definitionTypeID);
 408         }
 409         return null;
 410     }
 411
 412     private void sendPulseCommand(ChannelUID channelUID, ChannelParams params, WSResourceValue value,
 413             Integer pulseWidth) throws IhcExecption, ConversionException {
 414         logger.debug("Send {}ms pulse to resource: {}", pulseWidth, value.resourceID);
 415         logger.debug("Channel params: {}", params);
 416         Converter<WSResourceValue, Type> converter = ConverterFactory.getInstance().getConverter(value.getClass(),
 417                 OnOffType.class);
 418
 419         if (converter != null) {
 420             ConverterAdditionalInfo converterAdditionalInfo = new ConverterAdditionalInfo(null, params.isInverted(),
 421                     getCommandLevels(params));
 422
 423             WSResourceValue valOn = converter.convertFromOHType(OnOffType.ON, value, converterAdditionalInfo);
 424             WSResourceValue valOff = converter.convertFromOHType(OnOffType.OFF, value, converterAdditionalInfo);
 425
 426             // set resource to ON
 427             logger.debug("Update resource value (inverted output={}): {}", params.isInverted(), valOn);
 428             if (updateResource(valOn)) {
 429                 logger.debug("Sleeping: {}ms", pulseWidth);
 430                 scheduler.schedule(new Runnable() {
 431                     @Override
 432                     public void run() {
 433                         // set resource back to OFF
 434                         logger.debug("Update resource value (inverted output={}): {}", params.isInverted(), valOff);
 435                         try {
 436                             if (!updateResource(valOff)) {
 437                                 logger.warn("Channel {} update to resource '{}' failed.", channelUID, valOff);
 438                             }
 439                         } catch (IhcExecption e) {
 440                             logger.warn("Can't update channel '{}' value, cause {}", channelUID, e.getMessage());
 441                         }
 442                     }
 443                 }, pulseWidth, TimeUnit.MILLISECONDS);
 444             } else {
 445                 logger.warn("Channel {} update failed.", channelUID);
 446             }
 447         } else {
 448             logger.debug("No converter implemented for {} <-> {}", value.getClass(), OnOffType.class);
 449         }
 450     }
 451
 452     /**
 453      * Update resource value to IHC controller.
 454      */
 455     private boolean updateResource(WSResourceValue value) throws IhcExecption {
 456         boolean result = false;
 457         try {
 458             result = ihc.resourceUpdate(value);
 459         } catch (IhcExecption e) {
 460             logger.warn("Value could not be updated - retrying one time: {}.", e.getMessage(), e);
 461             result = ihc.resourceUpdate(value);
 462         }
 463         return result;
 464     }
 465
 466     @Override
 467     public void channelLinked(ChannelUID channelUID) {
 468         logger.debug("channelLinked: {}", channelUID);
 469
 470         switch (channelUID.getId()) {
 471             case CHANNEL_CONTROLLER_STATE:
 472                 updateControllerStateChannel();
 473                 break;
 474
 475             case CHANNEL_CONTROLLER_UPTIME:
 476                 updateControllerInformationChannels();
 477                 break;
 478
 479             case CHANNEL_CONTROLLER_TIME:
 480                 updateControllerTimeChannels();
 481                 break;
 482
 483             default:
 484                 Channel channel = thing.getChannel(channelUID.getId());
 485                 if (channel != null) {
 486                     try {
 487                         ChannelParams params = new ChannelParams(channel);
 488                         if (params.getResourceId() != null) {
 489                             if (!linkedResourceIds.contains(params.getResourceId())) {
 490                                 logger.debug("New channel '{}' found, resource id '{}'", channelUID.getAsString(),
 491                                         params.getResourceId());
 492                                 linkedResourceIds.add(params.getResourceId());
 493                                 updateNotificationsRequestReminder();
 494                             }
 495                         }
 496                     } catch (ConversionException e) {
 497                         logger.warn("Channel param error, reason: {}.", e.getMessage(), e);
 498                     }
 499                 }
 500         }
 501     }
 502
 503     @Override
 504     public void channelUnlinked(ChannelUID channelUID) {
 505         logger.debug("channelUnlinked: {}", channelUID);
 506
 507         switch (channelUID.getId()) {
 508             case CHANNEL_CONTROLLER_STATE:
 509             case CHANNEL_CONTROLLER_UPTIME:
 510             case CHANNEL_CONTROLLER_TIME:
 511                 break;
 512
 513             default:
 514                 Channel channel = thing.getChannel(channelUID.getId());
 515                 if (channel != null) {
 516                     try {
 517                         ChannelParams params = new ChannelParams(channel);
 518                         if (params.getResourceId() != null) {
 519                             linkedResourceIds.removeIf(c -> c.equals(params.getResourceId()));
 520                             updateNotificationsRequestReminder();
 521                         }
 522                     } catch (ConversionException e) {
 523                         logger.warn("Channel param error, reason: {}.", e.getMessage(), e);
 524                     }
 525                 }
 526         }
 527     }
 528
 529     /**
 530      * Initialize IHC client and open connection to IHC / ELKO LS controller.
 531      *
 532      */
 533     private void connect() throws IhcExecption {
 534         try {
 535             setConnectingState(true);
 536             logger.debug("Connecting to IHC / ELKO LS controller [hostname='{}', username='{}'].", conf.hostname,
 537                     conf.username);
 538             ihc = new IhcClient(conf.hostname, conf.username, conf.password, conf.timeout, conf.tlsVersion);
 539             ihc.openConnection();
 540             updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.NONE,
 541                     "Initializing communication to the IHC / ELKO controller");
 542             loadProject();
 543             createChannels();
 544             updateControllerProperties();
 545             updateControllerStateChannel();
 546             updateControllerInformationChannels();
 547             updateControllerTimeChannels();
 548             ihc.addEventListener(this);
 549             ihc.startControllerEventListeners();
 550             updateNotificationsRequestReminder();
 551             startRFPolling();
 552             updateStatus(ThingStatus.ONLINE);
 553         } finally {
 554             setConnectingState(false);
 555         }
 556     }
 557
 558     private void loadProject() throws IhcExecption {
 559         if (conf.loadProjectFile) {
 560             String fileName = String.format(LOCAL_IHC_PROJECT_FILE_NAME_TEMPLATE, thing.getUID().getId());
 561             String filePath = getFilePathInUserDataFolder(fileName);
 562             boolean loadProject = false;
 563
 564             if (projectFile == null) {
 565                 // try first load project file from local cache file.
 566                 try {
 567                     projectFile = ProjectFileUtils.readFromFile(filePath);
 568                 } catch (IhcExecption e) {
 569                     logger.debug("Error occured when read project file from file '{}', reason {}", filePath,
 570                             e.getMessage(), e);
 571                     loadProject = true;
 572                 }
 573             }
 574
 575             if (!ProjectFileUtils.projectEqualsToControllerProject(projectFile, ihc.getProjectInfo())) {
 576                 logger.debug(
 577                         "Local project file is not same as in the controller, reload project file from controller!");
 578                 loadProject = true;
 579             }
 580
 581             if (loadProject) {
 582                 logger.debug("Loading IHC /ELKO LS project file from controller...");
 583                 byte[] data = ihc.getProjectFileFromController();
 584                 logger.debug("Saving project file to local file '{}'", filePath);
 585                 try {
 586                     ProjectFileUtils.saveToFile(filePath, data);
 587                 } catch (IhcExecption e) {
 588                     logger.warn("Error occured when trying to write data to file '{}', reason {}", filePath,
 589                             e.getMessage(), e);
 590                 }
 591                 projectFile = ProjectFileUtils.converteBytesToDocument(data);
 592             }
 593         }
 594
 595         enumDictionary = new EnumDictionary(ProjectFileUtils.parseEnums(projectFile));
 596     }
 597
 598     private void createChannels() {
 599         if (conf.loadProjectFile && conf.createChannelsAutomatically) {
 600             logger.debug("Creating channels");
 601             List<Channel> thingChannels = new ArrayList<>();
 602             thingChannels.addAll(getThing().getChannels());
 603             ChannelUtils.addControllerChannels(getThing(), thingChannels);
 604             ChannelUtils.addChannelsFromProjectFile(getThing(), projectFile, thingChannels);
 605             printChannels(thingChannels);
 606             updateThing(editThing().withChannels(thingChannels).build());
 607         } else {
 608             logger.debug("Automatic channel creation disabled");
 609         }
 610     }
 611
 612     private void printChannels(List<Channel> thingChannels) {
 613         if (logger.isDebugEnabled()) {
 614             thingChannels.forEach(channel -> {
 615                 if (channel != null) {
 616                     String resourceId;
 617                     try {
 618                         Object id = channel.getConfiguration().get(PARAM_RESOURCE_ID);
 619                         resourceId = id != null ? "0x" + Integer.toHexString(((BigDecimal) id).intValue()) : "";
 620                     } catch (IllegalArgumentException e) {
 621                         resourceId = "";
 622                     }
 623
 624                     String channelType = channel.getAcceptedItemType() != null ? channel.getAcceptedItemType() : "";
 625                     String channelLabel = channel.getLabel() != null ? channel.getLabel() : "";
 626
 627                     logger.debug("Channel: {}", String.format("%-55s | %-10s | %-10s | %s", channel.getUID(),
 628                             resourceId, channelType, channelLabel));
 629                 }
 630             });
 631         }
 632     }
 633
 634     private void startRFPolling() {
 635         if (pollingJobRf == null || pollingJobRf.isCancelled()) {
 636             logger.debug("Start RF device refresh task, interval={}sec", 60);
 637             pollingJobRf = scheduler.scheduleWithFixedDelay(this::updateRfDeviceStates, 10, 60, TimeUnit.SECONDS);
 638         }
 639     }
 640
 641     /**
 642      * Disconnect connection to IHC / ELKO LS controller.
 643      *
 644      */
 645     private void disconnect() {
 646         cancelAllLongPressTasks();
 647         if (pollingJobRf != null && !pollingJobRf.isCancelled()) {
 648             pollingJobRf.cancel(true);
 649             pollingJobRf = null;
 650         }
 651         if (ihc != null) {
 652             try {
 653                 ihc.removeEventListener(this);
 654                 ihc.closeConnection();
 655                 ihc = null;
 656             } catch (IhcExecption e) {
 657                 logger.warn("Couldn't close connection to IHC controller", e);
 658             }
 659         }
 660         clearLastUpdateTimeCache();
 661     }
 662
 663     private void clearLastUpdateTimeCache() {
 664         lastUpdate.clear();
 665     }
 666
 667     @Override
 668     public void errorOccured(IhcExecption e) {
 669         logger.warn("Error occurred on communication to IHC controller: {}", e.getMessage(), e);
 670         logger.debug("Reconnection request");
 671         setReconnectRequest(true);
 672     }
 673
 674     @Override
 675     public void statusUpdateReceived(WSControllerState newState) {
 676         logger.debug("Controller state: {}", newState.getState());
 677
 678         if (!controllerState.equals(newState.getState())) {
 679             logger.debug("Controller state change detected ({} -> {})", controllerState, newState.getState());
 680
 681             switch (newState.getState()) {
 682                 case IhcClient.CONTROLLER_STATE_INITIALIZE:
 683                     logger.info("Controller state changed to initializing state, waiting for ready state");
 684                     updateState(new ChannelUID(getThing().getUID(), CHANNEL_CONTROLLER_STATE),
 685                             new StringType("initialize"));
 686                     updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.BRIDGE_OFFLINE,
 687                             "Controller is in initializing state");
 688                     break;
 689                 case IhcClient.CONTROLLER_STATE_READY:
 690                     logger.info("Controller state changed to ready state");
 691                     updateState(new ChannelUID(getThing().getUID(), CHANNEL_CONTROLLER_STATE), new StringType("ready"));
 692                     updateStatus(ThingStatus.ONLINE);
 693                     break;
 694                 default:
 695             }
 696
 697             if (controllerState.equals(IhcClient.CONTROLLER_STATE_INITIALIZE)
 698                     && newState.getState().equals(IhcClient.CONTROLLER_STATE_READY)) {
 699                 logger.debug("Reconnection request");
 700                 projectFile = null;
 701                 setReconnectRequest(true);
 702             }
 703         }
 704
 705         controllerState = newState.getState();
 706     }
 707
 708     @Override
 709     public void resourceValueUpdateReceived(WSResourceValue value) {
 710         logger.debug("resourceValueUpdateReceived: {}", value);
 711
 712         thing.getChannels().forEach(channel -> {
 713             try {
 714                 ChannelParams params = new ChannelParams(channel);
 715                 if (params.getResourceId() != null && params.getResourceId().intValue() == value.resourceID) {
 716                     updateChannelState(channel, params, value);
 717                 }
 718             } catch (ConversionException e) {
 719                 logger.warn("Channel param error, reason: {}.", e.getMessage(), e);
 720             } catch (RuntimeException e) {
 721                 logger.warn("Unknown error occured, reason: {}.", e.getMessage(), e);
 722             }
 723         });
 724
 725         checkPotentialButtonPresses(value);
 726     }
 727
 728     private void updateChannelState(Channel channel, ChannelParams params, WSResourceValue value) {
 729         if (params.isDirectionWriteOnly()) {
 730             logger.debug("Write only channel, skip update to {}", channel.getUID());
 731         } else {
 732             if (params.getChannelTypeId() != null) {
 733                 switch (params.getChannelTypeId()) {
 734                     case CHANNEL_TYPE_PUSH_BUTTON_TRIGGER:
 735                         break;
 736
 737                     default:
 738                         try {
 739                             logger.debug("Update channel '{}' state, channel params: {}", channel.getUID(), params);
 740                             Converter<WSResourceValue, Type> converter = ConverterFactory.getInstance()
 741                                     .getConverter(value.getClass(), channel.getAcceptedItemType());
 742                             if (converter != null) {
 743                                 State state = (State) converter.convertFromResourceValue(value,
 744                                         new ConverterAdditionalInfo(null, params.isInverted(),
 745                                                 getCommandLevels(params)));
 746                                 updateState(channel.getUID(), state);
 747                             } else {
 748                                 logger.debug("No converter implemented for {} <-> {}", value.getClass(),
 749                                         channel.getAcceptedItemType());
 750                             }
 751                         } catch (ConversionException e) {
 752                             logger.debug("Can't convert resource value '{}' to item type {}, reason: {}.", value,
 753                                     channel.getAcceptedItemType(), e.getMessage(), e);
 754                         }
 755                 }
 756             }
 757         }
 758     }
 759
 760     private void checkPotentialButtonPresses(WSResourceValue value) {
 761         if (value instanceof WSBooleanValue) {
 762             if (((WSBooleanValue) value).value) {
 763                 // potential button press
 764                 lastUpdate.put(value.resourceID, LocalDateTime.now());
 765                 updateTriggers(value.resourceID, Duration.ZERO);
 766             } else {
 767                 // potential button release
 768                 LocalDateTime lastUpdateTime = lastUpdate.get(value.resourceID);
 769                 if (lastUpdateTime != null) {
 770                     Duration duration = Duration.between(lastUpdateTime, LocalDateTime.now());
 771                     logger.debug("Time between uddates: {}", duration);
 772                     updateTriggers(value.resourceID, duration);
 773                 }
 774             }
 775         }
 776     }
 777
 778     private void updateTriggers(int resourceId, Duration duration) {
 779         thing.getChannels().forEach(channel -> {
 780             try {
 781                 ChannelParams params = new ChannelParams(channel);
 782                 if (params.getResourceId() != null && params.getResourceId().intValue() == resourceId) {
 783                     if (params.getChannelTypeId() != null) {
 784                         switch (params.getChannelTypeId()) {
 785                             case CHANNEL_TYPE_PUSH_BUTTON_TRIGGER:
 786                                 logger.debug("Update trigger channel '{}', channel params: {}",
 787                                         channel.getUID().getId(), params);
 788                                 if (duration.toMillis() == 0) {
 789                                     triggerChannel(channel.getUID().getId(), EVENT_PRESSED);
 790                                     createLongPressTask(channel.getUID().getId(), params.getLongPressTime());
 791                                 } else {
 792                                     cancelLongPressTask(channel.getUID().getId());
 793                                     triggerChannel(channel.getUID().getId(), EVENT_RELEASED);
 794                                     triggerChannel(channel.getUID().getId(), String.valueOf(duration.toMillis()));
 795                                     ButtonPressDurationDetector button = new ButtonPressDurationDetector(duration,
 796                                             params.getLongPressTime(), MAX_LONG_PRESS_IN_MS);
 797                                     logger.debug("resourceId={}, ButtonPressDurationDetector={}", resourceId, button);
 798                                     if (button.isShortPress()) {
 799                                         triggerChannel(channel.getUID().getId(), EVENT_SHORT_PRESS);
 800                                     }
 801                                     break;
 802                                 }
 803                         }
 804                     }
 805                 }
 806             } catch (ConversionException e) {
 807                 logger.warn("Channel param error, reason:  {}", e.getMessage(), e);
 808             }
 809         });
 810     }
 811
 812     private void createLongPressTask(String channelId, long longPressTimeInMs) {
 813         if (longPressFutures.containsKey(channelId)) {
 814             cancelLongPressTask(channelId);
 815         }
 816         logger.debug("Create long press task for channel '{}'", channelId);
 817         longPressFutures.put(channelId, scheduler.schedule(() -> triggerChannel(channelId, EVENT_LONG_PRESS),
 818                 longPressTimeInMs, TimeUnit.MILLISECONDS));
 819     }
 820
 821     private void cancelLongPressTask(String channelId) {
 822         if (longPressFutures.containsKey(channelId)) {
 823             logger.debug("Cancel long press task for channel '{}'", channelId);
 824             longPressFutures.get(channelId).cancel(false);
 825             longPressFutures.remove(channelId);
 826         }
 827     }
 828
 829     private void cancelAllLongPressTasks() {
 830         longPressFutures.entrySet().parallelStream().forEach(e -> e.getValue().cancel(true));
 831         longPressFutures.clear();
 832     }
 833
 834     private void updateRfDeviceStates() {
 835         if (ihc != null) {
 836             if (ihc.getConnectionState() != ConnectionState.CONNECTED) {
 837                 logger.debug("Controller is connecting, abort subscribe");
 838                 return;
 839             }
 840
 841             logger.debug("Update RF device data");
 842             try {
 843                 List<WSRFDevice> devs = ihc.getDetectedRFDevices();
 844                 logger.debug("RF data: {}", devs);
 845
 846                 devs.forEach(dev -> {
 847                     thing.getChannels().forEach(channel -> {
 848                         try {
 849                             ChannelParams params = new ChannelParams(channel);
 850                             if (params.getSerialNumber() != null
 851                                     && params.getSerialNumber().longValue() == dev.getSerialNumber()) {
 852                                 String channelId = channel.getUID().getId();
 853                                 if (params.getChannelTypeId() != null) {
 854                                     switch (params.getChannelTypeId()) {
 855                                         case CHANNEL_TYPE_RF_LOW_BATTERY:
 856                                             updateState(channelId,
 857                                                     dev.getBatteryLevel() == 1 ? OnOffType.OFF : OnOffType.ON);
 858                                             break;
 859                                         case CHANNEL_TYPE_RF_SIGNAL_STRENGTH:
 860                                             int signalLevel = new SignalLevelConverter(dev.getSignalStrength())
 861                                                     .getSystemWideSignalLevel();
 862                                             updateState(channelId, new StringType(String.valueOf(signalLevel)));
 863                                             break;
 864                                     }
 865                                 }
 866                             }
 867                         } catch (ConversionException e) {
 868                             logger.warn("Channel param error, reason:  {}", e.getMessage(), e);
 869                         }
 870                     });
 871                 });
 872             } catch (IhcExecption e) {
 873                 logger.debug("Error occured when fetching RF device information, reason: : {} ", e.getMessage(), e);
 874                 return;
 875             }
 876         }
 877     }
 878
 879     private void reconnectCheck() {
 880         if (ihc == null || isReconnectRequestActivated()) {
 881             try {
 882                 if (ihc != null) {
 883                     disconnect();
 884                 }
 885                 connect();
 886                 setReconnectRequest(false);
 887             } catch (IhcFatalExecption e) {
 888                 logger.warn("Can't open connection to controller {}", e.getMessage());
 889                 updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.COMMUNICATION_ERROR, e.getMessage());
 890                 setReconnectRequest(false);
 891                 return;
 892             } catch (IhcExecption e) {
 893                 logger.debug("Can't open connection to controller {}", e.getMessage());
 894                 updateStatus(ThingStatus.OFFLINE, ThingStatusDetail.COMMUNICATION_ERROR, e.getMessage());
 895                 setReconnectRequest(true);
 896                 return;
 897             }
 898         }
 899
 900         if (isValueNotificationRequestActivated() && !isConnecting()) {
 901             try {
 902                 enableResourceValueNotifications();
 903             } catch (IhcExecption e) {
 904                 logger.warn("Can't enable resource value notifications from controller. ", e);
 905             }
 906         }
 907     }
 908
 909     private Set<Integer> getAllLinkedChannelsResourceIds() {
 910         Set<Integer> resourceIds = Collections.synchronizedSet(new HashSet<>());
 911         resourceIds.addAll(this.getThing().getChannels().stream().filter(c -> isLinked(c.getUID())).map(c -> {
 912             try {
 913                 ChannelParams params = new ChannelParams(c);
 914                 logger.debug("Linked channel '{}' found, resource id '{}'", c.getUID().getAsString(),
 915                         params.getResourceId());
 916                 return params.getResourceId();
 917             } catch (ConversionException e) {
 918                 logger.warn("Channel param error, reason: {}.", e.getMessage(), e);
 919                 return null;
 920             }
 921         }).filter(c -> c != null && c != 0).collect(Collectors.toSet()));
 922         return resourceIds;
 923     }
 924
 925     /**
 926      * Order resource value notifications from IHC controller.
 927      */
 928     private void enableResourceValueNotifications() throws IhcExecption {
 929         logger.debug("Subscribe resource runtime value notifications");
 930
 931         if (ihc != null) {
 932             if (ihc.getConnectionState() != ConnectionState.CONNECTED) {
 933                 logger.debug("Controller is connecting, abort subscribe");
 934                 return;
 935             }
 936             setValueNotificationRequest(false);
 937             Set<Integer> resourceIds = ChannelUtils.getAllTriggerChannelsResourceIds(getThing());
 938             logger.debug("Enable runtime notfications for {} trigger(s)", resourceIds.size());
 939             logger.debug("Enable runtime notfications for {} channel(s)", linkedResourceIds.size());
 940             resourceIds.addAll(linkedResourceIds);
 941             resourceIds.addAll(getAllLinkedChannelsResourceIds());
 942             logger.debug("Enable runtime notfications for {} resources: {}", resourceIds.size(), resourceIds);
 943             if (!resourceIds.isEmpty()) {
 944                 try {
 945                     ihc.enableRuntimeValueNotifications(resourceIds);
 946                 } catch (IhcExecption e) {
 947                     logger.debug("Reconnection request");
 948                     setReconnectRequest(true);
 949                 }
 950             }
 951         } else {
 952             logger.warn("Controller is not initialized!");
 953             logger.debug("Reconnection request");
 954             setReconnectRequest(true);
 955         }
 956     }
 957
 958     private synchronized void updateNotificationsRequestReminder() {
 959         if (notificationsRequestReminder != null) {
 960             notificationsRequestReminder.cancel(false);
 961         }
 962
 963         logger.debug("Rechedule resource runtime value notifications order by {}ms", NOTIFICATIONS_REORDER_WAIT_TIME);
 964         notificationsRequestReminder = scheduler.schedule(new Runnable() {
 965
 966             @Override
 967             public void run() {
 968                 logger.debug("Delayed resource value notifications request is now enabled");
 969                 setValueNotificationRequest(true);
 970             }
 971         }, NOTIFICATIONS_REORDER_WAIT_TIME, TimeUnit.MILLISECONDS);
 972     }
 973
 974     private Map<Command, Object> getCommandLevels(ChannelParams params) {
 975         if (params.getOnLevel() != null) {
 976             Map<Command, Object> commandLevels = new HashMap<>();
 977             commandLevels.put(OnOffType.ON, params.getOnLevel());
 978             return Collections.unmodifiableMap(commandLevels);
 979         }
 980         return null;
 981     }
 982 }