[PSA] Android Marshmallow 6.0.1 breaks offline sync

[morticae]

Okay I think I've solved my own issue from another thread.  After checking out my logs, I'm fairly certain that a bug introduced in Android 6.0.1 release is responsible for breaking offline sync.  If you get an OS update you MAY want to hold off for a bit!

Model: Nexus 5x (yay for getting quick OS updates...)

OS Version: 6.0.1

Kernel: 3.10.73-gf215204

Build: MTC19Z (that's 6.0.1_r54)

Repro:

1) Update to 6.0.1

2) Mark songs as available offline

3) Downloading freezes and makes no progress

4) Go into settings and toggle Spotify app security permission for Storage off/on

5) Go back into Spotify app

6) Spotify will sync between 2 and 10 songs and then downloading stops once again

I hooked up adb and in the system logs I discovered a lot of this immediately after switching back to Spotify:

08-03 15:20:35.068: W/Binder_7(6216): type=1400 audit(0.0:2167): avc: denied { ioctl } for path="socket:[124745]" dev="sockfs" ino=124745 ioctlcmd=7704 scontext=u:r:system_server:s0 tcontext=u:r:system_server:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.071: I/sensors(4310): batch
08-03 15:20:35.068: W/Binder_7(6216): type=1400 audit(0.0:2168): avc: denied { ioctl } for path="socket:[124745]" dev="sockfs" ino=124745 ioctlcmd=7704 scontext=u:r:system_server:s0 tcontext=u:r:system_server:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.071: I/sensors(4310): activate
08-03 15:20:35.077: I/hubconnection(4310): sensorhub said: 'batch 1 flags:0, sampling_rate_Hz:6.25, max_report_latency_us:0'
08-03 15:20:35.078: I/hubconnection(4310): sensorhub said: 'activate 1 enable:1'
08-03 15:20:35.088: W/Binder_5(6706): type=1400 audit(0.0:2169): avc: denied { ioctl } for path="socket:[127650]" dev="sockfs" ino=127650 ioctlcmd=7704 scontext=u:r:surfaceflinger:s0 tcontext=u:r:surfaceflinger:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.088: W/Binder_5(6706): type=1400 audit(0.0:2170): avc: denied { ioctl } for path="socket:[127650]" dev="sockfs" ino=127650 ioctlcmd=7704 scontext=u:r:surfaceflinger:s0 tcontext=u:r:surfaceflinger:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.096: D/OpenGLRenderer(17485): Use EGL_SWAP_BEHAVIOR_PRESERVED: true
08-03 15:20:35.091: W/Binder_5(6706): type=1400 audit(0.0:2171): avc: denied { ioctl } for path="socket:[124748]" dev="sockfs" ino=124748 ioctlcmd=7704 scontext=u:r:surfaceflinger:s0 tcontext=u:r:surfaceflinger:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.091: W/Binder_5(6706): type=1400 audit(0.0:2172): avc: denied { ioctl } for path="socket:[124748]" dev="sockfs" ino=124748 ioctlcmd=7704 scontext=u:r:surfaceflinger:s0 tcontext=u:r:surfaceflinger:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.095: W/Binder_10(8201): type=1400 audit(0.0:2173): avc: denied { ioctl } for path="socket:[127654]" dev="sockfs" ino=127654 ioctlcmd=7704 scontext=u:r:system_server:s0 tcontext=u:r:system_server:s0 tclass=unix_stream_socket permissive=0
08-03 15:20:35.095: W/Binder_10(8201): type=1400 audit(0.0:2174): avc: denied { ioctl } for path="socket:[127654]" dev="sockfs" ino=127654 ioctlcmd=7704 scontext=u:r:system_server:s0 tcontext=u:r:system_server:s0 tclass=unix_stream_socket permissive=0

This appears to be a bug with accessing a property of a socket that shouldn't be accessed. A proposed back-port/fix is here.

I don't think it's the cause, but I also want to point out these logs I saw.  It seems that Spotify is having some kind of issue with loading my user data.  Could be related too.

08-03 15:20:35.906: W/ActivityManager(4310): Permission Denial: Accessing service ComponentInfo{com.google.android.music/com.google.android.music.dial.DialMediaRouteProviderService} from pid=17485, uid=10085 that is not exported from uid 10060
08-03 15:20:36.005: D/MdnsClient(5949): Multicast lock held. Releasing
08-03 15:20:36.015: D/MdnsClient(5949): #acquireLock. Multicast lock not held. Acquiring
08-03 15:20:36.295: E/Spotify(17485): [main@iyz:83] Error loading user data.