Something on my phone is waiting for me to go to sleep to contact ad servers

I realized last week that my phone's DNS wasn't going through pihole -- part of this is Comcast xFI's fault, part of this is Android's fault, and some of it was simply my fault by making some overly-effective firewall rules to prevent my server from being an open DNS relay. Ultimately, I "fixed" it properly by pointing Tailscale's MagicDNS at one of my Tailscale nodes running a Pi Hole server and leaving Tailscale running on my phone. Bit of extra battery usage but not significant enough to care unless I'm using my server also as an Exit Node.

But then I looked at my traffic graphs:

i plugged my phone back in to my pihole and ... something is misbehaving :) making thousands of attempts to look up doubleclick and adsense. pic.twitter.com/axIwC9FFfU

— rrix (@rrrrrrrix) April 12, 2022

Something on my phone makes thousands of requests overnight to look up googleadservices.com and ad.doubleclick.net ... I smell an ad impression fraud playbook, or at least someone doing too many DNS lookups. While my pihole does have a nearly constant background chatter of ad-server lookups on the order of 1-3 per minute, overnight these jump up to nearly 25 per minute.

On the one hand, this is expected and accepted behavior on mobile devices despite being a huge freakin' problem, but this one in particular raised my hackles: those periods where it went crazy are more or less the exact times I was asleep, which is really disturbing that something might be monitoring me specifically to hide its activity. This is, at the very least spooky and at most a pretty blatant violation of Privacy norms. Or maybe it's only running when my phone is plugged in so that someone doesn't worry about battery usage.

But what is normal after all?

Can I figure out which app is doing this?

I poked around in network data usage screens and battery usage screens, but of course that didn't elucidate much. Maybe tomorrow night i'll leave my phone unplugged and see if the battery usage reflects that.

But is there anything in the phone's debug logs? I ran adb logcat and saved the output to a file for analysis:

link to adb logs attachment

It's easy enough to slurp this file in to Python to analyze it. If I want to do more I can pull in Pandas and Numpy to do some jupyter style exploration, but I want to see some simple distributions of the messages. Logcat can give me some of this.

export LOG_FILE=~/org/data/20/220412T115028.569214/adb-output 
adb logcat -d -v long > $LOG_FILE

adb logcat -S 2>/dev/null

size/num main               system             crash              kernel             Total
Total    3318391645/41278326781755684/1344098  10428/55           0/0                4100157757/42622479
Now      248415/2199        236848/4023        10428/55                              495691/6277
Logspan  3:46.125(9.6%)     5:09:02.418(3.2%)                                        5:09:08.87
Overhead 371559             462136             13508                                 2294731

Chattiest UIDs in main log buffer:                           Size   +/-  Pruned
UID   PACKAGE                                               BYTES           NUM
706
1011
  PID/UID   COMMAND LINE                                       "             "
  652/1000  /system/bin/servicemanager                      19760           997
 1360/1000  /system/vendor/bin/cnss-daemon                  14672            14
 1765/1000  system_server                                    3632
  653/1000  /system/bin/hwservicemanager                      554
100
24
10206 com.google.android.inputmethod.latin                  28125  +61%
10457 com.google.android.providers.media.module             21991  +60%
1002  bluetooth                                             11673  +59%
1010  wifi                                                  10036  +60%
10167 com.google.android.gms                                 4527  +64%
10202 com.google.android.youtube                             4017  +60%
1010451 com.qualcomm.qti.devicestatisticsservice             3706  +56%
10451 com.qualcomm.qti.devicestatisticsservice               3612  +56%
0     root                                                   2073  +60%
10316 com.nextcloud.client                                   1340  +67%
10327 com.digibites.calendarplus                              965  +50%
1036  auditd                                                  828  +50%
1001  radio                                                   819  +50%
1010167 com.google.android.gms                                697  2.0X
10325 com.jumboprivacy                                        637  2.0X       1
10269 com.getsomeheadspace.android                            480
10123 com.android.vending                                     457


Chattiest UIDs in system log buffer:                         Size   +/-  Pruned
UID   PACKAGE                                               BYTES           NUM
24886
10263 com.nutomic.syncthingandroid                           4726  20X
10062 com.android.calllogbackup                              3051  13X
10135 com.android.systemui                                   2842  12X


Chattiest UIDs in crash log buffer:                          Size
UID   PACKAGE                                               BYTES
10206 com.google.android.inputmethod.latin                   7692
10286 appyweather.appyweather                                1601
1000  system                                                 1009
0     root                                                    126

