Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"Wrong host info" or "Can't reach database server at 127.0.0.1:3306" #846

Open
janpio opened this issue Aug 14, 2020 · 2 comments
Open

"Wrong host info" or "Can't reach database server at 127.0.0.1:3306" #846

janpio opened this issue Aug 14, 2020 · 2 comments

Comments

@janpio
Copy link
Contributor

janpio commented Aug 14, 2020

After @coleaeason fixed #818 they already posted, that our code was failing with Can't reach database server at 127.0.0.1:3306. I could confirm this now on our system:

2020-08-14T20:12:17.1756191Z Aug 14 20:12:11 fv-az30 provisioner[1513]:       E2E/Polling on next message
2020-08-14T20:12:17.1756941Z Aug 14 20:12:15 fv-az30 systemd[1]: Starting Generates prerequisite files for bedrock.service, if absent...
2020-08-14T20:12:17.1757587Z Aug 14 20:12:15 fv-az30 systemd[1]: Started Generates prerequisite files for bedrock.service, if absent.
2020-08-14T20:12:17.1758169Z Aug 14 20:12:15 fv-az30 systemd[1]: Starting Expensify Bedrock Server...
2020-08-14T20:12:17.1758707Z Aug 14 20:12:15 fv-az30 systemd[1]: Started Expensify Bedrock Server.
2020-08-14T20:12:17.1759328Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (main.cpp:314) main [main] [info] Starting bedrock server
2020-08-14T20:12:17.1760085Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1277) BedrockServer [main] [info] Loading plugins: CACHE, DB, JOBS, MYSQL
2020-08-14T20:12:17.1760820Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (Cache.cpp:95) initCacheSize [main] [info] No -cache.max specified, defaulting to 16GB
2020-08-14T20:12:17.1761581Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (Cache.cpp:99) initCacheSize [main] [info] Initializing cache with maximum size of 17179869184 bytes
2020-08-14T20:12:17.1762416Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1303) BedrockServer [main] [info] Creating BedrockServer with plugins: Cache, DB, Jobs, MySQL
2020-08-14T20:12:17.1763240Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1339) BedrockServer [main] [info] Opening control port on 'localhost:9999'
2020-08-14T20:12:17.1763988Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:1639) S_socket [main] [info] DNS lookup took 3ms for 'localhost'.
2020-08-14T20:12:17.1764688Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:1651) S_socket [main] [info] Resolved localhost to ip: 127.0.0.1.
2020-08-14T20:12:17.1765389Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1352) BedrockServer [main] [info] Launching sync thread 'sync'
2020-08-14T20:12:17.1766344Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:17.1767077Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:185) sync [sync] [info] Setting dbPool size to: 250
2020-08-14T20:12:17.1767838Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:71) SQLite [sync] [info] Opening sqlite database: /var/lib/bedrock/bedrock.db
2020-08-14T20:12:17.1768662Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:115) SQLite [sync] [info] {/var/lib/bedrock/bedrock.db} Opening database '/var/lib/bedrock/bedrock.db'.
2020-08-14T20:12:17.1769460Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:139) SQLite [sync] [info] {/var/lib/bedrock/bedrock.db} Using SQLite default PRAGMA synchronous
2020-08-14T20:12:17.1770162Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:152) SQLite [sync] [info] Setting cache_size to 1048576KB
2020-08-14T20:12:17.1770822Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:2508) SQVerifyTable [sync] [info] Creating 'journal'
2020-08-14T20:12:17.1771712Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:350) _sqliteWALCallback [sync] [info] [checkpoint] skipping checkpoint with 2 pages in WAL file (checkpoint every 2500 pages).
2020-08-14T20:12:17.1772378Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:160) SQLite [sync] [hmmm] Created journal table.
2020-08-14T20:12:17.1773062Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:2508) SQVerifyTable [sync] [info] Creating 'journal0000'
2020-08-14T20:12:17.1773957Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:350) _sqliteWALCallback [sync] [info] [checkpoint] skipping checkpoint with 4 pages in WAL file (checkpoint every 2500 pages).
2020-08-14T20:12:17.1774646Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:160) SQLite [sync] [hmmm] Created journal0000 table.
2020-08-14T20:12:17.1775332Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:2508) SQVerifyTable [sync] [info] Creating 'journal0001'
2020-08-14T20:12:17.1776204Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:350) _sqliteWALCallback [sync] [info] [checkpoint] skipping checkpoint with 6 pages in WAL file (checkpoint every 2500 pages).
2020-08-14T20:12:17.1776968Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:160) SQLite [sync] [hmmm] Created journal0001 table.
2020-08-14T20:12:17.1777641Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:2508) SQVerifyTable [sync] [info] Creating 'journal0002'
2020-08-14T20:12:17.1778507Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:350) _sqliteWALCallback [sync] [info] [checkpoint] skipping checkpoint with 8 pages in WAL file (checkpoint every 2500 pages).
2020-08-14T20:12:17.1779196Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:160) SQLite [sync] [hmmm] Created journal0002 table.
2020-08-14T20:12:17.1779882Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:1639) S_socket [sync] [info] DNS lookup took 0ms for '0.0.0.0'.
2020-08-14T20:12:17.1780570Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (libstuff.cpp:1651) S_socket [sync] [info] Resolved 0.0.0.0 to ip: 0.0.0.0.
2020-08-14T20:12:17.1781357Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:64) SQLiteNode [sync] [info] {bedrock/SEARCHING} [NOTIFY] setting commit count to: 0
2020-08-14T20:12:17.1782139Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:1943) _changeState [sync] [info] {bedrock/SEARCHING} [NOTIFY] setting commit count to: 0
2020-08-14T20:12:17.1782894Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:208) sync [sync] [info] Starting 2 worker threads.
2020-08-14T20:12:17.1783665Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:504) update [sync] [hmmm] {bedrock/SEARCHING} No peers configured, jumping to LEADING
2020-08-14T20:12:17.1784450Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:1943) _changeState [sync] [info] {bedrock/SEARCHING} [NOTIFY] setting commit count to: 0
2020-08-14T20:12:17.1785254Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:1970) _changeState [sync] [info] {bedrock/SEARCHING} Switching from 'SEARCHING' to 'LEADING'
2020-08-14T20:12:17.1786027Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:258) SQLite [blockingCommit] [info] Opening sqlite database: /var/lib/bedrock/bedrock.db
2020-08-14T20:12:17.1786876Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:264) SQLite [blockingCommit] [info] {/var/lib/bedrock/bedrock.db} Opening database '/var/lib/bedrock/bedrock.db'.
2020-08-14T20:12:17.1787761Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:544) verifyTable [sync] [info] Creating 'cache': CREATE TABLE cache ( name TEXT NOT NULL PRIMARY KEY, value BLOB NOT NULL )
2020-08-14T20:12:17.1788552Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:544) verifyTable [sync] [info] Creating 'cacheSize': CREATE TABLE cacheSize ( size INTEGER )
2020-08-14T20:12:17.1789380Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:285) SQLite [blockingCommit] [info] {/var/lib/bedrock/bedrock.db} Using SQLite default PRAGMA synchronous
2020-08-14T20:12:17.1790097Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:298) SQLite [blockingCommit] [info] Setting cache_size to 1048576KB
2020-08-14T20:12:17.1791752Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:544) verifyTable [sync] [info] Creating 'jobs': CREATE TABLE jobs ( created TIMESTAMP NOT NULL, jobID INTEGER NOT NULL PRIMARY KEY, state TEXT NOT NULL, name TEXT NOT NULL, nextRun TIMESTAMP NOT NULL, lastRun TIMESTAMP, repeat TEXT NOT NULL, data TEXT NOT NULL, priority INTEGER NOT NULL DEFAULT 500, parentJobID INTEGER NOT NULL DEFAULT 0, retryAfter TEXT NOT NULL DEFAULT "")
2020-08-14T20:12:17.1792558Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLitePool.cpp:49) get [blockingCommit] [info] Returning new DB handle: 1
2020-08-14T20:12:17.1793286Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:568) verifyIndex [sync] [info] Verifying index 'jobsName'. isUnique? 0
2020-08-14T20:12:17.1794324Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:578) verifyIndex [sync] [info] Creating index 'jobsName' on table 'jobs': ( name ). Executing 'CREATE INDEX jobsName ON jobs ( name )'.
2020-08-14T20:12:17.1795233Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:568) verifyIndex [sync] [info] Verifying index 'jobsParentJobIDState'. isUnique? 0
2020-08-14T20:12:17.1796670Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:578) verifyIndex [sync] [info] Creating index 'jobsParentJobIDState' on table 'jobs': ( parentJobID, state ) WHERE parentJobID != 0. Executing 'CREATE INDEX jobsParentJobIDState ON jobs ( parentJobID, state ) WHERE parentJobID != 0'.
2020-08-14T20:12:17.1797529Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:568) verifyIndex [sync] [info] Verifying index 'jobsStatePriorityNextRunName'. isUnique? 0
2020-08-14T20:12:17.1798711Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:578) verifyIndex [sync] [info] Creating index 'jobsStatePriorityNextRunName' on table 'jobs': ( state, priority, nextRun, name ). Executing 'CREATE INDEX jobsStatePriorityNextRunName ON jobs ( state, priority, nextRun, name )'.
2020-08-14T20:12:17.1799520Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:258) SQLite [worker1] [info] Opening sqlite database: /var/lib/bedrock/bedrock.db
2020-08-14T20:12:17.1800344Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:264) SQLite [worker1] [info] {/var/lib/bedrock/bedrock.db} Opening database '/var/lib/bedrock/bedrock.db'.
2020-08-14T20:12:17.1801122Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:2138) _upgradeDB [sync] [info] Finished running DB upgrade.
2020-08-14T20:12:17.1801952Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:285) SQLite [worker1] [info] {/var/lib/bedrock/bedrock.db} Using SQLite default PRAGMA synchronous
2020-08-14T20:12:17.1802649Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLite.cpp:298) SQLite [worker1] [info] Setting cache_size to 1048576KB
2020-08-14T20:12:17.1803312Z Aug 14 20:12:15 fv-az30 bedrock: xxxxxx (SQLitePool.cpp:49) get [worker1] [info] Returning new DB handle: 2
2020-08-14T20:12:17.1804131Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1479) postPoll [main] [info] Ready to process commands, opening command port on '0.0.0.0:8888'
2020-08-14T20:12:17.1804841Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (libstuff.cpp:1639) S_socket [main] [info] DNS lookup took 0ms for '0.0.0.0'.
2020-08-14T20:12:17.1805543Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (libstuff.cpp:1651) S_socket [main] [info] Resolved 0.0.0.0 to ip: 0.0.0.0.
2020-08-14T20:12:17.1806304Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1501) postPoll [main] [info] Opening port 'localhost:3306' for plugin 'MySQL'
2020-08-14T20:12:17.1807011Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (libstuff.cpp:1639) S_socket [main] [info] DNS lookup took 1ms for 'localhost'.
2020-08-14T20:12:17.1807730Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (libstuff.cpp:1651) S_socket [main] [info] Resolved localhost to ip: 127.0.0.1.
2020-08-14T20:12:17.1808668Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:17.1809469Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:1009) update [sync] [info] {bedrock/LEADING} [performance] Beginning QUORUM commit.
2020-08-14T20:12:17.1810441Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:1024) update [sync] [info] {bedrock/LEADING} beginning distributed transaction for commit #1 (8F2BB9DC0F94D8B688A6EF97DE9D9E8C7AE78572)
2020-08-14T20:12:17.1811778Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:1045) update [sync] [info] {bedrock/LEADING} [performance] SQLite::_sendToAllPeers in SQLiteNode took 0ms.
2020-08-14T20:12:17.1812696Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLite.cpp:350) _sqliteWALCallback [sync] [info] [checkpoint] skipping checkpoint with 17 pages in WAL file (checkpoint every 2500 pages).
2020-08-14T20:12:17.1813370Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLite.cpp:832) commit [sync] [info] SQuery 'COMMIT' took 1ms.
2020-08-14T20:12:17.1814123Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLite.cpp:845) commit [sync] [info] COMMIT operation wrote 9 pages. WAL file size is 70072 bytes.
2020-08-14T20:12:17.1815298Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:944) update [sync] [info] {bedrock/LEADING} SQLite::commit in SQLiteNode took 1ms.
2020-08-14T20:12:17.1816481Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:964) update [sync] [info] {bedrock/LEADING} Committed leader transaction for '1 (8F2BB9DC0F94D8B688A6EF97DE9D9E8C7AE78572).  (consistencyRequired=QUORUM), 0 of 0 approved (0 total) in 2 ms (0+0+0+0+1+0ms)
2020-08-14T20:12:17.1817475Z Aug 14 20:12:16 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:973) update [sync] [info] {bedrock/LEADING} [performance] Successfully committed QUORUM transaction. Sending COMMIT_TRANSACTION to peers.
2020-08-14T20:12:17.2252182Z mysqladmin: [Warning] Using a password on the command line interface can be insecure.
2020-08-14T20:12:17.4963920Z Wrong host info
2020-08-14T20:12:17.4970177Z 
2020-08-14T20:12:17.4970552Z finished prepare.sh
2020-08-14T20:12:17.4970707Z 
2020-08-14T20:12:17.4971583Z -----------------------------
2020-08-14T20:12:17.4971705Z 
2020-08-14T20:12:17.4971792Z 
2020-08-14T20:12:17.4972199Z -----------------------------
2020-08-14T20:12:17.4972445Z executing databases/bedrock/run.sh
2020-08-14T20:12:17.4988248Z + export 'DEBUG=*'
2020-08-14T20:12:17.4989826Z + DEBUG='*'
2020-08-14T20:12:17.4992300Z + export RUST_BACKTRACE=full
2020-08-14T20:12:17.4992902Z + RUST_BACKTRACE=full
2020-08-14T20:12:17.4993144Z + yarn install
2020-08-14T20:12:17.6777341Z yarn install v1.22.4
2020-08-14T20:12:17.6995905Z warning ../../package.json: No license field
2020-08-14T20:12:17.7281893Z [1/4] Resolving packages...
2020-08-14T20:12:17.7605363Z [2/4] Fetching packages...
2020-08-14T20:12:19.1233907Z [3/4] Linking dependencies...
2020-08-14T20:12:19.3330851Z [4/4] Building fresh packages...
2020-08-14T20:12:23.0262648Z Done in 5.35s.
2020-08-14T20:12:23.0432771Z + yarn prisma generate
2020-08-14T20:12:23.2217451Z yarn run v1.22.4
2020-08-14T20:12:23.2432698Z warning ../../package.json: No license field
2020-08-14T20:12:23.2577474Z $ /home/runner/work/e2e-tests/e2e-tests/databases/bedrock/node_modules/.bin/prisma generate
2020-08-14T20:12:23.7330289Z Environment variables loaded from prisma/.env
2020-08-14T20:12:25.0745126Z 
2020-08-14T20:12:25.0747105Z ✔ Generated Prisma Client to ./node_modules/@prisma/client in 119ms
2020-08-14T20:12:25.0747296Z 
2020-08-14T20:12:25.0747588Z You can now start using Prisma Client in your code:
2020-08-14T20:12:25.0747772Z 
2020-08-14T20:12:25.0747951Z ```
2020-08-14T20:12:25.0748420Z import { PrismaClient } from '@prisma/client'
2020-08-14T20:12:25.0748925Z // or const { PrismaClient } = require('@prisma/client')
2020-08-14T20:12:25.0749039Z 
2020-08-14T20:12:25.0749287Z const prisma = new PrismaClient()
2020-08-14T20:12:25.0749474Z ```
2020-08-14T20:12:25.0749579Z 
2020-08-14T20:12:25.0749864Z Explore the full API: http://pris.ly/d/client
2020-08-14T20:12:25.0978744Z Done in 1.88s.
2020-08-14T20:12:25.1013496Z + yarn prisma migrate save --create-db --experimental
2020-08-14T20:12:25.2814173Z yarn run v1.22.4
2020-08-14T20:12:25.3043111Z warning ../../package.json: No license field
2020-08-14T20:12:25.3197745Z $ /home/runner/work/e2e-tests/e2e-tests/databases/bedrock/node_modules/.bin/prisma migrate save --create-db --experimental
2020-08-14T20:12:25.7898697Z Environment variables loaded from prisma/.env
2020-08-14T20:12:26.8894970Z Error: Error: P1001: Can't reach database server at `127.0.0.1`:`3306`
2020-08-14T20:12:26.8895547Z 
2020-08-14T20:12:26.8895996Z Please make sure your database server is running at `127.0.0.1`:`3306`.
2020-08-14T20:12:26.8898035Z     at Object.ensureDatabaseExists (/home/runner/work/e2e-tests/e2e-tests/databases/bedrock/node_modules/@prisma/cli/build/index.js:2:2818789)
2020-08-14T20:12:26.8898630Z     at processTicksAndRejections (internal/process/task_queues.js:97:5)
2020-08-14T20:12:26.8899484Z     at async MigrateSave.parse (/home/runner/work/e2e-tests/e2e-tests/databases/bedrock/node_modules/@prisma/cli/build/index.js:2:2089873)
2020-08-14T20:12:26.8900640Z     at async main (/home/runner/work/e2e-tests/e2e-tests/databases/bedrock/node_modules/@prisma/cli/build/index.js:2:1561778)
2020-08-14T20:12:26.9076848Z error Command failed with exit code 1.

