Bug 828321

Thanks for a bug report. I tried to reproduce it, but it works fine for me, I do not receive any 'Network error' when selecting GAL after new boot of the machine. I'm wondering whether this can be related to password keyring, to which password I'm asked just after I log in, because the "Network error" can be also caused by incorrect or no password being available.

We can check what it does by creating a script which will log about the factory activity into file, and then search that file content for a reason what failed. I did that by these steps, all done by root:
a) rename /usr/libexec/evolution-addressbook-factory to
          /usr/libexec/evolution-addressbook-factory.orig
b) create a new text file named /usr/libexec/evolution-addressbook-factory
   with this content:
#!/bin/bash
LIBMAPI_DEBUG=15 /usr/libexec/evolution-addressbook-factory.orig &>/tmp/log.txt

c) set script to be executable:
   $ chmod a+x /usr/libexec/evolution-addressbook-factory
d) restart machine and repeat the error

When you see the error then observe the /tmp/log.txt file, which now contains detailed information about data being passed between client and server. Note this contains all private information, from server addresses to passwords, thus it's not good to share here in public. You can either send it directly to me, or search for any "error" string (quotes for clarity only) in the file.

For posterity: Sent the logs, as requested.

Thanks for the logs. I looked at them, made a 'diff' and here is what I see:
    Starting GENSEC submechanism gssapi_krb5
   -Failed to get kerberos credentials: kinit_to_ccache: No password available
    for kinit
   +Failed to get kerberos credentials: kinit for adam.difrischia@SERVER
    failed (Cannot contact any KDC for requested realm)
 
   -Cannot obtain client GSS credentials we need to contact
    exchangeRFR/MAIL.SERVER@ : kinit_to_ccache: No password available for kinit
   +Cannot reach a KDC we require to contact exchangeRFR/MAIL.SERVER@ : kinit
    for adam.difrischia@SERVER failed (Cannot contact any KDC for requested
    realm)
 
   -SPNEGO(gssapi_krb5) creating NEG_TOKEN_INIT failed:
    NT_STATUS_INVALID_PARAMETER
   +SPNEGO(gssapi_krb5) creating NEG_TOKEN_INIT failed:
    NT_STATUS_NO_LOGON_SERVERS

    Starting GENSEC submechanism ntlmssp

   -Got NTLMSSP neg_flags=0x60008235
   +Got NTLMSSP neg_flags=0x60088235
      NTLMSSP_NEGOTIATE_UNICODE
      NTLMSSP_REQUEST_TARGET
      NTLMSSP_NEGOTIATE_SIGN
      NTLMSSP_NEGOTIATE_SEAL
      NTLMSSP_NEGOTIATE_NTLM
      NTLMSSP_NEGOTIATE_ALWAYS_SIGN
   +  NTLMSSP_NEGOTIATE_NTLM2
      NTLMSSP_NEGOTIATE_128
      NTLMSSP_NEGOTIATE_KEY_EXCH
    NTLMSSP Sign/Seal - Initialising with flags:
   -Got NTLMSSP neg_flags=0x60008235
   +Got NTLMSSP neg_flags=0x60088235
      NTLMSSP_NEGOTIATE_UNICODE
      NTLMSSP_REQUEST_TARGET
      NTLMSSP_NEGOTIATE_SIGN
      NTLMSSP_NEGOTIATE_SEAL
      NTLMSSP_NEGOTIATE_NTLM
      NTLMSSP_NEGOTIATE_ALWAYS_SIGN
   +  NTLMSSP_NEGOTIATE_NTLM2
      NTLMSSP_NEGOTIATE_128
      NTLMSSP_NEGOTIATE_KEY_EXCH
   -NTLMSSP Sign/Seal - using NTLM1
   -rpc fault: WERR_ACCESS_DENIED
   -Failed to bind to uuid 1544f5e0-613c-11d1-93df-00c04fd7bd09 for
    1544f5e0-613c-11d1-93df-00c04fd7bd09@ncacn_ip_tcp:mail.server
    [1121,seal,print] NT_STATUS_NET_WRITE_FAULT
   -Failed to connect to remote server: ncacn_ip_tcp:mail.server
    [print,seal,] NT_STATUS_NET_WRITE_FAULT
...
   +ntlmssp_seal_data: seal
   +../librpc/rpc/dcerpc_util.c:140: auth_pad_length 8
   +ntlmssp_unseal_packet: seal
   +ntlmssp_check_packet: NTLMSSP signature OK !

The '-' lines are those from the non-working factory, while '+' lines are from working factory, that manually run (some lines were too long, thus I wrapped them).

There are two interesting parts:
a) the krb5 library response is different
b) the server returns different flags when running factory manually

It seems to me that the factory is run too early, when the machine network connections and/or kerberos authentication isn't initialized properly yet. Are you using kerberos to login to your server, or is this a password-based login? (I do not see what exact method was used in the logs, but the kerberos initialization seems to be involved here).

