FraunhoferIOSB / FROST-Server

A Complete Server implementation of the OGC SensorThings API
https://fraunhoferiosb.github.io/FROST-Server/
GNU Lesser General Public License v3.0
198 stars 74 forks source link

Importing of Observations does not work, due to missing Zulu time zone designator (when migrating from 1.14.2 to 2.0) #1485

Closed mikedolx closed 1 year ago

mikedolx commented 1 year ago

Hi,

in relevance to this discussion i'm creating a bug-ticket.

Background: We have migrated our tomcat installation of FROST v1.14.2 to a docker installation v1.14.2, with the intention to upgrade to MQTT (not only because of MQTT 😁). So far MQTT is working fine with v1.14.2. Now, if we upgrade our docker container to v2.0, we do not receive updates via MQTT anymore.

We use a cron-job that pushes each minute a huge amount of observations ~2K via REST-API (using DataArrays) to the FROST server. I can see the new observations, when requesting them via REST-API, but i do not get any published messages.

Do we miss some kind of migration from v1.14.2 to v.2.0, that would enable the MQTT-Messages?

Below, our docker-compose.yml and some log files.

version: '3.3'

services:
  frost-mqttp:
    image: fraunhoferiosb/frost-server:2.0
    container_name: frost-web-mqtt
    restart: unless-stopped
    ports:
      - ${EXTERNAL_HTTP_PORT}:8080
      - ${EXTERNAL_MQTT_PORT}:${EXTERNAL_MQTT_PORT}
    environment:
      - serviceRootUrl=${SERVICE_ROOT_URL}
      - queueLoggingInterval=1000
      - plugins.multiDatastream.enable=true
      - http_cors_enable=true
      - http_cors_allowed_origins=*
      - mqtt_Enabled=true
      - mqtt_QoS=2
      - mqtt_CreateThreadPoolSize=10
      - mqtt_CreateMessageQueueSize=100
      - mqtt_SubscribeThreadPoolSize=20
      - mqtt_SubscribeMessageQueueSize=100
      - mqtt_sslPort=${EXTERNAL_MQTT_PORT}
      - mqtt_javaKeystorePath=/tmp/keystore.jks
      - mqtt_keyStorePassword=${MQTT_KEYSTORE_PASS}
      - mqtt_keyManagerPassword=${MQTT_CERT_PASS}
      - mqtt_exposedEndpoints="mqtt://${EXTERNAL_HOSTNAME}:${EXTERNAL_MQTT_PORT}"
      - mqtt_maxInFlight=10000
      - persistence_db_driver=${DB_DRIVER}
      - persistence_db_url=${DB_URL}
      - persistence_db_username=${DB_USER}
      - persistence_db_password=${DB_PASSWORD}
      - persistence_autoUpdateDatabase=true
      - auth_provider=de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider
      - auth_db_driver=${DB_DRIVER}
      - auth_db_url=${DB_URL}
      - auth_db_username=${DB_USER}
      - auth_db_password=${DB_PASSWORD}
      - auth_autoUpdateDatabase=true
      - FROST_LL_io_moquette=DEBUG
    networks:
      - frost-backend
    volumes:
      - ./keystore.jks:/tmp/keystore.jks

networks:
  frost-backend:
    external: true

docker-compose logs -f

frost-web-mqtt | 08:27:38.372 [http-nio-8080-exec-1] INFO              org.jooq.Constants -
frost-web-mqtt |
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@  @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@  @@  @@    @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@  @@@@  @@  @@    @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@    @@  @@  @@@@  @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@    @@  @@  @@@@  @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@  @  @  @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@  @@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  Thank you for using jOOQ 3.16.14
frost-web-mqtt |
frost-web-mqtt | 08:27:38.375 [http-nio-8080-exec-1] INFO              org.jooq.Constants -
frost-web-mqtt |
frost-web-mqtt | jOOQ tip of the day: Whenever jOOQ doesn't support a native SQL feature, use plain SQL templating: https://www.jooq.org/doc/latest/manual/sql-building/plain-sql-templating/
frost-web-mqtt |
frost-web-mqtt | 08:27:38.495 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.exposedEndpoints has value '"mqtt://frost-dev.<redacted>.de:8883"'.
frost-web-mqtt | 08:27:47.888 [nioEventLoopGroup-3-1] INFO           liquibase.lockservice - Successfully acquired change log lock
frost-web-mqtt | 08:27:48.070 [nioEventLoopGroup-3-1] INFO             liquibase.changelog - Reading from public.databasechangelog
frost-web-mqtt | 08:27:48.272 [nioEventLoopGroup-3-1] INFO           liquibase.lockservice - Successfully released change log lock
frost-web-mqtt | 08:27:48.281 [nioEventLoopGroup-3-1] INFO  d.f.i.i.f.p.p.u.LiquibaseHelper - Liquibase changed the search_path from '"$user", public' to 'public, "$user", public'. Changing it back.
frost-web-mqtt | 08:27:48.285 [nioEventLoopGroup-3-1] INFO   d.f.i.i.f.a.b.DatabaseHandler - Database-update successful.
frost-web-mqtt | 08:27:48.299 [nioEventLoopGroup-3-1] DEBUG  io.moquette.broker.PostOffice - Routing cmd [CONN] for session [mqtt-explorer-c01516e8] to event processor 0
frost-web-mqtt | 08:27:48.301 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - readCompleted client CId: null
frost-web-mqtt | 08:27:48.307 [nioEventLoopGroup-3-1] DEBUG      i.m.b.m.MQTTMessageLogger - C<-B CONNACK <null>
frost-web-mqtt | 08:27:48.310 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Connection has been configured CId=mqtt-explorer-c01516e8, keepAlive=60, removeTemporaryQoS2=true, idleTime=90
frost-web-mqtt | 08:27:48.311 [nioEventLoopGroup-3-1] DEBUG    i.m.broker.InflightResender - Initializing autoflush handler on channel [id: 0x48ddd68c, L:/172.18.0.2:8883 - R:/<redacted>:65373]
frost-web-mqtt | 08:27:48.312 [nioEventLoopGroup-3-1] DEBUG        i.m.i.BrokerInterceptor - Sending MQTT CONNECT message to interceptor. CId=mqtt-explorer-c01516e8, interceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)
frost-web-mqtt | 08:27:48.347 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C->B SUBSCRIBE <mqtt-explorer-c01516e8> to topics [MqttTopicSubscription[topicFilter=v1.1/Datastreams, option=SubscriptionOption[qos=AT_MOST_ONCE, noLocal=false, retainAsPublished=false, retainHandling=SEND_AT_SUBSCRIBE]]]
frost-web-mqtt | 08:27:48.348 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Received MQTT message, type: SUBSCRIBE
frost-web-mqtt | 08:27:48.349 [nioEventLoopGroup-3-1] DEBUG  io.moquette.broker.PostOffice - Routing cmd [SUB] for session [mqtt-explorer-c01516e8] to event processor 0
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C->B SUBSCRIBE <mqtt-explorer-c01516e8> to topics [MqttTopicSubscription[topicFilter=v1.1/Things(9)/Datastreams(83)/Observations, option=SubscriptionOption[qos=EXACTLY_ONCE, noLocal=false, retainAsPublished=false, retainHandling=SEND_AT_SUBSCRIBE]]]
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Received MQTT message, type: SUBSCRIBE
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] DEBUG  io.moquette.broker.PostOffice - Routing cmd [SUB] for session [mqtt-explorer-c01516e8] to event processor 0
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - readCompleted client CId: mqtt-explorer-c01516e8
frost-web-mqtt | 08:27:48.355 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: <redacted>, messageId: 51900, topic: v1.1/Datastreams
frost-web-mqtt | 08:27:48.358 [Session Executor 0] DEBUG        i.m.i.BrokerInterceptor - Notifying MQTT SUBSCRIBE message to interceptor. CId=mqtt-explorer-c01516e8, topicFilter=v1.1/Datastreams, interceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)
frost-web-mqtt | 08:27:48.366 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C<-B SUBACK <mqtt-explorer-c01516e8> packetID <51900>, grantedQoses [0]
frost-web-mqtt | 08:27:48.370 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: <redacted>, messageId: 51901, topic: v1.1/Things(9)/Datastreams(83)/Observations
frost-web-mqtt | 08:27:48.371 [Session Executor 0] DEBUG        i.m.i.BrokerInterceptor - Notifying MQTT SUBSCRIBE message to interceptor. CId=mqtt-explorer-c01516e8, topicFilter=v1.1/Things(9)/Datastreams(83)/Observations, interceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)
frost-web-mqtt | 08:27:48.372 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C<-B SUBACK <mqtt-explorer-c01516e8> packetID <51901>, grantedQoses [2]
frost-web-mqtt | 08:27:48.936 [ pool-7-thread-1] INFO      d.f.i.i.f.mqtt.MqttManager - entityCreateQueue: 0, entityChangedQueue: 0, topics: 2

cat catalina.2023-03-08.log

