After 5.0.x upgrade, cannot add "OS X Server" account

Question

After 5.0.x upgrade, cannot add "OS X Server" account

After upgrading my server to El Capitan and Server 5.0.4, and a clean install on my client to El Capitan, I am unable to add an "OS X Server" account in the Internet accounts preference pane any more.

When adding the account, it gives an error "The user name or password for <server name> is incorrect."

If I try to add the services individually (using CardDAV, CalDAV, Mail accounts etc.) then the same server name, user name and password work without issue.

Looking on the server side, I get the following in the Password Service error log:

'algorithm' must be 'md5' or 'md5-sess'

I have no idea where that is coming from, though it appears it may relate to webdav: Webdav Sharing doesn't work after Server 5 update

however, attempting the fix linked from that discussion doesn't appear to work (also I don't recall the "OS X Server" account type ever adding anything relating to WebDAV in the past -- so it's quite possible this error is coming from something else).

Anyone have any thoughts for a fix or further diagnostics?

Posted on Oct 8, 2015 10:12 AM

Reply

Answer 1

Drizzt

Level 1

19 points

Oct 15, 2015 8:18 AM in response to James Carscadden

I have this problem also.

If you change "AuthType" from "Digest" to "Basic" in the file "/Library/Server/Web/Config/apache2/httpd_ACSServer.conf" and execute commands webappctl stop com.apple.webapp.ACSServer and webappctl start com.apple.webapp.ACSServer, the authentification will work, but both OS X and iOS 9 won't go pass the connection, you'll get a spinning wheel forever.

Reply

Answer 2

Oct 15, 2015 5:37 PM in response to Drizzt

I tried this out, and replicated your result. Changing "Digest" to "Basic" meant that I got past the original error, but had the spinning wheel forever.

This however, led me on a bit of a hunt for more on the ACSServer, which led in turn to /var/log/apache2/services/ACSServer_error_log wherein we find some interesting log entries (mildly edited to protect the innocent):

[Thu Oct 15 19:37:16.698660 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] AH01775: auth_via_xsauthenticator: challengeForNonce ACTIVE originalChallenge=Digest nonce="<stuff>",realm="<my realm>",qop="auth",algorithm=md5-ses

[Thu Oct 15 19:37:16.698988 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] auth_via_xsauthenticator: authenticator created, realm is <my realm>, method is GET.

[Thu Oct 15 19:37:16.699096 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] auth_via_xsauthenticator: XSAuthenticator setInitialResponse is private

[Thu Oct 15 19:37:16.745763 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] auth_via_xsauthenticator: Denied '<my user>'

[Thu Oct 15 19:37:16.745840 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] AH01764: updateNonceForChallenge(): Updating state of entry for nonce <stuff>, entry 0, newState 0

[Thu Oct 15 19:37:16.745854 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] note_digest_auth_failure: resp->username = <my user>, r->user=<my user>, realm = Accounts Config Service

[Thu Oct 15 19:37:16.746366 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] AH01764: saveChallenge(): sizeofEntry 216 numEntries 18 challengeNonce <stuff> challenge Digest nonce="<stuff>",realm="<my realm>",qop="auth",algorithm=md5-sess

[Thu Oct 15 19:37:16.746418 2015] [auth_digest_apple:info] [pid 46013] [client 127.0.0.1:58533] AH01764: saveChallenge(): saved entry 0 challenge Digest nonce="<stuff>",realm="<my realm>",qop="auth",algorithm=md5-sess

Note the three bits in red. It would appear that "auth_via_xsauthenticator" is using algorithm "md5-ses" -- which presumably is a typo, and is what is causing the previously mentioned error message of 'algorithm' must be 'md5' or 'md5-sess' in the password service error log. Interestingly later we see with the AH01764 entries, that is displays the proper algorithm of md5-sess in that case.

Unfortunately I can't find any further insight into the service, so I would suspect we've run into a bug that is going to need to be fixed in a subsequent server release.

Reply

Answer 3

Drizzt

Level 1

19 points

Oct 16, 2015 7:58 AM in response to James Carscadden

Copy mod_auth_digest_apple.so from Server.app 4.1.x to /Applications/Server.app/Contents/ServerRoot/usr/libexec/apache2 than restart ACSServer and it will work.

Definitively a bug in Server 5

Reply

Answer 4

