[horde] AS Mailbox not pushing new email

Simon Wilson simon at simonandkate.net
Sat Mar 2 02:49:05 UTC 2013

Previous message: [horde] AS email not current
Next message: [horde] AS Mailbox not pushing new email
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

AS 2.3.0

I had a meeting invitation sent to me, and it appeared in my Imp mailbox at
11:49:23am.

My iOS devices are set to read Horde email over ActiveSync, and are set to
server push.

$conf[activesync][ping][heartbeatmax] is set to standard 2700, so at over
2700 seconds worst-case scenarion it should have pushed, right?

It is now 3060 seconds later, and the push has not happened. Device has
been sync'ing as follows:

2013-03-02T02:38:26+00:00 INFO: [6586]  
Horde_Core_ActiveSync_Driver::authenticate() attempt for simon
2013-03-02T02:38:26+00:00 DEBUG: [6586] PING request received for user simon
2013-03-02T02:38:26+00:00 DEBUG: [Appl79030T3BA4S] loadDeviceInfo: simon
2013-03-02T02:38:26+00:00 INFO: Request being handled for device:  
Appl79030T3BA4S Supporting protocol version: 12.1
2013-03-02T02:38:26+00:00 INFO: [6586] Handling PING command received  
at timestamp: 1362191906.
2013-03-02T02:38:26+00:00 DEBUG: Reusing PING state: Array
(
     [@Contacts@] => Array
         (
             [class] => Contacts
             [windowsize] => 25
             [deletesasmoves] =>
             [filtertype] =>
             [truncation] => 0
             [rtftruncation] =>
             [mimesupport] => 0
             [mimetruncation] =>
             [conflict] => 1
             [bodyprefs] => Array
                 (
                     [wanted] => 1
                     [1] => Array
                         (
                             [type] => 1
                             [truncationsize] => 32768
                         )

                 )

             [lastsynckey] => {5125e673-2ae8-4495-abe1-25bcc0a801e6}16
             [pingable] => 1
             [id] => @Contacts@
             [synckey] => {5125e673-2ae8-4495-abe1-25bcc0a801e6}16
         )

     [@Tasks@] => Array
         (
             [class] => Tasks
             [windowsize] => 25
             [deletesasmoves] =>
             [filtertype] =>
             [truncation] => 0
             [rtftruncation] =>
             [mimesupport] =>
             [mimetruncation] =>
             [conflict] => 1
             [bodyprefs] => Array
                 (
                     [wanted] => 1
                     [1] => Array
                         (
                             [type] => 1
                             [truncationsize] => 32768
                         )

                 )

             [lastsynckey] => {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
             [id] => @Tasks@
             [pingable] => 1
             [synckey] => {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
         )

     [@Calendar@] => Array
         (
             [class] => Calendar
             [windowsize] => 25
             [deletesasmoves] =>
             [filtertype] => 4
             [truncation] => 0
             [rtftruncation] =>
             [mimesupport] =>
             [mimetruncation] =>
             [conflict] => 1
             [bodyprefs] => Array
                 (
                     [wanted] => 1
                     [1] => Array
                         (
                             [type] => 1
                             [truncationsize] => 32768
                         )

                 )

             [lastsynckey] => {5125e694-0130-4f7f-8c10-25bfc0a801e6}34
             [pingable] => 1
             [id] => @Calendar@
             [synckey] => {5125e694-0130-4f7f-8c10-25bfc0a801e6}34
         )

)

2013-03-02T02:38:26+00:00 DEBUG: [6586] Waiting for changes (heartbeat  
interval: 900)
2013-03-02T02:38:26+00:00 DEBUG: [6586] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T02:38:26+00:00 DEBUG: [6586] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T02:38:26+00:00 DEBUG: [6586] Initializing message diff  
engine for @Contacts@
2013-03-02T02:38:26+00:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191906, 0, 1)
2013-03-02T02:38:26+00:00 DEBUG: [6586] Found 0 message changes in @Contacts at .
2013-03-02T02:38:26+00:00 DEBUG: [6586] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T02:38:26+00:00 DEBUG: [6586] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T02:38:26+00:00 DEBUG: [6586] Initializing message diff  
engine for @Tasks@
2013-03-02T02:38:26+00:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191906, 0, 1)
2013-03-02T12:38:26+10:00 DEBUG: [6586] Found 0 message changes in @Tasks at .
2013-03-02T12:38:26+10:00 DEBUG: [6586] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:38:26+10:00 DEBUG: [6586] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:38:26+10:00 DEBUG: [6586] Initializing message diff  
engine for @Calendar@
2013-03-02T12:38:26+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191906, 1360982306, 1)
2013-03-02T12:38:26+10:00 DEBUG: [6586] Found 0 message changes in @Calendar at .
2013-03-02T12:38:53+10:00 DEBUG: [6589] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:38:53+10:00 DEBUG: [6589] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:38:53+10:00 DEBUG: [6589] Initializing message diff  
engine for @Contacts@
2013-03-02T12:38:53+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191933, 0, 1)
2013-03-02T12:38:53+10:00 DEBUG: [6589] Found 0 message changes in @Contacts at .
2013-03-02T12:38:53+10:00 DEBUG: [6589] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:38:53+10:00 DEBUG: [6589] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:38:53+10:00 DEBUG: [6589] Initializing message diff  
engine for @Tasks@
2013-03-02T12:38:53+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191933, 0, 1)
2013-03-02T12:38:53+10:00 DEBUG: [6589] Found 0 message changes in @Tasks at .
2013-03-02T12:38:53+10:00 DEBUG: [6589] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:38:53+10:00 DEBUG: [6589] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:38:53+10:00 DEBUG: [6589] Initializing message diff  
engine for @Calendar@
2013-03-02T12:38:53+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191933, 1360982333, 1)
2013-03-02T12:38:53+10:00 DEBUG: [6589] Found 0 message changes in @Calendar at .
2013-03-02T12:38:56+10:00 DEBUG: [6586] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:38:56+10:00 DEBUG: [6586] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:38:56+10:00 DEBUG: [6586] Initializing message diff  
engine for @Contacts@
2013-03-02T12:38:56+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191936, 0, 1)
2013-03-02T12:38:57+10:00 DEBUG: [6586] Found 0 message changes in @Contacts at .
2013-03-02T12:38:57+10:00 DEBUG: [6586] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:38:57+10:00 DEBUG: [6586] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:38:57+10:00 DEBUG: [6586] Initializing message diff  
engine for @Tasks@
2013-03-02T12:38:57+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191937, 0, 1)
2013-03-02T12:38:57+10:00 DEBUG: [6586] Found 0 message changes in @Tasks at .
2013-03-02T12:38:57+10:00 DEBUG: [6586] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:38:57+10:00 DEBUG: [6586] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:38:57+10:00 DEBUG: [6586] Initializing message diff  
engine for @Calendar@
2013-03-02T12:38:57+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191937, 1360982337, 1)
2013-03-02T12:38:57+10:00 DEBUG: [6586] Found 0 message changes in @Calendar at .
2013-03-02T12:39:23+10:00 DEBUG: [6589] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:23+10:00 DEBUG: [6589] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:23+10:00 DEBUG: [6589] Initializing message diff  
engine for @Contacts@
2013-03-02T12:39:23+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191963, 0, 1)
2013-03-02T12:39:23+10:00 DEBUG: [6589] Found 0 message changes in @Contacts at .
2013-03-02T12:39:23+10:00 DEBUG: [6589] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:23+10:00 DEBUG: [6589] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:23+10:00 DEBUG: [6589] Initializing message diff  
engine for @Tasks@
2013-03-02T12:39:23+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191963, 0, 1)
2013-03-02T12:39:23+10:00 DEBUG: [6589] Found 0 message changes in @Tasks at .
2013-03-02T12:39:23+10:00 DEBUG: [6589] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:23+10:00 DEBUG: [6589] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:23+10:00 DEBUG: [6589] Initializing message diff  
engine for @Calendar@
2013-03-02T12:39:23+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191963, 1360982363, 1)
2013-03-02T12:39:23+10:00 DEBUG: [6589] Found 0 message changes in @Calendar at .
2013-03-02T12:39:27+10:00 DEBUG: [6586] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:27+10:00 DEBUG: [6586] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:27+10:00 DEBUG: [6586] Initializing message diff  
engine for @Contacts@
2013-03-02T12:39:27+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191967, 0, 1)
2013-03-02T12:39:27+10:00 DEBUG: [6586] Found 0 message changes in @Contacts at .
2013-03-02T12:39:27+10:00 DEBUG: [6586] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:27+10:00 DEBUG: [6586] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:27+10:00 DEBUG: [6586] Initializing message diff  
engine for @Tasks@
2013-03-02T12:39:27+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191967, 0, 1)
2013-03-02T12:39:27+10:00 DEBUG: [6586] Found 0 message changes in @Tasks at .
2013-03-02T12:39:27+10:00 DEBUG: [6586] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:27+10:00 DEBUG: [6586] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:27+10:00 DEBUG: [6586] Initializing message diff  
engine for @Calendar@
2013-03-02T12:39:27+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191967, 1360982367, 1)
2013-03-02T12:39:27+10:00 DEBUG: [6586] Found 0 message changes in @Calendar at .
2013-03-02T12:39:53+10:00 DEBUG: [6589] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:53+10:00 DEBUG: [6589] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:53+10:00 DEBUG: [6589] Initializing message diff  
engine for @Contacts@
2013-03-02T12:39:53+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191993, 0, 1)
2013-03-02T12:39:53+10:00 DEBUG: [6589] Found 0 message changes in @Contacts at .
2013-03-02T12:39:53+10:00 DEBUG: [6589] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:53+10:00 DEBUG: [6589] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:53+10:00 DEBUG: [6589] Initializing message diff  
engine for @Tasks@
2013-03-02T12:39:53+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191993, 0, 1)
2013-03-02T12:39:53+10:00 DEBUG: [6589] Found 0 message changes in @Tasks at .
2013-03-02T12:39:53+10:00 DEBUG: [6589] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:53+10:00 DEBUG: [6589] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:53+10:00 DEBUG: [6589] Initializing message diff  
engine for @Calendar@
2013-03-02T12:39:53+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191993, 1360982393, 1)
2013-03-02T12:39:53+10:00 DEBUG: [6589] Found 0 message changes in @Calendar at .
2013-03-02T12:39:57+10:00 DEBUG: [6586] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:57+10:00 DEBUG: [6586] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:39:57+10:00 DEBUG: [6586] Initializing message diff  
engine for @Contacts@
2013-03-02T12:39:57+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362191997, 0, 1)
2013-03-02T12:39:57+10:00 DEBUG: [6586] Found 0 message changes in @Contacts at .
2013-03-02T12:39:57+10:00 DEBUG: [6586] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:57+10:00 DEBUG: [6586] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:39:57+10:00 DEBUG: [6586] Initializing message diff  
engine for @Tasks@
2013-03-02T12:39:57+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362191997, 0, 1)
2013-03-02T12:39:57+10:00 DEBUG: [6586] Found 0 message changes in @Tasks at .
2013-03-02T12:39:57+10:00 DEBUG: [6586] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:57+10:00 DEBUG: [6586] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:39:57+10:00 DEBUG: [6586] Initializing message diff  
engine for @Calendar@
2013-03-02T12:39:57+10:00 DEBUG: [6586]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362191997, 1360982397, 1)
2013-03-02T12:39:57+10:00 DEBUG: [6586] Found 0 message changes in @Calendar at .
2013-03-02T12:40:23+10:00 DEBUG: [6589] Initializing state for  
collection: @Contacts@, synckey:  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:40:23+10:00 DEBUG: [6589] Loading state for synckey  
{5125e673-2ae8-4495-abe1-25bcc0a801e6}16
2013-03-02T12:40:23+10:00 DEBUG: [6589] Initializing message diff  
engine for @Contacts@
2013-03-02T12:40:23+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 1361438476,  
1362192023, 0, 1)
2013-03-02T12:40:23+10:00 DEBUG: [6589] Found 0 message changes in @Contacts at .
2013-03-02T12:40:23+10:00 DEBUG: [6589] Initializing state for  
collection: @Tasks@, synckey: {5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:40:23+10:00 DEBUG: [6589] Loading state for synckey  
{5125e69b-fe7c-4f6f-bcab-22bfc0a801e6}4
2013-03-02T12:40:23+10:00 DEBUG: [6589] Initializing message diff  
engine for @Tasks@
2013-03-02T12:40:23+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 1361493185,  
1362192023, 0, 1)
2013-03-02T12:40:23+10:00 DEBUG: [6589] Found 0 message changes in @Tasks at .
2013-03-02T12:40:23+10:00 DEBUG: [6589] Initializing state for  
collection: @Calendar@, synckey:  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:40:23+10:00 DEBUG: [6589] Loading state for synckey  
{5125e694-0130-4f7f-8c10-25bfc0a801e6}34
2013-03-02T12:40:23+10:00 DEBUG: [6589] Initializing message diff  
engine for @Calendar@
2013-03-02T12:40:23+10:00 DEBUG: [6589]  
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 1362186939,  
1362192023, 1360982423, 1)
2013-03-02T12:40:23+10:00 DEBUG: [6589] Found 0 message changes in @Calendar at .

etc...

When I then go into Mail on the iPhone, it then prompts a full HUGE  
sync (the sync file for the next transaction is over 700KB - I will  
send to you directly if needed, but it contains a info I'd rather not  
post publicly).

So, push mail is not working for me, although apart from that I LOVE  
the new improvements to calendaring appointments and invites -  
Brilliant, thank you so much!

Simon



--
Simon Wilson
M: 0400 12 11 16
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 198 bytes
Desc: PGP Digital Signature
URL: <http://lists.horde.org/archives/horde/attachments/20130302/f402df0c/attachment-0001.bin>

Previous message: [horde] AS email not current
Next message: [horde] AS Mailbox not pushing new email
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

More information about the horde mailing list