retracing process can return an empty StacktraceTop for no reason

[Brian Murray]

I experienced a crash in Xenial with cdparanoia and it failed to retrace in the Error Tracker:

https://errors.ubuntu.com/oops/5ea5e280-01cd-11e6-9faf-fa163e8d4bab

The RetraceFailureReason indicates "No crash signature after retracing."

However, this did retrace successfully with the Launchpad retracers.

https://bugs.launchpad.net/ubuntu/+source/cdparanoia/+bug/1569494

Looking at the retracer log files we can see the following:

/home/brian/bin/retrace-result.sh 20160413 "5ea5e280-01cd-11e6-9faf-fa163e8d4bab"
2016-04-13 23:14:06,971:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Processing.
2016-04-13 23:14:07,238:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Decompressing to /tmp/tmpUg9dN_-swift.5ea5e280-01cd-11e6-9faf-fa163e8d4bab.oopsid.core
2016-04-13 23:14:22,743:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Retracing 5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift
2016-04-13 23:14:30,854:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Writing back to Cassandra
2016-04-13 23:14:30,857:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Apport did not return a crash_signature.
2016-04-13 23:14:30,857:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:StacktraceTop:
2016-04-13 23:14:30,857:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:?? ()
2016-04-13 23:14:30,858:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:?? ()
2016-04-13 23:14:30,858:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:?? ()
2016-04-13 23:14:30,858:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:?? ()
2016-04-13 23:14:30,862:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Could not retrace.
2016-04-13 23:14:31,935:3294:139787354564352:INFO:root:5ea5e280-01cd-11e6-9faf-fa163e8d4bab:swift:Done processing /tmp/tmpUg9dN_-swift.5ea5e280-01cd-11e6-9faf-fa163e8d4bab.oopsid

[Brian Murray (brian-murray)]

I've setup a retracer using the Precise version of the retracer charm in Canonistack. The unit has the following installed:

gdb from the daisy-plucker seeds version 7.10.90.20160215-0ubuntu3~12.04.1
apport bzr branch from my overlay-ppa and revision number 2983
daisy from trunk and revision number 698

I've manually retraced the same crash without a problem. Here's the command line used:

PYTHONPATH=/srv/daisy.ubuntu.com/production/local_config:/srv/daisy.ubuntu.com/production/daisy:/srv/daisy.ubuntu.com/production/apport:/srv/daisy.ubuntu.com/production python /srv/daisy.ubuntu.com/production/apport/bin/apport-retrace --verbose -S /srv/daisy.ubuntu.com/production/daisy/retracer/config/ ~/_usr_bin_cdparanoia.1000.crash -o /tmp/retraced.crash

[Brian Murray (brian-murray)]

The production retracers have the same apport bzr branch as I tested with and looking at the log for the failure to retrace again we see:

2016-04-13 21:40:07,524:3294:139787354564352:INFO:root:Running revision number: 697 with sandbox_dir /srv/daisy.ubuntu.com/production/cache, gdb 7.10.90.20160215-0ubuntu3~~0.IS.12.04.0.

[Brian Murray (brian-murray)]

There are also other crash reports that fail with "No crash signature after retracing".

https://errors.ubuntu.com/oops/73004320-031b-11e6-88f3-fa163ebeb28a

[Brian Murray (brian-murray)]

I submitted RT 90748 regarding have the same command as in #1 run on a production retracer. The cdparanoia crash was retraced successfully on the production retracer so perhaps it was temporary failure.

It was done on the following unit:

ubuntu@juju-lgw01-ue-et-ps45-production-manual-1:/tmp$ PYTHONPATH=/srv/daisy.ubuntu.com/production/local_config:/srv/daisy.ubuntu.com/production/daisy:/srv/daisy.ubuntu.com/production/apport:/srv/daisy.ubuntu.com/production python /srv/daisy.ubuntu.com/production/apport/bin/apport-retrace --verbose -S /srv/daisy.ubuntu.com/production/daisy/retracer/config/ /tmp/_usr_bin_cdparanoia.1000.crash -o /tmp/cdparanoia-retraced.crash

I guess the next step is to delete the crash signature for this crash so I can submit again and see if it retraces.

[Brian Murray (brian-murray)]

I submitted another cdparanoia crash and it successfully retraced.

2016-04-19 15:50:17,646:22478:139982256862976:INFO:root:5cc79c24-0646-11e6-b403-fa163e171d9b:swift:Processing.
2016-04-19 15:50:17,896:22478:139982256862976:INFO:root:5cc79c24-0646-11e6-b403-fa163e171d9b:swift:Decompressing to /tmp/tmpuwn7J_-swift.5cc79c24-0646-11e6-b403-fa163e171d9b.oopsid.core
2016-04-19 15:50:33,699:22478:139982256862976:INFO:root:5cc79c24-0646-11e6-b403-fa163e171d9b:swift:Retracing 5cc79c24-0646-11e6-b403-fa163e171d9b:swift
2016-04-19 15:50:50,375:22478:139982256862976:INFO:root:5cc79c24-0646-11e6-b403-fa163e171d9b:swift:Writing back to Cassandra
2016-04-19 15:50:50,399:22478:139982256862976:INFO:root:5cc79c24-0646-11e6-b403-fa163e171d9b:swift:Successfully retraced.
2016-04-19 15:50:51,549:22478:139982256862976:INFO:root:5cc79c24-0646-11e6-b403-fa163e171d9b:swift:Done processing /tmp/tmpuwn7J_-swift.5cc79c24-0646-11e6-b403-fa163e171d9b.oopsid