Oct 22, 2015 6:13 PM in response to Drizzt

As you've also mentioned in the thread about webdav, release 5.0.15 doesn't appear to fix the problem despite indications in the release notes that suggest it should have been fixed.

"Fixes several Web Server and WebDAV issues" -- not so much.

Interestingly that particular line is missing from the release notes in the corresponding web kb article - About OS X Server 5.0.15 - Apple Support

Looks like somebody pooched their branch merges or something. Guess I have to wait for the next release. (While hacking in the fix above again)

Reply

Answer 5

Hiraz

Level 1

4 points

Oct 29, 2015 11:10 PM in response to James Carscadden

I'm getting the same issue (on OS X Server 5.0.15 now) - "The username or password ... is incorrect" when adding OS X Server account, although the same account works fine for CalDav, CardDav, or SMB sharing... except in my case I'm not seeing the md5-ses errors in the ACSServer_error_log. Instead, I'm getting the following types of messages in /Library/Server/Logs/serverdocs.log:

Oct 30 12:34:06 os-x-server sdmd[31468] <Error>: #@com.apple.root.default-qos: [PostgreSQLClient.framework] Error executing query [SELECT unique_identifier FROM services]:

Oct 30 12:34:06 os-x-server sdmd[31569] <Error>: #@com.apple.main-thread: Could not connect to Postgres. Please make sure it is running and has the correct access.

(The second line repeats each time I start the File Sharing service from OS X Server).