None of this is particularly ... exciting or elucidating is it? the biggest logging systems which jump out to me are my keyboard input method, the media scanner which gets confused trying to analyze all the files I plug in to the device via Syncthing, YouTube, my calendar app... hmm. not much "there there"

import pathlib
in_file = pathlib.Path("data/20/220412T115028.569214/adb-output")
assert in_file.exists()

output = ''
with open(in_file, "r") as f:
  output = f.read()
assert len(output) > 0

blocks = output.split("\n\n")
[[block] for block in blocks[0:5]]

so using adb with -v long like i did breaks each message in to blocks separated by a blank line. good enough to parse like this, especially since all I really care about is the metadata header, usually the first line -- the first record looks corrupted but who knows.. let's see:

headers = []
import re

for block in blocks:
    lines = re.split("\n+", block)
    header = list(filter(lambda line: line.startswith("[") and line.endswith("]"), lines))
    second_line = ("\n".join(lines[2:]))
    headers.append(header + [second_line])

# only print the uhh header
[[header[0]] for header in headers[0:10]]

Cool so now all my headers are extracted, let's parse this! it's not exactly trivial, of course these lines aren't regular, you can see that they are generally set to the same column, especially the fields I care about (time, and that last field, the emitting module). we'll be ugly about it.

import re
from datetime import datetime

export = []

for header in headers:
    try:
        working_header = header[0]
    except IndexError:
        print("bad header: {}".format(header))
        continue
    parts = re.split(r"\s+", working_header)
    try:
        burp = "2022-{} {}000".format(parts[1], parts[2]) # (ref:burp)
        assembly = [datetime.strptime(burp, "%Y-%m-%d %H:%M:%S.%f"), parts[-2], header[-1]]
        export.append(assembly)
    except IndexError:
        continue

len(export)

: 7476

I am lazy with intermediate variable names.. (burp) takes the date and time and crams them in to a thing I can call datetime.strptime on & parts[-2] is the second to last element from that header, the Android module which emitted it.

And so I want all the messages between 21:00 and 09:00... I could do this within the logcat invocation, I probably should, but let's do some more nasty shit with datetime since i'm already invoking strptime...

start_window = datetime(2022, 4, 11, 22, 0)
end_window = datetime(2022, 4, 12, 9, 0)
def date_filter_fn(pair):
    dt = pair[0]
    if dt > start_window and dt < end_window:
        return True
    return False

filtered = list(filter(date_filter_fn, export))
len(filtered)

: 1660

That's not as much I would have hoped!! Let's see where they come from

sum_map = {}
for msg in filtered:
  module = msg[1]
  sum_map[module] = sum_map.get(module, 0) + 1

sum_map

{'F/libc': 1, 'F/DEBUG': 50, 'I/chatty': 1576, 'D/ActivityThread': 12, 'W/Looper': 4, 'W/ActivityThread': 4, 'W/SocketClient': 1, 'D/KeyguardViewMediator': 6, 'E/ActivityThread': 2, 'V/FingerprintManager': 2, 'V/MotoFingerprintManager': 2}

So chatty is .. chatty? grr.

grep -A1 "I/chatty" $LOG_FILE | head

[ 04-12 07:38:15.795  1765: 5526 I/chatty   ]
uid=1000(system) Binder:1765_C expire 2 lines
--
[ 04-12 07:38:16.708  1765: 4195 I/chatty   ]
uid=1000(system) Binder:1765_7 expire 2 lines
--
[ 04-12 07:38:16.858  1765: 6374 I/chatty   ]
uid=1000(system) Binder:1765_16 expire 2 lines
--
[ 04-12 07:38:17.119  1765: 1765 I/chatty   ]

Well that's not so useful is it... some things are being too chatty and being elided from the logs

Same string extraction gymnastics... Tired of ugly python? so am i... enjoy an ugly shell pipeline! one day maybe i'll just learn awk outright.

grep -A1 "I/chatty" $LOG_FILE | grep expire | awk '{print $2}' | sed -e 's/:.*//' | sort | uniq -c | sort -nr

