New issue
Advanced search Search tips

Issue 884054 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Closed: Oct 8
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug

Blocking:
issue 812037



Sign in to add a comment

Online demo setup fails with 409 error from DMServer

Project Member Reported by agawronska@chromium.org, Sep 14

Issue description

Platform: 11059.0.0
Chrome: 71.0.3552
Device: eve

Device id conflict? https://cs.chromium.org/chromium/src/components/policy/core/common/cloud/device_management_service.cc?rcl=98192dac000a6762dbba673a4dba180006e749fa&l=53

Logs:
[1377:1377:0913/175630.640617:VERBOSE1:wizard_controller.cc(627)] Showing demo mode preferences screen.
[1377:1377:0913/175630.640802:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: demo-preferences
[1377:1377:0913/175640.529392:VERBOSE1:wizard_controller.cc(1558)] Wizard screen exit code: DEMO_MODE_PREFERENCES_CONTINUED
[1377:1377:0913/175640.529492:VERBOSE1:wizard_controller.cc(569)] Showing network screen.
[1377:1377:0913/175640.529578:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: network-selection
[1377:1377:0913/175643.640510:VERBOSE1:wizard_controller.cc(1558)] Wizard screen exit code: NETWORK_CONNECTED
[1377:1377:0913/175643.640633:VERBOSE1:wizard_controller.cc(613)] Showing EULA screen.
[1377:1377:0913/175643.640706:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: eula
[1377:1377:0913/175646.552141:VERBOSE1:wizard_controller.cc(1558)] Wizard screen exit code: EULA_ACCEPTED
[1377:1377:0913/175646.552928:VERBOSE1:auto_enrollment_controller.cc(546)] Auto-enrollment disabled: flag in VPD.
[1377:1377:0913/175646.552983:VERBOSE1:auto_enrollment_controller.cc(548)] Auto-enrollment disabled: VPD
[1377:1377:0913/175646.553021:VERBOSE1:auto_enrollment_controller.cc(732)] New auto-enrollment state: 5
[1377:1377:0913/175646.553159:VERBOSE1:wizard_controller.cc(714)] Showing ARC Terms of Service screen.
[1377:1377:0913/175646.553243:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: arc-tos
[1377:1377:0913/175649.593364:ERROR:customization_document.cc(635)] Customization manifest is missing on server: https://ssl.gstatic.com/chrome/chromeos-customization/google-eve.json
[1377:1377:0913/175649.739964:VERBOSE1:wizard_controller.cc(1935)] Resolved local timezone={dstOffset=3600.000000, rawOffset=-28800.000000, timeZoneId='America/Los_Angeles', timeZoneName='Pacific Daylight Time', error_message='', status=0 (OK)}.
[1377:1377:0913/175649.740069:VERBOSE1:wizard_controller.cc(1957)] Resolve TimeZone: setting timezone to 'America/Los_Angeles'
[1377:1377:0913/175701.797718:VERBOSE1:wizard_controller.cc(1558)] Wizard screen exit code: ARC_TERMS_OF_SERVICE_ACCEPTED
[1377:1377:0913/175701.797834:VERBOSE1:wizard_controller.cc(1287)] StartOOBEUpdate
[1377:1377:0913/175701.797906:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: update
[1377:1377:0913/175701.797967:VERBOSE1:update_screen.cc(341)] UpdateScreen::OnPortalDetectionCompleted(): network=/service/1, state.status=2, state.response_code=204
[1377:1377:0913/175701.798011:VERBOSE1:update_screen.cc(552)] Initiate update check
[1377:1377:0913/175701.801255:VERBOSE1:update_screen.cc(98)] Callback from RequestUpdateCheck, result 0
[1377:1377:0913/175701.989293:VERBOSE1:wizard_controller.cc(1558)] Wizard screen exit code: UPDATE_NOUPDATE
[1377:1377:0913/175701.989411:VERBOSE1:wizard_controller.cc(750)] Showing Auto-enrollment check screen.
[1377:1377:0913/175701.989481:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: auto-enrollment-check
[1377:1377:0913/175701.991918:VERBOSE1:wizard_controller.cc(1558)] Wizard screen exit code: ENTERPRISE_AUTO_ENROLLMENT_CHECK_COMPLETED
[1377:1377:0913/175701.992003:VERBOSE1:wizard_controller.cc(633)] Showing demo mode setup screen.
[1377:1377:0913/175701.992044:VERBOSE1:wizard_controller.cc(1374)] SetCurrentScreenSmooth: demo-setup
[1377:1377:0913/175702.001046:VERBOSE1:demo_setup_controller.cc(156)] Starting demo mode enrollment online
[1377:1377:0913/175711.847000:VERBOSE1:component_updater_service.cc(409)] Update completed with error 0
[1377:1377:0913/175746.993464:WARNING:device_management_service.cc(313)] DMServer sent an error response: 409
[1377:1377:0913/175746.993655:WARNING:enrollment_handler_chromeos.cc(818)] Enrollment failed: 2, client: 11, validation: 0, store: 0, lock: 0
[1377:1377:0913/175746.993788:ERROR:demo_setup_controller.cc(384)] EnrollmentError: status: 2 client_status: 11 store_status: 0 validation_status: 0 lock_status: 0 fatal=0
 
Owner: agawronska@chromium.org
Status: Assigned (was: Unconfirmed)
Tried couple older builds going back to Platform 11005.1.0. Getting the error all the time.
Either my device is corrupted or there is problem on DMServer.

Will try other device and continue investigation tomorrow.
For posterity, can you provide the values from your vpd?
"mlb_serial_number"="QCM650-01396-080A79M000DC"
"in_accel_x_base_calibbias"="51"
"in_accel_y_base_calibbias"="-70"
"in_accel_z_base_calibbias"="-27"
"in_accel_x_lid_calibbias"="-2"
"in_accel_y_lid_calibbias"="-47"
"in_accel_z_lid_calibbias"="10"
"customization_id"="GOOGLE-EVE"
"region"="us"
"rlz_brand_code"="ZZAF"
"serial_number"="7924G00796"
"wifi_sar"="FF3C484458FF3C484458FFFFFFFFFFFFFFFFFFFF0000000000000000000000000000000000000000"
"als_cal_intercept"="-294.466666667"
"als_cal_slope"="1.97368421053"
"stable_device_secret_DO_NOT_SHARE"="7dac864dc5a042177d49af92bffd2720c5a9d8f7a2aa11d59d0e121d7e99f114"

"gbind_attribute"="=CikKIPhszwNKKZ_cttJPmMHh7vV_-0aFY7OjX-ww6OWae08AEAAaA2V2ZRCDtdWLAQ=="
"ubind_attribute"="=CikKICad5i1nCYGelx7TvVJObMYvhsfPezA25SpYWuMBpQFMEAEaA2V2ZRDa3cy1BQ=="
"battery_cto_disabled"="1"
"block_devmode"="0"
"first_active_omaha_ping_sent"="1"
"check_enrollment"="0"
"ActivateDate"="2018-35"
"battery_otd_temp_set"="1"

Same error on meowth with CrOS 11064.0.0.
I waiting for reply about this error from DMServer team.
Labels: M-70
I'm receiving this now on a caroline, after several successful enrolls. However, the first time I received this error was after trying and failing to enroll offline. I powerwashed after that, though, so I would expect that to clear state.

The DeviceManagementStatus is DM_STATUS_SERVICE_DEVICE_ID_CONFLICT.

Thoughts:
* Maybe the device sent something to the DMServer when it was enrolled offline that confused it
* Maybe the device has been enrolled too many times in the past N days
My kevin, on the other hand, successfully enrolls into Demo Mode but the DMServer then sends a 902 error response, and I'm kicked back to OOBE after briefly seeing the public session pod (but with a randomized name, not the normal "Demo session" name set by policy)
For my eve and meowth I used to enroll them offline in the past, but there were never problems after power washing. 

When device is setup offline, even if it goes online later, it should not talk to DMServer, because it is never registered with DMServer.

The info about device id is strange, because we do not send device id in the registration request. We only send device id in policy fetch request, which never happens if registration fails.
 
Cc: pmoon@google.com
My eve can enroll successfully, repeatedly, with both a recovery image and a test image.

So it does seem to be tied to certain devices somehow. What concerns me is that my caroline could enroll fine earlier today but stopped being able to enroll partway through the day.
My eve was enrolling fine whole day after clearing dm server record.

As for now I don't see anything on the client that would cause the problem.

Michael, did you say earlier that manually deprovisioning device from the domain does not change anything?
Right, manually deprovisioning device from the domain does not change anything.

(And in the past I've noticed that after re-enrolling a deprovisioned device, the device retains its old OU and initial enrolling user in the device list.)
That sounds right. Deprovisioning job would be triggered by dm server if the device was enrolled into different domain. If it is enrolled into the same domain the metadate are not cleared/updated.
> When device is setup offline, even if it goes online later, it should not talk to DMServer, because it is never registered with DMServer.
>
>The info about device id is strange, because we do not send device id in the registration request. We only send device id in policy fetch request, which never happens if registration fails.

Aha. When the device is offline-enrolled, it DOES talk to DMServer -- it is actually receiving updated user policy!

Devices are offline-enrolled by installing hard-coded policy, which was taken from a real policy installed by an online-enrolled device. So, every device that has been offline-enrolled has claimed to have the same device_id, and is apparently sending that to DMServer in policy fetch requests.

In other words:

1. Device A was enrolled online and set its device_id=$DEVICE_ID
2. Device B was offline enrolled using device_id=$DEVICE_ID
3. Device B contacts DMServer and claims to be $DEVICE_ID

After Device B is powerwashed, I can't understand why it fails to enroll using online enrollment. It should be generating a new device_id, and to Aga's point, isn't sending the device_id in the registration request anyway.

Is it possible that DMServer links some stable ID to the provided device_id, and is therefore confusing different devices with each other?

Actually it might be sending the device ID in the registration request -- as an HTTP parameter, not part of the proto. See DeviceManagementRequestJob::SetClientID: https://cs.chromium.org/chromium/src/components/policy/core/common/cloud/device_management_service.cc?type=cs&sq=package:chromium&g=0&l=506

And this device ID actually might be a *stable* ID -- looks like it's generated from /etc/machine-id:

https://cs.chromium.org/chromium/src/chrome/browser/policy/browser_dm_token_storage_linux.cc?type=cs&sq=package:chromium&g=0&l=81

I confirmed that in case of online demo setup we do not pass the device_id/client_id - it is just an empty string.

Device id is grabbed from install attributes. Device is not locked, so device id is empty.

Enrollment still fails with 409.
I meant that there is no old device_id being preserved. I am checking the generated id. 
Aga, it looks like the device id would be passed as an HTTP param in the device registration request, not as part of the protobuf. Is that what you checked, or did you check the proto?
I am checking what is being set to the request:
https://cs.chromium.org/chromium/src/components/policy/core/common/cloud/device_management_service.cc?type=cs&sq=package:chromium&g=0&l=506

I will try to check whole request too.

And this seems to be generated guid:
https://cs.chromium.org/chromium/src/components/policy/core/common/cloud/cloud_policy_client.cc?rcl=b1e0638a12b569791c0e64ec0fce247c6682c440&l=202

I do not see how this is linked to browser_dm_token_storage yet.

I tried online setup and the generated device id was:
59e6aaf7-336e-4440-aa83-7caaf1411d20

Then I tried offline setup immediately and id generated for offline was:
359aea4d-9f92-4125-a21a-d9c18ec18b89

I tried online again:
c0e04d1b-d594-454b-90d8-4e7165a077e7
Device that was setup offline do not attempt online registration.

It does attempt policy fetch with the id from the policy. It should not do that and I will fix it. I thought that offline enrolled device does not have dm token stored, but this is not true.
We probably should not include any DMToken (and especially valid one) in offline blob.

This still does not necessarily explain our problem.  
After clearing DMServer record my device was not setup offline at all, but I cannot enroll it online anyway. I don't know how the association with offline id would be revived.
Params of the policy fetch request done by offline device:
[8522:8522:0918/130248.449048:ERROR:device_management_service.cc(293)] [XXX] ----------------------------
[8522:8522:0918/130248.449064:ERROR:device_management_service.cc(295)] [XXX] request : policy
[8522:8522:0918/130248.449078:ERROR:device_management_service.cc(295)] [XXX] devicetype : 2
[8522:8522:0918/130248.449092:ERROR:device_management_service.cc(295)] [XXX] apptype : Chrome
[8522:8522:0918/130248.449106:ERROR:device_management_service.cc(295)] [XXX] agent : Google Chrome 71.0.3555.0(1948e36506627ac710569d75bc33085552c38cc0-refs/heads/master@{#591732})
[8522:8522:0918/130248.449121:ERROR:device_management_service.cc(295)] [XXX] platform : Linux,CrOS,nocturne|x86_64,NOCTURNE A2B-A3D-C2K-M34|11076.0.0
[8522:8522:0918/130248.449137:ERROR:device_management_service.cc(295)] [XXX] deviceid : 00d2dceb-f0c6-4501-a93d-4f43ab95f2c8
[8522:8522:0918/130248.449151:ERROR:device_management_service.cc(297)] [XXX] ----------------------------

Params of the failed registration request:
1064:1064:0918/130743.667958:ERROR:device_management_service.cc(293)] [XXX] ----------------------------
[1064:1064:0918/130743.667998:ERROR:device_management_service.cc(295)] [XXX] request : certificate_based_register
[1064:1064:0918/130743.668032:ERROR:device_management_service.cc(295)] [XXX] devicetype : 2
[1064:1064:0918/130743.668064:ERROR:device_management_service.cc(295)] [XXX] apptype : Chrome
[1064:1064:0918/130743.668096:ERROR:device_management_service.cc(295)] [XXX] agent : Google Chrome 71.0.3555.0(1948e36506627ac710569d75bc33085552c38cc0-refs/heads/master@{#591732})
[1064:1064:0918/130743.668129:ERROR:device_management_service.cc(295)] [XXX] platform : Linux,CrOS,nocturne|x86_64,NOCTURNE A2B-A3D-C2K-M34|11076.0.0
[1064:1064:0918/130743.668161:ERROR:device_management_service.cc(295)] [XXX] deviceid : f81ad68b-1e06-41e6-8b02-9a3d0a4e9303
[1064:1064:0918/130743.668193:ERROR:device_management_service.cc(297)] [XXX] ----------------------------

In the topic of stable id:
Device stable id was needed to get device certificates.
Maybe because of that DMServer is able to identify device and notice some mismatch?  
I did some tests for online/offline setup to see if there is something that triggers problems and I found nothing.

Clear DMServer record SN/87IA001J0
Setup device online (~ 10 times) yesterday - SUCCESS
Setup device online (~ 3 times) today - SUCCESS
Setup device fully offline, never connect to the network
Setup device online - SUCCESS
Setup device fully offline, connect to the network once setup
Setup device online (~ 3 times) - SUCCESS
Setup device offline while connected to the network
Setup device online (~ 3 times) - SUCCESS

Blocking: 812037
Cc: chchakrapani@chromium.org timkovich@chromium.org
I just got 409 when trying manual enrollment into not cros-demo-mode domain:
remora-test.mygbiz.com.


Right after that I was able to manually enroll into managedchrome.com
My managedchrome does not have public session configured, while remora and demo-mode do.
The workaround for demo mode is now deployed to alpha DMServer and I confirmed that it works.
Status: Verified (was: Assigned)
The  workaround is in prod and we do not observe problems. I am closing that.

Sign in to add a comment