[dev.icinga.com #3530] PostgreSQL-Sessionproblem

[icinga-migration]

This issue has been migrated from Redmine: https://dev.icinga.com/issues/3530

Created by dmikulski on 2013-01-11 12:56:33 +00:00

Assignee: mfrosch
Status: Resolved (closed on 2013-02-11 16:24:26 +00:00)
Target Version: 1.8.2
Last Update: 2013-02-11 16:24:26 +00:00 (in Redmine)

Icinga Version: 1.8.3
Icinga Web Version: 1.8.1
IDO Version: 1.8.0
OS Version: CentOS 6.3
DB Type: PostgreSQL
DB Version: PostgreSQL 8.4.13 und mit 9.2
Browser Version: FireFox 17.0.1 und andere

---

In a new installed CentOS6.3 with PostgreSQL 8.4 database, IDOUtils and Icinga, after Login my browser lands immediatly again in the Login Screen or there is the error message "Your login session has gone away, press ok to login again!
" (see screenshot).
The the issue I get on my Live-Testsystem. Sometime it works for a undefined time (sometime more sometimes less long) but the error then occur again.

Exrtact from Icinga-Web Log:
[Sat Jan 5 18:18:03 2013] [fatal] Uncaught AppKitDoctrineException: User attribute is not a NsmUser! (/usr/local/icinga-web/app/modules/AppKit/lib/auth/AppKitSecurityUser.class.php:270)

Auszug aus Icinga-Web-Debug Log:
[Sat Jan 5 18:17:42 2013] [debug] Auth.Provider: Object (name=internal) initialized
[Sat Jan 5 18:17:42 2013] [debug] Auth.Provider: Object (name=auth_key) initialized
[Sat Jan 5 18:17:42 2013] [debug] Auth.Provider: Object (name=http-basic-authentication) initialized
[Sat Jan 5 18:17:42 2013] [debug] Auth.Provider.HTTPBasicAuthentification: Got data (auth_name=, auth_type=)
[Sat Jan 5 18:17:51 2013] [debug] Auth.Dispatch: Starting authenticate (username=root)
[Sat Jan 5 18:17:51 2013] [info] Auth.Dispatch: Converting username to lowercase
[Sat Jan 5 18:17:51 2013] [debug] Auth.Dispatch: Userdata found in db (uid=1)
[Sat Jan 5 18:17:51 2013] [debug] Auth.Provider: Object (name=internal) initialized
[Sat Jan 5 18:17:51 2013] [debug] Auth.Dispatch: Authoritative provider found (provider=internal, authid=root)
[Sat Jan 5 18:17:51 2013] [debug] Auth.Provider.Database: HASH
[Sat Jan 5 18:17:51 2013] [debug] Auth.Dispatch: Successfull authentication (provder=internal)
[Sat Jan 5 18:17:51 2013] [info] Auth.Dispatch: Delegate authentication (not_authoritative=internal,user=root)
[Sat Jan 5 18:17:51 2013] [debug] Auth.Provider: Object (name=auth_key) initialized
[Sat Jan 5 18:17:51 2013] [debug] Auth.Provider: Object (name=http-basic-authentication) initialized
[Sat Jan 5 18:17:51 2013] [debug] Auth.Dispatch: Delegate authentication, try http-basic-authentication (not_authoritative=internal,user=root)
[Sat Jan 5 18:17:51 2013] [debug] Auth.Dispatch: Delegate authentication, no providers found for root (not_authoritative=internal)
[Sat Jan 5 18:17:52 2013] [info] User root (Root, Enoch) logged in!
[Sat Jan 5 18:18:01 2013] [debug] Auth.Provider: Object (name=internal) initialized
[Sat Jan 5 18:18:01 2013] [debug] Auth.Provider: Object (name=auth_key) initialized
[Sat Jan 5 18:18:01 2013] [debug] Auth.Provider: Object (name=http-basic-authentication) initialized
[Sat Jan 5 18:18:01 2013] [debug] Auth.Provider.HTTPBasicAuthentification: Got data (auth_name=, auth_type=)

I've already found this (but there is no feedback anymore):
http://www.mail-archive.com/icinga-users@lists.sourceforge.net/msg01531.html

Debugging isn't really possible with default setting. Maybe you know how I can get further information.

Currently I've to evaulate new monitoring systems for my boss and the future system will have to work with PostgreSQL. Is there a way to get help to fix this issue before the next release by myself?

In issue #3520 (https://dev.icinga.org/issues/3520) jmosshammer already told me to try his branch. I did this but I got the same problems again. I've looked in the database and my sessions (compare to the hash from my cookie) are there (4 session entries).

Attachments

• Icinga-Web-Fehler.jpg dmikulski - 2013-01-11 12:56:33 +00:00

Changesets

2013-02-06 20:41:24 +00:00 by mfrosch 2b164cd

Fix session handling for creation and destruction

on creation the session gets immediatly written
into the database before any parallel running thread
might insert it as well
(without this the session will only be written into
the database when actual data is put in)

on destruction the session will now not really be
wiped from the database, but all data will be cleared
from it

(refs #3530)

2013-02-11 14:18:05 +00:00 by mfrosch 5d1ad82

Merge branch 'mfrosch/fixsession' into mfrosch/1.8.2

(fixes #3530)

2013-02-11 18:39:56 +00:00 by mfrosch 6d49613

Fix session handling for creation and destruction

on creation the session gets immediatly written
into the database before any parallel running thread
might insert it as well
(without this the session will only be written into
the database when actual data is put in)

on destruction the session will now not really be
wiped from the database, but all data will be cleared
from it

(refs #3530)

[icinga-migration]

Updated by mfriedrich on 2013-01-11 13:03:34 +00:00

and your webservers time is in sync, as well as your clients request within the cookie is too?

[icinga-migration]

Updated by dmikulski on 2013-01-11 13:18:16 +00:00

The timestamp in the database session entries is the one from my timezone (Europe/Berlin). I've also configured the php.ini with this timezone and restartet the httpd. The webserver system time is the same as the one from my timezone.
When a login works I see the time of Icinga. It's the time from my timezone.
From this side it looks good.

[icinga-migration]

Updated by lbetz on 2013-01-14 12:28:06 +00:00

I have a problem similar to yours. I installed Icinga/Postgres in a Virtualbox and after 2 hours suddenly I had this problem. In my case, the VM time ran slower than the time of the browser and so Icinga-Web kicked me out with 'Your login session has gone away, press ok to login again!' and then I had the 'failed login' you told. The cookie on the client was the Problem.

My offer, try to delete the cookie and report the result.

[icinga-migration]

Updated by mfriedrich on 2013-02-01 12:09:33 +00:00

• Status changed from New to Assigned
• Assigned to set to jmosshammer
• Target Version set to 1.8.2

another report in this regard.
http://www.monitoring-portal.org/wbb/index.php?page=Thread&postID=183477#post183477

@Jannis
can you have a look please?

[icinga-migration]

Updated by dmikulski on 2013-02-02 16:56:59 +00:00

I've made a new installation with the current git (master). First login worked. Then I logged out and tried to login again but I was instantly moved back to the login screen.

I've looked at the new debug log and found only this entry:

[Sat Feb 2 17:48:16 2013] [warn] New: Setting org.icinga.ext.appstate => {upref_id 17:48:16",upref_modified 17:48:16"} (NsmUser::setPref(), line 284)

[icinga-migration]

Updated by mfrosch on 2013-02-06 20:46:21 +00:00

• Category set to Framework
• Assigned to changed from jmosshammer to mfrosch
• Done % changed from 0 to 50

Hey there,
I've done a bit of testing and I found some unwanted (I hope) problems in the session handling.

Basically 2 changes should help with this problem:

1. Saving a new session into database after creation
   (without waiting for some data to put in the session)

2. Not really destroying the session, but clearing its
   data (see session_destroy in the login page ajax call)

I've pushed my changes to mfrosch/fixsession.

dnsmichi/mheim/jmosshammer: Please review and hopefully merge.
shiftycent: Could you try this change in your setup?

Regards
Markus

[icinga-migration]

Updated by mfriedrich on 2013-02-08 10:10:36 +00:00

possibly related to #3652

[icinga-migration]

Updated by dmikulski on 2013-02-09 07:28:55 +00:00

Yes dnsmichi, it is possible that it is related to this. I've looked in the icinga-web-src/etc/lib/dbInitializeTask.php and found that there is a logfile written to "/tmp/doctrine.log" where I found this:

[INIT ERROR] : SQLSTATE[23503]: Foreign key violation: 7 FEHLER: Einfügen oder Aktualisieren in Tabelle »nsm_princal_target« verletzt Fremdschlüssel-Constraint »nsm_principal_target_pt_principal_id_nsm_principal_principal_id«
DETAIL: Schlüssel (pt_principal_id)=(3) ist nicht in Tabelle »nsm_principal« vorhanden.

@lazyfrosch
First Login worked well but after I've logged out and logged in again I got an exception:

Uncaught Doctrine_Hydrator_Exception thrown:
Couldn't hydrate. Found non-unique key mapping named 'org.icinga.ext.appstate' for the field named 'upref_key'.
Stacktrace:

#0 /usr/local/icinga-web/lib/doctrine/lib/Doctrine/Hydrator.php(148): Doctrine_Hydrator_Graph->hydrateResultSet(Object(Doctrine_Connection_Statement))
#1 /usr/local/icinga-web/lib/doctrine/lib/Doctrine/Query/Abstract.php(1036): Doctrine_Hydrator->hydrateResultSet(Object(Doctrine_Connection_Statement), Array)
#2 /usr/local/icinga-web/app/modules/AppKit/lib/database/models/NsmUser.php(336): Doctrine_Query_Abstract->execute(Array, 3)
#3 /usr/local/icinga-web/app/modules/AppKit/lib/auth/AppKitSecurityUser.class.php(304): NsmUser->getPreferences()
#4 /usr/local/icinga-web/app/modules/AppKit/templates/Ext/HeaderSuccess.php(30): AppKitSecurityUser->getPreferences()
#5 /usr/local/icinga-web/lib/agavi/src/renderer/AgaviPhpRenderer.class.php(101): require('/usr/local/icin...')
#6 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1617): AgaviPhpRenderer->render(Object(AgaviFileTemplateLayer), Array, Array, Array)
#7 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1702): AgaviExecutionFilter->execute(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#8 /usr/local/icinga-web/lib/agavi/src/filter/AgaviSecurityFilter.class.php(61): AgaviFilterChain->execute(Object(AgaviExecutionContainer))
#9 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1702): AgaviSecurityFilter->execute(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#10 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(870): AgaviFilterChain->execute(Object(AgaviExecutionContainer))
#11 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1600): AgaviExecutionContainer->execute()
#12 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1702): AgaviExecutionFilter->execute(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#13 /usr/local/icinga-web/lib/agavi/src/filter/AgaviSecurityFilter.class.php(73): AgaviFilterChain->execute(Object(AgaviExecutionContainer))
#14 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1702): AgaviSecurityFilter->execute(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#15 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(870): AgaviFilterChain->execute(Object(AgaviExecutionContainer))
#16 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(900): AgaviExecutionContainer->execute()
#17 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(872): AgaviExecutionContainer->proceed()
#18 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1266): AgaviExecutionContainer->execute()
#19 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1255): AgaviDispatchFilter->execute(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#20 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1700): AgaviFilter->executeOnce(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#21 /usr/local/icinga-web/lib/agavi/src/filter/AgaviFormPopulationFilter.class.php(78): AgaviFilterChain->execute(Object(AgaviExecutionContainer))
#22 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(1700): AgaviFormPopulationFilter->executeOnce(Object(AgaviFilterChain), Object(AgaviExecutionContainer))
#23 /usr/local/icinga-web/app/cache/config/compile.xml_production__119920113a175a2dcea22e33a36de83ba298e663.php(579): AgaviFilterChain->execute(Object(AgaviExecutionContainer))
#24 /usr/local/icinga-web/pub/index.php(49): AgaviController->dispatch()
#25 {main}

[icinga-migration]

Updated by dmikulski on 2013-02-09 14:55:47 +00:00

Now it seems to work with manual db schema import.

With already installed branch:

• mfrosch/fixsession
  I've made "make db-drop" and then recreated the db as postgres user with "createdb -O icinga_web icinga_web". After this I've imported the schema from icinga-web-src/etc/schema/pgsql.sql as postgres user with "psql -U icinga_web -d icinga_web < pgsql.sql" tried to login again. Now I can login and logout as often I wish without any error. The icinga-web installation remained untouched all the time. So the error regarding this problem seem to result from "make db-initialize" procedure.

I will do further tests and start now the installation of lconf for icinga-web.

[icinga-migration]

Updated by mfrosch on 2013-02-11 16:24:26 +00:00

• Status changed from Assigned to Resolved
• Done % changed from 50 to 100

Applied in changeset 5d1ad82.