Postgres is running (in various configurations - the caldav and carddav versions no longer running since they aren't required in my environment...):

# ps auxww | grep postgres

_teamsserver 34725 0.0 0.0 2459132 744 ?? Ss 1:52PM 0:00.00 postgres: stats collector process

_teamsserver 34724 0.0 0.0 2459132 492 ?? Ss 1:52PM 0:00.00 postgres: archiver process

_teamsserver 34723 0.0 0.0 2629612 1956 ?? Ss 1:52PM 0:00.00 postgres: autovacuum launcher process

_teamsserver 34722 0.0 0.0 2621160 740 ?? Ss 1:52PM 0:00.00 postgres: wal writer process

_teamsserver 34721 0.0 0.0 2621160 1092 ?? Ss 1:52PM 0:00.02 postgres: writer process

_teamsserver 34720 0.0 0.0 2621160 756 ?? Ss 1:52PM 0:00.00 postgres: checkpointer process

_teamsserver 34718 0.0 0.0 2448892 532 ?? Ss 1:52PM 0:00.00 postgres: logger process

_teamsserver 34716 0.0 0.7 2623208 28904 ?? S 1:52PM 0:00.06 /Applications/Server.app/Contents/ServerRoot/usr/bin/postgres_real -D /Library/Server/Wiki/Database.xpg/Cluster.pg -c log_connections=on -c log_min_error_statement=WARNING -c listen_addresses= -c max_connections=500 -c unix_socket_group=_teamsserver -c log_statement=ddl -c log_line_prefix=%t -c log_lock_waits=on -c unix_socket_permissions=0770 -c log_rotation_age=1440 -c unix_socket_directories=/Library/Server/Wiki/PostgresSocket -c log_min_messages=WARNING -c logging_collector=on -c log_filename=postgres-%a.log -c log_truncate_on_rotation=on -c log_directory=/Library/Server/Wiki/Logs

_teamsserver 34711 0.0 1.5 2519336 64432 ?? S 1:52PM 0:01.14 xpostgres -D /Library/Server/Wiki/Database.xpg/Cluster.pg -c log_connections=on -c log_min_error_statement=WARNING -c listen_addresses= -c max_connections=500 -c unix_socket_group=_teamsserver -c log_statement=ddl -c log_line_prefix=%t -c log_lock_waits=on -c unix_socket_permissions=0770 -c log_rotation_age=1440 -c unix_socket_directories=/Library/Server/Wiki/PostgresSocket -c log_min_messages=WARNING -c logging_collector=on -c log_filename=postgres-%a.log -c log_truncate_on_rotation=on -c log_directory=/Library/Server/Wiki/Logs

_xserverdocs 33599 0.0 0.1 2608108 2168 ?? Ss 1:26PM 0:00.06 postgres: wal sender process _xserverdocs [local] streaming 0/16000DF8

_xserverdocs 33593 0.0 0.0 2467324 732 ?? Ss 1:26PM 0:00.07 postgres: stats collector process

_xserverdocs 33592 0.0 0.0 2467324 548 ?? Ss 1:26PM 0:00.01 postgres: archiver process

_xserverdocs 33591 0.0 0.1 2616300 2112 ?? Ss 1:26PM 0:00.03 postgres: autovacuum launcher process

_xserverdocs 33590 0.0 0.0 2607976 736 ?? Ss 1:26PM 0:00.02 postgres: wal writer process

_xserverdocs 33589 0.0 0.0 2607976 1592 ?? Ss 1:26PM 0:00.06 postgres: writer process

_xserverdocs 33588 0.0 0.1 2616168 2100 ?? Ss 1:26PM 0:00.01 postgres: checkpointer process

_xserverdocs 33586 0.0 0.0 2459132 528 ?? Ss 1:26PM 0:00.00 postgres: logger process

_xserverdocs 33585 0.0 0.5 2610024 20136 ?? S 1:26PM 0:00.08 /Applications/Server.app/Contents/ServerRoot/usr/bin/postgres_real -D /Library/Server/ServerDocs/Database.xpg/cluster.pg -c log_connections=on -c log_min_error_statement=WARNING -c listen_addresses= -c max_connections=200 -c log_rotation_size=10MB -c unix_socket_group=_xserverdocs -c log_statement=ddl -c log_line_prefix=%m -c log_lock_waits=on -c unix_socket_permissions=0770 -c log_rotation_age=1440 -c unix_socket_directories=/Library/Server/ServerDocs/Database.xpg/sockets -c log_min_messages=WARNING -c logging_collector=on -c log_filename=postgres-%%a.log -c log_truncate_on_rotation=on -c log_directory=/Library/Server/Logs/ServerDocsPostgreSQL

_xserverdocs 33575 0.0 1.4 2518312 59928 ?? S 1:26PM 0:01.79 xpostgres -D /Library/Server/ServerDocs/Database.xpg/cluster.pg -c log_connections=on -c log_min_error_statement=WARNING -c listen_addresses= -c max_connections=200 -c log_rotation_size=10MB -c unix_socket_group=_xserverdocs -c log_statement=ddl -c log_line_prefix=%m -c log_lock_waits=on -c unix_socket_permissions=0770 -c log_rotation_age=1440 -c unix_socket_directories=/Library/Server/ServerDocs/Database.xpg/sockets -c log_min_messages=WARNING -c logging_collector=on -c log_filename=postgres-%%a.log -c log_truncate_on_rotation=on -c log_directory=/Library/Server/Logs/ServerDocsPostgreSQL

_devicemgr 31053 0.0 0.1 2747244 2180 ?? Ss 12:26PM 0:00.01 postgres: _devicemgr devicemgr_v2m0 [local] idle

_devicemgr 31052 0.0 0.4 2758016 17328 ?? Ss 12:26PM 0:00.26 postgres: _devicemgr devicemgr_v2m0 [local] idle

_devicemgr 30890 0.0 0.5 2764032 21992 ?? Ss 12:25PM 0:00.57 postgres: _devicemgr devicemgr_v2m0 [local] idle

_devicemgr 30886 0.0 0.1 2755436 2712 ?? Ss 12:25PM 0:00.01 postgres: _devicemgr devicemgr_v2m0 [local] idle

_devicemgr 30885 0.0 0.4 2778116 17640 ?? Ss 12:25PM 0:00.72 postgres: _devicemgr devicemgr_v2m0 [local] idle

_devicemgr 30884 0.0 0.5 2763008 21908 ?? Ss 12:25PM 0:00.71 postgres: _devicemgr devicemgr_v2m0 [local] idle

_devicemgr 30862 0.0 0.0 2755060 1524 ?? Ss 12:24PM 0:00.31 postgres: wal sender process _devicemgr [local] streaming 0/51EF9B0

_devicemgr 30853 0.0 0.0 2467324 748 ?? Ss 12:24PM 0:00.45 postgres: stats collector process

_devicemgr 30852 0.0 0.0 2467324 488 ?? Ss 12:24PM 0:00.02 postgres: archiver process last was 000000010000000000000004.00000028.backup

_devicemgr 30851 0.0 0.0 2754668 1804 ?? Ss 12:24PM 0:00.14 postgres: autovacuum launcher process

_devicemgr 30850 0.0 0.0 2746348 1344 ?? Ss 12:24PM 0:00.11 postgres: wal writer process

_devicemgr 30849 0.0 0.0 2746348 1776 ?? Ss 12:24PM 0:00.10 postgres: writer process

_devicemgr 30848 0.0 0.1 2754540 4840 ?? Ss 12:24PM 0:00.23 postgres: checkpointer process

_devicemgr 30846 0.0 0.0 2458108 384 ?? Ss 12:24PM 0:00.06 postgres: logger process

_devicemgr 30845 0.0 0.2 2748264 8656 ?? S 12:24PM 0:00.21 /Applications/Server.app/Contents/ServerRoot/usr/bin/postgres_real -D /Library/Server/ProfileManager/Config/ServiceData/Data/PostgreSQL -c unix_socket_directories=/Library/Server/ProfileManager/Config/var/PostgreSQL -c default_transaction_isolation=serializable -c logging_collector=on -c log_rotation_size=10MB -c log_connections=on -c log_lock_waits=on -c log_statement=ddl -c log_line_prefix=%m -c listen_addresses= -c log_directory=/Library/Logs/ProfileManager -c log_filename=PostgreSQL-%F.log -c log_file_mode=0640 -c log_min_messages=WARNING -c log_min_error_statement=WARNING -c unix_socket_group=_devicemgr -c unix_socket_permissions=0770 -c max_connections=200 -c shared_buffers=256MB

_devicemgr 30825 0.0 0.1 2519336 6264 ?? Ss 12:24PM 0:02.53 xpostgres -a /Library/Server/ProfileManager/Config/PostgreSQL_config.plist -D /Library/Server/ProfileManager/Config/ServiceData/Data/PostgreSQL -c unix_socket_directories=/Library/Server/ProfileManager/Config/var/PostgreSQL -c default_transaction_isolation=serializable -c logging_collector=on -c log_rotation_size=10MB -c log_connections=on -c log_lock_waits=on -c log_statement=ddl -c log_line_prefix=%m -c listen_addresses= -c log_directory=/Library/Logs/ProfileManager -c log_filename=PostgreSQL-%F.log -c log_file_mode=0640 -c log_min_messages=WARNING -c log_min_error_statement=WA XPC_FLAGS=0x0 PYTHONPATH=/Applications/Server.app/Contents/ServerRoot/Library/CalendarServer/ lib/python2.7/site-packages

root 34753 0.0 0.0 2435192 840 s000 S+ 1:53PM 0:00.00 grep postgres

_teamsserver 34731 0.0 0.1 2630444 5040 ?? Ss 1:52PM 0:00.01 postgres: collab collab [local] idle

_teamsserver 34730 0.0 0.1 2621420 2192 ?? Ss 1:52PM 0:00.00 postgres: wal sender process _teamsserver [local] streaming 2E/100049E0

But I wouldn't know if there's something missing that's meant to be there.

I can't find any info on how to give postgres the correct access for IOS file sharing ... nor would I know how it may have lost that in the first place.

I've tried setting AuthType to Basic instead of Digest, but in my case both types give the same result for the iOS file sharing ... indicating that there's something broken before this step even comes into play.

I've tried resetting things by closing server, moving it to the trash, waiting for it to prompt to stop services and then moving it back and restarting (as per Postgres won't start after restart)... but that makes no difference.

I've also tried resetting ProfileManager to a blank slate (OS X Server: How to reset Profile Manager to its original state - Apple Support) since it seems to control a lot of the auth side of things (clutching at straws due to lack of other options!), but this also made no difference.

If I thought it would work I'd also be willing to try the 4.1.x version of mod_auth_digest_aple.so, but I seem to have other issues anyway - and I'm not sure where to find that file anyhow since I don't have a 4.1.x copy of server handy.

Reply

Answer 6

Jan 9, 2016 9:29 PM in response to Hiraz

Any news on this issue?

Reply

Answer 7

kuinak

Level 1

0 points

Jan 21, 2016 3:04 PM in response to James Carscadden

I ran into this problem today and found your post which pushed me in the right direction. I noticed that my logs were showing the algorithm as "md5-se" as opposed to the "md5-ses" you saw. So, on a hunch, I shortened the name of my server by a few characters and it worked! Looks like the bug has to deal with something truncating the values that the digest gets challenged against.

Reply