PHPFina error in logs: get_meta start_time already defined but npoints is 0

icenov · 5 May 2020 08:56

Noticed these error messages in the log file a few days ago, and been meaning to follow up… But system is now almost broken - lost inputs, mqtt broker erratic etc.
System is an emonBase with a few emonTxs, emonThs and some bespoke RFM sensors.

I thought it might be due to lack of disk space on /dev/root as it was 95% full, so removed node-red and npm which freed up about 150 MB. Rebooted etc but still missing plenty of inputs. The SD card is a 3 month old quality card, so should be OK. I suspect the lack of disk space triggered a problem, which has now cascaded. I think it will need a fresh install, but interested in what caused this error message.

2020-05-04 22:27:30.289|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0
2020-05-04 22:27:30.291|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0
2020-05-04 22:27:30.292|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0
2020-05-04 22:27:30.297|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0
2020-05-04 22:27:30.298|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0
2020-05-04 22:27:30.305|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0
2020-05-04 22:27:30.306|WARN|PHPFina.php|PHPFina:get_meta start_time already defined but npoints is 0

repeated every few seconds, so thousands during a day.

Server Information

Services

emonhub :- Active Running
emoncms_mqtt :- Active Running
feedwriter :- Active Running - sleep 300s 143 feed points pending write
service-runner :- Active Running
emonPiLCD :- Inactive Dead
redis-server :- Active Running
mosquitto :- Active Running
demandshaper :- Active Running

Emoncms

Version :- low-write 10.2.2
Modules :- Administration | App v2.1.1 | Backup v2.2.3 | EmonHub Config v2.0.5 | Dashboard v2.0.7 | DemandShaper v1.2.5 | Device v2.0.5 | EventProcesses | Feed | Graph v2.0.9 | Input | Postprocess v2.1.2 | CoreProcess | Schedule | Network Setup v1.0.0 | sync | Time | User | Visualisation | WiFi v2.0.2
Git :-
- URL :- GitHub - emoncms/emoncms: Web-app for processing, logging and visualising energy, temperature and other environmental data
- Branch :- * stable
- Describe :- 10.2.2

Server

OS :- Linux 4.19.97-v7+
Host :- emonpi2 | emonpi2 | (192.168.20.126)
Date :- 2020-05-05 18:38:36 AEST
Uptime :- 18:38:36 up 7:10, 2 users, load average: 0.50, 0.35, 0.19

Memory

RAM :- Used: 22.77%
- Total :- 975.62 MB
- Used :- 222.15 MB
- Free :- 753.47 MB
Swap :- Used: 0.00%
- Total :- 100 MB
- Used :- 0 B
- Free :- 100 MB
  Write Load Period

Disk

/ :- Used: 91.30%
- Total :- 3.92 GB
- Used :- 3.58 GB
- Free :- 151.74 MB
- Write Load :- 565.4 B/s (6 hours 53 mins)
/var/opt/emoncms :- Used: 7.59%
- Total :- 10 GB
- Used :- 777.54 MB
- Free :- 8.74 GB
- Write Load :- 78.15 B/s (6 hours 53 mins)
/boot :- Used: 20.71%
- Total :- 252.05 MB
- Used :- 52.21 MB
- Free :- 199.84 MB
- Write Load :- 0 B/s (6 hours 53 mins)
/var/log :- Used: 59.70%
- Total :- 50 MB
- Used :- 29.85 MB
- Free :- 20.15 MB
- Write Load :- n/a

HTTP

Server :- Apache/2.4.38 (Raspbian) HTTP/1.1 CGI/1.1 80

MySQL

Version :- 5.5.5-10.3.17-MariaDB-0+deb10u1
Host :- localhost:6379 (127.0.0.1)
Date :- 2020-05-05 18:38:36 (UTC 10:00‌)
Stats :- Uptime: 26029 Threads: 15 Questions: 123814 Slow queries: 0 Opens: 49 Flush tables: 1 Open tables: 43 Queries per second avg: 4.756

Redis

Version :-
- Redis Server :- 5.0.3
- PHP Redis :- 5.1.1
Host :- localhost:6379
Size :- 233 keys (819.25K)
Uptime :- 0 days

MQTT Server

Version :- Mosquitto 1.5.7
Host :- localhost:1883 (127.0.0.1)

PHP

Version :- 7.3.11-1~deb10u1 (Zend Version 3.3.11)
Modules :- apache2handlercalendar Core ctype curl date dom v20031129exif fileinfo filter ftp gd gettext hash iconv json v1.7.0libxml mbstring mosquitto v0.4.0mysqli mysqlnd vmysqlnd 5.0.12-dev - 20150407 - $Id: 7cc7cc96e675f6d72e5cf0f267f48e167c2abb23 $openssl pcre PDO pdo_mysql Phar posix readline redis v5.1.1Reflection session shmop SimpleXML sockets sodium SPL standard sysvmsg sysvsem sysvshm tokenizer wddx xml xmlreader xmlwriter xsl Zend OPcache zlib

Pi

Model :- Raspberry Pi 3 Model B Rev 1.2 - 1GB (Sony UK)
Serial num. :- 5F51CEB5
Temperature :- 47.24°C - 47.2°C
emonpiRelease :- emonSD-02Oct19
File-system :- read-write