2177 Binder
    478 ActivityManager
    383 UEventObserver
    250 ConnectivitySer
    240 system_server
     72 android.anim
     71 android.display
     65 batterystats-wo
     53 android.ui
     50 android.fg
     48 PowerManagerSer
     44 android.bg
     26 expire
     20 /system/bin/servicemanager
     11 SyncManager
      9 onProviders.ECP
      6 Thread-8
      6 ranker
      6 HwBinder
      6 /data/app/~~bXf7VcDuNg7_iWAGE_Bdiw==/com.nutomic.syncthingandroid-vk_6lW7Ia1yF2y1eCZsdjg==/lib/arm64/libsyncthing.so
      5 InputReader
      4 NetworkStats
      4 backup
      3 /system/bin/ip
      2 Thread-48341
      2 android.io
      2 AlarmManager
      1 Thread-48342
      1 Thread-48340
      1 Thread-48336
      1 /system/vendor/bin/cnss-daemon
      1 NetworkWatchlis
      1 com.fastmail.app
      1 backup-0
      1 AdbDebuggingMan

so this is a dead end to tracking this down, it seems -- I'm sure I gave "informed consent" when I installed whatever app is tracking my sleep schedule to run advertising fraud schemes.

What's next, must I install network monitoring software directly on my phone to track this down?

What about dumpsys output?

Okay that was a dead end ... Poking around on some poorly stack overflow questions and SEO'd android dev blog google results, i found that there is a command in Android systems called dumpsys which will ... dump system information to the terminal. In particular, it can dump detailed network statistics broken down by the process UID responsible for the traffic. Since my phone isn't doing a whole lot over night, in theory those 20000+ DNS requests should wind up in here somehow one hopes...

adb shell dumpsys netstats detail > /tmp/netstats
echo "[[file:/tmp/netstats]]"

The output of the dumpsys command is just barely structured...

what if i yaml load it lul:

import yaml

try: 
   with open("/tmp/netstats", "r") as f:
      dictmaybe = yaml.safe_load(f.read())
except Exception:
   dictmaybe = "lol no"

dictmaybe

: lol no

cool so i gotta parse this wordsoup myself

import pathlib
import re
from datetime import datetime

lines = pathlib.Path("/tmp/netstats").read_text().split("\n")

PARSE_STATE = None
curr_uid = None

parsed_data = []

for line in lines:
  if line.startswith("UID stats"):
    PARSE_STATE = "UID"
    continue

  if PARSE_STATE is not None:
    match = re.search(r"^(?P<whitespace> +)", line)

    if match is None:
      print("nope")
      level = 0
      PARSE_STATE = None
      curr_uid = None
      continue

    level = int(len(match.group("whitespace")) / 2)
    if level == 1 and line.startswith("  ident"):
      # extract UID
      m = re.search(r"uid=(?P<uid>\d+)", line)
      if not m:
        pass
        #print("line bad {}".format(line))
      else:
        curr_uid = m.group("uid") 

    if level == 3:
      # example line
      # st=1648792800 rb=0 rp=0 tb=76 tp=1 op=0
      m = re.search(r"st=(?P<st>\d+) rb=(?P<rb>\d+).*tb=(?P<tb>\d+).*", line)
      if m is None:
        print("uhh {}".format(line))
        continue

      ts = datetime.fromtimestamp(int(m.group("st")))

      parsed_data.append([ts, curr_uid, m.group("rb"), m.group("tb")])

len(parsed_data)

: 8245

Now we can shove the dataframe in to Pandas and plot the output...

import pandas as pd

time_index = [r[0] for r in parsed_data]
uid_index = [r[1] for r in parsed_data ]
midx = pd.MultiIndex.from_arrays([time_index, uid_index], names=["ts", "uid"])

df = pd.DataFrame(data=parsed_data, columns=["ts", "uid", "rx", "tx"], index=time_index)
df = df.sort_index()
df['ts'] = pd.to_datetime(df['ts'])  
df['rx'] = pd.to_numeric(df['rx'])  
df['tx'] = pd.to_numeric(df['tx'])  
df['uid'] = pd.to_numeric(df['uid'])  
df.head()

: ts uid rx tx : 2022-03-31 23:00:00 2022-03-31 23:00:00 10187 25594 8944 : 2022-03-31 23:00:00 2022-03-31 23:00:00 10316 137686 31767 : 2022-03-31 23:00:00 2022-03-31 23:00:00 10315 67770 24965 : 2022-03-31 23:00:00 2022-03-31 23:00:00 1010223 275681 77330 : 2022-03-31 23:00:00 2022-03-31 23:00:00 10307 87947 42552

downsize = df.loc["2022/04/11 02:00":"2022/04/12 09:00"]
downsize.head()

