Metabase: Metabase 0.32.5 - unexpected end of stream, read 0 bytes from 7

[vbezl]

• Your operating system: Ubuntu 18.04
• Your databases: Postgres for metabase and mostly mysql-s for queries
• Metabase version: 0.32.5
• Metabase hosting environment: Hetzner cloud server (Ubuntu 18.04)
• Metabase internal database: Postgres

After upgrading to 0.32.5 - the following error rises from time to time on absolutely different queries:
"unexpected end of stream, read 0 bytes from 7"

Here's info from metabase.log:

05-04 09:06:23 ESC[1mDEBUG middleware.logESC[0m :: ESC[32mGET /api/card/96 200 14 ms (6 DB calls) Jetty threads: 8/50 (3 busy, 4 idle, 0 queued) (57 total active threads)ESC[0m
05-04 09:06:23 ESC[1mDEBUG middleware.logESC[0m :: ESC[32mGET /api/alert/question/96 200 3 ms (1 DB calls) Jetty threads: 8/50 (3 busy, 4 idle, 0 queued) (57 total active threads)ESC[0m
05-04 09:06:23 ESC[1mDEBUG async.semaphore-channelESC[0m :: Permit available without waiting, will run fn immediately
05-04 09:06:23 ESC[1mDEBUG async.utilESC[0m :: Running metabase.query_processor.middleware.async$async__GT_sync$fn__33067@2abb8456 on separate thread...
05-04 09:06:23 ESC[1mDEBUG async.api-responseESC[0m :: ESC[32mstarting streaming responseESC[0m
SQLNonTransientConnectionException:
Message: (conn=39249477) unexpected end of stream, read 0 bytes from 7 (socket was closed by server)
SQLState: 08
Error Code: 0
05-04 09:06:23 ESC[1mERROR sql-jdbc.executeESC[0m :: nil
05-04 09:06:23 ESC[1mWARN middleware.process-userland-queryESC[0m :: Query failure ESC[31m{:status :failed,
:class java.lang.Exception,
:error "(conn=39249477) unexpected end of stream, read 0 bytes from 7 (socket was closed by server)",
:stacktrace
("--> driver.sql_jdbc.execute$do_with_try_catch.invokeStatic(execute.clj:222)"
"driver.sql_jdbc.execute$do_with_try_catch.invoke(execute.clj:213)"
"driver.sql_jdbc.execute$execute_query.invokeStatic(execute.clj:283)"
"driver.sql_jdbc.execute$execute_query.invoke(execute.clj:277)"
"driver.sql_jdbc$fn__63131.invokeStatic(sql_jdbc.clj:48)"
"driver.sql_jdbc$fn__63131.invoke(sql_jdbc.clj:47)"
"query_processor$fn__40730$execute_query__40735$fn__40736.invoke(query_processor.clj:61)"
"query_processor$fn__40730$execute_query__40735.invoke(query_processor.clj:55)"
"query_processor.middleware.mbql_to_native$mbql__GT_native$fn__35010.invoke(mbql_to_native.clj:36)"
"query_processor.middleware.annotate$result_rows_maps__GT_vectors$fn__32612.invoke(annotate.clj:368)"
"query_processor.middleware.annotate$add_column_info$fn__32517.invoke(annotate.clj:303)"
"query_processor.middleware.cumulative_aggregations$handle_cumulative_aggregations$fn__34490.invoke(cumulative_aggregations.clj:57)"
"query_processor.middleware.limit$limit$fn__34983.invoke(limit.clj:19)"
"query_processor.middleware.results_metadata$record_and_return_metadata_BANG_$fn__40595.invoke(results_metadata.clj:86)"
"query_processor.middleware.format_rows$format_rows$fn__34971.invoke(format_rows.clj:26)"
"query_processor.middleware.add_dimension_projections$add_remapping$fn__31669.invoke(add_dimension_projections.clj:234)"
"query_processor.middleware.add_row_count_and_status$add_row_count_and_status$fn__32063.invoke(add_row_count_and_status.clj:16)"
"query_processor.middleware.driver_specific$process_query_in_context$fn__34732.invoke(driver_specific.clj:12)"
"query_processor.middleware.resolve_driver$resolve_driver$fn__37561.invoke(resolve_driver.clj:15)"
"query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__33903$fn__33904.invoke(bind_effective_timezone.clj:9)"
"util.date$call_with_effective_timezone.invokeStatic(date.clj:88)"
"util.date$call_with_effective_timezone.invoke(date.clj:77)"
"query_processor.middleware.bind_effective_timezone$bind_effective_timezone$fn__33903.invoke(bind_effective_timezone.clj:8)"
"query_processor.middleware.store$initialize_store$fn__40620$fn__40621.invoke(store.clj:11)"
"query_processor.store$do_with_new_store.invokeStatic(store.clj:35)"
"query_processor.store$do_with_new_store.invoke(store.clj:31)"
"query_processor.middleware.store$initialize_store$fn__40620.invoke(store.clj:10)"
"query_processor.middleware.async$async__GT_sync$fn__33067.invoke(async.clj:19)"
"async.util$fn__32906$do_on_separate_thread_STAR___32911$fn__32912$fn__32913.invoke(util.clj:71)"),
:query
{:constraints {:max-results 10000, :max-results-bare-rows 2000},
:type :native,
:middleware {:userland-query? true},
:native
{:query
"SELECT DATE(odate) as date, count(*) as cnf_orders\n FROM rent_orders o\n inner join rent_apartments a on o.aid_reserved = a.id\n inner join rent_clients c on o.clientid = c.id\n where o.confirmed=1 and date(o.odate)>=date_sub(curdate(), interval 30 day) and date(o.odate)oid>0 and c.fname != 'Renovation'\n group by DATE(odate)\n order by DATE(odate) desc",
:collection "qo_groups"},
:info
{:executed-by 1,
:context :question,
:card-id 96,
:dashboard-id nil,
:query-hash [6, 20, -33, 3, 46, 65, 58, -73, 0, 45, 44, -36, 25, -85, -124, 119, -117, -94, -67, 88, 91, 86, -63, 88, -103, 118, 35, -81, -108, 60, 43, 42]},
:parameters [],
:async? true,
:cache-ttl nil}}
ESC[0m
05-04 09:06:23 ESC[1mDEBUG async.api-responseESC[0m :: ESC[34mAsync response finished, closing channels.ESC[0m
05-04 09:06:23 ESC[1mDEBUG middleware.logESC[0m :: ESC[32mPOST /api/card/96/query 200 [ASYNC: completed] 179 ms (9 DB calls) Jetty threads: 8/50 (2 busy, 5 idle, 0 queued) (57 total active threads)ESC[0m
05-04 09:06:23 ESC[1mWARN middleware.asyncESC[0m :: Unhandled exception, exepected catch-exceptions middleware to handle it.
java.lang.Exception: Invalid response from database driver. No :status provided.true
at metabase.query_processor.middleware.process_userland_query$format_userland_query_result.invokeStatic(process_userland_query.clj:97)
at metabase.query_processor.middleware.process_userland_query$format_userland_query_result.invoke(process_userland_query.clj:87)
at clojure.core$partial$fn__5828.invoke(core.clj:2638)
at metabase.query_processor.middleware.async_wait$wait_for_permit$fn__33563$fn__33602$state_machine__8574__auto____33623$fn__33625.invoke(async_wait.clj:49)
at metabase.query_processor.middleware.async_wait$wait_for_permit$fn__33563$fn__33602$state_machine__8574__auto____33623.invoke(async_wait.clj:49)
at clojure.core.async.impl.ioc_macros$run_state_machine.invokeStatic(ioc_macros.clj:973)
at clojure.core.async.impl.ioc_macros$run_state_machine.invoke(ioc_macros.clj:972)
at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invokeStatic(ioc_macros.clj:977)
at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invoke(ioc_macros.clj:975)
at clojure.core.async.impl.ioc_macros$take_BANG_$fn__8592.invoke(ioc_macros.clj:986)
at clojure.core.async.impl.channels.ManyToManyChannel$fn__3478$fn__3479.invoke(channels.clj:95)
at clojure.lang.AFn.run(AFn.java:22)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
(END)

[flamber]

Hi @vbezl
Which versions of MySQL? Are you using ProxySQL? Since the error says "socket was closed by server", you should check the log of the MySQL server - maybe there's more details.

[vbezl]

Hi @flamber,
Thanks for your answer and question!

Remote MySQL version which we are querying is:

Server version: 5.6.31-77.0 - MySQL Community Server (GPL)

Protocol version: 10

It was the same before (we haven't changed it).
Can this be a problem of connecting to local Metabase Postgres database or you're sure this log means that the issue is with connection to remote database?
We haven't changed anything on remote side, however we completely upgraded Metabase server and reinstalled it from the scratch (then imported the previously backed up Metabase postgres database). Maybe we are missing some configurations on the local metabase side? Maybe some mysql client config or postgres config?

Thanks a lot for your answer!

[flamber]

When the log says the server closed the connection, then maybe there's something in the remote log.
Which version of Metabase were you using before the complete upgrade?
Metabase changed drivers in version 0.32, so it's now using MariaDB Connector/J as the driver for MySQL, which has fixed some issues, but caused a couple of other issues.

[vbezl]

We were using Metabase 0.31.2.
I think the reason for this issue is the change of drivers in 0.32, because we haven't changed anything else except Metabase version and Metabase server (we moved to cloud).
I'll probably downgrade to 0.31 and check if the issue still persists.

[flamber]

Might be related to #9548, so it might be an issue with compatibility with MySQL 5.6
If you can see what the error log in MySQL says, then it would probably help.

[vbezl]

@flamber I've just downgraded to 0.31.2 and it works like a charm :)
So, the issue is definitely with something in 0.32 - mostly possible compatibility with MySQL 5.6 (and we have exactly MySQL 5.6 on the query side).
Unfortunately it's almost impossible for me to get mysql error logs from that server. Sorry about that! I'd really like to help solving that issue! :(

[camsaul]

Hey, unfortunately we only officially support MySQL 5.7+. We switched to using the MariaDB JDBC driver in 0.32 which would be why things might have worked in the past but don’t work any longer.

[tuaris]

MariaDB 10.x should be supported in addition to MySQL 5.7+ correct?

[flamber]

@tuaris
I'm using MariaDB 10.3 without issues - I haven't tested 0.32.x with earlier 10.x, but it should work.
MySQL 5.7+ should be working too on 0.32.x - if not, then look at the log.

[brivazac]

Hello,
I have the same issue since i updgrade to 0.32.
At this moment, my MYSQL version was 5.7.
Some weeks later i have updated my database to MYSQL 8. And it is still the same.

So the issue opened is not relative to 5.6.

Exact message is:
(conn=11938) unexpected end of stream, read 0 bytes from 7 (socket was closed by server)

But if i click on REFRESH button, it works. Problem happen only the 1st time. It's not ok for me because i use Notififications, and as the request fail, i don't receive the result.

[flamber]

@brivazac You might be also experiencing issue #9989, since it only happens first time.

[tuaris]

If I understand this issue correctly, this is the MariaDB server dropping the connection due to inactivity? Metabase doesn't detect the closed connection and fails to gracefully re-connect?

If so, then the workaround would be to decrease the wait_timeout value in the JDBC connection string options? Or would increasing make more sense?

[tuaris]

Sorry to continue pinging on this issue. I'm currently on 10.1. @flamber If I upgrade to MariaDB 10.3, this problem should go away?

[flamber]

@tuaris I'm not seeing this issue on 10.3 with 0.32.9, so either it's fixed with 10.3 or it's something to do with specific MariaDB configuration (I have only changed charset on my configuration).

[cloverzrg]

set connect string :

usePipelineAuth=false

[dvdhoek]

Same issue, same version.

[lequi]

Same issue

[tuaris]

Using usePipelineAuth=false did not solve the problem. I upgraded to MariaDB 10.2, still not solved.

[dvdhoek]

Any advice for a fix? I tried downgrading but I can't seem to connect the existing database to older versions.

I'm on MariaDB 10.3.16

[araratmartirossyan]

Same issue

[tuaris]

I upgraded to 10.3.18-MariaDB-1:10.3.18 and the issue continues.

[w92]

Hello @flamber @salsakran or anyone else who can help it looks like there are issues still often with Metabase or the MySQL connector that cause query to crash/not display!

Please help fix this issue, it is a big issue if suddenly the charts stop working and clients say the "software is broken" and need to reload and hope it works. That's a kind of show stopper and should be fixed.

We are using MySQl 5.7 with these settings:

SHOW VARIABLES LIKE "%timeout%" ;
connect_timeout | 10
-- | --
delayed_insert_timeout | 300
have_statement_timeout | YES
innodb_flush_log_at_timeout | 1
innodb_lock_wait_timeout | 50
innodb_rollback_on_timeout | OFF
interactive_timeout | 28800
lock_wait_timeout | 31536000
net_read_timeout | 30
net_write_timeout | 60
rpl_stop_slave_timeout | 31536000
slave_net_timeout | 60
wait_timeout | 300

And we observed after some time (20minutes or maybe 3hours, not sure) dashboard won't load anymore, produce an error " java.sql.SQLNonTransientConnectionException,
:error "unexpected end of stream, read 0 bytes from 4 (socket was closed by server)",
:cause {:class java.io.EOFException, :error "unexpected end of stream, read 0 bytes from 4 (socket was closed by server)"}}}" according to metabase.log 0.33.6.

Logfile entry:

{:query
"SELECT count(*) AS count FROM bi_events LEFT JOIN client client__via__client_code ON bi_events.client_code = client__via__client_code.code WHERE (date(bi_events.happened_at) BETWEEN date(date_add(now(), INTERVAL -30 day)) AND date(now()) AND client__via__client_code.code = ?)",
:params ("BRZ")},
:cause
{:class java.sql.SQLNonTransientConnectionException,
:error "unexpected end of stream, read 0 bytes from 4 (socket was closed by server)",
:cause {:class java.io.EOFException, :error "unexpected end of stream, read 0 bytes from 4 (socket was closed by server)"}}}
^[[0m
2019-12-10 11:06:17,611 [async-dispatch-7] DEBUGmetabase.middleware.log - ^[[32mGET /api/embed/dashboard/eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJyZXNvdXJjZSI6eyJkYXNoYm9hcmQiOjV9LCJwYXJhbXMiOnsiY2xpZW50X2NvZGUiOiJCUloifX0.ET-TmaB7Z-icCElBk5ZhRNvpgEib0Z_m4mhDy5FinaU/dashcard/7/card/7 200 [ASYNC: completed] 280.7 ms (42 DB calls) Jetty threads: 4/50 (2 idle, 0 queued) (74 total active threads) Queries in flight: 2^[[0m
2019-12-10 11:06:29,897 [qp-database-2-threadpool-11] INFO metabase.query-processor.middleware.cache - Query took 12581 ms to run; miminum for cache eligibility is 1000 ms

[tuaris]

I'm currently running Metabase 0.33.4 and have not seen this issue popup since updating.
I haven't tested it with 0.33.5/6

[w92]

@tuaris : for security and performance reasons we run latest version, can you please try to see if the issue persist with the latest version?

with mysql/mariadb with what connections string settings do you use, maybe something different than us?

[flamber]

I thought this problem might have been fixed by PR #11018 (0.33.4). The MariaDB Connector/J was upgraded in PR #11286 (0.33.5.1), to support MySQL 8 better. Besides that, there hasn't been any major connection changes on 0.33.x (from what I can remember).

Can anyone who has problems with this please give feedback, since I'm not able to reproduce:

1. Version of Metabase? (preferably "Diagnostic Info" from Admin > Troubleshooting)
2. Version of MySQL/MariaDB? Output from Metabase Native query:
   SELECT @@version;
3. Output from Metabase Native query:
   SHOW VARIABLES LIKE "%timeout%";
4. Are you using any Connection String parameters (Admin > Databases > mysql/mariadb)?
5. How is your MySQL/MariaDB connected to Metabase? localhost, local network, SSH tunnel, ...? Are you using TLS or other connection encryption?

[w92]

@flamber thanks for looking into this issue since it's been a kind of annoying showstopper and makes the otherwise great metabase software look bad 👍
We hope that using the information above you can reproduce the issue e.g. setup a similar test environment to debug the issues

Version of Metabase? (preferably "Diagnostic Info" from Admin > Troubleshooting)

0.33.6

Version of MySQL/MariaDB? Output from Metabase Native query:
SELECT @@version;

5.7.28-1

Output from Metabase Native query:
SHOW VARIABLES LIKE "%timeout%";

connect_timeout | 10
-- | --
delayed_insert_timeout | 300
have_statement_timeout | YES
innodb_flush_log_at_timeout | 1
innodb_lock_wait_timeout | 50
innodb_rollback_on_timeout | OFF
interactive_timeout | 28800
lock_wait_timeout | 31536000
net_read_timeout | 30
net_write_timeout | 60
rpl_stop_slave_timeout | 31536000
slave_net_timeout | 60
wait_timeout | 300

Are you using any Connection String parameters (Admin > Databases > mysql/mariadb)?

sessionVariables=wait_timeout=14400&collation=utf8mb4_unicode_ci

How is your MySQL/MariaDB connected to Metabase? localhost, local network, SSH tunnel, ...? Are you using TLS or other connection encryption?

Right now using a SSH tunnel, we tried without the SSH tunnel (Directly to the database on localhost) but it behaved very similar, sometimes the mentioned errors when trying to open charts. About encryption I'm not sure, we didn't activate anything special maybe it's ony by default.

[flamber]

@w92
Okay, something is not working correctly, since wait_timeout=300 even though you're setting it through the Connection String to 14400.

Right now using a SSH tunnel, we tried without the SSH tunnel (Directly to the database on localhost) but it behaved very similar, sometimes the mentioned errors when trying to open charts.

I don't understand this. Why are you using SSH tunnel, if the database is already running on the same machine as Metabase (localhost)? I have a feeling that your network (that includes SSH tunnels) is causing this problem.

[tuaris]

@w92 I updated to 0.33.6 about 20 hours ago and so far the issue hasn't shown up.

[w92]

@flamber sorry I executed the show variables statement in the wrong window, here is the output when I execute it in Metabase, we can see the wait_timeout is correctly set!

we have the SSH tunel to localhost since it seemed a bit more stable with the tunnel, even with a disabled tunnel the end of stream error is also there, so disabling it doesn't solve the issue!

have you been able to locally or on a testserver debug the issue / reproduce the error? this could help to investigate

"delayed_insert_timeout
300
have_statement_timeout
YES
innodb_flush_log_at_timeout
1
innodb_lock_wait_timeout
50
innodb_rollback_on_timeout
OFF
interactive_timeout
28800
lock_wait_timeout
31536000
net_read_timeout
30
net_write_timeout
60
rpl_stop_slave_timeout
31536000
slave_net_timeout
60
wait_timeout
14400"

@tuaris : try to not open some questions for about 1hour and later open them again, that's usually when the unexpected end of stream error shows up.
if you open them often the error will be once and later not (caching i guess)

[flamber]

@w92
I have not been able to reproduce this issue, which is why I have been asking for more information from anyone experiencing this issue.

It's the first time I've heard that adding more wrapping to a connection (like SSH tunnel) made it more stable - specially when the database is running on the same machine as Metabase.

I would recommend you head over to the forum - https://discourse.metabase.com/ - which is a better place for troubleshooting. And post a lot more details, like "Diagnostic Info" from Admin > Troubleshooting, and cat /etc/os-release and your MySQL configuration. And maybe a little map of your network topology.

[w92]

thanks @flamber i created a discussion here: https://discourse.metabase.com/t/after-opening-questions-dashboards-that-idled-for-some-hours-we-get-errors-e-g-unexpected-end-of-stream-read-0-bytes-from-7/8326

maybe someone else can let you look into a testsystem? we have customer data there so can't let someone on, maybe other can help.

@tuaris @myfailemtions @lequi @dvdhoek @brivazac @vbezl : can one of the many guys having the same issue please let flambers or someone else look into a system that shows the error so the devs can finally debug this issue? we can't do that ourselves since we have sensitive data

[w92]

Is anyone else still having this issue with recent metabase versions?
I saw above many people reported this issue of questions erroring out after idling for some time, can someone tell us if it's happening still?

[w92]

@flamber
i noticed before commit https://github.com/metabase/metabase/commit/3395f0b21b22e63c563e8b1f85446a396886efc9#diff-00e1629831a2a6dd5283b787cbcae0b6L44

it said: "(defn mysql..." and there ":subname (make-subname host port db extra-connection-params)" after this comit the text "extra-connection-params" is gone, could this mean it's an bug that the extra-connection-params e.g. wait_time increase are not passed or did this code move somewhere else?

now it says. ":subname (make-subname host port db)}", why was the "extra-connection-params" removed? @camsaul maybe knows?

i tested it (e.g. ran "SHOW VARIABLES LIKE "%timeout%" ;" as sql question) and it looks it worked, the wait_timeout value was like i set it in the extra connection params in the metabase db settings

[flamber]

@w92 I don't understand what the question is, since you already know that the Connection String is applied to the connection as you noted in https://github.com/metabase/metabase/issues/9885#issuecomment-564975864
Have you tried searching the internet for ideas? Like I said, perhaps you should try different wait_timeout values, together with other settings too:
https://stackoverflow.com/questions/18816974/migrating-from-mysql-mariadb-server-closing-client-connections-unexpectedly
https://stackoverflow.com/questions/25595809/database-sleeping-and-causing-exception

[w92]

@flamber We tried increasing the wait_timeout to many different values already, the question was is the connection extra params are passed and they are, so something else might cause the "unexpected out of stream" errors still.

[flamber]

@w92 I have asked for your MySQL configuration, since it might be something there.
Also, I have no idea how you're running Metabase, since you haven't posted "Diagnostic Info" from Admin > Troubleshooting. And I don't know which OS+version you're using.
The stackoverflow questions are talking about decreasing the value to 180 or even less, combined with other things, so please re-read those questions/comments.

[w92]

@flamber

os version: debian 9.11

diagnostic info:

{
“browser-info”: {
“language”: “de”,
“platform”: “Win32”,
“userAgent”: “Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:71.0) Gecko/20100101 Firefox/71.0”,
“vendor”: “”
},
“system-info”: {
“java.runtime.name”: “OpenJDK Runtime Environment”,
“java.runtime.version”: “1.8.0_232-8u232-b09-1~deb9u1-b09”,
“java.vendor”: “Oracle Corporation”,
“java.vendor.url”: “http://java.oracle.com/”,
“java.version”: “1.8.0_232”,
“java.vm.name”: “OpenJDK 64-Bit Server VM”,
“java.vm.version”: “25.232-b09”,
“os.name”: “Linux”,
“os.version”: “4.9.0-11-amd64”,
“user.language”: “en”,
“user.timezone”: “Europe/Berlin”
},
“metabase-info”: {
“databases”: [
“mysql”
],
“hosting-env”: “unknown”,
“application-database”: “mysql”,
“run-mode”: “prod”,
“version”: {
“tag”: “v0.33.6”,
“date”: “2019-11-19”,
“branch”: “release-0.33.x”,
“hash”: “be1e0e1”
},
“settings”: {
“report-timezone”: “Europe/Berlin”
}
}
}

[w92]

@flamber we found a possible issue:

I edited the file "metabase\metabase\src\metabase\driver\sql_jdbc\connection.clj" like this:

"maxIdleTime" 200
"minPoolSize" 1
"initialPoolSize" 1
"maxPoolSize" 15

, recompiled Metabase and using "show processlist " on mysql I noticed there was still a connection open that's longer than 200 seconds idle!

| Id | User | Host | db | Command | Time | State | Info
-- | -- | -- | -- | -- | -- | -- | -- | --
Beenden | 4837846 | user | 127.0.0.1:46786 | dbname | Sleep | 202 | | NULL

Can you please check if this params e.g. maxIdleTime are working correctly? If you enter e.g. 10 seconds it should not have any open connections on the db server side, right?

It seems this idle connection closing isn't working

[flamber]

@w92 That's two different things. Welcome to difficult parts of maintaining connections :wink:
Here's some references:
https://stackoverflow.com/questions/24565274/c3p0-maxidletime-is-same-as-wait-timeout-of-mysql
https://mariadb.com/kb/en/library/about-mariadb-connector-j/#pool-parameters
Also interesting, related issue #10063 and #8679
Try setting your Connection String to maxIdleTime=60&sessionVariables=wait_timeout=180 as noted in https://github.com/metabase/metabase/issues/10063#issuecomment-498435490

[w92]

@flamber @camsaul

finally we are able to get rid of the end of stream errors, the fix or probably more workaround is to set Dc3p0 parameters DIRECTLY when starting the metabase.jar e.g. like this:

java -Dc3p0.maxIdleTime=250 -Dc3p0.idleConnectionTestPeriod=250 metabase.jar

if we set this in the connection string it seems to have no effect, can you please check if the file resources/c3p0.properties or something else is overriding/blocking the c3p0 parameters when setting it in the connection string params?
i saw this file exists: https://github.com/metabase/metabase/blob/master/resources/c3p0.properties

i have the impression someething isn't passing the values e.g. maxIdleTime correctly if you set in in the metabase db settings connection string extra params!

it seems if i goe above 300 with this values the errors come back, so maybe it's connected to our wait_timeout of 300 somehow?

our hoster said they don't think firewalls are causing this issues.

[flamber]

@w92 Great you found a solution! :+1:

Which connection string did you try? maxIdleTime=250&idleConnectionTestPeriod=250

It will not be added to ./resources/c3p0.properties, because that means it cannot be overwritten.
I think it would go into the driver or perhaps the connection handler, but this needs to be tested a lot more to ensure there's no side-effects.

If you read the links I posted, it says that maxIdleTime has to be below wait_timeout, so that's why you're having problems at 300.

I don't see how firewall are related, since you said that both Metabase and MySQL are running on the same machine/container/localhost.

[w92]

@flamber

Happy new year, sorry I was on vacation during the last 2 week so could not reply earlier.

The issue of charts not loading after some times seems solved on our side, we just set wait_timeout to the MySQL default value.

It seems there is another issue, if you set values for the c3p0 e.g. maxIdleTime=250&idleConnectionTestPeriod=250 it is not respected, can you please try this to make sure Metabase works correctly?

Add the JDBC params in Metabase, e.g. "maxIdleTime=60&idleConnectionTestPeriod=60", run on MySQL "show processlist;" and you will see connections are idle and alive after 60 seconds, if you pass this params when starting metabase they will be reflected.

So like this it works: "java -Dc3p0.maxIdleTime=60 -Dc3p0.idleConnectionTestPeriod=60 metabase.jar".

[camsaul]

@w92 the reason maxIdleTime=60&idleConnectionTestPeriod=60 doesn't work is because those are properties that need to be passed to the c3p0 connection pool, not to the MySQL/MariaDB JDBC driver. When you include them in the JDBC connection string they are passed to the JDBC driver (and possibly to the server as well).

@flamber WRT

It will not be added to ./resources/c3p0.properties, because that means it cannot be overwritten.

I would happily add it to ./resources/c3p0.properties if it resolves issues people are facing. IIRC specifying the properties via the Java command line (e.g. -Dmy.property=value) would still override the ones from the config file.

FWIW I considered doing something similar in #11086. I didn't realize this issue was open, but it might be a good reason to merge that PR after all.

[camsaul]

I've been testing with MariaDB as part of fixing another bug and have managed to run into this

[w92]

thanks for your reply, we set the wait_timeout of our mysql server to the mysql default value and don't see any "unexpected end of stream" errors anymore currently, we consider the issue resolved by just using default vendor settings

[camsaul]

Fixed by #11086

[camsaul]

bumping to p2 since I've been able to repro accidentally when using MariaDB before fix