Bug 339393

Summary:	Akonadi fail to fetch IMAP folder content with over 100MiB of messages (akonadi try to fetch too many UIDs at once)
Product:	[Frameworks and Libraries] Akonadi	Reporter:	boris.sh.1983+kde.bugzilla
Component:	IMAP resource	Assignee:	Christian Mollekopf <chrigi_1>
Status:	RESOLVED FIXED
Severity:	major	CC:	adeptsmail, franzschrober, kdepim-bugs, martin.steigerwald, Martin, mollekopf, vkrause, woebbeking
Priority:	NOR
Version:	1.13.0
Target Milestone:	---
Platform:	Debian unstable
OS:	Linux
Latest Commit:		Version Fixed In:
Sentry Crash Report:
Attachments:	Instead of fetching everything in every attempt try to work with 2K intervals Split large UID Search commands to multiple smaller ones in batchfetcher

Description boris.sh.1983+kde.bugzilla 2014-09-25 18:46:30 UTC

Dear Maintainer,

I upgraded to kdepim 4.14-1 from 4.13 (debian unstable) and added a new IMAP account, trying to sync INBOX resolted in zero messages in the folder. during the time of the sync a popup with "synching folder inbox" is presented that go to 100%.

INBOX folder size ~4.5GiB , ~10K unread emails 

When I created a smaller folder on the IMAP server bellow 100MiB (10MiB
akonadi was able to sync and fetch the content).

I was able to sync smaller folders.

IMAP server Exchange 2007

IMAP logs when clicking on "update folder" (for INBOX):

==> imap.log.2116.1 <==
S: * 28592 EXISTS
S: * 0 RECENT
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2385  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62022  ]
S: * OK The next unique identifier value [ UIDNEXT 42677  ]
S: A000008 OK SELECT completed. [ READ-WRITE  ]
C: A000009 IDLE
S: + IDLE accepted, awaiting DONE command.

==> imap.log.2116.2 <==
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2385  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62022  ]
S: * OK The next unique identifier value [ UIDNEXT 42677  ]
S: A000012 OK SELECT completed. [ READ-WRITE  ]
C: A000013 UID SEARCH UID 1:42677
S: A000013 NO Server Unavailable. 15
S: * BYE Connection closed. 14
X

==> imap.log.2116.3 <==
C: A000004 SELECT "INBOX"
S: * 28592 EXISTS
S: * 0 RECENT
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2385  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62022  ]
S: * OK The next unique identifier value [ UIDNEXT 42677  ]
S: A000004 OK SELECT completed. [ READ-WRITE  ]
C: A000005 EXPUNGE
S: A000005 OK EXPUNGE completed.
C: A000006 SELECT "INBOX"
S: * 28592 EXISTS
S: * 0 RECENT
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2385  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62022  ]
S: * OK The next unique identifier value [ UIDNEXT 42677  ]
S: A000006 OK SELECT completed. [ READ-WRITE  ]
C: A000007 UID SEARCH UID 1:42677
S: A000007 NO Server Unavailable. 15
C: A000008 EXPUNGE
S: A000008 OK EXPUNGE completed.
C: A000009 SELECT "INBOX"
S: * 28592 EXISTS
S: * 0 RECENT
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2385  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62022  ]
S: * OK The next unique identifier value [ UIDNEXT 42677  ]
S: A000009 OK SELECT completed. [ READ-WRITE  ]
C: A000010 UID SEARCH UID 1:42677
S: A000010 NO Server Unavailable. 15

IMAP log for being able to fetch emails :

S: A000004 OK LIST completed.
C: A000005 LSUB "" *
S: * LSUB ( ) / Arch
S: * LSUB ( ) / Archives/2011
S: * LSUB ( ) / INBOX
S: * LSUB ( ) / Sent Items
S: * LSUB ( ) / TEST
S: A000005 OK LSUB completed.
C: A000006 SUBSCRIBE "Junk E-Mail"
S: A000006 OK SUBSCRIBE completed.

