Resolving since H4 doesn't use frames, and this has been hanging around.

Hmm I don't get this message on logout but I do get it when I try to 
dele SyncML sessions. Maybe related?

experiencing the same type of behavior on logouts on a new install.   
Horde newb, please advise what, if any, additional info you need/want 
on our configuration.

I've got this rather annoying problem, and was wondering whether or 
not it would be possible to resolve it by locking records during the 
initial reads using SQL in the following manner:



http://dev.mysql.com/doc/refman/5.0/en/innodb-locking-reads.html



I'm leaning towards a SHARE lock myself as it allows all reads to 
continue but only the first one to read gets to update, but I've not 
studied when the SQL is issued and whether anything would be blocked 
awaiting a DB lock if something else holds a lock...



I'm not sure what the PEAR DB library fix would be as they don't know 
that an update is imminent unless they're told so by the code using 
their library, which is exactly what the above tries to achieve...



'course, PEAR may have some other method for this already but I'm no 
PEAR expert, indeed, the best solution overall would probably be 
Optimistic locking but that would probably require significant code 
changes or adding another library between Horde and the DB...

Can you please post a link to that ticket here?

I agree on the crudeness of the patch, so I'm going to file a bug in 
the PEAR DB site :-)

That's really a crude hack that I'd rather like to avoid. Do you have 
a word from the DB maintainers whether they consider this a bug? Have 
you reported this to them?

Hello.



I have been struggling with a problem similar this for a few days: 
basically a non-very-deterministic behavior of the two logout links 
with the horde_logout_token in the main page. My scenario is Horde 
3.3.5 using MS SQL Server as session data storage through PEAR's DB 
abstraction layer.



Maybe this could give some ideas to others with the same problem, and 
I think it could be at least a bug report and fix for my specific 
situation.



Finally it seems to turn out that it is a race condition problem 
during the situations of simultaneous update of the session_data, 
because of DB transaction mechanisms that are not so obvious in their 
inner working in PEAR DB. The first thing that I noticed is that the 
problem arose in reloads of the main page, which has two frames, each 
one with a logout button with a horde_logout_token (those values are 
stored in the session_data field as "horde_form_secrets"). If you 
reload first one frame, then the other, everything works as expected 
(slow down one of the participants in the race so no problems appear 
:-) ).



PEAR DB uses the concept of autocommit as a way of start automatically 
a transaction, but the real transaction (issuing the "BEGIN 
TRANSACTION" to the DB) starts just with a so called "manipulation 
query" (INSERT, UPDATE, DELETE). That means that the intended atomic 
process:



  1. Read session data from DB

  2. Update session data in DB



is not actually a transaction, because the BEGIN TRANSACTION starts in 
the 2nd step.

That leads to a situation with no atomicity and hence a really nice 
"race condition" with not so really nice results.



As I didn't plan to fix anything in PEAR DB, I found a workaround that 
could be acceptable, even if it's not the most elegant way.



I forced a "manipulation query" in the _read() function at 
lib/Horde/SessionHandler/sql.php just before the 1st step of obtaining 
the session data, in order to force the begin of the transaction:



         /* Force manipulation query to effectively begin the transaction */

         $table = $this->_params['table'];

         $updatestring = 'session_id=session_id';

         $wherestring = 'session_id = ?';

         $query = sprintf('UPDATE %s SET %s WHERE %s',

                           $table,

                           $updatestring,

                           $wherestring);

         $values[] = $id;

         $result = $this->_write_db->query($query, $values);

         if (is_a($result, 'PEAR_Error')) {

             Horde::logMessage($result, __FILE__, __LINE__, PEAR_LOG_ERR);

             return false;

         }



This makes transaction work and no more race condition appeared in my 
scenario so far.

See patch attached.

Maybe there was some oddity in mysql sessionhandler table, or during 
upgrade. I empty session-handler table and now admin/sessions.php 
works fine.

Sorry for noise...

Regards

I only notice that into administration setting 'admin/sessions.php' I 
can't see any session references.

Page stays waiting forever after I click.

This happens with last horde-webmail-1.2.4 and mysql session handler, 
rowlocking, not persistent, INNODB table.

So, we're back to start, it has nothing to do with either rowlocking 
or persistent connections. There is still no common scheme when this 
happens.

I now have an update.  To test the 'rowlocking' component of your

question, I had a few changes to make to the database side as well

as the application's configuration.



We do not use persistent connections.  With rowlocking turned off, the

behavior does still occur.

Any update?

Sorry about that.  In regards to the behavior when using the MySQL 
session handler, we are not currently using persistent connections.   
We are, however, using row-level locking.  I will have to modify a few 
things in order to try it without row-level locking.



Hopefully, I can quickly get that information to you.

Ping?

Can you try if it works with either persistent connections or 
rowlocking turned off?

I agree: with php 5.2.10 it works. But I have to set



$conf['sessionhandler']['params']['persistent'] = false;



otherwise it locks table just after login:



2009-07-27T08:42:12.977668+02:00  HORDE[7639]: [horde] Error 
retrieving session data (id = jrulbam7sks33etj0lbc8dpba6): Lock wait 
timeout exceeded; try restarting transaction [pid 7639 on line 144 of 
"horde-webmail-1.2.3/lib/Horde/SessionHandler/mysql.php"]



Mysql has innodb horde_sessionhandler table. I set also

$conf['sessionhandler']['params']['rowlocking'] = true;

and I use TCP to connect.



So mysql session handler doesn't work with persistent connections.

Thanks Rick, I upgraded my CentOS 5.3 to the latest patches and the 
problem is now resolved.

I upgraded my server (not because of this issue) from Apache 
2.0.59/php5.2.0 to Lighttpd 1.4.23/php 5.2.10 and I have no longer 
seen this issue.  My horde configuration was not changed.

Just so that you know there are more of us out there, I have the same 
exact problem where the logout from the tree gives me the same error.   
I am using a user defined session handler that has a persistent MySQL 
connection.

See also ticket #7618.

I originally noted the error while using the MySQL session handler, 
but have since changed to memcache.  Both throw the error 
unpredictably for me.

At the time that I posted my addition to this bug report, the answer to

Jan's question was "yes".  I was using the Memcache Session Handler (not

Horde Memcache Session Handler) which was through the specification of

