emonhub warnings and exceptions

Hi,

I've been trying to get another system running in parallel with my current emonbase system and in checking the emonhub log file found some strange entries.

Firstly, I'm getting a lot of Warnings about connecting to emoncms as follows:

2015-12-19 01:03:49,086 WARNING emonCMS couldn't send to server, URLError: [Errno -2] Name or service not known
2015-12-19 01:03:49,088 WARNING emonCMS send failure: wanted 'ok' but got ''
2015-12-19 01:04:09,270 WARNING emonCMS couldn't send to server, URLError: [Errno -2] Name or service not known
2015-12-19 01:04:09,273 WARNING emonCMS send failure: wanted 'ok' but got ''
2015-12-19 01:05:19,490 WARNING emonCMS couldn't send to server, URLError: timed out
2015-12-19 01:05:19,493 WARNING emonCMS send failure: wanted 'ok' but got ''
2015-12-19 01:05:39,666 WARNING emonCMS couldn't send to server, URLError: [Errno -2] Name or service not known
2015-12-19 01:05:39,669 WARNING emonCMS send failure: wanted 'ok' but got ''

Also just after this I got:

2015-12-19 01:07:06,080 WARNING emonCMS couldn't send to server, Exception: Traceback (most recent call last):
  File "/home/pi/emonhub/src/emonhub_reporter.py", line 227, in _send_post
    response = urllib2.urlopen(request, timeout=60)
  File "/usr/lib/python2.7/urllib2.py", line 154, in urlopen
    return opener.open(url, data, timeout)
  File "/usr/lib/python2.7/urllib2.py", line 431, in open
    response = self._open(req, data)
  File "/usr/lib/python2.7/urllib2.py", line 449, in _open
    '_open', req)
  File "/usr/lib/python2.7/urllib2.py", line 409, in _call_chain
    result = func(*args)
  File "/usr/lib/python2.7/urllib2.py", line 1227, in http_open
    return self.do_open(httplib.HTTPConnection, req)
  File "/usr/lib/python2.7/urllib2.py", line 1200, in do_open
    r = h.getresponse(buffering=True)
  File "/usr/lib/python2.7/httplib.py", line 1073, in getresponse
    response.begin()
  File "/usr/lib/python2.7/httplib.py", line 415, in begin
    version, status, reason = self._read_status()
  File "/usr/lib/python2.7/httplib.py", line 371, in _read_status
    line = self.fp.readline(_MAXLINE + 1)
  File "/usr/lib/python2.7/socket.py", line 476, in readline
    data = self._sock.recv(self._rbufsize)
timeout: timed out

and some time later after I rebooted I got a lot of warnings about my local emoncms

2015-12-19 13:56:48,663 INFO EmonHub Pre-Release Development Version (rc1.2)
2015-12-19 13:56:48,705 INFO Opening hub...
2015-12-19 13:56:56,200 WARNING emonCMSlocal send failure: wanted 'ok' but got 'Can't connect to database, please verify credentials/configuration in settings.php<br />Error message: <b>Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)</b>'
2015-12-19 13:56:56,396 WARNING emonCMSlocal send failure: wanted 'ok' but got 'Can't connect to database, please verify credentials/configuration in settings.php<br />Error message: <b>Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)</b>'

which did clear after a second or two and then it started up with the intermittent errors about the connection to emoncms.org

Any ideas what the issue could be. I'm guessing the ones after reboot are due to the local system getting up and running?

Simon

pb66's picture

Re: emonhub warnings and exceptions

What image/software are you running? I see the log says emonhub v1.2 was this installed manually or included in an image? 

Is it a new install or just a new problem?

the initial fault reported by emonhub is that there is a DNS problem, either in the OS, router or ISP etc. the latter warning it relays the response from emoncms, so emoncms was having some connection issue of it's own with the local mySQL server.

Thr traceback in between those issues is also a network type issue although I am unsure what and emonhub should have handled it better, if we find out what was causing the network issues I may be able to improve the error handling.

