1

I have a pi 3 with Android Things that I use to control an irrigation system. It connects to wifi, gets the weather forecast and controls the irrigation valves based on the weather info. It runs NanoHttpd to provide a server so that I can control the system through a web interface, view log files etc.

It's working great, but not reliably. I usually find it offline each morning and have to reboot it. I'm wondering if failing updates are the issue? Here are some of the error messages listed overnight. Can anyone suggest an area I should look into? If updating is an issue, is there any way I can disable that? The only network interaction I'd like to see is checking the weather and operating as a server.

Thanks.

019-04-10 11:20:29.701 296-449/system_process E/TaskPersister: File error accessing recents directory (directory doesn't exist?).

2019-04-10 11:46:21.432 296-314/system_process E/KernelUidCpuFreqTimeReader: Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
2019-04-10 11:46:21.434 296-314/system_process E/KernelWakelockReader: neither /proc/wakelocks nor /d/wakeup_sources exists

2019-04-10 12:16:21.442 296-314/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for wifi
2019-04-10 12:16:21.442 296-314/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for bluetooth
2019-04-10 12:16:21.442 296-314/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for telephony
2019-04-10 12:16:21.444 296-314/system_process E/KernelUidCpuFreqTimeReader: Failed to read /proc/uid_time_in_state: java.io.FileNotFoundException: /proc/uid_time_in_state (No such file or directory)
2019-04-10 12:16:21.445 296-314/system_process E/KernelWakelockReader: neither /proc/wakelocks nor /d/wakeup_sources exists
2019-04-10 12:16:21.445 296-314/system_process W/BatteryStatsImpl: Couldn't get kernel wake lock stats

2019-04-10 12:52:36.895 296-1204/system_process W/WindowManager: Permission Denial: dismissKeyguard from pid=2580, uid=2000 requires android.permission.CONTROL_KEYGUARD

2019-04-11 22:14:53.783 736-1162/com.google.android.gms.persistent W/Conscrypt: Could not set socket write timeout: java.lang.reflect.InvocationTargetException
2019-04-11 22:14:53.783 736-1162/com.google.android.gms.persistent W/Conscrypt:     at java.lang.reflect.Method.invoke(Native Method)
2019-04-11 22:14:53.783 736-1162/com.google.android.gms.persistent W/Conscrypt:     at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@12520015@12.5.20 (030300-189423146):13)
2019-04-11 22:14:53.783 736-1162/com.google.android.gms.persistent W/Conscrypt: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor)
2019-04-11 22:14:53.783 736-1162/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.Linux.setsockoptTimeval(Native Method)
2019-04-11 22:14:53.783 736-1162/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.ForwardingOs.setsockoptTimeval(ForwardingOs.java:175)
2019-04-11 22:14:53.882 736-1162/com.google.android.gms.persistent W/Conscrypt: Could not set socket write timeout: java.lang.reflect.InvocationTargetException
2019-04-11 22:14:53.883 736-1162/com.google.android.gms.persistent W/Conscrypt:     at java.lang.reflect.Method.invoke(Native Method)
2019-04-11 22:14:53.883 736-1162/com.google.android.gms.persistent W/Conscrypt:     at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@12520015@12.5.20 (030300-189423146):13)
2019-04-11 22:14:53.883 736-1162/com.google.android.gms.persistent W/Conscrypt: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor)
2019-04-11 22:14:53.883 736-1162/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.Linux.setsockoptTimeval(Native Method)
2019-04-11 22:14:53.883 736-1162/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.ForwardingOs.setsockoptTimeval(ForwardingOs.java:175)
2019-04-11 22:14:54.021 736-1162/com.google.android.gms.persistent W/GLSUser: [AppCertManager] IOException while requesting key: 
    java.io.IOException: Invalid device key response.

2019-04-11 22:16:22.186 296-372/system_process E/WifiVendorHal: getSupportedFeatureSet(l.891) failed {.code = ERROR_NOT_AVAILABLE, .description = }
2019-04-11 22:16:22.187 296-372/system_process E/WifiVendorHal: getSupportedFeatureSet(l.897) failed {.code = ERROR_NOT_AVAILABLE, .description = }
2019-04-11 22:16:22.190 296-314/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for wifi
2019-04-11 22:16:22.190 296-314/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for bluetooth
2019-04-11 22:16:22.190 296-314/system_process E/BatteryExternalStatsWorker: no controller energy info supplied for telephony
2019-04-11 22:16:22.193 296-314/system_process E/KernelWakelockReader: neither /proc/wakelocks nor /d/wakeup_sources exists
2019-04-11 22:16:22.194 296-314/system_process W/BatteryStatsImpl: Couldn't get kernel wake lock stats