: ts uid rx tx : 2022-04-11 03:00:00 2022-04-11 03:00:00 10009 845261 626572 : 2022-04-11 03:00:00 2022-04-11 03:00:00 10125 736 560 : 2022-04-11 03:00:00 2022-04-11 03:00:00 10459 60067 26615 : 2022-04-11 03:00:00 2022-04-11 03:00:00 10264 553 250 : 2022-04-11 03:00:00 2022-04-11 03:00:00 10205 9992 4444

import matplotlib
import matplotlib.pyplot as plt
import seaborn

uids = downsize["uid"].unique()
fig, ax = plt.subplots()
seaborn.set_style("ticks")
for uid in uids:
    this_uid_df = downsize.loc[downsize["uid"]==uid]
    total_bytes = this_uid_df["tx"].sum()
    if total_bytes > 64000:
        seaborn.lineplot(
            ax=ax,
            data=this_uid_df.groupby("ts").sum(),
            legend="full",
            y="tx", x="ts",
            palette="deep",
            label=f"{uid} ({total_bytes})", 
        )

h,l = ax.get_legend_handles_labels()
ax.legend_.remove()

fig.autofmt_xdate()
fig.legend(h, l, loc="center right", ncol=4, mode="tight", fontsize=6)

loc = 'data/20/220412T115028.569214/plt1.png'
fig.savefig(loc, bbox_inches=matplotlib.transforms.Bbox([[0,0],[11,5]]))
loc

some interesting outliers, but no idea which... Let's see

maxis = downsize.groupby("uid")["tx"].sum().sort_values().iloc[::-1]
maxis[0:19]

uid
10009      38107508
10316      14349564
10329      13844479
10263      11445899
10195       7216042
10282       6528796
10167       5088949
10276       4504974
10325       4177685
0           3882100
10123       3757039
10250       3587922
10125       2573676
10281       2539344
10202       1615213
1010123     1572069
1010125     1437782
10274       1423099
10218       1410081
Name: tx, dtype: int64

And the top 10 UIDs are....

top10 = maxis.index[0:50].astype(str)
"\n".join(top10)

10009
10316
10329
10263
10195
10282
10167
10276
10325
0
10123
10250
10125
10281
10202
1010123
1010125
10274
10218
1010228
10318
1010167
10247
10191
10264
10343
10286
10272
10307
1073
10185
10186
10285
1010205
10270
10278
1010185
10337
10287
10136
10279
10269
10204
10205
10254
10112
10459
10209
1000
1010223

Okay so ... this gives me the maximum transmitted bytes in the 2 hour sampling window, which is quite useful. Using a different dumpsys command I can figure out which will export information about the packages including the UID mapping.

run in adb shell dumpsys package > packages_dump.txt

export PKG_FILE=data/20/220412T115028.569214/packages_dump.txt

function finduid() {
  echo -ne "$1 "
  (grep -F -B1 "userId=$1" $PKG_FILE || echo "unknown") | head -1 
}

finduid <<top-10-network-uids()>>

10009   Package [com.tailscale.ipn] (15c63bb):
10316   Package [com.nextcloud.client] (8557d8e):
10329   Package [com.urbandroid.sleep.addon.port] (9289605):
10263   Package [com.nutomic.syncthingandroid] (62758f2):
10195   Package [com.google.android.apps.youtube.music] (2d9cbd):
10282   Package [org.mozilla.firefox] (3eb3ec8):
10167   Package [com.google.android.gms] (34fe9b0):
10276   Package [reddit.news] (e0e810b):
10325   Package [com.jumboprivacy] (182b16):
0   Session 3187895:
10123   Package [com.android.vending] (1e9a0f3):
10250   Package [im.vector.app] (a9196df):
10125   Package [com.google.android.googlequicksearchbox] (aa27695):
10281   Package [com.urbandroid.sleep] (72e44f5):
10202   Package [com.google.android.youtube] (cde6cf2):
1010123 unknown
1010125 unknown
10274   Package [com.fastmail.app] (2950a72):
10218   Package [com.google.android.apps.maps] (5781bd6):
1010228 unknown
10318   Package [com.amtrak.rider] (15aeca7):
1010167 unknown
10247   Package [org.wikipedia] (4eb34cd):
10191   Package [com.google.android.apps.messaging] (964e000):
10264   Package [org.thoughtcrime.securesms] (d548d43):
10343   Package [com.joelapenna.foursquared] (da3d527):
10286   Package [appyweather.appyweather] (c92a9d2):
10272   Package [net.daylio] (cc56e43):
10307   Package [au.com.shiftyjelly.pocketcasts] (fd687df):
1073   Package [com.google.android.networkstack.tethering] (8b64538):
10185   Package [com.google.android.gm] (c22cfc7):
10186   Package [com.google.android.apps.photos] (3a6bf15):
10285   Package [com.google.android.apps.googlevoice] (7af19a6):
1010205 unknown
10270   Package [com.thetransitapp.droid] (464161b):
10278   Package [com.google.android.apps.translate] (d9af303):
1010185 unknown
10337   Package [com.discord] (ac80e48):
10287   Package [org.owntracks.android] (bc7083a):
10136   Package [com.google.android.dialer] (66db079):
10279   Package [com.bandcamp.android] (f39fab3):
10269   Package [com.getsomeheadspace.android] (208cd9):
10204   Package [com.google.android.apps.docs] (43008d0):
10205   Package [com.google.android.calendar] (dc1f0dc):
10254   Package [com.peterjosling.scroball] (a00421):
10112   Package [com.motorola.gamemode] (1226818):
10459   Package [gov.wa.doh.exposurenotifications] (6c2971b):
10209   Package [com.google.android.apps.tachyon] (c3a03b6):
1000   Package [com.tailscale.ipn] (15c63bb):
1010223 unknown

