Unable to start loop in integrated mode: sql: Scan error on column index 20, name "publication_deadline"

[MButcho]

When I loop out, I get green confirmation windows, but nothing shows as initiated.

Expected behavior
I expect:

Actual behavior
No loop out is showing. I opened loop_sqlite.db and checked data:

To reproduce
Every time I loop out, I receive weird date in DB. LND and all is running well.

System information
I am using Lightning Terminal standalone with this in litd.conf:
lnd-mode=integrated
Running v0.10.4-alpha downloaded lightning-terminal-linux-amd64-v0.10.4-alpha.tar.gz from https://github.com/lightninglabs/lightning-terminal/releases/tag/v0.10.4-alpha
Running local node with Ubuntu 22.04 and SSD

When I restart a service with wrong date, this is the error in litd.log:
2023-08-05 12:07:26.324 [INF] LOOPD: Opening sqlite3 database at: /home/litd/.loop/mainnet/loop_sqlite.db
2023-08-05 12:07:26.445 [WRN] GRPC: [core] grpc: addrConn.createTransport failed to connect to {swap.lightning.today:11010 swap.lightning.today:11010 0 }. Err: connection error: desc = "transport: Error while dialing dial tcp: lookup swap.lightning.today: operation was canceled". Reconnecting...
2023-08-05 12:07:26.447 [ERR] LITD: Error starting Lightning Terminal: could not start subservers: unable to start loop in integrated mode: sql: Scan error on column index 20, name "publication_deadline": unsupported Scan, storing driver.Value type string into type *time.Time

[MButcho]

When I switched to lnd-mode=remote, I get Initiated transaction in loop out tab, the transaction goes through, but the sqlite db still showing invalid dates for the new transaction:

[gStart9]

We've had several users encounter the same (or very similar) error on Lit v0.10.2-alpha today:

2023-08-05T11:09:10-05:00   LND Node status online
2023-08-05T11:09:10-05:00   LND Alias XXXXXXXXXX
2023-08-05T11:09:10-05:00   LND Version 0.16.4-beta commit=v0.16.4-beta
2023-08-05T11:09:10-05:00   LiT Version 0.10.2-alpha commit=v0.10.2-alpha
2023-08-05T11:09:10-05:00   Web interface 127.0.0.1:8443, lightning-terminal.embassy:8443 (open https://127.0.0.1:8443 or http://lightning-terminal.embassy:8443 in your browser)
2023-08-05T11:09:10-05:00  ----------------------------------------------------------
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.232 [INF] LITD: Connecting basic lnd client
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.432 [INF] LITD: Connecting full lnd client
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.433 [INF] LNDC: Creating lnd connection to lnd.embassy:10009
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.433 [INF] LNDC: Connected to lnd
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.437 [INF] LNDC: Waiting for lnd to unlock
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.437 [INF] LNDC: Wallet state of lnd is now: Lnd main server is ready for requests
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.446 [INF] LNDC: lnd version: v0.16.4-beta, build tags 'autopilotrpc,signrpc,walletrpc,chainrpc,invoicesrpc,watchtowerrpc,neutrinorpc,monitoring,peersrpc,kvdb_postgres,kvdb_etcd,kvdb_sqlite'
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.446 [INF] LNDC: Using network mainnet
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.446 [INF] LNDC: Waiting for lnd to be fully synced to its chain backend, this might take a while
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.454 [INF] LNDC: lnd is now fully synced to its chain backend
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.598 [INF] LOOPD: Protocol version: MuSig2
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.598 [INF] LOOPD: Swap server address: swap.lightning.today:11010
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.598 [INF] LOOPD: Opening sqlite3 database at: /root/.loop/mainnet/loop_sqlite.db
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.696 [WRN] GRPC: [core] grpc: addrConn.createTransport failed to connect to {swap.lightning.today:11010 swap.lightning.today:11010 <nil> 0 <nil>}. Err: connection error: desc = "transport: authentication handshake failed: context canceled". Reconnecting...
2023-08-05T11:09:10-05:00  2023-08-05 16:09:10.696 [ERR] LITD: Error starting Lightning Terminal: could not start subservers: unable to start loop in integrated mode: sql: Scan error on column index 20, name "publication_deadline": unsupported Scan, storing driver.Value type string into type *time.Time
2023-08-05T11:09:10-05:00  could not start subservers: unable to start loop in integrated mode: sql: Scan error on column index 20, name "publication_deadline": unsupported Scan, storing driver.Value type string into type *time.Time

For at least this user, LiT will not start due to this error.

[ellemouton]

LiT will not start due to this error.

Just noting here that once #541 is in, then an error in one of the subservers wont prevent the rest of LiT from starting up 👍

[sputn1ck]

Thanks for reporting this.

Are the swaps created manually via terminal-web/lightning-terminal or via autoloop?

[MButcho]

Manually via terminal-web, I don't use autoloops :)

[sputn1ck]

Okay, I found the origin of the bug. We were using milliseconds instead of seconds as unix time, which is why those dates are super far in the future. Prior to sqlite we would be storing those milliseconds directly. With sqlite we switched over to timestamp strings, which is why this surfaced now.

We're currently discussing which parts to change. Fix will be out soon™