08-Mar-2023 08:04:08.068 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.72
08-Mar-2023 08:04:08.075 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Feb 18 2023 09:25:13 UTC
08-Mar-2023 08:04:08.082 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.72.0
08-Mar-2023 08:04:08.083 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
08-Mar-2023 08:04:08.083 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.3.18-150300.59.93-default
08-Mar-2023 08:04:08.084 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
08-Mar-2023 08:04:08.084 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /opt/java/openjdk
08-Mar-2023 08:04:08.085 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           11.0.18+10
08-Mar-2023 08:04:08.085 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Eclipse Adoptium
08-Mar-2023 08:04:08.086 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
08-Mar-2023 08:04:08.086 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
08-Mar-2023 08:04:08.115 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
08-Mar-2023 08:04:08.116 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
08-Mar-2023 08:04:08.116 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
08-Mar-2023 08:04:08.117 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
08-Mar-2023 08:04:08.117 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
08-Mar-2023 08:04:08.118 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
08-Mar-2023 08:04:08.118 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
08-Mar-2023 08:04:08.118 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
08-Mar-2023 08:04:08.122 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
08-Mar-2023 08:04:08.122 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
08-Mar-2023 08:04:08.123 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
08-Mar-2023 08:04:08.123 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
08-Mar-2023 08:04:08.124 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
08-Mar-2023 08:04:08.124 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
08-Mar-2023 08:04:08.248 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.36] using APR version [1.7.0].
08-Mar-2023 08:04:08.248 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS >
08-Mar-2023 08:04:08.248 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
08-Mar-2023 08:04:08.256 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 3.0.2 15 Mar 2022]
08-Mar-2023 08:04:08.722 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
08-Mar-2023 08:04:08.745 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [1225] milliseconds
08-Mar-2023 08:04:08.807 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
08-Mar-2023 08:04:08.808 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.72]
08-Mar-2023 08:04:08.812 SEVERE [main] org.apache.catalina.startup.HostConfig.beforeStart Unable to create directory for deployment: [/usr/local/tomcat/conf/Catalina/localhost]
08-Mar-2023 08:04:08.820 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/FROST-Server]
08-Mar-2023 08:04:12.216 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a co>
08-Mar-2023 08:04:16.795 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/FROST-Server] has finished in >
08-Mar-2023 08:04:16.797 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
08-Mar-2023 08:04:16.827 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [8080] milliseconds

tail localhost_access_log.2023-03-08.txt

