[horde] AS Mailbox not pushing new email

Michael Rubinsky mrubinsk at horde.org
Sat Mar 2 16:23:31 UTC 2013

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

Quoting Simon Wilson <simon at simonandkate.net>> 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
>
Your device simply is not polling the INBOX. I've seen this happen  
sometime s on iOS. Usually it's from then user manually pressing  
refresh. It takes until the next full PING request to catch up.

mike
Sent from mobile

Simon Wilson <simon at simonandkate.net> wrote:

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

More information about the horde mailing list