Closed Bug 1254780 Opened 10 years ago Closed 10 years ago

log_types is huge (408 KiB)

Categories

(Core :: WebRTC: Networking, defect)

Product:
Core
Component:
WebRTC: Networking
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla48
Tracking Flags:
Tracking Status
firefox48 --- fixed
Blocking Flags:
backlog tech-debt

People

(Reporter: n.nethercote, Assigned: n.nethercote)

References

Details

(Whiteboard: [MemShrink:P3])

Attachments

(1 file)

Shrink log_types from 1024 entries to 16
1012 bytes, patch
ekr
: review+
Details | Diff | Splinter Review
By far the biggest static data symbol in libxul is nrappkit's |log_types|. It's 408 KiB! And that contributes to the memory usage of every Firefox process. The relevant code: > #define NR_REG_MAX_NR_REGISTRY_LEN 128 > > typedef char NR_registry[NR_REG_MAX_NR_REGISTRY_LEN]; > > #define LOG_NUM_DESTINATIONS 3 > > typedef struct log_type_ { > char *facility_name; > int level[LOG_NUM_DESTINATIONS]; > NR_registry dest_facility_key[LOG_NUM_DESTINATIONS]; > } log_type; > > #define MAX_LOG_TYPES 1024 > > static log_type log_types[MAX_LOG_TYPES]; I don't know much about this code, but statically allocating 1024 of these things seems... generous. Perhaps it would be more suitable to use heap allocation, and start off with a smallish array -- 4 or 8 elements? -- and then resize it on demand? I'd be happy to try implementing that, or I could let someone else who knows more about this code do it. ekr, what do you think?
Flags: needinfo?(ekr)
glandium identified that because log_types is zeroed, it's in the .bss section, and so it doesn't get paged into physical memory until it's touched. I confirmed that with smaps -- original I had this for libxul's .bss: > Size: 764 kB > Rss: 276 kB and then I changed log_types from 1024 entries to 4 just as a test and got this: > Size: 360 kB > Rss: 276 kB So it saves some address space but doesn't reduce physical memory usage at all. Bummer.
> So it saves some address space but doesn't reduce physical memory usage at > all. Bummer. Not surprising; as you'd expect almost all of those are unused, so they eat address space, and maybe one 4K-ish page in memory (and perhaps then only if logging is enabled with env vars).
I think it would be fine to change it to 32 or something, but it also doesn't sound like it adds much value.
Flags: needinfo?(ekr)
Whiteboard: [MemShrink] → [MemShrink:P3]
I'd like to do this if only so that log_types doesn't forever sit at the top of the static data size table in bug 1254777. 16 entries still seems generous and gets it down from 408 KiB.
Attachment #8728767 - Flags: review?(ekr)
Assignee: nobody → n.nethercote
Status: NEW → ASSIGNED
> 16 entries still seems generous and gets it down from 408 KiB. And I meant to add "to 6.4 KiB, which is #125 in the table".
backlog: --- → tech-debt
ekr: 2 week review ping for a 1 line patch.
Comment on attachment 8728767 [details] [diff] [review] Shrink log_types from 1024 entries to 16 Review of attachment 8728767 [details] [diff] [review]: ----------------------------------------------------------------- Based on c1, it doesn't seem like this has any significant operational impact on Firefox, it's just annoying when you look at the list. Is that correct? If so, it seems like an unnecessary change.
Attachment #8728767 - Flags: review?(ekr)
It only saves address space. But on Win32 crashes due to running out of address space are a reasonably significant fraction of all crashes, so it buys us 402 KiB of extra headroom there.
Comment on attachment 8728767 [details] [diff] [review] Shrink log_types from 1024 entries to 16 Review of attachment 8728767 [details] [diff] [review]: ----------------------------------------------------------------- Based on c1, it doesn't seem like this has any significant operational impact on Firefox, it's just annoying when you look at the list. Is that correct? If so, it seems like an unnecessary change.
Attachment #8728767 - Flags: review+
Backed out because it seems to cause crashes in Windows 7 debug developer tools tests. Backout: https://hg.mozilla.org/integration/mozilla-inbound/rev/964a638d77fa Jobs with crashes: https://treeherder.mozilla.org/logviewer.html#?job_id=24525745&repo=mozilla-inbound https://treeherder.mozilla.org/logviewer.html#?job_id=24526640&repo=mozilla-inbound https://treeherder.mozilla.org/logviewer.html#?job_id=24532451&repo=mozilla-inbound 01:49:51 WARNING - PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::gfx::Log<1,mozilla::gfx::CriticalLogger>::WriteLog(std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &)] 01:49:51 INFO - Crash dump filename: c:\users\cltbld\appdata\local\temp\tmpqjk4w3.mozrunner\minidumps\8f0a54da-9c94-41e5-a3b4-bfd9a99d1845.dmp 01:49:51 INFO - Operating system: Windows NT 01:49:51 INFO - 6.1.7601 Service Pack 1 01:49:51 INFO - CPU: x86 01:49:51 INFO - GenuineIntel family 6 model 30 stepping 5 01:49:51 INFO - 8 CPUs 01:49:51 INFO - Crash reason: EXCEPTION_BREAKPOINT 01:49:51 INFO - Crash address: 0x5ee16df7 01:49:51 INFO - Assertion: Unknown assertion type 0x00000000 01:49:51 INFO - Process uptime: 54 seconds 01:49:51 INFO - Thread 39 (crashed) 01:49:51 INFO - 0 xul.dll!mozilla::gfx::Log<1,mozilla::gfx::CriticalLogger>::WriteLog(std::basic_string<char,std::char_traits<char>,std::allocator<char> > const &) [Logging.h:5081a75fbe8c : 512 + 0x22] 01:49:51 INFO - eip = 0x5ee16df7 esp = 0x0612f5fc ebp = 0x0612f600 ebx = 0x0ddb40c0 01:49:51 INFO - esi = 0x00000200 edi = 0x00000005 eax = 0x61aa8d5c ecx = 0x68d50ad9 01:49:51 INFO - edx = 0x00935279 efl = 0x00000206 01:49:51 INFO - Found by: given as instruction pointer in context 01:49:51 INFO - 1 xul.dll!mozilla::gfx::Log<1,mozilla::gfx::CriticalLogger>::Flush() [Logging.h:5081a75fbe8c : 282 + 0xb] 01:49:51 INFO - eip = 0x5ee12820 esp = 0x0612f608 ebp = 0x0612f648 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 2 xul.dll!mozilla::layers::AsyncTransactionWaiter::WaitComplete() [AsyncTransactionTracker.cpp:5081a75fbe8c : 39 + 0x26] 01:49:51 INFO - eip = 0x5ef737f4 esp = 0x0612f650 ebp = 0x0612f71c 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 3 xul.dll!mozilla::layers::ImageBridgeChild::FlushAllImages(mozilla::layers::ImageClient *,mozilla::layers::ImageContainer *) [ImageBridgeChild.cpp:5081a75fbe8c : 665 + 0xf] 01:49:51 INFO - eip = 0x5ef841c5 esp = 0x0612f724 ebp = 0x0612f73c 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 4 xul.dll!mozilla::layers::ImageContainer::ClearAllImages() [ImageContainer.cpp:5081a75fbe8c : 282 + 0x9] 01:49:51 INFO - eip = 0x5eebd159 esp = 0x0612f744 ebp = 0x0612f758 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 5 xul.dll!mozilla::VideoFrameContainer::ClearCurrentFrame() [VideoFrameContainer.cpp:5081a75fbe8c : 95 + 0xf] 01:49:51 INFO - eip = 0x5fc75cd6 esp = 0x0612f760 ebp = 0x0612f774 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 6 xul.dll!mozilla::MediaFormatReader::ReleaseMediaResources() [MediaFormatReader.cpp:5081a75fbe8c : 1624 + 0xc] 01:49:51 INFO - eip = 0x5fc354f3 esp = 0x0612f77c ebp = 0x0612f790 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 7 xul.dll!mozilla::MediaDecoderReader::Shutdown() [MediaDecoderReader.cpp:5081a75fbe8c : 370 + 0x7] 01:49:51 INFO - eip = 0x5fc430df esp = 0x0612f784 ebp = 0x0612f790 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 8 xul.dll!mozilla::MediaFormatReader::Shutdown() [MediaFormatReader.cpp:5081a75fbe8c : 141 + 0xa] 01:49:51 INFO - eip = 0x5fc43616 esp = 0x0612f798 ebp = 0x0612f7a8 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 9 xul.dll!mozilla::detail::MethodCallInvokeHelper<RefPtr<mozilla::MozPromise<bool,bool,0> >,mozilla::MediaDecoderReader>(RefPtr<mozilla::MozPromise<bool,bool,0> > ( mozilla::MediaDecoderReader::*)(void),mozilla::MediaDecoderReader *,mozilla::Tuple<> &,mozilla::IndexSequence<>) [MozPromise.h:5081a75fbe8c : 917 + 0xb] 01:49:51 INFO - eip = 0x5fbdf5e9 esp = 0x0612f7b0 ebp = 0x0612f7bc 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 10 xul.dll!mozilla::detail::MethodCall<mozilla::MozPromise<bool,bool,0>,mozilla::MediaDecoderReader>::Invoke() [MozPromise.h:5081a75fbe8c : 942 + 0x19] 01:49:51 INFO - eip = 0x5fc25eb9 esp = 0x0612f7c4 ebp = 0x0612f7dc 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 11 xul.dll!mozilla::detail::ProxyRunnable<mozilla::MozPromise<bool,bool,0>,mozilla::MediaDecoderReader>::Run() [MozPromise.h:5081a75fbe8c : 960 + 0x16] 01:49:51 INFO - eip = 0x5fc3c859 esp = 0x0612f7e4 ebp = 0x0612f7f0 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 12 xul.dll!mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [TaskDispatcher.h:5081a75fbe8c : 192 + 0x1d] 01:49:51 INFO - eip = 0x5e517d34 esp = 0x0612f7f8 ebp = 0x0612f808 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 13 xul.dll!mozilla::TaskQueue::Runner::Run() [TaskQueue.cpp:5081a75fbe8c : 171 + 0xe] 01:49:51 INFO - eip = 0x5e517c01 esp = 0x0612f810 ebp = 0x0612f868 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 14 xul.dll!nsThreadPool::Run() [nsThreadPool.cpp:5081a75fbe8c : 228 + 0xe] 01:49:51 INFO - eip = 0x5e5184e0 esp = 0x0612f870 ebp = 0x0612f8b4 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 15 xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:5081a75fbe8c : 994 + 0xe] 01:49:51 INFO - eip = 0x5e51546d esp = 0x0612f8bc ebp = 0x0612f99c 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 16 xul.dll!NS_ProcessNextEvent(nsIThread *,bool) [nsThreadUtils.cpp:5081a75fbe8c : 297 + 0xd] 01:49:51 INFO - eip = 0x5e54404c esp = 0x0612f9a4 ebp = 0x0612f9b0 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 17 xul.dll!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate *) [MessagePump.cpp:5081a75fbe8c : 361 + 0xa] 01:49:51 INFO - eip = 0x5e815ee5 esp = 0x0612f9b8 ebp = 0x0612f9dc 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 18 xul.dll!MessageLoop::RunInternal() [message_loop.cc:5081a75fbe8c : 234 + 0xf] 01:49:51 INFO - eip = 0x5e7e4053 esp = 0x0612f9e4 ebp = 0x0612f9fc 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 19 xul.dll!MessageLoop::RunHandler() [message_loop.cc:5081a75fbe8c : 227 + 0x5] 01:49:51 INFO - eip = 0x5e7e400b esp = 0x0612fa04 ebp = 0x0612fa30 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 20 xul.dll!MessageLoop::Run() [message_loop.cc:5081a75fbe8c : 201 + 0x7] 01:49:51 INFO - eip = 0x5e7e3d55 esp = 0x0612fa38 ebp = 0x0612fa50 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 21 xul.dll!nsThread::ThreadFunc(void *) [nsThread.cpp:5081a75fbe8c : 396 + 0xc] 01:49:51 INFO - eip = 0x5e51a9c5 esp = 0x0612fa58 ebp = 0x0612fa90 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 22 nss3.dll!_PR_NativeRunThread [pruthr.c:5081a75fbe8c : 397 + 0x6] 01:49:51 INFO - eip = 0x67f2594f esp = 0x0612fa98 ebp = 0x0612fab0 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 23 nss3.dll!pr_root [w95thred.c:5081a75fbe8c : 95 + 0xa] 01:49:51 INFO - eip = 0x67f1998f esp = 0x0612fab8 ebp = 0x0612fabc 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 24 msvcr120.dll!_callthreadstartex [threadex.c : 376 + 0x6] 01:49:51 INFO - eip = 0x68d5c01d esp = 0x0612fac4 ebp = 0x0612faf4 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 25 msvcr120.dll + 0x2c001 01:49:51 INFO - eip = 0x68d5c001 esp = 0x0612fafc ebp = 0x0612fb00 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 26 kernel32.dll!BaseThreadInitThunk + 0x12 01:49:51 INFO - eip = 0x765b3c45 esp = 0x0612fb08 ebp = 0x0612fb0c 01:49:51 INFO - Found by: previous frame's frame pointer 01:49:51 INFO - 27 ntdll.dll!__RtlUserThreadStart + 0x27 01:49:51 INFO - eip = 0x77f237f5 esp = 0x0612fb14 ebp = 0x0612fb4c 01:49:51 INFO - Found by: call frame info 01:49:51 INFO - 28 ntdll.dll!_RtlUserThreadStart + 0x1b 01:49:51 INFO - eip = 0x77f237c8 esp = 0x0612fb54 ebp = 0x0612fb64 01:49:51 INFO - Found by: call frame info
Flags: needinfo?(n.nethercote)
> Backed out because it seems to cause crashes in Windows 7 debug developer > tools tests. > > Backout: https://hg.mozilla.org/integration/mozilla-inbound/rev/964a638d77fa > 01:49:51 WARNING - PROCESS-CRASH | Main app process exited normally | > application crashed [@ > mozilla::gfx::Log<1,mozilla::gfx::CriticalLogger>::WriteLog(std:: > basic_string<char,std::char_traits<char>,std::allocator<char> > const &)] I can't possibly imagine how this change could cause gfx logging assertion failures. A full search of c/cpp/h files finds log_types are only used in rlog.c, and MAX_LOG_TYPES the same (so no linkage collisions).
I was also surprised. No matter; I'll do some try runs early next week and reland if the backout was unnecessary.
Flags: needinfo?(n.nethercote)
Sorry for the backout, I searched newer Win 7 debug dt runs and found 2 crashes of that type from tests run after the backout: https://treeherder.mozilla.org/logviewer.html#?job_id=24586823&repo=mozilla-inbound https://treeherder.mozilla.org/logviewer.html#?job_id=24573263&repo=mozilla-inbound Please reland the patch.
> Please reland the patch. Will do. Thank you for checking.
https://hg.mozilla.org/mozilla-central/rev/98dd6cb59d8e
Status: ASSIGNED → RESOLVED
Closed: 10 years ago
status-firefox48: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla48
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: