6.0.0-beta1
7/13/25

[#12827] PHP ERROR: array_intersect_key() when purging deleted items
Summary PHP ERROR: array_intersect_key() when purging deleted items
Queue IMP
Queue Version 6.1.5
Type Bug
State Resolved
Priority 1. Low
Owners slusarz (at) horde (dot) org
Requester aria (at) bsc (dot) gwu (dot) edu
Created 11/08/2013 (4265 days ago)
Due
Updated 11/21/2013 (4252 days ago)
Assigned 11/11/2013 (4262 days ago)
Resolved 11/21/2013 (4252 days ago)
Github Issue Link
Github Pull Request
Milestone
Patch No

History
11/21/2013 10:17:40 PM Michael Slusarz Comment #21
State ⇒ Resolved
Reply to this comment
Horde_Imap_Client 2.16.1.
11/21/2013 10:16:53 PM Git Commit Comment #20 Reply to this comment
Changes have been made in Git (master):

commit fb255f0aa4ed4a12a1c9d8df996bdc26a0f536c3
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Thu Nov 21 14:32:03 2013 -0700

     [mms] Fix intermittent error when purging messages using a 
Horde_Cache caching backend (Bug #12827).

  framework/Imap_Client/package.xml |    2 ++
  1 files changed, 2 insertions(+), 0 deletions(-)

http://git.horde.org/horde-git/-/commit/fb255f0aa4ed4a12a1c9d8df996bdc26a0f536c3
11/21/2013 01:53:00 PM aria (at) bsc (dot) gwu (dot) edu Comment #19 Reply to this comment
I assume that the debug logs were helpful.  That's a relief.

I don't have access to your GIT so I will wait until this one makes it 
out on a release.  THANKS for fixing.
11/21/2013 04:58:23 AM Michael Slusarz Comment #18
Assigned to Michael Slusarz
Reply to this comment
Try this.

And TIL that assigning a reference to a non-existent array key DOESN'T 
cause a PHP error - it instead creates a reference to a null value.   
(Although it is documented, so my bad: 
http://www.php.net/manual/en/language.references.whatdo.php)
11/21/2013 04:54:15 AM Git Commit Comment #17 Reply to this comment
Changes have been made in Git (master):

commit dbf3b9f6529b4b17e62fb999b18c268ea2c24480
Author: Michael M Slusarz <slusarz@horde.org>
Date:   Wed Nov 20 21:52:23 2013 -0700

     Fix error message when deleting messages using a Horde_Cache 
caching backend

     Bug #12827

  .../lib/Horde/Imap/Client/Cache/Backend/Cache.php  |    2 ++
  1 files changed, 2 insertions(+), 0 deletions(-)

http://git.horde.org/horde-git/-/commit/dbf3b9f6529b4b17e62fb999b18c268ea2c24480
11/20/2013 06:49:32 PM aria (at) bsc (dot) gwu (dot) edu Comment #16
New Attachment: debug-purge.txt Download
Reply to this comment
Here is attachment #2
11/20/2013 06:48:35 PM aria (at) bsc (dot) gwu (dot) edu Comment #15
New Attachment: debug-login.txt Download
Reply to this comment
I apologize in advance if this is rather convoluted or not what you 
wanted but I have no understanding of PHP and am not a software 
developer.

Here is a summary of what I did.
0-setup the PEAR/Horde/Imap/Client/Cache/Backend/Cache.php file with 
the debug statements (see below).
1-Cleared the cache backend (file system)
2-sent two messages to a test user with an empty inbox
3-login as the test user and display the inbox resulting in a debug 
file being generated.  See attachment debug-login.txt
4-marked messages for deletion and click purge deleted.  See 
attachment debug-purge.txt

To setup the debug, I changed two functions in the Cache.php file as follows:

     public function deleteMsgs($mailbox, $uids)
     {
$dmsg = "deleteMsgs-ENTRY";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);
         $slicemap = &$this->_slicemap[$mailbox];
$dmsg = "deleteMsgs-POINT-1";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);
         $deleted = array_intersect_key($slicemap['s'], array_flip($uids));
(snip)
And  further down:

     protected function _loadSliceMap($mailbox, $uidvalid = null)
     {
$dmsg = "_loadSliceMap-TOP";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);

         if (!isset($this->_slicemap[$mailbox]) &&
             (($data = $this->_cache->get($this->_getCid($mailbox, 
'slicemap'), 0)) !== false) &&
             ($slice = @unserialize($data)) &&
             is_array($slice)) {
             $this->_slicemap[$mailbox] = $slice;
         }

$dmsg = "_loadSliceMap-AFTER-IF-1";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);

         if (isset($this->_slicemap[$mailbox])) {
             $ptr = &$this->_slicemap[$mailbox];
             if (is_null($ptr['d']['uidvalid'])) {
                 $ptr['d']['uidvalid'] = $uidvalid;
$dmsg = "_loadSliceMap-RETURN-1";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);
                 return;
             } elseif (!is_null($uidvalid) &&
                       ($ptr['d']['uidvalid'] != $uidvalid)) {
                 $this->_deleteMailbox($mailbox);
             } else {
$dmsg = "_loadSliceMap-RETURN-2";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);
                 return;
             }
         }
$dmsg = "_loadSliceMap-AFTER-IF-2";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);


         $this->_slicemap[$mailbox] = array(
             // Tracking count for purposes of determining slices
             'c' => 0,
             // Metadata storage
             // By default includes UIDVALIDITY of mailbox.
             'd' => array('uidvalid' => $uidvalid),
             // The ID of the last slice.
             'i' => 0,
             // The slice list.
             's' => array()
         );
$dmsg = "_loadSliceMap-END";
Horde::debug($dmsg);
Horde::debug($this->_slicemap);

     }

It appears that when you click purge deleted, the function 
loadslicemap is not called at all.

Something tells me this is not going to be useful.  If not, please let 
me know what to change or send me a php code that has the debug 
statements you need and I will use that.
Thanks,
Aria



11/20/2013 07:03:14 AM Michael Slusarz Comment #14 Reply to this comment
I am happy to place debug code elsewhere if you would just tell me 
where it would be most helpful.  I also am testing this on a 
separate system so I can do any type of debugging you need.
See my comment below.  You need to pretty much put debug statements 
all throughout the code to figure out when the _slicemap variable is 
altered.  (the 'INBOX' key should contain an array value, rather than 
a null value).

I would start in _loadSliceMap(), since that's where $_slicemap is 
rebuilt from cache data.

11/20/2013 06:58:15 AM Michael Slusarz Comment #13 Reply to this comment
You don't happen to use the json-c extension shipped with latest 
Ubuntu/Debian versions?
This should be irrelevant.  The IMAP caching code doesn't use JSON.   
And I don't believe any of the Horde_Cache drivers do either.
11/19/2013 01:40:31 PM aria (at) bsc (dot) gwu (dot) edu Comment #12 Reply to this comment
You don't happen to use the json-c extension shipped with latest 
Ubuntu/Debian versions?
I am using SLES-11-sp3 system.  The only json related rpm is 
php53-json-5.3.17-0.15.1.
11/19/2013 01:37:49 PM aria (at) bsc (dot) gwu (dot) edu Comment #11 Reply to this comment

[Show Quoted Text - 16 lines]
I am happy to place debug code elsewhere if you would just tell me 
where it would be most helpful.  I also am testing this on a separate 
system so I can do any type of debugging you need.
11/19/2013 10:43:12 AM Jan Schneider Comment #10 Reply to this comment
You don't happen to use the json-c extension shipped with latest 
Ubuntu/Debian versions?
11/19/2013 05:13:54 AM Michael Slusarz Comment #9 Reply to this comment
2013-11-18T23:04:01+00:00 DEBUG: Variable information:
array(1) {
   ["INBOX"]=>
   &NULL
}
I have absolutely no idea how this value can be null.

The _slicemap variable, at the mailbox level, can only be altered in 
these locations:

save()  - no way this can be set to null.
clear() - this would destroy the INBOX key, so that's not it
_deleteMailbox - see (clear) - would destroy the INBOX key entirely.

That leaves _loadSliceMap().  But this can't be it either.  _slicemap 
is only set from cache data IF the unserialized data is an array.   
Otherwise, the slicemap is recreated as an array value.

I am totally out of ideas.  Someone is going to have to track this 
down locally.  I can neither reproduce, and there is no place in the 
code where this can happen that I can see.
11/18/2013 11:06:19 PM aria (at) bsc (dot) gwu (dot) edu Comment #8 Reply to this comment
Thanks.  Here is the debug output:

2013-11-18T23:04:01+00:00 DEBUG: Variable information:
array(1) {
   ["INBOX"]=>
   &NULL
}

Backtrace:
  1. Horde_Core_Ajax_Application->doAction() 
/data/www/horde/services/ajax.php:58
  2. call_user_func() /usr/share/php5/PEAR/Horde/Core/Ajax/Application.php:162
  3. IMP_Ajax_Application_Handler_Dynamic->purgeDeleted()
  4. IMP_Message->expungeMailbox() 
/data/www/horde/imp/lib/Ajax/Application/Handler/Dynamic.php:737
  5. IMP_Imap->expunge() /data/www/horde/imp/lib/Message.php:803
  6. IMP_Imap->__call() /data/www/horde/imp/lib/Message.php:803
  7. call_user_func_array() /data/www/horde/imp/lib/Imap.php:566
  8. Horde_Imap_Client_Base->expunge()
  9. Horde_Imap_Client_Socket->_expunge() 
/usr/share/php5/PEAR/Horde/Imap/Client/Base.php:2106
10. Horde_Imap_Client_Socket->_sendCmd() 
/usr/share/php5/PEAR/Horde/Imap/Client/Socket.php:1958
11. Horde_Imap_Client_Socket->_sendCmdChunk() 
/usr/share/php5/PEAR/Horde/Imap/Client/Socket.php:3863
12. Horde_Imap_Client_Socket->_getLine() 
/usr/share/php5/PEAR/Horde/Imap/Client/Socket.php:3933
13. Horde_Imap_Client_Socket->_serverResponse() 
/usr/share/php5/PEAR/Horde/Imap/Client/Socket.php:4145
14. Horde_Imap_Client_Socket->_deleteMsgs() 
/usr/share/php5/PEAR/Horde/Imap/Client/Socket.php:4334
15. Horde_Imap_Client_Base->_deleteMsgs() 
/usr/share/php5/PEAR/Horde/Imap/Client/Socket.php:3810
16. Horde_Imap_Client_Cache->deleteMsgs() 
/usr/share/php5/PEAR/Horde/Imap/Client/Base.php:3940
17. Horde_Imap_Client_Cache_Backend_Cache->deleteMsgs() 
/usr/share/php5/PEAR/Horde/Imap/Client/Cache.php:218
18. Horde::debug() 
/usr/share/php5/PEAR/Horde/Imap/Client/Cache/Backend/Cache.php:278

11/18/2013 10:44:23 PM Michael Slusarz Comment #7 Reply to this comment
Michael, would it help if I add some debugging code to one of the 
modules to help gather some information that would be useful?  If 
so, please let me know what module and what to add and I will gladly 
send you the results.
Line 276 of Horde_Imap_Client_Cache_Backend_Cache:

if (!is_array($slicemap['s'])) {
Horde::debug($this->_slicemap);
}

Horde::debug() documentation: http://wiki.horde.org/Doc/Dev/DebugH4
11/14/2013 09:28:45 PM aria (at) bsc (dot) gwu (dot) edu Comment #6 Reply to this comment
I've tested using the Horde_Cache driver - and made sure I deleted 
more messages than fit into a single slice.  I still can't reproduce 
this error.
Michael, would it help if I add some debugging code to one of the 
modules to help gather some information that would be useful?  If so, 
please let me know what module and what to add and I will gladly send 
you the results.
11/14/2013 09:17:15 PM Michael Slusarz Comment #5 Reply to this comment
I've tested using the Horde_Cache driver - and made sure I deleted 
more messages than fit into a single slice.  I still can't reproduce 
this error.
11/11/2013 05:34:57 PM Michael Slusarz Comment #4
State ⇒ Feedback
Reply to this comment
From the previous ticket:

"So what is argument #1 to array_intersect_keys()?"

"There is no way I can see that slicemap['s'] can be anything but an
array. "
11/11/2013 01:53:53 PM cyx (at) gmx (dot) at Comment #3 Reply to this comment
I see the same error on my machine:
[imp] PHP ERROR: array_intersect_key(): Argument #1 is not an array 
[pid 83445 on line 276 of 
"/usr/local/share/pear/Horde/Imap/Client/Cache/Backend/Cache.php"]

11/08/2013 03:38:04 PM aria (at) bsc (dot) gwu (dot) edu Comment #2 Reply to this comment
Forgot to mention that I have purged the client side cache and the 
server side cache as well.  I have seen this message in the latest GA 
release for Horde/IMP and in previous releases over the past few months.
11/08/2013 03:22:40 PM aria (at) bsc (dot) gwu (dot) edu Comment #1
Priority ⇒ 1. Low
State ⇒ Unconfirmed
Patch ⇒ No
Milestone ⇒
Summary ⇒ PHP ERROR: array_intersect_key() when purging deleted items
Type ⇒ Bug
Queue ⇒ IMP
Reply to this comment
Hi,

When I click purge deleted in a mailbox using any of the IMP 
interfaces, I get the following error message in the horde.log file:

WARN: HORDE [imp] PHP ERROR: array_intersect_key(): Argument #1 is not 
an array [pid 7485 on line 276 of 
"/usr/share/php5/PEAR/Horde/Imap/Client/Cache/Backend/Cache.php"]

I do NOT get the message if I just delete a message.  I do not use a 
trash mailbox.  Deleted messages remain in the mailbox and are just 
marked as deleted until purged.

This is similar to the dev discussion here:   
http://lists.horde.org/archives/dev/Week-of-Mon-20090413/023933.html

and a closed ticket here:  http://bugs.horde.org/ticket/12593

Please let me know how I can provide additional information to assist.
Thanks,
Aria

Saved Queries