172.18.0.1 - - [08/Mar/2023:08:17:23 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-026%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:23 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:24 +0000] "GET /FROST-Server/v1.1 HTTP/1.1" 200 2455
172.18.0.1 - - [08/Mar/2023:08:17:25 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-027%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:25 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:26 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-028%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:26 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:27 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-029%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:27 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:27 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-030%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:27 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:27 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-031%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:28 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-032%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:28 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:30 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-033%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:30 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:32 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-034%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:32 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:33 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-035%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:33 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2003
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2
172.18.0.1 - - [08/Mar/2023:08:17:34 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 2157
172.18.0.1 - - [08/Mar/2023:08:17:35 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-036%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:35 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:37 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-037%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:37 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315
172.18.0.1 - - [08/Mar/2023:08:17:38 +0000] "GET /FROST-Server/v1.1/Sensors?$filter=name%20eq%27Sensor-SG-038%20ID1%27&$select=@iot.id,name,description&$expand=Datastreams($select=@iot.id,n>
172.18.0.1 - - [08/Mar/2023:08:17:38 +0000] "POST /FROST-Server/v1.1/CreateObservations HTTP/1.1" 201 6315

The log files

Thanks and BR, Michael

hylkevds commented 1 year ago

Can you also post the bit of the docker-compose output where FROST loads and echos all the settings that are in use?

Are you certain that you are posting Obs to Datastream 83, and that that Datastream is in Thing 9 (in other words, that v1.1/Things(9)/Datastreams(83)/Observations is correct)

mikedolx commented 1 year ago

Can you also post the bit of the docker-compose output where FROST loads and echos all the settings that are in use?

Sure. Here you go.

Just stumbled apon an exception, that i must have overlooked. It's in the log below, stating that a database upgrade failed.

frost-web-mqtt | NOTE: Picked up JDK_JAVA_OPTIONS:  --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
frost-web-mqtt | 08-Mar-2023 08:27:27.366 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version name:   Apache Tomcat/9.0.72
frost-web-mqtt | 08-Mar-2023 08:27:27.370 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Feb 18 2023 09:25:13 UTC
frost-web-mqtt | 08-Mar-2023 08:27:27.371 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version number: 9.0.72.0
frost-web-mqtt | 08-Mar-2023 08:27:27.371 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
frost-web-mqtt | 08-Mar-2023 08:27:27.371 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            5.3.18-150300.59.93-default
frost-web-mqtt | 08-Mar-2023 08:27:27.372 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
frost-web-mqtt | 08-Mar-2023 08:27:27.372 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /opt/java/openjdk
frost-web-mqtt | 08-Mar-2023 08:27:27.373 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           11.0.18+10
frost-web-mqtt | 08-Mar-2023 08:27:27.373 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Eclipse Adoptium
frost-web-mqtt | 08-Mar-2023 08:27:27.373 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /usr/local/tomcat
frost-web-mqtt | 08-Mar-2023 08:27:27.374 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /usr/local/tomcat
frost-web-mqtt | 08-Mar-2023 08:27:27.399 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
frost-web-mqtt | 08-Mar-2023 08:27:27.399 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
frost-web-mqtt | 08-Mar-2023 08:27:27.400 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
frost-web-mqtt | 08-Mar-2023 08:27:27.401 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
frost-web-mqtt | 08-Mar-2023 08:27:27.402 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
frost-web-mqtt | 08-Mar-2023 08:27:27.402 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/usr/local/tomcat/conf/logging.properties
frost-web-mqtt | 08-Mar-2023 08:27:27.403 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
frost-web-mqtt | 08-Mar-2023 08:27:27.403 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
frost-web-mqtt | 08-Mar-2023 08:27:27.403 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
frost-web-mqtt | 08-Mar-2023 08:27:27.404 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
frost-web-mqtt | 08-Mar-2023 08:27:27.404 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
frost-web-mqtt | 08-Mar-2023 08:27:27.405 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/usr/local/tomcat
frost-web-mqtt | 08-Mar-2023 08:27:27.405 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/usr/local/tomcat
frost-web-mqtt | 08-Mar-2023 08:27:27.406 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/usr/local/tomcat/temp
frost-web-mqtt | 08-Mar-2023 08:27:27.489 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent Loaded Apache Tomcat Native library [1.2.36] using APR version [1.7.0].
frost-web-mqtt | 08-Mar-2023 08:27:27.490 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [true].
frost-web-mqtt | 08-Mar-2023 08:27:27.490 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
frost-web-mqtt | 08-Mar-2023 08:27:27.496 INFO [main] org.apache.catalina.core.AprLifecycleListener.initializeSSL OpenSSL successfully initialized [OpenSSL 3.0.2 15 Mar 2022]
frost-web-mqtt | 08-Mar-2023 08:27:27.878 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
frost-web-mqtt | 08-Mar-2023 08:27:27.916 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [894] milliseconds
frost-web-mqtt | 08-Mar-2023 08:27:27.988 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
frost-web-mqtt | 08-Mar-2023 08:27:27.989 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.72]
frost-web-mqtt | 08-Mar-2023 08:27:27.992 SEVERE [main] org.apache.catalina.startup.HostConfig.beforeStart Unable to create directory for deployment: [/usr/local/tomcat/conf/Catalina/localhost]
frost-web-mqtt | 08-Mar-2023 08:27:28.008 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/FROST-Server]
frost-web-mqtt | 08-Mar-2023 08:27:32.055 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
frost-web-mqtt | 08:27:32.587 [            main] INFO   d.f.i.i.f.util.GitVersionInfo - FROST-Server.Core Version: 46e6362
frost-web-mqtt | 08:27:32.590 [            main] INFO  d.f.i.i.f.h.c.AbstractContextListener - Context initialised, loading settings.
frost-web-mqtt | 08:27:32.880 [            main] INFO     d.f.i.i.f.settings.Settings - Not set logSensitiveData, using default value 'false'.
frost-web-mqtt | 08:27:32.881 [            main] INFO     d.f.i.i.f.settings.Settings - Setting tempPath has value '/usr/local/tomcat/work/Catalina/localhost/FROST-Server'.
frost-web-mqtt | 08:27:32.881 [            main] INFO     d.f.i.i.f.settings.Settings - Setting serviceRootUrl has value 'https://frost-dev.solingen.de:8443/FROST-Server'.
frost-web-mqtt | 08:27:32.882 [            main] INFO     d.f.i.i.f.settings.Settings - Not set useAbsoluteNavigationLinks, using default value 'true'.
frost-web-mqtt | 08:27:32.882 [            main] INFO     d.f.i.i.f.settings.Settings - Not set defaultCount, using default value 'true'.
frost-web-mqtt | 08:27:32.882 [            main] INFO     d.f.i.i.f.settings.Settings - Not set defaultTop, using default value '100'.
frost-web-mqtt | 08:27:32.883 [            main] INFO     d.f.i.i.f.settings.Settings - Not set maxTop, using default value '100'.
frost-web-mqtt | 08:27:32.883 [            main] INFO     d.f.i.i.f.settings.Settings - Not set alwaysOrderbyId, using default value 'true'.
frost-web-mqtt | 08:27:32.883 [            main] INFO     d.f.i.i.f.settings.Settings - Not set maxDataSize, using default value '25000000'.
frost-web-mqtt | 08:27:32.884 [            main] INFO     d.f.i.i.f.settings.Settings - Not set extension.filterDelete.enable, using default value 'false'.
frost-web-mqtt | 08:27:32.886 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.mqttServerImplementationClass, using default value 'de.fraunhofer.iosb.ilt.sensorthingsserver.mqtt.moquette.MoquetteMqttServer'.
frost-web-mqtt | 08:27:32.886 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.Enabled, using default value 'true'.
frost-web-mqtt | 08:27:32.886 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.Port, using default value '1883'.
frost-web-mqtt | 08:27:32.887 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.Host, using default value '0.0.0.0'.
frost-web-mqtt | 08:27:32.887 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.internalHost, using default value 'localhost'.
frost-web-mqtt | 08:27:32.887 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.SubscribeMessageQueueSize has value '100'.
frost-web-mqtt | 08:27:32.888 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.SubscribeThreadPoolSize has value '20'.
frost-web-mqtt | 08:27:32.888 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.CreateMessageQueueSize has value '100'.
frost-web-mqtt | 08:27:32.888 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.CreateThreadPoolSize has value '10'.
frost-web-mqtt | 08:27:32.889 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.QoS has value '2'.
frost-web-mqtt | 08:27:32.890 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.persistenceManagerImplementationClass, using default value 'de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.PostgresPersistenceManager'.
frost-web-mqtt | 08:27:32.890 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.idGenerationMode, using default value 'ServerGeneratedOnly'.
frost-web-mqtt | 08:27:32.891 [            main] INFO     d.f.i.i.f.settings.Settings - Setting persistence.autoUpdateDatabase has value 'true'.
frost-web-mqtt | 08:27:32.891 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.slowQueryThreshold, using default value '200'.
frost-web-mqtt | 08:27:32.891 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.queryTimeout, using default value '0'.
frost-web-mqtt | 08:27:32.892 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.countMode, using default value 'full'.
frost-web-mqtt | 08:27:32.893 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.countEstimateThreshold, using default value '10000'.
frost-web-mqtt | 08:27:32.893 [            main] INFO     d.f.i.i.f.settings.Settings - Setting bus.busImplementationClass has value 'de.fraunhofer.iosb.ilt.frostserver.messagebus.InternalMessageBus'.
frost-web-mqtt | 08:27:32.894 [            main] INFO     d.f.i.i.f.settings.Settings - Not set extension.customLinks.enable, using default value 'false'.
frost-web-mqtt | 08:27:32.895 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.providedPlugins, using default value 'de.fraunhofer.iosb.ilt.frostserver.plugin.coremodel.PluginCoreService,de.fraunhofer.iosb.ilt.frostserver.plugin.coremodel.PluginCoreModel,de.fraunhofer.iosb.ilt.frostserver.formatter.PluginResultFormatDefault,de.fraunhofer.iosb.ilt.frostserver.plugin.actuation.PluginActuation,de.fraunhofer.iosb.ilt.frostserver.plugin.multidatastream.PluginMultiDatastream,de.fraunhofer.iosb.ilt.frostserver.plugin.batchprocessing.PluginBatchProcessing,de.fraunhofer.iosb.ilt.frostserver.plugin.format.dataarray.PluginResultFormatDataArray,de.fraunhofer.iosb.ilt.frostserver.plugin.format.csv.PluginResultFormatCsv,de.fraunhofer.iosb.ilt.frostserver.plugin.format.geojson.PluginResultFormatGeoJson,de.fraunhofer.iosb.ilt.frostserver.plugin.openapi.PluginOpenApi,de.fraunhofer.iosb.ilt.frostserver.plugin.odata.PluginOData,de.fraunhofer.iosb.ilt.frostserver.plugin.modelloader.PluginModelLoader'.
frost-web-mqtt | 08:27:32.895 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.plugins, using default value ''.
frost-web-mqtt | 08:27:32.895 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading plugins.
frost-web-mqtt | 08:27:32.896 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.coremodel.PluginCoreService
frost-web-mqtt | 08:27:32.897 [            main] INFO  d.f.i.i.f.p.c.PluginCoreService - Creating new Core Service Plugin.
frost-web-mqtt | 08:27:32.898 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreService.enable, using default value 'true'.
frost-web-mqtt | 08:27:32.900 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.coremodel.PluginCoreModel
frost-web-mqtt | 08:27:32.926 [            main] INFO   d.f.i.i.f.p.c.PluginCoreModel - Creating new Core Model Plugin.
frost-web-mqtt | 08:27:32.927 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.enable, using default value 'true'.
frost-web-mqtt | 08:27:32.928 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType, using default value 'LONG'.
frost-web-mqtt | 08:27:32.928 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.datastream, using default value 'LONG'.
frost-web-mqtt | 08:27:32.928 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.feature, using default value 'LONG'.
frost-web-mqtt | 08:27:32.929 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.historicalLocation, using default value 'LONG'.
frost-web-mqtt | 08:27:32.929 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.location, using default value 'LONG'.
frost-web-mqtt | 08:27:32.929 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.observedProperty, using default value 'LONG'.
frost-web-mqtt | 08:27:32.929 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.observation, using default value 'LONG'.
frost-web-mqtt | 08:27:32.930 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.sensor, using default value 'LONG'.
frost-web-mqtt | 08:27:32.930 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.coreModel.idType.thing, using default value 'LONG'.
frost-web-mqtt | 08:27:32.930 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.formatter.PluginResultFormatDefault
frost-web-mqtt | 08:27:32.932 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.actuation.PluginActuation
frost-web-mqtt | 08:27:32.936 [            main] INFO   d.f.i.i.f.p.a.PluginActuation - Creating new Actuation Plugin.
frost-web-mqtt | 08:27:32.937 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.actuation.enable, using default value 'false'.
frost-web-mqtt | 08:27:32.937 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.multidatastream.PluginMultiDatastream
frost-web-mqtt | 08:27:32.941 [            main] INFO  d.f.i.i.f.p.m.PluginMultiDatastream - Creating new MultiDatastream Plugin.
frost-web-mqtt | 08:27:32.942 [            main] INFO     d.f.i.i.f.settings.Settings - Setting plugins.multiDatastream.enable has value 'true'.
frost-web-mqtt | 08:27:32.942 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.multiDatastream.idType.multiDatastream, using default value 'LONG'.
frost-web-mqtt | 08:27:32.942 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.batchprocessing.PluginBatchProcessing
frost-web-mqtt | 08:27:32.944 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.batchProcessing.enable, using default value 'true'.
frost-web-mqtt | 08:27:32.944 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.format.dataarray.PluginResultFormatDataArray
frost-web-mqtt | 08:27:32.946 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.dataArray.enable, using default value 'true'.
frost-web-mqtt | 08:27:32.955 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.format.csv.PluginResultFormatCsv
frost-web-mqtt | 08:27:32.956 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.csv.enable, using default value 'true'.
frost-web-mqtt | 08:27:32.956 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.format.geojson.PluginResultFormatGeoJson
frost-web-mqtt | 08:27:32.957 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.geojson.enable, using default value 'true'.
frost-web-mqtt | 08:27:32.958 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.openapi.PluginOpenApi
frost-web-mqtt | 08:27:32.959 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.openApi.enable, using default value 'false'.
frost-web-mqtt | 08:27:32.959 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.odata.PluginOData
frost-web-mqtt | 08:27:32.961 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.odata.enable, using default value 'false'.
frost-web-mqtt | 08:27:32.961 [            main] INFO       d.f.i.i.f.s.PluginManager - Loading de.fraunhofer.iosb.ilt.frostserver.plugin.modelloader.PluginModelLoader
frost-web-mqtt | 08:27:32.962 [            main] INFO  d.f.i.i.f.p.m.PluginModelLoader - Creating new ModelLoader Plugin.
frost-web-mqtt | 08:27:32.963 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.modelLoader.enable, using default value 'false'.
frost-web-mqtt | 08:27:33.309 [            main] INFO  d.f.i.i.f.p.PersistenceManagerFactory - Running database update for de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.PostgresPersistenceManager
frost-web-mqtt | 08:27:33.309 [            main] INFO  d.f.i.i.f.p.p.PostgresPersistenceManager - Applying upgrades in liquibase/core.xml
frost-web-mqtt | 08:27:33.312 [            main] INFO     d.f.i.i.f.settings.Settings - Setting persistence.db.url has value '*****'.
frost-web-mqtt | 08:27:33.313 [            main] INFO  d.f.i.i.f.p.p.u.ConnectionUtils - Setting up BasicDataSource for database connections.
frost-web-mqtt | 08:27:33.313 [            main] INFO     d.f.i.i.f.settings.Settings - Setting persistence.db.driver has value 'org.postgresql.Driver'.
frost-web-mqtt | 08:27:33.332 [            main] INFO     d.f.i.i.f.settings.Settings - Setting persistence.db.url has value '*****'.
frost-web-mqtt | 08:27:33.332 [            main] INFO     d.f.i.i.f.settings.Settings - Setting persistence.db.username has value 'sensorthings'.
frost-web-mqtt | 08:27:33.332 [            main] INFO     d.f.i.i.f.settings.Settings - Setting persistence.db.password has value '*****'.
frost-web-mqtt | 08:27:33.333 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.db.conn.idle.max, using default value '8'.
frost-web-mqtt | 08:27:33.333 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.db.conn.max, using default value '8'.
frost-web-mqtt | 08:27:33.334 [            main] INFO     d.f.i.i.f.settings.Settings - Not set persistence.db.conn.idle.min, using default value '0'.
frost-web-mqtt | 08:27:33.956 [            main] INFO              liquibase.database - Set default schema name to public
frost-web-mqtt | 08:27:34.451 [            main] INFO           liquibase.lockservice - Successfully acquired change log lock
frost-web-mqtt | 08:27:35.116 [            main] INFO             liquibase.changelog - Reading from public.databasechangelog
frost-web-mqtt | 08:27:35.282 [            main] INFO           liquibase.lockservice - Successfully released change log lock
frost-web-mqtt | 08:27:35.288 [            main] INFO  d.f.i.i.f.p.p.u.LiquibaseHelper - Liquibase changed the search_path from '"$user", public' to 'public, "$user", public'. Changing it back.
frost-web-mqtt | 08:27:35.297 [            main] INFO  d.f.i.i.f.p.PersistenceManagerFactory - Database-update successful.
frost-web-mqtt | 08:27:35.297 [            main] INFO  d.f.i.i.f.p.PersistenceManagerFactory - Running database update for de.fraunhofer.iosb.ilt.frostserver.plugin.coremodel.PluginCoreModel
frost-web-mqtt | 08:27:35.298 [            main] INFO  d.f.i.i.f.p.p.PostgresPersistenceManager - Applying upgrades in liquibase/plugincoremodel/tables.xml
frost-web-mqtt | 08:27:35.321 [            main] INFO              liquibase.database - Set default schema name to public
frost-web-mqtt | 08:27:35.434 [            main] INFO           liquibase.lockservice - Successfully acquired change log lock
frost-web-mqtt | 08:27:35.786 [            main] INFO             liquibase.changelog - Reading from public.databasechangelog
frost-web-mqtt | 08:27:35.947 [            main] INFO           liquibase.lockservice - Successfully released change log lock
frost-web-mqtt | 08:27:35.956 [            main] INFO  d.f.i.i.f.p.p.u.LiquibaseHelper - Liquibase changed the search_path from '"$user", public' to 'public, "$user", public'. Changing it back.
frost-web-mqtt | 08:27:35.967 [            main] INFO  d.f.i.i.f.p.PersistenceManagerFactory - Database-update successful.
frost-web-mqtt | 08:27:35.967 [            main] INFO  d.f.i.i.f.p.PersistenceManagerFactory - Running database update for de.fraunhofer.iosb.ilt.frostserver.plugin.multidatastream.PluginMultiDatastream
frost-web-mqtt | 08:27:35.968 [            main] INFO  d.f.i.i.f.p.p.PostgresPersistenceManager - Applying upgrades in liquibase/pluginmultidatastream/tables.xml
frost-web-mqtt | 08:27:35.990 [            main] INFO              liquibase.database - Set default schema name to public
frost-web-mqtt | 08:27:36.102 [            main] INFO           liquibase.lockservice - Successfully acquired change log lock
frost-web-mqtt | 08:27:36.311 [            main] INFO             liquibase.changelog - Reading from public.databasechangelog
frost-web-mqtt | 08:27:36.469 [            main] INFO           liquibase.lockservice - Successfully released change log lock
frost-web-mqtt | 08:27:36.474 [            main] INFO  d.f.i.i.f.p.p.u.LiquibaseHelper - Liquibase changed the search_path from '"$user", public' to 'public, "$user", public'. Changing it back.
frost-web-mqtt | 08:27:36.519 [            main] INFO  d.f.i.i.f.p.PersistenceManagerFactory - Database-update successful.
frost-web-mqtt | 08:27:36.519 [            main] INFO   d.f.i.i.f.p.c.PluginCoreModel - Initialising Core Model Types...
frost-web-mqtt | 08:27:36.520 [            main] INFO  d.f.i.i.f.p.m.PluginMultiDatastream - Initialising MultiDatastream Types...
frost-web-mqtt | 08:27:36.521 [            main] INFO       d.f.i.i.f.s.PluginManager - Initialising data model plugins. Pass 1, 2 plugins.
frost-web-mqtt | 08:27:36.522 [            main] INFO   d.f.i.i.f.p.c.PluginCoreModel - Linking Core Model Types...
frost-web-mqtt | 08:27:36.546 [            main] INFO  d.f.i.i.f.p.m.PluginMultiDatastream - Linking MultiDatastream Types...
frost-web-mqtt | 08:27:36.549 [            main] INFO   d.f.i.i.f.model.ModelRegistry - Finalising 9 EntityTypes.
frost-web-mqtt | 08:27:36.550 [            main] INFO     d.f.i.i.f.settings.Settings - Setting http.cors.enable has value 'true'.
frost-web-mqtt | 08:27:36.551 [            main] INFO     d.f.i.i.f.settings.Settings - Setting http.cors.allowed.origins has value '*'.
frost-web-mqtt | 08:27:36.551 [            main] INFO     d.f.i.i.f.settings.Settings - Not set http.cors.allowed.methods, using default value 'GET,POST,HEAD,OPTIONS'.
frost-web-mqtt | 08:27:36.551 [            main] INFO     d.f.i.i.f.settings.Settings - Not set http.cors.exposed.headers, using default value 'Location'.
frost-web-mqtt | 08:27:36.552 [            main] INFO     d.f.i.i.f.settings.Settings - Not set http.cors.allowed.headers, using default value 'Origin, Accept, X-Requested-With, Content-Type, Access-Control-Request-Method, Access-Control-Request-Headers, Authorization'.
frost-web-mqtt | 08:27:36.552 [            main] INFO     d.f.i.i.f.settings.Settings - Not set http.cors.support.credentials, using default value 'false'.
frost-web-mqtt | 08:27:36.552 [            main] INFO     d.f.i.i.f.settings.Settings - Not set http.cors.preflight.maxage, using default value '1800'.
frost-web-mqtt | 08:27:36.552 [            main] INFO     d.f.i.i.f.settings.Settings - Not set http.cors.request.decorate, using default value 'true'.
frost-web-mqtt | 08:27:36.555 [            main] INFO     d.f.i.i.f.settings.Settings - Not set bus.workerPoolSize, using default value '2'.
frost-web-mqtt | 08:27:36.555 [            main] INFO     d.f.i.i.f.settings.Settings - Not set bus.queueSize, using default value '100'.
frost-web-mqtt | 08:27:36.560 [            main] INFO     d.f.i.i.f.settings.Settings - Setting auth.provider has value 'de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider'.
frost-web-mqtt | 08:27:36.560 [            main] INFO  d.f.i.i.f.h.c.AbstractContextListener - Turning on authentication.
frost-web-mqtt | 08:27:36.568 [            main] INFO   d.f.i.i.f.a.b.DatabaseHandler - Initialising DatabaseHandler.
frost-web-mqtt | 08:27:36.569 [            main] INFO     d.f.i.i.f.settings.Settings - Setting auth.autoUpdateDatabase has value 'true'.
frost-web-mqtt | 08:27:36.570 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.read, using default value 'read'.
frost-web-mqtt | 08:27:36.570 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.create, using default value 'create'.
frost-web-mqtt | 08:27:36.571 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.update, using default value 'update'.
frost-web-mqtt | 08:27:36.571 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.delete, using default value 'delete'.
frost-web-mqtt | 08:27:36.571 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.admin, using default value 'admin'.
frost-web-mqtt | 08:27:36.573 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.allowAnonymousRead, using default value 'false'.
frost-web-mqtt | 08:27:36.612 [            main] WARN   d.f.i.i.f.m.MqttServerFactory - Using MqttServerClass de.fraunhofer.iosb.ilt.frostserver.mqtt.moquette.MoquetteMqttServer instead of old name de.fraunhofer.iosb.ilt.sensorthingsserver.mqtt.moquette.MoquetteMqttServer
frost-web-mqtt | 08:27:36.621 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.immediate_buffer_flush, using default value 'true'.
frost-web-mqtt | 08:27:36.622 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.session_queue_size, using default value '1024'.
frost-web-mqtt | 08:27:36.622 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.session_timeout_seconds, using default value '3600'.
frost-web-mqtt | 08:27:36.623 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.netty.mqtt.message_size, using default value '8092'.
frost-web-mqtt | 08:27:36.623 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.persistentStoreType, using default value 'memory'.
frost-web-mqtt | 08:27:36.623 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.WebsocketPort, using default value '9876'.
frost-web-mqtt | 08:27:36.623 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.javaKeystorePath has value '/tmp/keystore.jks'.
frost-web-mqtt | 08:27:36.623 [            main] INFO  d.f.i.i.f.m.m.MoquetteMqttServer - Configuring keystore for ssl
frost-web-mqtt | 08:27:36.624 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.keyStorePassword has value '*****'.
frost-web-mqtt | 08:27:36.624 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.keyManagerPassword has value '*****'.
frost-web-mqtt | 08:27:36.624 [            main] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.sslPort has value '8883'.
frost-web-mqtt | 08:27:36.625 [            main] INFO     d.f.i.i.f.settings.Settings - Not set mqtt.secureWebsocketPort, using default value '443'.
frost-web-mqtt | 08:27:36.625 [            main] INFO     d.f.i.i.f.settings.Settings - Setting auth.provider has value 'de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider'.
frost-web-mqtt | 08:27:36.626 [            main] INFO       d.f.i.i.f.m.m.AuthWrapper - Initialising authentication.
frost-web-mqtt | 08:27:36.627 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.allowAnonymousRead, using default value 'false'.
frost-web-mqtt | 08:27:36.627 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.read, using default value 'read'.
frost-web-mqtt | 08:27:36.627 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.create, using default value 'create'.
frost-web-mqtt | 08:27:36.628 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.update, using default value 'update'.
frost-web-mqtt | 08:27:36.628 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.delete, using default value 'delete'.
frost-web-mqtt | 08:27:36.628 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.role.admin, using default value 'admin'.
frost-web-mqtt | 08:27:36.629 [            main] DEBUG      io.moquette.broker.Server - Configuring Using persistent store file, path: null
frost-web-mqtt | 08:27:36.629 [            main] INFO       io.moquette.broker.Server - Configuring message interceptors...
frost-web-mqtt | 08:27:36.631 [            main] INFO         i.m.i.BrokerInterceptor - Initializing broker interceptor. InterceptorIds=[SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)]
frost-web-mqtt | 08:27:36.633 [            main] INFO         i.m.i.BrokerInterceptor - Adding MQTT message interceptor. InterceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71), handledMessageTypes=[class io.moquette.interception.messages.InterceptConnectMessage, class io.moquette.interception.messages.InterceptDisconnectMessage, class io.moquette.interception.messages.InterceptConnectionLostMessage, class io.moquette.interception.messages.InterceptPublishMessage, class io.moquette.interception.messages.InterceptSubscribeMessage, class io.moquette.interception.messages.InterceptUnsubscribeMessage, class io.moquette.interception.messages.InterceptAcknowledgedMessage]
frost-web-mqtt | 08:27:36.634 [            main] DEBUG      io.moquette.broker.Server - Initialized MQTT protocol processor
frost-web-mqtt | 08:27:36.634 [            main] INFO       io.moquette.broker.Server - Using default SSL context creator
frost-web-mqtt | 08:27:36.635 [            main] DEBUG      io.moquette.broker.Server - Configuring MQTT authenticator
frost-web-mqtt | 08:27:36.636 [            main] DEBUG      io.moquette.broker.Server - Configuring MQTT authorizator policy
frost-web-mqtt | 08:27:36.638 [            main] INFO  i.m.b.s.CTrieSubscriptionDirectory - Initializing CTrie
frost-web-mqtt | 08:27:36.641 [            main] INFO  i.m.b.s.CTrieSubscriptionDirectory - Initializing subscriptions store...
frost-web-mqtt | 08:27:36.653 [            main] INFO      i.m.broker.SessionRegistry - Starting Session Cleaner.
frost-web-mqtt | 08:27:36.697 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Initializing Netty acceptor
frost-web-mqtt | 08:27:36.698 [            main] INFO     i.m.broker.NewNettyAcceptor - Netty is using NIO
frost-web-mqtt | 08:27:36.752 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Configuring TCP MQTT transport
frost-web-mqtt | 08:27:36.753 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Initializing integration. Protocol=TCP MQTT
frost-web-mqtt | 08:27:36.764 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Binding integration. host=0.0.0.0, port=1883
frost-web-mqtt | 08:27:36.831 [            main] INFO     i.m.broker.NewNettyAcceptor - Server bound to host=0.0.0.0, port=1883, protocol=TCP MQTT
frost-web-mqtt | 08:27:36.847 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Configuring Websocket MQTT transport
frost-web-mqtt | 08:27:36.848 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Initializing integration. Protocol=Websocket MQTT
frost-web-mqtt | 08:27:36.848 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Binding integration. host=0.0.0.0, port=9876
frost-web-mqtt | 08:27:36.849 [            main] INFO     i.m.broker.NewNettyAcceptor - Server bound to host=0.0.0.0, port=9876, protocol=Websocket MQTT
frost-web-mqtt | 08:27:36.850 [nioEventLoopGroup-2-1] DEBUG    i.m.broker.NewNettyAcceptor - bound TCP MQTT port: 1883
frost-web-mqtt | 08:27:36.852 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - Checking SSL configuration properties...
frost-web-mqtt | 08:27:36.853 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - Initializing SSL context. KeystorePath = /tmp/keystore.jks.
frost-web-mqtt | 08:27:36.856 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - Loading keystore. KeystorePath = /tmp/keystore.jks.
frost-web-mqtt | 08:27:36.856 [            main] WARN  i.m.b.DefaultMoquetteSslContextCreator - No keystore has been found in the bundled resources. Scanning filesystem...
frost-web-mqtt | 08:27:36.857 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - Loading external keystore. Url = /tmp/keystore.jks.
frost-web-mqtt | 08:27:36.857 [nioEventLoopGroup-2-2] DEBUG    i.m.broker.NewNettyAcceptor - bound Websocket MQTT port: 9876
frost-web-mqtt | 08:27:36.859 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - Initializing key manager...
frost-web-mqtt | 08:27:36.861 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - Initializing SSL context...
frost-web-mqtt | 08:27:36.924 [            main] INFO  i.m.b.DefaultMoquetteSslContextCreator - The SSL context has been initialized successfully.
frost-web-mqtt | 08:27:36.924 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Configuring SSL MQTT transport
frost-web-mqtt | 08:27:36.924 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Starting SSL on port 8883
frost-web-mqtt | 08:27:36.924 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Initializing integration. Protocol=SSL MQTT
frost-web-mqtt | 08:27:36.924 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Binding integration. host=0.0.0.0, port=8883
frost-web-mqtt | 08:27:36.925 [            main] INFO     i.m.broker.NewNettyAcceptor - Server bound to host=0.0.0.0, port=8883, protocol=SSL MQTT
frost-web-mqtt | 08:27:36.926 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Configuring secure websocket MQTT transport
frost-web-mqtt | 08:27:36.927 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Initializing integration. Protocol=Secure websocket
frost-web-mqtt | 08:27:36.927 [            main] DEBUG    i.m.broker.NewNettyAcceptor - Binding integration. host=0.0.0.0, port=443
frost-web-mqtt | 08:27:36.927 [nioEventLoopGroup-2-3] DEBUG    i.m.broker.NewNettyAcceptor - bound SSL MQTT port: 8883
frost-web-mqtt | 08:27:36.934 [            main] INFO     i.m.broker.NewNettyAcceptor - Server bound to host=0.0.0.0, port=443, protocol=Secure websocket
frost-web-mqtt | 08:27:36.935 [            main] INFO       io.moquette.broker.Server - Moquette integration has been started successfully in 307 ms
frost-web-mqtt | 08:27:36.935 [            main] INFO     d.f.i.i.f.settings.Settings - Setting queueLoggingInterval has value '1000'.
frost-web-mqtt | 08:27:36.936 [nioEventLoopGroup-2-4] DEBUG    i.m.broker.NewNettyAcceptor - bound Secure websocket port: 443
frost-web-mqtt | 08:27:36.948 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Turning on Basic authentication.
frost-web-mqtt | 08:27:36.948 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting roleAdmin, set to value: admin
frost-web-mqtt | 08:27:36.948 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting roleGet, set to value: admin
frost-web-mqtt | 08:27:36.949 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting rolePost, set to value: admin
frost-web-mqtt | 08:27:36.949 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting rolePatch, set to value: admin
frost-web-mqtt | 08:27:36.949 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting rolePut, set to value: admin
frost-web-mqtt | 08:27:36.949 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting roleDelete, set to value: admin
frost-web-mqtt | 08:27:36.949 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting allowAnonymousRead, using default value: F
frost-web-mqtt | 08:27:36.950 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.realmName, using default value 'FROST-Server'.
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Turning on Basic authentication.
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting roleAdmin, set to value: admin
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting roleGet, set to value: read
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting rolePost, set to value: create
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting rolePatch, set to value: update
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting rolePut, set to value: update
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting roleDelete, set to value: delete
frost-web-mqtt | 08:27:36.952 [            main] INFO   d.f.i.i.f.a.b.BasicAuthFilter - Filter setting allowAnonymousRead, set to value: F
frost-web-mqtt | 08:27:36.953 [            main] INFO     d.f.i.i.f.settings.Settings - Not set auth.realmName, using default value 'FROST-Server'.
frost-web-mqtt | 08-Mar-2023 08:27:36.966 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/FROST-Server] has finished in [8,958] ms
frost-web-mqtt | 08-Mar-2023 08:27:36.968 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
frost-web-mqtt | 08-Mar-2023 08:27:37.034 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [9117] milliseconds
frost-web-mqtt | 08:27:37.098 [http-nio-8080-exec-1] INFO   d.f.i.i.f.a.b.DatabaseHandler - Running database update for de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.url has value '*****'.
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO  d.f.i.i.f.p.p.u.ConnectionUtils - Setting up BasicDataSource for database connections.
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.driver has value 'org.postgresql.Driver'.
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.url has value '*****'.
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.username has value 'sensorthings'.
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.password has value '*****'.
frost-web-mqtt | 08:27:37.099 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Not set auth.db.conn.idle.max, using default value '8'.
frost-web-mqtt | 08:27:37.100 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Not set auth.db.conn.max, using default value '8'.
frost-web-mqtt | 08:27:37.100 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Not set auth.db.conn.idle.min, using default value '0'.
frost-web-mqtt | 08:27:37.217 [http-nio-8080-exec-1] INFO              liquibase.database - Set default schema name to public
frost-web-mqtt | 08:27:37.362 [nioEventLoopGroup-3-1] DEBUG    i.m.broker.AutoFlushHandler - Initializing autoflush handler on channel [id: 0x48ddd68c, L:/172.18.0.2:8883 - R:/62.217.43.10:65373] Cid: null
frost-web-mqtt | 08:27:37.438 [http-nio-8080-exec-1] INFO           liquibase.lockservice - Successfully acquired change log lock
frost-web-mqtt | 08:27:37.545 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - readCompleted client CId: null
frost-web-mqtt | 08:27:37.596 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C->B CONNECT <null>
frost-web-mqtt | 08:27:37.596 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Received MQTT message, type: CONNECT
frost-web-mqtt | 08:27:37.597 [nioEventLoopGroup-3-1] INFO   d.f.i.i.f.a.b.DatabaseHandler - Running database update for de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider
frost-web-mqtt | 08:27:37.650 [http-nio-8080-exec-1] INFO             liquibase.changelog - Reading from public.databasechangelog
frost-web-mqtt | 08:27:37.658 [nioEventLoopGroup-3-1] INFO              liquibase.database - Set default schema name to public
frost-web-mqtt | 08:27:37.798 [nioEventLoopGroup-3-1] INFO           liquibase.lockservice - Waiting for changelog lock....
frost-web-mqtt | 08:27:37.839 [http-nio-8080-exec-1] INFO           liquibase.lockservice - Successfully released change log lock
frost-web-mqtt | 08:27:37.848 [http-nio-8080-exec-1] ERROR d.f.i.i.f.p.p.u.LiquibaseHelper - Failed to upgrade database
frost-web-mqtt | liquibase.exception.LiquibaseException: java.lang.RuntimeException: Cannot end scope phcijjcgii when currently at scope pdvsvvtqfa
frost-web-mqtt |        at liquibase.Liquibase.runInScope(Liquibase.java:2410)
frost-web-mqtt |        at liquibase.Liquibase.update(Liquibase.java:211)
frost-web-mqtt |        at liquibase.Liquibase.update(Liquibase.java:197)
frost-web-mqtt |        at liquibase.Liquibase.update(Liquibase.java:193)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.utils.LiquibaseHelper.runLiquibaseUpdate(LiquibaseHelper.java:95)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.utils.LiquibaseHelper.doUpgrades(LiquibaseHelper.java:66)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.DatabaseHandler.doUpgrades(DatabaseHandler.java:187)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider.doUpgrades(BasicAuthProvider.java:84)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.util.LiquibaseUtils.maybeUpdateDatabase(LiquibaseUtils.java:49)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.DatabaseHandler.maybeUpdateDatabase(DatabaseHandler.java:168)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.DatabaseHandler.isValidUser(DatabaseHandler.java:87)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthFilter.findCredentials(BasicAuthFilter.java:130)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthFilter.doFilter(BasicAuthFilter.java:168)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.catalina.filters.CorsFilter.handleNonCORS(CorsFilter.java:328)
frost-web-mqtt |        at org.apache.catalina.filters.CorsFilter.doFilter(CorsFilter.java:158)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
frost-web-mqtt |        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
frost-web-mqtt |        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
frost-web-mqtt |        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130)
frost-web-mqtt |        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
frost-web-mqtt |        at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:673)
frost-web-mqtt |        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
frost-web-mqtt |        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
frost-web-mqtt |        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
frost-web-mqtt |        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
frost-web-mqtt |        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:926)
frost-web-mqtt |        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1791)
frost-web-mqtt |        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
frost-web-mqtt |        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
frost-web-mqtt |        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
frost-web-mqtt |        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
frost-web-mqtt |        at java.base/java.lang.Thread.run(Thread.java:829)
frost-web-mqtt | Caused by: java.lang.RuntimeException: Cannot end scope phcijjcgii when currently at scope pdvsvvtqfa
frost-web-mqtt |        at liquibase.Scope.exit(Scope.java:230)
frost-web-mqtt |        at liquibase.Scope.child(Scope.java:191)
frost-web-mqtt |        at liquibase.Scope.child(Scope.java:179)
frost-web-mqtt |        at liquibase.Scope.child(Scope.java:158)
frost-web-mqtt |        at liquibase.Liquibase.runInScope(Liquibase.java:2405)
frost-web-mqtt |        ... 38 common frames omitted
frost-web-mqtt | 08:27:37.851 [http-nio-8080-exec-1] ERROR  d.f.i.i.f.a.b.DatabaseHandler - Database upgrade failed.
frost-web-mqtt | de.fraunhofer.iosb.ilt.frostserver.util.exception.UpgradeFailedException: liquibase.exception.LiquibaseException: java.lang.RuntimeException: Cannot end scope phcijjcgii when currently at scope pdvsvvtqfa
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.utils.LiquibaseHelper.runLiquibaseUpdate(LiquibaseHelper.java:100)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.utils.LiquibaseHelper.doUpgrades(LiquibaseHelper.java:66)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.DatabaseHandler.doUpgrades(DatabaseHandler.java:187)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthProvider.doUpgrades(BasicAuthProvider.java:84)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.util.LiquibaseUtils.maybeUpdateDatabase(LiquibaseUtils.java:49)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.DatabaseHandler.maybeUpdateDatabase(DatabaseHandler.java:168)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.DatabaseHandler.isValidUser(DatabaseHandler.java:87)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthFilter.findCredentials(BasicAuthFilter.java:130)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthFilter.doFilter(BasicAuthFilter.java:168)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.catalina.filters.CorsFilter.handleNonCORS(CorsFilter.java:328)
frost-web-mqtt |        at org.apache.catalina.filters.CorsFilter.doFilter(CorsFilter.java:158)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
frost-web-mqtt |        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
frost-web-mqtt |        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
frost-web-mqtt |        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130)
frost-web-mqtt |        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
frost-web-mqtt |        at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:673)
frost-web-mqtt |        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
frost-web-mqtt |        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
frost-web-mqtt |        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
frost-web-mqtt |        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
frost-web-mqtt |        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:926)
frost-web-mqtt |        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1791)
frost-web-mqtt |        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
frost-web-mqtt |        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
frost-web-mqtt |        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
frost-web-mqtt |        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
frost-web-mqtt |        at java.base/java.lang.Thread.run(Thread.java:829)
frost-web-mqtt | Caused by: liquibase.exception.LiquibaseException: java.lang.RuntimeException: Cannot end scope phcijjcgii when currently at scope pdvsvvtqfa
frost-web-mqtt |        at liquibase.Liquibase.runInScope(Liquibase.java:2410)
frost-web-mqtt |        at liquibase.Liquibase.update(Liquibase.java:211)
frost-web-mqtt |        at liquibase.Liquibase.update(Liquibase.java:197)
frost-web-mqtt |        at liquibase.Liquibase.update(Liquibase.java:193)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.persistence.pgjooq.utils.LiquibaseHelper.runLiquibaseUpdate(LiquibaseHelper.java:95)
frost-web-mqtt |        ... 34 common frames omitted
frost-web-mqtt | Caused by: java.lang.RuntimeException: Cannot end scope phcijjcgii when currently at scope pdvsvvtqfa
frost-web-mqtt |        at liquibase.Scope.exit(Scope.java:230)
frost-web-mqtt |        at liquibase.Scope.child(Scope.java:191)
frost-web-mqtt |        at liquibase.Scope.child(Scope.java:179)
frost-web-mqtt |        at liquibase.Scope.child(Scope.java:158)
frost-web-mqtt |        at liquibase.Liquibase.runInScope(Liquibase.java:2405)
frost-web-mqtt |        ... 38 common frames omitted
frost-web-mqtt | 08:27:37.852 [http-nio-8080-exec-1] INFO   d.f.i.i.f.a.b.DatabaseHandler - Database-update-log:
frost-web-mqtt | Failed to upgrade database:
frost-web-mqtt | java.lang.RuntimeException: Cannot end scope phcijjcgii when currently at scope pdvsvvtqfa
frost-web-mqtt |
frost-web-mqtt | 08:27:37.853 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.url has value '*****'.
frost-web-mqtt | 08:27:37.853 [http-nio-8080-exec-1] INFO  d.f.i.i.f.p.p.u.ConnectionUtils - Setting up BasicDataSource for database connections.
frost-web-mqtt | 08:27:37.853 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.driver has value 'org.postgresql.Driver'.
frost-web-mqtt | 08:27:37.853 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.url has value '*****'.
frost-web-mqtt | 08:27:37.853 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.username has value 'sensorthings'.
frost-web-mqtt | 08:27:37.854 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting auth.db.password has value '*****'.
frost-web-mqtt | 08:27:37.854 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Not set auth.db.conn.idle.max, using default value '8'.
frost-web-mqtt | 08:27:37.854 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Not set auth.db.conn.max, using default value '8'.
frost-web-mqtt | 08:27:37.854 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Not set auth.db.conn.idle.min, using default value '0'.
frost-web-mqtt | 08:27:37.936 [ pool-7-thread-1] INFO      d.f.i.i.f.mqtt.MqttManager - entityCreateQueue: 0, entityChangedQueue: 0, topics: 0
frost-web-mqtt | 08:27:38.372 [http-nio-8080-exec-1] INFO              org.jooq.Constants -
frost-web-mqtt |
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@  @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@  @@  @@    @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@  @@@@  @@  @@    @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@    @@  @@  @@@@  @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@    @@  @@  @@@@  @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@  @  @  @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@        @@        @@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@  @@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
frost-web-mqtt | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  Thank you for using jOOQ 3.16.14
frost-web-mqtt |
frost-web-mqtt | 08:27:38.375 [http-nio-8080-exec-1] INFO              org.jooq.Constants -
frost-web-mqtt |
frost-web-mqtt | jOOQ tip of the day: Whenever jOOQ doesn't support a native SQL feature, use plain SQL templating: https://www.jooq.org/doc/latest/manual/sql-building/plain-sql-templating/
frost-web-mqtt |
frost-web-mqtt | 08:27:38.495 [http-nio-8080-exec-1] INFO     d.f.i.i.f.settings.Settings - Setting mqtt.exposedEndpoints has value '"mqtt://frost-dev.<redacted>.de:8883"'.
frost-web-mqtt | 08:27:47.888 [nioEventLoopGroup-3-1] INFO           liquibase.lockservice - Successfully acquired change log lock
frost-web-mqtt | 08:27:48.070 [nioEventLoopGroup-3-1] INFO             liquibase.changelog - Reading from public.databasechangelog
frost-web-mqtt | 08:27:48.272 [nioEventLoopGroup-3-1] INFO           liquibase.lockservice - Successfully released change log lock
frost-web-mqtt | 08:27:48.281 [nioEventLoopGroup-3-1] INFO  d.f.i.i.f.p.p.u.LiquibaseHelper - Liquibase changed the search_path from '"$user", public' to 'public, "$user", public'. Changing it back.
frost-web-mqtt | 08:27:48.285 [nioEventLoopGroup-3-1] INFO   d.f.i.i.f.a.b.DatabaseHandler - Database-update successful.
frost-web-mqtt | 08:27:48.299 [nioEventLoopGroup-3-1] DEBUG  io.moquette.broker.PostOffice - Routing cmd [CONN] for session [mqtt-explorer-c01516e8] to event processor 0
frost-web-mqtt | 08:27:48.301 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - readCompleted client CId: null
frost-web-mqtt | 08:27:48.307 [nioEventLoopGroup-3-1] DEBUG      i.m.b.m.MQTTMessageLogger - C<-B CONNACK <null>
frost-web-mqtt | 08:27:48.310 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Connection has been configured CId=mqtt-explorer-c01516e8, keepAlive=60, removeTemporaryQoS2=true, idleTime=90
frost-web-mqtt | 08:27:48.311 [nioEventLoopGroup-3-1] DEBUG    i.m.broker.InflightResender - Initializing autoflush handler on channel [id: 0x48ddd68c, L:/172.18.0.2:8883 - R:/62.217.43.10:65373]
frost-web-mqtt | 08:27:48.312 [nioEventLoopGroup-3-1] DEBUG        i.m.i.BrokerInterceptor - Sending MQTT CONNECT message to interceptor. CId=mqtt-explorer-c01516e8, interceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)
frost-web-mqtt | 08:27:48.347 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C->B SUBSCRIBE <mqtt-explorer-c01516e8> to topics [MqttTopicSubscription[topicFilter=v1.1/Datastreams, option=SubscriptionOption[qos=AT_MOST_ONCE, noLocal=false, retainAsPublished=false, retainHandling=SEND_AT_SUBSCRIBE]]]
frost-web-mqtt | 08:27:48.348 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Received MQTT message, type: SUBSCRIBE
frost-web-mqtt | 08:27:48.349 [nioEventLoopGroup-3-1] DEBUG  io.moquette.broker.PostOffice - Routing cmd [SUB] for session [mqtt-explorer-c01516e8] to event processor 0
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C->B SUBSCRIBE <mqtt-explorer-c01516e8> to topics [MqttTopicSubscription[topicFilter=v1.1/Things(9)/Datastreams(83)/Observations, option=SubscriptionOption[qos=EXACTLY_ONCE, noLocal=false, retainAsPublished=false, retainHandling=SEND_AT_SUBSCRIBE]]]
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - Received MQTT message, type: SUBSCRIBE
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] DEBUG  io.moquette.broker.PostOffice - Routing cmd [SUB] for session [mqtt-explorer-c01516e8] to event processor 0
frost-web-mqtt | 08:27:48.352 [nioEventLoopGroup-3-1] DEBUG      i.m.broker.MQTTConnection - readCompleted client CId: mqtt-explorer-c01516e8
frost-web-mqtt | 08:27:48.355 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: <redacted>, messageId: 51900, topic: v1.1/Datastreams
frost-web-mqtt | 08:27:48.358 [Session Executor 0] DEBUG        i.m.i.BrokerInterceptor - Notifying MQTT SUBSCRIBE message to interceptor. CId=mqtt-explorer-c01516e8, topicFilter=v1.1/Datastreams, interceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)
frost-web-mqtt | 08:27:48.366 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C<-B SUBACK <mqtt-explorer-c01516e8> packetID <51900>, grantedQoses [0]
frost-web-mqtt | 08:27:48.370 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: <redacted>, messageId: 51901, topic: v1.1/Things(9)/Datastreams(83)/Observations
frost-web-mqtt | 08:27:48.371 [Session Executor 0] DEBUG        i.m.i.BrokerInterceptor - Notifying MQTT SUBSCRIBE message to interceptor. CId=mqtt-explorer-c01516e8, topicFilter=v1.1/Things(9)/Datastreams(83)/Observations, interceptorId=SensorThings API Server (721b1228-1c01-4ef3-9547-9cbba088ac71)
frost-web-mqtt | 08:27:48.372 [nioEventLoopGroup-3-1] INFO       i.m.b.m.MQTTMessageLogger - C<-B SUBACK <mqtt-explorer-c01516e8> packetID <51901>, grantedQoses [2]
frost-web-mqtt | 08:27:48.936 [ pool-7-thread-1] INFO      d.f.i.i.f.mqtt.MqttManager - entityCreateQueue: 0, entityChangedQueue: 0, topics: 2