Client Information

HTTP

Browser :- Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/81.0.4044.129 Safari/537.36
Language :- en-US,en;q=0.9,nb;q=0.8,zu;q=0.7

Window

Size :- 1347 x 743

Screen

Resolution :- 1280 x 800

TrystanLea · 5 May 2020 17:08

Hello @icenov, could you check the contents and file permissions of your PHPFina data files, could you try the following and paste the result here?

ls -lh /var/opt/emoncms/phpfina

or if an older SD card

ls -lh /home/pi/data/phpfina

icenov · 5 May 2020 22:36

Hi @TrystanLea, here is the output of ls:

total 639M
-rw-r--r-- 1 www-data root     1.3M May  4 20:40 111.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:14 111.meta
-rw-r--r-- 1 www-data root     827K Apr 10 12:14 116.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:14 116.meta
-rw-r--r-- 1 www-data root        8 Apr 10 12:14 117.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 117.meta
-rw-r--r-- 1 www-data root      41M May  5 08:44 11.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:11 11.meta
-rw-r--r-- 1 www-data root      41M May  5 08:44 12.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 12.meta
-rw-r--r-- 1 www-data root     994K May  4 20:40 131.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 131.meta
-rw-r--r-- 1 www-data root     993K May  4 20:40 133.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:14 133.meta
-rw-r--r-- 1 www-data www-data 606K May  6 08:25 134.dat
-rw-r--r-- 1 www-data www-data   16 Apr 18 10:02 134.meta
-rw-r--r-- 1 www-data root      41M May  5 08:44 13.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:10 13.meta
-rw-r--r-- 1 www-data root      41M May  5 08:44 14.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 14.meta
-rw-r--r-- 1 www-data root      41M May  5 08:44 15.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:10 15.meta
-rw-r--r-- 1 www-data root      40M May  5 19:09 23.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:11 23.meta
-rw-r--r-- 1 www-data root     6.6M May  5 17:59 28.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 28.meta
-rw-r--r-- 1 www-data root     6.6M May  5 17:59 29.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 29.meta
-rw-r--r-- 1 www-data root     6.6M May  6 08:25 30.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 30.meta
-rw-r--r-- 1 www-data root     6.6M May  6 08:25 31.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 31.meta
-rw-r--r-- 1 www-data root      39M May  5 08:44 33.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 33.meta
-rw-r--r-- 1 www-data root      39M May  5 08:44 34.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:10 34.meta
-rw-r--r-- 1 www-data root      38M May  6 08:25 35.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:10 35.meta
-rw-r--r-- 1 www-data root      38M May  5 17:59 36.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:10 36.meta
-rw-r--r-- 1 www-data root      33M May  5 19:09 38.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 38.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:11 39.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 40.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 41.meta
-rw-r--r-- 1 www-data root      22M May  5 19:09 43.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 43.meta
-rw-r--r-- 1 www-data root     4.5M Apr 10 12:08 45.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 45.meta
-rw-r--r-- 1 www-data root      22M May  5 19:09 46.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 46.meta
-rw-r--r-- 1 www-data root      372 Apr 10 12:06 47.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:09 47.meta
-rw-r--r-- 1 www-data root      364 Apr 10 12:10 48.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 48.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:08 50.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:06 51.meta
-rw-r--r-- 1 www-data root     2.1M Apr 10 12:06 52.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:09 52.meta
-rw-r--r-- 1 www-data root        0 Apr 10 12:11 59.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:06 59.meta
-rw-r--r-- 1 www-data root      18M May  4 20:40 60.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:11 60.meta
-rw-r--r-- 1 www-data root      18M May  4 20:40 61.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:11 61.meta
-rw-r--r-- 1 www-data root      18M May  4 20:40 62.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:12 62.meta
-rw-r--r-- 1 www-data root      18M May  4 20:40 63.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:12 63.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:12 64.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:12 65.meta
-rw-r--r-- 1 www-data root       16 Apr 10 12:12 66.meta
-rw-r--r-- 1 www-data root      13M Apr 10 12:13 67.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:12 67.meta
-rw-r--r-- 1 www-data root      11M Apr 10 12:13 76.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 76.meta
-rw-r--r-- 1 www-data root      11M Apr 10 12:13 77.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 77.meta
-rw-r--r-- 1 www-data root     9.3M Apr 10 12:13 80.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 80.meta
-rw-r--r-- 1 www-data root     9.4M May  4 20:40 86.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 86.meta
-rw-r--r-- 1 www-data root     9.4M May  4 20:40 87.dat
-rw-r--r-- 1 www-data root       16 Apr 10 12:13 87.meta

TrystanLea · 6 May 2020 13:18

My guess is that the errors are resulting from this feed.
Can you find feedid 59 in your emoncms interface? (hover over the feed name to see the feed id and other details). You could try and delete it from the feed list interface if not needed.

icenov · 7 May 2020 00:00

OK - it was an old feed (one of 3) which are now deleted. But strangely, the error messages stopped last night (according to log) before I saw your reply and deleted the feed. There’s been no new log entries since then (I’m using “warn” level - so maybe all good), but I might change that to info and recheck.