Rclone serve dlna, after few hours of idle running: panic: Logger uninitialized. names=[]

[disconnect5852]

I've used rclone serve dlna with a google drive backend for years, now switched to an S3 compatible provider, idrive e2.
For the rclone dlna server start command, i just changed the backend, everything else is the same. It works ok, but after few hours idling, rclone crashes with this error log:

2022/12/16 06:40:27 INFO  : /static/X_MS_MediaReceiverRegistrar.xml: 192.168.0.25:58845 GET 200  
2022/12/16 06:40:27 INFO  : /static/X_MS_MediaReceiverRegistrar.xml: 192.168.0.25:58844 GET 200  
2022/12/16 08:47:21 INFO  : /static/ContentDirectory.xml: 192.168.0.25:40690 GET 200  
2022/12/16 08:47:21 INFO  : /static/ContentDirectory.xml: 192.168.0.25:40689 GET 200  
2022/12/16 08:47:21 INFO  : /static/ConnectionManager.xml: 192.168.0.25:40693 GET 200  
2022/12/16 08:47:21 INFO  : /static/ConnectionManager.xml: 192.168.0.25:40694 GET 200  
2022/12/16 08:47:21 INFO  : /static/X_MS_MediaReceiverRegistrar.xml: 192.168.0.25:40697 GET 200  
2022/12/16 08:47:21 INFO  : /static/X_MS_MediaReceiverRegistrar.xml: 192.168.0.25:40698 GET 200  
panic: Logger uninitialized. names=[]

goroutine 651257 [running]:
github.com/anacrolix/log.loggerCore.handle({0x0, {0x0, 0x0, 0x0}, {0x0, 0x0, 0x0}, {0x0}, {0x0}, {0x0, ...}, ...}, ...)
	github.com/anacrolix/log@v0.13.1/logger-core.go:82 +0x1e8
github.com/anacrolix/log.loggerCore.lazyLog({0x0, {0x0, 0x0, 0x0}, {0x0, 0x0, 0x0}, {0x0}, {0x0}, {0x0, ...}, ...}, ...)
	github.com/anacrolix/log@v0.13.1/logger-core.go:72 +0x18f
github.com/anacrolix/log.loggerCore.LazyLog(...)
	github.com/anacrolix/log@v0.13.1/logger-core.go:55
github.com/anacrolix/log.Logger.Printf({{0x0, {0x0, 0x0, 0x0}, {0x0, 0x0, 0x0}, {0x0}, {0x0}, {0x0, ...}, ...}}, ...)
	github.com/anacrolix/log@v0.13.1/logger.go:22 +0x10e
github.com/anacrolix/dms/ssdp.(*Server).send(0xc000ad28c0, {0xc0004d1800?, 0x113, 0x0?}, 0x0?)
	github.com/anacrolix/dms@v1.5.0/ssdp/ssdp.go:215 +0x27b
github.com/anacrolix/dms/ssdp.(*Server).delayedSend.func1()
	github.com/anacrolix/dms@v1.5.0/ssdp/ssdp.go:225 +0xc5
created by github.com/anacrolix/dms/ssdp.(*Server).delayedSend
	github.com/anacrolix/dms@v1.5.0/ssdp/ssdp.go:222 +0xcb

Yesterday it happened about 2 hours after the start, today 7 hours later, so totally random.

rclone version:

rclone v1.60.1
- os/version: ubuntu 20.04 (64 bit)
- os/kernel: 5.4.0-125-generic (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.19.3
- go/linking: static
- go/tags: none

Command: nohup rclone serve dlna idrive2test:/bucket/xxxxxx --no-modtime --no-checksum --log-level INFO --log-file ~/dlna.out --read-only &

[ncw (Nick Craig-Wood)]

It looks like we forgot to initialize the dlna ssdp server logger.

Can you give this a go? It should log something too. It may log too much stuff - feedback on that would be useful.

v1.61.0-beta.6650.af37cab3e.fix-dlna-logger on branch fix-dlna-logger (uploaded in 15-30 mins)

[disconnect5852]

trying, so far it works. Now i stop dlna playing, and wait few hours, see if crashes

[disconnect5852]

Had this strange log message, but still runs without problem: 2022-12-17T00:18:11+0100 NIL [github.com/anacrolix/dms/ssdp.(*Server).send:215]: error writing to UDP socket: write udp 0.0.0.0:1900->239.255.255.250:1900: sendto: operation not permitted

[ncw (Nick Craig-Wood)]

Thats the error message which would have crashed the server before I think.

That is a write to a multicast address I think, not sure why you'd get operation not permitted - maybe the multicast address timed out.

I've merged this to master now which means it will be in the latest beta in 15-30 minutes and released in v1.61

[disconnect5852]

Thanks, since few days i use it, no problem so far.