Are you certain that you are posting Obs to Datastream 83, and that that Datastream is in Thing 9 (in other words, that v1.1/Things(9)/Datastreams(83)/Observations is correct)

Yes, as i had that set up previously running with FROST v1.14.2 in docker. I did receive all the observations from that datastream/thing. The topic might be a bit too long, but i kept it as it was working.

Edit: typo, added docker

hylkevds commented 1 year ago

Can you test if the topic v1.1/Observations gives results?

mikedolx commented 1 year ago

The topic does not return any results. On the other hand i do not get any Observations after 9am, allthough the cron script does not complain about any errors.

mikedolx commented 1 year ago

Small addition: I have enabled the batch processing plugin by setting the docker-compose environment variable to plugins_batchProcessing_enable=true. Not sure if the notation is correct. AFAIR, i can take the settings from here and just replace the dot with _.

hylkevds commented 1 year ago

I've not been able to reproduce the problem yet.

Can you try setting auth_autoUpdateDatabase=false, so that there is no exception?

Does it work when posting individual Observations (not using DataArrays)?

At startup FROST echos all settings it reads, and whether it is using the default value, or a provided value. For example:

frost-web-mqtt | 08:27:32.944 [            main] INFO     d.f.i.i.f.settings.Settings - Not set plugins.batchProcessing.enable, using default value 'true'.