Analyzing the list of "network-noisy" packages

Okay, so we've narrowed it down --

let's skim through this list and see if anything that shouldn't be there hops out at me...

com.urbandroid.sleep.addon.port is the sleep tracker i use, and it does make a shitload of network calls. This isn't surprising as I have their cloud backup enabled with data going back to 2012. I've been paying for it, so I'll be pretty sour if they're running ad-fraud on my phone.

Tailscale, Nextcloud, Syncthing, Firefox (with ublock origin, etc addons installed), shouldn't be doing these things and will have a lot of natural network traffic. I sure hope I can trust these things as I can't feasibly replace them.

reddit.news is Relay for reddit which is the reddit mobile app I use , I wouldn't put it past them or some JS loaded in a site's web frame, but it happens regularly.

com.amtrak.rider could be doing mean things, their site already runs a bunch of spy-ing bullshit... but background ad-fraud? idk.

net.daylio is a mood/habit tracking app which has a nightly automated backup function. I hope they're not doing anything untoward

Some com.google packages, they wouldn't ad fraud themselves right?

com.jumboprivacy which is a paid service to run little privacy preserving scripts against web services on your device... uh huh...

The google quick search is a bit surprising to me, I suppose.

And of course there are some things being run as root (uid 0), and some other high-level UIDs which aren't reflected in my package list....

Something approaching a conclusion

All of this leaves me where I started, confused and a bit disoriented, unsure of what is happening on my own device in my own home and basically powerless to do anything about it.

But it raises a lot of questions, of course the main one being "what did I learn"

I learned that:

• the android system environment is always doing "something", and is usually too chatty about what those "something"s are for you to be able to really see why.

• adb dumpsys has a lot of useful information about your phone including timeseries data.

• there is always basically unsurprising data usage "at scale" in my phone.

Another question: did i actually learn anything useful in these stats? Remember that this all started with tracking down DNS traffic, which of course is miniscule compared to even a single JPG or /r/formula1 comment thread loaded by Relay. In reality, any app on my system could be running a campaign like this, and there are not a lot of tools to explore this data usage.

Of course, you gave your "informed consent" when you installed these apps!

What is there to do for someone who doesn't consent?

dark laughter

how do you feel about the unabomber manifesto?

...

I'll disable some of these apps or at least force close them tonight and see how many times we try to load ad-impressions overnight.

I also noticed within the dumpsys service was a way to dump the active "activities" on an Android device. I'll set up ADB in a cron job and see what sort of interesting things run overnight, perhaps. write some awful plain-text parser again to extract the useful bits of data out of it.

My Librem 5 will supposably ship soon, and while it'll be nice to have something approaching a libre or at least introspectable userspace, and a set of mostly functional free apps, there are parts of my life that won't fit on this device. Even if it's living in a desk drawer 18 hours a day, if it's just running weird ad campaigns while I sleep or while it charges, should I feel okay with that?

How should I?

Note to self on opening this doc:

Make sure to hack in a python for the session, don't feel like putting this somewhere for direnv

(setq org-babel-python-command (concat (s-chomp (shell-command-to-string "nix-build ~/org/nix-shells/python-pandas.nix"))
                                       "/bin/python")))

: /nix/store/jnvmbh39cfr8hsifc6ql40np0a1bmaxx-python3-3.9.10-env/bin/python