It definitely looks like the server rejected you (see the -rpc fault: WERR_ACCESS_DENIED). Do you logon on the server when your machine starts?

I would imagine the kerberos initialization is due to the evolution-mapi package connecting to Exchange, however I don't use Kerberos or any network login, it's simple offline local authentication. The only authentication I do at the moment are connecting to our office's Exchange server via Evolution or accessing some SMB shares, but for testing purposes I didn't hit any of the SMB shares.

The kerberos auth makes sense, there was doen a fix in evolution-mapi to disable it if user doesn't have kerberos authentication selected. Unfortunately all the other parts seem to suggest that the server rejected evolution-mapi's attempt to login (with that WERR_ACCESS_DENIED), and it only works after some time, which suggests there is done some post-login operation between your machine and the server in the background. I cannot explain the differences in the logs otherwise.

It doesn't seem to fix itself with time alone. I have to manually run that, or it doesn't work at all.

I've updated my machine to the following packages:

evolution-3.4.2-1.fc17.x86_64
evolution-mapi-3.4.2-1.fc17.x86_64

And now it doesn't seem to be throwing that error message, but it's still the same issue. (Could that be due to the debug logging you had me put in place?)

I do not know samba4 internals, but I do not expect any changes in behaviour with debugging being on. The addressbook factory usually closes book backends when they are not used (instead of calendar factory, which lefts them opened). In case you have anything running what uses MAPI books from the beginning, like you have set it for completion and you search for contact photos or you have it selected for inclusion in Birthdays & Anniversaries calendar, then it's kept opened, probably in some disconnected state.

Does it help to disable "Evolution Alarm Notify" from "Startup Programs"
in gnome-session-properties? I would like to try this only for testing, because with that disabled you'll not receive any alarm/reminder notifications.

That didn't seem to change anything, no. Still received the error "Error loading address book: cannot connect: mapilogonex: Network Error" in the Add-a-contact window of a new e-mail.

Created attachment 594981 [details]
contacts view error

I have a similar problem.
I have sent the log.txt generated on my system as from comment 1.
My current installed versions are:
evolution-mapi-3.4.3-2.fc17.x86_64
evolution-3.4.3-1.fc17.x86_64

When I open contacts view I get what attached picture error

Thanks for the log. I see there basically the same what is in comment #3 and and comment #5, the server rejects with rpc fault: WERR_ACCESS_DENIED, namely:
   NTLMSSP Sign/Seal - Initialising with flags:
   Got NTLMSSP neg_flags=0x60008235
     NTLMSSP_NEGOTIATE_UNICODE
     NTLMSSP_REQUEST_TARGET
     NTLMSSP_NEGOTIATE_SIGN
     NTLMSSP_NEGOTIATE_SEAL
     NTLMSSP_NEGOTIATE_NTLM
     NTLMSSP_NEGOTIATE_ALWAYS_SIGN
     NTLMSSP_NEGOTIATE_128
     NTLMSSP_NEGOTIATE_KEY_EXCH
   NTLMSSP Sign/Seal - using NTLM1
   rpc fault: WERR_ACCESS_DENIED
   Failed to bind to uuid 1544f5e0-613c-11d1-93df-00c04fd7bd09 for 1544f5e0-
   613c-11d1-93df-00c04fd7bd09@ncacn_ip_tcp:my_mail_server[11111,seal,print]
   NT_STATUS_NET_WRITE_FAULT
   Failed to connect to remote server: ncacn_ip_tcp:my_mail_server[print,
   seal,] NT_STATUS_NET_WRITE_FAULT

And I'm still out of idea why it would do that, unfortunately.

I made couple more fixes in evolution-mapi, the current version is 3.4.3-5, which also touches kerberos authentication and few other good fixes. I do not know whether it'll help anyhow here or not, though.

I am able to reproduce similar error when I have stored incorrect password for my MAPI account (which is a sub-bug of this, because, in such case, user should be asked for his.her password in such case). Otherwise it's like 1 out of 10 tries (restarts) when I see the error even with correct stored password, though it's very rarely for me.

Maybe a workaround: Check in each book Properties (right click on it in Contacts view), whether the book is selected for inclusion in Birthday & Anniversaries calendar. Better if it is not.

Gone in Contacts view and only the Personal Gal on this computer had "Birthday & Anniversaries" selected. Deselected it too and restarted evolution but the problem still there.

I didn't read the workaround posted at the beginning of the bugzilla, but it works for me too.
I'm using the scratch build evolution-mapi-3.4.3-5.1.fc17.x86_64 (for the sent items incorrect date bug, see upstream bugzilla
https://bugzilla.gnome.org/show_bug.cgi?id=679041)

evolution open right at boot of the os

$ uptime
 14:56:25 up  3:51,  5 users,  load average: 0.83, 0.78, 0.76

