OH 3.2.0 M1 + Influx 1.8.7 not storing data

czupyt · August 5, 2021, 1:05pm

This week I updated influxdb to 1.8.7 and OpenHAB from 3.1.0 to 3.2.0 M1. The problem with version 1.8.7 is solved by me and now influx is running itself, but I see that now OpenHAB does not store data in database. Firstly I had following error in log

2021-08-05 13:26:39.471 [ERROR] [org.influxdb.impl.BatchProcessor    ] - Batch could not be sent. Data will be lost
org.influxdb.InfluxDBException: [shard 189] open /var/lib/influxdb/data/openhab_db/autogen/189/fields.idx.1.tmp: permission denied
	at org.influxdb.InfluxDBException.buildExceptionFromErrorMessage(InfluxDBException.java:161) ~[bundleFile:?]
	at org.influxdb.InfluxDBException.buildExceptionForErrorState(InfluxDBException.java:173) ~[bundleFile:?]
	at org.influxdb.impl.InfluxDBImpl.execute(InfluxDBImpl.java:827) ~[bundleFile:?]
	at org.influxdb.impl.InfluxDBImpl.write(InfluxDBImpl.java:460) ~[bundleFile:?]
	at org.influxdb.impl.OneShotBatchWriter.write(OneShotBatchWriter.java:22) ~[bundleFile:?]
	at org.influxdb.impl.BatchProcessor.write(BatchProcessor.java:340) [bundleFile:?]
	at org.influxdb.impl.BatchProcessor$1.run(BatchProcessor.java:287) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [?:?]
	at java.util.concurrent.FutureTask.run(Unknown Source) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]
	at java.lang.Thread.run(Unknown Source) [?:?]

But now I see following entries:

2021-08-05 15:02:58.216 [ERROR] [org.influxdb.impl.BatchProcessor    ] - Batch could not be sent. Data will be lost
org.influxdb.InfluxDBException: engine: error rolling WAL segment: error opening new segment file for wal (2): open /var/lib/influxdb/wal/openhab_db/autogen/189/_06264.wal: permission denied
	at org.influxdb.InfluxDBException.buildExceptionFromErrorMessage(InfluxDBException.java:161) ~[bundleFile:?]
	at org.influxdb.InfluxDBException.buildExceptionForErrorState(InfluxDBException.java:173) ~[bundleFile:?]
	at org.influxdb.impl.InfluxDBImpl.execute(InfluxDBImpl.java:827) ~[bundleFile:?]
	at org.influxdb.impl.InfluxDBImpl.write(InfluxDBImpl.java:460) ~[bundleFile:?]
	at org.influxdb.impl.OneShotBatchWriter.write(OneShotBatchWriter.java:22) ~[bundleFile:?]
	at org.influxdb.impl.BatchProcessor.write(BatchProcessor.java:340) [bundleFile:?]
	at org.influxdb.impl.BatchProcessor$1.run(BatchProcessor.java:287) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) [?:?]
	at java.util.concurrent.FutureTask.run(Unknown Source) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]
	at java.lang.Thread.run(Unknown Source) [?:?]

I see there is a difference in first line and accessing fields.idx.1.tmp previously and now _06264.wal.

Status of influxdb shows following output, also something with this wal file.