C: A000004 SELECT "Junk E-Mail"
S: * 1065 EXISTS
S: * 5 RECENT
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62042  ]
S: * OK The next unique identifier value [ UIDNEXT 2911  ]
S: A000004 OK SELECT completed. [ READ-WRITE  ]
C: A000005 EXPUNGE
S: A000005 OK EXPUNGE completed.
C: A000006 SELECT "Junk E-Mail"
S: * 1065 EXISTS
S: * 0 RECENT
S: * FLAGS ( \Seen \Answered \Flagged \Deleted \Draft $MDNSent )
S: * OK Permanent flags [ PERMANENTFLAGS ( \Seen \Answered \Flagged
\Deleted \Draft $MDNSent )  ]
S: * OK Is the first unseen message [ UNSEEN 2  ]
S: * OK UIDVALIDITY value [ UIDVALIDITY 62042  ]
S: * OK The next unique identifier value [ UIDNEXT 2911  ]
S: A000006 OK SELECT completed. [ READ-WRITE  ]
C: A000007 UID SEARCH UID 1:2911
S: * SEARCH 1036 1037 1038 1039 1040 1041 1042 1043 1044 1045 1046 1047
1048 1049 1050 1051 1052 1053 1054 1055 1056 1057 1058 1059 1060 1061
1062 1063 1064 1065 1066 1067 1068 1069 1070 1071 1072 1073 1074 1075
1076 1077 1078 1079 1080 1081 1082 1083 1084 1085 1086 1087 1088 1089
1090 1091 1092 1093 1094 1095 1096 1097 1098 1099 1100 1101 1102 1103
1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117
1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129 1130 1131
1132 1133 1134 1135 1136 1137 1138 1139 1140 1141 1142 1143 1144 1145
1146 1147 1148 1149 1150 1151 1152 1153 1154 1155 1156 1157 1158 1159
1160 1161 1162 1163 1164 1165 1166 1167 1168 1169 1170 1171 1172 1173
1174 1175 1176 1177 1178 1179 1180 1181 1182 1183 1184 1185 1186 1187
1188 1189 1190 1191 1192 1193 1194 1195 1196 1197 1198 1199 1200 1201
1202 1203 1204 1205 1206 1207 1208 1209 1210 1211 1212 1213 1214 1215
1216 1217 1218 1219 1220 1221 1222 1223 1224 1225 1226 1227 1228 1229
1230 1231 1232 1233 1234 1235 1236 1237 1238 1239 1240 1241 1242 1243
1244 1245 1246 1247 1248 1249 1250 1251 1252 1253 1254 1255 1256 1257
1258 1259 1260 1261 1262 1263 1264 1265 1266 1267 1268 1269 1270 1271
1272 1273 1274 1275 1276 1277 1278 1279 1280 1281 1282 1283 1284 1285
1286 1287 1288 1289 1290 1291 1292 1293 1294 1295 1296 1297 1298 1299
1300 1301 1302 1303 1304 1305 1306 1307 1308 1309 1310 1311 1312 1313
1314 1315 1316 1317 1318 1319 1320 1321 1322 1323 1324 1325 1326 1327
1328 1329 1330 1331 1332 1333 1334 1335 1336 1337 1338 1339 1341 1343
1345 1347 1349 1351 1353 1355 1357 1359 1361 1363 1365 1367 1369 1373
1375 1377 1379 1381 1383 1387 1389 1391 1393 1397 1401 1403 1405 1407
1409 1411 1413 1415 1417 1419 1421 1423 1425 1427 1429 1431 1433 1435
1437 1439 1441 1443 1445 1447 1449 1451 1453 1455 1457 1459 1461 1463
1465 1467 1469 1471 1473 1475 1477 1479 1481 1483 1485 1487 1489 1491
1493 1495 1497 1499 1501 1503 1505 1507 1509 1511 1513 1515 1517 1519
1521 1523 1525 1527 1529 1531 1533 1535 1537 1539 1541 1543 1545 1547
1549 1551 1553 1555 1557 1561 1563 1565 1567 1569 1571 1573 1575 1577
1581 1585 1587 1589 1591 1593 1595 1597 1599 1601 1603 1605 1607 1609
1611 1613 1615 1617 1621 1623 1625 1627 1629 1631 1633 1635 1637 1639
1641 1643 1645 1647 1649 1653 1655 1657 1659 1661 1663 1665 1667 1669
1671 1673 1675 1677 1679 1681 1683 1685 1687 1689 1691 1693 1695 1697
1699 1701 1703 1705 1707 1709 1711 1713 1715 1717 1719 1721 1723 1725
1727 1729 1731 1733 1735 1737 1739 1741 1743 1745 1747 1749 1751 1753
1755 1757 1759 1761 1763 1765 1767 1769 1771 1773 1775 1777 1779 1781
1783 1785 1787 1789 1791 1793 1795 1797 1799 1801 1803 1805 1807 1809
1811 1813 1815 1817 1819 1821 1823 1825 1827 1829 1831 1833 1835 1837
1839 1841 1843 1845 1847 1849 1851 1853 1855 1857 1859 1861 1863 1865
1867 1869 1871 1873 1875 1877 1879 1881 1883 1885 1887 1889 1891 1893
1895 1897 1899 1901 1903 1905 1907 1909 1911 1913 1915 1917 1919 1921
1923 1925 1927 1929 1931 1933 1935 1937 1939 1941 1943 1945 1947 1949
1951 1953 1955 1957 1959 1961 1963 1965 1967 1969 1971 1973 1975 1977
1979 1981 1983 1984 1985 1986 1987 1989 1991 1993 1995 1997 1999 2001
2003 2005 2007 2009 2011 2013 2015 2017 2019 2021 2023 2025 2027 2029
2031 2033 2035 2037 2039 2041 2043 2045 2047 2049 2051 2053 2055 2057
2059 2061 2063 2065 2067 2069 2071 2073 2075 2077 2079 2081 2083 2085
2087 2089 2091 2093 2095 2097 2099 2101 2103 2105 2107 2109 2111 2113
2115 2117 2119 2121 2123 2125 2127 2129 2131 2133 2135 2137 2139 2141
2143 2145 2147 2149 2151 2153 2155 2157 2159 2161 2163 2165 2167 2169
2171 2173 2175 2177 2179 2181 2183 2185 2187 2189 2191 2193 2195 2197
2199 2201 2203 2205 2207 2209 2211 2213 2215 2217 2219 2221 2223 2225
2227 2229 2231 2233 2235 2237 2239 2241 2243 2245 2247 2249 2251 2253
2255 2257 2259 2261 2263 2265 2267 2269 2271 2273 2275 2277 2279 2281
2283 2285 2287 2289 2291 2293 2295 2297 2299 2301 2303 2305 2307 2309
2311 2313 2315 2317 2319 2321 2323 2325 2327 2329 2331 2333 2335 2337
2339 2340 2342 2344 2346 2348 2350 2352 2354 2356 2358 2360 2362 2364
2366 2368 2370 2372 2374 2376 2378 2380 2382 2384 2386 2388 2390 2392
2394 2396 2398 2400 2402 2404 2406 2408 2410 2412 2414 2416 2418 2420
2422 2424 2426 2428 2430 2432 2434 2436 2438 2440 2442 2444 2446 2448
2450 2452 2454 2456 2458 2460 2462 2464 2466 2468 2470 2472 2474 2476
2478 2480 2482 2484 2486 2488 2490 2492 2494 2496 2498 2500 2502 2504
2506 2508 2510 2512 2514 2516 2518 2520 2522 2524 2526 2528 2530 2532
2534 2536 2538 2540 2542 2544 2546 2548 2550 2552 2554 2556 2558 2560
2562 2564 2566 2568 2570 2572 2574 2576 2578 2580 2582 2584 2586 2588
2590 2592 2594 2596 2598 2600 2602 2604 2606 2608 2610 2612 2614 2616
2618 2620 2622 2624 2626 2628 2630 2632 2634 2636 2638 2640 2642 2644
2646 2648 2650 2652 2654 2656 2658 2660 2662 2664 2666 2668 2670 2672
2674 2676 2678 2680 2682 2684 2686 2688 2690 2692 2694 2696 2698 2700
2702 2704 2706 2708 2710 2712 2714 2716 2718 2720 2722 2724 2726 2728
2730 2732 2734 2736 2738 2740 2742 2744 2746 2748 2750 2752 2754 2756
2758 2760 2762 2764 2766 2768 2770 2772 2776 2778 2780 2782 2784 2786
2792 2794 2796 2798 2804 2806 2808 2810 2818 2820 2822 2824 2826 2828
2830 2832 2834 2838 2842 2846 2850 2852 2856 2860 2862 2864 2866 2868
2870 2872 2874 2876 2878 2880 2882 2884 2886 2888 2894 2896 2902 2904
2906 2908 2910
S: A000007 OK SEARCH completed.
C: A000008 UID FETCH 1036:1135 (RFC822.SIZE INTERNALDATE BODY.PEEK[]
FLAGS UID)

