Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

More informative logs to help debugging #2038

Draft
wants to merge 4 commits into
base: master
Choose a base branch
from
Draft

Conversation

DonggeLiu
Copy link
Contributor

Recent experiments have Fuzz target binary not found. errors which appears to be flaky and cannot be reproduced locally.

This PR adds more logs to help understand the cause.

@DonggeLiu
Copy link
Contributor Author

DonggeLiu commented Aug 23, 2024

@jonathanmetzman: Instead of running experiments and debugging the error here, shall we merge this now, so that we can debug via other user experiments?
A recent exp (discussed below) makes me think there are more logs to add/edit, e.g., this should at least be a warning.

@DonggeLiu DonggeLiu marked this pull request as draft August 24, 2024 11:43
@DonggeLiu
Copy link
Contributor Author

DonggeLiu commented Aug 24, 2024

Using 2024-08-23-2028-libafl as an example to help adding more debug logs here.
I think there is a mysterious but benign "timeout error" in building fuzz targets.

Known

FuzzBench log shows the cloud build to it failed to build fuzzz target openthread_ot-ip6-send with libafl:
image

Note that the 4th log shows build config was ready in 11 AM, and the 5th log shows the cloud build command errored out ~4 hours later with return code -9 .

4-hour happens to be the timeout for executing the gcloud build submit command.

Unknown

However, here is the mysterious part that I failed to understand.

The Cloud Build logs shows those the cloud build 11:13 AM build succeeded in 5 min 8 sec which is within the 4 hour timeout:
image
Note that the Cloud Build time out is also 4 hours.

How come the cloud build succeeded but the gcloud builds submit command timeout?

It is benign so far, because another cloud build was created right after this failure at 15:15 and this time it worked.

The same issue happened with systemd_fuzz-link-parser too:
image

But other benchmarks seem fine in the first time:
image

Appendix

The FuzzBench log shows the glcoud command error code is -9, its output is:

