log2.txt

2016-09-26 16:13:54.281717 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Init()
2016-09-26 16:13:54.281743 UTC - [Main Thread]: D/cache2 CacheFileHandles::CacheFileHandles() [this=7f083f581600]
2016-09-26 16:13:54.281748 UTC - [Main Thread]: D/cache2 CacheFileIOManager::CacheFileIOManager [this=7f083f5815c0]
2016-09-26 16:13:54.281861 UTC - [Main Thread]: D/cache2 CacheFileIOManager::OnProfile() [gInstance=7f083f5815c0]
2016-09-26 16:13:54.282151 UTC - [Main Thread]: D/cache2 CacheIndex::Init()
2016-09-26 16:13:54.282162 UTC - [Main Thread]: D/cache2 CacheIndex::CacheIndex [this=7f08402d1240]
2016-09-26 16:13:54.282166 UTC - [Main Thread]: D/cache2 CacheIndex::ReadIndexFromDisk()
2016-09-26 16:13:54.282169 UTC - [Main Thread]: D/cache2 CacheIndex::ChangeState() changing state INITIAL -> READING
2016-09-26 16:13:54.282172 UTC - [Main Thread]: D/cache2 CacheFileIOManager::CacheIndexStateChanged()
2016-09-26 16:13:54.282217 UTC - [Main Thread]: D/cache2 CacheFileIOManager::OpenFile() [key=index, flags=8, listener=7f083f779910]
2016-09-26 16:13:54.282228 UTC - [Main Thread]: D/cache2 CacheFileIOManager::OpenFile() [key=index.log, flags=8, listener=7f083f779940]
2016-09-26 16:13:54.282254 UTC - [Main Thread]: D/cache2 CacheFileIOManager::OpenFile() [key=index.tmp, flags=8, listener=7f083f779970]
2016-09-26 16:13:54.282283 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenSpecialFileInternal() [key=index, flags=8]
2016-09-26 16:13:54.282417 UTC - [Cache2 I/O]: D/cache2 CacheFileContextEvictor::CacheFileContextEvictor() [this=7f083f7793d0]
2016-09-26 16:13:54.282422 UTC - [Cache2 I/O]: D/cache2 CacheFileContextEvictor::Init()
2016-09-26 16:13:54.282425 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.282429 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.282435 UTC - [Cache2 I/O]: D/cache2 CacheFileContextEvictor::LoadEvictInfoFromDisk() [this=7f083f7793d0]
2016-09-26 16:13:54.282464 UTC - [Cache2 I/O]: D/cache2 CacheFileContextEvictor::~CacheFileContextEvictor() [this=7f083f7793d0]
2016-09-26 16:13:54.282469 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::StartRemovingTrash()
2016-09-26 16:13:54.282752 UTC - [Cache2 I/O]: D/cache2 CacheIndex::OnFileOpenedInternal() [opener=7f083f779910, handle=0, result=0x80040111]
2016-09-26 16:13:54.282762 UTC - [Cache2 I/O]: D/cache2 CacheIndex::FinishRead() [succeeded=0]
2016-09-26 16:13:54.282767 UTC - [Cache2 I/O]: D/cache2 CacheIndex::ProcessPendingOperations()
2016-09-26 16:13:54.282770 UTC - [Cache2 I/O]: D/cache2 CacheIndex::StartUpdatingIndex() [rebuild=1]
2016-09-26 16:13:54.282773 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=0, notInitialized=0, removed=0, dirty=0, fresh=0, empty=0, size=0]
2016-09-26 16:13:54.282795 UTC - [Cache2 I/O]: D/cache2 CacheIndex::ChangeState() changing state READING -> BUILDING
2016-09-26 16:13:54.282798 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimit()
2016-09-26 16:13:54.282806 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::CacheIndexStateChanged()
2016-09-26 16:13:54.282816 UTC - [Cache2 I/O]: D/cache2 CacheIndex::StartUpdatingIndex() - 0 ms elapsed since startup, scheduling timer to fire in 50000 ms.
2016-09-26 16:13:54.282832 UTC - [Cache2 I/O]: D/cache2 CacheIndex::ScheduleUpdateTimer() [delay=50000]
2016-09-26 16:13:54.282856 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenSpecialFileInternal() [key=index.log, flags=8]
2016-09-26 16:13:54.282870 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenSpecialFileInternal() [key=index.tmp, flags=8]
2016-09-26 16:13:54.282880 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal()
2016-09-26 16:13:54.283023 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.283029 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.283031 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize()
2016-09-26 16:13:54.283034 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize() - returning 0
2016-09-26 16:13:54.283039 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal() - Cache size and free space in limits. [cacheSize=0kB, cacheSizeLimit=256000kB, freeSpace=106633871360, freeSpaceLimit=5242880]
2016-09-26 16:13:54.291171 UTC - [Main Thread]: D/nsHttp Creating nsHttpHandler [this=7f083f587000].
2016-09-26 16:13:54.291226 UTC - [Main Thread]: D/nsHttp nsHttpHandler::Init
2016-09-26 16:13:54.291334 UTC - [Main Thread]: D/nsHttp nsHttpHandler::PrefsChanged [pref=(null)]
2016-09-26 16:13:54.291340 UTC - [Main Thread]: D/nsHttp nsHttpHandler::PrefsChanged Security Pref Changed (null)
2016-09-26 16:13:54.291886 UTC - [Main Thread]: D/nsHttp nsHttpHandler::MakeNewRequestTokenBucket this=7f083f587000 child=0
2016-09-26 16:13:54.291966 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::Init
2016-09-26 16:13:54.291971 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::Init
2016-09-26 16:13:54.291980 UTC - [Main Thread]: V/nsHttp Creating nsHttpConnectionMgr @7f0849e7e1e0
2016-09-26 16:13:54.291983 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::Init
2016-09-26 16:13:54.291993 UTC - [Main Thread]: D/nsHttp > legacy-app-name = Mozilla
2016-09-26 16:13:54.291995 UTC - [Main Thread]: D/nsHttp > legacy-app-version = 5.0
2016-09-26 16:13:54.291998 UTC - [Main Thread]: D/nsHttp > platform = X11
2016-09-26 16:13:54.292000 UTC - [Main Thread]: D/nsHttp > oscpu = Linux x86_64
2016-09-26 16:13:54.292002 UTC - [Main Thread]: D/nsHttp > misc = rv:52.0
2016-09-26 16:13:54.292005 UTC - [Main Thread]: D/nsHttp > product = Gecko
2016-09-26 16:13:54.292007 UTC - [Main Thread]: D/nsHttp > product-sub = 20100101
2016-09-26 16:13:54.292009 UTC - [Main Thread]: D/nsHttp > app-name = 
2016-09-26 16:13:54.292011 UTC - [Main Thread]: D/nsHttp > app-version = 52.0a1
2016-09-26 16:13:54.292014 UTC - [Main Thread]: D/nsHttp > compat-firefox = Firefox/52.0
2016-09-26 16:13:54.292016 UTC - [Main Thread]: D/nsHttp nsHttpHandler::BuildUserAgent
2016-09-26 16:13:54.292024 UTC - [Main Thread]: D/nsHttp > user-agent = Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 /52.0a1
2016-09-26 16:13:54.292053 UTC - [Main Thread]: D/nsHttp nsHttpHandler::MakeNewRequestTokenBucket this=7f083f587000 child=0
2016-09-26 16:13:54.294063 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NewProxiedChannel [proxyInfo=0]
2016-09-26 16:13:54.294092 UTC - [Main Thread]: V/nsHttp Creating HttpBaseChannel @3f556000
2016-09-26 16:13:54.294098 UTC - [Main Thread]: D/nsHttp Creating nsHttpChannel [this=7f083f556000]
2016-09-26 16:13:54.299277 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::Init [this=7f083f556000]
2016-09-26 16:13:54.299299 UTC - [Main Thread]: V/nsHttp host=localhost port=36870
2016-09-26 16:13:54.299303 UTC - [Main Thread]: V/nsHttp uri=http://localhost:36870/content
2016-09-26 16:13:54.299315 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Init [this=7f083f556000]
2016-09-26 16:13:54.300677 UTC - [Main Thread]: D/nsHttp nsHttpChannel::AsyncOpen [this=7f083f556000]
2016-09-26 16:13:54.401863 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::SetRequestHeader [this=7f083f556000 header="Cookie" value="" merge=0]
2016-09-26 16:13:54.401882 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=3f556058 event="http-on-opening-request"]
2016-09-26 16:13:54.401924 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ResolveProxy [this=7f083f556000]
2016-09-26 16:13:54.403632 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnProxyAvailable [this=7f083f556000 pi=0 status=0 mStatus=0]
2016-09-26 16:13:54.403646 UTC - [Main Thread]: D/nsHttp nsHttpChannel::BeginConnect [this=7f083f556000]
2016-09-26 16:13:54.403655 UTC - [Main Thread]: D/nsHttp host=localhost port=36870
2016-09-26 16:13:54.403660 UTC - [Main Thread]: D/nsHttp uri=http://localhost:36870/content
2016-09-26 16:13:54.403925 UTC - [Main Thread]: D/nsHttp AltSvcCache::LookupMapping 7f0849e7e1e8 http:localhost:36870:.
2016-09-26 16:13:54.404072 UTC - [Main Thread]: D/nsHttp AltSvcCache::LookupMapping 7f0849e7e1e8 MISS
2016-09-26 16:13:54.404097 UTC - [Main Thread]: D/nsHttp AltSvcCache::GetAltServiceMapping 7f0849e7e1e8 key=http:localhost:36870:. existing=0 validated=0 ttl=0
2016-09-26 16:13:54.404109 UTC - [Main Thread]: D/nsHttp nsHttpChannel 7f083f556000 Using default connection info
2016-09-26 16:13:54.404117 UTC - [Main Thread]: V/nsHttp Init nsHttpConnectionInfo @7f0849e78cc0
2016-09-26 16:13:54.404186 UTC - [Main Thread]: D/nsHttp nsHttpChannelAuthProvider::AddAuthorizationHeaders? [this=7f083d693700 channel=7f083f556538]
2016-09-26 16:13:54.404204 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::GetAuthEntryForPath [key=http://localhost:36870 path=/]
2016-09-26 16:13:54.404214 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=3f556058 event="http-on-modify-request"]
2016-09-26 16:13:54.404239 UTC - [Main Thread]: D/nsHttp nsHttpChannel::BeginConnect [this=7f083f556000] prefetching
2016-09-26 16:13:54.404342 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ContinueBeginConnectWithResult [this=7f083f556000]
2016-09-26 16:13:54.404350 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Connect [this=7f083f556000]
2016-09-26 16:13:54.404460 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::SpeculativeConnect [ci=......localhost:36870]
2016-09-26 16:13:54.404528 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OpenCacheEntry [this=7f083f556000]
2016-09-26 16:13:54.404544 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgSpeculativeConnect [ci=......localhost:36870]
2016-09-26 16:13:54.404552 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Init()
2016-09-26 16:13:54.404570 UTC - [Socket Thread]: V/nsHttp Init nsHttpConnectionInfo @7f0849e78f60
2016-09-26 16:13:54.404595 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::AtActiveConnectionLimit [ci=......localhost:36870 caps=401]
2016-09-26 16:13:54.404602 UTC - [Socket Thread]: V/nsHttp    connection count = 0, limit 6
2016-09-26 16:13:54.404606 UTC - [Socket Thread]: V/nsHttp   result: false
2016-09-26 16:13:54.404609 UTC - [Main Thread]: D/cache2 CacheStorageService::AddStorageEntry [entryKey=:http://localhost:36870/content, contextKey=]
2016-09-26 16:13:54.404613 UTC - [Socket Thread]: V/nsHttp Creating nsHalfOpenSocket [this=7f083f7b3e20 trans=7f083d691560 ent=localhost key=......localhost:36870]
2016-09-26 16:13:54.404622 UTC - [Main Thread]: D/cache2   new storage entries table for context ''
2016-09-26 16:13:54.404671 UTC - [Main Thread]: D/cache2 CacheEntry::CacheEntry [this=7f083d693c00]
2016-09-26 16:13:54.404676 UTC - [Main Thread]: D/cache2 CacheStorageService::RecordMemoryOnlyEntry [entry=7f083d693c00, memory=0, overwrite=1]
2016-09-26 16:13:54.404681 UTC - [Main Thread]: D/cache2   not recorded as memory only
2016-09-26 16:13:54.404686 UTC - [Main Thread]: D/cache2   new entry 7f083d693c00 for :http://localhost:36870/content
2016-09-26 16:13:54.404690 UTC - [Main Thread]: D/cache2 New CacheEntryHandle 7f083d6896e0 for entry 7f083d693c00
2016-09-26 16:13:54.404693 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::SetupStreams [this=7f083f7b3e20 ent=......localhost:36870] setup routed transport to origin localhost:36870 via :443
2016-09-26 16:13:54.404695 UTC - [Main Thread]: D/cache2 CacheEntry::AsyncOpen [this=7f083d693c00, state=NOTLOADED, flags=16, callback=7f083f556520]
2016-09-26 16:13:54.404708 UTC - [Main Thread]: D/cache2 CacheEntry::RememberCallback [this=7f083d693c00, cb=7f083f556520, state=NOTLOADED]
2016-09-26 16:13:54.404713 UTC - [Main Thread]: D/cache2 CacheEntry::Load [this=7f083d693c00, trunc=0]
2016-09-26 16:13:54.404716 UTC - [Main Thread]: D/cache2 CacheIndex::HasEntry() [key=:http://localhost:36870/content]
2016-09-26 16:13:54.404726 UTC - [Main Thread]: D/cache2 CacheIndex::HasEntry() - result is 2
2016-09-26 16:13:54.404733 UTC - [Main Thread]: D/cache2 CacheFile::CacheFile() [this=7f08402e5e00]
2016-09-26 16:13:54.404748 UTC - [Main Thread]: D/cache2 CacheEntry::BackgroundOp this=7f083d693c00 dipatch of 1
2016-09-26 16:13:54.404749 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ActivateTimeoutTick() this=7f0849e7e1e0 mTimeoutTick=0
2016-09-26 16:13:54.404754 UTC - [Main Thread]: D/cache2   performing load, file=7f08402e5e00
2016-09-26 16:13:54.404764 UTC - [Cache2 I/O]: D/cache2 CacheEntry REGISTER [this=7f083d693c00]
2016-09-26 16:13:54.404780 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::SetupPrimaryStream [this=7f083f7b3e20 ent=localhost rv=0]
2016-09-26 16:13:54.404792 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::RegisterEntry [entry=7f083d693c00]
2016-09-26 16:13:54.404793 UTC - [Main Thread]: D/cache2 CacheFile::Init() [this=7f08402e5e00, key=:http://localhost:36870/content, createNew=0, memoryOnly=0, priority=0, listener=7f083d693c10]
2016-09-26 16:13:54.404808 UTC - [Main Thread]: D/cache2 CacheFileIOManager::OpenFile() [key=:http://localhost:36870/content, flags=1, listener=7f08402e5e08]
2016-09-26 16:13:54.404825 UTC - [Main Thread]: D/cache2 CacheEntry::OnHandleClosed [this=7f083d693c00, state=LOADING, handle=7f083d6896e0]
2016-09-26 16:13:54.404829 UTC - [Main Thread]: D/cache2   not the writer
2016-09-26 16:13:54.404835 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenFileInternal() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, key=:http://localhost:36870/content, flags=1]
2016-09-26 16:13:54.404836 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Connect 7f083f556000 AwaitingCacheCallbacks forces async
2016-09-26 16:13:54.404852 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ContinueBeginConnectWithResult result [this=7f083f556000 rv=0 mCanceled=0]
2016-09-26 16:13:54.404875 UTC - [Cache2 I/O]: D/cache2 CacheFileHandles::GetHandle() hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3 no handle entries found
2016-09-26 16:13:54.404881 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::SetupBackupTimer() [this=7f083f7b3e20], did not arm
2016-09-26 16:13:54.404911 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::CacheFileHandle() [this=7f083d6916e0, hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3]
2016-09-26 16:13:54.404920 UTC - [Cache2 I/O]: D/cache2 CacheFileHandles::NewHandle() hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3 created new handle 7f083d6916e0, entry=7f083f571c68
2016-09-26 16:13:54.404927 UTC - [Cache2 I/O]: D/cache2 CacheIndex::AddEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3]
2016-09-26 16:13:54.404933 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.404938 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=0, notInitialized=0, removed=0, dirty=0, fresh=0, empty=0, size=0]
2016-09-26 16:13:54.404945 UTC - [Cache2 I/O]: D/cache2 CacheIndexEntry::CacheIndexEntry() - Created record [rec=7f083d686130]
2016-09-26 16:13:54.404955 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.404960 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=1, removed=0, dirty=1, fresh=1, empty=0, size=0]
2016-09-26 16:13:54.404973 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnFileOpened() [this=7f08402e5e00, rv=0x00000000, handle=7f083d6916e0]
2016-09-26 16:13:54.404983 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::CacheFileMetadata() [this=7f0848085f20, handle=7f083d6916e0, key=:http://localhost:36870/content]
2016-09-26 16:13:54.405009 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::ReadMetadata() [this=7f0848085f20, listener=7f08402e5e10]
2016-09-26 16:13:54.405015 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::ReadMetadata() - Filesize == 0, creating empty metadata. [this=7f0848085f20]
2016-09-26 16:13:54.405020 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=240]
2016-09-26 16:13:54.405025 UTC - [Cache2 I/O]: D/cache2   mMemorySize=240 (+240,-0)
2016-09-26 16:13:54.405030 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::SetPinned [this=7f083d6916e0, pinned=0]
2016-09-26 16:13:54.405030 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::OnOutputStreamReady [this=7f083f7b3e20 ent=localhost primary]
2016-09-26 16:13:54.405039 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnMetadataRead() [this=7f08402e5e00, rv=0x00000000]
2016-09-26 16:13:54.405044 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ConditionallyStopTimeoutTick armed=1 active=0
2016-09-26 16:13:54.405050 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::InitIndexEntry() [handle=7f083d6916e0, appId=0, anonymous=0, inIsolatedMozBrowser=0, pinned=0]
2016-09-26 16:13:54.405054 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ConditionallyStopTimeoutTick stop==true
2016-09-26 16:13:54.405075 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::UpdateIndexEntry() [handle=7f083d6916e0, frecency=0, expirationTime=4294967295]
2016-09-26 16:13:54.405077 UTC - [Socket Thread]: V/nsHttp Creating nsHttpConnection @7f08402d13e0
2016-09-26 16:13:54.405086 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::OnOutputStreamReady Created new nshttpconnection 7f08402d13e0
2016-09-26 16:13:54.405086 UTC - [Cache2 I/O]: D/cache2 CacheEntry::OnFileReady [this=7f083d693c00, rv=0x00000000, new=1]
2016-09-26 16:13:54.405095 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Init this=7f08402d13e0
2016-09-26 16:13:54.405096 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.405105 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.405110 UTC - [Cache2 I/O]: D/cache2   pinning=0
2016-09-26 16:13:54.405114 UTC - [Cache2 I/O]: D/cache2 CacheEntry::InvokeCallbacks BEGIN [this=7f083d693c00]
2016-09-26 16:13:54.405115 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::OnOutputStreamReady no transaction match returning conn 7f08402d13e0 to pool
2016-09-26 16:13:54.405124 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgReclaimConnection [conn=7f08402d1418]
2016-09-26 16:13:54.405131 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::SetupSSL 7f08402d13e0 caps=0x401 ......localhost:36870
2016-09-26 16:13:54.405131 UTC - [Cache2 I/O]: D/cache2 CacheEntry::InvokeCallback [this=7f083d693c00, state=EMPTY, cb=7f083f556520]
2016-09-26 16:13:54.405140 UTC - [Cache2 I/O]: D/cache2   advancing to WRITING state
2016-09-26 16:13:54.405142 UTC - [Socket Thread]: V/nsHttp   adding connection to idle list
2016-09-26 16:13:54.405148 UTC - [Cache2 I/O]: D/cache2 CacheEntry::InvokeAvailableCallback [this=7f083d693c00, state=WRITING, cb=7f083f556520, r/o=0, n/w=0]
2016-09-26 16:13:54.405151 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::BeginIdleMonitoring [this=7f08402d13e0]
2016-09-26 16:13:54.405155 UTC - [Socket Thread]: V/nsHttp Entering Idle Monitoring Mode [this=7f08402d13e0]
2016-09-26 16:13:54.405155 UTC - [Cache2 I/O]: D/cache2   redispatched, (rv = 0x00000000)
2016-09-26 16:13:54.405163 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::PruneDeadConnectionsAfter
2016-09-26 16:13:54.405169 UTC - [Cache2 I/O]: D/cache2 CacheEntry::InvokeCallbacks END [this=7f083d693c00]
2016-09-26 16:13:54.405176 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=5]
2016-09-26 16:13:54.405177 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.405189 UTC - [Cache2 I/O]: D/cache2 CacheIndex::InitEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, appId=0, anonymous=0, inIsolatedMozBrowser=0, pinned=0]
2016-09-26 16:13:54.405189 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.405196 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.405202 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.405204 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=1, removed=0, dirty=1, fresh=1, empty=0, size=0]
2016-09-26 16:13:54.405209 UTC - [Socket Thread]: V/nsHttp Destroying nsHalfOpenSocket [this=7f083f7b3e20]
2016-09-26 16:13:54.405213 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.405221 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.405228 UTC - [Cache2 I/O]: D/cache2 CacheIndex::InsertRecordToFrecencyArray() [record=7f083d686130, hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3]
2016-09-26 16:13:54.405242 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=, size=0]
2016-09-26 16:13:54.405249 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.405254 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.405259 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.405260 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.405267 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.405277 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=4]
2016-09-26 16:13:54.405287 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=0, expirationTime=4294967295, size=]
2016-09-26 16:13:54.405293 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.405294 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.405299 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.405306 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.405308 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.405313 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.405316 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.405322 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.422929 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnLookupComplete [this=7f083f556000] prefetch complete: success status[0x0]
2016-09-26 16:13:54.432344 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeAvailableCallback [this=7f083d693c00, state=WRITING, cb=7f083f556520, r/o=0, n/w=0]
2016-09-26 16:13:54.432380 UTC - [Main Thread]: D/cache2 CacheFile::OnFetched() this=7f08402e5e00
2016-09-26 16:13:54.432386 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.432432 UTC - [Main Thread]: D/cache2 CacheEntry::BackgroundOp this=7f083d693c00 dipatch of 2
2016-09-26 16:13:54.432440 UTC - [Main Thread]: D/cache2 New CacheEntryHandle 7f0849e16660 for entry 7f083d693c00
2016-09-26 16:13:54.432449 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnCacheEntryAvailable [this=7f083f556000 entry=7f0849e16660 new=1 appcache=0 status=0 mAppCache=0 mAppCacheForWrite=0]
2016-09-26 16:13:54.432457 UTC - [Main Thread]: D/nsHttp nsHttpChannel::SetupTransaction [this=7f083f556000]
2016-09-26 16:13:54.432482 UTC - [Main Thread]: D/nsHttp Creating nsHttpTransaction @7f083d69c000
2016-09-26 16:13:54.432489 UTC - [Main Thread]: D/nsHttp nsHttpChannel 7f083f556000 created nsHttpTransaction 7f083d69c000
2016-09-26 16:13:54.432496 UTC - [Main Thread]: D/nsHttp nsHttpTransaction::Init [this=7f083d69c000 caps=1]
2016-09-26 16:13:54.432528 UTC - [Cache2 I/O]: D/cache2 CacheEntry FRECENCYUPDATE [this=7f083d693c00, frecency=283979,7879490585]
2016-09-26 16:13:54.432544 UTC - [Main Thread]: I/nsHttp http request [
2016-09-26 16:13:54.432561 UTC - [Main Thread]: I/nsHttp   GET /content HTTP/1.1
2016-09-26 16:13:54.432566 UTC - [Main Thread]: I/nsHttp   Host: localhost:36870
2016-09-26 16:13:54.432573 UTC - [Main Thread]: I/nsHttp   User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 /52.0a1
2016-09-26 16:13:54.432579 UTC - [Main Thread]: I/nsHttp   Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
2016-09-26 16:13:54.432593 UTC - [Main Thread]: I/nsHttp   Accept-Language: en-US,en;q=0.5
2016-09-26 16:13:54.432598 UTC - [Main Thread]: I/nsHttp   Accept-Encoding: gzip, deflate
2016-09-26 16:13:54.432603 UTC - [Main Thread]: I/nsHttp   Connection: keep-alive
2016-09-26 16:13:54.432607 UTC - [Main Thread]: I/nsHttp ]
2016-09-26 16:13:54.432650 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::AddTransaction [trans=7f083d69c000 0]
2016-09-26 16:13:54.432697 UTC - [Main Thread]: D/cache2   writing/revalidating
2016-09-26 16:13:54.432750 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgNewTransaction [trans=7f083d69c028]
2016-09-26 16:13:54.432771 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::SetupSSL 7f08402d13e0 caps=0x401 ......localhost:36870
2016-09-26 16:13:54.432840 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::TryDispatchTransaction without conn [trans=7f083d69c000 ci=7f0849e78f60 ci=......localhost:36870 caps=1 tunnelprovider=0 onlyreused=0 active=0 idle=1]
2016-09-26 16:13:54.432856 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::SetupSSL 7f08402d13e0 caps=0x401 ......localhost:36870
2016-09-26 16:13:54.432864 UTC - [Socket Thread]: V/nsHttp    reusing connection [conn=7f08402d13e0]
2016-09-26 16:13:54.432869 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::EndIdleMonitoring [this=7f08402d13e0]
2016-09-26 16:13:54.432874 UTC - [Socket Thread]: V/nsHttp Leaving Idle Monitoring Mode [this=7f08402d13e0]
2016-09-26 16:13:54.432880 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::StopPruneDeadConnectionsTimer
2016-09-26 16:13:54.432896 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ActivateTimeoutTick() this=7f0849e7e1e0 mTimeoutTick=7f083d68b0b0
2016-09-26 16:13:54.432931 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::DispatchTransaction [ent-ci=......localhost:36870 7f083d68af60 trans=7f083d69c000 caps=1 conn=7f08402d13e0 priority=0]
2016-09-26 16:13:54.432941 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::DispatchAbstractTransaction [ci=......localhost:36870 trans=7f083d69c000 caps=1 conn=7f08402d13e0]
2016-09-26 16:13:54.432945 UTC - [Socket Thread]: V/nsHttp    not using pipeline datastructure due to class solo.
2016-09-26 16:13:54.432954 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Activate [this=7f08402d13e0 trans=7f083d69c000 caps=1]
2016-09-26 16:13:54.432978 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::SetupSSL 7f08402d13e0 caps=0x1 ......localhost:36870
2016-09-26 16:13:54.432985 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::StartShortLivedTCPKeepalives[7f08402d13e0] idle time[10s].
2016-09-26 16:13:54.433018 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketWritable [this=7f08402d13e0] host=localhost
2016-09-26 16:13:54.433025 UTC - [Socket Thread]: V/nsHttp   writing transaction request stream
2016-09-26 16:13:54.433032 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::GetSecurityInfo trans=7f083d69c000 tlsfilter=0 socket=7f083d69ac18
2016-09-26 16:13:54.433069 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::OnSocketStatus [this=7f083d69c000 status=804b0005 progress=287]
2016-09-26 16:13:54.433076 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::OnTransportStatus 7f083d69c000 SENDING_TO without request body
2016-09-26 16:13:54.433083 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketWritable 7f08402d13e0 ReadSegments returned [rv=0 read=287 sock-cond=0]
2016-09-26 16:13:54.433088 UTC - [Socket Thread]: V/nsHttp   writing transaction request stream
2016-09-26 16:13:54.433094 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketWritable 7f08402d13e0 ReadSegments returned [rv=0 read=0 sock-cond=0]
2016-09-26 16:13:54.433100 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::OnSocketStatus [this=7f083d69c000 status=804b000a progress=0]
2016-09-26 16:13:54.433113 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::ResumeRecv [this=7f08402d13e0]
2016-09-26 16:13:54.433205 UTC - [Socket Thread]: V/nsHttp    dispatched step 2 (idle) trans=7f083d69c000
2016-09-26 16:13:54.433213 UTC - [Socket Thread]: V/nsHttp   ProcessNewTransaction Dispatch Immediately trans=7f083d69c000
2016-09-26 16:13:54.436581 UTC - [Main Thread]: D/cache2 CacheFile::SetFrecency() this=7f08402e5e00, frecency=1022327236
2016-09-26 16:13:54.436600 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.436627 UTC - [Main Thread]: D/cache2 CacheFileIOManager::UpdateIndexEntry() [handle=7f083d6916e0, frecency=1022327236, expirationTime=]
2016-09-26 16:13:54.436653 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetFrecency() [this=7f0848085f20, frecency=1022327236,000000]
2016-09-26 16:13:54.436694 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=1022327236, expirationTime=, size=]
2016-09-26 16:13:54.436713 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.436719 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.436724 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.436729 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.436736 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.509872 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable [this=7f08402d13e0]
2016-09-26 16:13:54.509895 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::WriteSegments 7f083d69c000 reentrantFlag=0
2016-09-26 16:13:54.509935 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::OnSocketStatus [this=7f083d69c000 status=804b0006 progress=169]
2016-09-26 16:13:54.509941 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ProcessData [this=7f083d69c000 count=169]
2016-09-26 16:13:54.509944 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseHead [count=169]
2016-09-26 16:13:54.509954 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [HTTP/1.1 200 OK]
2016-09-26 16:13:54.509958 UTC - [Socket Thread]: D/nsHttp nsHttpResponseHead::ParseVersion [version=HTTP/1.1 200 OK]
2016-09-26 16:13:54.509984 UTC - [Socket Thread]: D/nsHttp Have status line [version=11 status=200 statusText=OK]
2016-09-26 16:13:54.509989 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [content-type: text/plain]
2016-09-26 16:13:54.510000 UTC - [Socket Thread]: D/nsHttp ParseContentType [type=text/plain]
2016-09-26 16:13:54.510007 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [cache-control: max-age=86400]
2016-09-26 16:13:54.510015 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [connection: close]
2016-09-26 16:13:54.510022 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [server: httpd.js]
2016-09-26 16:13:54.510031 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [date: Mon, 26 Sep 2016 16:13:54 GMT]
2016-09-26 16:13:54.510040 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ParseLine [content-length: 13]
2016-09-26 16:13:54.510050 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::HandleContent [this=7f083d69c000 count=0]
2016-09-26 16:13:54.510054 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::HandleContentStart [this=7f083d69c000]
2016-09-26 16:13:54.510057 UTC - [Socket Thread]: I/nsHttp http response [
2016-09-26 16:13:54.510073 UTC - [Socket Thread]: I/nsHttp   HTTP/1.1 200 OK
2016-09-26 16:13:54.510077 UTC - [Socket Thread]: I/nsHttp   Content-Type: text/plain
2016-09-26 16:13:54.510080 UTC - [Socket Thread]: I/nsHttp   Cache-Control: max-age=86400
2016-09-26 16:13:54.510083 UTC - [Socket Thread]: I/nsHttp   Connection: close
2016-09-26 16:13:54.510086 UTC - [Socket Thread]: I/nsHttp   Server: httpd.js
2016-09-26 16:13:54.510089 UTC - [Socket Thread]: I/nsHttp   Date: Mon, 26 Sep 2016 16:13:54 GMT
2016-09-26 16:13:54.510092 UTC - [Socket Thread]: I/nsHttp   Content-Length: 13
2016-09-26 16:13:54.510095 UTC - [Socket Thread]: I/nsHttp     OriginalHeaders
2016-09-26 16:13:54.510098 UTC - [Socket Thread]: I/nsHttp   Content-Type: text/plain
2016-09-26 16:13:54.510107 UTC - [Socket Thread]: I/nsHttp   Cache-Control: max-age=86400
2016-09-26 16:13:54.510110 UTC - [Socket Thread]: I/nsHttp   Connection: close
2016-09-26 16:13:54.510113 UTC - [Socket Thread]: I/nsHttp   Server: httpd.js
2016-09-26 16:13:54.510116 UTC - [Socket Thread]: I/nsHttp   Date: Mon, 26 Sep 2016 16:13:54 GMT
2016-09-26 16:13:54.510119 UTC - [Socket Thread]: I/nsHttp   Content-Length: 13
2016-09-26 16:13:54.510121 UTC - [Socket Thread]: I/nsHttp ]
2016-09-26 16:13:54.510126 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnHeadersAvailable [this=7f08402d13e0 trans=7f083d69c000 response-head=7f083f5e3700]
2016-09-26 16:13:54.510137 UTC - [Socket Thread]: V/nsHttp Assessing red penalty to localhost class 3 for event 131075. Penalty now 0, throttle[3] = 250
2016-09-26 16:13:54.510147 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::HandleContent [this=7f083d69c000 count=0 read=0 mContentRead=0 mContentLength=13]
2016-09-26 16:13:54.510152 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable 7f08402d13e0 trans->ws rv=0 n=0 socketin=0
2016-09-26 16:13:54.510156 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::WriteSegments 7f083d69c000 reentrantFlag=0
2016-09-26 16:13:54.510164 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable 7f08402d13e0 trans->ws rv=0 n=0 socketin=80470007
2016-09-26 16:13:54.510167 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::ResumeRecv [this=7f08402d13e0]
2016-09-26 16:13:54.515072 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable [this=7f08402d13e0]
2016-09-26 16:13:54.515100 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::WriteSegments 7f083d69c000 reentrantFlag=0
2016-09-26 16:13:54.515110 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::OnSocketStatus [this=7f083d69c000 status=804b0006 progress=182]
2016-09-26 16:13:54.515114 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::ProcessData [this=7f083d69c000 count=13]
2016-09-26 16:13:54.515135 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::HandleContent [this=7f083d69c000 count=13]
2016-09-26 16:13:54.515140 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::HandleContent [this=7f083d69c000 count=13 read=13 mContentRead=13 mContentLength=13]
2016-09-26 16:13:54.515144 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction 7f083d69c000 request context set to null in ReleaseBlockingTransaction() - was 0
2016-09-26 16:13:54.515157 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable 7f08402d13e0 trans->ws rv=0 n=13 socketin=0
2016-09-26 16:13:54.515161 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::WriteSegments 7f083d69c000 reentrantFlag=0
2016-09-26 16:13:54.515165 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::OnSocketReadable 7f08402d13e0 trans->ws rv=80470002 n=13 socketin=0
2016-09-26 16:13:54.515169 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::CloseTransaction[this=7f08402d13e0 trans=7f083d69c000 reason=80470002]
2016-09-26 16:13:54.515186 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction::Close [this=7f083d69c000 reason=0]
2016-09-26 16:13:54.515201 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ReclaimConnection [conn=7f08402d13e0]
2016-09-26 16:13:54.515224 UTC - [Socket Thread]: D/nsHttp nsHttpTransaction 7f083d69c000 request context set to null in ReleaseBlockingTransaction() - was 0
2016-09-26 16:13:54.515244 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgReclaimConnection [conn=7f08402d1418]
2016-09-26 16:13:54.515253 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ConditionallyStopTimeoutTick armed=1 active=0
2016-09-26 16:13:54.515256 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ConditionallyStopTimeoutTick stop==true
2016-09-26 16:13:54.515263 UTC - [Socket Thread]: V/nsHttp   connection cannot be reused; closing connection
2016-09-26 16:13:54.515268 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Close [this=7f08402d13e0 reason=80004004]
2016-09-26 16:13:54.515280 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Close drained 0 bytes
2016-09-26 16:13:54.515295 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.515300 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=0 queued=0]
2016-09-26 16:13:54.515305 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=0 queued=0]
2016-09-26 16:13:54.515309 UTC - [Socket Thread]: V/nsHttp Destroying nsHttpConnection @7f08402d13e0
2016-09-26 16:13:54.515313 UTC - [Socket Thread]: V/nsHttp nsHttpConnection 7f08402d13e0 performed 1 HTTP/1.x transactions
2016-09-26 16:13:54.515366 UTC - [Socket Thread]: V/nsHttp nsHttpConnection 7f08402d13e0 read 0kb on connection spdy=0
2016-09-26 16:13:54.516590 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnStartRequest [this=7f083f556000 request=7f083f571e00 status=0]
2016-09-26 16:13:54.516603 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ProcessResponse [this=7f083f556000 httpStatus=200]
2016-09-26 16:13:54.516611 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=3f556058 event="http-on-examine-response"]
2016-09-26 16:13:54.516622 UTC - [Main Thread]: D/nsHttp nsHttpChannelAuthProvider::CheckForSuperfluousAuth? [this=7f083d693700 channel=7f083f556538]
2016-09-26 16:13:54.516628 UTC - [Main Thread]: D/nsHttp   continuation state has been reset
2016-09-26 16:13:54.516636 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ProcessNormal [this=7f083f556000]
2016-09-26 16:13:54.516649 UTC - [Main Thread]: D/nsHttp nsHttpChannel::InitCacheEntry [this=7f083f556000 entry=7f0849e16660]
2016-09-26 16:13:54.516671 UTC - [Main Thread]: D/nsHttp nsHttpResponseHead::MustValidate ??
2016-09-26 16:13:54.516675 UTC - [Main Thread]: D/nsHttp no mandatory validation requirement
2016-09-26 16:13:54.516685 UTC - [Main Thread]: D/nsHttp freshnessLifetime = 86400, currentAge = 0
2016-09-26 16:13:54.516710 UTC - [Main Thread]: D/cache2 CacheFile::SetExpirationTime() this=7f08402e5e00, expiration=1474992834
2016-09-26 16:13:54.516713 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.516729 UTC - [Main Thread]: D/cache2 CacheFileIOManager::UpdateIndexEntry() [handle=7f083d6916e0, frecency=, expirationTime=1474992834]
2016-09-26 16:13:54.516739 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetExpirationTime() [this=7f0848085f20, expirationTime=1474992834]
2016-09-26 16:13:54.516763 UTC - [Main Thread]: D/cache2 CacheFile::SetElement() this=7f08402e5e00
2016-09-26 16:13:54.516767 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.516774 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=strongly-framed, value=7f085db64ebf]
2016-09-26 16:13:54.516778 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=strongly-framed]
2016-09-26 16:13:54.516796 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=304]
2016-09-26 16:13:54.516799 UTC - [Main Thread]: D/cache2   mMemorySize=304 (+304,-240)
2016-09-26 16:13:54.516801 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=1474992834, size=]
2016-09-26 16:13:54.516803 UTC - [Main Thread]: D/nsHttp nsHttpChannel::AddCacheEntryHeaders [this=7f083f556000] begin
2016-09-26 16:13:54.516816 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.516821 UTC - [Main Thread]: D/cache2 CacheFile::SetElement() this=7f08402e5e00
2016-09-26 16:13:54.516826 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.516831 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.516831 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.516836 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.516841 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=request-method, value=7f085db69f31]
2016-09-26 16:13:54.516846 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.516850 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=request-method]
2016-09-26 16:13:54.516870 UTC - [Main Thread]: D/cache2 CacheFile::SetElement() this=7f08402e5e00
2016-09-26 16:13:54.516874 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.516883 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=response-head, value=7f083d6b4378]
2016-09-26 16:13:54.516887 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=response-head]
2016-09-26 16:13:54.516890 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=496]
2016-09-26 16:13:54.516893 UTC - [Main Thread]: D/cache2   mMemorySize=496 (+496,-304)
2016-09-26 16:13:54.516902 UTC - [Main Thread]: D/cache2 CacheFile::SetElement() this=7f08402e5e00
2016-09-26 16:13:54.516906 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.516914 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=original-response-headers, value=7f083d6b4378]
2016-09-26 16:13:54.516917 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=original-response-headers]
2016-09-26 16:13:54.516921 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=752]
2016-09-26 16:13:54.516924 UTC - [Main Thread]: D/cache2   mMemorySize=752 (+752,-496)
2016-09-26 16:13:54.516928 UTC - [Main Thread]: D/cache2 CacheEntry::MetaDataReady [this=7f083d693c00, state=WRITING]
2016-09-26 16:13:54.516932 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks BEGIN [this=7f083d693c00]
2016-09-26 16:13:54.516935 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks END [this=7f083d693c00]
2016-09-26 16:13:54.516942 UTC - [Main Thread]: D/nsHttp   calling mListener->OnStartRequest
2016-09-26 16:13:54.518922 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::DoApplyContentConversions [this=7f083f556000]
2016-09-26 16:13:54.518946 UTC - [Main Thread]: D/nsHttp Preparing to write data into the cache [uri=http://localhost:36870/content]
2016-09-26 16:13:54.518952 UTC - [Main Thread]: D/cache2 CacheFile::SetElement() this=7f08402e5e00
2016-09-26 16:13:54.518955 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.518967 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=uncompressed-len, value=7f085db64ebf]
2016-09-26 16:13:54.518971 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=uncompressed-len]
2016-09-26 16:13:54.518975 UTC - [Main Thread]: D/nsHttp Trading cache input stream for output stream [channel=7f083f556000]
2016-09-26 16:13:54.518979 UTC - [Main Thread]: D/cache2 CacheEntry::OpenOutputStream [this=7f083d693c00]
2016-09-26 16:13:54.518982 UTC - [Main Thread]: D/cache2 CacheEntry::OpenOutputStreamInternal [this=7f083d693c00]
2016-09-26 16:13:54.519009 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::CacheFileOutputStream() [this=7f083d68ada0]
2016-09-26 16:13:54.519014 UTC - [Main Thread]: D/cache2 CacheFile::OpenOutputStream() - Creating new output stream 7f083d68ada0 [this=7f08402e5e00]
2016-09-26 16:13:54.519020 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Seek() [this=7f083d68ada0, whence=0, offset=0]
2016-09-26 16:13:54.519024 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68ada0, releaseOnly=1]
2016-09-26 16:13:54.519027 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Seek() [this=7f083d68ada0, pos=0]
2016-09-26 16:13:54.519052 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks BEGIN [this=7f083d693c00]
2016-09-26 16:13:54.519055 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks END [this=7f083d693c00]
2016-09-26 16:13:54.519065 UTC - [Main Thread]: D/nsHttp nsHttpChannel::InstallCacheListener sync tee 7f083d6c4ce0 rv=0 cacheIOTarget=0
2016-09-26 16:13:54.519083 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnDataAvailable [this=7f083f556000 request=7f083f571e00 offset=0 count=13]
2016-09-26 16:13:54.519720 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Write() [this=7f083d68ada0, count=13]
2016-09-26 16:13:54.519729 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68ada0, releaseOnly=0]
2016-09-26 16:13:54.519732 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=0, caller=1, listener=0]
2016-09-26 16:13:54.519738 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6cd980, index=0, initByWriter=1]
2016-09-26 16:13:54.519744 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Created new empty chunk 7f083d6cd980 [this=7f08402e5e00]
2016-09-26 16:13:54.519747 UTC - [Main Thread]: D/cache2 CacheFileChunk::InitNew() [this=7f083d6cd980]
2016-09-26 16:13:54.519752 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=0, hash=d10d]
2016-09-26 16:13:54.519756 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=754]
2016-09-26 16:13:54.519759 UTC - [Main Thread]: D/cache2   mMemorySize=754 (+754,-752)
2016-09-26 16:13:54.519763 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6cd980, ensuredBufSize=13]
2016-09-26 16:13:54.519767 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6cd980, size=512]
2016-09-26 16:13:54.519770 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 512 [this=7f083d6cd980]
2016-09-26 16:13:54.519774 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6cd980, offset=0, len=13]
2016-09-26 16:13:54.519796 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cd980]
2016-09-26 16:13:54.519800 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68ada0, releaseOnly=1]
2016-09-26 16:13:54.519819 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68ada0, idx=0]
2016-09-26 16:13:54.519822 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Write() - Wrote 13 bytes [this=7f083d68ada0]
2016-09-26 16:13:54.520090 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnStopRequest [this=7f083f556000 request=7f083f571e00 status=0]
2016-09-26 16:13:54.520097 UTC - [Main Thread]: D/nsHttp   dropping upload stream
2016-09-26 16:13:54.520101 UTC - [Main Thread]: D/nsHttp nsHttpChannel 7f083f556000 has a strongly framed transaction: 1
2016-09-26 16:13:54.520106 UTC - [Main Thread]: D/nsHttp nsHttpTransaction::DeleteSelfOnConsumerThread [this=7f083d69c000]
2016-09-26 16:13:54.520110 UTC - [Main Thread]: D/nsHttp Destroying nsHttpTransaction @7f083d69c000
2016-09-26 16:13:54.520114 UTC - [Main Thread]: D/nsHttp nsHttpTransaction 7f083d69c000 request context set to null in ReleaseBlockingTransaction() - was 0
2016-09-26 16:13:54.520129 UTC - [Main Thread]: D/nsHttp nsHttpChannel::FinalizeCacheEntry [this=7f083f556000]
2016-09-26 16:13:54.520132 UTC - [Main Thread]: D/nsHttp nsHttpChannel::FinalizeCacheEntry [this=7f083f556000] Is Strongly Framed
2016-09-26 16:13:54.520136 UTC - [Main Thread]: D/cache2 CacheFile::SetElement() this=7f08402e5e00
2016-09-26 16:13:54.520139 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.520150 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=strongly-framed, value=7f085db5e623]
2016-09-26 16:13:54.520154 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key found [this=7f0848085f20, key=strongly-framed]
2016-09-26 16:13:54.520161 UTC - [Main Thread]: D/nsHttp   calling OnStopRequest
2016-09-26 16:13:54.520180 UTC - [Main Thread]: D/cache2 CacheFile::RemoveOutput() [this=7f08402e5e00, output=7f083d68ada0, status=0x00000000]
2016-09-26 16:13:54.520184 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() [this=7f08402e5e00]
2016-09-26 16:13:54.520188 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() - fail2 [this=7f08402e5e00, idx=0]
2016-09-26 16:13:54.520191 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cd980]
2016-09-26 16:13:54.520194 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.520321 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::~CacheFileOutputStream() [this=7f083d68ada0]
2016-09-26 16:13:54.520351 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6cd980, idx=0]
2016-09-26 16:13:54.520369 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Writing dirty chunk to the disk [this=7f08402e5e00]
2016-09-26 16:13:54.520384 UTC - [Main Thread]: D/cache2 CacheFileChunk::Write() [this=7f083d6cd980, handle=7f083d6916e0, listener=7f08402e5e00]
2016-09-26 16:13:54.520404 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=0, count=13, validate=0, truncate=0, listener=7f083d6cd980]
2016-09-26 16:13:54.520480 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=0, count=13, validate=0, truncate=0]
2016-09-26 16:13:54.520561 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenNSPRHandle BEGIN, handle=7f083d6916e0
2016-09-26 16:13:54.520697 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenNSPRHandle END, handle=7f083d6916e0
2016-09-26 16:13:54.521061 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=, size=1]
2016-09-26 16:13:54.521090 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.521106 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=1, size=0]
2016-09-26 16:13:54.521121 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.521136 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=1]
2016-09-26 16:13:54.521151 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal()
2016-09-26 16:13:54.521361 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.521384 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.521397 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize()
2016-09-26 16:13:54.521409 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize() - returning 1
2016-09-26 16:13:54.521428 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal() - Cache size and free space in limits. [cacheSize=1kB, cacheSizeLimit=256000kB, freeSpace=106633183232, freeSpaceLimit=5242880]
2016-09-26 16:13:54.521445 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataWritten() [this=7f083d6cd980, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.521470 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6cd980, idx=0]
2016-09-26 16:13:54.521487 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=0, hash=43b9]
2016-09-26 16:13:54.521502 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=754]
2016-09-26 16:13:54.521519 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() - Releasing unused chunk [this=7f08402e5e00, chunk=7f083d6cd980]
2016-09-26 16:13:54.521559 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.521617 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() - Writing metadata [this=7f08402e5e00]
2016-09-26 16:13:54.521636 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::WriteMetadata() [this=7f0848085f20, offset=13, listener=7f08402e5e10]
2016-09-26 16:13:54.521666 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=13, count=470, validate=1, truncate=1, listener=7f0848085f20]
2016-09-26 16:13:54.521698 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=754]
2016-09-26 16:13:54.521729 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=4]
2016-09-26 16:13:54.521784 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=13, count=470, validate=1, truncate=1]
2016-09-26 16:13:54.522064 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::OnDataWritten() [this=7f0848085f20, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.522085 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnMetadataWritten() [this=7f08402e5e00, rv=0x00000000]
2016-09-26 16:13:54.522099 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnMetadataWritten() - Releasing file handle [this=7f08402e5e00]
2016-09-26 16:13:54.522111 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::ReleaseNSPRHandle() [handle=7f083d6916e0]
2016-09-26 16:13:54.522147 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=754]
2016-09-26 16:13:54.522166 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=4]
2016-09-26 16:13:54.522186 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::MaybeReleaseNSPRHandleInternal() [handle=7f083d6916e0, ignore shutdown=0]
2016-09-26 16:13:54.522204 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::MaybeReleaseNSPRHandleInternal() DONE
2016-09-26 16:13:54.522220 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.555913 UTC - [Main Thread]: D/nsHttp nsHttpChannel::CloseCacheEntry [this=7f083f556000] mStatus=0 mCacheEntryIsWriteOnly=1
2016-09-26 16:13:54.647580 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks BEGIN [this=7f083d693c00]
2016-09-26 16:13:54.647607 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks END [this=7f083d693c00]
2016-09-26 16:13:54.647731 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6cd980]
2016-09-26 16:13:54.647749 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 0 [this=7f083d6cd980]
2016-09-26 16:13:54.648196 UTC - [Main Thread]: D/cache2 CacheEntry::OpenAlternativeOutputStream [this=7f083d693c00, type=text/binary]
2016-09-26 16:13:54.648221 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetElement() [this=7f0848085f20, key=alt-data, value=7fff7f60d9c0]
2016-09-26 16:13:54.648228 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=alt-data]
2016-09-26 16:13:54.648235 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::CacheFileOutputStream() [this=7f083d68b2e0]
2016-09-26 16:13:54.648241 UTC - [Main Thread]: D/cache2 CacheFile::OpenAlternativeOutputStream() - Creating new output stream 7f083d68b2e0 [this=7f08402e5e00]
2016-09-26 16:13:54.656738 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Write() [this=7f083d68b2e0, count=262147]
2016-09-26 16:13:54.656751 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=0]
2016-09-26 16:13:54.656755 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=0, caller=1, listener=0]
2016-09-26 16:13:54.656763 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6cd980, index=0, initByWriter=1]
2016-09-26 16:13:54.656769 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Reading newly created chunk 7f083d6cd980 from the disk [this=7f08402e5e00]
2016-09-26 16:13:54.656774 UTC - [Main Thread]: D/cache2 CacheFileChunk::Read() [this=7f083d6cd980, handle=7f083d6916e0, len=13, listener=7f08402e5e00]
2016-09-26 16:13:54.656785 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6cd980, size=512]
2016-09-26 16:13:54.656790 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 512 [this=7f083d6cd980]
2016-09-26 16:13:54.656795 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Read() [handle=7f083d6916e0, offset=0, count=13, listener=7f083d6cd980]
2016-09-26 16:13:54.656814 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6cd980, ensuredBufSize=262144]
2016-09-26 16:13:54.656820 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6cd980, size=262144]
2016-09-26 16:13:54.656860 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::ReadInternal() [handle=7f083d6916e0, offset=0, count=13]
2016-09-26 16:13:54.656873 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenNSPRHandle BEGIN, handle=7f083d6916e0
2016-09-26 16:13:54.656893 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::OpenNSPRHandle END, handle=7f083d6916e0
2016-09-26 16:13:54.656903 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataRead() [this=7f083d6cd980, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.656907 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 262656 [this=7f083d6cd980]
2016-09-26 16:13:54.656928 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6cd980, offset=13, len=262131]
2016-09-26 16:13:54.656936 UTC - [Main Thread]: D/cache2 ValidityMap::Log() - number of pairs: 1
2016-09-26 16:13:54.656940 UTC - [Main Thread]: D/cache2     (13, 262131)
2016-09-26 16:13:54.656944 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=0]
2016-09-26 16:13:54.656948 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::ReleaseChunk() [this=7f083d68b2e0, idx=0]
2016-09-26 16:13:54.656953 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=1, caller=1, listener=0]
2016-09-26 16:13:54.656958 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6cdbc0, index=1, initByWriter=1]
2016-09-26 16:13:54.656964 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Created new empty chunk 7f083d6cdbc0 [this=7f08402e5e00]
2016-09-26 16:13:54.656967 UTC - [Main Thread]: D/cache2 CacheFileChunk::InitNew() [this=7f083d6cdbc0]
2016-09-26 16:13:54.656972 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=1, hash=d10d]
2016-09-26 16:13:54.656977 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=756]
2016-09-26 16:13:54.656981 UTC - [Main Thread]: D/cache2   mMemorySize=756 (+756,-754)
2016-09-26 16:13:54.656986 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6cdbc0, ensuredBufSize=16]
2016-09-26 16:13:54.656989 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6cdbc0, size=512]
2016-09-26 16:13:54.656993 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 263168 [this=7f083d6cdbc0]
2016-09-26 16:13:54.656998 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6cdbc0, offset=0, len=16]
2016-09-26 16:13:54.657001 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cdbc0]
2016-09-26 16:13:54.657006 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=1]
2016-09-26 16:13:54.657009 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68b2e0, idx=1]
2016-09-26 16:13:54.657013 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Write() - Wrote 262147 bytes [this=7f083d68b2e0]
2016-09-26 16:13:54.657059 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataRead() - Merging buffers. [this=7f083d6cd980]
2016-09-26 16:13:54.657072 UTC - [Cache2 I/O]: D/cache2 ValidityMap::Log() - number of pairs: 1
2016-09-26 16:13:54.657082 UTC - [Cache2 I/O]: D/cache2     (13, 262131)
2016-09-26 16:13:54.657090 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 262656 [this=7f083d6cd980]
2016-09-26 16:13:54.657098 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkRead() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6cd980, idx=0]
2016-09-26 16:13:54.657114 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.661716 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6cd980, idx=0]
2016-09-26 16:13:54.661730 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Writing dirty chunk to the disk [this=7f08402e5e00]
2016-09-26 16:13:54.661734 UTC - [Main Thread]: D/cache2 CacheFileChunk::Write() [this=7f083d6cd980, handle=7f083d6916e0, listener=7f08402e5e00]
2016-09-26 16:13:54.661740 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=0, count=262144, validate=0, truncate=0, listener=7f083d6cd980]
2016-09-26 16:13:54.661804 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=0, count=262144, validate=0, truncate=0]
2016-09-26 16:13:54.662036 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=, size=256]
2016-09-26 16:13:54.662045 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.662049 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=1]
2016-09-26 16:13:54.662053 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.662057 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=256]
2016-09-26 16:13:54.662061 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal()
2016-09-26 16:13:54.662119 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.662124 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.662127 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize()
2016-09-26 16:13:54.662130 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize() - returning 256
2016-09-26 16:13:54.662136 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal() - Cache size and free space in limits. [cacheSize=256kB, cacheSizeLimit=256000kB, freeSpace=106632925184, freeSpaceLimit=5242880]
2016-09-26 16:13:54.662140 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataWritten() [this=7f083d6cd980, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.662146 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6cd980, idx=0]
2016-09-26 16:13:54.662540 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NewProxiedChannel [proxyInfo=0]
2016-09-26 16:13:54.662563 UTC - [Main Thread]: V/nsHttp Creating HttpBaseChannel @3f5c4800
2016-09-26 16:13:54.662570 UTC - [Main Thread]: D/nsHttp Creating nsHttpChannel [this=7f083f5c4800]
2016-09-26 16:13:54.662583 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::Init [this=7f083f5c4800]
2016-09-26 16:13:54.662588 UTC - [Main Thread]: V/nsHttp host=localhost port=36870
2016-09-26 16:13:54.662592 UTC - [Main Thread]: V/nsHttp uri=http://localhost:36870/content
2016-09-26 16:13:54.662604 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Init [this=7f083f5c4800]
2016-09-26 16:13:54.662938 UTC - [Main Thread]: D/nsHttp nsHttpChannel::AsyncOpen [this=7f083f5c4800]
2016-09-26 16:13:54.662983 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=0, hash=3e1a]
2016-09-26 16:13:54.662987 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=756]
2016-09-26 16:13:54.662992 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() - Releasing unused chunk [this=7f08402e5e00, chunk=7f083d6cd980]
2016-09-26 16:13:54.662997 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::SetRequestHeader [this=7f083f5c4800 header="Cookie" value="" merge=0]
2016-09-26 16:13:54.663004 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.663013 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=3f5c4858 event="http-on-opening-request"]
2016-09-26 16:13:54.663019 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.663023 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ResolveProxy [this=7f083f5c4800]
2016-09-26 16:13:54.663076 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnProxyAvailable [this=7f083f5c4800 pi=0 status=0 mStatus=0]
2016-09-26 16:13:54.663083 UTC - [Main Thread]: D/nsHttp nsHttpChannel::BeginConnect [this=7f083f5c4800]
2016-09-26 16:13:54.663088 UTC - [Main Thread]: D/nsHttp host=localhost port=36870
2016-09-26 16:13:54.663090 UTC - [Main Thread]: D/nsHttp uri=http://localhost:36870/content
2016-09-26 16:13:54.663104 UTC - [Main Thread]: D/nsHttp AltSvcCache::LookupMapping 7f0849e7e1e8 http:localhost:36870:.
2016-09-26 16:13:54.663110 UTC - [Main Thread]: D/nsHttp AltSvcCache::LookupMapping 7f0849e7e1e8 MISS
2016-09-26 16:13:54.663114 UTC - [Main Thread]: D/nsHttp AltSvcCache::GetAltServiceMapping 7f0849e7e1e8 key=http:localhost:36870:. existing=0 validated=0 ttl=0
2016-09-26 16:13:54.663118 UTC - [Main Thread]: D/nsHttp nsHttpChannel 7f083f5c4800 Using default connection info
2016-09-26 16:13:54.663122 UTC - [Main Thread]: V/nsHttp Init nsHttpConnectionInfo @7f0849e79040
2016-09-26 16:13:54.663149 UTC - [Main Thread]: D/nsHttp nsHttpChannelAuthProvider::AddAuthorizationHeaders? [this=7f083d694800 channel=7f083f5c4d38]
2016-09-26 16:13:54.663161 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::GetAuthEntryForPath [key=http://localhost:36870 path=/]
2016-09-26 16:13:54.663168 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=3f5c4858 event="http-on-modify-request"]
2016-09-26 16:13:54.663183 UTC - [Main Thread]: D/nsHttp nsHttpChannel::BeginConnect [this=7f083f5c4800] prefetching
2016-09-26 16:13:54.663218 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ContinueBeginConnectWithResult [this=7f083f5c4800]
2016-09-26 16:13:54.663224 UTC - [Main Thread]: D/nsHttp nsHttpChannel::Connect [this=7f083f5c4800]
2016-09-26 16:13:54.663271 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::SpeculativeConnect [ci=......localhost:36870]
2016-09-26 16:13:54.663302 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OpenCacheEntry [this=7f083f5c4800]
2016-09-26 16:13:54.663328 UTC - [Main Thread]: D/cache2 CacheStorageService::AddStorageEntry [entryKey=:http://localhost:36870/content, contextKey=]
2016-09-26 16:13:54.663337 UTC - [Main Thread]: D/cache2 New CacheEntryHandle 7f083d6c7220 for entry 7f083d693c00
2016-09-26 16:13:54.663343 UTC - [Main Thread]: D/cache2 CacheEntry::AsyncOpen [this=7f083d693c00, state=READY, flags=16, callback=7f083f5c4d20]
2016-09-26 16:13:54.663349 UTC - [Main Thread]: D/cache2 CacheEntry::RememberCallback [this=7f083d693c00, cb=7f083f5c4d20, state=READY]
2016-09-26 16:13:54.663353 UTC - [Main Thread]: D/cache2 CacheEntry::Load [this=7f083d693c00, trunc=0]
2016-09-26 16:13:54.663356 UTC - [Main Thread]: D/cache2   already loaded
2016-09-26 16:13:54.663357 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgSpeculativeConnect [ci=......localhost:36870]
2016-09-26 16:13:54.663376 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::AtActiveConnectionLimit [ci=......localhost:36870 caps=401]
2016-09-26 16:13:54.663380 UTC - [Socket Thread]: V/nsHttp    connection count = 0, limit 6
2016-09-26 16:13:54.663383 UTC - [Socket Thread]: V/nsHttp   result: false
2016-09-26 16:13:54.663389 UTC - [Socket Thread]: V/nsHttp Creating nsHalfOpenSocket [this=7f083d6c17a0 trans=7f083f7bf920 ent=localhost key=......localhost:36870]
2016-09-26 16:13:54.663402 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::SetupStreams [this=7f083d6c17a0 ent=......localhost:36870] setup routed transport to origin localhost:36870 via :443
2016-09-26 16:13:54.663359 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks BEGIN [this=7f083d693c00]
2016-09-26 16:13:54.663432 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallback [this=7f083d693c00, state=READY, cb=7f083f5c4d20]
2016-09-26 16:13:54.663437 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnCacheEntryCheck enter [channel=7f083f5c4800 entry=7f083d693c00]
2016-09-26 16:13:54.663438 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ActivateTimeoutTick() this=7f0849e7e1e0 mTimeoutTick=7f083d68b0b0
2016-09-26 16:13:54.663450 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key found [this=7f0848085f20, key=request-method]
2016-09-26 16:13:54.663459 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::SetupPrimaryStream [this=7f083d6c17a0 ent=localhost rv=0]
2016-09-26 16:13:54.663460 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key found [this=7f0848085f20, key=original-response-headers]
2016-09-26 16:13:54.663470 UTC - [Main Thread]: D/nsHttp nsHttpResponseHead::ParseCachedOriginalHeader [this=7f083a00b580]
2016-09-26 16:13:54.663496 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key found [this=7f0848085f20, key=response-head]
2016-09-26 16:13:54.663502 UTC - [Main Thread]: D/nsHttp nsHttpResponseHead::ParseCachedHead [this=7f083a00b580]
2016-09-26 16:13:54.663506 UTC - [Main Thread]: D/nsHttp nsHttpResponseHead::ParseVersion [version=HTTP/1.1 200 OK
Content-Type: text/plain
Cache-Control: max-age=86400
Server: httpd.js
Date: Mon, 26 Sep 2016 16:13:54 GMT
Content-Length: 13
]
2016-09-26 16:13:54.663511 UTC - [Main Thread]: D/nsHttp Have status line [version=11 status=200 statusText=OK]
2016-09-26 16:13:54.663516 UTC - [Main Thread]: D/nsHttp ParseContentType [type=text/plain]
2016-09-26 16:13:54.663529 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::SetupBackupTimer() [this=7f083d6c17a0], did not arm
2016-09-26 16:13:54.663532 UTC - [Main Thread]: D/cache2 CacheEntry::GetDataSize [this=7f083d693c00]
2016-09-26 16:13:54.663542 UTC - [Main Thread]: D/cache2   size=13
2016-09-26 16:13:54.663546 UTC - [Main Thread]: D/nsHttp ### CheckPartial rv=0, size=13, contentLength=13
2016-09-26 16:13:54.663552 UTC - [Main Thread]: D/cache2 CacheEntry::GetIsForcedValid [this=7f083d693c00, IsForcedValid=0]
2016-09-26 16:13:54.663557 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key found [this=7f0848085f20, key=strongly-framed]
2016-09-26 16:13:54.663562 UTC - [Main Thread]: D/nsHttp nsHttpResponseHead::MustValidate ??
2016-09-26 16:13:54.663565 UTC - [Main Thread]: D/nsHttp no mandatory validation requirement
2016-09-26 16:13:54.663575 UTC - [Main Thread]: D/nsHttp   NowInSeconds()=1474906434, expiration time=1474992834, freshness lifetime=86400, age=0
2016-09-26 16:13:54.663579 UTC - [Main Thread]: D/nsHttp   not validating, expire time not in the past
2016-09-26 16:13:54.663582 UTC - [Main Thread]: D/nsHttp Not validating based on expiration time
2016-09-26 16:13:54.663586 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key not found [this=7f0848085f20, key=auth]
2016-09-26 16:13:54.663591 UTC - [Main Thread]: D/cache2 CacheEntry::OpenAlternativeInputStream [this=7f083d693c00, type=text/binary]
2016-09-26 16:13:54.663595 UTC - [Main Thread]: D/cache2 CacheEntry::OpenInputStreamInternal [this=7f083d693c00]
2016-09-26 16:13:54.663599 UTC - [Main Thread]: D/cache2 New CacheEntryHandle 7f083d6c7ee0 for entry 7f083d693c00
2016-09-26 16:13:54.663603 UTC - [Main Thread]: D/cache2 CacheFileMetadata::GetElement() - Key found [this=7f0848085f20, key=alt-data]
2016-09-26 16:13:54.663605 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::OnOutputStreamReady [this=7f083d6c17a0 ent=localhost primary]
2016-09-26 16:13:54.663612 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ConditionallyStopTimeoutTick armed=1 active=0
2016-09-26 16:13:54.663612 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CacheFileInputStream() [this=7f083d68be40]
2016-09-26 16:13:54.663620 UTC - [Main Thread]: D/cache2 CacheFile::OpenAlternativeInputStream() - Creating new input stream 7f083d68be40 [this=7f08402e5e00]
2016-09-26 16:13:54.663631 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Seek() [this=7f083d68be40, whence=0, offset=0]
2016-09-26 16:13:54.663635 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.663639 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=0, caller=0, listener=7f083d68be50]
2016-09-26 16:13:54.663644 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6cde90, index=0, initByWriter=0]
2016-09-26 16:13:54.663649 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Reading newly created chunk 7f083d6cde90 from the disk [this=7f08402e5e00]
2016-09-26 16:13:54.663654 UTC - [Main Thread]: D/cache2 CacheFileChunk::Read() [this=7f083d6cde90, handle=7f083d6916e0, len=262144, listener=7f08402e5e00]
2016-09-26 16:13:54.663621 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ConditionallyStopTimeoutTick stop==true
2016-09-26 16:13:54.663695 UTC - [Socket Thread]: V/nsHttp Creating nsHttpConnection @7f08402d0200
2016-09-26 16:13:54.663700 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::OnOutputStreamReady Created new nshttpconnection 7f08402d0200
2016-09-26 16:13:54.663706 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Init this=7f08402d0200
2016-09-26 16:13:54.663720 UTC - [Socket Thread]: V/nsHttp nsHalfOpenSocket::OnOutputStreamReady no transaction match returning conn 7f08402d0200 to pool
2016-09-26 16:13:54.663725 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgReclaimConnection [conn=7f08402d0238]
2016-09-26 16:13:54.663731 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Read() [handle=7f083d6916e0, offset=0, count=262144, listener=7f083d6cde90]
2016-09-26 16:13:54.663733 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::SetupSSL 7f08402d0200 caps=0x401 ......localhost:36870
2016-09-26 16:13:54.663747 UTC - [Socket Thread]: V/nsHttp   adding connection to idle list
2016-09-26 16:13:54.663748 UTC - [Main Thread]: D/cache2 CacheFile::QueueChunkListener() [this=7f08402e5e00, idx=0, listener=7f083d68be50]
2016-09-26 16:13:54.663753 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::BeginIdleMonitoring [this=7f08402d0200]
2016-09-26 16:13:54.663764 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=0, mStatus=0x00000000, mChunk=0, mListeningForChunk=0, mWaitingForUpdate=0]
2016-09-26 16:13:54.663766 UTC - [Socket Thread]: V/nsHttp Entering Idle Monitoring Mode [this=7f08402d0200]
2016-09-26 16:13:54.663758 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::ReadInternal() [handle=7f083d6916e0, offset=0, count=262144]
2016-09-26 16:13:54.663769 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Seek() [this=7f083d68be40, pos=13]
2016-09-26 16:13:54.663781 UTC - [Main Thread]: D/cache2 CacheEntry::GetAltDataSize [this=7f083d693c00]
2016-09-26 16:13:54.663784 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::PruneDeadConnectionsAfter
2016-09-26 16:13:54.663786 UTC - [Main Thread]: D/nsHttp Opened cache input stream without buffering [channel=7f083f5c4800, mCacheEntry=7f083d693c00, stream=7f083d68be40]
2016-09-26 16:13:54.663798 UTC - [Main Thread]: D/nsHttp nsHTTPChannel::OnCacheEntryCheck exit [this=7f083f5c4800 doValidation=0 result=0]
2016-09-26 16:13:54.663802 UTC - [Main Thread]: D/cache2   OnCacheEntryCheck: rv=0x00000000, result=0
2016-09-26 16:13:54.663802 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.663808 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeAvailableCallback [this=7f083d693c00, state=READY, cb=7f083f5c4d20, r/o=0, n/w=0]
2016-09-26 16:13:54.663812 UTC - [Main Thread]: D/cache2   ready/has-meta, notifying OCEA with entry and NS_OK
2016-09-26 16:13:54.663815 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.663817 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataRead() [this=7f083d6cde90, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.663823 UTC - [Main Thread]: D/cache2 CacheEntry::BackgroundOp this=7f083d693c00 dipatch of 2
2016-09-26 16:13:54.663822 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.663922 UTC - [Socket Thread]: V/nsHttp Destroying nsHalfOpenSocket [this=7f083d6c17a0]
2016-09-26 16:13:54.663935 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.663958 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgProcessPendingQ [ci=......localhost:36870]
2016-09-26 16:13:54.663965 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.663970 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::ProcessPendingQForEntry [ci=......localhost:36870 ent=7f083d68af60 active=0 idle=1 queued=0]
2016-09-26 16:13:54.664677 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkRead() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6cde90, idx=0]
2016-09-26 16:13:54.664685 UTC - [Cache2 I/O]: D/cache2 CacheFile::NotifyChunkListeners() [this=7f08402e5e00, idx=0, rv=0x00000000, chunk=7f083d6cde90]
2016-09-26 16:13:54.664690 UTC - [Cache2 I/O]: D/cache2 CacheFile::NotifyChunkListener() [this=7f08402e5e00, listener=7f083d68be50, target=7f0849e83ce0, rv=0x00000000, idx=0, chunk=7f083d6cde90]
2016-09-26 16:13:54.664695 UTC - [Cache2 I/O]: D/cache2 NotifyChunkListenerEvent::NotifyChunkListenerEvent() [this=7f083d6ed760]
2016-09-26 16:13:54.664713 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.664720 UTC - [Cache2 I/O]: D/cache2 NotifyChunkListenerEvent::Run() [this=7f083d6ed760]
2016-09-26 16:13:54.664725 UTC - [Cache2 I/O]: D/cache2 CacheFileInputStream::OnChunkAvailable() [this=7f083d68be40, result=0x00000000, idx=0, chunk=7f083d6cde90]
2016-09-26 16:13:54.664730 UTC - [Cache2 I/O]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=0, mStatus=0x00000000, mChunk=7f083d6cde90, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.664734 UTC - [Cache2 I/O]: D/cache2 NotifyChunkListenerEvent::~NotifyChunkListenerEvent() [this=7f083d6ed760]
2016-09-26 16:13:54.664751 UTC - [Cache2 I/O]: D/cache2 CacheEntry FRECENCYUPDATE [this=7f083d693c00, frecency=283980,4811185973]
2016-09-26 16:13:54.664760 UTC - [Main Thread]: D/cache2 CacheFile::OnFetched() this=7f08402e5e00
2016-09-26 16:13:54.664771 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.664788 UTC - [Main Thread]: D/cache2 New CacheEntryHandle 7f083d6c7fa0 for entry 7f083d693c00
2016-09-26 16:13:54.664794 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnCacheEntryAvailable [this=7f083f5c4800 entry=7f083d6c7fa0 new=0 appcache=0 status=0 mAppCache=0 mAppCacheForWrite=0]
2016-09-26 16:13:54.664801 UTC - [Main Thread]: D/cache2 CacheEntry::InvokeCallbacks END [this=7f083d693c00]
2016-09-26 16:13:54.664806 UTC - [Main Thread]: D/cache2 CacheEntry::OnHandleClosed [this=7f083d693c00, state=READY, handle=7f083d6c7220]
2016-09-26 16:13:54.664808 UTC - [Main Thread]: D/cache2   not the writer
2016-09-26 16:13:54.664819 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ReadFromCache [this=7f083f5c4800] Using cached copy of: http://localhost:36870/content
2016-09-26 16:13:54.664836 UTC - [Main Thread]: D/cache2 CacheFileInputStream::AsyncWait() [this=7f083d68be40, callback=7f083f50c308, flags=0, requestedCount=0, eventTarget=7f0849e81150]
2016-09-26 16:13:54.664842 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.664846 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=0]
2016-09-26 16:13:54.664851 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=7f083f50c308, mClosed=0, mStatus=0x00000000, mChunk=7f083d6cde90, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.664860 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6cde90]
2016-09-26 16:13:54.664864 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=262131]
2016-09-26 16:13:54.664867 UTC - [Main Thread]: D/cache2 CacheFileInputStream::NotifyListener() [this=7f083d68be40]
2016-09-26 16:13:54.664909 UTC - [Main Thread]: D/nsHttp nsHttpChannel::ContinueBeginConnectWithResult result [this=7f083f5c4800 rv=0 mCanceled=0]
2016-09-26 16:13:54.666466 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6cd980]
2016-09-26 16:13:54.666486 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 512 [this=7f083d6cd980]
2016-09-26 16:13:54.666543 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnLookupComplete [this=7f083f5c4800] prefetch complete: success status[0x0]
2016-09-26 16:13:54.669576 UTC - [Main Thread]: D/cache2 CacheFile::SetFrecency() this=7f08402e5e00, frecency=1022329732
2016-09-26 16:13:54.669586 UTC - [Main Thread]: D/cache2 CacheFile::PostWriteTimer() [this=7f08402e5e00]
2016-09-26 16:13:54.669602 UTC - [Main Thread]: D/cache2 CacheFileIOManager::UpdateIndexEntry() [handle=7f083d6916e0, frecency=1022329732, expirationTime=]
2016-09-26 16:13:54.669645 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetFrecency() [this=7f0848085f20, frecency=1022329732,000000]
2016-09-26 16:13:54.669648 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=1022329732, expirationTime=, size=]
2016-09-26 16:13:54.669660 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.669664 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=256]
2016-09-26 16:13:54.669668 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.669672 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=256]
2016-09-26 16:13:54.669711 UTC - [Main Thread]: D/nsHttp nsHttpHandler::NotifyObservers [chan=3f5c4858 event="http-on-examine-cached-response"]
2016-09-26 16:13:54.669718 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.669762 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.669768 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=0]
2016-09-26 16:13:54.669774 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Available() [this=7f083d68be40, retval=262147, rv=0x00000000]
2016-09-26 16:13:54.669779 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnStartRequest [this=7f083f5c4800 request=7f083f50c300 status=0]
2016-09-26 16:13:54.669801 UTC - [Main Thread]: D/nsHttp   calling mListener->OnStartRequest
2016-09-26 16:13:54.669900 UTC - [Main Thread]: V/nsHttp HttpBaseChannel::DoApplyContentConversions [this=7f083f5c4800]
2016-09-26 16:13:54.669907 UTC - [Main Thread]: V/nsHttp not applying conversion because delivering alt-data
2016-09-26 16:13:54.669917 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.669923 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=0]
2016-09-26 16:13:54.669942 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Available() [this=7f083d68be40, retval=262147, rv=0x00000000]
2016-09-26 16:13:54.669948 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=0]
2016-09-26 16:13:54.669953 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnDataAvailable [this=7f083f5c4800 request=7f083f50c300 offset=0 count=262147]
2016-09-26 16:13:54.669966 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=0]
2016-09-26 16:13:54.670768 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Read() [this=7f083d68be40, count=262147]
2016-09-26 16:13:54.670777 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReadSegments() [this=7f083d68be40, count=262147]
2016-09-26 16:13:54.670781 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.670784 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=0]
2016-09-26 16:13:54.670787 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6cde90]
2016-09-26 16:13:54.670790 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=262131]
2016-09-26 16:13:54.670828 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.670831 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReleaseChunk() [this=7f083d68be40, idx=0]
2016-09-26 16:13:54.670836 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=1, caller=0, listener=7f083d68be50]
2016-09-26 16:13:54.670841 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Found chunk 7f083d6cdbc0 in mChunks [this=7f08402e5e00]
2016-09-26 16:13:54.670846 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=0, mStatus=0x00000000, mChunk=7f083d6cdbc0, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.670849 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6cdbc0]
2016-09-26 16:13:54.670853 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=16]
2016-09-26 16:13:54.670858 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6cde90, idx=0]
2016-09-26 16:13:54.670863 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Releasing unused chunk [this=7f08402e5e00, chunk=7f083d6cde90]
2016-09-26 16:13:54.670867 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.670885 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6cde90]
2016-09-26 16:13:54.670954 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.670959 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=1]
2016-09-26 16:13:54.670962 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReadSegments() [this=7f083d68be40, rv=0x00000000, retval=262147]
2016-09-26 16:13:54.675924 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Write() [this=7f083d68b2e0, count=786442]
2016-09-26 16:13:54.675939 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=0]
2016-09-26 16:13:54.675942 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68b2e0, idx=1]
2016-09-26 16:13:54.675946 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6cdbc0, ensuredBufSize=262144]
2016-09-26 16:13:54.675949 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6cdbc0, size=261632]
2016-09-26 16:13:54.676261 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 262144 [this=7f083d6cdbc0]
2016-09-26 16:13:54.676282 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6cdbc0, offset=16, len=262128]
2016-09-26 16:13:54.676307 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cdbc0]
2016-09-26 16:13:54.676311 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=0]
2016-09-26 16:13:54.676314 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::ReleaseChunk() [this=7f083d68b2e0, idx=1]
2016-09-26 16:13:54.676326 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=2, caller=1, listener=0]
2016-09-26 16:13:54.676335 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6cde90, index=2, initByWriter=1]
2016-09-26 16:13:54.676340 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Created new empty chunk 7f083d6cde90 [this=7f08402e5e00]
2016-09-26 16:13:54.676343 UTC - [Main Thread]: D/cache2 CacheFileChunk::InitNew() [this=7f083d6cde90]
2016-09-26 16:13:54.676364 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=2, hash=d10d]
2016-09-26 16:13:54.676369 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=760]
2016-09-26 16:13:54.676372 UTC - [Main Thread]: D/cache2   mMemorySize=760 (+760,-756)
2016-09-26 16:13:54.676376 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6cde90, ensuredBufSize=262144]
2016-09-26 16:13:54.676379 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6cde90, size=262144]
2016-09-26 16:13:54.676389 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 524288 [this=7f083d6cde90]
2016-09-26 16:13:54.676409 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6cde90, offset=0, len=262144]
2016-09-26 16:13:54.676413 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cde90]
2016-09-26 16:13:54.676416 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=0]
2016-09-26 16:13:54.676419 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::ReleaseChunk() [this=7f083d68b2e0, idx=2]
2016-09-26 16:13:54.676423 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=3, caller=1, listener=0]
2016-09-26 16:13:54.676427 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6ce0d0, index=3, initByWriter=1]
2016-09-26 16:13:54.676431 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Created new empty chunk 7f083d6ce0d0 [this=7f08402e5e00]
2016-09-26 16:13:54.676434 UTC - [Main Thread]: D/cache2 CacheFileChunk::InitNew() [this=7f083d6ce0d0]
2016-09-26 16:13:54.676455 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=3, hash=d10d]
2016-09-26 16:13:54.676458 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=760]
2016-09-26 16:13:54.676461 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6ce0d0, ensuredBufSize=262144]
2016-09-26 16:13:54.676483 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6ce0d0, size=262144]
2016-09-26 16:13:54.676492 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 786432 [this=7f083d6ce0d0]
2016-09-26 16:13:54.676551 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6ce0d0, offset=0, len=262144]
2016-09-26 16:13:54.676572 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6ce0d0]
2016-09-26 16:13:54.676576 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=0]
2016-09-26 16:13:54.676579 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::ReleaseChunk() [this=7f083d68b2e0, idx=3]
2016-09-26 16:13:54.676582 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=4, caller=1, listener=0]
2016-09-26 16:13:54.676586 UTC - [Main Thread]: D/cache2 CacheFileChunk::CacheFileChunk() [this=7f083d6ce1f0, index=4, initByWriter=1]
2016-09-26 16:13:54.676590 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Created new empty chunk 7f083d6ce1f0 [this=7f08402e5e00]
2016-09-26 16:13:54.676593 UTC - [Main Thread]: D/cache2 CacheFileChunk::InitNew() [this=7f083d6ce1f0]
2016-09-26 16:13:54.676596 UTC - [Main Thread]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=4, hash=d10d]
2016-09-26 16:13:54.676605 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.676608 UTC - [Main Thread]: D/cache2   mMemorySize=768 (+768,-760)
2016-09-26 16:13:54.676611 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetWriteHandle() [this=7f083d6ce1f0, ensuredBufSize=26]
2016-09-26 16:13:54.676614 UTC - [Main Thread]: D/cache2 CacheFileChunk::CanAllocate() [this=7f083d6ce1f0, size=512]
2016-09-26 16:13:54.676618 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 786944 [this=7f083d6ce1f0]
2016-09-26 16:13:54.676621 UTC - [Main Thread]: D/cache2 CacheFileChunk::UpdateDataSize() [this=7f083d6ce1f0, offset=0, len=26]
2016-09-26 16:13:54.676624 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6ce1f0]
2016-09-26 16:13:54.676627 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() [this=7f083d68b2e0, releaseOnly=1]
2016-09-26 16:13:54.676635 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68b2e0, idx=4]
2016-09-26 16:13:54.676638 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Write() - Wrote 786442 bytes [this=7f083d68b2e0]
2016-09-26 16:13:54.676644 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6cde90, idx=2]
2016-09-26 16:13:54.676648 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Writing dirty chunk to the disk [this=7f08402e5e00]
2016-09-26 16:13:54.676652 UTC - [Main Thread]: D/cache2 CacheFileChunk::Write() [this=7f083d6cde90, handle=7f083d6916e0, listener=7f08402e5e00]
2016-09-26 16:13:54.676682 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=524288, count=262144, validate=0, truncate=0, listener=7f083d6cde90]
2016-09-26 16:13:54.676727 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6ce0d0, idx=3]
2016-09-26 16:13:54.676733 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Writing dirty chunk to the disk [this=7f08402e5e00]
2016-09-26 16:13:54.676737 UTC - [Main Thread]: D/cache2 CacheFileChunk::Write() [this=7f083d6ce0d0, handle=7f083d6916e0, listener=7f08402e5e00]
2016-09-26 16:13:54.676737 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=524288, count=262144, validate=0, truncate=0]
2016-09-26 16:13:54.676742 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=786432, count=262144, validate=0, truncate=0, listener=7f083d6ce0d0]
2016-09-26 16:13:54.677189 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::Close() [this=7f083d68b2e0]
2016-09-26 16:13:54.677200 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::CloseWithStatus() [this=7f083d68b2e0, aStatus=0x00000000]
2016-09-26 16:13:54.677203 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::CloseWithStatusLocked() [this=7f083d68b2e0, aStatus=0x00000000]
2016-09-26 16:13:54.677207 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::ReleaseChunk() [this=7f083d68b2e0, idx=4]
2016-09-26 16:13:54.677213 UTC - [Main Thread]: D/cache2 CacheFile::RemoveOutput() [this=7f08402e5e00, output=7f083d68b2e0, status=0x80470002]
2016-09-26 16:13:54.677215 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() [this=7f08402e5e00]
2016-09-26 16:13:54.677242 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() - fail2 [this=7f08402e5e00, idx=2]
2016-09-26 16:13:54.677245 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cde90]
2016-09-26 16:13:54.677248 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() - fail2 [this=7f08402e5e00, idx=4]
2016-09-26 16:13:54.677251 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6ce1f0]
2016-09-26 16:13:54.677255 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() - fail2 [this=7f08402e5e00, idx=1]
2016-09-26 16:13:54.677262 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6cdbc0]
2016-09-26 16:13:54.677266 UTC - [Main Thread]: D/cache2 CacheFile::NotifyListenersAboutOutputRemoval() - fail2 [this=7f08402e5e00, idx=3]
2016-09-26 16:13:54.677269 UTC - [Main Thread]: D/cache2 CacheFileChunk::NotifyUpdateListeners() [this=7f083d6ce0d0]
2016-09-26 16:13:54.677289 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.677314 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6ce1f0, idx=4]
2016-09-26 16:13:54.677320 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Writing dirty chunk to the disk [this=7f08402e5e00]
2016-09-26 16:13:54.677324 UTC - [Main Thread]: D/cache2 CacheFileChunk::Write() [this=7f083d6ce1f0, handle=7f083d6916e0, listener=7f08402e5e00]
2016-09-26 16:13:54.677329 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=1048576, count=26, validate=0, truncate=0, listener=7f083d6ce1f0]
2016-09-26 16:13:54.677346 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=, size=768]
2016-09-26 16:13:54.677359 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.677364 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=256]
2016-09-26 16:13:54.677385 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.677389 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=768]
2016-09-26 16:13:54.677393 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal()
2016-09-26 16:13:54.677403 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=262147]
2016-09-26 16:13:54.677415 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=262147]
2016-09-26 16:13:54.677437 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.677441 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=1]
2016-09-26 16:13:54.677446 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Available() [this=7f083d68be40, retval=786442, rv=0x00000000]
2016-09-26 16:13:54.677452 UTC - [Main Thread]: D/cache2 CacheFileInputStream::AsyncWait() [this=7f083d68be40, callback=7f083f50c308, flags=0, requestedCount=0, eventTarget=7f0849e81150]
2016-09-26 16:13:54.677459 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.677462 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=1]
2016-09-26 16:13:54.677467 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=7f083f50c308, mClosed=0, mStatus=0x00000000, mChunk=7f083d6cdbc0, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.677470 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6cdbc0]
2016-09-26 16:13:54.677474 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=262128]
2016-09-26 16:13:54.677477 UTC - [Main Thread]: D/cache2 CacheFileInputStream::NotifyListener() [this=7f083d68be40]
2016-09-26 16:13:54.677512 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.677536 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.677539 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize()
2016-09-26 16:13:54.677559 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize() - returning 768
2016-09-26 16:13:54.677565 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal() - Cache size and free space in limits. [cacheSize=768kB, cacheSizeLimit=256000kB, freeSpace=106632663040, freeSpaceLimit=5242880]
2016-09-26 16:13:54.677591 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataWritten() [this=7f083d6cde90, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.677598 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6cde90, idx=2]
2016-09-26 16:13:54.678448 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=2, hash=b0a2]
2016-09-26 16:13:54.678473 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.678500 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() - Caching unused chunk [this=7f08402e5e00, chunk=7f083d6cde90]
2016-09-26 16:13:54.678527 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.678542 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=5]
2016-09-26 16:13:54.678550 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=786432, count=262144, validate=0, truncate=0]
2016-09-26 16:13:54.678625 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.678674 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=1]
2016-09-26 16:13:54.678681 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Available() [this=7f083d68be40, retval=786442, rv=0x00000000]
2016-09-26 16:13:54.678711 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=262147]
2016-09-26 16:13:54.678735 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnDataAvailable [this=7f083f5c4800 request=7f083f50c300 offset=262147 count=786442]
2016-09-26 16:13:54.678742 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=262147]
2016-09-26 16:13:54.678883 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=, size=1024]
2016-09-26 16:13:54.678890 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.678916 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=768]
2016-09-26 16:13:54.678920 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.678923 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=1024]
2016-09-26 16:13:54.678927 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal()
2016-09-26 16:13:54.679003 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.679009 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.679012 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize()
2016-09-26 16:13:54.679015 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize() - returning 1024
2016-09-26 16:13:54.679020 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal() - Cache size and free space in limits. [cacheSize=1024kB, cacheSizeLimit=256000kB, freeSpace=106632400896, freeSpaceLimit=5242880]
2016-09-26 16:13:54.679024 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataWritten() [this=7f083d6ce0d0, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.679030 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6ce0d0, idx=3]
2016-09-26 16:13:54.679418 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Read() [this=7f083d68be40, count=786442]
2016-09-26 16:13:54.679950 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=3, hash=c92c]
2016-09-26 16:13:54.679956 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.679962 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() - Caching unused chunk [this=7f08402e5e00, chunk=7f083d6ce0d0]
2016-09-26 16:13:54.679985 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.679998 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=4]
2016-09-26 16:13:54.680004 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=1048576, count=26, validate=0, truncate=0]
2016-09-26 16:13:54.680043 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReadSegments() [this=7f083d68be40, count=786442]
2016-09-26 16:13:54.680074 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.680078 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=1]
2016-09-26 16:13:54.680081 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6cdbc0]
2016-09-26 16:13:54.680103 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=262128]
2016-09-26 16:13:54.680145 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.680150 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReleaseChunk() [this=7f083d68be40, idx=1]
2016-09-26 16:13:54.680157 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=2, caller=0, listener=7f083d68be50]
2016-09-26 16:13:54.680162 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Reusing cached chunk 7f083d6cde90 [this=7f08402e5e00]
2016-09-26 16:13:54.680171 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=0, mStatus=0x00000000, mChunk=7f083d6cde90, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.680175 UTC - [Cache2 I/O]: D/cache2 CacheIndex::UpdateEntry() [hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, frecency=, expirationTime=, size=1025]
2016-09-26 16:13:54.680175 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6cde90]
2016-09-26 16:13:54.680183 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=262144]
2016-09-26 16:13:54.680186 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::BeforeChange()
2016-09-26 16:13:54.680188 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6cdbc0, idx=1]
2016-09-26 16:13:54.680209 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=1024]
2016-09-26 16:13:54.680217 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Writing dirty chunk to the disk [this=7f08402e5e00]
2016-09-26 16:13:54.680223 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::AfterChange()
2016-09-26 16:13:54.680225 UTC - [Main Thread]: D/cache2 CacheFileChunk::Write() [this=7f083d6cdbc0, handle=7f083d6916e0, listener=7f08402e5e00]
2016-09-26 16:13:54.680228 UTC - [Cache2 I/O]: D/cache2 CacheIndexStats::Log() [count=1, notInitialized=0, removed=0, dirty=1, fresh=1, empty=0, size=1025]
2016-09-26 16:13:54.680233 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal()
2016-09-26 16:13:54.680236 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=262144, count=262144, validate=0, truncate=0, listener=7f083d6cdbc0]
2016-09-26 16:13:54.680304 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.680309 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReleaseChunk() [this=7f083d68be40, idx=2]
2016-09-26 16:13:54.680314 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=3, caller=0, listener=7f083d68be50]
2016-09-26 16:13:54.680316 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate()
2016-09-26 16:13:54.680318 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Reusing cached chunk 7f083d6ce0d0 [this=7f08402e5e00]
2016-09-26 16:13:54.680322 UTC - [Cache2 I/O]: D/cache2 CacheIndex::IsUpToDate() - returning 0
2016-09-26 16:13:54.680337 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize()
2016-09-26 16:13:54.680337 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=0, mStatus=0x00000000, mChunk=7f083d6ce0d0, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.680359 UTC - [Cache2 I/O]: D/cache2 CacheIndex::GetCacheSize() - returning 1025
2016-09-26 16:13:54.680365 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6ce0d0]
2016-09-26 16:13:54.680371 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=262144]
2016-09-26 16:13:54.680373 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::EvictIfOverLimitInternal() - Cache size and free space in limits. [cacheSize=1025kB, cacheSizeLimit=256000kB, freeSpace=106632396800, freeSpaceLimit=5242880]
2016-09-26 16:13:54.680378 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataWritten() [this=7f083d6ce1f0, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.680384 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6ce1f0, idx=4]
2016-09-26 16:13:54.680388 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=4, hash=8c9c]
2016-09-26 16:13:54.680392 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.680397 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() - Caching unused chunk [this=7f08402e5e00, chunk=7f083d6ce1f0]
2016-09-26 16:13:54.680406 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.680418 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=4]
2016-09-26 16:13:54.680419 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.680432 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=262144, count=262144, validate=0, truncate=0]
2016-09-26 16:13:54.680433 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReleaseChunk() [this=7f083d68be40, idx=3]
2016-09-26 16:13:54.680444 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() [this=7f08402e5e00, idx=4, caller=0, listener=7f083d68be50]
2016-09-26 16:13:54.680448 UTC - [Main Thread]: D/cache2 CacheFile::GetChunkLocked() - Reusing cached chunk 7f083d6ce1f0 [this=7f08402e5e00]
2016-09-26 16:13:54.680453 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=0, mStatus=0x00000000, mChunk=7f083d6ce1f0, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.680457 UTC - [Main Thread]: D/cache2 CacheFileChunk::GetReadHandle() [this=7f083d6ce1f0]
2016-09-26 16:13:54.680460 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CanRead() [this=7f083d68be40, canRead=26]
2016-09-26 16:13:54.680465 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.680468 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=4]
2016-09-26 16:13:54.680472 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReadSegments() [this=7f083d68be40, rv=0x00000000, retval=786442]
2016-09-26 16:13:54.680540 UTC - [Cache2 I/O]: D/cache2 CacheFileChunk::OnDataWritten() [this=7f083d6cdbc0, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.680563 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() [this=7f08402e5e00, rv=0x00000000, chunk=7f083d6cdbc0, idx=1]
2016-09-26 16:13:54.681448 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::SetHash() [this=7f0848085f20, idx=1, hash=465b]
2016-09-26 16:13:54.681464 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.681477 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnChunkWritten() - Releasing unused chunk [this=7f08402e5e00, chunk=7f083d6cdbc0]
2016-09-26 16:13:54.681494 UTC - [Cache2 I/O]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.681508 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.681553 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=1048589]
2016-09-26 16:13:54.681573 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Tell() [this=7f083d68be40, retval=1048589]
2016-09-26 16:13:54.681579 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() [this=7f083d68be40, releaseOnly=0]
2016-09-26 16:13:54.681583 UTC - [Main Thread]: D/cache2 CacheFileInputStream::EnsureCorrectChunk() - Have correct chunk [this=7f083d68be40, idx=4]
2016-09-26 16:13:54.681588 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Available() [this=7f083d68be40, retval=0, rv=0x80470002]
2016-09-26 16:13:54.681594 UTC - [Main Thread]: D/cache2 CacheFileInputStream::Close() [this=7f083d68be40]
2016-09-26 16:13:54.681599 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CloseWithStatus() [this=7f083d68be40, aStatus=0x00000000]
2016-09-26 16:13:54.681602 UTC - [Main Thread]: D/cache2 CacheFileInputStream::CloseWithStatusLocked() [this=7f083d68be40, aStatus=0x00000000]
2016-09-26 16:13:54.681605 UTC - [Main Thread]: D/cache2 CacheFileInputStream::ReleaseChunk() [this=7f083d68be40, idx=4]
2016-09-26 16:13:54.681611 UTC - [Main Thread]: D/cache2 CacheFileInputStream::MaybeNotifyListener() [this=7f083d68be40, mCallback=0, mClosed=1, mStatus=0x80470002, mChunk=0, mListeningForChunk=-1, mWaitingForUpdate=0]
2016-09-26 16:13:54.681619 UTC - [Main Thread]: D/cache2 CacheEntry::OnHandleClosed [this=7f083d693c00, state=READY, handle=7f083d6c7ee0]
2016-09-26 16:13:54.681626 UTC - [Main Thread]: D/cache2   not the writer
2016-09-26 16:13:54.681634 UTC - [Main Thread]: D/nsHttp nsHttpChannel::OnStopRequest [this=7f083f5c4800 request=7f083f50c300 status=0]
2016-09-26 16:13:54.681637 UTC - [Main Thread]: D/nsHttp   dropping upload stream
2016-09-26 16:13:54.681641 UTC - [Main Thread]: D/nsHttp   calling OnStopRequest
2016-09-26 16:13:54.788494 UTC - [Main Thread]: D/nsHttp nsHttpChannel::CloseCacheEntry [this=7f083f5c4800] mStatus=0 mCacheEntryIsWriteOnly=0
2016-09-26 16:13:54.788670 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6cde90, idx=2]
2016-09-26 16:13:54.788685 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Releasing unused chunk [this=7f08402e5e00, chunk=7f083d6cde90]
2016-09-26 16:13:54.788691 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.788696 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6cde90]
2016-09-26 16:13:54.788712 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 524800 [this=7f083d6cde90]
2016-09-26 16:13:54.788792 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6ce0d0, idx=3]
2016-09-26 16:13:54.788801 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Releasing unused chunk [this=7f08402e5e00, chunk=7f083d6ce0d0]
2016-09-26 16:13:54.788806 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.788810 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6ce0d0]
2016-09-26 16:13:54.788825 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 262656 [this=7f083d6ce0d0]
2016-09-26 16:13:54.788904 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() [this=7f08402e5e00, chunk=7f083d6ce1f0, idx=4]
2016-09-26 16:13:54.788913 UTC - [Main Thread]: D/cache2 CacheFile::DeactivateChunk() - Caching unused chunk [this=7f08402e5e00, chunk=7f083d6ce1f0]
2016-09-26 16:13:54.788918 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.789005 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6cdbc0]
2016-09-26 16:13:54.789023 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 512 [this=7f083d6cdbc0]
2016-09-26 16:13:54.790389 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::SetupSSL 7f08402d0200 caps=0x401 ......localhost:36870
2016-09-26 16:13:54.790444 UTC - [Socket Thread]: V/nsHttp Server initiated close of idle conn 7f08402d0200
2016-09-26 16:13:54.790470 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::CloseIdleConnection 7f0849e7e1e0 conn=7f08402d0200
2016-09-26 16:13:54.790504 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Close [this=7f08402d0200 reason=80004004]
2016-09-26 16:13:54.790525 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::EndIdleMonitoring [this=7f08402d0200]
2016-09-26 16:13:54.790544 UTC - [Socket Thread]: V/nsHttp Leaving Idle Monitoring Mode [this=7f08402d0200]
2016-09-26 16:13:54.790580 UTC - [Socket Thread]: V/nsHttp nsHttpConnection::Close drained 0 bytes
2016-09-26 16:13:54.790632 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::StopPruneDeadConnectionsTimer
2016-09-26 16:13:54.790682 UTC - [Socket Thread]: V/nsHttp Destroying nsHttpConnection @7f08402d0200
2016-09-26 16:13:54.790706 UTC - [Socket Thread]: V/nsHttp nsHttpConnection 7f08402d0200 performed 0 HTTP/1.x transactions
2016-09-26 16:13:54.859170 UTC - [Main Thread]: D/nsHttp Destroying nsHttpChannel [this=7f083f5c4800]
2016-09-26 16:13:54.859233 UTC - [Main Thread]: D/cache2 CacheEntry::OnHandleClosed [this=7f083d693c00, state=READY, handle=7f083d6c7fa0]
2016-09-26 16:13:54.859246 UTC - [Main Thread]: D/cache2   not the writer
2016-09-26 16:13:54.859262 UTC - [Main Thread]: V/nsHttp Destroying HttpBaseChannel @3f5c4800
2016-09-26 16:13:54.859300 UTC - [Main Thread]: D/nsHttp Destroying nsHttpConnectionInfo @49e79040
2016-09-26 16:13:54.859353 UTC - [Main Thread]: D/cache2 CacheFile::RemoveInput() [this=7f08402e5e00, input=7f083d68be40, status=0x80470002]
2016-09-26 16:13:54.859376 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.859438 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() - Writing metadata [this=7f08402e5e00]
2016-09-26 16:13:54.859456 UTC - [Main Thread]: D/cache2 CacheFileMetadata::WriteMetadata() [this=7f0848085f20, offset=1048602, listener=7f08402e5e10]
2016-09-26 16:13:54.859489 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Write() [handle=7f083d6916e0, offset=1048602, count=504, validate=1, truncate=1, listener=7f0848085f20]
2016-09-26 16:13:54.859524 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.859542 UTC - [Main Thread]: D/cache2 CacheFile::CleanUpCachedChunks() [this=7f08402e5e00, idx=4, chunk=7f083d6ce1f0]
2016-09-26 16:13:54.859553 UTC - [Main Thread]: D/cache2 CacheFile::CleanUpCachedChunks() - Removing chunk
2016-09-26 16:13:54.859564 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::WriteInternal() [handle=7f083d6916e0, offset=1048602, count=504, validate=1, truncate=1]
2016-09-26 16:13:54.859567 UTC - [Main Thread]: D/cache2 CacheFileChunk::~CacheFileChunk() [this=7f083d6ce1f0]
2016-09-26 16:13:54.859652 UTC - [Main Thread]: D/cache2 CacheFileChunk::BuffersAllocationChanged() - Normal chunks usage 0 [this=7f083d6ce1f0]
2016-09-26 16:13:54.859768 UTC - [Main Thread]: D/cache2 CacheFileInputStream::~CacheFileInputStream() [this=7f083d68be40]
2016-09-26 16:13:54.859799 UTC - [Main Thread]: D/nsHttp Destroying nsHttpChannel [this=7f083f556000]
2016-09-26 16:13:54.859818 UTC - [Main Thread]: D/cache2 CacheEntry::OnHandleClosed [this=7f083d693c00, state=READY, handle=7f0849e16660]
2016-09-26 16:13:54.859861 UTC - [Main Thread]: D/cache2 CacheEntry::BackgroundOp this=7f083d693c00 dipatch of 4
2016-09-26 16:13:54.859879 UTC - [Main Thread]: V/nsHttp Destroying HttpBaseChannel @3f556000
2016-09-26 16:13:54.859913 UTC - [Main Thread]: D/nsHttp Destroying nsHttpConnectionInfo @49e78cc0
2016-09-26 16:13:54.859978 UTC - [Cache2 I/O]: D/cache2 CacheFileMetadata::OnDataWritten() [this=7f0848085f20, handle=7f083d6916e0, result=0x00000000]
2016-09-26 16:13:54.860004 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnMetadataWritten() [this=7f08402e5e00, rv=0x00000000]
2016-09-26 16:13:54.860018 UTC - [Cache2 I/O]: D/cache2 CacheFile::OnMetadataWritten() - Releasing file handle [this=7f08402e5e00]
2016-09-26 16:13:54.860030 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::ReleaseNSPRHandle() [handle=7f083d6916e0]
2016-09-26 16:13:54.860071 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=768]
2016-09-26 16:13:54.860091 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=4]
2016-09-26 16:13:54.860127 UTC - [Cache2 I/O]: D/cache2 CacheEntry CALLBACKS (invoke) [this=7f083d693c00]
2016-09-26 16:13:54.860139 UTC - [Cache2 I/O]: D/cache2 CacheEntry::InvokeCallbacks BEGIN [this=7f083d693c00]
2016-09-26 16:13:54.860151 UTC - [Cache2 I/O]: D/cache2 CacheEntry::InvokeCallbacks END [this=7f083d693c00]
2016-09-26 16:13:54.860170 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::MaybeReleaseNSPRHandleInternal() [handle=7f083d6916e0, ignore shutdown=0]
2016-09-26 16:13:54.860190 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::MaybeReleaseNSPRHandleInternal() DONE
2016-09-26 16:13:54.860205 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.881324 UTC - [Main Thread]: D/nsHttp nsHttpHandler::Observe [topic="profile-change-net-teardown"]
2016-09-26 16:13:54.881343 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::ClearAll
2016-09-26 16:13:54.881352 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::ClearAll
2016-09-26 16:13:54.881357 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::Shutdown
2016-09-26 16:13:54.881433 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgShutdown
2016-09-26 16:13:54.881448 UTC - [Socket Thread]: V/nsHttp nsHttpConnectionMgr::StopPruneDeadConnectionsTimer
2016-09-26 16:13:54.881457 UTC - [Socket Thread]: D/nsHttp Destroying nsHttpConnectionInfo @49e78f60
2016-09-26 16:13:54.881489 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::OnMsgShutdownConfirm
2016-09-26 16:13:54.909937 UTC - [Main Thread]: D/cache2 CacheStorageService::Shutdown - start
2016-09-26 16:13:54.910023 UTC - [Main Thread]: D/cache2 CacheStorageService::Shutdown - done
2016-09-26 16:13:54.910042 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Shutdown() [gInstance=7f083f5815c0]
2016-09-26 16:13:54.910058 UTC - [Main Thread]: D/cache2 CacheIndex::PreShutdown() [gInstance=7f08402d1240]
2016-09-26 16:13:54.910073 UTC - [Main Thread]: D/cache2 CacheIndex::PreShutdown() - [state=3, indexOnDiskIsValid=0, dontMarkIndexClean=0]
2016-09-26 16:13:54.910072 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::ShutdownBackground - start
2016-09-26 16:13:54.910134 UTC - [Main Thread]: D/cache2 CacheIndex::PreShutdown() - Closing iterators.
2016-09-26 16:13:54.910149 UTC - [Cache2 I/O]: D/cache2 CacheEntry::~CacheEntry [this=7f083d693c00]
2016-09-26 16:13:54.910189 UTC - [Cache2 I/O]: D/cache2 CacheStorageService::ShutdownBackground - done
2016-09-26 16:13:54.910223 UTC - [Cache2 I/O]: D/cache2 CacheIndex::PreShutdownInternal() - [state=3, indexOnDiskIsValid=0, dontMarkIndexClean=0]
2016-09-26 16:13:54.910257 UTC - [Cache2 I/O]: D/cache2 CacheIndex::FinishUpdate() [succeeded=0]
2016-09-26 16:13:54.910272 UTC - [Cache2 I/O]: D/cache2 CacheIndex::ChangeState() changing state BUILDING -> READY
2016-09-26 16:13:54.910284 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::CacheIndexStateChanged()
2016-09-26 16:13:54.910348 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::ShutdownInternal() [this=7f083f5815c0]
2016-09-26 16:13:54.910408 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Log() - entry file [this=7f083d6916e0, hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3, isDoomed=0, priority=0, closed=1, invalid=0, pinning=1, fileExists=1, fileSize=1049106, leafName=FCDD1A69760ACC917346BEE4A5968D4A9F6B58F3, key=:http://localhost:36870/content]
2016-09-26 16:13:54.910449 UTC - [Cache2 I/O]: D/cache2 CacheFileIOManager::MaybeReleaseNSPRHandleInternal() [handle=7f083d6916e0, ignore shutdown=0]
2016-09-26 16:13:54.910473 UTC - [Cache2 I/O]: D/cache2 CacheFileHandles::RemoveHandle() hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3 removing handle 7f083d6916e0
2016-09-26 16:13:54.910493 UTC - [Cache2 I/O]: D/cache2 CacheFileHandles::RemoveHandle() hash=fcdd1a69760acc917346bee4a5968d4a9f6b58f3 list is empty, removing entry 7f083f571c68
2016-09-26 16:13:54.910513 UTC - [Cache2 I/O]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=3]
2016-09-26 16:13:54.910642 UTC - [Main Thread]: D/cache2 CacheIndex::Shutdown() [gInstance=7f08402d1240]
2016-09-26 16:13:54.910682 UTC - [Main Thread]: D/cache2 CacheIndex::Shutdown() - [state=5, indexOnDiskIsValid=0, dontMarkIndexClean=1, sanitize=0]
2016-09-26 16:13:54.910697 UTC - [Main Thread]: D/cache2 CacheIndex::ChangeState() changing state READY -> SHUTDOWN
2016-09-26 16:13:54.910708 UTC - [Main Thread]: D/cache2 CacheIndex::RemoveJournalAndTempFile()
2016-09-26 16:13:54.910771 UTC - [Main Thread]: D/cache2 CacheIndex::~CacheIndex [this=7f08402d1240]
2016-09-26 16:13:54.910794 UTC - [Main Thread]: D/cache2 CacheIndexEntry::~CacheIndexEntry() - Deleting record [rec=7f083d686130]
2016-09-26 16:13:54.910817 UTC - [Main Thread]: D/cache2 CacheFileIOManager::~CacheFileIOManager [this=7f083f5815c0]
2016-09-26 16:13:54.910852 UTC - [Main Thread]: D/cache2 CacheFileHandles::~CacheFileHandles() [this=7f083f581600]
2016-09-26 16:13:54.996817 UTC - [Main Thread]: D/cache2 CacheFile::RemoveOutput() [this=7f08402e5e00, output=7f083d68b2e0, status=0x80470002]
2016-09-26 16:13:54.996845 UTC - [Main Thread]: D/cache2 CacheFile::RemoveOutput() - This output was already removed, ignoring call [this=7f08402e5e00]
2016-09-26 16:13:54.996855 UTC - [Main Thread]: D/cache2 CacheFileOutputStream::~CacheFileOutputStream() [this=7f083d68b2e0]
2016-09-26 16:13:54.996862 UTC - [Main Thread]: D/cache2 CacheFile::~CacheFile() [this=7f08402e5e00]
2016-09-26 16:13:54.996868 UTC - [Main Thread]: D/cache2 CacheFile::WriteMetadataIfNeededLocked() [this=7f08402e5e00]
2016-09-26 16:13:54.996879 UTC - [Main Thread]: D/cache2 CacheFileMetadata::~CacheFileMetadata() [this=7f0848085f20]
2016-09-26 16:13:54.996889 UTC - [Main Thread]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=2]
2016-09-26 16:13:54.996896 UTC - [Main Thread]: D/cache2 CacheStorageService::OnMemoryConsumptionChange [consumer=7f0848085f28, size=0]
2016-09-26 16:13:54.996903 UTC - [Main Thread]: D/cache2   mMemorySize=0 (+0,-768)
2016-09-26 16:13:54.996909 UTC - [Main Thread]: D/cache2 CacheFileHandle::Release() [this=7f083d6916e0, refcnt=1]
2016-09-26 16:13:54.996915 UTC - [Main Thread]: D/cache2 CacheFileHandle::~CacheFileHandle() [this=7f083d6916e0]
2016-09-26 16:13:55.051404 UTC - [Main Thread]: D/nsHttp nsHttpHandler::Observe [topic="xpcom-shutdown"]
2016-09-26 16:13:55.051422 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::ClearAll
2016-09-26 16:13:55.051425 UTC - [Main Thread]: D/nsHttp nsHttpAuthCache::ClearAll
2016-09-26 16:13:55.051428 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::Shutdown
2016-09-26 16:13:55.051464 UTC - [Main Thread]: D/cache2 CacheFileIOManager::Shutdown() [gInstance=0]
2016-09-26 16:13:55.053891 UTC - [Main Thread]: D/cache2 CacheStorageService::~CacheStorageService
2016-09-26 16:13:55.053963 UTC - [Main Thread]: D/nsHttp Deleting nsHttpHandler [this=7f083f587000]
2016-09-26 16:13:55.053968 UTC - [Main Thread]: V/nsHttp nsHttpConnectionMgr::Shutdown
2016-09-26 16:13:55.053973 UTC - [Main Thread]: V/nsHttp Destroying nsHttpConnectionMgr @7f0849e7e1e0