Paul

Bramco's picture

Re: emonhub warnings and exceptions

Hi Paul, it's a brand new installation on a Pi 2 with the full Jessie image. All done according to your installation guide. No errors on the way, or finger trouble on my behalf. The rfm is a new rfm69. 

I'm struggling at the moment to get a stable system, the other one I'm working on is a PiB with rfm12 with Jessie which was my old system and worked forever without a hitch but is now not seeing the inputs. I'm getting the non numeric error - WARNING 19 Discarded RX frame 'non-numerical content'. Which I think is because the rfm doesn't get initialised properly. I get all the - WARNING 1 Discarded RX frame 'non-numerical content' : ['Available', 'commands:'] followed by all the commands the rfm understands. I'm a bit lothe to update the firmware on this one as it's run fine in the past.

Getting to the stage where it'll all be going out the window before long  :-)

Thanks in advance for any suggestions you might have.

Simon 

pb66's picture

Re: emonhub warnings and exceptions

Hi Simon. So the current system is a Pi 2 running "stock" ie not read-only, Raspbian Jessie, with emonhub v1.2 and emoncms, I'm assuming v9.2, is it "low-write", SD or HDD, stable or master, are there any emoncms modules installed? have you installed anything else or made any other changes? for example the wi-fi or are you using ethernet?

The install guides are by Paul Reed not myself so I am not overly familiar with them but it is a great help to know exactly what you have and linking or quoting the guides is a good start.

For the record I have had some stability issues with Jessie, I have not got to the bottom off it and I do not use Jessie for my own live system. On my dev Pi's it seems to be pot luck whether they even boot, sometimes I have to power cycle half a dozen times before a successful boot and that is just fresh Jessie, no changes, no software installed, so I'm aware it's not perfect. I know many users report no problems at all but I can only report what I see.  The latest revision of Jessie now includes a "wait for internet connection on boot" option, I'm unsure if it previously waited or not but now it's optional, this may be related to the boot issue I have if Jessie is "waiting" for an internet connection, but since I always boot with a known good wired internet connection, it would suggest Jessie cannot see the internet connection and therefore I wonder if there are "network" issues in Jessie, Again I can only call it as I see it, I'm sure there are many that will want to defend Jessie, but none are more eager than me to use Jessie.

Are you still getting the errors on the current system?

On your older system the non-numerical content response to the help text is expected from emonhub if the help text is triggered. The help text is only printed once at startup and following any unrecognised commands from the serial port. Assuming your rfm12 isn't resetting for some reason the likelyhood is something is being passed to the rfm2pi from the Pi, emonhub should have exclusive access to serial port and if that is the case the commands maybe coming from emonhub. is it v1.2 or the "emon-pi" variant, if the latter is the "usa" option removed from emonhub.conf? If the rogue command did come from emonhub it will be in the log just before the errors if you have "loglevel = DEBUG" set in the conf. 

Paul

Bramco's picture

Re: emonhub warnings and exceptions

Paul,

I've copied the Admin page below which gives all the various versions etc. After the Jessie install I used the Setup to extend the partition, change the host name and password and also checked the locale etc. I also configured wifi and then set it to boot to CLI.

After installing emoncms, emonhub and configuring things for my api keys etc. I also followed the HDD guide and loaded the apps. Can't remember if I did this before or after the HDD step but it doesn't matter too much as I'm running from the HDD anyway. I'm pretty sure I loaded MQTT on this one as well and enabled it. But I didn't set it to low write or disable the logs.

It's interesting that you have had issues with Jessie. I haven't had any problems with booting but I did notice a strange lack of response from the system when sshing in with MobaXterm. Sometimes takes an age for the Pi to respond when letters are typed. No idea what that is about.

On the old system it's the same build effectively although I haven't done the HDD step or installed the Apps. I was trying to get myself a clean Jessie based system on the old Pi.

