From 7723403b1facaf6f281e5f61256c402dcd4090aa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=C8=98tefan=20Talpalaru?= Date: Tue, 14 Apr 2020 15:21:16 +0200 Subject: [PATCH] debug prints (#132) * debug prints * CI: enable stack traces * Azure: better NimBinaries cache key * CI changes - Azure: remove Linux target - Travis: add ARM64 target * uglify the code in order to save 12 bytes per LPStream object --- .travis.yml | 16 +++++++++++++++- azure-pipelines.yml | 10 +++++----- libp2p.nimble | 4 ++-- libp2p/connection.nim | 4 +++- libp2p/protocols/secure/secio.nim | 9 +++++++-- libp2p/stream/bufferstream.nim | 21 ++++++++++++++++++++- libp2p/stream/lpstream.nim | 5 ++++- 7 files changed, 56 insertions(+), 13 deletions(-) diff --git a/.travis.yml b/.travis.yml index 37789bd55..4283d984a 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,5 +1,7 @@ language: go +dist: bionic + # https://docs.travis-ci.com/user/caching/ cache: directories: @@ -15,9 +17,21 @@ go: "1.12.x" matrix: include: - os: linux + arch: amd64 + env: + - NPROC=2 + before_install: + - export GOPATH=$HOME/go + - os: linux + arch: arm64 + env: + - NPROC=6 # Worth trying more than 2 parallel jobs: https://travis-ci.community/t/no-cache-support-on-arm64/5416/8 + # (also used to get a different cache key than the amd64 one) before_install: - export GOPATH=$HOME/go - os: osx + env: + - NPROC=2 before_install: - export GOPATH=$HOME/go @@ -26,7 +40,7 @@ install: # regressions of the fast-paced Nim development while maintaining the # flexibility to apply patches - curl -O -L -s -S https://raw.githubusercontent.com/status-im/nimbus-build-system/master/scripts/build_nim.sh - - env MAKE="make -j2" bash build_nim.sh Nim csources dist/nimble NimBinaries + - env MAKE="make -j${NPROC}" bash build_nim.sh Nim csources dist/nimble NimBinaries - export PATH="$PWD/Nim/bin:$GOPATH/bin:$PATH" # install and build go-libp2p-daemon diff --git a/azure-pipelines.yml b/azure-pipelines.yml index 4a80b3a20..059cba697 100644 --- a/azure-pipelines.yml +++ b/azure-pipelines.yml @@ -18,10 +18,10 @@ strategy: # UCPU: amd64 # PLATFORM: x64 # TEST_LANG: cpp - Linux_64bit: - VM: 'ubuntu-16.04' - PLATFORM: x64 - TEST_LANG: c + #Linux_64bit: + #VM: 'ubuntu-16.04' + #PLATFORM: x64 + #TEST_LANG: c # Linux_cpp_64bit: # VM: 'ubuntu-16.04' # UCPU: amd64 @@ -53,7 +53,7 @@ steps: - task: CacheBeta@1 displayName: 'cache Nim binaries' inputs: - key: NimBinaries | $(Agent.OS) | $(PLATFORM) + key: NimBinaries | $(Agent.OS) | $(PLATFORM) | "$(Build.SourceBranchName)" | "v3" path: NimBinaries - task: CacheBeta@1 diff --git a/libp2p.nimble b/libp2p.nimble index d9879f756..8841e8af1 100644 --- a/libp2p.nimble +++ b/libp2p.nimble @@ -16,8 +16,8 @@ requires "nim > 0.19.4", "stew" proc runTest(filename: string) = - exec "nim --opt:speed -d:release c -r tests/" & filename - # rmFile "tests/" & filename + exec "nim c -r --opt:speed -d:debug --verbosity:0 --hints:off tests/" & filename + rmFile "tests/" & filename.toExe task test, "Runs the test suite": runTest "testnative" diff --git a/libp2p/connection.nim b/libp2p/connection.nim index 0d73eac77..6fc31821a 100644 --- a/libp2p/connection.nim +++ b/libp2p/connection.nim @@ -7,7 +7,7 @@ ## This file may not be copied, modified, or distributed except according to ## those terms. -import chronos, chronicles +import chronos, chronicles, oids import peerinfo, multiaddress, stream/lpstream, @@ -54,6 +54,8 @@ proc init*[T: Connection](self: var T, stream: LPStream): T = new self self.stream = stream self.closeEvent = newAsyncEvent() + when chronicles.enabledLogLevel == LogLevel.TRACE: + self.oid = genOid() asyncCheck self.bindStreamClose() return self diff --git a/libp2p/protocols/secure/secio.nim b/libp2p/protocols/secure/secio.nim index 95a99ffb3..935aa452e 100644 --- a/libp2p/protocols/secure/secio.nim +++ b/libp2p/protocols/secure/secio.nim @@ -6,7 +6,7 @@ ## at your option. ## This file may not be copied, modified, or distributed except according to ## those terms. -import chronos, chronicles +import chronos, chronicles, oids import nimcrypto/[sysrand, hmac, sha2, sha, hash, rijndael, twofish, bcmode] import secure, ../../connection, @@ -177,12 +177,15 @@ proc macCheckAndDecode(sconn: SecioConn, data: var seq[byte]): bool = method readMessage(sconn: SecioConn): Future[seq[byte]] {.async.} = ## Read message from channel secure connection ``sconn``. + when chronicles.enabledLogLevel == LogLevel.TRACE: + logScope: + stream_oid = $sconn.stream.oid try: var buf = newSeq[byte](4) await sconn.readExactly(addr buf[0], 4) let length = (int(buf[0]) shl 24) or (int(buf[1]) shl 16) or (int(buf[2]) shl 8) or (int(buf[3])) - trace "Recieved message header", header = buf.shortLog, length = length + trace "Received message header", header = buf.shortLog, length = length if length <= SecioMaxMessageSize: buf.setLen(length) await sconn.readExactly(addr buf[0], length) @@ -260,6 +263,8 @@ proc newSecioConn(conn: Connection, secrets.ivOpenArray(i1)) result.peerInfo = PeerInfo.init(remotePubKey) + when chronicles.enabledLogLevel == LogLevel.TRACE: + result.oid = genOid() proc transactMessage(conn: Connection, msg: seq[byte]): Future[seq[byte]] {.async.} = diff --git a/libp2p/stream/bufferstream.nim b/libp2p/stream/bufferstream.nim index 43425e847..2fc088a1e 100644 --- a/libp2p/stream/bufferstream.nim +++ b/libp2p/stream/bufferstream.nim @@ -30,7 +30,7 @@ ## will suspend until either the amount of elements in the ## buffer goes below ``maxSize`` or more data becomes available. -import deques, math +import deques, math, oids import chronos, chronicles import ../stream/lpstream @@ -63,6 +63,7 @@ proc requestReadBytes(s: BufferStream): Future[void] = ## data becomes available in the read buffer result = newFuture[void]() s.readReqs.addLast(result) + trace "requestReadBytes(): added a future to readReqs" proc initBufferStream*(s: BufferStream, handler: WriteHandler = nil, @@ -74,6 +75,8 @@ proc initBufferStream*(s: BufferStream, s.lock = newAsyncLock() s.writeHandler = handler s.closeEvent = newAsyncEvent() + when chronicles.enabledLogLevel == LogLevel.TRACE: + s.oid = genOid() proc newBufferStream*(handler: WriteHandler = nil, size: int = DefaultBufferSize): BufferStream = @@ -103,6 +106,10 @@ proc pushTo*(s: BufferStream, data: seq[byte]) {.async.} = ## is preserved. ## + when chronicles.enabledLogLevel == LogLevel.TRACE: + logScope: + stream_oid = $s.oid + try: await s.lock.acquire() var index = 0 @@ -110,10 +117,12 @@ proc pushTo*(s: BufferStream, data: seq[byte]) {.async.} = while index < data.len and s.readBuf.len < s.maxSize: s.readBuf.addLast(data[index]) inc(index) + trace "pushTo()", msg = "added " & $index & " bytes to readBuf" # resolve the next queued read request if s.readReqs.len > 0: s.readReqs.popFirst().complete() + trace "pushTo(): completed a readReqs future" if index >= data.len: return @@ -130,6 +139,11 @@ method read*(s: BufferStream, n = -1): Future[seq[byte]] {.async.} = ## ## This procedure allocates buffer seq[byte] and return it as result. ## + when chronicles.enabledLogLevel == LogLevel.TRACE: + logScope: + stream_oid = $s.oid + + trace "read()", requested_bytes = n var size = if n > 0: n else: s.readBuf.len() var index = 0 @@ -140,6 +154,7 @@ method read*(s: BufferStream, n = -1): Future[seq[byte]] {.async.} = while s.readBuf.len() > 0 and index < size: result.add(s.popFirst()) inc(index) + trace "read()", read_bytes = index if index < size: await s.requestReadBytes() @@ -154,6 +169,10 @@ method readExactly*(s: BufferStream, ## If EOF is received and ``nbytes`` is not yet read, the procedure ## will raise ``LPStreamIncompleteError``. ## + when chronicles.enabledLogLevel == LogLevel.TRACE: + logScope: + stream_oid = $s.oid + var buff: seq[byte] try: buff = await s.read(nbytes) diff --git a/libp2p/stream/lpstream.nim b/libp2p/stream/lpstream.nim index 455190b88..fc7764a1c 100644 --- a/libp2p/stream/lpstream.nim +++ b/libp2p/stream/lpstream.nim @@ -7,12 +7,15 @@ ## This file may not be copied, modified, or distributed except according to ## those terms. -import chronos +import oids +import chronicles, chronos type LPStream* = ref object of RootObj isClosed*: bool closeEvent*: AsyncEvent + when chronicles.enabledLogLevel == LogLevel.TRACE: + oid*: Oid LPStreamError* = object of CatchableError LPStreamIncompleteError* = object of LPStreamError