The Arcology Garden

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?

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 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.

shell source: :session *shell* :results none
export LOG_FILE=~/org/data/20/220412T115028.569214/adb-output 
adb logcat -d -v long > $LOG_FILE

shell source: :session *shell* :results verbatim
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"

python source: :session *adb-logcat-exploration*
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:

python source: :session *adb-logcat-exploration*
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.

python source: :session *adb-logcat-exploration*
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...

python source: :session *adb-logcat-exploration* :results none
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

python source: :session *adb-logcat-exploration*
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

python source: :session *adb-logcat-exploration* :results verbatim
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.

shell source: :session *shell* :results verbatim
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.

shell source: :session *shell* :results verbatim
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?

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...

shell source: :session *shell*
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:

python source: 
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

python source: :session *adb-logcat-exploration*
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...

python source: :session *adb-logcat-exploration* :results verbatim
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

python source: :session *adb-logcat-exploration* :results verbatim
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

python source: :session *adb-logcat-exploration* :results none
import matplotlib
import matplotlib.pyplot as plt
import seaborn

python source: :session *adb-logcat-exploration* :results file
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

python source: :session *adb-logcat-exploration*
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....

python source: :session *adb-logcat-exploration*
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 [[shell:adb shell dumpsys package > packages_dump.txt]]

shell source: :noweb yes :results verbatim
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

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....

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!

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?

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

emacs-lisp source: 
(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