This bug may or may not be related to debian bug 761045 

-- System Information:
Debian Release: jessie/sid
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 3.9-1-amd64 (SMP w/2 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages kdepim-runtime depends on:
ii  akonadi-server                1.13.0-2
ii  kde-runtime                   4:4.14.0-2
ii  kdepimlibs-kio-plugins        4:4.14.1-1
ii  libakonadi-calendar4          4:4.14.1-1
ii  libakonadi-contact4           4:4.14.1-1
ii  libakonadi-kabc4              4:4.14.1-1
ii  libakonadi-kcal4              4:4.14.1-1
ii  libakonadi-kde4               4:4.14.1-1
ii  libakonadi-kmime4             4:4.14.1-1
ii  libakonadi-notes4             4:4.14.1-1
ii  libakonadiprotocolinternals1  1.13.0-2
ii  libc6                         2.19-11
ii  libgcc1                       1:4.9.1-14
ii  libkabc4                      4:4.14.1-1
ii  libkalarmcal2                 4:4.14.1-1
ii  libkcal4                      4:4.14.1-1
ii  libkcalcore4                  4:4.14.1-1
ii  libkcalutils4                 4:4.14.1-1
ii  libkcmutils4                  4:4.14.1-1
ii  libkdecore5                   4:4.14.1-1
ii  libkdeui5                     4:4.14.1-1
ii  libkgapi2-2                   2.2.0-1
ii  libkimap4                     4:4.14.1-1
ii  libkio5                       4:4.14.1-1
ii  libkmbox4                     4:4.14.1-1
ii  libkmime4                     4:4.14.1-1
ii  libknewstuff3-4               4:4.14.1-1
ii  libknotifyconfig4             4:4.14.1-1
ii  libkolab0                     0.5.3-1
ii  libkpimidentities4            4:4.14.1-1
ii  libkpimtextedit4              4:4.14.1-1
ii  libkpimutils4                 4:4.14.1-1
ii  libkresources4                4:4.14.1-1
ii  libkrosscore4                 4:4.14.1-1
ii  libmailtransport4             4:4.14.1-1
ii  libmicroblog4                 4:4.14.1-1
ii  libqjson0                     0.8.1-3
ii  libqt4-dbus                   4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqt4-declarative            4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqt4-network                4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqt4-script                 4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqt4-xml                    4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqt4-xmlpatterns            4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqtcore4                    4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libqtgui4                     4:4.8.6+git64-g5dc8b2b+dfsg-2
ii  libsolid4                     4:4.14.1-1
ii  libstdc++6                    4.9.1-14

Reproducible: Always

Steps to Reproduce:
1. Upgrade from kdepim 4.13 to 4.14-1
2. Add new imap resource to an exchange 2007 account
3. Sync a folder with over 100mb , in my case ~4.5GiB that is spent over 42677 diffrent messages

Actual Results:  
Empty folder

Expected Results:  
All messages in folder need to be downloaded and appear in the synced folder.

Comment 1 boris.sh.1983+kde.bugzilla 2014-10-11 22:22:04 UTC

Created attachment 89092 [details]
Instead of fetching everything in every attempt try to work with 2K intervals

I don't understand why the it does not work with Batchfetcher, but this dirty workaround allowed me to fetch (slowly) the data.

Comment 2 boris.sh.1983+kde.bugzilla 2014-10-12 09:26:42 UTC

After additional review , Please ignore  0001-use-2K-in-every-attempt-to-use-retrieve-items.patch and do not apply this

Comment 3 boris.sh.1983+kde.bugzilla 2014-10-13 08:34:44 UTC

Created attachment 89107 [details]
Split large UID Search commands to multiple smaller ones in batchfetcher

Split SearchJob inside batchfetcher if amount of messages is above a threshold (2K).

Comment 4 Andre Woebbeking 2014-10-13 20:31:08 UTC

Hi Boris,

thanks for your fix but it doesn't work for me. Only some mails of the folder are synced. I wondered about a too low unread count and if you (re)create an IMAP account the folders also only contains some mails.

This is probably caused as you simply start n SearchJobs and call onUidSearchDone() n times instead of collecting all results and then call onUidSearchDone() only once.


Cheers,
André

Comment 5 Andre Woebbeking 2014-10-18 17:44:51 UTC

Hi, at https://git.reviewboard.kde.org/r/120644/ you find a new patch for 4.14 based on Boris' one. Please test it.

Comment 6 boris.sh.1983+kde.bugzilla 2014-10-20 19:25:32 UTC

Hi Andre, 

thanks for your fix but it doesn't work for me, 
Only a small portion of the emails had been downloaded (<800), and then the sync drops along with a parser exception. 

I suspect that I get a variant of 338967.

Traces : 

SearchManager::registerInstance( "akonadi_imap_resource_20" ) 
Registering search instance  "akonadi_imap_resource_20" 
 list is empty 
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_mailfilter_agent_11668_akKvoX" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_mailfilter_agent_11668_akKvoX" true false 
Database "akonadi" opened using driver "QMYSQL" 
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_archivemail_agent_11660_LnpgTG" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_archivemail_agent_11660_LnpgTG" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_mailfilter_agent_11668_dq9if3" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_mailfilter_agent_11668_dq9if3" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_archivemail_agent_11660_NGtPSO" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_archivemail_agent_11660_NGtPSO" true false 
.
.
.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x1612d90)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_mailfilter_agent_11668_sgrR5V" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_mailfilter_agent_11668_sgrR5V" true false 
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x1612d90)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
.
.
.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
.
.
.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x1612d90)
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_B9OzyL" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_B9OzyL" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_fjn7xb" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_fjn7xb" true false 
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_uxYeH2" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_uxYeH2" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_LG85jc" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_LG85jc" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_qzFFSK" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_qzFFSK" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_TbRpaQ" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_TbRpaQ" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_u59tgu" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_u59tgu" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_TCf9Sm" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11752_TCf9Sm" true false 
Database "akonadi" opened using driver "QMYSQL" 

Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_8lAMgy" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_8lAMgy" true false 
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_RUNGgq" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_RUNGgq" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_iJpHqu" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_iJpHqu" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_0ZaAsY" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_0ZaAsY" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_LQYlXh" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_LQYlXh" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_GfSP16" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_GfSP16" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_LRaghF" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_LRaghF" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_WPWJgM" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "kontact_11766_WPWJgM" true false 
.
.
.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x1607190)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x1607190)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::startRetrievalTasks: Starting retrieval for  "INBOX"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x1607190)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: Starting message retrieval. Elapsed(ms):  1842
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: MessageCount:  26103 Local message count:  0
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: UidNext:  43273 Local UidNext:  0
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: HighestModSeq:  0 Local HighestModSeq:  0
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: Fetching complete mailbox  "INBOX"
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_WPWJgM" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_LRaghF" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_GfSP16" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_LQYlXh" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_0ZaAsY" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_iJpHqu" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_RUNGgq" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "kontact_11766_8lAMgy" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_TCf9Sm" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_u59tgu" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_TbRpaQ" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_qzFFSK" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_LG85jc" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_uxYeH2" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_fjn7xb" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11752_B9OzyL" now serving: () 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_vdqiCR" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_vdqiCR" true false 
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_KIwwe5" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_KIwwe5" true false 
Database "akonadi" opened using driver "QMYSQL" 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_9OTmNc" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_9OTmNc" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_HizrfC" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_HizrfC" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_eYk8ta" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_eYk8ta" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_4mDuVP" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_4mDuVP" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_1tT46D" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_1tT46D" true false 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_xzk3ws" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadiconsole_11793_xzk3ws" true false 
Database "akonadi" opened using driver "QMYSQL" 
 list is empty 

