Hello everyone,
For a very long time, I've had problems with slow loading ipdevinfo pages (typically when opening a switch listed in "Reports" -> All IP Devices) I first thought this was related with poor performance I/O on my VMWare instance the server was running on, but the problem persists on a physical server as well. Sometimes it never opens, it just "hangs" in a state of loading the page. I haven't tried to Wireshark the connection between my client and the NAV server itself, nor between the NAV server and the postgres server (which is hosted on another server on the same subnet) I don't have the same problem on all switches, and I've also thought I might have been unlucky catching my server in a heavy cricket/collection cycle (although its running on a 2 x QuadCore and 16GB memory system.....)
I've tried to look in the error- and access logs in /var/log/apache2 without seeing anything suspicious. The load of the server is also quite low when I have this problem, so I doubt it's a performance issue. Have anyone else had a similar problem, or knows how I can troubleshoot it?
Currently running NAV 3.5.6 on a Debian Lenny system with an external postgres database (running in RH EL5)
Many thanks for any help!
------------------------------------------------------ Vidar Stokkenes Konsulent Nettverk Seksjon for nettverk og telekom Helse Nord IKT - Tromsø
Tlf: 76 16 61 87 / 77 66 99 55 Mobil: 95 87 99 42 e-post: vidarst@hn-ikt.no
Actually, after a bit more of clicking - I managed to get this output in /var/log/apache2/nav.domain.com-error.log when I click the switch name in "Reports":
<snip>
[Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] mod_python (pid=29222, interpreter='navserver.domain.com', phase='PythonHandler', handler='django.core.handlers.modpython'): Application error, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] ServerName: 'navserver.domain.com', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] DocumentRoot: '/usr/share/nav/htdocs', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] URI: '/ipdevinfo/campus-problem-switch.domain.no/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Location: None, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Directory: '/usr/share/nav/htdocs/ipdevinfo/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Filename: '/usr/share/nav/htdocs/ipdevinfo/campus-problem-switch.domain.no', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] PathInfo: '/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Traceback (most recent call last):, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1537, in HandlerDispatch\n default=default_handler, arg=req, silent=hlist.silent), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1229, in _process_target\n result = _execute_target(config, req, object, arg), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1128, in _execute_target\n result = object(arg), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/var/lib/python-support/python2.5/django/core/handlers/modpython.py", line 228, in handler\n return ModPythonHandler()(req), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/var/lib/python-support/python2.5/django/core/handlers/modpython.py", line 220, in __call__\n req.write(chunk), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] IOError: Write failed, client closed connection., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] python_handler: Dispatch() returned non-integer., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] mod_python (pid=29223, interpreter='navserver.domain.com', phase='PythonHandler', handler='django.core.handlers.modpython'): Application error, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] ServerName: 'navserver.domain.com', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] DocumentRoot: '/usr/share/nav/htdocs', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] URI: '/ipdevinfo/campus-problem-switch.domain.no/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Location: None, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Directory: '/usr/share/nav/htdocs/ipdevinfo/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Filename: '/usr/share/nav/htdocs/ipdevinfo/campus-problem-switch.domain.no', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] PathInfo: '/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Traceback (most recent call last):, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1537, in HandlerDispatch\n default=default_handler, arg=req, silent=hlist.silent), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1229, in _process_target\n result = _execute_target(config, req, object, arg), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1128, in _execute_target\n result = object(arg), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/var/lib/python-support/python2.5/django/core/handlers/modpython.py", line 228, in handler\n return ModPythonHandler()(req), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/var/lib/python-support/python2.5/django/core/handlers/modpython.py", line 220, in __call__\n req.write(chunk), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] IOError: Write failed, client closed connection., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] python_handler: Dispatch() returned non-integer., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] mod_python (pid=16710, interpreter='navserver.domain.com', phase='PythonHandler', handler='django.core.handlers.modpython'): Application error, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] ServerName: 'navserver.domain.com', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] DocumentRoot: '/usr/share/nav/htdocs', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] URI: '/ipdevinfo/campus-problem-switch.domain.no/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Location: None, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Directory: '/usr/share/nav/htdocs/ipdevinfo/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Filename: '/usr/share/nav/htdocs/ipdevinfo/campus-problem-switch.domain.no', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] PathInfo: '/', referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] Traceback (most recent call last):, referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1537, in HandlerDispatch\n default=default_handler, arg=req, silent=hlist.silent), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1229, in _process_target\n result = _execute_target(config, req, object, arg), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/usr/lib/python2.5/site-packages/mod_python/importer.py", line 1128, in _execute_target\n result = object(arg), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/var/lib/python-support/python2.5/django/core/handlers/modpython.py", line 228, in handler\n return ModPythonHandler()(req), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] File "/var/lib/python-support/python2.5/django/core/handlers/modpython.py", line 220, in __call__\n req.write(chunk), referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] IOError: Write failed, client closed connection., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/ [Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] python_handler: Dispatch() returned non-integer., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/
</snip>
-----Original Message----- From: Stokkenes Vidar [mailto:Vidar.Stokkenes@hn-ikt.no] Sent: 15. april 2010 15:05 To: nav-users@uninett.no Subject: ipdevinfo takes ages to load
Hello everyone,
For a very long time, I've had problems with slow loading ipdevinfo pages (typically when opening a switch listed in "Reports" -> All IP Devices) I first thought this was related with poor performance I/O on my VMWare instance the server was running on, but the problem persists on a physical server as well. Sometimes it never opens, it just "hangs" in a state of loading the page. I haven't tried to Wireshark the connection between my client and the NAV server itself, nor between the NAV server and the postgres server (which is hosted on another server on the same subnet) I don't have the same problem on all switches, and I've also thought I might have been unlucky catching my server in a heavy cricket/collection cycle (although its running on a 2 x QuadCore and 16GB memory system.....)
I've tried to look in the error- and access logs in /var/log/apache2 without seeing anything suspicious. The load of the server is also quite low when I have this problem, so I doubt it's a performance issue. Have anyone else had a similar problem, or knows how I can troubleshoot it?
Currently running NAV 3.5.6 on a Debian Lenny system with an external postgres database (running in RH EL5)
Many thanks for any help!
Vidar Stokkenes Konsulent Nettverk Seksjon for nettverk og telekom Helse Nord IKT - Tromsø
Tlf: 76 16 61 87 / 77 66 99 55 Mobil: 95 87 99 42 e-post: vidarst@hn-ikt.no
On Thu, Apr 15, 2010 at 03:23:12PM +0200, Stokkenes Vidar wrote:
Actually, after a bit more of clicking - I managed to get this output in /var/log/apache2/nav.domain.com-error.log when I click the switch name in "Reports":
[snip long traceback log]
[Thu Apr 15 15:14:11 2010] [error] [client 172.29.0.33] IOError: Write failed, client closed connection., referer: https://nav.domain.com/ipdevinfo/campus-problem-switch.domain.no/
All this tells me is that your browser closed the HTTP connection before the server had finished sending all the page data.
On Thu, Apr 15, 2010 at 03:04:31PM +0200, Stokkenes Vidar wrote:
Hello everyone,
For a very long time, I've had problems with slow loading ipdevinfo pages (typically when opening a switch listed in "Reports" -> All IP Devices)
Does this switch have any CAM records associated with it?
There is a known issue in ipdevinfo that will cause it to take forever to load a page for a device that has no CAM records - typically servers or pure layer 3 devices (routers).
I see now this hasn't been registered as a bug in Launchpad, but it has been fixed for NAV 3.6. PostgreSQL creates a crappy query plan for a simple query that wants to find the first CAM entry from a device, and it ends up scanning all CAM records (often millions), just to find out that there are no rows.
If this seems to be a match for your problem, you can find the fix w/details here: http://metanav.uninett.no/hg/default/rev/b2d0a4699bb1