TORC: DEL_ONION got error: invalid arguments: unexpected code

[benthecarman]

Noticied in my lightning node's logs this:

TORC: sendCommand:DEL_ONION got err:unexpected code, reply:Bad arguments to DEL_ONION: Need at least 1 argument(s)
TORC: DEL_ONION got error: invalid arguments: unexpected code

Seems like something is failing on the tor shutdown, this is on v0.14.3

my lnd tor settings

--tor.active
--tor.socks=...
--tor.control=...
--tor.v3
--tor.skip-proxy-for-clearnet-targets

[yyforyongyu]

Saw these errors from #6148 too, which was caused by a power outage.

Can you share more relevant logs? I'm looking for keywords like serviceID, added to tor controller, removing serviceID:, or any logs from TORC.

[leemr]

I got this error on a reboot, basically same as a power fail since services are terminated. Seems like much hasn't changed since https://github.com/etcd-io/etcd/issues/10466#issuecomment-468566327

I now have it running, but I think it was an old/stale state so I restarted lnd.service with lnd.conf as below. After the restart, comment out the reset-wallet-transactions and once the reset is complete (many hours) it will auto restart w/o the reset (you don't want to keep looping).

...
[Application Options]
reset-wallet-transactions=true
...

First, systemctl stop lnd.service or else it'll try starting every minute. As ~bitcoin go install go.etcd.io/bbolt/cmd/bbolt@latest and go env said GOBIN wasn't set so cd go/bin. I found all the *.db, for me it was channel.db that was corrupt.

bitcoin@raspberrypi:~/go/bin $ ./bbolt check /mnt/hdd/lnd/data/graph/mainnet/channel.db  
page 131358: unreachable unfreed
page 131359: unreachable unfreed
page 131360: unreachable unfreed
3 errors found
invalid value

So I compacted and replaced channel.db.

bitcoin@raspberrypi:~/go/bin $ ./bbolt compact -o a.db /mnt/hdd/lnd/data/graph/mainnet/channel.db  
914604032 -> 779902976 bytes (gain=1.17x)

systemctl start lnd.service now properly starts. As I mentioned, think/know it's old state so am rescanning.

Did not try starting w/o channel.db and did not investigate the key/value pairs to see what was missing, I hope rescan picks it all up. I was using reboot since the magic command restart was hanging.

[guggero]

You should use the lnd internal compaction (db.bolt.auto-compact=true) for compaction. If you don't get any errors on compacting the channel.db, you are lucky and can continue using it.

BTW, the reset-wallet-transactions only affects the wallet.db file, which is very easily re-created from the seed. So the file to be very careful with is the channel.db as that contains your channel state.

[leemr]

Thanks for the info, still trying to sort out all the pieces. Maybe lnd could check the dbs before start (yes, it can take a few seconds depending on size) and if there is corruption, then alert the user or try to compact the corrupt db (which worked for me). lnd starting w/ a corrupt db (in this case) meant it exited w/ error code 2...every minute. Maybe one of the channel pages was a tor connection and thus throwing the tor error, but everything else running behind tor had no problems so it was a misleading error.

[Crypt-iQ]

This occurs because torController.Start() is called in lnd.go before being passed into newServer. At this point, the activeServiceID isn't set. If an error happens during startup before createNewHiddenService is called (which calls AddOnion and sets activeServiceID), then torController.Stop is called. This calls DelOnion with an activeServiceID of "". So the fix here is to not call DelOnion if there's an empty activeServiceID

[walmer-bolfet]

I found this issue searching after I selected the option on my raspiblitz to compact my database and the log displayed these error messages:

` [ERR] TORC: DEL_ONION got error: invalid arguments: unexpected code

[ERR] LTND: error stopping tor controller: invalid arguments: unexpected code `

The node then completed shutdown, initiated and completed compacting process and returned to operations.

Perhaps is will learn what ‘invalid arguments: unexpected code’ remedy I might apply, but in the mean time, my nodes seems to be operating nominally.

[guggero]

See the comment above. This happens when lnd shuts down after not having been fully started. Which might have happened during the compaction.

[walmer-bolfet]

Thank you guggero. Looking above, it is not clear to me. Am I correct to believe that there is no issue with my node, as I am able to compact my channel.db and restart, even though these error statements appear in my log? And no action to remedy is necessary?

[saubyk]

Closing this issue as missing reproduction and no activity for a while