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

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