Upgrade Server 4 - stalled at profile manager

Question

Level 2

425 points

Upgrade Server 4 - stalled at profile manager

Am trying to upgrade to Server 4.0 from 3.2.1

The server install process stalls at about halfway across the blue line - with the statement "updating profile manager service".

This is odd because we don't use the profile manager service, and it was disabled in the 3.2.1 configuration (i.e. set to not start in the Server app)

No obvious errors in the system log.

Anyone got any suggestions about what I can do to kick it along?

Thanks in advance for any help.

Mac mini (Late 2012), OS X Server

Posted on Oct 17, 2014 12:36 PM

Reply

Answer 1

Oct 17, 2014 12:45 PM in response to Gavin Lawrie

Hi Gavin,

Can you paste into this discussion the contents of /Library/Logs/ProfileManager/migration_tool.log? (Or the last 100 or so lines if the file is really large.) That would be the first place to look for problems.

Reply

Answer 2

Gavin Lawrie Author

Level 2

425 points

Oct 17, 2014 4:04 PM in response to mscott_mdm

Hi

Here are the logs. Also included screen capture of the server migration window in its current state. Been like that for several hours (I just went out to watch a movie and have returned to see line in same place as previously). The weird thing about this is even though the migration tool is still stalled, some server services are up and running (e.g. mail). No idea what is going on etc.

Thanks!

Gavin

[10343] [2014/10/17 20:32:24.817] -[SULogFileCollection setGlobalLogLevelPrefix:]: YES

0:: [10343] [2014/10/17 20:32:24.820]

############################################################################### ##

migration_tool-883.16 (PID:10343, OS:14A389, SERVER:14S333, ARCH:x86_64) starting

LA: migration_tool

Log verbosity level = 1

UID = 220, EUID = 220

############################################################################### ##

0:: [10343] [2014/10/17 20:32:24.888] Waiting for postgres to startup....

0:: [10343] [2014/10/17 20:32:25.482] +[PGConnection reloadPreferences]: DBDebug = NO, DBLogNotices = NO, DBLogSQL = NO, DBMonitor = NO

0:: [10343] [2014/10/17 20:32:25.628] +[PGConnection reloadPreferences]: DBDebug = NO, DBLogNotices = NO, DBLogSQL = NO, DBMonitor = NO

0:: [10343] [2014/10/17 20:32:26.767] Dropping views...

0:: [10343] [2014/10/17 20:32:27.008] Dropping trigger functions...

0:: [10343] [2014/10/17 20:32:27.452] Dropping remaining non-dependent functions...

0:: [10343] [2014/10/17 20:32:28.521] MIGRATE_00880.008 completed successfully

0:: [10343] [2014/10/17 20:32:28.529] MIGRATE_00881.003 completed successfully

0:: [10343] [2014/10/17 20:32:28.539] MIGRATE_00881.006 completed successfully

0:: [10343] [2014/10/17 20:32:28.571] MIGRATE_00881.009 completed successfully

0:: [10343] [2014/10/17 20:32:28.590] MIGRATE_00883.006 completed successfully

0:: [10343] [2014/10/17 20:32:28.633] MIGRATE_00883.008 completed successfully

0:: [10343] [2014/10/17 20:32:28.667] MIGRATE_00883.011 completed successfully

0:: [10343] [2014/10/17 20:32:28.670] Re-creating functions, triggers, and views...

0:: [10343] [2014/10/17 20:32:29.687] +[PGConnection reloadPreferences]: DBDebug = NO, DBLogNotices = NO, DBLogSQL = NO, DBMonitor = NO

0:: [10343] [2014/10/17 20:32:29.694] ShutdownMigrator: 2014-10-17 19:32:29 +0000

0:: [10343] [2014/10/17 20:32:29.694] BYE

Reply

Answer 3

Oct 17, 2014 4:47 PM in response to Gavin Lawrie

Well, that looks fine. Can you see if there's a file in /Library/Logs/ that has the words "DeviceManager" or "ProfileManager" in it? (But not the directory named "ProfileManager".) If there is one, please paste its contents here.

Reply

Answer 4

Gavin Lawrie Author

Level 2

425 points

Oct 17, 2014 4:50 PM in response to mscott_mdm

Hi

This is the last block of entries in a log called "ServerSetup_DeviceManager.log" in /Library/Logs. Is this what you are looking for? It contains an error at least... 😉

2014-10-17 20:32:22 deviceManagerCommon.sh: A postgres cluster appers to already exist at /Library/Server/ProfileManager/Config/ServiceData/Data/PostgreSQL

2014-10-17 20:32:22 deviceManagerCommon.sh: Pre-flight starting postgres...

2014-10-17 20:32:22 deviceManagerCommon.sh: Started xpostgres with PID 10294

2014-10-17 20:32:22 XPG.10297: Process parent is PID 10294

2014-10-17 20:32:22 XPG.10297: Excluding data directory.

2014-10-17 20:32:22 XPG.10297: Turning on archive logging.

2014-10-17 20:32:22 XPG.10297: Cleaning up any existing postmaster.pid file

2014-10-17 20:32:22 XPG.10297: Starting postgres.

