User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:76.0) Gecko/20100101 Firefox/76.0

Steps to reproduce:

No idea how this happened, all I have is a profile: https://profiler.firefox.com/public/f1a3e008e36dfb60a838d906e79e15169bf5d8cc/calltree/?globalTrackOrder=0&localTrackOrderByPid=418-0-1-2-3-4-5-6-7-8-9-10-11~&thread=12&v=4. Look at the "mozStorage #6" thread.

Actual results:

The mozStorage #6 thread is using 100% CPU for no apparent reason

Expected results:

It should not

Restarting Firefox made the problem go away, sorry I have no further information

Just happened again, I had to force quit Firefox because mozStorage #6 was still in its loop after the rest of the program had shut down

Unfortunately these are a bit unreadable because mozStorage #6 doesn't give any detail about which database was being accessed and why.
We do add info to the profiler as a marker in https://searchfox.org/mozilla-central/rev/54f965e51e4f77866bec42737978d40d4c1fdfc5/storage/mozStorageConnection.cpp#1102 but here I just see a "too long" string... maybe we should crop these strings to the maximum, so at least one part is visible and we can make a guess about the running query.
Markus, could these macros crop the text instead of showing a useless (too long) string? Am I looking in the wrong place? what's the maximum length?

Maybe we should also add a marker for the db name, if available, or we should name the thread after the db name, if available.

For this debugging we may have to use the old method, Storage has a log system, you must set two environment variables MOZ_LOG="mozStorage:5" and MOZ_LOG_FILE="path_to/mozlog.txt"
You can refer to https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Gecko_Logging#Example_Usage (See Enabling logging and Redirecting logging).
In the log file, for each query that took a longer time than expected there should be the elapsed time, you should be able to find the one with the large time... it's not trivial because it generates a lot of text.
Also remember to disable logging once done.
I am sorry for the trouble.

(In reply to Marco Bonardo [:mak] from comment #3)

Markus, could these macros crop the text instead of showing a useless (too long) string?

Definitely. I filed bug 1635570 on it.

what's the maximum length?

512 bytes.

Is it possible to enable logging at runtime? This only seems to happen after running Firefox for a while, and I probably shouldn't be constantly running with logs.

Good news! You can adjust logging at runtime via either:

• about:networking#logging
• Modifying the preferences documented at the bottom of the https://developer.mozilla.org/en-US/docs/Mozilla/Developer_guide/Gecko_Logging#Enabling_Logging section. logging.mozStorage I believe is the appropriate numeric pref, which would be set to 5 when you want to turn it on.

tbodt, does comment 7 help with getting more logging? (It sounds like that might be what we're blocked on here)

Thanks for the report & for your help in getting us closer to understanding the problem!

Yes, I'll post a comment next time this happens.

It just happened again and I turned on logging, but got nothing from mozStorage #6, mostly just from DOMCacheThread and IndexedDB #1405. Uploading just in case it's useful. I'll restart Firefox and leave mozStorage logging on permanently.

Could you run the loggin at other times and try to see what "usually" mozStorage #6 is? (maybe post some query snippet on it)
Another interesting thing to do, would be to copy the profile folder and then try to use the copy with Nightly, bug 1635570 has been fixed in Nightly, thus the profiler should now be able to report the first part of the running query as marker data. Basically get a profile like the last one, but using Nightly.

I think I should file a bug to replace these unreadable "mozStorage #n" names with the telemetryName, after Mossop's patch moving telemetry name closer to the connection it should be even easier. Update: filed bug 1638256.

Here are the mozStorage #6 logs I've collected since yesterday. The full log is over the 10MB limit for Bugzilla, let me know if you want me to upload somewhere.

2020-05-15 06:12:44.543030 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
      SELECT frecency
      FROM moz_places
      WHERE url_hash = hash(:url) AND url = :url
      LIMIT 1' (0x0x1427d5c70)
2020-05-15 06:12:44.645359 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
    SELECT guid
    FROM moz_bookmarks
    WHERE parent = (
      SELECT id FROM moz_bookmarks WHERE guid = :parentGuid
    )
    ORDER BY position' (0x0x1427d5ed0)
2020-05-15 06:12:45.282647 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x143e0a540)
2020-05-15 06:12:45.311992 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x143e0a540)
2020-05-15 06:12:45.474857 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
      SELECT url, IFNULL(title, '') AS title, frecency
      FROM moz_places
      WHERE guid = :guid' (0x0x12eb0d970)
2020-05-15 06:12:45.485048 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
      SELECT visit_type type, visit_date date
      FROM moz_historyvisits
      JOIN moz_places h ON h.id = place_id
      WHERE url_hash = hash(:url) AND url = :url
      ORDER BY date DESC LIMIT 20' (0x0x143e0a540)
2020-05-15 06:14:22.041418 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x118afabd0)
2020-05-15 06:24:22.696513 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x118afbed0)
2020-05-15 06:34:23.169258 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x12eb0e7b0)
2020-05-15 06:44:23.732661 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x132d578d0)
2020-05-15 06:46:09.406174 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
    SELECT n.name, h.url, a.content FROM moz_anno_attributes n
    JOIN moz_annos a ON n.id = a.anno_attribute_id
    JOIN moz_places h ON h.id = a.place_id
    WHERE n.name IN (?,?)
  ' (0x0x14a1bc970)