Will check to se if I still have errors but emonhub seems to have stopped logging for some reason. I'll make sure debug is off and reboot. EDIT: Debug was off and it's still not logging after a reboot.....  Odd.

Emoncms Version 9.2 | 2015.11.27
Server OS Linux 4.1.13+
Host Homepi Homepi (127.0.1.1)
Date 2015-12-20 15:53:29 UTC
Uptime 15:53:29 up 2:13, 2 users, load average: 0.27, 0.15, 0.15
HTTP Server Apache/2.4.10 (Raspbian) HTTP/1.1 CGI/1.1 80
Database Version MySQL 5.5.44-0+deb8u1
Host localhost (127.0.0.1)
Date 2015-12-20 15:53:29 (UTC 00:00‌​)
Stats Uptime: 8036 Threads: 2 Questions: 71821 Slow queries: 0 Opens: 59 Flush tables: 1 Open tables: 52 Queries per second avg: 8.937
MQTT Version n/a
Host 192.168.0.11 (192.168.0.11)
PHP Version 5.6.14-0+deb8u1 (Zend Version 2.6.0)
Modules Core   date   ereg   libxml   openssl   pcre   zlib   bcmath   bz2   calendar   ctype   dba   dom   hash   fileinfo   filter   ftp   gettext   SPL   iconv   mbstring   session   posix   Reflection   standard   shmop   SimpleXML   soap   sockets   Phar   exif   sysvmsg   sysvsem   sysvshm   tokenizer   wddx   xml   xmlreader   xmlwriter   zip   apache2handler   PDO   curl   dio   json   mcrypt   mysql   mysqli   pdo_mysql   readline   redis   mhash   Zend OPcache  

pb66's picture

Re: emonhub warnings and exceptions

I have noticed the SSH latency as well, sometimes when typing the console just stops printing and I have found I can actually open another SSH window log in and fully type the "stuck" command or text before the first console eventually finishes displaying what I typed. 

I find that odd as the 2nd instance proves everything currently works and there was no apparent reason for it.

Anyway I haven't looked deeply into the info you've given yet but I did notice some anomalies in the print above. the hostname appears duplicated, then the IP address in brackets after it is 127.0.1.1 presumably "localhost" and yet further on "Host localhost is 127.0.0.1" (which I believe to be the more accurate) and then under MQTT there is a "assigned" IP intended for the MQTT broker I know but probally a fixed IP for the same machine so there are at least 5 ways of "addressing itself", not a problem if they all work all the time but since we have a possible DNS issue this may not help.

You say your old system worked "forever" so there is a strong possibility it's debian Jessie not Raspian Jessie as it took ages to  port to Raspbian so may have differences.

What did "configured wifi" consist of? just using the in-built gui to add ssid and password or did you edit things to try and keep wifi alive?

Paul

Bramco's picture

Re: emonhub warnings and exceptions

Configured wifi was just using the gui - top right.

The MQTT address is the dynamic address assigned by my router to the Pi. Everything works fine there and the 127.0.0.1 is something I've asked about before. Seems to be the local host address assigned during the installs.

Interesting you also see the stop/start on SSH windows - not sure I've seen anything about this elsewhere but then I've not been looking. Anyone else seen this?

Bramco's picture

Re: emonhub warnings and exceptions

Paul,

You didn't mention anything about the start up issue with the MySQL type errors as follows:

After reboot the log reads as follows...

2015-12-20 16:14:33,909 INFO EmonHub Pre-Release Development Version (rc1.2)
2015-12-20 16:14:33,969 INFO Opening hub...
2015-12-20 16:14:41,807 WARNING emonCMSlocal send failure: wanted 'ok' but got 'Can't connect to database, please verify credentials/configuration in settings.php<br />Error message: <b>Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)</b>'
.......
2015-12-20 16:14:46,399 WARNING emonCMSlocal send failure: wanted 'ok' but got 'Can't connect to database, please verify credentials/configuration in settings.php<br />Error message: <b>Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)</b>'