void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_xzk3ws" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_1tT46D" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_4mDuVP" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_eYk8ta" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_HizrfC" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_9OTmNc" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_KIwwe5" now serving: () 
void Akonadi::Server::NotificationSource::serviceUnregistered(const QString&) Notification source "akonadiconsole_11793_vdqiCR" now serving: () 
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) ImapIdleManager::onIdleStopped: IDLE dropped maybe we should reconnect?
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x1612cb0)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x1612cb0)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x1612cb0)
.
.
.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionPrivate::onSocketTimeout: Socket timeout!
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666) BatchFetcher::onUidSearchDone: Search job failed:  "Connection to server lost." 
akonadi_imap_resource_20(11666) RetrieveItemsTask::onRetrievalDone: "" 
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x155b500)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x155b500)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveCollectionMetadataTask::doStart: "/INBOX"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x155b500)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::startRetrievalTasks: Starting retrieval for  "INBOX"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: Starting message retrieval. Elapsed(ms):  1879
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: MessageCount:  26103 Local message count:  0
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: UidNext:  43273 Local UidNext:  0
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: HighestModSeq:  0 Local HighestModSeq:  0
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveItemsTask::onFinalSelectDone: Fetching complete mailbox  "INBOX"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) ImapIdleManager::onIdleStopped: IDLE dropped maybe we should reconnect?
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x1552060)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x1552060)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x1552060)

