New Wallet: Downloading Blocks: low on virtual memory - out of memory

[WhisperingChaos]

Version: `0.9.2`
OS & Version: Windows 7 Ultimate 6.1.7601 Service Pack 1 Build 7601
Node version: `Geth/v1.7.2-stable-1db4ecdc`
Number of blocks synchronized: 4,440,007

First time creation of new wallet. While downloading blocks & chain structure, Windows generates Your system is low on virtual memory. Not long after, all memory is exhausted and wallet program halts with, I believe, ~"Out of Memory" dialog. Close dialog box and then restart wallet application. This returns all memory to system as confirmed by viewing Task Manager. The new instance continues where last one left off. As this new instance progresses, memory consumed by the wallet program continues to increase until it too exhausts the machine's physical memory and needs to be restarted.

Restarted wallet program four times before it finally completed.

An interesting observation: The memory leak occurs only when downloading blocks. The memory leak doesn't happen when downloading block chain structures. After the last restart, nearly all the blocks had been downloaded and the program primarily focused on downloading block chain structures. During this period, physical memory usage would climb for the program but it would occasionally be released.

I noticed from the logs that you're using golang. Given the behavior described above and golang's cooperative multitasking model (remember Windows 3.1), I would suggest you view the goroutine responsible for downloading blocks and determine if it's involved in a tight execution loop. If so, that tight loop prevents the go scheduler and therefore, the go garbage collector from running. Since the garbage collector doesn't execute, the program eventually runs out of memory as it can't reclaim any thing that's no longer used by the program.

Another suggestion would be to review the code to better optimize its use of memory. Please note that you can share an array between two goroutines as long as the slices used by each function don't overlap. As defined by golang's language spec non-overlaping slices avoid race conditions. I've use this technique to statically allocate a buffer that can then be shared with two goroutines such that one goroutine fills a portion of an array that's considered "empty" while another goroutine reads from that same array using a slice that points to the "non-empty" portion. Besides eliminating what would have been many dynamic memory allocations, this method also averts unnecessary copying.

Here's some resources to help debug problem:

Zipped Wallet Logs that contain "panic" messages: node.log.zip

Windows Event Viewer message:

Windows successfully diagnosed a low virtual memory condition. The following programs consumed the
most virtual memory: geth.exe (4280) consumed 6830936064 bytes, Ethereum Wallet.exe (3688)
consumed 136228864 bytes, and Ethereum Wallet.exe (3116) consumed 90513408 bytes.

<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
- <System>
  <Provider Name="Microsoft-Windows-Resource-Exhaustion-Detector" Guid="{9988748E-C2E8-4054-85F6-0C3E1CAD2470}" /> 
  <EventID>2004</EventID> 
  <Version>0</Version> 
  <Level>3</Level> 
  <Task>3</Task> 
  <Opcode>33</Opcode> 
  <Keywords>0x8000000020000000</Keywords> 
  <TimeCreated SystemTime="2017-10-27T04:45:33.505859300Z" /> 
  <EventRecordID>27638</EventRecordID> 
  <Correlation ActivityID="{8269902F-6B7B-4374-95B7-B6D8E7BF0ED5}" /> 
  <Execution ProcessID="980" ThreadID="4396" /> 
  <Channel>System</Channel> 
  <Computer>MomOffice-PC</Computer> 
  <Security UserID="S-1-5-18" /> 
  </System>
- <UserData>
- <MemoryExhaustionInfo xmlns:auto-ns2="http://schemas.microsoft.com/win/2004/08/events" xmlns="http://www.microsoft.com/Windows/Resource/Exhaustion/Detector/Events">
- <SystemInfo>
  <SystemCommitLimit>8585490432</SystemCommitLimit> 
  <SystemCommitCharge>8325173248</SystemCommitCharge> 
  <ProcessCommitCharge>7713812480</ProcessCommitCharge> 
  <PagedPoolUsage>141836288</PagedPoolUsage> 
  <PhysicalMemorySize>8587399168</PhysicalMemorySize> 
  <PhysicalMemoryUsage>8230174720</PhysicalMemoryUsage> 
  <NonPagedPoolUsage>40955904</NonPagedPoolUsage> 
  <Processes>45</Processes> 
  </SystemInfo>
- <ProcessInfo>
- <Process_1>
  <Name>geth.exe</Name> 
  <ID>4280</ID> 
  <CreationTime>2017-10-27T04:26:59.291015600Z</CreationTime> 
  <CommitCharge>6830936064</CommitCharge> 
  <HandleCount>1253</HandleCount> 
  <Version>0.0.0.0</Version> 
  <TypeInfo>201</TypeInfo> 
  </Process_1>
- <Process_2>
  <Name>Ethereum Wallet.exe</Name> 
  <ID>3688</ID> 
  <CreationTime>2017-10-27T04:26:54.443359300Z</CreationTime> 
  <CommitCharge>136228864</CommitCharge> 
  <HandleCount>263</HandleCount> 
  <Version>0.9.2.2008</Version> 
  <TypeInfo>210</TypeInfo> 
  </Process_2>