(from https://github.com/prisma/e2e-tests/pull/610/checks?check_run_id=986450520)

This is output from /var/log/syslog after running bedrock -fork to confirm Bedrock did indeed start properly.

Then the output Wrong host info is from mysqladmin -h 127.0.0.1 -u root -proot status which I tried to add to get the status of the MySQL server.

Finally "Error: Error: P1001: Can't reach database server at 127.0.0.1:3306" is from when our client in Rust tries to connect to the database.

Our script tries to run 3 times, so later I get more output from syslog about this connection attempty via mysqladmin and our client:

2020-08-14T20:12:43.3038224Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (main.cpp:295) main [main] [eror] Assertion failed: (SFileExists(args["-db"])) != true
2020-08-14T20:12:43.3039122Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SLog.cpp:13) SLogStackTrace [main] [warn]
2020-08-14T20:12:43.3041191Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SLog.cpp:13) SLogStackTrace [main] [warn] SLogStackTrace() [0x632e39]
2020-08-14T20:12:43.3041939Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SLog.cpp:13) SLogStackTrace [main] [warn] bedrock(main+0x13c3) [0x4a8e33]
2020-08-14T20:12:43.3042776Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SLog.cpp:13) SLogStackTrace [main] [warn] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0) [0x7fdf1ee6d840]
2020-08-14T20:12:43.3043593Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SLog.cpp:13) SLogStackTrace [main] [warn] bedrock(_start+0x29) [0x4ad479]
2020-08-14T20:12:43.3044386Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:163) _SSignal_StackTrace [main] [warn] Signal Aborted(6) caused crash, logging stack trace.
2020-08-14T20:12:43.3045025Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn]
2020-08-14T20:12:43.3045796Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] _SSignal_StackTrace(int, siginfo_t*, void*) [0x62db80]
2020-08-14T20:12:43.3046621Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] /lib/x86_64-linux-gnu/libpthread.so.0(+0x11390) [0x7fdf1fa3d390]
2020-08-14T20:12:43.3047446Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x38) [0x7fdf1ee82438]
2020-08-14T20:12:43.3048258Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] /lib/x86_64-linux-gnu/libc.so.6(abort+0x16a) [0x7fdf1ee8403a]
2020-08-14T20:12:43.3048992Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] bedrock(main+0x13c8) [0x4a8e38]
2020-08-14T20:12:43.3049834Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0) [0x7fdf1ee6d840]
2020-08-14T20:12:43.3050567Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:167) _SSignal_StackTrace [main] [warn] bedrock(_start+0x29) [0x4ad479]
2020-08-14T20:12:43.3051264Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:171) _SSignal_StackTrace [main] [warn] Calling DIE function.
2020-08-14T20:12:43.3052021Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (SSignal.cpp:174) _SSignal_StackTrace [main] [warn] DIE function returned, aborting (if not done).
2020-08-14T20:12:43.3052819Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 0 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3053630Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:2282) _acceptSockets [main] [info] Plugin 'MySQL' accepted a socket from '127.0.0.1:43902'
2020-08-14T20:12:43.3054393Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (MySQL.cpp:234) onPortAccept [main] [info] {MySQL} Accepted MySQL request from '127.0.0.1:43902'
2020-08-14T20:12:43.3055180Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 63 of 63 bytes.
2020-08-14T20:12:43.3056122Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3057060Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 64 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3057714Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (MySQL.cpp:332) onPortRecv [main] [info] {MySQL} Sending OK
2020-08-14T20:12:43.3058480Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 13 of 13 bytes.
2020-08-14T20:12:43.3059442Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3060251Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 5 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3060911Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (MySQL.cpp:332) onPortRecv [main] [info] {MySQL} Sending OK
2020-08-14T20:12:43.3061686Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 13 of 13 bytes.
2020-08-14T20:12:43.3062685Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3063525Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 5 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3064173Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (MySQL.cpp:332) onPortRecv [main] [info] {MySQL} Sending OK
2020-08-14T20:12:43.3064942Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 13 of 13 bytes.
2020-08-14T20:12:43.3065899Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3066710Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 0 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3067666Z Aug 14 20:12:17 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3068620Z Aug 14 20:12:18 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3069677Z Aug 14 20:12:25 fv-az30 bedrock: message repeated 7 times: [ xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.]
2020-08-14T20:12:43.3070501Z Aug 14 20:12:25 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:477) update [sync] [info] {bedrock/LEADING} [performance] Network stats: 10007 ms elapsed.
2020-08-14T20:12:43.3071291Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 0 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3072104Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:2282) _acceptSockets [main] [info] Plugin 'MySQL' accepted a socket from '127.0.0.1:43948'
2020-08-14T20:12:43.3072864Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (MySQL.cpp:234) onPortAccept [main] [info] {MySQL} Accepted MySQL request from '127.0.0.1:43948'
2020-08-14T20:12:43.3074114Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 63 of 63 bytes.
2020-08-14T20:12:43.3075076Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3076036Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (main.cpp:352) main [main] [info] [performance] main poll loop timing: 10521 ms elapsed. 10518 ms in poll. 2 ms in postPoll.
2020-08-14T20:12:43.3076854Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 92 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3077504Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (MySQL.cpp:332) onPortRecv [main] [info] {MySQL} Sending OK
2020-08-14T20:12:43.3078273Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 13 of 13 bytes.
2020-08-14T20:12:43.3079226Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3080035Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 20 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3080779Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (MySQL.cpp:261) onPortRecv [main] [info] {MySQL} Processing query 'SELECT @@socket;'
2020-08-14T20:12:43.3081675Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (MySQL.cpp:273) onPortRecv [main] [info] {MySQL} Returning variable 'socket'='/tmp/mysql.sock'
2020-08-14T20:12:43.3082425Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 103 of 103 bytes.
2020-08-14T20:12:43.3083526Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 489ms.
2020-08-14T20:12:43.3084328Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 5 bytes in the socket buffer before receiving.
2020-08-14T20:12:43.3085292Z Aug 14 20:12:26 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3086258Z Aug 14 20:12:27 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3087329Z Aug 14 20:12:35 fv-az30 bedrock: message repeated 8 times: [ xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.]
2020-08-14T20:12:43.3088155Z Aug 14 20:12:35 fv-az30 bedrock: xxxxxx (SQLiteNode.cpp:477) update [sync] [info] {bedrock/LEADING} [performance] Network stats: 10000 ms elapsed.
2020-08-14T20:12:43.3089095Z Aug 14 20:12:36 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3089977Z Aug 14 20:12:36 fv-az30 bedrock: xxxxxx (main.cpp:352) main [main] [info] [performance] main poll loop timing: 10493 ms elapsed. 10002 ms in poll. 490 ms in postPoll.
2020-08-14T20:12:43.3090922Z Aug 14 20:12:37 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3091898Z Aug 14 20:12:38 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3092837Z Aug 14 20:12:39 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
2020-08-14T20:12:43.3093955Z Aug 14 20:12:41 fv-az30 bedrock: message repeated 2 times: [ xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.]
2020-08-14T20:12:43.3094946Z Aug 14 20:12:42 fv-az30 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 0 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.