In this case there was no variable plugins_batchProcessing_enable, so it's using the default value.

mikedolx commented 1 year ago

Can you try setting auth_autoUpdateDatabase=false, so that there is no exception?

Yes, still no messages on MQTT.

Does it work when posting individual Observations (not using DataArrays)?

Yes, i have a small python-script, that creates single Observations. After creating an Observation, i get an update in my MQTT-Explorer.

In this case there was no variable plugins_batchProcessing_enable, so it's using the default value.

I saw that in the logs. I thought, that we might have an issue, because the DataArray plugin is not enabled. But as i understand, the default value for that plugin is true, therefore enabled.

What puzzles me is, that the cron-script seemingly works. It does not complain about any errors from the server.

I have added FROST_LL_parser=DEBUG to the docker-compose.yml to see if there is any problem. As it seems, the GET-Requests from the script seem to work. But i would have expecet to see "Observations" in the logs, which i don't.

frost-web-mqtt | 12:31:01.136 [http-nio-8080-exec-4] DEBUG    d.f.i.i.f.p.path.PathParser - Parsing: /Sensors
frost-web-mqtt | 12:31:01.137 [http-nio-8080-exec-4] DEBUG    d.f.i.i.f.p.path.PathParser - IdentifiedPath
frost-web-mqtt | 12:31:01.137 [http-nio-8080-exec-4] DEBUG    d.f.i.i.f.p.path.PathParser - EntityType : (String)Sensors
frost-web-mqtt | 12:31:01.275 [http-nio-8080-exec-5] DEBUG    d.f.i.i.f.p.path.PathParser - Parsing: /Sensors
frost-web-mqtt | 12:31:01.275 [http-nio-8080-exec-5] DEBUG    d.f.i.i.f.p.path.PathParser - IdentifiedPath
frost-web-mqtt | 12:31:01.275 [http-nio-8080-exec-5] DEBUG    d.f.i.i.f.p.path.PathParser - EntityType : (String)Sensors
frost-web-mqtt | 12:31:01.643 [http-nio-8080-exec-6] DEBUG    d.f.i.i.f.p.path.PathParser - Parsing: /Sensors
frost-web-mqtt | 12:31:01.643 [http-nio-8080-exec-6] DEBUG    d.f.i.i.f.p.path.PathParser - IdentifiedPath
frost-web-mqtt | 12:31:01.643 [http-nio-8080-exec-6] DEBUG    d.f.i.i.f.p.path.PathParser - EntityType : (String)Sensors
frost-web-mqtt | 12:31:02.011 [http-nio-8080-exec-7] DEBUG    d.f.i.i.f.p.path.PathParser - Parsing: /Sensors
frost-web-mqtt | 12:31:02.013 [http-nio-8080-exec-7] DEBUG    d.f.i.i.f.p.path.PathParser - IdentifiedPath
frost-web-mqtt | 12:31:02.014 [http-nio-8080-exec-7] DEBUG    d.f.i.i.f.p.path.PathParser - EntityType : (String)Sensors
frost-web-mqtt | 12:31:02.404 [http-nio-8080-exec-9] DEBUG    d.f.i.i.f.p.path.PathParser - Parsing: /Sensors
frost-web-mqtt | 12:31:02.404 [http-nio-8080-exec-9] DEBUG    d.f.i.i.f.p.path.PathParser - IdentifiedPath
frost-web-mqtt | 12:31:02.404 [http-nio-8080-exec-9] DEBUG    d.f.i.i.f.p.path.PathParser - EntityType : (String)Sensors
frost-web-mqtt | 12:31:03.188 [http-nio-8080-exec-10] DEBUG    d.f.i.i.f.p.path.PathParser - Parsing: /Sensors
frost-web-mqtt | 12:31:03.188 [http-nio-8080-exec-10] DEBUG    d.f.i.i.f.p.path.PathParser - IdentifiedPath
frost-web-mqtt | 12:31:03.188 [http-nio-8080-exec-10] DEBUG    d.f.i.i.f.p.path.PathParser - EntityType : (String)Sensors

