Andoroid 11 开机广播处理超时导致第三方应用启动延迟

//第一个收到
09-13 17:45:03.406 D/WifiSleepController(  432): onReceive, action=android.intent.action.BOOT_COMPLETED
//异常LOG位置
09-13 17:46:07.077 W/BroadcastQueue(  432): Timeout of broadcast BroadcastRecord{35f0038 u0 android.intent.action.BOOT_COMPLETED} - receiver=android.os.BinderProxy@e7eb8bf, started 60000ms ago
09-13 17:46:07.077 W/BroadcastQueue(  432): Receiver during timeout of BroadcastRecord{35f0038 u0 android.intent.action.BOOT_COMPLETED} : ResolveInfo{af90b8c com.android.phone/.vvm.VvmSimStateTracker m=0x108000}

final void broadcastTimeoutLocked(boolean fromMsg) {
        if (fromMsg) {
            mPendingBroadcastTimeoutMessage = false;
        }
        if (mDispatcher.isEmpty() || mDispatcher.getActiveBroadcastLocked() == null) {
            return;
        }
        long now = SystemClock.uptimeMillis();
        BroadcastRecord r = mDispatcher.getActiveBroadcastLocked();
        if (fromMsg) {
            if (!mService.mProcessesReady) {
                // Only process broadcast timeouts if the system is ready; some early
                // broadcasts do heavy work setting up system facilities
                return;
            }
            // If the broadcast is generally exempt from timeout tracking, we're done
            if (r.timeoutExempt) {
                if (DEBUG_BROADCAST) {
                    Slog.i(TAG_BROADCAST, "Broadcast timeout but it's exempt: "
                            + r.intent.getAction());
                }
                return;
            }
            long timeoutTime = r.receiverTime + mConstants.TIMEOUT;
            if (timeoutTime > now) {
                // We can observe premature timeouts because we do not cancel and reset the
                // broadcast timeout message after each receiver finishes.  Instead, we set up
                // an initial timeout then kick it down the road a little further as needed
                // when it expires.
                if (DEBUG_BROADCAST) Slog.v(TAG_BROADCAST,
                        "Premature timeout ["
                        + mQueueName + "] @ " + now + ": resetting BROADCAST_TIMEOUT_MSG for "
                        + timeoutTime);
                setBroadcastTimeoutLocked(timeoutTime);
                return;
            }
        }
        if (r.state == BroadcastRecord.WAITING_SERVICES) {
            // In this case the broadcast had already finished, but we had decided to wait
            // for started services to finish as well before going on.  So if we have actually
            // waited long enough time timeout the broadcast, let's give up on the whole thing
            // and just move on to the next.
            Slog.i(TAG, "Waited long enough for: " + (r.curComponent != null
                    ? r.curComponent.flattenToShortString() : "(null)"));
            r.curComponent = null;
            r.state = BroadcastRecord.IDLE;
            processNextBroadcast(false);
            return;
        }
        // If the receiver app is being debugged we quietly ignore unresponsiveness, just
        // tidying up and moving on to the next broadcast without crashing or ANRing this
        // app just because it's stopped at a breakpoint.
        final boolean debugging = (r.curApp != null && r.curApp.isDebugging());
        Slog.w(TAG, "Timeout of broadcast " + r + " - receiver=" + r.receiver
                + ", started " + (now - r.receiverTime) + "ms ago");
}

<receiver
            android:name="com.android.phone.vvm.VvmSimStateTracker"
            android:exported="false"
            androidprv:systemUserOnly="true">
            <intent-filter>
                <action android:name="android.intent.action.BOOT_COMPLETED"/>
                <action android:name="android.telephony.action.CARRIER_CONFIG_CHANGED"/>
                <action android:name="android.intent.action.SIM_STATE_CHANGED"/>
            </intent-filter>
        </receiver>

