Opened 2 months ago

Last modified 8 weeks ago

#2458 new defect

Router watchdog barking because of outdated leaset

Reported by: jogger Owned by:
Priority: minor Milestone: undecided
Component: router/general Version: 0.9.38
Keywords: Cc: zab
Parent Tickets:

Description

I get this every minute in my logs, same leaseset for more than a week - router runs fine otherwise:

12.03.19, 09:16:37 ERROR [uterWatchdog] client.ClientManagerFacadeImpl?: Client bohwswqqx6orlerppkbvhuibxmrk5po6rlscxphzcd575xe3j74a.b32.i2p has a leaseSet that expired 13d ago
12.03.19, 09:16:37 ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog?: Ready and waiting jobs: 0
12.03.19, 09:16:37 ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog?: Job lag: 0
12.03.19, 09:16:37 ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog?: Participating tunnel count: 200
12.03.19, 09:16:37 ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog?: 1 minute send processing time: 210ms
12.03.19, 09:16:37 ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog?: Outbound send rate: 392,00KiBps
12.03.19, 09:16:37 ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog?: Memory: 89,70MiB / 128,00MiB

Subtickets (add)

Change History (6)

comment:1 Changed 2 months ago by zab

  • Cc zab added

Related: #2455

comment:2 Changed 2 months ago by zzz

13 days ago... hmm... any guess what client bohws... is?
whatever happened, we shouldn't be spamming the logs
can you go back 13 days ago in the logs and try to find the original problem?

comment:3 Changed 2 months ago by anonymous maybe

maybe this going to be useful:

  • I2P Version and Running Environment
 I2P version:	0.9.38-0-1ubuntu1
Java version:	Oracle Corporation 9-Debian (OpenJDK Runtime Environment 9-Debian+0-9b181-4bpo91)
Wrapper version:	3.5.30
Server version:	9.2.21.v20170120
Servlet version:	Jasper JSP 2.3 Engine
JSTL version:	standard-taglib 1.2.5
Platform:	Linux amd64 4.14.103-1.pvops.qubes.x86_64
Processor:	Haswell Core i3/i5/i7 model 60 (coreihwl)
JBigI status:	Locally optimized library libjbigi-linux-coreihwl_64.so loaded from file
GMP version:	6.1.2
JBigI version:	4
JCpuId version:	3
Encoding:	UTF-8
Charset:	UTF-8
Built By:	Undefined
  • Critical Logs
    3/15/19, 8:07:57 AM CRIT [uterWatchdog] 2p.router.tasks.RouterWatchdog: Router appears hung, or there is severe network congestion. Watchdog starts barking!
    3/14/19, 9:35:56 PM CRIT [uterWatchdog] 2p.router.tasks.RouterWatchdog: Router appears hung, or there is severe network congestion. Watchdog starts barking!
  • Router Logs
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Memory: 52.55MiB / 966.69MiB
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Outbound send rate: 926Bps
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: 1 minute send processing time: 95ms
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Participating tunnel count: 2
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Job lag: 0
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Ready and waiting jobs: 0
    3/15/19, 8:08:57 AM ERROR [uterWatchdog] client.ClientManagerFacadeImpl: Client o5zh4hhe57o4c3npasnha4hul3ti5vxkvbggpdqusngo2tw3uxbq.b32.i2p has a leaseSet that expired 11m ago
    3/15/19, 8:07:57 AM CRIT [uterWatchdog] 2p.router.tasks.RouterWatchdog: Router appears hung, or there is severe network congestion. Watchdog starts barking!
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Memory: 60.73MiB / 966.69MiB
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Outbound send rate: 1.04KiBps
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: 1 minute send processing time: 126ms
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Participating tunnel count: 2
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Job lag: 0
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] 2p.router.tasks.RouterWatchdog: Ready and waiting jobs: 0
    3/15/19, 8:07:57 AM ERROR [uterWatchdog] client.ClientManagerFacadeImpl: Client o5zh4hhe57o4c3npasnha4hul3ti5vxkvbggpdqusngo2tw3uxbq.b32.i2p has a leaseSet that expired 10m ago
    3/15/19, 6:14:06 AM DEBUG [nt Runner 16] .i2ptunnel.I2PTunnelHTTPClient: HTTPClient[4/2]: Destination: i2p-projekt.i2p
    3/15/19, 6:14:06 AM DEBUG [nt Runner 16] .i2ptunnel.I2PTunnelHTTPClient: HTTPClient[4/2]: NewRequest header: [GET /hosts.txt HTTP/1.1
         Host: udhdrtrcetjm5sxzskjyr5ztpeszydbh4dpl3pl4utgqqw2v4jna.b32.i2p
         Cache-Control: no-cache
         Pragma: no-cache
         If-None-Match: "1546003468.22-203509-3078492705-gzip"
         If-Modified-Since: Fri, 28 Dec 2018 13:24:28 GMT
         Accept-Encoding: gzip
         X-Accept-Encoding: x-i2p-gzip;q=1.0, identity;q=0.5, deflate;q=0, gzip;q=0, *;q=0
         User-Agent: MYOB/6.66 (AN/ON)
         Connection: close
        
         ]
    3/15/19, 6:14:06 AM DEBUG [nt Runner 16] .i2ptunnel.I2PTunnelHTTPClient: HTTPClient[4/2]: Line=[]
    3/15/19, 6:14:06 AM DEBUG [nt Runner 16] .i2ptunnel.I2PTunnelHTTPClient: HTTPClient[4/2]: Line=[Connection: close]
    3/15/19, 6:14:06 AM DEBUG [nt Runner 16] .i2ptunnel.I2PTunnelHTTPClient: HTTPClient[4/2]: Line=[User-Agent: Wget/1.11.4]
  • Service (Wrapper) Logs