end of log and system functioning OK. This is on the Jessie system as above, so installed through the Raspi installation instructions.

It looks as though on startup emonhub can't get through to the database as it is taking time to start up. Should emonhub not wait for some time, say 10 seconds, before trying to connect to the database, or maybe after an initial send failure wait for 5 seconds and try again etc.

Also, why does it say EmonHun Pre-release Development Version (rc1.2) when this is the production version. Might be an idea to fix that.

Simon

pb66's picture

Re: emonhub warnings and exceptions

127.0.0.1 is a usual "localhost" reference, I was wondering where the 127.0.1.1 crept in.

setting the MQTT server to the DCHP assigned IP may cause trouble at some point, most routers do seem to be consistent with ip assignment but it's not guaranteed, if a new ip is assigned by your router the defined MQTT setting will not follow suit. The Pi's ip address should be fixed or preferably use a "localhost" address for MQTT eg try using 127.0.0.1.

I see where you are coming from with making emonhub wait at start up but the reality is that emoncms can spit out exceptions and warnings anytime so yes a delay may fix some of the problem some of the time but when ever emoncms restarts or just has an issue it outputs a message, in fact v9 encourages this behavior more than v8 and there is even a setting to increase the action in settings.php (this should be "false" to work better with emonhub, but even that doesn't totally prevent the error messages).

If you are running emonhub v1.2 it isn't so much of an issue as emonhub just logs the warnings and keeps retrying to post the data, the "emon-pi" variant doesn't react to the messages and just assumes the data was accepted, discards the data and moves on.

Emoncms should really use return codes to indicate a successful post or an error and I would be happy to collaborate with emoncms devs and make emonhub work with those codes if that approach was adopted.

I'm thinking it's probally better not to start changing the name now as that may suggest the code has changed and cause confusion with the "emon-pi" variant. There have been no real changes to that "release candidate" for over a year. It did not make "production status" despite it's prolonged and reliable stability as there were many feature changes proposed in the experimental branch for a second release candidate that required a significant change to the core of emonhub, due to lack of peer interest development stalled until the "emon-pi" variant was released based on that experimental proof of concept code. Hopefully in the new year I will be able to return to that code and we can work towards getting v2 out and subject to testing worthy of a proper "released" status.

Paul

Bramco's picture

Re: emonhub warnings and exceptions

Ah, I get it Paul, sorry hadn't really twigged to your point about the difference in the localhost addresses.

MySQL seems to have it right and I've noticed this in the past when installing the system. It would look like the 127.0.1.1 is from emoncms. I wonder if there isn't a typo in the code somewhere. I guess this could be searched for.    EDIT: A quick search on emoncms in github shows 127.0.1.1 isn't in the code, so no idea where it's coming from.

On the MQTT address, I think this is how you would want it, because to access the system from outside your router you have to reserve the ip address for the emoncms system, so this is a fixed address as such inside your firewall even though it is dynamically allocated. In fact it might be an idea to add a section to the installation guide on accessing systems externally and using DuckDNS for example.

And thanks for the background on emonhub, my thoughts were really about trying to make sure any warnings etc. were 'real' and not just due to normal startup, so that anyone looking at the logs would only see information in there which was relevant and not get sidetracked. Similarly for the name, if anyone starts delving they'll think that they haven't got the latest and greatest. But if you are going to start on V2 in the New Year then this I'm sure will get sorted then.

Simon

pb66's picture

Re: emonhub warnings and exceptions

Using DuckDNS and accessing from outside the LAN is a whole other thing and not really relevant to this. If you were accessing MQTT from outside the LAN then the router would port forward any traffic pointed at the nominated port of the external (router) ip to the IP of the machine hosting the MQTT broker, regardless of whether the IP was dynamically assigned or fixed.

I don't recall you saying the Pi has a fixed address so please forgive me if I've missed or forgotten something. Just for clarification the points I'm making are not for or against the use of fixed ip addresses, they are about whether you have or you haven't without taking a stance whether you should or you shouldn't.

Setting the MQTT's IP address in emoncms only tells emoncms where the broker is, In this instance it is on the same machine but you are effectively telling it "the fixed ip address that the mqtt broker is at currently and will always be located at is 192.168.0.11 because that is the dynamically assigned ip assigned by the router (and could be prone to change)" which is misleading. the using a localhost reference would tell emoncms "it's on the same machine no matter what the machines IP is".

Defining the "fixed" ip of the MQTT broker is fine IF it is actually a fixed IP, which unless you fix the machine's IP address it isn't.

Anyhow, the MQTT ip address is unlikely to be the cause of the issue you've had and it may never present a problem if the dynamically assigned ip never changes, but it could cause unnecessary confusion for absolutely no gain. I only mentioned it since there is possibly a DNS / DCHP issue at large.

Regards the warnings in emonhub, they are not standard start up messages, they are both valid and informative , you are right they shouldn't be there. but pointing the finger at emonhub is shooting the messenger, emonhub has brought you good info that you may not of found elsewhere, delaying emonhub starting is the coding equivalent of us sticking our heads in the sand and hoping the problem just goes away.

There was a problem that effected emoncms, emoncms broadcast that event and emonhub logged it. If we don't want emonhub to know, we should stop emoncms sharing the problem and if we don't want emoncms to have a problem we need to fix the issue. Delaying emonhub starting is a bit like not switching your phone on in the morning incase someone rings to warn you of a problem you really should know about.

Going back to the log in your original post "couldn't send to server, URLError: [Errno -2] Name or service not known" is a very specific warning pointing to a problem resolving a name or IP, this combined with a relayed warning from emoncms indicating a problem accessing mySQL strongly suggests a dns/dchp/routing issue was present at that time, I can't say why that occurred but papering over the cracks and hiding the issue so the logs "appear" to be correct is not a direction I want to take emonhub in.

Paul

Bramco's picture

Re: emonhub warnings and exceptions

but pointing the finger at emonhub is shooting the messenger   Paul, I had no intention of doing that and if it came across as that sincere apologies. Like many on the forum, I'm amazed at what has been achieved with the software and I couldn't be anywhere near having such a sophisticated system without the efforts of everyone involved.

My comments about waiting etc. was simply an observation that as with many systems, sometimes things take time to 'settle' down and various services to become ready. So I guess the proper question I should have asked is whether this is normal behavior at startup, in terms of emoncms not being able to access the mySQL server and there being a problem resolving a name or IP.

If that is the case then surely each of the parts should wait until the services they need are ready before going into normal mode. Obviously not a clue how one would go about this  but I'm sure folks like yourself who are au fait with Linux would know how to do this.

If it's not the case, then given I've followed the installation instructions to a T then has anyone any idea of what could be causing this. Do other users see this, do you see it in your logs after a complete refresh, Jessie + emoncms and emonhub?

pb66's picture

Re: emonhub warnings and exceptions

No need for any apologies at all, I see your prospective and didn't take any offense at all, I wasn't so much defending emonhub as making sure you were on the right path.

No that isn't "normal" start up and yes things should be fixed, done probably or catered for, As I previously said I don't know why it happened, therefore I don't know how to fix it. I was trying to point out some observations re the fixed/dynamic ip and the double host name in hope that might nudge someone or something but no, at the moment if forced to make a wild guess (which is always a bad idea) I would say something is not 100% in Jessie as we have both seen other issues, but I'm not in a position to make that call.

Paul

Bramco's picture

Re: emonhub warnings and exceptions

Paul,

Here's a link to some info on 127.0.1.1.   Seems it's all quite normal.....

 

http://serverfault.com/questions/363095/why-does-my-hostname-appear-with...

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.