In Addition i could observe exception below, but i don't think, that these are relevant. Somehow i think, the initial import does not work using DataArrays.

The exceptions:

frost-web-mqtt | 12:30:45.549 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: solingenReader, messageId: 55634, topic: v1.1/Datastreams
frost-web-mqtt | 12:30:45.550 [Session Executor 0] INFO     i.m.broker.SessionEventLoop - SessionEventLoop Session Executor 0 reached exception in processing command
frost-web-mqtt | java.util.concurrent.ExecutionException: java.lang.NullPointerException
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.executeTask(SessionEventLoop.java:49)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.run(SessionEventLoop.java:34)
frost-web-mqtt |        at java.base/java.lang.Thread.run(Thread.java:829)
frost-web-mqtt | Caused by: java.lang.NullPointerException: null
frost-web-mqtt |        at io.moquette.broker.PostOffice.subscribeClientToTopics(PostOffice.java:236)
frost-web-mqtt |        at io.moquette.broker.MQTTConnection.lambda$processSubscribe$6(MQTTConnection.java:375)
frost-web-mqtt |        at io.moquette.broker.SessionCommand.execute(SessionCommand.java:23)
frost-web-mqtt |        at io.moquette.broker.PostOffice.lambda$routeCommand$5(PostOffice.java:635)
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.executeTask(SessionEventLoop.java:46)
frost-web-mqtt |        ... 2 common frames omitted
frost-web-mqtt | 12:30:45.556 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: solingenReader, messageId: 55635, topic: v1.1/Things(9)/Datastreams(83)/Observations
frost-web-mqtt | 12:30:45.557 [Session Executor 0] INFO     i.m.broker.SessionEventLoop - SessionEventLoop Session Executor 0 reached exception in processing command
frost-web-mqtt | java.util.concurrent.ExecutionException: java.lang.NullPointerException
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.executeTask(SessionEventLoop.java:49)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.run(SessionEventLoop.java:34)
frost-web-mqtt |        at java.base/java.lang.Thread.run(Thread.java:829)
frost-web-mqtt | Caused by: java.lang.NullPointerException: null
frost-web-mqtt |        at io.moquette.broker.PostOffice.subscribeClientToTopics(PostOffice.java:236)
frost-web-mqtt |        at io.moquette.broker.MQTTConnection.lambda$processSubscribe$6(MQTTConnection.java:375)
frost-web-mqtt |        at io.moquette.broker.SessionCommand.execute(SessionCommand.java:23)
frost-web-mqtt |        at io.moquette.broker.PostOffice.lambda$routeCommand$5(PostOffice.java:635)
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.executeTask(SessionEventLoop.java:46)
frost-web-mqtt |        ... 2 common frames omitted
frost-web-mqtt | 12:30:45.560 [Session Executor 0] DEBUG i.moquette.broker.Authorizator - Client will be subscribed to the topic username: solingenReader, messageId: 55636, topic: v1.1/Observations
frost-web-mqtt | 12:30:45.561 [Session Executor 0] INFO     i.m.broker.SessionEventLoop - SessionEventLoop Session Executor 0 reached exception in processing command
frost-web-mqtt | java.util.concurrent.ExecutionException: java.lang.NullPointerException
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.executeTask(SessionEventLoop.java:49)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.run(SessionEventLoop.java:34)
frost-web-mqtt |        at java.base/java.lang.Thread.run(Thread.java:829)
frost-web-mqtt | Caused by: java.lang.NullPointerException: null
frost-web-mqtt |        at io.moquette.broker.PostOffice.subscribeClientToTopics(PostOffice.java:236)
frost-web-mqtt |        at io.moquette.broker.MQTTConnection.lambda$processSubscribe$6(MQTTConnection.java:375)
frost-web-mqtt |        at io.moquette.broker.SessionCommand.execute(SessionCommand.java:23)
frost-web-mqtt |        at io.moquette.broker.PostOffice.lambda$routeCommand$5(PostOffice.java:635)
frost-web-mqtt |        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
frost-web-mqtt |        at io.moquette.broker.SessionEventLoop.executeTask(SessionEventLoop.java:46)
frost-web-mqtt |        ... 2 common frames omitted