public void onReceive(Context context, Intent intent) {
        final String action = intent.getAction();
        if (action == null) {
            VvmLog.w(TAG, "Null action for intent.");
            return;
        }
        VvmLog.i(TAG, action);
        switch (action) {
            case Intent.ACTION_BOOT_COMPLETED:
                onBootCompleted(context);
                break;
    //Ignore....
    }
    private void onBootCompleted(Context context) {
        for (PhoneAccountHandle phoneAccountHandle : sPreBootHandles) {
            TelephonyManager telephonyManager = getTelephonyManager(context, phoneAccountHandle);
            if (telephonyManager == null) {
                continue;
            }
            if (telephonyManager.getServiceState().getState() == ServiceState.STATE_IN_SERVICE) {
                sListeners.put(phoneAccountHandle, null);
                sendConnected(context, phoneAccountHandle);
            } else {
                listenToAccount(context, phoneAccountHandle);
            }
        }
        sPreBootHandles.clear();
    }

<application android:name="PhoneApp"
            android:persistent="true"
            android:label="@string/phoneAppLabel"
            android:icon="@mipmap/ic_launcher_phone"
            android:allowBackup="false"
            android:supportsRtl="true"
            android:usesCleartextTraffic="true"
            android:defaultToDeviceProtectedStorage="true"
            android:directBootAware="true">

public class PhoneApp extends Application {
    PhoneGlobals mPhoneGlobals;
    public PhoneApp() {
    }
    @Override
    public void onCreate() {
        if (UserHandle.myUserId() == 0) {
            // We are running as the primary user, so should bring up the
            // global phone state.
            mPhoneGlobals = new PhoneGlobals(this);
            mPhoneGlobals.onCreate();
            TelecomAccountRegistry.getInstance(this).setupOnBoot();
        }
    }
}

public void onCreate() {
        if (VDBG) Log.v(LOG_TAG, "onCreate()...");
        ContentResolver resolver = getContentResolver();
        // Cache the "voice capable" flag.
        // This flag currently comes from a resource (which is
        // overrideable on a per-product basis):
        sVoiceCapable = ((TelephonyManager) getSystemService(Context.TELEPHONY_SERVICE))
                .isVoiceCapable();
        // ...but this might eventually become a PackageManager "system
        // feature" instead, in which case we'd do something like:
        // sVoiceCapable =
        //   getPackageManager().hasSystemFeature(PackageManager.FEATURE_TELEPHONY_VOICE_CALLS);
        if (mCM == null) {
            // Initialize AnomalyReporter early so that it can be used
            AnomalyReporter.initialize(this);
            // Inject telephony component factory if configured using other jars.
            XmlResourceParser parser = getResources().getXml(R.xml.telephony_injection);
            TelephonyComponentFactory.getInstance().injectTheComponentFactory(parser);
            // Initialize the telephony framework
            PhoneFactory.makeDefaultPhones(this);
    //ignored...
    }

public static void makeDefaultPhones(Context context) {
        makeDefaultPhone(context);
    }
     @UnsupportedAppUsage
    public static void makeDefaultPhone(Context context) {
        synchronized (sLockProxyPhones) {
            if (!sMadeDefaults) {
                sContext = context;
                // create the telephony device controller.
                TelephonyDevController.create();
                TelephonyMetrics metrics = TelephonyMetrics.getInstance();
                metrics.setContext(context);
                int retryCount = 0;
                for(;;) {
                    boolean hasException = false;
                    retryCount ++;
                    try {
                        // use UNIX domain socket to
                        // prevent subsequent initialization
                        new LocalServerSocket("com.android.internal.telephony");
                    } catch (java.io.IOException ex) {
                        hasException = true;
                    }
                    if ( !hasException ) {
                        break;
                    } else if (retryCount > SOCKET_OPEN_MAX_RETRY) {
                        throw new RuntimeException("PhoneFactory probably already running");
                    } else {
                        try {
                            Thread.sleep(SOCKET_OPEN_RETRY_MILLIS);
                        } catch (InterruptedException er) {
                        }
                    }
                }
                // register statsd pullers.
                sMetricsCollector = new MetricsCollector(context);
                sPhoneNotifier = new DefaultPhoneNotifier(context);
                int cdmaSubscription = CdmaSubscriptionSourceManager.getDefault(context);
                Rlog.i(LOG_TAG, "Cdma Subscription set to " + cdmaSubscription);
                /* In case of multi SIM mode two instances of Phone, RIL are created,
                   where as in single SIM mode only instance. isMultiSimEnabled() function checks
                   whether it is single SIM or multi SIM mode */
                int numPhones = TelephonyManager.getDefault().getActiveModemCount();
                int[] networkModes = new int[numPhones];
                sPhones = new Phone[numPhones];
                sCommandsInterfaces = new RIL[numPhones];
                sTelephonyNetworkFactories = new TelephonyNetworkFactory[numPhones];
                for (int i = 0; i < numPhones; i++) {
                    // reads the system properties and makes commandsinterface
                    // Get preferred network type.
                    networkModes[i] = RILConstants.PREFERRED_NETWORK_MODE;
                    Rlog.i(LOG_TAG, "Network Mode set to " + Integer.toString(networkModes[i]));
                    sCommandsInterfaces[i] = new RIL(context, networkModes[i],
                            cdmaSubscription, i);
                }
                // Ignored
    }

@UnsupportedAppUsage
    public RIL(Context context, int preferredNetworkType,
            int cdmaSubscription, Integer instanceId) {
        super(context);
        if (RILJ_LOGD) {
            riljLog("RIL: init preferredNetworkType=" + preferredNetworkType
                    + " cdmaSubscription=" + cdmaSubscription + ")");
        }
        mContext = context;
        mCdmaSubscription  = cdmaSubscription;
        mPreferredNetworkType = preferredNetworkType;
        mPhoneType = RILConstants.NO_PHONE;
        mPhoneId = instanceId == null ? 0 : instanceId;
        if (isRadioBugDetectionEnabled()) {
            mRadioBugDetector = new RadioBugDetector(context, mPhoneId);
        }
        TelephonyManager tm = (TelephonyManager) context.getSystemService(
                Context.TELEPHONY_SERVICE);
        mIsCellularSupported = tm.isVoiceCapable() || tm.isSmsCapable() || tm.isDataCapable();
        mRadioResponse = new RadioResponse(this);
        mRadioIndication = new RadioIndication(this);
        mOemHookResponse = new OemHookResponse(this);
        mOemHookIndication = new OemHookIndication(this);
        mRilHandler = new RilHandler();
        mRadioProxyDeathRecipient = new RadioProxyDeathRecipient();
        PowerManager pm = (PowerManager)context.getSystemService(Context.POWER_SERVICE);
        mWakeLock = pm.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, RILJ_WAKELOCK_TAG);
        mWakeLock.setReferenceCounted(false);
        mAckWakeLock = pm.newWakeLock(PowerManager.PARTIAL_WAKE_LOCK, RILJ_ACK_WAKELOCK_NAME);
        mAckWakeLock.setReferenceCounted(false);
        mWakeLockTimeout = TelephonyProperties.wake_lock_timeout()
                .orElse(DEFAULT_WAKE_LOCK_TIMEOUT_MS);
        mAckWakeLockTimeout = TelephonyProperties.wake_lock_timeout()
                .orElse(DEFAULT_ACK_WAKE_LOCK_TIMEOUT_MS);
        mWakeLockCount = 0;
        mRILDefaultWorkSource = new WorkSource(context.getApplicationInfo().uid,
                context.getPackageName());
        mActiveWakelockWorkSource = new WorkSource();
        TelephonyDevController tdc = TelephonyDevController.getInstance();
        tdc.registerRIL(this);
        // set radio callback; needed to set RadioIndication callback (should be done after
        // wakelock stuff is initialized above as callbacks are received on separate binder threads)
        getRadioProxy(null);
        getOemHookProxy(null);
        if (RILJ_LOGD) {
            riljLog("Radio HAL version: " + mRadioVersion);
        }
    }
    /** Returns a {@link IRadio} instance or null if the service is not available. */
    @VisibleForTesting
    public synchronized IRadio getRadioProxy(Message result) {
        if (!SubscriptionManager.isValidPhoneId(mPhoneId)) return null;
        if (!mIsCellularSupported) {
            if (RILJ_LOGV) riljLog("getRadioProxy: Not calling getService(): wifi-only");
            if (result != null) {
                AsyncResult.forMessage(result, null,
                        CommandException.fromRilErrno(RADIO_NOT_AVAILABLE));
                result.sendToTarget();
            }
            return null;
        }
        if (mRadioProxy != null) {
            return mRadioProxy;
        }
        try {
            if (mDisabledRadioServices.contains(mPhoneId)) {
                riljLoge("getRadioProxy: mRadioProxy for " + HIDL_SERVICE_NAME[mPhoneId]
                        + " is disabled");
            } else {
                try {
                    mRadioProxy = android.hardware.radio.V1_5.IRadio.getService(
                            HIDL_SERVICE_NAME[mPhoneId], true);
                    mRadioVersion = RADIO_HAL_VERSION_1_5;
                } catch (NoSuchElementException e) {
                }
                if (mRadioProxy == null) {
                    try {
                        mRadioProxy = android.hardware.radio.V1_4.IRadio.getService(
                                HIDL_SERVICE_NAME[mPhoneId], true);
                        mRadioVersion = RADIO_HAL_VERSION_1_4;
                    } catch (NoSuchElementException e) {
                    }
                }
                if (mRadioProxy == null) {
                    try {
                        mRadioProxy = android.hardware.radio.V1_3.IRadio.getService(
                                HIDL_SERVICE_NAME[mPhoneId], true);
                        mRadioVersion = RADIO_HAL_VERSION_1_3;
                    } catch (NoSuchElementException e) {
                    }
                }
                if (mRadioProxy == null) {
                    try {
                        mRadioProxy = android.hardware.radio.V1_2.IRadio.getService(
                                HIDL_SERVICE_NAME[mPhoneId], true);
                        mRadioVersion = RADIO_HAL_VERSION_1_2;
                    } catch (NoSuchElementException e) {
                    }
                }
                if (mRadioProxy == null) {
                    try {
                        mRadioProxy = android.hardware.radio.V1_1.IRadio.getService(
                                HIDL_SERVICE_NAME[mPhoneId], true);
                        mRadioVersion = RADIO_HAL_VERSION_1_1;
                    } catch (NoSuchElementException e) {
                    }
                }
                if (mRadioProxy == null) {
                    try {
                        mRadioProxy = android.hardware.radio.V1_0.IRadio.getService(
                                HIDL_SERVICE_NAME[mPhoneId], true);
                        mRadioVersion = RADIO_HAL_VERSION_1_0;
                    } catch (NoSuchElementException e) {
                    }
                }
                if (mRadioProxy != null) {
                    mRadioProxy.linkToDeath(mRadioProxyDeathRecipient,
                            mRadioProxyCookie.incrementAndGet());
                    mRadioProxy.setResponseFunctions(mRadioResponse, mRadioIndication);
                } else {
                    mDisabledRadioServices.add(mPhoneId);
                    riljLoge("getRadioProxy: mRadioProxy for "
                            + HIDL_SERVICE_NAME[mPhoneId] + " is disabled");
                }
            }
        } catch (RemoteException e) {
            mRadioProxy = null;
            riljLoge("RadioProxy getService/setResponseFunctions: " + e);
        }
        if (mRadioProxy == null) {
            // getService() is a blocking call, so this should never happen
            riljLoge("getRadioProxy: mRadioProxy == null");
            if (result != null) {
                AsyncResult.forMessage(result, null,
                        CommandException.fromRilErrno(RADIO_NOT_AVAILABLE));
                result.sendToTarget();
            }
        }
        return mRadioProxy;
    }

/**
     * each RIL call this interface to register/unregister the unsolicited hardware
     * configuration callback data it can provide.
     */
    public static void registerRIL(CommandsInterface cmdsIf) {
        /* get the current configuration from this ril... */
        cmdsIf.getHardwareConfig(sRilHardwareConfig);
        /* ... process it ... */
        if (sRilHardwareConfig != null) {
            AsyncResult ar = (AsyncResult) sRilHardwareConfig.obj;
            if (ar.exception == null) {
                handleGetHardwareConfigChanged(ar);
            }
        }
        /* and register for async device configuration change. */
        cmdsIf.registerForHardwareConfigChanged(sTelephonyDevController, EVENT_HARDWARE_CONFIG_CHANGED, null);
    }
    public static void unregisterRIL(CommandsInterface cmdsIf) {
        cmdsIf.unregisterForHardwareConfigChanged(sTelephonyDevController);
    }

01:48:48.154  1880-1880  chatty       com.android.phone  I  uid=1001(radio) com.android.phone expire 4 lines
01:48:48.160   331-339   RIL RILU     pid-331            E  cannot find ttyname for AT Port
01:48:48.161   331-339   RIL RILC                        D  USB can't find at device
01:48:51.161   331-339   RIL RILU                        D  find_pci_device is 0
01:48:51.170   331-339   RIL RILU                        E  cannot find ttyname for AT Port
01:48:51.171   331-339   RIL RILC                        D  USB can't find at device
01:48:52.168  1880-1880  HidlS...ment com.android.phone  W  Waited one second for android.hardware.radio@1.1::IRadio/slot1
01:48:53.172  1880-1880  HidlS...ment                    W  Waited one second for android.hardware.radio@1.1::IRadio/slot1
01:48:54.172   331-339   RIL RILU     pid-331            D  find_pci_device is 0

2022-09-16 07:18:14.975 426-1802/system_process E/ActivityManager: ANR in com.android.phone
    PID: 873
    Reason: Broadcast of Intent { act=android.intent.action.BOOT_COMPLETED flg=0x89000010 cmp=com.android.phone/.vvm.VvmSimStateTracker (has extras) }
    Load: 0.0 / 0.0 / 0.0
    ----- Output from /proc/pressure/memory -----
    some avg10=0.00 avg60=0.00 avg300=0.00 total=0
    full avg10=0.00 avg60=0.00 avg300=0.00 total=0
    ----- End output from /proc/pressure/memory -----
    CPU usage from 64519ms to 0ms ago (2022-09-16 07:17:10.274 to 2022-09-16 07:18:14.793):
      10% 426/system_server: 7.9% user + 2.6% kernel / faults: 15491 minor 133 major
      3.5% 579/com.android.systemui: 2.9% user + 0.5% kernel / faults: 8380 minor 1 major
      1.6% 174/surfaceflinger: 1% user + 0.6% kernel / faults: 550 minor
      1.5% 1124/com.google.android.inputmethod.pinyin: 1.2% user + 0.2% kernel / faults: 5726 minor 39 major
      1.4% 331/adbd: 0.4% user + 1% kernel / faults: 8283 minor
      1.3% 146/rknn_server: 0.1% user + 1.2% kernel
      0.5% 224/android.hardware.graphics.composer@2.1-service: 0.2% user + 0.3% kernel / faults: 31 minor
      0.5% 138/logd: 0.1% user + 0.3% kernel / faults: 21 minor
      0.4% 340/installd: 0.3% user + 0.1% kernel / faults: 140 minor
      0.4% 246/zygote64: 0% user + 0.3% kernel / faults: 2679 minor
      0.3% 329/rild: 0% user + 0.3% kernel
      0.3% 7/kworker/u8:0-flush-179:0: 0% user + 0.3% kernel / faults: 1137 minor
      0.2% 50/cfinteractive: 0% user + 0.2% kernel
      0.2% 286/audioserver: 0.1% user + 0.1% kernel / faults: 125 minor
      0.2% 346/mediaserver: 0.1% user + 0.1% kernel / faults: 346 minor
      0.2% 141/hwservicemanager: 0% user + 0.1% kernel / faults: 192 minor
      0.2% 387/media.swcodec: 0.1% user + 0% kernel / faults: 136 minor
      0.2% 870/logcat: 0% user + 0.1% kernel
      0.2% 949/com.android.launcher3: 0.1% user + 0% kernel / faults: 537 minor
      0.2% 1/init: 0% user + 0.1% kernel / faults: 39 minor
      0.1% 81/kworker/0:1H-mmc_complete: 0% user + 0.1% kernel
      0.1% 111/kworker/2:2H-kblockd: 0% user + 0.1% kernel
      0.1% 262/android.hardware.audio.service: 0% user + 0.1% kernel / faults: 37 minor
      0.1% 230/kworker/u8:3-devfreq_wq: 0% user + 0.1% kernel / faults: 770 minor
      0.1% 393/irq/77-dwc3: 0% user + 0.1% kernel
      0.1% 873/com.android.phone: 0% user + 0% kernel / faults: 14 minor
      0.1% 244/statsd: 0% user + 0% kernel / faults: 6 minor
      0.1% 896/com.android.settings: 0.1% user + 0% kernel / faults: 420 minor 1 major
      0.1% 95/kworker/1:1H-kblockd: 0% user + 0.1% kernel
      0.1% 231/kworker/0:3H-mmc_complete: 0% user + 0.1% kernel
      0.1% 917/android.ext.services: 0.1% user + 0% kernel / faults: 630 minor
      0.1% 46/kworker/2:1-events_freezable: 0% user + 0.1% kernel
      0.1% 80/kworker/3:1H-kblockd: 0% user + 0.1% kernel
      0.1% 140/servicemanager: 0% user + 0% kernel
      0.1% 1102/com.android.deskclock: 0% user + 0% kernel / faults: 503 minor
      0% 229/kworker/u8:2: 0% user + 0% kernel / faults: 350 minor
      0% 425/kworker/u9:2-kbase_pm_poweroff_wait: 0% user + 0% kernel
      0% 10/rcu_preempt: 0% user + 0% kernel
      0% 139/lmkd: 0% user + 0% kernel
      0% 216/android.hardware.graphics.allocator@4.0-service: 0% user + 0% kernel / faults: 191 minor
      0% 481/kworker/u9:3-blk_crypto_wq: 0% user + 0% kernel
      0% 78/ion_system_heap: 0% user + 0% kernel
      0% 105/kworker/1:2H-kblockd: 0% user + 0% kernel
      0% 124/kworker/3:2-events_power_efficient: 0% user + 0% kernel
      0% 190/f2fs_discard-25: 0% user + 0% kernel
      0% 270/android.hardware.health@2.1-service: 0% user + 0% kernel
      0% 977/com.hsdz.systemcontroler:shellservice: 0% user + 0% kernel / faults: 163 minor
      0% 11/rcu_sched: 0% user + 0% kernel
      0% 14/kworker/0:1-kdmflush: 0% user + 0% kernel
      0% 45/kconsole: 0% user + 0% kernel
      0% 131/kworker/1:2-kdmflush: 0% user + 0% kernel
      0% 148/vold: 0% user + 0% kernel / faults: 87 minor
      0% 172/android.system.suspend@1.0-service: 0% user + 0% kernel
      0% 280/android.hardware.power-service.rockchip: 0% user + 0% kernel
      0% 342/media.extractor: 0% user + 0% kernel
      0% 822/com.android.se: 0% user + 0% kernel / faults: 10 minor