OS 10.9 / Server 3.2.2 - Profile Manager Push

Question

Level 1

5 points

OS 10.9 / Server 3.2.2 - Profile Manager Push

With no apparent reason - Today devices have been quite intermittent when attempting to push new settings from Profile Manager. These machines have been fine for weeks, since deployment even, until today. The MacMini Server has been restarted for the sake of troubleshooting but the issue persists.

Attached are is a sample log from the Server's 'Device Server Log' - From start to finish of one client trying to update. I've removed the FQDN, LongNames, ShortNames and DeviceNames intentionally. Any idea's would be greatly appreciated...

2::Dec 02 15:58:47.793 [1100] <192.168.50.129> {GetAppPreference (common.php:63)} GetAppPreference: Pref for 'DBLogSQL' = 
1::Dec 02 15:58:47.793 [1100] <192.168.50.129> {LogElapsedTime (common.php:78)} Time since script start: 230us [https://DOMAIN/devicemanagement/api/device/mdm_connect]
1::Dec 02 15:58:47.793 [1100] <192.168.50.129> {require_once (mdm_connect.php:11)} vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv - PUT mdm_connect
3::Dec 02 15:58:47.796 [1100] <192.168.50.129> mdm_connect.php: incoming_request={
3::Dec 02 15:58:47.796 [1100] <192.168.50.129>   'AuthToken'=>'<BinaryString: 28 bytes>',
3::Dec 02 15:58:47.796 [1100] <192.168.50.129>   'Status'=>'Idle',
3::Dec 02 15:58:47.796 [1100] <192.168.50.129>   'UDID'=>'9b1c54c9ed7b5c7caab2fec15251a7d4',
3::Dec 02 15:58:47.796 [1100] <192.168.50.129>   'UserID'=>'4E6491E8-761F-4C27-9D6D-A37DD28F0A66',
3::Dec 02 15:58:47.796 [1100] <192.168.50.129>   'UserLongName'=>'LONGNAME',
3::Dec 02 15:58:47.796 [1100] <192.168.50.129>   'UserShortName'=>'SHORTNAME'
3::Dec 02 15:58:47.796 [1100] <192.168.50.129> }
2::Dec 02 15:58:47.796 [1100] <192.168.50.129> {Target_for_client_certificate (target.php:369)} Target_for_client_certificate: checkin_token = '1839f7df-ac64-4b05-94cf-004b7f5fb2ab'
2::Dec 02 15:58:47.798 [1100] <192.168.50.129> {LabSession_for_incoming_request (target.php:384)} dev_udid='9b1c54c9ed7b5c7caab2fec15251a7d4', user_guid='4E6491E8-761F-4C27-9D6D-A37DD28F0A66'
3::Dec 02 15:58:47.802 [1100] <192.168.50.129> {LabSession_for_incoming_request (target.php:384)} LabSession_for_incoming_request: LabSession for UserID 4E6491E8-761F-4C27-9D6D-A37DD28F0A66, UDID 9b1c54c9ed7b5c7caab2fec15251a7d4: NETWORK LS: <SHORTNAME[16](S-GUID:4e6491e8-761f-4c27-9d6d-a37dd28f0a66, C-GUID:4e6491e8-761f-4c27-9d6d-a37dd28f0a66)@DEVICENAME(SN:C02NG1ZLG3QP, CN:1839f7df-ac64-4b05-94cf-004b7f5fb2ab)>
1::Dec 02 15:58:47.802 [1100] <192.168.50.129> {Target_for_incoming_request (mdm_connect.php:20)} Found target NETWORK LS: <SHORTNAME[16](S-GUID:4e6491e8-761f-4c27-9d6d-a37dd28f0a66, C-GUID:4e6491e8-761f-4c27-9d6d-a37dd28f0a66)@DEVICENAME(SN:C02NG1ZLG3QP, CN:1839f7df-ac64-4b05-94cf-004b7f5fb2ab)>
1::Dec 02 15:58:47.802 [1100] <192.168.50.129> For request:
1::Dec 02 15:58:47.802 [1100] <192.168.50.129> {
1::Dec 02 15:58:47.802 [1100] <192.168.50.129>   'AuthToken'=>'<BinaryString: 28 bytes>',
1::Dec 02 15:58:47.802 [1100] <192.168.50.129>   'Status'=>'Idle',
1::Dec 02 15:58:47.802 [1100] <192.168.50.129>   'UDID'=>'9b1c54c9ed7b5c7caab2fec15251a7d4',
1::Dec 02 15:58:47.802 [1100] <192.168.50.129>   'UserID'=>'4E6491E8-761F-4C27-9D6D-A37DD28F0A66',
1::Dec 02 15:58:47.802 [1100] <192.168.50.129>   'UserLongName'=>'LONGNAME',
1::Dec 02 15:58:47.802 [1100] <192.168.50.129>   'UserShortName'=>'SHORTNAME'
1::Dec 02 15:58:47.802 [1100] <192.168.50.129> }
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> {LabSession_validate_auth_token (mdm_connect.php:37)} Failed auth for target NETWORK LS: <SHORTNAME[16](S-GUID:4e6491e8-761f-4c27-9d6d-a37dd28f0a66, C-GUID:4e6491e8-761f-4c27-9d6d-a37dd28f0a66)@DEVICENAME(SN:C02NG1ZLG3QP, CN:1839f7df-ac64-4b05-94cf-004b7f5fb2ab)>, incoming_request={
0::Dec 02 15:58:47.803 [1100] <192.168.50.129>   'AuthToken'=>'<BinaryString: 28 bytes>',
0::Dec 02 15:58:47.803 [1100] <192.168.50.129>   'Status'=>'Idle',
0::Dec 02 15:58:47.803 [1100] <192.168.50.129>   'UDID'=>'9b1c54c9ed7b5c7caab2fec15251a7d4',
0::Dec 02 15:58:47.803 [1100] <192.168.50.129>   'UserID'=>'4E6491E8-761F-4C27-9D6D-A37DD28F0A66',
0::Dec 02 15:58:47.803 [1100] <192.168.50.129>   'UserLongName'=>'LONGNAME',
0::Dec 02 15:58:47.803 [1100] <192.168.50.129>   'UserShortName'=>'SHORTNAME'
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> }
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> {LogException (common.php:466)} EXCEPTION: 403 Forbidden - unable to validate auth token at
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> #0 /Applications/Server.app/Contents/ServerRoot/usr/share/devicemgr/backend/php/mdm_connect.php(37): DieForbidden('unable to valid...')
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> #1 /Applications/Server.app/Contents/ServerRoot/usr/share/devicemgr/backend/php/db.php(396): _connect_transaction_1(Array)
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> #2 /Applications/Server.app/Contents/ServerRoot/usr/share/devicemgr/backend/php/mdm_connect.php(126): PerformInTransaction('_connect_transa...', Array)
0::Dec 02 15:58:47.803 [1100] <192.168.50.129> #3 {main}
1::Dec 02 15:58:47.803 [1100] <192.168.50.129> {SendFinalOutput (common.php:473)} Sent Final Output (14 bytes)
1::Dec 02 15:58:47.803 [1100] <192.168.50.129> ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ - /devicemanagement/mdm/mdm_connect
0::Dec 02 15:58:47.804 [1100] <192.168.50.129> {SendFinalOutput (common.php:473)} Completed in 10ms | 403 Forbidden  [https://DOMAIN/devicemanagement/api/device/mdm_connect]

Posted on Dec 2, 2014 4:26 PM

Reply

Answer 1

May 5, 2015 4:34 PM in response to Sonofiron

Did you ever figure out what was going on with this/fix it? I'm having erratic problems with PM on the latest version of Server w/ Yosemite and my logs look like yours. Some machines just refuse to accept profiles.

Reply