$ ps -ef | grep [f]acto
g.cecchi  1566     1  0 11:06 ?        00:00:00 /usr/libexec/evolution-calendar-factory
g.cecchi  1695     1  0 11:06 ?        00:00:00 /usr/libexec/evolution-addressbook-factory

If I write an e-mail and begin entering a name of an internal MS Exchange GAL contact, nothing happens; no auto-completion. I discard the e-mail

Then I manually run in a terminal
$ /usr/libexec/evolution-addressbook-factory
EDataFactory is now online.
Registering EBookBackendGoogleFactory ('google')
Registering EBookBackendVCFFactory ('vcf')
Registering EBookBackendMapiContactsFactory ('mapi')
Registering EBookBackendMapiGalFactory ('mapigal')
Registering EBookBackendLDAPFactory ('ldap')
Registering EBookBackendFileFactory ('local')
Registering EBookBackendWebdavFactory ('webdav')
Server is up and running...
Bus name 'org.gnome.evolution.dataserver.AddressBook3' acquired.
Bye.

$ ps -ef | grep [f]acto
g.cecchi  1566     1  0 11:06 ?        00:00:00 /usr/libexec/evolution-calendar-factory

Then I try again to write the same e-mail as before and the name is correctly auto-completed...

And now
$ ps -ef | grep [f]acto
g.cecchi  1566     1  0 11:06 ?        00:00:00 /usr/libexec/evolution-calendar-factory
g.cecchi  7722     1  1 14:55 ?        00:00:00 /usr/libexec/evolution-addressbook-factory

Donna if it can help debugging.
It is quite disappointing to have an evolution-mapi not able to make auto-completion vs Exchange users ootb, in my opinion..

Gianluca

(In reply to comment #13)
> It is quite disappointing to have an evolution-mapi not able to make
> auto-completion vs Exchange users ootb, in my opinion..

Yes, I agree. The thing is that I cannot reproduce this reliably, and thus I cannot properly debug this. I would like to guide for debugging, but I do not have much idea what to try. I'm stuck here. The only idea I have is that the evolution-addressbook-factory starts too early, before other system service (or something) is fully running, which causes evolution-mapi (and samba4 at the background) fail to connect. The "proof" might be that restarting factory (by killing the first) is enough to have this working as expected. But that is just my guess.

One of the other things I've noticed after the recent upgrade in evoltuion, is that whenever the connection actually does work, it takes a good 10-15 seconds before it actually loads the GAL, which, if you're impatient, would probably cause you to close the window under the guise of "It's not working." since the list remains empty.

Is there a reason that the addressbook starts at logon or at startup? Could it just wait for Evolution to be opened, or is that tied into the GNOME's address book?

What do you mean with
it takes a good 10-15 seconds before it actually loads the GAL
?
In my case I open evolution, then I compose an e-mail putting into the "to:" field the surname of the person I want to send the message to.
The person belongs to the MS Exchange organization GAL.
I wait about a minute and nothing happens in terms of auto-completion.
I discard the message
Then from a terminal I run 
$ /usr/libexec/evolution-addressbook-factory
I compose a message again and now it instantly auto-completes the e-mail address.
This is with
evolution-mapi-3.4.3-5.1.fc17.x86_64
openchange-1.0-6.fc17.x86_64

I mean exactly that. After running [...]/evolution-addressbook-factory, if I open a new message and go to To: to load the contacts window, and drop the list down to "Global Address List", it doesn't populate the list for roughly 10-15 seconds. During that time you can flip back and forth between local contacts, GAL, and any other lists you have, but neither GAL nor a list of contacts I have on the Exchange server loads until roughly 10-15 seconds later. After that everything's pretty instant, but I do have a roughly 10-15 second lag before anything shows up after that. Enumeration, perhaps? We don't have that many people here, roughly 250 users with mailboxes and ~15-20 groups.

As I wrote in comment #7, auto-start of evolution-calendar-factory can be due to Birthdays & Anniversaries calendar, which can be used in evolution-alarm-notify, which is auto-started to provide event Reminders (you can have in preferences to populate notification before each Birthday/Anniversary). You can try to move away 
/etc/xdg/autostart/evolution-alarm-notify.desktop
only for testing. If the addressbook factory will be started anyway, then other process invokes it on start.

The 15 seconds lag can be due to connecting to the server. I see here similar time till the all connection is established. That's a single call from a view of evolution-mapi, but OpenChange (libmapi) and samba4 does quite many things there.

*** Bug 847317 has been marked as a duplicate of this bug. ***

The above duplicate is from evolution-ews, which suffers of the same issue as evolution-mapi. These two are using completely different ways how to connect to the Exchange server, thus I guess this is some service run ordering issue, or something like that, which, probably, does something with password reading, which leads to failed authentication.

I moved this upstream as [1]. Please see [1] for any further updates. Please CC there if possible, in case upstream developers will have additional questions.

[1] https://bugzilla.gnome.org/show_bug.cgi?id=681815