2019/03/14 18:07:31 | --> Wrapper Started as Daemon
2019/03/14 18:07:31 | Java Service Wrapper Community Edition 64-bit 3.5.30
2019/03/14 18:07:31 |   Copyright (C) 1999-2016 Tanuki Software, Ltd. All Rights Reserved.
2019/03/14 18:07:31 |     http://wrapper.tanukisoftware.com
2019/03/14 18:07:31 | 
2019/03/14 18:07:31 | Launching a JVM...
2019/03/14 18:07:32 | WrapperManager: Initializing...
2019/03/14 18:07:32 | Starting I2P 0.9.38-0-1ubuntu1
2019/03/14 18:07:32 | INFO: Native CPUID library jcpuid-x86-linux loaded from file
2019/03/14 18:07:32 | INFO: Locally optimized library libjbigi-linux-coreihwl_64.so loaded from file
2019/03/14 18:07:36 | WARN: IP changed, restarting with a new identity and port
2019/03/14 18:07:36 | INFO:  Removing old identity file: router.info
2019/03/14 18:07:36 | INFO:  Removing old identity file: router.keys.dat
2019/03/14 18:07:36 | INFO:  Removing old identity file: keyBackup/privateEncryption.key
2019/03/14 18:07:36 | INFO:  Removing old identity file: keyBackup/publicEncryption.key
2019/03/14 18:07:36 | INFO:  Removing old identity file: keyBackup/privateSigning.key
2019/03/14 18:07:36 | INFO:  Removing old identity file: keyBackup/publicSigning.key
2019/03/14 18:07:37 | CRIT  [ Establisher] net.i2p.router.Router         : Starting final shutdown(4)
2019/03/14 18:07:37 | CRIT  [ Establisher] net.i2p.router.Router         : Shutdown(4) complete
2019/03/14 18:07:40 | on_exit trigger matched.  Restarting the JVM.  (Exit code: 4)
2019/03/14 18:07:55 | Launching a JVM...
2019/03/14 18:07:55 | WrapperManager: Initializing...
2019/03/14 18:07:55 | Starting I2P 0.9.38-0-1ubuntu1
2019/03/14 18:07:55 | INFO: Native CPUID library jcpuid-x86-linux loaded from file
2019/03/14 18:07:55 | INFO: Locally optimized library libjbigi-linux-coreihwl_64.so loaded from file
2019/03/14 21:36:15 | CRIT  [uterWatchdog] 2p.router.tasks.RouterWatchdog: Router appears hung, or there is severe network congestion.  Watchdog starts barking!
2019/03/15 08:07:58 | CRIT  [uterWatchdog] 2p.router.tasks.RouterWatchdog: Router appears hung, or there is severe network congestion.  Watchdog starts barking!

comment:4 Changed 8 weeks ago by jogger

It definitely depends on the peer. Saw barking with this guy 7vbgg4q5jxwwulex5cicga7iozu4xgivrwo3mc3y37h2fsrpre5a.b32.i2p twice for 11-12 min yesterday and today. Nothing else in the logs.

So far has only happened on routers with # of tunnels restricted.

comment:5 Changed 8 weeks ago by zzz

what do you mean "# of tunnels restricted" ? what is restricted? this is some manual configuration you did?

comment:6 Changed 8 weeks ago by jogger

I used this limiter:

router.maxParticipatingTunnels=200

Note: See TracTickets for help on using tickets.