it in the php.ini file.



However, since that time, I have also been experimenting with the Horde

MySQL session handler.  I have also experienced the same behavior.

However, I have been able to isolate the behavior a little more.



I don't know whether it would be construed as a bug or just undesirable

behavior which is understandable.



Installed Software

------------------



* RHEL5 RPM Installations

   Apache 2.2

   PHP 5.1.6

   MySQL 5.0.45



* Horde Groupware Webmail edition (version 1.2.3)

   Configured to use Horde MySQL session handler



Configuration

-------------

* Database => MySQL

* Authentication => Imp

* Session Handler => Horde MySQL Session Handler



Steps (run from a Linux desktop)

-----

1. Connect to Webmail and successfully authenticate.



2. Let the session remain idle gc_maxlifetime and have garbage collection

    take place.  (So the session ID associated with Step #1 is removed from

    the horde_sessionhandler table).



3. Open another browser window, running on the SAME desktop, and log in

    using the SAME login.



4. Now click on the "Logout" button associated with the idle session

    established in Step #1.  The browser will return a page stating



       "We cannot verify that this request was really sent by you. It

        could be a malicious request. If you intended to perform this

        action, you can retry it now."



5. If instead, you click on any other button, things continue as normal,

    but I think that it is operating off of the new session ID (and

    cookie) associated with the session established in Step #3.



If I perform Step #3 from the SAME desktop and use a DIFFERENT login from

that which was used in Step #1, the logout and all other operations work,

meaning that the session (from Step #1) is automatically logged out.



If I perform Step #3 from a different desktop and use the SAME login as in

Step #1, the logout and all other operations also work.



Does this make sense?  I can try to further explain, if necessary.



Please note:  I have not gone back to my Memcache configuration to verify

               if the pattern that I have found with MySQL also applies to

               the Memcache scenario that I documented before.

I fixed my problem...



In the Custom session Handler I choose "Use the default PHP session 
handler (file-based by default)" instead of mysql (that I selected 
when I install horde)



now, all logout button works perfectly.



hope my hint will help others...

In my php.ini I have:



session.save_handler = files



no special config from the default

So, are you saying that this only happens if you configure a custom 
session in handler in the *PHP* configuration (as opposed to the Horde 
configuration)?

Is this what the other reporters are using too?

I have the same problem...



When I use the logout on head bar it only work if I'm in IMP if I'm in 
the main horde section I get the error message.



I can reproduce it anytime

Installed Software

--------------------------

* RHEL5 RPM Installations

   Apache 2.2

   PHP v5.1.6

   MySQL 5.0.45



* Horde Groupware Webmail Edition (version 1.2.2)

   http://ftp.horde.org/pub/horde-webmail/horde-webmail-1.2.2.tar.gz



* Memcached (version 1.2.6)

   http://www.danga.com/memcached/download.bml



* Memcache PHP Module (version 2.2.5)

   http://pecl.php.net/package/memcache





Configuration

--------------------

* Database => MySQL

* Authentication => imp

* Session Handler => Default PHP Session Handler