- <Process_3>
  <Name>Ethereum Wallet.exe</Name> 
  <ID>3116</ID> 
  <CreationTime>2017-10-27T04:26:46.618164000Z</CreationTime> 
  <CommitCharge>90513408</CommitCharge> 
  <HandleCount>487</HandleCount> 
  <Version>0.9.2.2008</Version> 
  <TypeInfo>219</TypeInfo> 
  </Process_3>
- <Process_4>
  <Name /> 
  <ID>0</ID> 
  <CreationTime>1601-01-01T00:00:00.000000000Z</CreationTime> 
  <CommitCharge>0</CommitCharge> 
  <HandleCount>0</HandleCount> 
  <Version>0.0.0.0</Version> 
  <TypeInfo>0</TypeInfo> 
  </Process_4>
- <Process_5>
  <Name /> 
  <ID>0</ID> 
  <CreationTime>1601-01-01T00:00:00.000000000Z</CreationTime> 
  <CommitCharge>0</CommitCharge> 
  <HandleCount>0</HandleCount> 
  <Version>0.0.0.0</Version> 
  <TypeInfo>0</TypeInfo> 
  </Process_5>
- <Process_6>
  <Name /> 
  <ID>0</ID> 
  <CreationTime>1601-01-01T00:00:00.000000000Z</CreationTime> 
  <CommitCharge>0</CommitCharge> 
  <HandleCount>0</HandleCount> 
  <Version>0.0.0.0</Version> 
  <TypeInfo>0</TypeInfo> 
  </Process_6>
  </ProcessInfo>
- <PagedPoolInfo>
- <Tag_1>
  <Name>CM31</Name> 
  <PoolUsed>68063232</PoolUsed> 
  </Tag_1>
- <Tag_2>
  <Name>CM25</Name> 
  <PoolUsed>15142912</PoolUsed> 
  </Tag_2>
- <Tag_3>
  <Name>MmSt</Name> 
  <PoolUsed>9866672</PoolUsed> 
  </Tag_3>
  </PagedPoolInfo>
- <NonPagedPoolInfo>
- <Tag_1>
  <Name>Mdl</Name> 
  <PoolUsed>2546544</PoolUsed> 
  </Tag_1>
- <Tag_2>
  <Name>Pool</Name> 
  <PoolUsed>1742416</PoolUsed> 
  </Tag_2>
- <Tag_3>
  <Name>File</Name> 
  <PoolUsed>1379760</PoolUsed> 
  </Tag_3>
  </NonPagedPoolInfo>
- <ExhaustionEventInfo>
  <Time>2017-10-27T04:45:25.655870600Z</Time> 
  </ExhaustionEventInfo>
  </MemoryExhaustionInfo>
  </UserData>
  </Event>

[achempion]

What is your memory size by the way?

[WhisperingChaos]

8GB - Also machine configured to disable virtual memory management page files, so physical RAM = maximum memory amount.

That said, I currently am at loss as to why the Event Viewer log entry, provided by first post reports:

<SystemInfo>
  <SystemCommitLimit>8585490432</SystemCommitLimit> 
  <SystemCommitCharge>8325173248</SystemCommitCharge> 
  <ProcessCommitCharge>7713812480</ProcessCommitCharge> 
  <PagedPoolUsage>141836288</PagedPoolUsage> 
**<PhysicalMemorySize>8587399168</PhysicalMemorySize>** 
  <PhysicalMemoryUsage>8230174720</PhysicalMemoryUsage> 
  <NonPagedPoolUsage>40955904</NonPagedPoolUsage> 

[WhisperingChaos]

The "panic" stack trace provided in the zipped log files: (node.log.1, node.log.2) above includes C:/gopath/src/github.com/ethereum/go-ethereum/p2p/peer.go:251 +0xb4 fp=0xc164af9fd0 sp=0xc164af9ed8 pc=0x9c1124 runtime.goexit(). This references a tight loop in the positive execution pathway, as it lacks a select mechanism, channel request, or explicit runtime function that would yield its execution to go's scheduler. Unfortunately, I don't know enough about the code base to confidently identify this snippet causing the memory leak but it might be a good place to start.

func (p *Peer) readLoop(errc chan<- error) {
	defer p.wg.Done()
	for {
		msg, err := p.rw.ReadMsg()
		if err != nil {
			errc <- err
			return
		}
		msg.ReceivedAt = time.Now()
		if err = p.handle(msg); err != nil {
			errc <- err
			return
		}
	}
}

Also, I would suggest avoiding naked channel reads/writes like errc <- err. In this situation, if the goroutine consuming messages from this channel hasn't started, is too busy, or has terminated without closing the channel, then this snippet will potentially block the function's continued execution forever. Writing a function to encapsulate a select block whose default case writes to a log using a closure is relatively simple and confers much safety and reliability.

[WhisperingChaos]

Duplicate of go-ethereum #15157.

[lock]

This thread has been automatically locked because it has not had recent activity. Please open a new issue for related bugs and link to relevant comments in this thread.