● influxdb.service - InfluxDB is an open-source, distributed, time series database
   Loaded: loaded (/lib/systemd/system/influxdb.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2021-08-05 14:33:28 CEST; 31min ago
     Docs: https://docs.influxdata.com/influxdb/
  Process: 20426 ExecStart=/usr/lib/influxdb/scripts/influxd-systemd-start.sh (code=exited, status=0/SUCCESS)
 Main PID: 20427 (influxd)
    Tasks: 14 (limit: 4411)
   CGroup: /system.slice/influxdb.service
           └─20427 /usr/bin/influxd -config /etc/influxdb/influxdb.conf

Aug 05 15:04:45 openhab influxd-systemd-start.sh[20426]: [httpd] 127.0.0.1 - openhab [05/Aug/2021:15:04:45 +0200] "POST /write?db=openhab_db&rp=autogen&precision=n&consistency=one HTTP/1.1 " 500 171 "-" "okhttp/3.14.4" b4c3b323-f5ed-11eb
Aug 05 15:04:45 openhab influxd-systemd-start.sh[20426]: ts=2021-08-05T13:04:45.371486Z lvl=error msg="[500] - \"engine: error rolling WAL segment: error opening new segment file for wal (2): open /var/lib/influxdb/wal/openhab_db/autogen
Aug 05 15:04:45 openhab influxd-systemd-start.sh[20426]: ts=2021-08-05T13:04:45.835128Z lvl=info msg="Executing query" log_id=0Vm_h~q0000 service=query query="SELECT value::field, item::tag FROM openhab_db.autogen.FF_Corridor_Temperature
Aug 05 15:04:45 openhab influxd-systemd-start.sh[20426]: [httpd] 127.0.0.1 - openhab [05/Aug/2021:15:04:45 +0200] "GET /query?db=openhab_db&epoch=ms&q=SELECT+%22value%22%3A%3Afield%2C%22item%22%3A%3Atag+FROM+autogen.FF_Corridor_Temperatu
Aug 05 15:04:45 openhab influxd-systemd-start.sh[20426]: [httpd] 127.0.0.1 - openhab [05/Aug/2021:15:04:45 +0200] "POST /write?db=openhab_db&rp=autogen&precision=n&consistency=one HTTP/1.1 " 500 171 "-" "okhttp/3.14.4" b510929a-f5ed-11eb
Aug 05 15:04:45 openhab influxd-systemd-start.sh[20426]: ts=2021-08-05T13:04:45.875417Z lvl=error msg="[500] - \"engine: error rolling WAL segment: error opening new segment file for wal (2): open /var/lib/influxdb/wal/openhab_db/autogen
Aug 05 15:04:46 openhab influxd-systemd-start.sh[20426]: [httpd] 127.0.0.1 - openhab [05/Aug/2021:15:04:46 +0200] "POST /write?db=openhab_db&rp=autogen&precision=n&consistency=one HTTP/1.1 " 500 171 "-" "okhttp/3.14.4" b52f9c8d-f5ed-11eb
Aug 05 15:04:46 openhab influxd-systemd-start.sh[20426]: ts=2021-08-05T13:04:46.078737Z lvl=error msg="[500] - \"engine: error rolling WAL segment: error opening new segment file for wal (2): open /var/lib/influxdb/wal/openhab_db/autogen
Aug 05 15:04:46 openhab influxd-systemd-start.sh[20426]: [httpd] 127.0.0.1 - openhab [05/Aug/2021:15:04:46 +0200] "POST /write?db=openhab_db&rp=autogen&precision=n&consistency=one HTTP/1.1 " 500 171 "-" "okhttp/3.14.4" b59b08dd-f5ed-11eb
Aug 05 15:04:46 openhab influxd-systemd-start.sh[20426]: ts=2021-08-05T13:04:46.782916Z lvl=error msg="[500] - \"engine: error rolling WAL segment: error opening new segment file for wal (2): open /var/lib/influxdb/wal/openhab_db/autogen
l

Any idea what is happening? I was trying to search on google and openhab forum, but no luck so far.

rlkoshak · August 5, 2021, 2:16pm

The errors point to file permission problems. Does what ever user InfluxDB is running under have permission to write to /var/lib/influxdb/data/openhab_db/autogen/189/fields.idx.1.tmp and /var/lib/influxdb/wal/openhab_db/autogen/189/_06264.wal? In particular that user needs permission to read/write and for the directories execute all the files under /var/lib/influxdb. The execute permissions on a directory is what allows a user to cd to it.

Database servers tend to have very strict permissions on their folders and files and if that got messed up it breaks things.

Wolfgang_S · August 5, 2021, 8:19pm

This one ( Error writing snapshot ... Permission denied - InfluxData Community Forums ) shows up by googling and is about permissions like @rlkoshak already suggested.

czupyt · August 6, 2021, 5:18am

Thanks both @rlkoshak @Wolfgang_S for answers. Morning update of influx solved problems. Maybe I forgot to add the info, that yesterday dyrung day I checked permissions and ownership and all belonged to influxdb except /var/lib/influxdb/data/openhab_db/autogen/189, so I changed it to influxdb, therefore error was changed from

[shard 189] open /var/lib/influxdb/data/openhab_db/autogen/189/fields.idx.1.tmp: permission denied

to

org.influxdb.InfluxDBException: engine: error rolling WAL segment: error opening new segment file for wal (2): open /var/lib/influxdb/wal/openhab_db/autogen/189/_06264.wal: permission denied

I did not make to check the _06264.wal file itself (before morning update), but folder 189 belonged to influxdb after my change. Now, after update of influx, this file is gone in this folder. Anyway, updating helped.