* /etc/php.ini

   Using the default /etc/php.ini file with the recommended additional or

   modified lines to support the Memcache Session Handler.



   [NOTE: Many of these settings are quite short in order to test behavior.]



   extension=memcache.so

   session.save_handler = memcache

   session.save_path = "tcp://localhost:11211"

   session.use_cookies = 1

   session.use_only_cookies = 1

   session.name = PHPSESSID

   session.auto_start = 0

   session.cookie_lifetime = 300

   session.gc_probability = 1

   session.gc_divisor = 1

   session.gc_maxlifetime = 122



   expose_php = Off

   display_errors = Off            (default)

   log_errors = On                 (default)

   register_globals = Off          (default)



* /etc/php.d/memcache.ini

   memcache.allow_failover = 1

   memcache.max_failover_attempts = 20

   memcache.chunk_size = 8192

   memcache.default_port = 11211

   memcache.hash_strategy = standard

   memcache.hash_function = crc32



* I am currently running the Memcached daemon in the foreground, so that I

   could better understand see the dialogue between the application and

   the server.



Problem

------------

* Thus far, everything seems to work until I attempt to log out.

* If I click on an application in the sidebar and then click on the "Log out"

   icon at the top of the frame, log out is successful.  The displayed URL is:



https://hostname/imp/login.php?horde_logout_token=<tokenstring>=horde&logout_reason=logout



* If I click on the "Log out" in the side bar, I receive the error:



         We cannot verify that this request was really sent by you. It could

         be a malicious request. If you intended to perform this action,

         you can retry it now.



   The displayed URL is:



https://hostname/login.php?horde_logout_token=<tokenstring>=horde&logout_reason=logout



   However, if I modify the URL and change it to (Please, notice the only

   change being the addition of "imp" to the URL):



https://hostname/imp/login.php?horde_logout_token=<tokenstring>=horde&logout_reason=logout



   , it then successfully logs out.





* I have tracked down the code which is responsible for the error.  It is

   located in the 'checkRequestToken' function in the file,

   <Horde root directory>/lib/Horde.php



--------------------------------------------

function checkRequestToken($slug, $token)

     {

         if (empty($_SESSION['horde_form_secrets'][$token])) {

             return PEAR::raiseError(_("We cannot verify that this 
request was really sent by you. It could be a malicious request. If 
you intended to perform this action, you can retry it now."));

         }



         if (($_SESSION['horde_form_secrets'][$token] + 
$GLOBALS['conf']['urls']['token_lifetime'] * 60) < time()) {

             return PEAR::raiseError(sprintf(_("This request cannot be 
completed because the link you followed or the form you submitted was 
only valid for %s minutes. Please try again now."), 
$GLOBALS['conf']['urls']['token_lifetime']));

         }



         return true;

     }

--------------------------------------------



* When I used the Horde Memcache Session Handler, all "Log outs" (icon

   and sidebar) worked.  However, the Horde Memcache Session Handler does

   not include an expiration on the session in the communication with

   the Memcached daemon, which is something we require.

Just in case it could be useful, i'm using

php-5.2.8

PEAR-MDB2_Driver_pgsql-1.5.0_beta1

PEAR-MDB2-2.5.0_beta1



i don't know if it's a Postgresql related issue or a more generic 
db-agnostic one.

It should be interesting to understand why the bug only trigger when 
using the left logout button and not the one in the top bar: is logout 
managed differently in the left/top buttons ?

I can't reproduce this with the MySQL session handler either.

Yes, you are right!

We are using custom, sql-based session handler, too. (MySQL 5.0.51).



If i change session handler to default PHP file-based, there is no error.

I'm able to reproduce the issue on my system.

The problem only occours using the sql driver for sessionhandler in 
conf.php and only clicking on the "Logout" item in the left bar (using 
the logout button on the top is okay).

I'm using Horde Groupware Webmail Edition 1.2.2 with Postgresql 8.2.

Let me know if you need more info.

I've seen it sporadically for a while now, when logging out as I 
recall.  I just had a user report it, which is why I'm looking into it 
again.



I have not been able to reproduce it at will though.

I don't see this either, and I don't see any other user reports.

hmm, i can reproduce this since several horde webmail versions.

We use IMP (dovecot IMAP) as authenticate handler, perhaps that is a 
difference.

I can't reproduce this.

When I log in into our horde Webmail AND log out, immediately, i got the



"We cannot verify that this request was really sent by you. It could 
be a malicious request. If you intended to perform this action, you 
can retry it now."



message.



This only happens with the "logout" button from the left frame menu. 
The "logout" button in the head bar always works.



Probably there is something wrong with the "horde_logout_token", 
within registration.



To watch the error, please follow these steps exactly:

1. ) Log in to your horde framework

2.) Push the "logout" Button in the left frame  (last one)

3. ) You get the message about "malicious request", mentioned above,

AND you are not logged out correctly (session still alive)



1. ) Log in to your horde framework

2.) Push a button like Webmail/Inbox

3.) Push the "logout" Button in the left frame  (last one)

4. ) Your are logged out correctly