Any idea what is going on here?
@cannikin cannikin mentioned this issue Feb 12, 2021
Closed
@cannikin
Copy link

We'd love to make Bedrock a first-class citizen for Redwood but we're stuck on this weird error! Is there anything we can do to help debug?

@janpio
Copy link
Contributor Author

janpio commented May 1, 2021

Discovered -v and also have a more stable setup where I know it is reading our local SQLite database - but the MySQL connection still can not be established. Here are some logs:

May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (STCPServer.cpp:62) acceptSocket [main] [dbug] Accepting socket from '127.0.0.1:52440' on port 'localhost:3306'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 0 bytes in the socket buffer before receiving.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (BedrockServer.cpp:2282) _acceptSockets [main] [info] Plugin 'MySQL' accepted a socket from '127.0.0.1:52440'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (MySQL.cpp:234) onPortAccept [main] [info] {MySQL} Accepted MySQL request from '127.0.0.1:52440'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 63 of 63 bytes.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 92 bytes in the socket buffer before receiving.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (MySQL.cpp:244) onPortRecv [main] [dbug] {MySQL} Received command #1: '580000010902080000000001210000000000000000000000000000000000000000000000726F6F740061FFB6E5B83A44845B2D65DEF4B056C1D46AA20400626564726F636B006D7973716C5F6E61746976655F70617373776F726400'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (MySQL.cpp:332) onPortRecv [main] [info] {MySQL} Sending OK
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 13 of 13 bytes.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 20 bytes in the socket buffer before receiving.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (MySQL.cpp:244) onPortRecv [main] [dbug] {MySQL} Received command #0: '100000000353454C454354204040736F636B6574'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (MySQL.cpp:261) onPortRecv [main] [info] {MySQL} Processing query 'SELECT @@socket;'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (MySQL.cpp:273) onPortRecv [main] [info] {MySQL} Returning variable 'socket'='/tmp/mysql.sock'
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1941) S_sendconsume [main] [info] [performance] Send() took 0 ms and sent 103 of 103 bytes.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (libstuff.cpp:1887) S_recvappend [main] [info] [performance] 0 bytes in the socket buffer before receiving.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (STCPManager.cpp:141) postPoll [main] [dbug] Connection to '127.0.0.1:52440' died (recv=0, send=1)
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (BedrockServer.cpp:1699) postPoll [main] [info] [performance] Read from 1 sockets, attempted to deserialize 0 commands, 0 were complete and deserialized in 0ms.
May  1 00:20:19 fv-az185-372 bedrock: xxxxxx (STCPManager.cpp:213) closeSocket [main] [dbug] Closing socket '127.0.0.1:52440'

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@cannikin @janpio