2019-04-11 22:43:53.485 736-9107/com.google.android.gms.persistent E/WakeLock: release without a matched acquire!
2019-04-11 22:43:53.526 296-443/system_process I/WifiService: getConnectionInfo uid=10012
2019-04-11 22:43:53.920 736-9954/com.google.android.gms.persistent W/Conscrypt: Could not set socket write timeout: java.lang.reflect.InvocationTargetException
2019-04-11 22:43:53.921 736-9954/com.google.android.gms.persistent W/Conscrypt:     at java.lang.reflect.Method.invoke(Native Method)
2019-04-11 22:43:53.921 736-9954/com.google.android.gms.persistent W/Conscrypt:     at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@12520015@12.5.20 (030300-189423146):13)
2019-04-11 22:43:53.921 736-9954/com.google.android.gms.persistent W/Conscrypt: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor)
2019-04-11 22:43:53.921 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.Linux.setsockoptTimeval(Native Method)
2019-04-11 22:43:53.921 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.ForwardingOs.setsockoptTimeval(ForwardingOs.java:175)
2019-04-11 22:43:54.013 736-9954/com.google.android.gms.persistent W/Conscrypt: Could not set socket write timeout: java.lang.reflect.InvocationTargetException
2019-04-11 22:43:54.013 736-9954/com.google.android.gms.persistent W/Conscrypt:     at java.lang.reflect.Method.invoke(Native Method)
2019-04-11 22:43:54.013 736-9954/com.google.android.gms.persistent W/Conscrypt:     at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@12520015@12.5.20 (030300-189423146):13)
2019-04-11 22:43:54.013 736-9954/com.google.android.gms.persistent W/Conscrypt: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor)
2019-04-11 22:43:54.013 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.Linux.setsockoptTimeval(Native Method)
2019-04-11 22:43:54.013 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.ForwardingOs.setsockoptTimeval(ForwardingOs.java:175)
2019-04-11 22:43:54.174 736-9954/com.google.android.gms.persistent W/Conscrypt: Could not set socket write timeout: java.lang.reflect.InvocationTargetException
2019-04-11 22:43:54.175 736-9954/com.google.android.gms.persistent W/Conscrypt:     at java.lang.reflect.Method.invoke(Native Method)
2019-04-11 22:43:54.175 736-9954/com.google.android.gms.persistent W/Conscrypt:     at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@12520015@12.5.20 (030300-189423146):13)
2019-04-11 22:43:54.175 736-9954/com.google.android.gms.persistent W/Conscrypt: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor)
2019-04-11 22:43:54.175 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.Linux.setsockoptTimeval(Native Method)
2019-04-11 22:43:54.175 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.ForwardingOs.setsockoptTimeval(ForwardingOs.java:175)
2019-04-11 22:43:54.203 736-9954/com.google.android.gms.persistent W/Conscrypt: Could not set socket write timeout: java.lang.reflect.InvocationTargetException
2019-04-11 22:43:54.203 736-9954/com.google.android.gms.persistent W/Conscrypt:     at java.lang.reflect.Method.invoke(Native Method)
2019-04-11 22:43:54.203 736-9954/com.google.android.gms.persistent W/Conscrypt:     at com.google.android.gms.org.conscrypt.Platform.setSocketWriteTimeout(:com.google.android.gms@12520015@12.5.20 (030300-189423146):13)
2019-04-11 22:43:54.204 736-9954/com.google.android.gms.persistent W/Conscrypt: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor)
2019-04-11 22:43:54.204 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.Linux.setsockoptTimeval(Native Method)
2019-04-11 22:43:54.204 736-9954/com.google.android.gms.persistent W/Conscrypt:     at libcore.io.ForwardingOs.setsockoptTimeval(ForwardingOs.java:175)

2019-04-11 23:40:15.666 998-9936/com.google.android.gms W/OkHttpClient: A connection to https://www.googleapis.com/ was leaked. Did you forget to close a response body?

2019-04-12 03:22:53.060 393-436/com.google.android.things.internal.devicemanagement V/UpdateManagementServiceImpl: Received StatusUpdate from update_engine: UPDATE_STATUS_CHECKING_FOR_UPDATE
2019-04-12 03:22:53.060 211-211/? I/update_engine: [0412/022253:INFO:action_processor.cc(46)] ActionProcessor: starting OmahaRequestAction
2019-04-12 03:22:53.062 211-211/? I/update_engine: [0412/022253:INFO:omaha_request_action.cc(772)] Posting an Omaha request to https://clients2.google.com/service/update2/brillo
2019-04-12 03:22:53.062 211-211/? I/update_engine: [0412/022253:INFO:omaha_request_action.cc(773)] Request: <?xml version="1.0" encoding="UTF-8"?>
    <request protocol="3.0" version="Brillo-0.1.0.0" updaterversion="Brillo-0.1.0.0" installsource="scheduler" ismachine="1">
        <os version="1.0.10.5360514" platform="Brillo" sp="12_armv7l"></os>
        <app appid="android-things:h1ffkm" cohort="1:1:" cohortname="stable-channel" version="12" track="stable-channel" _a.6jek27.version="1063" _a.ce6ks2.version="3" _a.dple2g.version="1" _a.ma8ki1.version="2" _g.gms_core.version="12520015.5360514" fingerprint="Things/iot_rpi3/rpi3:8.1.0/OIM1.180327.081/5360514:userdebug/dev-keys" os_build_type="userdebug" lang="en-US" board="iot_rpi3" hardware_class="Google::" delta_okay="true" fw_version="" ec_version="" installdate="4459" >
            <updatecheck targetversionprefix=""></updatecheck>
        </app>
        <app appid="android-things:som-rpi3" cohort="1:1:" cohortname="stable-channel" version="1.0.10.5360514" track="stable-channel" fingerprint="Things/iot_rpi3/rpi3:8.1.0/OIM1.180327.081/5360514:userdebug/dev-keys" os_build_type="userdebug" lang="en-US" board="iot_rpi3" hardware_class="Google::" delta_okay="true" fw_version="" ec_version="" installdate="4459" >
            <updatecheck targetversionprefix=""></updatecheck>
        </app>
    </request>