2020-05-15 06:46:09.431325 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement 'SELECT h.id, guid, url, title, frecency
                
               FROM moz_places h 
               WHERE h.url_hash = hash(:url) AND h.url = :url
               ' (0x0x14a1bc970)
2020-05-15 06:54:24.242593 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x12e9e0840)
2020-05-15 07:04:24.884628 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x12eb0eb40)
2020-05-15 07:14:25.435111 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x132d572e0)
2020-05-15 07:24:26.270236 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x12eb0ec70)
2020-05-15 07:34:26.798986 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x120ce2a00)
2020-05-15 07:44:27.291784 UTC - [Parent 43499: mozStorage #6]: D/mozStorage Initialized statement '
        SELECT DISTINCT p.guid FROM moz_places p
        JOIN moz_historyvisits v ON p.id = v.place_id
        WHERE p.guid IN (?,?,?,?,?,?,?,?,?,?,?) AND
            (p.hidden = 1 OR v.visit_type IN (0,
              8))
      ' (0x0x120ce4c70)

ok, I'm moving this to Places, do you have many bookmarks or tags (like many thosands)?

Could you please go to about:support and try to run the Places Database Integrity check that's on that page? Please post the log it prints once done.

I have probably less than 100 bookmarks. Here's the log from the integrity check:

> Task: checkIntegrity
+ The places.sqlite database is sane
+ The favicons.sqlite database is sane
> Task: invalidateCaches
+ The caches have been invalidated
> Task: checkCoherence
+ The database is coherent
> Task: expire
+ Database cleaned up
> Task: originFrecencyStats
+ Recalculated origin frecency stats
> Task: vacuum
+ Initial database size is 25600KiB
+ The database has been vacuumed
+ Final database size is 25600KiB
> Task: stats
+ Places.sqlite size is 25600KiB
+ Favicons.sqlite size is 13356KiB
+ pragma_user_version is 53
+ pragma_page_size is 32768
+ pragma_cache_size is -2048
+ pragma_journal_mode is wal
+ pragma_synchronous is 1
+ History can store a maximum of 156039 unique pages
+ Table moz_places has 44231 records
+ Table moz_historyvisits has 58160 records
+ Table moz_inputhistory has 161 records
+ Table moz_hosts has 0 records
+ Table moz_bookmarks has 222 records
+ Table moz_keywords has 2 records
+ Table sqlite_sequence has 1 records
+ Table moz_anno_attributes has 2 records
+ Table moz_annos has 194 records
+ Table moz_items_annos has 0 records
+ Table sqlite_stat1 has 20 records
+ Table moz_bookmarks_deleted has 0 records
+ Table moz_meta has 7 records
+ Table moz_origins has 4572 records
+ Index sqlite_autoindex_moz_inputhistory_1
+ Index sqlite_autoindex_moz_hosts_1
+ Index sqlite_autoindex_moz_keywords_1
+ Index sqlite_autoindex_moz_anno_attributes_1
+ Index sqlite_autoindex_moz_bookmarks_deleted_1
+ Index sqlite_autoindex_moz_origins_1
+ Index moz_places_hostindex
+ Index moz_places_visitcount
+ Index moz_places_frecencyindex
+ Index moz_places_lastvisitdateindex
+ Index moz_historyvisits_placedateindex
+ Index moz_historyvisits_fromindex
+ Index moz_historyvisits_dateindex
+ Index moz_bookmarks_itemindex
+ Index moz_bookmarks_parentindex
+ Index moz_bookmarks_itemlastmodifiedindex
+ Index moz_places_guid_uniqueindex
+ Index moz_bookmarks_guid_uniqueindex
+ Index moz_keywords_placepostdata_uniqueindex
+ Index moz_annos_placeattributeindex
+ Index moz_items_annos_itemattributeindex
+ Index moz_places_url_hashindex
+ Index moz_bookmarks_dateaddedindex
+ Index moz_places_originidindex
> Task: _refreshUI

There's over 200 bookmarks, which seem more than you expect. Can you please also tell us what addons you have installed, just incase you have one which is creating them? (eg, I use the "livemarks" addon which regularly creates and deletes bookmarks, so I have far more than I'd initially expect)

Here's my addons list from about:support. I'm fairly sure none of these automatically create bookmarks.

