6.0.0-git
2019-03-23

[#10098] save_sent_mail pref gets corrupted
Summary save_sent_mail pref gets corrupted
Queue IMP
Queue Version Git master
Type Bug
State Resolved
Priority 2. Medium
Owners slusarz (at) horde (dot) org
Requester rsalmon (at) mbpgroup (dot) com
Created 2011-05-18 (2866 days ago)
Due
Updated 2011-08-24 (2768 days ago)
Assigned 2011-05-26 (2858 days ago)
Resolved 2011-08-24 (2768 days ago)
Milestone
Patch No

History
2011-08-24 16:14:51 Michael Slusarz Comment #27
State ⇒ Resolved
Reply to this comment
Closing. Reopen if problems are seen.
2011-08-24 16:13:03 Git Commit Comment #26 Reply to this comment
Changes have been made in Git for this ticket:

Log entry for Bug #10098

  1 files changed, 5 insertions(+), 5 deletions(-)
http://git.horde.org/horde-git/-/commit/2db30450d1f309df3ef29f95780c957dbe6af554
2011-08-24 08:06:18 rsalmon (at) mbpgroup (dot) com Comment #25 Reply to this comment
So try this patch and see if it fixes things.
it looks good so far. I will run  further tests for a day or two, to 
make sure I don't get the original behaviour any more.

thanks.
2011-08-24 05:21:45 Michael Slusarz Comment #24 Reply to this comment
if $_prefs['default_identity']['locked'] is set to true. I don't get 
a Sent folder.
This was the key piece of information.  If default_identity was 
locked, we were taking the current value of the various identity 
properties and temporarily saving them to the prefs cache.  However, 
this saved information was written directly to the prefs backend, 
without first calling setValue(), so any necessary changes (like 
converting from object -> string) were not done.

I don't see why we even need to save to the prefs cache.  We should 
just let subsequent calls to getValue() grab the default values from 
the preferences backend as needed.

So try this patch and see if it fixes things.
2011-08-24 05:16:21 Git Commit Comment #23 Reply to this comment
Changes have been made in Git for this ticket:

Bug #10098: Fix identities when default_identity is locked

  1 files changed, 0 insertions(+), 10 deletions(-)
http://git.horde.org/horde-git/-/commit/73f2df2a6d06b2151b1c7e4e54b0b19c0e62cc39
2011-08-24 04:52:41 Michael Slusarz Comment #22 Reply to this comment
  --- Identity.php.org        2011-08-23 17:17:09.000000000 +0200
+++ Identity.php        2011-08-23 17:17:15.000000000 +0200
@@ -524,1 +524,1 @@
-                ? IMP_Mailbox::get(IMP_Mailbox::prefFrom($val))
+                ? strval(IMP_Mailbox::get(IMP_Mailbox::prefFrom($val)))
Except that's not right.  sent_mail_folder should be an IMP_Mailbox 
object, not a string.  So casting to a string is wrong.
2011-08-23 15:29:38 rsalmon (at) mbpgroup (dot) com Comment #21 Reply to this comment
with
$_prefs['default_identity']['locked'] = true;

and

  --- Identity.php.org        2011-08-23 17:17:09.000000000 +0200
+++ Identity.php        2011-08-23 17:17:15.000000000 +0200
@@ -524,1 +524,1 @@
-                ? IMP_Mailbox::get(IMP_Mailbox::prefFrom($val))
+                ? strval(IMP_Mailbox::get(IMP_Mailbox::prefFrom($val)))


It works for me. I don't know if this can work with multiple identities.




2011-08-23 14:08:03 rsalmon (at) mbpgroup (dot) com Comment #20 Reply to this comment

[Show Quoted Text - 29 lines]
I've updated php to version 5.3.7 and git this morning. Now, if horde 
pref $_prefs['default_identity']['locked'] is set to false, all seamed 
to be working Ok.

if $_prefs['default_identity']['locked'] is set to true. I don't get a 
Sent folder.
I've added some logging  in /imp/lib/Prefs/Identity.php
     public function getValue($key, $identity = null)
     {
         $val = parent::getValue($key, $identity);
         switch ($key) {
         case 'sent_mail_folder':
             if (is_string($val) === false) 
{horde::logMessage("7777777777777 '$val' " . print_r($val,true));}
             return (is_string($val) && strlen($val))
                 ? IMP_Mailbox::get(IMP_Mailbox::prefFrom($val))
                 : null;

...

here is the ouput :
2011-08-23T15:54:25+02:00 INFO: HORDE [imp] 7777777777777 'INBOX.Sent' 
IMP_Mailbox Object
(
     [cache] => Array
         (
         )

     [changed] => 0
     [_mbox:protected] => INBOX.Sent
)
2011-08-23T15:54:33+02:00 INFO: HORDE [imp] 7777777777777 'INBOX.Sent' 
IMP_Mailbox Object
(
     [cache] => Array
         (
             [n] => Array
                 (
                     [0] => .
                     [2] => INBOX.
                     [4] => 1
                 )

             [d] => Sent
         )

     [changed] => 0
     [_mbox:protected] => INBOX.Sent
)








2011-08-17 04:27:37 Michael Slusarz Comment #19 Reply to this comment
Maybe this commit will help - it will do sanity checking on saved
identities data.
no, this is worth. I don't get any Sent folder now.
Now I am just convinced that your PHP is just badly broken.  As 
previously mentioned, there is only **ONE** place where we set the 
value of sent_mail_folder -> in IMP_Prefs_Identity::setValue().  If we 
are saving the 'sent_mail_folder' key, the value is ALWAYS passed 
through IMP_Mailbox::prefTo($val).  IMP_Mailbox::prefTo() ALWAYS 
returns a string:

         if (($ns = self::get($mbox)->namespace_info) !== null) {
              if ($ns['name'] == $def_ns['name']) {
                  /* From personal namespace => strip namespace. */
                  return substr(strval($mbox), 
strlen($def_ns['name'])); // STRING RETURN
              } elseif ($ns['name'] == $empty_ns['name']) {
                  /* From empty namespace => prefix with delimiter. */
                  return $empty_ns['delimiter'] . strval($mbox); // 
STRING RETURN
              }
          }

         return strval($mbox);  // STRING RETURN

You will have to figure out exactly why this isn't working on your 
system, or I am going to mark this bug bogus (because nobody else can 
reproduce).
2011-07-28 07:31:43 rsalmon (at) mbpgroup (dot) com Comment #18 Reply to this comment
Maybe this commit will help - it will do sanity checking on saved 
identities data.
no, this is worth. I don't get any Sent folder now.
here is what I get in the logs after clicking on 'new message'
Horde::logMessage(print_r($val, true));


2011-07-28T09:03:15+02:00 INFO: HORDE [imp] IMP_Mailbox Object
(
     [cache] => Array
         (
             [n] => Array
                 (
                     [0] => .
                     [2] => INBOX.
                     [4] => 1
                 )

             [d] => Sent
         )

     [changed] => 0
     [_mbox:protected] => INBOX.Sent
)
  [pid 24793 on line 523 of 
"/var/www/html/hordetest/imp/lib/Prefs/Identity.php"]


the test is_string($val) returns false
Still think your identities data is corrupt though.
I already cleared prefs :
mysql> delete from horde_prefs;

and identities are locked and prefs are set using hooks (see settings 
in logs.tgz). May be this is why I'm having this random issue.




2011-07-27 19:00:40 Michael Slusarz Comment #17 Reply to this comment
Maybe this commit will help - it will do sanity checking on saved 
identities data.  Still think your identities data is corrupt though.
2011-07-27 19:00:16 Git Commit Comment #16 Reply to this comment
Changes have been made in Git for this ticket:

Bug #10098: Sanity checking on saved identity data

  1 files changed, 10 insertions(+), 3 deletions(-)
http://git.horde.org/horde-git/-/commit/0a899c2e98de7225fa6d1ce7a22b296ed2a771e6
2011-07-27 18:54:35 Michael Slusarz Comment #15 Reply to this comment

[Show Quoted Text - 26 lines]
Try deleting all 'identities' prefs in your preferences backend.   
Looks like you have bad data in there.
2011-07-27 13:43:44 rsalmon (at) mbpgroup (dot) com Comment #14 Reply to this comment
Just notice that I get an error in apache's log file as well :

[Wed Jul 27 11:38:09 2011] [error] [client 192.168.1.73] PHP Fatal 
error:  Uncaught exception 'Horde_Imap_Client_Exception' with message 
'IMAP read error or IMAP connection timed out.' in 
/var/www/html/hordetest/libs/Horde/Imap/Client/Base.php:219\nStack 
trace:\n#0 
/var/www/html/hordetest/libs/Horde/Imap/Client/Socket.php(3949): 
Horde_Imap_Client_Base->_exception('IMAP read error...', 
'SERVER_READERRO...')\n#1 
/var/www/html/hordetest/libs/Horde/Imap/Client/Socket.php(3783): 
Horde_Imap_Client_Socket->_readData()\n#2 
/var/www/html/hordetest/libs/Horde/Imap/Client/Socket.php(4058): 
Horde_Imap_Client_Socket->_getLine()\n#3 
/var/www/html/hordetest/libs/Horde/Imap/Client/Socket.php(3709): 
Horde_Imap_Client_Socket->_parseResponse(8, true)\n#4 
/var/www/html/hordetest/libs/Horde/Imap/Client/Socket.php(627): 
Horde_Imap_Client_Socket->_sendLine('LOGOUT', Array)\n#5 
/var/www/html/hordetest/libs/Horde/Imap/Client/Base.php(642): 
Horde_Imap_Client_Socket->_logout()\n#6 
/var/www/html/hordetest/libs/Horde/Imap/Client/Base.php(249): 
Horde_Imap_Client_Base->logout()\n#7 [internal function]: 
Horde_Imap_Client_B in 
/var/www/html/hordetest/libs/Horde/Imap/Client/Base.php on line 219, 
referer: http://192.168.1.22/hordetest/imp/

2011-07-27 13:31:54 rsalmon (at) mbpgroup (dot) com New Attachment: logs.tgz Download
 
2011-07-27 13:30:58 rsalmon (at) mbpgroup (dot) com Comment #13 Reply to this comment
Maybe this fixes things?
Nope :-(

I have tried to set different values to 
$servers['imap']['cache']['lifetime'] and noticed that I get 
different results.
whatever value $servers['imap']['cache']['lifetime'], I always end up 
having the same issue.

I've updated from git this morning, logged in (dynamic mode) and 
clicked on New message.
The folder "Array\n" is created on the IMAP server (courier-imap 
4.8.1) and new sent emails will not be saved in the Sent folder. See 
attached logs file.

I've attached my IMP/horde config files. May be one of you will see 
something wrong.

I tried to find out why I get randomly the following error, but I 
didn't get anywhere :
2011-07-27T11:37:38+02:00 WARN: HORDE [imp] PHP ERROR: strlen() 
expects parameter 1 to be string, array given [pid 23914 on line 520 
of "/var/www/html/hordetest/imp/lib/Prefs/Identity.php"]

Any hint ?


2011-05-27 08:51:07 rsalmon (at) mbpgroup (dot) com Comment #12 Reply to this comment
Maybe this fixes things?
Nope :-(

I have tried to set different values to 
$servers['imap']['cache']['lifetime'] and noticed that I get different 
results.

I need to test further before posting what works and what doesn't.
2011-05-26 21:42:28 Michael Slusarz Comment #11
Assigned to Michael Slusarz
State ⇒ Feedback
Reply to this comment
Maybe this fixes things?
2011-05-26 21:42:13 Git Commit Comment #10 Reply to this comment
Changes have been made in Git for this ticket:

Bug #10098: Make sure output from prefTo is always a string

  1 files changed, 3 insertions(+), 3 deletions(-)
http://git.horde.org/horde-git/-/commit/9bd6f6d7710e9fbbb1b5194449b9498e8a312cf3
2011-05-20 10:12:18 rsalmon (at) mbpgroup (dot) com Comment #9
New Attachment: logs.zip Download
Reply to this comment

this doesn't happen when backend.local.php:$servers['imap']['cache'] => false.

it looks like the cache gets corrupt at some stage. can it be related 
to some TTL ?

attached is the logs when the problem occurs and then hitting "rebuild 
folder list".

I don't have cache enabled :
$conf['session']['cache_limiter'] = 'nocache';
$conf['group']['cache'] = false;
$conf['share']['cache'] = false;
$conf['cache']['driver'] = 'Null';
$conf['cache']['use_memorycache'] = '';
$conf['cachecss'] = false;
$conf['cachejs'] = false;
$conf['cachethemes'] = false;
$conf['sessionhandler']['memcache'] = false;
$conf['memcache']['enabled'] = false;



2011-05-20 07:48:09 Jan Schneider Comment #8 Reply to this comment
it seams that $val is an object, not a string. So the strlen call 
should fail in the return, no ?
No, it will cast the object to a string.
2011-05-20 07:31:40 rsalmon (at) mbpgroup (dot) com Comment #7 Reply to this comment
I have no idea, and there doesn't seem to be any place where this
could realistically happen.
:-)
this was supposed to be a :-(


2011-05-20 07:30:13 rsalmon (at) mbpgroup (dot) com Comment #6 Reply to this comment
I have no idea, and there doesn't seem to be any place where this 
could realistically happen.
:-)

In function /imp/lib/Prefs/Identity.php: function getValue
I've added the following code just before the return call :
if ($key == 'sent_mail_folder') {Horde::debug($val);}

And this is what I get :
2011-05-20T09:12:10+02:00 DEBUG: Variable information:
object(IMP_Mailbox)#213 (3) {
   ["cache"]=>
   array(2) {
     ["n"]=>
     array(3) {
       [0]=>
       string(1) "."
       [2]=>
       string(6) "INBOX."
       [4]=>
       int(1)
     }
     ["d"]=>
     string(7) "Envoy√©"
   }
   ["changed"]=>
   int(0)
   ["_mbox":protected]=>
   string(10) "INBOX.Sent"
}

Backtrace:
1. IMP_Views_Compose::showCompose() 
/var/www/html/hordetest/imp/compose-dimp.php:247
2. Imp_Prefs_Identity->getValue() 
/var/www/html/hordetest/imp/lib/Views/Compose.php:91
3. Horde::debug() /var/www/html/hordetest/imp/lib/Prefs/Identity.php:520

it seams that $val is an object, not a string. So the strlen call 
should fail in the return, no ?
and IMP_Mailbox::get(IMP_Mailbox::prefFrom($val)) seams to be 
returning an object(IMP_Mailbox)
However, there was some problems with the sent mail prefs UI that 
may have caused bad data to be stored in the save_sent_mail 
preference - try resaving the correct values through the UI again.
I didn't use the UI to set pref, and pref save_sent_mail wasn't set in 
horde_prefs. I used the default value (whatever is set in prefs.php).

but just to make sure, I delete all prefs in DB (mysql> delete from 
horde_prefs;) and will test again...


2011-05-19 16:46:23 Michael Slusarz Comment #5 Reply to this comment
I have no idea, and there doesn't seem to be any place where this 
could realistically happen.  However, there was some problems with the 
sent mail prefs UI that may have caused bad data to be stored in the 
save_sent_mail preference - try resaving the correct values through 
the UI again.
2011-05-19 16:45:02 Git Commit Comment #4 Reply to this comment
Changes have been made in Git for this ticket:

Bug #10098: Fixes to sent mail preferences UI

  3 files changed, 16 insertions(+), 11 deletions(-)
http://git.horde.org/horde-git/-/commit/9c898563d83be57c0ccff767c6e7fc4c3a9bfc1d
2011-05-18 13:41:36 rsalmon (at) mbpgroup (dot) com Comment #3 Reply to this comment

$_prefs['id']['value'] = '';
$_prefs['id']['locked'] = true;
$_prefs['id']['hook'] = true;
$_prefs['fullname']['value'] = '';
$_prefs['fullname']['locked'] = true;
$_prefs['fullname']['hook'] = true;
$_prefs['from_addr']['value'] = '';
$_prefs['from_addr']['locked'] = true;
$_prefs['from_addr']['hook'] = true;
$_prefs['default_identity']['locked'] = true;
2011-05-18 13:39:51 rsalmon (at) mbpgroup (dot) com Comment #2
New Attachment: sentpref-imaplog.txt Download
Reply to this comment
attached is the imaplog.txt
2011-05-18 13:39:14 rsalmon (at) mbpgroup (dot) com Comment #1
Type ⇒ Bug
State ⇒ Unconfirmed
Priority ⇒ 2. Medium
Summary ⇒ save_sent_mail pref gets corrupted
Queue ⇒ IMP
Milestone ⇒
Patch ⇒ No
New Attachment: sentpref-horde.txt Download
Reply to this comment
This is happening for a while now (a few weeks), save_sent_mail pref 
gets corrupted at some stage.

$conf['user']['select_sentmail_folder'] = true;
$conf['server']['fixed_folders'] = array('Drafts', 'Trash', 'Sent');
$_prefs['save_sent_mail']['value'] = 1
$_prefs['sent_mail_folder']['value'] => 
Horde_String::convertCharset('Sent', 'UTF-8', 'UTF7-IMAP')

Using dynamic mode, courier-imap, I log in (using english language or 
french) and do some compose/reply/drag&drop/delete messages. And after 
a while, could be 10 minutes or 1 hour, I get the following notice
'The folder "Sent" was successfully created' !

And a weird inaccessible folder is created : "Array\n"

attached is horde.log

I haven't found a way to reproduce this so I'm open to any idea on how 
to track down this issue.

Saved Queries