2014-10-17 20:32:22 XPG.10297: Waiting for data directory: /Library/Server/ProfileManager/Config/ServiceData/Data/PostgreSQL

2014-10-17 20:32:22 XPG.10297: Data directory exists.

2014-10-17 20:32:22 XPG.10297: Spawning postgres now.

2014-10-17 20:32:22 XPG.10297: Waiting for socket to appear in socket directory: /Library/Server/ProfileManager/Config/var/PostgreSQL

2014-10-17 20:32:23 deviceManagerCommon.sh: Stopping postgres pre-flight instance...

2014-10-17 20:32:23 XPG.10297: Decremented reference count. Count is now: 0

2014-10-17 20:32:23 XPG.10297: Reference count reached zero. Shutting down.

2014-10-17 20:32:23 XPG.10297: Killing idle connections...

2014-10-17 20:32:23 XPG.10297: Spawning... ('/Applications/Server.app/Contents/ServerRoot/usr/bin/psql', '-q', '-h', '/Library/Server/ProfileManager/Config/var/PostgreSQL', '-d', 'postgres', '-c', "SELECT pid, (SELECT pg_terminate_backend(pid)) as killed from pg_stat_activity WHERE state LIKE 'idle';")

pid | killed

-----+--------

(0 rows)

2014-10-17 20:32:23 XPG.10297: Socket available; starting should now be complete.

2014-10-17 20:32:24 XPG.10297: log receiver: pg_receivexlog: could not connect to server: FATAL: the database system is shutting down

pg_receivexlog: disconnected; waiting 5 seconds to try again

2014-10-17 20:32:24 XPG.10297: Postgres exited.

2014-10-17 20:32:24 XPG.10297: pg_receivexlog still running; terminating.

2014-10-17 20:32:24 XPG.10297: log receiver: pg_receivexlog: could not connect to server: could not connect to server: No such file or directory

Is the server running locally and accepting

connections on Unix domain socket "/Library/Server/ProfileManager/Config/var/PostgreSQL/.s.PGSQL.5432"?

2014-10-17 20:32:24 deviceManagerCommon.sh: Starting postgres under launchd...

{

}

{

}

2014-10-17 20:32:24 deviceManagerCommon.sh: Migrating PM SACL in OD...

PM SACL group has already been migrated

2014-10-17 20:32:24 deviceManagerCommon.sh: Preparing/migrating database...

{

}

2014-10-17 20:32:29 deviceManagerCommon.sh: Done!

Oct 17 20:32:55.009 Applying DeviceManager<7fca7144d750> Profile Manager

Oct 17 20:32:55.010 DeviceManager<7fca7144d750> Running '/Applications/Server.app/Contents/ServerRoot/usr/libexec/deviceManagerCommon.s h'

2014-10-17 20:32:55 deviceManagerCommon.sh: Starting...

2014-10-17 20:32:55 deviceManagerCommon.sh: Ensuring Profile Manager services are unloaded and terminated...

{

}

{

}

{

}

Reply

Answer 5

Oct 17, 2014 6:54 PM in response to Gavin Lawrie

I had the same issue with the calendar service. Take a look in that thread on how I solved this.

Server App 4.0 stuck on "Upgrading Calendar Service"

Reply

Answer 6

Oct 17, 2014 8:11 PM in response to Gavin Lawrie

Gavin,

Actually, that looks OK for the most part. It is a little odd that the deviceManagerCommon.sh script seems to have been run again almost immediately after it finished, and it seems to have hung in that 2nd pass. If this were my server, I'd probably try to identify the process ID of the script and kill it. Something like this (in Terminal):

ps ax | grep deviceManagerCommon

The first number in the line that isn't "grep deviceManagerCommon" is the process ID. Replace '<pid>' with the number obtained above:

sudo kill <pid>

And if that doesn't work, use this bigger hammer:

sudo kill -9 <pid>

The reason I think this will be OK is because the setup script obviously ran fine the first time. The only thing is that you might need to manually run this script yet again to get some of the support services turned back on, otherwise you'll get errors in Server.app. Or, since you've never used Profile Manager, you could just reset it to factory defaults with this:

sudo /Applications/Server.app/Contents/ServerRoot/usr/share/devicemgr/config/wipeDB

But only do that if you're sure there isn't any data in Profile Manager you want to keep.

Reply

Answer 7

Gavin Lawrie Author

Level 2

425 points

Oct 18, 2014 3:07 AM in response to mscott_mdm

Hi

Thanks - killing the process did the trick. mscott_mdm: I'm really grateful for your help with this. Very much appreciated!

For the benefit of anyone else who has to do the same thing - this is what happened on our system:

When I killed the process, the server update process switched to an error screen within the upgrade window reporting that the update had failed and highlighting the script that was killed as the culprit.
The error screen had a 'continue' button - when I clicked on this the server app main window opened... (phew!)
The server app reported that all our usual services were working normally, but we were getting errors related to our SSL certificate when accessing remotely (mail, wiki, calendar all bleating about there being a dud certificate)
A reboot of the server didn't fix the issue, but going through to the 'certificates' panel and reselecting our certificate in the 'Secure Services using' drop down did the trick.

