[Catalyst] weird problem with session_expires

[Nicolas Raspail]

Hello,

I have a strange problem with my session. I'm using Session,  
Session::State::URI and Session::Store::FastMmap and XML RPC commands.

I can successfully use session, but when I want to check if a session  
has expired or not, session_expires never returns me 0 if the session  
has expired. Instead, it seems that it returns me the expire time plus  
the time between the two XML RPC call !

Example:

my test script sends a first command, sleep 10 seconds and sends the  
second command. Here is the debug output I get :

[info] *** Request 1 (0.167/s) [590] [Thu Aug 30 16:08:39 2007] ***
[debug] "POST" request for "rpc" from "10.30.72.167"
[debug] XML-RPC: Method called: login
[debug] Path is "login"
[debug] Created session "46616ce55819d55f5af3b062061e86fa0abc5a99"
[fatal] $VAR1 = {
           '__user_realm' => 'default',
           'data' => 'Session 46616ce55819d55f5af3b062061e86fa0abc5a99',
           '__user' => bless( {
                                'password' => 'test',
                                'store' =>  
'Catalyst::Plugin::Authentication::Store::Minimal',
                                'auth_realm' => 'default',
                                'id' => 'nicolas',
                                '__hash_obj_key_is_array' => {}
                              },  
'Catalyst::Plugin::Authentication::User::Hash' ),
           '__created' => 1188482919,
           '__updated' => 1188482919
         };
[info] Request took 0.034786s (28.747/s)
.----------------------------------------------------------------+-----------.
| Action                                                         | Time      |
+----------------------------------------------------------------+-----------+
| /xmlrpc/login                                                  | 0.006627s |
| /xmlrpc/end                                                    | 0.000050s |
'----------------------------------------------------------------+-----------'

[info] *** Request 2 (0.118/s) [590] [Thu Aug 30 16:08:50 2007] ***
[debug] Query Parameters are:
.-------------------------------------+--------------------------------------.
| Parameter                           | Value                                |
+-------------------------------------+--------------------------------------+
| sessionid                           | 46616ce55819d55f5af3b062061e86fa0ab- |
|                                     | c5a99                                |
'-------------------------------------+--------------------------------------'
[debug] "POST" request for "rpc/" from "10.30.72.167"
[debug] XML-RPC: Method called: host_register
[debug] Found sessionid "46616ce55819d55f5af3b062061e86fa0abc5a99" in  
query parameters
[debug] Path is "host_register"
[fatal] 1188482979 (from $c->get_session_data)
[fatal] >>>Expire 1188482990 (from $c->session_expires)
[debug] Restored session "46616ce55819d55f5af3b062061e86fa0abc5a99"
[fatal] Session 46616ce55819d55f5af3b062061e86fa0abc5a99
[fatal] >>>hostid = 1e0aa748
[fatal] >>>hostname = rhel5-test
[info] Request took 0.019859s (50.355/s)
.----------------------------------------------------------------+-----------.
| Action                                                         | Time      |
+----------------------------------------------------------------+-----------+
| /xmlrpc/host_register                                          | 0.002980s |
| /xmlrpc/end                                                    | 0.000046s |
'----------------------------------------------------------------+-----------'

As you can see, there is a difference between the time in the store  
area and the time returned from session_expires.

Am'I doing a mistake or there is a sort of bug ?

Regards

Nicolas