redex
redex copied to clipboard
facebook
R8 rejects DebugInfo
Background In our build pipeline, D8 is ran after Redex on some of our DEX files which fails on parsing debug info.
Stacktraces
Stacktrace 1:
[CIRCULAR REFERENCE:java.lang.AssertionError]
Caused by: java.lang.AssertionError
at com.android.tools.r8.utils.LebUtils.parseUleb128(LebUtils.java:26)
at com.android.tools.r8.dex.BinaryReader.getUleb128(BinaryReader.java:44)
at com.android.tools.r8.dex.DexParser.parseDebugInfo(DexParser.java:501)
at com.android.tools.r8.dex.DexParser.cacheAt(DexParser.java:418)
at com.android.tools.r8.dex.DexParser.debugInfoAt(DexParser.java:497)
at com.android.tools.r8.dex.DexParser.parseCodeItem(DexParser.java:897)
at com.android.tools.r8.dex.DexParser.ensureCodesInited(DexParser.java:162)
at com.android.tools.r8.dex.DexParser.readMethods(DexParser.java:642)
at com.android.tools.r8.dex.DexParser.addClassDefsTo(DexParser.java:746)
at com.android.tools.r8.dex.ApplicationReader$ClassReader.lambda$readDexSources$0(ApplicationReader.java:279)
at java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec(ForkJoinTask.java:1386)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
Stacktrace 2:
Caused by: java.lang.AssertionError
at com.android.tools.r8.dex.JumboStringRewriter.recordDebugEventTargets(JumboStringRewriter.java:519)
at com.android.tools.r8.dex.JumboStringRewriter.recordTargets(JumboStringRewriter.java:587)
at com.android.tools.r8.dex.JumboStringRewriter.rewrite(JumboStringRewriter.java:113)
at com.android.tools.r8.graph.DexEncodedMethod.rewriteCodeWithJumboStrings(DexEncodedMethod.java:1155)
at com.android.tools.r8.dex.ApplicationWriter.lambda$rewriteCodeWithJumboStrings$3(ApplicationWriter.java:573)
at com.android.tools.r8.graph.DexClass.forEachMethod(DexClass.java:315)
at com.android.tools.r8.dex.ApplicationWriter.rewriteCodeWithJumboStrings(ApplicationWriter.java:570)
at com.android.tools.r8.dex.ApplicationWriter.lambda$write$1(ApplicationWriter.java:293)
at java.util.concurrent.ForkJoinTask$AdaptedCallable.exec(ForkJoinTask.java:1424)
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
I'm able to resolve the first stacktrace by cherrypicking the following commits related to DebugInfo into stable:
- c811108ae68a3496b47817f50d96e4156315b9cd
- 23daef8a861e5cb54de2a767db46015964d973b3
- d55a36422cc5ec8c386db95df47f18dfb8fd7c07
- 86a96e90f6ad95f4432034ced76a6e4e5b7cb63c
- b9cd1537f738fd4239ecef9f2b9be804336e00b4
For the second stacktrace, I did not see any fixes related to JumboStrings. Here is the relevant info from r8 debugging:
// <PC>: <PC in hex>: <instruction>
0: 0x00: ConstClass v2, java.io.IOException
2: 0x02: CheckCast v5, com.google.android.gms.tasks.zzu
4: 0x04: IgetObject v3, v5, Field java.lang.Object com.google.android.gms.tasks.zzu.mLock
6: 0x06: MonitorEnter v3
7: 0x07: IgetBoolean v1, v5, Field boolean com.google.android.gms.tasks.zzu.zzagf
9: 0x09: ConstString v0, "Task is not yet complete"
11: 0x0b: InvokeStatic { v1 v0 } Lcom/google/android/gms/ads/impl/R$string;->checkState(ZLjava/lang/Object;)V
14: 0x0e: IgetBoolean v0, v5, Field boolean com.google.android.gms.tasks.zzu.zzfi
16: 0x10: IfNez v0, 0x87 (+119)
18: 0x12: IgetObject v0, v5, Field java.lang.Exception com.google.android.gms.tasks.zzu.zzagh
20: 0x14: InvokeVirtual { v2 v0 } Ljava/lang/Class;->isInstance(Ljava/lang/Object;)Z
23: 0x17: MoveResult v0
24: 0x18: IfNez v0, 0x7e (+102)
26: 0x1a: IgetObject v1, v5, Field java.lang.Exception com.google.android.gms.tasks.zzu.zzagh
28: 0x1c: IfNez v1, 0x78 (+92)
30: 0x1e: IgetObject v2, v5, Field java.lang.Object com.google.android.gms.tasks.zzu.zzagg
32: 0x20: MonitorExit v3
33: 0x21: CheckCast v2, android.os.Bundle
35: 0x23: ConstString v3, "SERVICE_NOT_AVAILABLE"
37: 0x25: IfEqz v2, 0x72 (+77)
39: 0x27: ConstStringJumbo v0, "registration_id"
42: 0x2a: InvokeVirtual { v2 v0 } Landroid/os/Bundle;->getString(Ljava/lang/String;)Ljava/lang/String;
45: 0x2d: MoveResultObject v0
46: 0x2e: IfNez v0, 0x57 (+41)
48: 0x30: ConstStringJumbo v0, "unregistered"
51: 0x33: InvokeVirtual { v2 v0 } Landroid/os/Bundle;->getString(Ljava/lang/String;)Ljava/lang/String;
54: 0x36: MoveResultObject v0
55: 0x37: IfNez v0, 0x57 (+32)
57: 0x39: ConstString v0, "error"
59: 0x3b: InvokeVirtual { v2 v0 } Landroid/os/Bundle;->getString(Ljava/lang/String;)Ljava/lang/String;
62: 0x3e: MoveResultObject v1
63: 0x3f: ConstString v0, "RST"
65: 0x41: InvokeVirtual { v0 v1 } Ljava/lang/String;->equals(Ljava/lang/Object;)Z
68: 0x44: MoveResult v0
69: 0x45: IfNez v0, 0x4f (+10)
71: 0x47: IfEqz v1, 0x58 (+17)
73: 0x49: NewInstance v0, java.io.IOException
75: 0x4b: InvokeDirect { v0 v1 } Ljava/io/IOException;-><init>(Ljava/lang/String;)V
78: 0x4e: Throw v0
79: 0x4f: NewInstance v1, java.io.IOException
81: 0x51: ConstString v0, "INSTANCE_ID_RESET"
83: 0x53: InvokeDirect { v1 v0 } Ljava/io/IOException;-><init>(Ljava/lang/String;)V
86: 0x56: Throw v1
87: 0x57: ReturnObject v0
88: 0x58: InvokeStatic { v2 } Ljava/lang/String;->valueOf(Ljava/lang/Object;)Ljava/lang/String;
91: 0x5b: MoveResultObject v2
92: 0x5c: InvokeVirtual { v2 } Ljava/lang/String;->length()I
95: 0x5f: MoveResult v0
96: 0x60: AddIntLit8 v1, v0, #21
98: 0x62: ConstString v0, "Unexpected response: "
100: 0x64: InvokeStatic { v1 v0 v2 } Lcom/android/tools/r8/GeneratedOutlineSupport;->outline141(ILjava/lang/String;Ljava/lang/String;)Ljava/lang/String;
103: 0x67: MoveResultObject v2
104: 0x68: NewInstance v1, java.lang.Throwable
106: 0x6a: InvokeDirect { v1 } Ljava/lang/Throwable;-><init>()V
109: 0x6d: ConstString v0, "FirebaseInstanceId"
111: 0x6f: InvokeStatic { v0 v2 v1 } Landroid/util/Log;->w(Ljava/lang/String;Ljava/lang/String;Ljava/lang/Throwable;)I
114: 0x72: NewInstance v0, java.io.IOException
116: 0x74: InvokeDirect { v0 v3 } Ljava/io/IOException;-><init>(Ljava/lang/String;)V
119: 0x77: Throw v0
120: 0x78: NewInstance v0, com.google.android.gms.tasks.RuntimeExecutionException
122: 0x7a: InvokeDirect { v0 v1 } Lcom/google/android/gms/tasks/RuntimeExecutionException;-><init>(Ljava/lang/Throwable;)V
125: 0x7d: Throw v0
126: 0x7e: IgetObject v0, v5, Field java.lang.Exception com.google.android.gms.tasks.zzu.zzagh
128: 0x80: InvokeVirtual { v2 v0 } Ljava/lang/Class;->cast(Ljava/lang/Object;)Ljava/lang/Object;
131: 0x83: MoveResultObject v0
132: 0x84: CheckCast v0, java.lang.Throwable
134: 0x86: Throw v0
135: 0x87: NewInstance v1, java.util.concurrent.CancellationException
137: 0x89: ConstString v0, "Task is already canceled."
139: 0x8b: InvokeDirect { v1 v0 } Ljava/util/concurrent/CancellationException;-><init>(Ljava/lang/String;)V
142: 0x8e: Throw v1
143: 0x8f: MoveException v0
144: 0x90: MonitorExit v3
145: 0x91: Throw v0
Here is some debugging info I collected using a breakpoint before the failing assert. Note, the pogram counter gets incremented to address 27 which does not have a corresponding instruction.
Program Counter increase for each Debug event from DebugInfo:
Debug events from DebugInfo:
Let me know if there is any other info I can provide.
cc @danzimm
I'm able to resolve the first stacktrace by cherrypicking the following commits related to DebugInfo into stable: c811108ae68a3496b47817f50d96e4156315b9cd, 23daef8a861e5cb54de2a767db46015964d973b3, d55a36422cc5ec8c386db95df47f18dfb8fd7c07, 86a96e90f6ad95f4432034ced76a6e4e5b7cb63c, b9cd1537f738fd4239ecef9f2b9be804336e00b4
Which repo are these commit hashes from? I get a 404 when I try to use them in this repo
I'm curious which debug_info_kind you're using? It's specified in the redex config and here's a list of the options with some comments. Does switching to "no_custom_symbolication" workaround this issue?
(note: use this function to get the string names used in the config)
I have the following defined in the config: "debug_info_kind": "no_custom_symbolication".
Sorrry I seem to have copied over the SHAs from cherrypicking and not the originals. Here are the correct ones: https://github.com/facebook/redex/commit/ca7fc6936f49fd682349227224989857e25d314e https://github.com/facebook/redex/commit/30d194f64dc197d82aabbf82d7037f5897a5eebf https://github.com/facebook/redex/commit/27ea91a5ed8c7b609291f62ae9f402e3eb37d631 https://github.com/facebook/redex/commit/117f3bed1f1183748ca41789b862234f85643dcf https://github.com/facebook/redex/commit/60e711b3a36977c830eb75f59f192ca589b12331
Chatted a bit with Ben offline about the second stack trace. Sounds like the debug info being emitted is technically malformed but wouldn't cause any issue at runtime- I guess d8/r8 is a stickler for this kind of thing. Specifically certain debug info items are getting emitted with more address mappings that there are addresses in the code item pointing to it.
This must be an artifact from IODI (as IODI's whole point is to emit extra mappings for functions so that debug info can be reused), so I'll take a look within the next week or so and hopefully get a PR up to fix it!
Ok, I think I a have a decent grasp on what's going on here. With Zim's help, we were able to create a python script to find all instances of the debug info referencing invalid PCs. I was also able to reproduce the issue when no passes were supplied.
In one of the instances, I observed that the positions in IR were correct but when lowering in generate_debug_instructions, converting positions to DebugInstructions would skip some ADVANCE_PC instructions. The reason being only a subset of positions included a file name and this is required to be converted into debug instructions. I'm not sure if this restriction is actually necessary.
It is expected that none of our positions have source files as we strip these out with R8. During Redex's deobfuscation step, it generates a best guess source file name if and only if the given position was remapped (i.e. different method/line number). Given the following mapping:
org.bouncycastle.crypto.engines.AESFastEngine -> org.bouncycastle.crypto.engines.AESFastEngine:
1:1:void unpackBlock(byte[],int):0:0 -> processBlock
1:1:int processBlock(byte[],int,byte[],int):0 -> processBlock
2:2:int processBlock(byte[],int,byte[],int):0:0 -> processBlock
3:3:void encryptBlock(int[][]):0:0 -> processBlock
3:3:int processBlock(byte[],int,byte[],int):0 -> processBlock
4:4:int processBlock(byte[],int,byte[],int):0:0 -> processBlock
5:5:void decryptBlock(int[][]):0:0 -> processBlock
5:5:int processBlock(byte[],int,byte[],int):0 -> processBlock
6:6:void packBlock(byte[],int):0:0 -> processBlock
6:6:int processBlock(byte[],int,byte[],int):0 -> processBlock
7:7:int processBlock(byte[],int,byte[],int):0:0 -> processBlock
processBlock's debug info will be given a source file for lines 1, 3, 5 and 6 as there are multiple entries and the first corresponds to a different method in each instance. Note, if processBlock always came before other methods then no source file names would have been generated. So there could potentially be some non-deteriministic behavior here.
I suspect the original issue with debug instructions not being emitted for positions without file names is due to the following code block in generate_debug_instructions:
for (auto it = entries.begin(); it != entries.end(); ++it) {
// find all entries that belong to the same address, and group them by type
auto addr = it->addr;
std::vector<DexPosition*> positions;
std::vector<DexDebugInstruction*> insns;
for (; it != entries.end() && it->addr == addr; ++it) {
switch (it->type) {
case DexDebugEntryType::Position:
if (it->pos->file != nullptr) {
positions.push_back(it->pos.get());
}
break;
case DexDebugEntryType::Instruction:
insns.push_back(it->insn.get());
break;
}
}
--it;
auto addr_delta = addr - prev_addr;
prev_addr = addr;
for (auto pos : positions) {
pos_mapper->register_position(pos);
}
// only emit the last position entry for a given address
if (!positions.empty()) {
// ...
}
for (auto insn : insns) {
// Potential issue:
if (addr_delta != 0) {
dbgops.emplace_back(
new DexDebugInstruction(DBG_ADVANCE_PC, addr_delta));
addr_delta = 0;
}
dbgops.emplace_back(insn->clone());
}
}
return dbgops;
}
Moving the conditional if (addr_delta != 0) { ... } block out of the for-loop ensures that a change to the address register generates a new instruction.
With this change and the cherrypicks mentioned above, D8 no longer fails on parsing debug info. As for the ProguardMap issue, I don't have a sense for what the correct solution is and with the proposed fix this weird behavior wouldn't affect us anymore.
Actually scratch the last part. It's better to instead remove the source file requirement. The motivation being that a given address may have multiple positions without source files and we'd want to use the logic to only take the last position entry for a given address.
Making the following adjustment also makes the instructions consistent with what R8 is producing. With that said, I'm still seeing a large increase in debug info size as tracked in https://github.com/facebook/redex/issues/523