akonadi_imap_resource_20(11666)/kdepimlibs (kimap) BatchFetcher::fetchNextBatch: Fetching  44  intervals
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) BatchFetcher::fetchNextBatch: Fetching  28  intervals
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV2(const QString&, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_newmailnotifier_agent_11671_XKMNfG" true 
QDBusObjectPath Akonadi::Server::NotificationManager::subscribeV3(const QString&, bool, bool) Akonadi::Server::NotificationManager(0x23c6410) "akonadi_newmailnotifier_agent_11671_XKMNfG" true false 
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) BatchFetcher::fetchNextBatch: Fetching  16  intervals
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) ImapIdleManager::onIdleStopped: IDLE dropped maybe we should reconnect?
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x163f480)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x163f480)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x163f480)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) BatchFetcher::fetchNextBatch: Fetching  36  intervals
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionPrivate::onSocketTimeout: Socket timeout!
The stream parser raised an exception: Unable to read more data 
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666) BatchFetcher::onHeadersFetchDone: Fetch job failed  "Connection to server lost." 
akonadi_imap_resource_20(11666) RetrieveItemsTask::onRetrievalDone: "" 
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::LoginJob: KIMAP::LoginJob(0x20816e0)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::reconnect: connectToHost "exchange2007.domain.tld" 143
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::doStart: KIMAP::LoginJob(0x20816e0)
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "StartTls" "A000001"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::sslConnected: TLS negotiation done.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "*"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: Capabilities updated:  ("IMAP4", "IMAP4rev1", "AUTH=NTLM", "AUTH=GSSAPI", "AUTH=PLAIN", "IDLE", "NAMESPACE", "LITERAL+")
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Capability" "A000002"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "+"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::handleResponse: "Login" "A000003"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) RetrieveCollectionMetadataTask::doStart: "/INBOX"
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::LoginJob::~LoginJob: KIMAP::LoginJob(0x20816e0)
.
.
.
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) KIMAP::SessionThread::doCloseSocket: close
akonadi_imap_resource_20(11666)/kdepimlibs (kimap) ImapIdleManager::onIdleStopped: IDLE dropped maybe we should reconnect?

