MQTT Not Connected

Just connected my emonpi but I’m having two issues. The first issue is that the LCD is reporting that MQTT is not connected. But a tail of /var/log/mosquitto/mosquitto.log produces:

1492297665: Socket error on client paho/D93DD1CD3C5D68662C, disconnecting.
1492297733: New connection from 127.0.0.1 on port 1883.
1492297733: New client connected from 127.0.0.1 as paho/3F51D877D37D2C9D47 (c1, k60, u’emonpi’).
1492297739: Socket error on client openhab.1492297529360, disconnecting.
1492297739: Socket error on client mosq/olMP[OlHljx4;[email protected]@, disconnecting.
1492297740: New connection from ::1 on port 1883.
1492297740: New client connected from ::1 as mosq/eI;[email protected] (c1, k5, u’emonpi’).
1492297760: New connection from 127.0.0.1 on port 1883.
1492297760: New client connected from 127.0.0.1 as openhab.1492297760094 (c1, k60, u’emonpi’).
1492297762: New connection from 127.0.0.1 on port 1883.

The second problem, probably related, is that I’m not getting any data out on the feeds I created.

tail /var/log/emoncms.log produces:

2017-04-15 23:05:14.095|WARN|phpmqtt_input.php|Starting MQTT Input script
2017-04-15 23:05:15.225|WARN|phpmqtt_input.php|Subscribing to: emon/#
2017-04-15 23:05:15.226|WARN|phpmqtt_input.php|Not connected, retrying connection
2017-04-15 23:05:15.227|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2017-04-15 23:05:15.228|WARN|phpmqtt_input.php|Subscribed to topic: emon/#
2017-04-15 23:08:59.873|WARN|phpmqtt_input.php|Starting MQTT Input script
2017-04-15 23:09:00.998|WARN|phpmqtt_input.php|Subscribing to: emon/#
2017-04-15 23:09:00.998|WARN|phpmqtt_input.php|Not connected, retrying connection
2017-04-15 23:09:00.999|WARN|phpmqtt_input.php|Connecting to MQTT server: Connection Accepted.: code: 0
2017-04-15 23:09:00.999|WARN|phpmqtt_input.php|Subscribed to topic: emon/#

Version information:

Server Information
Emoncms Version low-write 9.8.0 | 2017.02.01
** Modules admin app backup config dashboard eventp feed graph input postprocess process schedule time user vis wifi**
** Buffer 0 feed points pending write**
** Writer Daemon is running with sleep 60s**
Server OS Linux 4.4.26-v7+
** Host emonpi emonpi (127.0.1.1)**
** Date 2017-04-15 23:20:13 UTC**
** Uptime 23:20:14 up 15 min, 1 user, load average: 0.15, 0.13, 0.14**
HTTP Server Apache/2.4.10 (Raspbian) HTTP/1.1 CGI/1.1 80
Database Version MySQL 5.5.52-0+deb8u1
** Host localhost (127.0.0.1)**
** Date 2017-04-15 23:20:13 (UTC 00:00‌​)**
** Stats Uptime: 921 Threads: 3 Questions: 2529 Slow queries: 0 Opens: 57 Flush tables: 1 Open tables: 50 Queries per second avg: 2.745**
Redis Version 2.8.17
** Host localhost:6379 (127.0.0.1)**
** Size 31 keys (496.39K)**
** Uptime 0 days**
MQTT Version 1.4.10
** Host localhost:1883 (127.0.0.1)**
Pi CPU Temp 46.16°C
** Release emonSD-07Nov16**

I ran emonpi update from the web interface and rebooted but that did not fix the issue. Not sure what to try next.

More information:

sudo apt-get update pauses at (had to change http to ---- because new users can only post two links):

Ign ----://dl.bintray.com stable InRelease
Ign ----://dl.bintray.com stable Release.gpg
Ign ----://dl.bintray.com stable Release
Hit ----://dl.bintray.com stable/main armhf Packages
Ign ----://dl.bintray.com stable/main Translation-en_GB
Hit ----://dl.bintray.com stable/main armhf Packages
Err ----://dl.bintray.com stable/main armhf Packages
** Failed to stat - stat (2: No such file or directory)**
Ign ----://dl.bintray.com stable/main Translation-en
45% [Working]

cat /var/log/emonpilcd/emonpilcd.log produces:

2017-04-15 23:51:13,592 INFO Starting emonPiLCD V2.1.0
2017-04-15 23:51:13,853 INFO I2C LCD DETECTED 0x3f
2017-04-15 23:51:14,299 INFO SD card image build version: emonSD-07Nov16
2017-04-15 23:51:14,302 INFO Connecting to redis server…
2017-04-15 23:51:14,313 ERROR waiting for redis-server to start…
2017-04-15 23:51:15,319 ERROR waiting for redis-server to start…
2017-04-15 23:51:16,325 ERROR waiting for redis-server to start…
2017-04-15 23:51:17,330 ERROR waiting for redis-server to start…
2017-04-15 23:51:18,336 ERROR waiting for redis-server to start…
2017-04-15 23:51:19,342 ERROR waiting for redis-server to start…
2017-04-15 23:51:20,348 ERROR waiting for redis-server to start…
2017-04-15 23:51:21,356 INFO Connected to redis
2017-04-15 23:51:21,357 INFO Connecting to MQTT Server: 127.0.0.1 on port: 1883 with user: emonpi
2017-04-15 23:51:21,361 ERROR Could not connect to MQTT
2017-04-15 23:51:38,058 INFO Starting emonPiLCD V2.1.0
2017-04-15 23:51:38,391 INFO I2C LCD DETECTED 0x3f
2017-04-15 23:51:38,877 INFO SD card image build version: emonSD-07Nov16
2017-04-15 23:51:38,879 INFO Connecting to redis server…
2017-04-15 23:51:38,887 INFO Connected to redis
2017-04-15 23:51:38,888 INFO Connecting to MQTT Server: 127.0.0.1 on port: 1883 with user: emonpi
2017-04-15 23:51:38,894 INFO Connected to MQTT
2017-04-15 23:58:11,811 INFO lcd button press 0
2017-04-15 23:58:11,813 INFO Mode button pressed
2017-04-15 23:58:11,814 INFO Page: 0
2017-04-15 23:58:13,169 INFO lcd button press 0
2017-04-15 23:58:13,170 INFO Mode button pressed
2017-04-15 23:58:13,170 INFO Page: 1
2017-04-15 23:58:14,794 INFO lcd button press 0
2017-04-15 23:58:14,795 INFO Mode button pressed
2017-04-15 23:58:14,796 INFO Page: 4
2017-04-15 23:58:16,048 INFO lcd button press 0
2017-04-15 23:58:16,049 INFO Mode button pressed
2017-04-15 23:58:16,050 INFO Page: 5

One more note. I issued the following:

sudo service mosquitto restart
sudo service emonPiLCD restart

A tail of the emonPiLCD log file shows:

2017-04-16 12:53:13,406 INFO Starting emonPiLCD V2.1.0
2017-04-16 12:53:13,643 INFO I2C LCD DETECTED 0x3f
2017-04-16 12:53:14,080 INFO SD card image build version: emonSD-07Nov16
2017-04-16 12:53:14,082 INFO Connecting to redis server…
2017-04-16 12:53:14,088 INFO Connected to redis
2017-04-16 12:53:14,089 INFO Connecting to MQTT Server: 127.0.0.1 on port: 1883 with user: emonpi
2017-04-16 12:53:14,094 INFO Connected to MQTT
2017-04-16 12:54:07,270 INFO lcd button press 0
2017-04-16 12:54:07,272 INFO Mode button pressed
2017-04-16 12:54:07,273 INFO Page: 1
2017-04-16 12:54:08,315 INFO lcd button press 0
2017-04-16 12:54:08,316 INFO Mode button pressed
2017-04-16 12:54:08,316 INFO Page: 4
2017-04-16 12:54:09,585 INFO lcd button press 0
2017-04-16 12:54:09,586 INFO Mode button pressed
2017-04-16 12:54:09,587 INFO Page: 5

But the LCD is still reporting MQTT not connected and all my inputs are still NaN.

File emonpiupdate.log listed below. I’ve also now performed a sudo apt-get update and sudo apt-get upgrade (which took quite awhile). Still no inputs listed however.

emonpiupdate.log:

I2C LCD DETECTED Ox3f
Starting emonPi Update >
via service-runner-update.sh
EUID: 1000
Argument: emonpi
Sun 16 Apr 20:49:18 EDT 2017
git pull /home/pi/emonpi
* master
  wifiap
On branch master
Your branch is up-to-date with 'origin/master'.
Untracked files:
        1
        hardware/emonpi/emonpi2c/
        lcd/gsmhuaweistatus.pyc
        lcd/i2c_lib.pyc
nothing added to commit but untracked files present (use "git add" to track)
Already up-to-date.
git pull /home/pi/RFM2Pi
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
Already up-to-date.
git pull /home/pi/emonhub
  K0den-wibeee_interface
* emon-pi
  hmm01i-syslogging
On branch emon-pi
Your branch is up-to-date with 'origin/emon-pi'.
nothing to commit, working directory clean
Already up-to-date.
git pull /home/pi/oem_openHab
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
Already up-to-date.
git pull /home/pi/usefulscripts
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
git pull /home/pi/huawei-hilink-status
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
Start emonPi Atmega328 firmware update:
=================================
EmonPi update started
=================================
EUID: 1000
Requirement already up-to-date: paho-mqtt in /usr/local/lib/python2.7/dist-packages
Stopping OpenEnergyMonitor emonHub: emonhub has been stopped ok.
Start ATmega328 serial upload using avrdude with latest.hex
Discrete Sampling
avrdude -c arduino -p ATMEGA328P -P /dev/ttyAMA0 -b 115200 -U flash:w:/home/pi/emonpi/firmware/compiled/latest.hex
avrdude-original: Using autoreset DTR on GPIO Pin 7
Starting OpenEnergyMonitor emonHub: emonhub has been started ok.
Start emonhub update script:
=================================
EmonPi update started
=================================
Running emonhub automatic node addition script
EUID: 1000
EUID: 1000
[[5]]
Node 5 already present
[[6]]
Node 6 already present
[[7]]
Node 7 already present
[[8]]
Node 8 already present
[[9]]
Node 9 already present
[[10]]
Node 10 already present
[[11]]
Node 11 already present
[[19]]
Node 19 already present
[[20]]
Node 20 already present
[[21]]
Node 21 already present
[[22]]
Node 22 already present
[[23]]
Node 23 already present
[[24]]
Node 24 already present
[[25]]
Node 25 already present
[[26]]
Node 26 already present
Start emoncms update:
=================================
Emoncms update started
Sun 16 Apr 20:50:22 EDT 2017
EUID: 1000
Checking cron tab for service runner entry...
service runner crontab entry already installed
git pull /var/www/emoncms
  dev-mosquitto-php
  master
* stable
  symlinked_modules
On branch stable
Your branch is up-to-date with 'origin/stable'.
nothing to commit, working directory clean
Already up-to-date.
git pull /var/www/emoncms/Modules/app
* 9.0
On branch 9.0
Your branch is up-to-date with 'origin/9.0'.
nothing to commit, working directory clean
Already up-to-date.
git pull /var/www/emoncms/Modules/config
* 9.0
On branch 9.0
Your branch is up-to-date with 'origin/9.0'.
nothing to commit, working directory clean
Already up-to-date.
git pull /var/www/emoncms/Modules/wifi
* 9.0
On branch 9.0
Your branch is up-to-date with 'origin/9.0'.
nothing to commit, working directory clean
Already up-to-date.
git pull /var/www/emoncms/Modules/dashboard
  environ-master
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
Already up-to-date.
git pull /var/www/emoncms/Modules/graph
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
Already up-to-date.
git pull /home/pi/postprocess
Your branch is up-to-date with 'remotes/origin/emonpi'.
Already up-to-date.
git pull /home/pi/backup
* master
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working directory clean
Already up-to-date.
update mqtt_input systemd unit file
Update Emoncms database
[]
Restarting Services...
Restarting OpenEnergyMonitor emonHub: emonhub has been restarted ok.
Log is turned off
Restarting feedwriter
Restarting openhab (via systemctl): openhab.service.
set log rotate config owner to root
Restarting Services...
Starting emonPi LCD service..
Filesystem is locked - Read Only access
type ' rpi-rw ' to unlock
Sun 16 Apr 20:51:04 EDT 2017
...................
emonPi update done

emonhub.log below:

2017-04-17 21:09:38,875 INFO     MainThread EmonHub emonHub 'emon-pi' variant v1.2
2017-04-17 21:09:38,876 INFO     MainThread Opening hub...
2017-04-17 21:09:38,877 INFO     MainThread Logging level set to DEBUG
2017-04-17 21:09:38,878 INFO     MainThread Creating EmonHubJeeInterfacer 'RFM2Pi'
2017-04-17 21:09:38,881 DEBUG    MainThread Opening serial port: /dev/ttyAMA0 @ 115200 bits/s
2017-04-17 21:09:40,883 WARNING  MainThread Device communication error - check settings
2017-04-17 21:09:40,884 INFO     MainThread Setting RFM2Pi frequency: 433 (4b)
2017-04-17 21:09:41,885 INFO     MainThread Setting RFM2Pi group: 210 (210g)
2017-04-17 21:09:42,887 INFO     MainThread Setting RFM2Pi quiet: 0 (0q)
2017-04-17 21:09:43,889 INFO     MainThread Setting RFM2Pi baseid: 5 (5i)
2017-04-17 21:09:44,891 INFO     MainThread Setting RFM2Pi calibration: 110V (2p)
2017-04-17 21:09:45,893 DEBUG    MainThread Setting RFM2Pi subchannels: ['ToRFM12']
2017-04-17 21:09:45,895 DEBUG    MainThread Interfacer: Subscribed to channel' : ToRFM12
2017-04-17 21:09:45,895 DEBUG    MainThread Setting RFM2Pi pubchannels: ['ToEmonCMS']
2017-04-17 21:09:45,896 DEBUG    MainThread Interfacer: Subscribed to channel' : ToRFM12
2017-04-17 21:09:45,897 INFO     MainThread Creating EmonHubMqttInterfacer 'MQTT'
2017-04-17 21:09:45,899 INFO     MainThread MQTT Init mqtt_host=127.0.0.1 mqtt_port=1883 mqtt_user=emonpi
2017-04-17 21:09:45,902 DEBUG    MainThread MQTT Subscribed to channel' : ToEmonCMS
2017-04-17 21:09:45,924 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2017-04-17 21:09:45,926 DEBUG    MainThread emoncmsorg Subscribed to channel' : ToEmonCMS
2017-04-17 21:09:46,022 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:46,024 INFO     MQTT       Could not connect...
2017-04-17 21:09:47,126 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:47,128 INFO     MQTT       Could not connect...
2017-04-17 21:09:48,231 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:48,233 INFO     MQTT       Could not connect...
2017-04-17 21:09:49,336 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:49,337 INFO     MQTT       Could not connect...
2017-04-17 21:09:50,440 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:50,443 INFO     MQTT       Could not connect...
2017-04-17 21:09:51,546 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:51,649 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:09:51,652 INFO     MQTT       connection status: Connection successful
2017-04-17 21:09:51,654 DEBUG    MQTT       CONACK => Return code: 0
2017-04-17 21:09:51,756 INFO     MQTT       on_subscribe
2017-04-17 21:11:28,014 DEBUG    MainThread SIGINT received.
2017-04-17 21:11:28,015 INFO     MainThread Exiting hub...
2017-04-17 21:11:28,205 INFO     MainThread Exit completed
2017-04-17 21:11:29,317 INFO     MainThread EmonHub emonHub 'emon-pi' variant v1.2
2017-04-17 21:11:29,318 INFO     MainThread Opening hub...
2017-04-17 21:11:29,318 INFO     MainThread Logging level set to DEBUG
2017-04-17 21:11:29,319 INFO     MainThread Creating EmonHubJeeInterfacer 'RFM2Pi'
2017-04-17 21:11:29,322 DEBUG    MainThread Opening serial port: /dev/ttyAMA0 @ 115200 bits/s
2017-04-17 21:11:31,325 WARNING  MainThread Device communication error - check settings
2017-04-17 21:11:31,326 INFO     MainThread Setting RFM2Pi frequency: 433 (4b)
2017-04-17 21:11:32,329 INFO     MainThread Setting RFM2Pi group: 210 (210g)
2017-04-17 21:11:33,331 INFO     MainThread Setting RFM2Pi quiet: 0 (0q)
2017-04-17 21:11:34,333 INFO     MainThread Setting RFM2Pi baseid: 5 (5i)
2017-04-17 21:11:35,335 INFO     MainThread Setting RFM2Pi calibration: 110V (2p)
2017-04-17 21:11:36,338 DEBUG    MainThread Setting RFM2Pi subchannels: ['ToRFM12']
2017-04-17 21:11:36,339 DEBUG    MainThread Interfacer: Subscribed to channel' : ToRFM12
2017-04-17 21:11:36,339 DEBUG    MainThread Setting RFM2Pi pubchannels: ['ToEmonCMS']
2017-04-17 21:11:36,340 DEBUG    MainThread Interfacer: Subscribed to channel' : ToRFM12
2017-04-17 21:11:36,342 INFO     MainThread Creating EmonHubMqttInterfacer 'MQTT'
2017-04-17 21:11:36,343 INFO     MainThread MQTT Init mqtt_host=127.0.0.1 mqtt_port=1883 mqtt_user=emonpi
2017-04-17 21:11:36,345 DEBUG    MainThread MQTT Subscribed to channel' : ToEmonCMS
2017-04-17 21:11:36,347 INFO     MainThread Creating EmonHubEmoncmsHTTPInterfacer 'emoncmsorg'
2017-04-17 21:11:36,349 DEBUG    MainThread emoncmsorg Subscribed to channel' : ToEmonCMS
2017-04-17 21:11:36,447 INFO     MQTT       Connecting to MQTT Server
2017-04-17 21:11:36,450 INFO     MQTT       connection status: Connection successful
2017-04-17 21:11:36,451 DEBUG    MQTT       CONACK => Return code: 0
2017-04-17 21:11:36,553 INFO     MQTT       on_subscribe

As for the last question, if I go to 192.168.1.254/emoncms/input/view there are no input’s listed. If there’s another place to look for them, I’m not aware of it. I should note that the 115200 baud rate is a change I’ve tried based on another poster’s suggestion. I can change it back to 38400 but it still fails.