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

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