2019-04-12 03:22:53.062 211-211/? I/update_engine: [0412/022253:INFO:libcurl_http_fetcher.cc(146)] Starting/Resuming transfer
2019-04-12 03:22:53.062 211-211/? I/update_engine: [0412/022253:INFO:libcurl_http_fetcher.cc(165)] Using proxy: no
2019-04-12 03:22:53.063 211-211/? I/update_engine: [0412/022253:INFO:libcurl_http_fetcher.cc(308)] Setting up curl options for HTTPS
2019-04-12 03:22:54.158 211-211/? I/update_engine: [0412/022254:INFO:metrics_reporter_omaha.cc(499)] Uploading 0 for metric UpdateEngine.CertificateCheck.UpdateCheck
...
2019-04-12 03:22:56.231 211-211/? E/update_engine: [0412/022256:ERROR:utils.cc(192)] fd >= 0 failed: No such file or directory
2019-04-12 03:22:56.231 211-211/? E/update_engine: [0412/022256:ERROR:cpu_limiter.cc(74)] Failed to change cgroup cpu shares to 2 using /sys/fs/cgroup/cpu/update-engine/cpu.shares
2019-04-12 03:22:56.231 211-211/? I/update_engine: [0412/022256:INFO:action_processor.cc(116)] ActionProcessor: finished OmahaResponseHandlerAction with code ErrorCode::kOmahaUpdateDeferredPerPolicy
2019-04-12 03:22:56.231 393-438/com.google.android.things.internal.devicemanagement V/UpdateManagementServiceImpl: Received StatusUpdate from update_engine: UPDATE_STATUS_UPDATE_AVAILABLE
2019-04-12 03:22:56.231 211-211/? I/update_engine: [0412/022256:INFO:action_processor.cc(121)] ActionProcessor: Aborting processing due to failure.
2019-04-12 03:22:56.231 211-211/? I/update_engine: [0412/022256:INFO:update_attempter.cc(920)] Processing Done.
2019-04-12 03:22:56.232 211-211/? E/update_engine: [0412/022256:ERROR:update_attempter.cc(1313)] Update failed.

Update:
I have been looking at a number of posts about failing SD cards, and as I'm on my second - with an app that does very little read/write once it's running - I decided to act on the unproven notion that the card is at fault. I have ordered an expensive industrial one - after all, I'm trying to set up an irrigation system that is reliable. Just failing for one hot day would be disastrous.

Regarding your updated answer:

directory/file permissions are not changed. Does the execution account changes to another with less rights? No Are there network shares involved? No Maybe the storage place or disk is full? Definitely not What do you find with journalctl -b -e before rebooting? journalctl Not found

Anyway, hopefully a few months down the line I'll remember to report back that the industrial SD card solved the problem (ATP 8 GB MicroSDHC Card Class 10).

  • You wrote that there is no command journalctl. This command is available by default on Raspbian. What operating system do you use? – Ingo Apr 12 at 21:00
  • I'm using Android Things - sorry I forgot to mention that. – pir8ped Apr 13 at 12:03
0

There are many indicators that access to the SD Card is a problem (directory doesn't exist, No such file or directory, Bad file descriptor, etc). At the first glance it seems that your SD Card has get a very bad performance or may be broken. I would suggest to try a new SD Card.

Nearly all error messages say they cannot access data. You may have a look for another reason. Does directory/file permissions changed? Does the execution account changes to another with less rights? Are there network shares involved? Maybe the storage place or disk is full? What do you find with journalctl -b -e before rebooting? You mentioned failing updates. Does an update have failed?

  • That would be disappointing! I replaced the card maybe 2-3 weeks ago and it doesn't get much use - just recording irrigation events etc. I doubt it has more then a few hundred read/writes per day. I have a spare, but the setup being headless and wired in, changing the card isn't trivial. It's a Kingston 16Gb. Is there something more reliable? – pir8ped Apr 12 at 11:02
  • @pir8ped I have updated the answer. – Ingo Apr 12 at 11:40
  • I have now replaced the SD card, but I still get the app crashing with the same error message: Caused by: android.system.ErrnoException: setsockopt failed: EBADF (Bad file descriptor) 2019-04-11 22:43:53.921 736-9954/com.google.android.gms.persistent W/Conscrypt: at libcore.io.Linux.setsockoptTimeval(Native Method) I can't identify my own code as being the cause of the problem. – pir8ped Apr 16 at 8:06
  • @pir8ped Sorry, but I'm not familiar with Android Things. – Ingo Apr 16 at 8:28

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.