Log spammed with "Power request failed: OPERATION_NOT_ALLOWED" (Volla Quintus)

haagch

About once per second this message is logged to journalctl:
Jul 02 13:12:01 ubuntu-phablet ofonod[4404]: Power request failed: OPERATION_NOT_ALLOWED

The only google result for "ofonod" "Power request failed" "OPERATION_NOT_ALLOWED" is this thread about another Volla phone: https://forum.sailfishos.org/t/the-volla-x23-gx4-thread/15726/88. But it is not specifically about this issue, so I thought I'd create a new thread specifically for it.

As far as I can tell this message is harmless: I can call the mobile number and the phone rings. I can call other numbers from this phone. I only wonder what it takes to get rid of this message - and does it indicate higher than intended power draw?

When I run sudo systemctl stop ofono.service and sudo /usr/sbin/ofonod -P ril --nodetach --debug I see that the full message produced every second is

ofonod[4404]: src/binder_radio.c:binder_radio_power_request_retry_cb() slot2
slot2 < [000002e0] 24 setRadioPower
  0000: 61 6e 64 72 6f 69 64 2e  68 61 72 64 77 61 72 65    android. hardware
  0010: 2e 72 61 64 69 6f 40 31  2e 30 3a 3a 49 52 61 64    .radio@1 .0::IRad
  0020: 69 6f 00 00 e0 02 00 00  01 00 00 00                io...... ....
slot2 > [000002e0] 23 setRadioPowerResponse OPERATION_NOT_ALLOWED
  0000: 61 6e 64 72 6f 69 64 2e  68 61 72 64 77 61 72 65    android. hardware
  0010: 2e 72 61 64 69 6f 40 31  2e 30 3a 3a 49 52 61 64    .radio@1 .0::IRad
  0020: 69 6f 52 65 73 70 6f 6e  73 65 00 00 85 2a 74 70    ioRespon se...*tp
  0030: 00 00 00 00 60 50 19 b1  7f 00 00 00 0c 00 00 00    ....`P.. ........
  0040: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00    ........ ........
  0050: 00 00 00 00                                         ....
ofonod[4404]: Power request failed: OPERATION_NOT_ALLOWED
ofonod[4404]: src/binder_radio.c:binder_radio_check_state() slot2 retry scheduled

but likewise the only google result for "setRadioPowerResponse" "OPERATION_NOT_ALLOWED" is the android source code.

What's next? Does this originate somewhere in the android driver stack? Could there be a way to allow this operation or might this be something the android driver generally does not allow and ofonod should be changed to stop retrying when OPERATION_NOT_ALLOWED is returned?

haagch

Looking further I guess that setRadioPower is the actual function returning the error:
https://android.googlesource.com/platform/frameworks/opt/telephony/+/master/src/java/com/android/internal/telephony/PhoneInternalInterface.java#576

    /**
     * Sets the radio power on/off state (off is sometimes
     * called "airplane mode"). Current state can be gotten via
     * {@link #getServiceState()}.{@link
     * android.telephony.ServiceState#getState() getState()}.
     * <strong>Note: </strong>This request is asynchronous.
     * getServiceState().getState() will not change immediately after this call.
     * registerForServiceStateChanged() to find out when the
     * request is complete. This will set the reason for radio power state as {@link
     * android.telephony.TelephonyManager#RADIO_POWER_REASON_USER}. This will not guarantee that the
     * requested radio power state will actually be set.
     * See {@link #setRadioPowerForReason(boolean, boolean, boolean, boolean, int)}
     * for details.
     *
     * @param power true means "on", false means "off".
     */
    default void setRadioPower(boolean power) {
        setRadioPower(power, false, false, false);
    }

So this seems to be just a general on/off toggle and should not have power saving implications.

Disabling the "Cellular data" seems to only disable the data connection, not the telephony connection, and does not affect this message. Enabling "Flight Mode" does seem to make the message stop. Flight Mode also does seem to work because I can't call the mobile number anymore when flight mode is on.

So is this maybe just a bogus error?