Since then the server has been working normally / well.

P.S. The certificate issue might be an anomaly - we use a Comodo certificate that we purchased a couple of years ago. At some point Apple introduced a requirement for these certificates to support / have a 'code signing' capability alongside their other features. Comodo apparently can't or won't comply with this requirement and so their SSL certificates no longer are able to fully support OS X Server services (it is only Open Directory that requires this feature, remaining services can be secured with Comodo SSL). As you would expect, Apple blame Comodo and Comodo blame Apple. Until our cert expires we're stuck with it, but maybe it causes these other SSL problems we've seen.

Reply

Answer 8

Gavin Lawrie Author

Level 2

425 points

Oct 18, 2014 3:09 AM in response to Kraftwerk

Hi Kraftwerk - yes thanks for the heads-up. I saw the post while looking for answers before I posted my question: glad to see you got your issue sorted. I did look to see if your fix would work for us, but I think the directory structure for Profile Manager is not same as for Calendar, so wasn't clear how to apply your fix in this case. But thanks for taking time to let me know. Appreciated!

Reply

Answer 9

mcapurro

Level 1

0 points

Oct 25, 2014 9:02 AM in response to mscott_mdm

I do need some help as well. I'm getting stuck much sooner:

[21290] [2014/10/23 05:26:52.187] -[SULogFileCollection setGlobalLogLevelPrefix:]: YES

0:: [21290] [2014/10/23 05:26:52.189]

############################################################################### ##

migration_tool-883.16 (PID:21290, OS:14A389, SERVER:14S333, ARCH:x86_64) starting

LA: migration_tool

Log verbosity level = 1

UID = 220, EUID = 220

############################################################################### ##

0:: [21290] [2014/10/23 05:26:52.256] Waiting for postgres to startup....

0:: [21290] [2014/10/23 05:26:52.666] +[PGConnection reloadPreferences]: DBDebug = NO, DBLogNotices = NO, DBLogSQL = NO, DBMonitor = NO

0:: [21290] [2014/10/23 05:26:52.810] +[PGConnection reloadPreferences]: DBDebug = NO, DBLogNotices = NO, DBLogSQL = NO, DBMonitor = NO

0:: [21290] [2014/10/23 05:26:53.287] Caught unhandled exception -[PGConnection executeCSQL:] (/SourceCache/RemoteDeviceManagement/RemoteDeviceManagement-883.16/Compiled/Fra mework-Models/Postgres/PGConnection.m:330): "Postgres error 42883 (ERROR: function __dm_cleanup_3x_with_triggers() does not exist

LINE 1: ...E settings SET needs_initial_od_sync = TRUE WHERE __dm_clean...

^

HINT: No function matches the given name and argument types. You might need to add explicit type casts.

)"

1:: [21290] [2014/10/23 05:26:53.323] EXCEPTION: Error <-[SCEPHelper odRootCertificate] (/SourceCache/RemoteDeviceManagement/RemoteDeviceManagement-883.16/Compiled/Fra mework-Base/Support/SCEPHelper.m:61): "'((SCEPHELPER_GetODRootCertificate(self.connection, &root, &rootCnt)))' error 1">

USERINFO: {

NSLocalizedDescription = "Operation not permitted";

}

0:: [21290] [2014/10/23 05:26:53.388] +[PGConnection reloadPreferences]: DBDebug = NO, DBLogNotices = NO, DBLogSQL = NO, DBMonitor = NO

0:: [21290] [2014/10/23 05:26:53.392] ShutdownMigrator: 2014-10-23 11:26:53 +0000

0:: [21290] [2014/10/23 05:26:53.392] BYE

any ideas?

Reply

Answer 10

Oct 25, 2014 9:14 AM in response to mcapurro

mcapurro,

Your problem actually looks very different. This looks like a fairly common OD/certificate issue, but the details of this error are going to be in /Library/Logs/ProfileManager/scep_helper.log. I would recommend you start a new question so that the answers we (hopefully) find will also be easier for other people to find. Regardless, include the last 50 or so lines from that log file if you can.

Thanks.

Reply

Answer 11

Oct 25, 2014 9:15 AM in response to mscott_mdm

Heh, never mind the "new thread" thing. I see you already did this.

Reply

Answer 12

rkm1

Level 1

0 points

Feb 12, 2015 11:00 AM in response to Gavin Lawrie

I just had this same problem with the freeze while updating the Profile Manager when the server was disconnected from the internet. I aborted, restored from Time Machine, configured an an internet connection, then restarted the update. It ran with no problems. My guess is something was phoning home to Apple during the Profile Manager update and waiting forever for an answer.

Reply

Answer 13

BJH75

Level 1

7 points

Apr 16, 2015 4:11 PM in response to Gavin Lawrie

When you are accepting the license agreement for Server there is a checkbox near the bottom that says something like:

"Use Apple Services to determine how this server is accessible over the Internet"

(might not be exact because I don't have it in front of me right now).

Anyway, on a fresh 10.10.3 install with Server 4.1 I was having this problem hanging at Profile Manager like the OP.

Running again but un-checking the box for this option resulted in a successful install.

Reply