The OOPS is here:

https://errors.ubuntu.com/oops/5cc79c24-0646-11e6-b403-fa163e171d9b

[Brian Murray (brian-murray)]

Given that things are working again, in the interest of making the data in the Error Tracker useful I went ahead and removed SASes from the Indexes table for crashes appearing in the top 100 for Ubuntu 16.04 that had no crash signature after retracing. I also did this for all the packagekit crashes to test the methodology and tools.

[Brian Murray (brian-murray)]

Further testing indicates that apport (or gdb) will sometimes retrace a report and yet there will not be a crash signature after retracing. This can happen if we are missing debug symbols or the crash had old package versions. However, there are also cases where the report does not have an UnreportableReason, is not missing debug symbols, has an original StacktraceAddressSignature and the retraced report has a StacktraceTop full of "?? ()". In those cases we should try retracing again and see what happens.

[Brian Murray (brian-murray)]

I've tested this on my staging version of the Error Tracker and we can see the results of an attempt to retrace here.

2016-04-26 19:58:25,627:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Retracing 140cd49c-0be9-11e6-acd5-fa163eef413f:swift
asd2016-04-26 20:01:24,729:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Writing back to Cassandra
2016-04-26 20:01:24,733:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Apport did not return a crash_signature.
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:StacktraceTop:
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:?? ()
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:?? ()
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:?? ()
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:?? ()
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:?? ()
2016-04-26 20:01:24,734:28850:140353452214080:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Requeueing a possible apport failure.
....
2016-04-26 20:02:00,735:1211:140228033050432:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Retracing 140cd49c-0be9-11e6-acd5-fa163eef413f:swift
2016-04-26 20:04:08,997:1211:140228033050432:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Writing back to Cassandra
2016-04-26 20:04:09,017:1211:140228033050432:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Successfully retraced.
2016-04-26 20:04:09,018:1211:140228033050432:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:RetraceOutdatedPackages:
2016-04-26 20:04:09,018:1211:140228033050432:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:no debug symbol package found for libllvm3.6v5 (Ubuntu 15.10)
2016-04-26 20:04:13,531:1211:140228033050432:INFO:root:140cd49c-0be9-11e6-acd5-fa163eef413f:swift:Done processing /tmp/tmp2JPhza-swift.140cd49c-0be9-11e6-acd5-fa163eef413f.oopsid

[Brian Murray (brian-murray)]

In daisy revision number 700 I've modified the retracer to put a crash report back on the queue when it fails with the following criteria.

The StacktraceTop only contains "?? ()"
The original report contains a StacktraceAddressSignature
The report does not have an UnreportableReason
There are no missing debug symbols

I also added a counter to keep track of the crashes like this: retrace.missing.crash_signature.apport_issue

This revision of daisy has now landed in production.

[Brian Murray (brian-murray)]

Here are some logs from the production retracers reprocessing a failure of this category.

./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:23,549:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Processing.
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:23,617:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Decompressing to /tmp/tmpAUED9R-swift.5063ed58-0c44-11e6-9d57-fa163ebeb28a.oopsid.core
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:24,061:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Retracing 5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,157:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Writing back to Cassandra
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,162:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Apport did not return a crash_signature.
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,162:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:StacktraceTop:
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,163:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:?? ()
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,163:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:?? ()
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,163:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:?? ()
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,163:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:?? ()
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,163:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:?? ()
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:55:35,163:21330:140638664505088:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Requeueing a possible apport failure.
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:57:07,290:4986:139655565539072:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Processing.
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:57:07,429:4986:139655565539072:INFO:urllib3.connectionpool:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Starting new HTTP connection (1): 10.34.0.136
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:57:07,748:4986:139655565539072:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Decompressing to /tmp/tmp3QdAr4-swift.5063ed58-0c44-11e6-9d57-fa163ebeb28a.oopsid.core
./e-t-retracer-app-10.42.32.39/production-logs/retracer-amd64.log:2016-04-27 06:57:08,202:4986:139655565539072:INFO:root:5063ed58-0c44-11e6-9d57-fa163ebeb28a:swift:Retracin...

[Brian Murray (brian-murray)]

Come to find out we also retry "Transient apport failures" a lot in the same way, so perhaps requeueing (the requeue function) isn't really putting things at the end of the queue.