"fuzzbench/builders/libafl/openthread_ot-ip6-send-fuzzer]
1bce520b935d: Preparing
68a21fa7cefb: Preparing
7a81c2367f06: Preparing
44c5b1f35d4c: Preparing
5496ee56b3d0: Preparing
cf861a9f4ad5: Preparing
b465e77fbbca: Preparing
ac2f0aa51028: Preparing
26a98072958b: Preparing
da5289a751ef: Preparing
5053ee54613a: Preparing
536d2dba66f7: Preparing
d5baacba37d8: Preparing
9513aa32b708: Preparing
4fe31ac34bcd: Preparing
c215fcd61004: Preparing
b9c6ad950989: Preparing
3352954bf165: Preparing
cf861a9f4ad5: Waiting
f2451a90a8e5: Preparing
b465e77fbbca: Waiting
413a6592f152: Preparing
536d2dba66f7: Waiting
803d12e33934: Preparing
ac2f0aa51028: Waiting
ebb7b3a2a964: Preparing
da5289a751ef: Waiting
26a98072958b: Waiting
d5baacba37d8: Waiting
5f70bf18a086: Preparing
8f5eaa34ef3d: Preparing
5053ee54613a: Waiting
9513aa32b708: Waiting
6c2d8a26f1fe: Preparing
46aed4b18726: Preparing
4fe31ac34bcd: Waiting
b9c6ad950989: Waiting
197042153f80: Preparing
c215fcd61004: Waiting
8699d0706512: Preparing
5f70bf18a086: Waiting
ebe553c6bad5: Preparing
8f5eaa34ef3d: Waiting
f9741830d7d9: Preparing
3352954bf165: Waiting
730a63674d3a: Preparing
c31a5d60b7c4: Preparing
f2451a90a8e5: Waiting
803d12e33934: Waiting
5e4f13c3c983: Preparing
ebb7b3a2a964: Waiting
413a6592f152: Waiting
c3e12e531a6a: Preparing
6c2d8a26f1fe: Waiting
ebe553c6bad5: Waiting
d6131df7ab0a: Preparing
f9741830d7d9: Waiting
64f9a7f69fb3: Preparing
46aed4b18726: Waiting
b25a0b6be592: Preparing
197042153f80: Waiting
8699d0706512: Waiting
1742f00afc40: Preparing
730a63674d3a: Waiting
64f9a7f69fb3: Waiting
433efee1b82b: Preparing
c3e12e531a6a: Waiting
c31a5d60b7c4: Waiting
d6131df7ab0a: Waiting
c71a7aae8bf8: Preparing
b25a0b6be592: Waiting
1742f00afc40: Waiting
5e4f13c3c983: Waiting
b90919eba68c: Preparing
c71a7aae8bf8: Waiting
3ead380fed58: Preparing
433efee1b82b: Waiting
b2a8ec120b1d: Preparing
3ead380fed58: Waiting
da6e2c1565d2: Preparing
507734a87c1e: Preparing
dfe629743122: Preparing
0e8e960d198e: Preparing
da828fc163dc: Preparing
9e7dff0207a6: Preparing
492c667ecde4: Preparing
0002c93bdb37: Preparing
da6e2c1565d2: Waiting
0e8e960d198e: Waiting
dfe629743122: Waiting
da828fc163dc: Waiting
0002c93bdb37: Waiting
507734a87c1e: Waiting
1bce520b935d: Layer already exists
7a81c2367f06: Layer already exists
44c5b1f35d4c: Layer already exists
5496ee56b3d0: Layer already exists
68a21fa7cefb: Layer already exists
cf861a9f4ad5: Layer already exists
b465e77fbbca: Layer already exists
ac2f0aa51028: Layer already exists
26a98072958b: Layer already exists
da5289a751ef: Layer already exists
5053ee54613a: Layer already exists
536d2dba66f7: Layer already exists
9513aa32b708: Layer already exists
4fe31ac34bcd: Layer already exists
d5baacba37d8: Layer already exists
b9c6ad950989: Layer already exists
c215fcd61004: Layer already exists
f2451a90a8e5: Layer already exists
413a6592f152: Layer already exists
3352954bf165: Layer already exists
803d12e33934: Layer already exists
ebb7b3a2a964: Layer already exists
6c2d8a26f1fe: Layer already exists
5f70bf18a086: Layer already exists
46aed4b18726: Layer already exists
8f5eaa34ef3d: Layer already exists
197042153f80: Layer already exists
8699d0706512: Layer already exists
ebe553c6bad5: Layer already exists
f9741830d7d9: Layer already exists
c31a5d60b7c4: Layer already exists
5e4f13c3c983: Layer already exists
730a63674d3a: Layer already exists
64f9a7f69fb3: Layer already exists
c3e12e531a6a: Layer already exists
d6131df7ab0a: Layer already exists
b25a0b6be592: Layer already exists
1742f00afc40: Layer already exists
433efee1b82b: Layer already exists
c71a7aae8bf8: Layer already exists
3ead380fed58: Layer already exists
b90919eba68c: Layer already exists
b2a8ec120b1d: Layer already exists
da6e2c1565d2: Layer already exists
507734a87c1e: Layer already exists
0e8e960d198e: Layer already exists
9e7dff0207a6: Layer already exists
da828fc163dc: Layer already exists
dfe629743122: Layer already exists
492c667ecde4: Layer already exists
0002c93bdb37: Layer already exists
2024-08-23-2028-libafl: digest: sha256:70dcb3a25af24a7b13dc6bc3158cacf45ef297bded91f4b0729b05a839a0ee11 size: 11025
1bce520b935d: Preparing
68a21fa7cefb: Preparing
7a81c2367f06: Preparing
44c5b1f35d4c: Preparing
5496ee56b3d0: Preparing
cf861a9f4ad5: Preparing
b465e77fbbca: Preparing
ac2f0aa51028: Preparing
26a98072958b: Preparing
da5289a751ef: Preparing
5053ee54613a: Preparing
68a21fa7cefb: Layer already exists
536d2dba66f7: Preparing
d5baacba37d8: Preparing
7a81c2367f06: Layer already exists
9513aa32b708: Preparing
1bce520b935d: Layer already exists
4fe31ac34bcd: Preparing
44c5b1f35d4c: Layer already exists
c215fcd61004: Preparing
b9c6ad950989: Preparing
5053ee54613a: Waiting
da5289a751ef: Waiting
3352954bf165: Preparing
536d2dba66f7: Waiting
5496ee56b3d0: Layer already exists
f2451a90a8e5: Preparing
d5baacba37d8: Waiting
cf861a9f4ad5: Waiting
413a6592f152: Preparing
4fe31ac34bcd: Waiting
9513aa32b708: Waiting
ac2f0aa51028: Waiting
803d12e33934: Preparing
b465e77fbbca: Waiting
26a98072958b: Waiting
ebb7b3a2a964: Preparing
b465e77fbbca: Layer already exists
c215fcd61004: Waiting
f2451a90a8e5: Waiting
5f70bf18a086: Preparing
b9c6ad950989: Waiting
ac2f0aa51028: Layer already exists
cf861a9f4ad5: Layer already exists
8f5eaa34ef3d: Preparing
803d12e33934: Waiting
26a98072958b: Layer already exists
6c2d8a26f1fe: Preparing
ebb7b3a2a964: Waiting
5f70bf18a086: Waiting
8f5eaa34ef3d: Waiting
46aed4b18726: Preparing
6c2d8a26f1fe: Waiting
197042153f80: Preparing
da5289a751ef: Layer already exists
8699d0706512: Preparing
46aed4b18726: Waiting
ebe553c6bad5: Preparing
5053ee54613a: Layer already exists
536d2dba66f7: Layer already exists
f9741830d7d9: Preparing
8699d0706512: Waiting
730a63674d3a: Preparing
f9741830d7d9: Waiting
c31a5d60b7c4: Preparing
5e4f13c3c983: Preparing
c31a5d60b7c4: Waiting
c3e12e531a6a: Preparing
730a63674d3a: Waiting
d6131df7ab0a: Preparing
5e4f13c3c983: Waiting
c3e12e531a6a: Waiting
64f9a7f69fb3: Preparing
b25a0b6be592: Preparing
1742f00afc40: Preparing
b25a0b6be592: Waiting
d6131df7ab0a: Waiting
64f9a7f69fb3: Waiting
433efee1b82b: Preparing
d5baacba37d8: Layer already exists
9513aa32b708: Layer already exists
4fe31ac34bcd: Layer already exists
c215fcd61004: Layer already exists
c71a7aae8bf8: Preparing
1742f00afc40: Waiting
b90919eba68c: Preparing
3ead380fed58: Preparing
b9c6ad950989: Layer already exists
3352954bf165: Layer already exists
b2a8ec120b1d: Preparing
c71a7aae8bf8: Waiting
da6e2c1565d2: Preparing
b90919eba68c: Waiting
3ead380fed58: Waiting
507734a87c1e: Preparing
f2451a90a8e5: Layer already exists
413a6592f152: Layer already exists
803d12e33934: Layer already exists
5f70bf18a086: Layer already exists
da6e2c1565d2: Waiting
46aed4b18726: Layer already exists
dfe629743122: Preparing
ebb7b3a2a964: Layer already exists
6c2d8a26f1fe: Layer already exists
197042153f80: Layer already exists
8f5eaa34ef3d: Layer already exists
0e8e960d198e: Preparing
507734a87c1e: Waiting
da828fc163dc: Preparing
dfe629743122: Waiting
ebe553c6bad5: Layer already exists
9e7dff0207a6: Preparing
8699d0706512: Layer already exists
da828fc163dc: Waiting
730a63674d3a: Layer already exists
f9741830d7d9: Layer already exists
5e4f13c3c983: Layer already exists
c3e12e531a6a: Layer already exists
492c667ecde4: Preparing
9e7dff0207a6: Waiting
0002c93bdb37: Preparing
c31a5d60b7c4: Layer already exists
0002c93bdb37: Waiting
9e7dff0207a6: Layer already exists
b90919eba68c: Layer already exists
64f9a7f69fb3: Layer already exists
0e8e960d198e: Layer already exists
b2a8ec120b1d: Layer already exists
507734a87c1e: Layer already exists
d6131df7ab0a: Layer already exists
b25a0b6be592: Layer already exists
492c667ecde4: Layer already exists
0002c93bdb37: Layer already exists
dfe629743122: Layer already exists
c71a7aae8bf8: Layer already exists
3ead380fed58: Layer already exists
da828fc163dc: Layer already exists
433efee1b82b: Layer already exists
da6e2c1565d2: Layer already exists
1742f00afc40: Layer already exists
latest: digest: sha256:70dcb3a25af24a7b13dc6bc3158cacf45ef297bded91f4b0729b05a839a0ee11 size: 11025
Pushing gcr.io/fuzzbench/runners/libafl/openthread_ot-ip6-send-fuzzer-intermediate:2024-08-23-2028-libafl
The push refers to repository [gcr.io/fuzzbench/runners/libafl/openthread_ot-ip6-send-fuzzer-intermediate]
d42685b128e7: Preparing
88636d4b72fd: Preparing
ec5c6d6981f6: Preparing
76f630d3125c: Preparing
955c9fe749e1: Preparing
f2190927feb0: Preparing
b4cece03c7b9: Preparing
3ec3ded77c0c: Preparing
b4cece03c7b9: Waiting
f2190927feb0: Waiting
3ec3ded77c0c: Waiting
955c9fe749e1: Layer already exists
88636d4b72fd: Layer already exists
ec5c6d6981f6: Layer already exists
76f630d3125c: Layer already exists
f2190927feb0: Layer already exists
b4cece03c7b9: Layer already exists
3ec3ded77c0c: Layer already exists
d42685b128e7: Pushed
2024-08-23-2028-libafl: digest: sha256:a8ab5b64ec58f52e3a5f67f05b24bc5235f77648761f3bd1eb6a0b64fb6949ec size: 2007
Pushing gcr.io/fuzzbench/runners/libafl/openthread_ot-ip6-send-fuzzer-intermediate
The push refers to repository [gcr.io/fuzzbench/runners/libafl/openthread_ot-ip6-send-fuzzer-intermediate]
d42685b128e7: Preparing
88636d4b72fd: Preparing
ec5c6d6981f6: Preparing
76f630d3125c: Preparing
955c9fe749e1: Preparing
f2190927feb0: Preparing
b4cece03c7b9: Preparing
3ec3ded77c0c: Preparing
f2190927feb0: Waiting
b4cece03c7b9: Waiting
3ec3ded77c0c: Waiting
76f630d3125c: Layer already exists
d42685b128e7: Layer already exists
955c9fe749e1: Layer already exists
88636d4b72fd: Layer already exists
ec5c6d6981f6: Layer already exists
f2190927feb0: Layer already exists
3ec3ded77c0c: Layer already exists
b4cece03c7b9: Layer already exists
2024-08-23-2028-libafl: digest: sha256:a8ab5b64ec58f52e3a5f67f05b24bc5235f77648761f3bd1eb6a0b64fb6949ec size: 2007
d42685b128e7: Preparing
88636d4b72fd: Preparing
ec5c6d6981f6: Preparing
76f630d3125c: Preparing
955c9fe749e1: Preparing
f2190927feb0: Preparing
b4cece03c7b9: Preparing
3ec3ded77c0c: Preparing
d42685b128e7: Layer already exists
88636d4b72fd: Layer already exists
ec5c6d6981f6: Layer already exists
3ec3ded77c0c: Waiting
b4cece03c7b9: Layer already exists
3ec3ded77c0c: Layer already exists
955c9fe749e1: Layer already exists
76f630d3125c: Layer already exists
f2190927feb0: Layer already exists
"

@DonggeLiu
Copy link
Contributor Author

Another bug happened in #2028 is Fuzz target binary not found.:
image

I will use this PR to print out more info to assist debugging.

@DonggeLiu
Copy link
Contributor Author

/gcbrun run_experiment.py -a --experiment-config /opt/fuzzbench/service/experiment-config.yaml --experiment-name 2024-08-25-2038-libaf --fuzzers libafl

@DonggeLiu
Copy link
Contributor Author

Experiment 2024-08-25-2038-libaf data and results will be available later at:
The experiment data.
The experiment report.
The experiment report(experimental).

This was referenced Aug 25, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant