Automatic refreshObject task is never removed from task queue

Grímur Daníelsson grimurd at snerpa.is
Tue Jul 26 11:24:44 EDT 2016


I tried fiddling around with the timeout in apache and the timeout in genieacs but nothing changed, a new refreshObject task is started every ~20-30 seconds.

>From what I can gather the default timeout in apache is 60 seconds so the default there is higher than the default in genieacs so I would think it would have worked when I was using the defaults if that was the problem.

Here's my current genieacs config (in case i'm doing something wrong there)
{
  "MONGODB_CONNECTION_URL" : "mongodb://127.0.0.1/genieacs",
  "REDIS_PORT" : "6379",
  "REDIS_HOST" : "127.0.0.1",
  "CWMP_INTERFACE" : "0.0.0.0",
  "CWMP_PORT" : 7547,
  "CWMP_SSL" : false,
  "NBI_INTERFACE" : "0.0.0.0",
  "NBI_PORT" : 7557,
  "FS_INTERFACE" : "0.0.0.0",
  "FS_PORT" : 7567,
  "FS_IP" : "127.0.0.1",
  "LOG_INFORMS" : false,
  "DEBUG" : false,
  "SESSION_TIMEOUT": 120,
  "GET_PARAMETER_NAMES_DEPTH_THRESHOLD":3
}

Apache 2 virtual hosts:
<VirtualHost 19X.XXX.XXX.163:80>
    ServerName tr069.domain.com
    LogLevel debug
    TransferLog /var/log/apache2/tr069.domain.com.access.log
    ErrorLog /var/log/apache2/tr069.domain.com.err.log

    ProxyPreserveHost On
    ProxyPass / http://127.0.0.1:7547/
    ProxyPassReverse / http://127.0.0.1:7547/
    ProxyTimeout 125
</VirtualHost>

<VirtualHost 19X.XXX.XXX.163:443>
    ServerName tr069.domain.com
    LogLevel debug
    TransferLog /var/log/apache2/tr069.domain.com -https.access.log
    ErrorLog /var/log/apache2/tr069.domain.com -https.err.log

    ProxyPreserveHost On
    ProxyPass / http://127.0.0.1:7547/
    ProxyPassReverse / http://127.0.0.1:7547/
    ProxyTimeout 125

    SSLEngine on
    SSLProxyEngine on
    SSLProtocol all -SSLv2 -SSLv3
    SSLCompression off
    SSLHonorCipherOrder on
    SSLCipherSuite ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:DES-CBC3-SHA:HIGH:!aNULL:!eNULL:!EXPORT:!DES:!MD5:!PSK:!RC4

    SSLCertificateFile /path/to/file
    SSLCertificateKeyFile /path/to/file
</VirtualHost>


Here's what 2 minutes of the CWMP log look like:

26 Jul 15:07:27 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:07:30 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:07:30 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:07:35 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:07:47 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:07:47 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:07:50 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:07:54 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:08:01 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:08:07 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:08:10 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:08:13 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:08:18 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:08:26 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:08:28 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:08:31 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:08:34 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:08:45 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:08:47 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:08:51 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:08:53 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:09:03 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:09:06 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:09:11 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:09:11 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:09:23 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:09:26 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)
26 Jul 15:09:26 - XXXXXXX -VMG1312%2DB10A-S140YXXXXX543: Started task refreshObject(57977ca307dd24b4396584d9)
26 Jul 15:09:32 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX742: Started task refreshObject(57977cb7f657a9b139838f1e)
26 Jul 15:09:40 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX759: Started task refreshObject(57977ca207dd24b4396584d8)
26 Jul 15:09:43 - XXXXXXX -VMG1312%2DB10A-S130YXXXXX774: Started task refreshObject(57977caf07dd24b4396584da)



<redir.aspx?C=b907d32f5c804528a8dbaad5e0461db6&URL=http%3a%2f%2fsnerpa.is%2fdisclaimer%2f>
On 07/26/2016 11:20 AM, Steve Hawkes wrote:
The HTTP timeout in Genie is the SESSION_TIMEOUT setting in the config file. The observation that devices talking direct to Genie work fine suggests that the HTTP timeout in Apache is much less.
I think Genie defaults to 30 seconds. When I started working with our copy of Genie I think it was set to 300 seconds which is probably a bit excessive.
I did go through the debug dump file to see how long each section of the tree took to transfer but I cannot remember what the longest one was now! :o

Thanks
Yak

From: Users [mailto:users-bounces at lists.genieacs.com] On Behalf Of Grímur Daníelsson
Sent: 26 July 2016 11:36
To: Community support for GenieACS users <users at lists.genieacs.com><mailto:users at lists.genieacs.com>
Subject: Re: Automatic refreshObject task is never removed from task queue

Do you know the default HTTP timeout in GenieACS? Or if I can configure the HTTP timeout somewhere? Changing the timeout in apache is no problem if I know what to change it to.

Regards, Grímur

On 07/26/2016 09:12 AM, Steve Hawkes wrote:

Hi Grimur,
The behaviour you are describing is what seems to happen when the HTTP connection has timed out. My guess would be config change in Genie is holding the HTTP connection open for longer to Apache but Apache has its own time out setting so it is dropping the connection before the ZyXEL has replied.
Unfortunately my knowledge of Apache is close to zero so I do not know how to configure it.

Thanks
Yak

From: Users [mailto:users-bounces at lists.genieacs.com] On Behalf Of Grímur Daníelsson
Sent: 22 July 2016 11:43
To: Community support for GenieACS users <mailto:users at lists.genieacs.com> <users at lists.genieacs.com><mailto:users at lists.genieacs.com>
Subject: Re: Automatic refreshObject task is never removed from task queue

This seems to somehow be related to apache which I'm using as a reverse proxy in front of genieacs.

If I configure my devices to talk to genieacs directly the tasks are finished properly.

Does anyone have an example config for apache that works with genieacs? Or is apache not suitable for this purpose?

Regards, Grímur
On 07/22/2016 09:03 AM, Grímur Daníelsson wrote:
Unfortunately this made no difference. The refreshObject tasks still aren't showing up as completed and CPEs are still informing every 20-30 seconds.

The odd thing is that I'm getting "Started task" in the log for the same devices every ~15 seconds. So it's as if the refreshObject task is failing and restarting but I get no faulty tasks.

I also occasionally get these errors in the error log "xmlMallocBreakpoint reached on block 0" but it does not happen that regularly. Only every couple of hours.

Regards, Grímur


On 07/21/2016 05:03 PM, Dan Morphis wrote:
I had to set GET_PARAMETER_NAMES_DEPTH_THRESHOLD to 3, and SESSION_TIMEOUT to 120 for the ZyXel stuff to work. Try that.

On Thu, Jul 21, 2016 at 7:20 AM, Grímur Daníelsson <grimurd at snerpa.is<mailto:grimurd at snerpa.is>> wrote:
Hi Yak

I had tried setting GET_PARAMETER_NAMES_DEPTH_THRESHOLD set to 3 without success.

As per your suggestion i tried setting the session timeout first to 60 seconds, then to 120 seconds and reducing the depth threshold to 2. But that didn't make any difference. Some routers seemed to take
longer between informs but others still seems to contact the ACS every 30 seconds.

How much did you raise the session timeout to?

Regards, Grimur


On 07/21/2016 02:16 PM, Steve Hawkes wrote:
Hi Grimur,
We have had a similar issue with VMG1312s. We increased the SESSION_TIMEOUT and changed the  GET_PARAMETER_NAMES_DEPTH_THRESHOLD to 2 so it does the tree in sections. Trying to get the whole tree on 1312s seems to take for ever and Genie give up waiting.
I did try setting the GET_PARAMETER_NAMES_DEPTH_THRESHOLD to 3 but though it worked it was marginally slower to get through the whole tree.

Thanks
Yak

From: Users [<mailto:users-bounces at lists.genieacs.com>mailto:users-bounces at lists.genieacs.com] On Behalf Of Grímur Daníelsson
Sent: 21 July 2016 10:11
To: Community support for GenieACS users <mailto:users at lists.genieacs.com> <users at lists.genieacs.com><mailto:users at lists.genieacs.com>
Subject: Automatic refreshObject task is never removed from task queue

Hello everyone

I'm having problems with the refreshObject tasks on our CPEs.

The tasks never seem to be completed and because of that it looks to me like the CPEs are being hammered by refresh requests from genieacs.
I have set the inform interval to 900 seconds but in spite of that they seem to be informing every 15-30 seconds at least. This stops when I
remove the refreshObject task from the queue manually and they go back to informing at regular intervals. If I refresh the CPE manually
through the GUI it refreshes sucessfully and the task is removed without problems.
There are no faults in the faults tab in the GUI.
This seems to happen on all types of CPEs. We got a few Zyxel CPEs and this happens to all of them. VMG1312-B10A, VMG8924-B10A and P-870HN-51b.

There are no errors to speak of in the genieacs error log. Tailing the console log shows a non-stop stream of "Started task refreshObject()" but nothing else out of the ordinary.

I'm completely stuck, anyone know what the problem could be?
--
Best regards,
Grímur Daníelsson
Software Developer
Sales & Services
Sími: +354 520-4000<tel:%2B354%20520-4000> - <mailto:grimurd at snerpa.is> grimurd at snerpa.is<mailto:grimurd at snerpa.is>
Snerpa ehf - Mánagata 6 - 400 Ísafjörður
<http://www.snerpa.is>http://www.snerpa.is - Lagalegur fyrirvari<http://snerpa.is/disclaimer/>
--
Steve Hawkes
Systems Developer
Zen Internet
Main Switchboard: 01706 902000
Web: zen.co.uk<http://zen.co.uk>

Winner of 'Services Company of the Year' at the UK IT Industry Awards

This message is private and confidential. If you have received this message in error, please notify us and remove it from your system.


Zen Internet Limited may monitor email traffic data to manage billing, to handle customer enquiries and for the prevention and detection of fraud. We may also monitor the content of emails sent to and/or from Zen Internet Limited for the purposes of security, staff training and to monitor quality of service.

Zen Internet Limited is registered in England and Wales, Sandbrook Park, Sandbrook Way, Rochdale, OL11 1RY Company No. 03101568 VAT Reg No. 686 0495 01


_______________________________________________
Users mailing list
Users at lists.genieacs.com<mailto:Users at lists.genieacs.com>
http://lists.genieacs.com/mailman/listinfo/users





-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.genieacs.com/pipermail/users/attachments/20160726/2ee2d3ec/attachment-0001.html>


More information about the Users mailing list