1Password extension (desktop app required)	4.7.5.90	true	onepassword4@agilebits.com
Amazon.com	1.1	true	amazondotcom@search.mozilla.org
Auto Tab Discard	0.3.5.2	true	{c2c003ee-bd69-42a2-b0e9-6f34222cb046}
Bing	1.1	true	bing@search.mozilla.org
Bypass Paywalls	1.7.1	true	bypasspaywalls@bypasspaywalls.weebly.com
DuckDuckGo	1.0	true	ddg@search.mozilla.org
eBay	1.0	true	ebay@search.mozilla.org
FrankerFaceZ	4.0	true	frankerfacez@frankerfacez.com
Google	1.0	true	google@search.mozilla.org
HTTPS Everywhere	2020.3.16	true	https-everywhere@eff.org
Multi-touch Zoom	0.95	true	{90b5a72e-cdbd-49df-8304-5b5d6ea84a0f}
Native HLS Playback	0.12.4	true	{55b190e3-7d92-4315-8a2d-ae6c7cd68c9f}
Open In IINA	2.0.0	true	open_in_iina_firefox@iina.io
Privacy Badger	2020.5.12	true	jid1-MnnxcxisBPnSXQ@jetpack
React Developer Tools	4.6.0	true	@react-devtools
Refined GitHub	20.5.11	true	{a4c4eda4-fb84-4a84-b4a1-f7c1cbf2a1ad}
Sourcegraph	20.3.18.1833	true	sourcegraph-for-firefox@sourcegraph.com
Stylus	1.5.11	true	{7a7a4a92-a2a0-41d1-9fd7-1e92480d612d}
Tampermonkey	4.10.6112	true	firefox@tampermonkey.net
To Google Translate	4.0.6	true	jid1-93WyvpgvxzGATw@jetpack
Twitter	1.0	true	twitter@search.mozilla.org
uBlock Origin	1.26.2	true	uBlock0@raymondhill.net
Vimium	1.66	true	{d7742d87-e61d-4b78-b8a1-b469842139fa}
Wayback Machine	1.8.6	true	wayback_machine@mozilla.org
Wikipedia (en)	1.0	true	wikipedia@search.mozilla.org
Zoom Redirector	1.0.1	true	{2d0a18e8-6b0a-4c8c-9256-6e00c01f07fe}
Chrome Store Foxified	3.4	false	Chrome-Store-Foxified@jetpack
Panasonic Avionics DRM Playback	1.0.2.5	false	drmWebExtension@panasonic.aero
Test Pilot	2.0.8-dev-2425b5a	false	@testpilot-addon
WorldBrain's Memex	2.0.20	false	info@worldbrain.io

There's nothing particularly scary in the numbers from comment 15. And off-hand I don't see scary add-ons (of course I didn't check the source of each of them!).
At this point the only remaining thing would be to get which query takes so long, by running the profiler in Nightly and getting the cropped marker from the profile itself, and maybe from there we could make a more efficient one.

The severity field is not set for this bug.
:mak, could you have a look please?

For more information, please visit auto_nag documentation.

let's just backlog for now, we don't have enough data to make it actionable though.

I just had this recur (with mozStorage #3 instead of #6). Now that I have the fix for bug 1635570, the profile is more helpful. https://share.firefox.dev/3kdU3NK

You can now see the query:

Connection::stepStatement /* do not warn (bug no): cannot use an index */
       WITH RECURSIVE
       descendants(fk, level, type, id, guid, parent, parentGuid, position,
                   title, dateAdded, lastModified) AS (
         SELECT b1.fk, 0, b1.type, b1.id, b1.guid, b1.parent,
                (SELECT guid FROM moz_bookmarks WHERE id = b1.parent),
                b1.position, b1.title, b1.dateAdded, b1.lastModified
         FROM moz_bookmarks b1 WHERE b1.guid=:item_guid
         UNION ALL
         SELECT b2.fk, level ...

It looks like a call to PlacesUtils.promiseBookmarksTree, the perf problem looks strange with so few bookmarks, I don't expect it to take more than a few milliseconds.
Bug 1081106 would help a bit here, if the problem is use of promiseBookmarksTree fetching more than necessary for fetchTree, but I don't expect that to solve this, because I don't think the problem lies in the querying...

I wonder what's that DOM worker taking up the same time, is it delayed by the query or the opposite? I'm basically wondering if something in that worker is keeping the system so busy, that this query takes a lot longer than expected to complete.
The profile doesn't contain enough information (afaict) to tell what's that worker.

Yeah, the worker data seems like maybe the privacy page of the share process might have over-sanitized it? Unless the worker ended up in some kind of weird hang/deadlock sufficiently long ago that its profiler buffer data all aged out of the buffer and so there's just like one weird lingering datapoint?

(In reply to Marco Bonardo [:mak] from comment #22)

I wonder what's that DOM worker taking up the same time, is it delayed by the query or the opposite? I'm basically wondering if something in that worker is keeping the system so busy, that this query takes a lot longer than expected to complete.
The profile doesn't contain enough information (afaict) to tell what's that worker.

My guess is that this is the subprocess worker, and it's not busy, but has its event loop blocked for periods of 5s by https://searchfox.org/mozilla-central/rev/25d5a4443a7e13cfa58eff38f1faa5e69f0b170f/toolkit/modules/subprocess/subprocess_worker_unix.js#20
(I thought about this worker because it caused issues when I was working on about:performance, see bug 1497794. This is not something that I could have found from the profile alone.)

Unfortunately we don't have enough information to try to debug the issue locally. The query could maybe be micro-optimized, but that's unlikely to solve this kind of long hang.
If you should hit this again, please reopen the bug attaching a new performance profile (the profiler now has some interesting new features) and a full log from the about:support page.