The exception above complains about the topics, that i have subscribed in my MQTT-Explorer.

mikedolx commented 1 year ago

After enabling FROST_LL_service=DEBUG i found this:

12:41:05.481 [http-nio-8080-exec-5] DEBUG d.f.i.i.f.p.f.d.ServiceDataArray - Failed to create entity
frost-web-mqtt | java.lang.IllegalArgumentException: phenomenonTime could not be parsed as time instant or time interval.
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.plugin.format.dataarray.ArrayValueHandlers.lambda$createDefaults$4(ArrayValueHandlers.java:99)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.plugin.format.dataarray.ServiceDataArray.handleDataArrayItems(ServiceDataArray.java:138)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.plugin.format.dataarray.ServiceDataArray.executeCreateObservations(ServiceDataArray.java:99)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.plugin.format.dataarray.PluginResultFormatDataArray.execute(PluginResultFormatDataArray.java:124)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.http.common.ServletMain.executeService(ServletMain.java:113)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.http.common.ServletMain.processRequest(ServletMain.java:95)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.http.common.ServletMain.doPost(ServletMain.java:140)
frost-web-mqtt |        at javax.servlet.http.HttpServlet.service(HttpServlet.java:528)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.http.common.ServletMain.service(ServletMain.java:173)
frost-web-mqtt |        at javax.servlet.http.HttpServlet.service(HttpServlet.java:596)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:209)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at de.fraunhofer.iosb.ilt.frostserver.auth.basic.BasicAuthFilter.doFilter(BasicAuthFilter.java:182)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.catalina.filters.CorsFilter.handleNonCORS(CorsFilter.java:328)
frost-web-mqtt |        at org.apache.catalina.filters.CorsFilter.doFilter(CorsFilter.java:158)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:178)
frost-web-mqtt |        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:153)
frost-web-mqtt |        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
frost-web-mqtt |        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
frost-web-mqtt |        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
frost-web-mqtt |        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:130)
frost-web-mqtt |        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
frost-web-mqtt |        at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:673)
frost-web-mqtt |        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
frost-web-mqtt |        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
frost-web-mqtt |        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
frost-web-mqtt |        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
frost-web-mqtt |        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:926)
frost-web-mqtt |        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1791)
frost-web-mqtt |        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
frost-web-mqtt |        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
frost-web-mqtt |        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
frost-web-mqtt |        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
frost-web-mqtt |        at java.base/java.lang.Thread.run(Thread.java:829)

Have there been any changes between v1.x and v2.0 in regards to this?

hylkevds commented 1 year ago

When posting DataArrays any errors do not result in a HTTP error, but are reflected in the returned JSON. For each Observation this contains either the selfLink of the created Observation, or the error message.

Can you give an example of what you post to the server?

mikedolx commented 1 year ago

I found the problem.

the PHP-Script was creating the phenomenonTime like this:

date("Y-m-d", strtotime($value['timestamp'])).'T'.date("H:i:s", strtotime($value['timestamp']))
# example 2023-03-08T13:58:06

I added the zulu time zone designator, and afterwards it was working fine.

date("Y-m-d", strtotime($value['timestamp'])).'T'.date("H:i:s\Z", strtotime($value['timestamp']))
# example 2023-03-08T13:58:06Z <- this guy was missing

Not only i had my MQTT-Messages back, the Observations were also imported to the FROST-Server. Therefore i'm marking this bug as resolved.

Still, it seems that the FROST-Server v1.x does handle the parsing of the phenomenonTime differently. Could this be made configurable, or more tolerant?

I'm renaming the bug to better match the topic

hylkevds commented 1 year ago

I'm quite surprised that it worked in 1.14.x in the first place. Without a timezone the date should have been rejected...

mikedolx commented 1 year ago

It works now. Important for us was to set the correct timezone for the docker container with the environment variable TZ=Europe/Berlin. This might be something to be added to the docs, allthough it's probably a setting inherited by the parent image.

If you like, i can add this small documentation update via PR.