Comment 7 Andre Woebbeking 2014-10-21 05:33:04 UTC

Boris, thanks for testing. Two things:
1) in BatchFetcher::setSearchUids() I only activate the splitted SearchJobs if serverGreeting().contains("Microsoft Exchange"). Maybe your server has another text.
2) I wonder about RetrieveItemsTask::onFinalSelectDone: UidNext:  43273 Local UidNext:  0. E. g. I've UidNext:  41364 Local UidNext:  41364. AFAIK the 0 results in a SearchJob UID 1:0 which cannot be splittet.

Comment 8 boris.sh.1983+kde.bugzilla 2014-10-21 08:05:16 UTC

Hi Andre, 

Your patch does solve the problem of Exchange choking on large UID search, however the inital bug of unable to sync over 100 Mib folder is not solved yet.

It does split the search job as expected, yet when exchange disconnects the session we do not continue from the last fetched uid.

After the next akonadi restart, retrieveitemstask will trigger refetching of the dir and and not from the last uid in the collection.

Comment 9 Andre Woebbeking 2014-10-30 19:46:59 UTC

Git commit 94b64eebb6a88846b221aad810045fecb4173f79 by Andre Woebbeking.
Committed on 30/10/2014 at 19:46.
Pushed by woebbe into branch 'KDE/4.14'.

Make BatchFetcher workaround MS Exchange "bugs"

If the result of UID SEARCH is too big Exchange just disconnects. To work around
this the UID SEARCH is splitted into smaller chunks (I choose 2000 arbitrarily).

First I wanted to do this for all servers but I've a server where UIDs go up to
1 billion which results in half a million SearchJobs. So I do the splitting only
for Exchange servers. I don't know if there is a better way to recognize Exchange
servers than to look at Session::serverGreeting()?

There are still issues with Exchange but at least for me it's usable again.
REVIEW: 120644

M  +31   -9    resources/imap/batchfetcher.cpp
M  +3    -2    resources/imap/batchfetcher.h
M  +2    -2    resources/imap/retrieveitemstask.cpp

http://commits.kde.org/kdepim-runtime/94b64eebb6a88846b221aad810045fecb4173f79

Comment 10 Martin Steigerwald 2015-01-21 12:41:45 UTC

Andre, may this help with:

Bug 343114 - gets stuck on one request that times out, kmail and akonadiconsole do not display any mail payloads anymore, stuck waiting

?

I get this several times a day with an Exchange account and need to restart at least KMail, sometimes also Akonadi to get it to work again. I have KMail 4.14.2 debian package installed, but am using latest Akonadi 1.13 git with MySQL optimizations. I may complete a more recent KMail 4.14.4 and kdepim-runtime 4.14.4 if need be.

Comment 11 Andre Woebbeking 2015-01-21 16:48:50 UTC

I don't know. I had no timeout but a "Server Unavailable. 15" error when Exchange disconnected.

For the fix you only need the imap resource (from kdepim-runtime).

But at work I'm running KDE 4.14.2 with kdepim-runtime 4.13.x now. This works surprisingly well :-)