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

[ISSUE]Facing lot of "use of closed network connection" error #698

Open
3 tasks done
devendermishra opened this issue Feb 9, 2024 · 2 comments
Open
3 tasks done

[ISSUE]Facing lot of "use of closed network connection" error #698

devendermishra opened this issue Feb 9, 2024 · 2 comments
Assignees
@Lagovas
Labels
question

Comments

@devendermishra
Copy link

devendermishra commented Feb 9, 2024 •
edited

Describe the bug
I have setup an acra-server on ec2 install on t3-micro instance. DB is on t4g medium instance (using aurora mysql). I have an existing PHP application which was connecting db directly. Now, it is connecting through acra. Now, I am getting logs of "use of closed network connection error"

time="2024-02-09T10:16:02Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.9.228:51494->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=372 time="2024-02-09T10:16:02Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=372 time="2024-02-09T10:16:02Z" level=info msg="Finished processing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=372 time="2024-02-09T10:16:02Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.9.228:51542->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=380 time="2024-02-09T10:16:02Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=380 time="2024-02-09T10:16:02Z" level=info msg="Finished processing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=380 time="2024-02-09T10:16:02Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.9.228:51478->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=370 time="2024-02-09T10:16:02Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=370 time="2024-02-09T10:16:02Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.9.228:51500->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=374 time="2024-02-09T10:16:02Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=374 time="2024-02-09T10:16:02Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.9.228:51518->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=376

To Reproduce
./acra-server -client_id ${ACRA_CLIENT_ID} -db_host <db_host> -db_port 3306 --incoming_connection_close_timeout=60 --http_api_enable=true -mysql_enable --v -keys_dir keystore/stashfin -encryptor_config_file encryptor_config.yml

Expected behavior
A clear and concise description of what you expected to happen.
Application should be able to work. When a database connection is closed, it should be closed.

Acra configuration files

Environment (please complete the following information):

  • Acra version: 0.95.0

  • Database server and its version: MySQL 8

  • Installed components:

    • AcraServer

  • Data-in-transit encryption between Acra and the client-side application:

    • no transport encryption

  • Installation way:

    • via package manager
@Zhaars
Copy link
Contributor

Zhaars commented Feb 12, 2024

Hello @devendermishra!

Thanks for reaching out!

Unfortunately, based on the information you provided, it's challenging to thoroughly analyze the issue. The problem seems to have multiple aspects, and it could potentially be on your end, possibly due to incorrect network settings.

To assist you more effectively, could you please provide additional details or steps to reproduce the problem? Additionally, providing a complete Acra log with details of the error you encountered, preferably using the -d flag, would be helpful.

@devendermishra
Copy link
Author

Thanks Zhaars for helping out.

Log after -d flag:

time="2024-02-13T03:29:08Z" level=debug msg="New packet" client_id=StashfinID deprecate_eof=false proxy=client sequence_number=0 session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="New packet" client_id=StashfinID deprecate_eof=false proxy=client sequence_number=0 session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="Can't read packet from server" client_id=StashfinID session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="Stop to proxy" client_id=StashfinID interrupt_side=Client-AcraServer session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="EOF connection closed" client_id=StashfinID interrupt_side=Client-AcraServer session_id=1582
time="2024-02-13T03:29:08Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=Client-AcraServer session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="Close acra-connector connection" client_id=StashfinID session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="Close db connection" client_id=StashfinID session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="All connections closed" client_id=StashfinID session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="Second proxy goroutine stopped" client_id=StashfinID error="AcraServer-Database:read tcp 172.31.12.255:54358->172.31.35.209:3306: use of closed network connection" interrupt_side=Client-AcraServer session_id=1582
time="2024-02-13T03:29:08Z" level=info msg="Finished processing client's connection" client_id=StashfinID interrupt_side=Client-AcraServer session_id=1582
time="2024-02-13T03:29:08Z" level=debug msg="Close connections on CommandQuit command" client_id=StashfinID deprecate_eof=false proxy=client sequence_number=0 session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="Can't read packet from server" client_id=StashfinID session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="Stop to proxy" client_id=StashfinID interrupt_side=AcraServer-Database session_id=1583
time="2024-02-13T03:29:08Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.12.255:54360->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=1583
time="2024-02-13T03:29:08Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="Close acra-connector connection" client_id=StashfinID session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="Close db connection" client_id=StashfinID session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="Close connections on CommandQuit command" client_id=StashfinID deprecate_eof=false proxy=client sequence_number=0 session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="Can't read packet from server" client_id=StashfinID session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="Stop to proxy" client_id=StashfinID interrupt_side=AcraServer-Database session_id=1584
time="2024-02-13T03:29:08Z" level=error msg="Network error" client_id=StashfinID code=1100 error="read tcp 172.31.12.255:54376->172.31.35.209:3306: use of closed network connection" interrupt_side=AcraServer-Database session_id=1584
time="2024-02-13T03:29:08Z" level=info msg="Closing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="Close acra-connector connection" client_id=StashfinID session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="Close db connection" client_id=StashfinID session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="All connections closed" client_id=StashfinID session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="Second proxy goroutine stopped" client_id=StashfinID error="Client-AcraServer:EOF" interrupt_side=AcraServer-Database session_id=1583
time="2024-02-13T03:29:08Z" level=info msg="Finished processing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=1583
time="2024-02-13T03:29:08Z" level=debug msg="All connections closed" client_id=StashfinID session_id=1584
time="2024-02-13T03:29:08Z" level=debug msg="Second proxy goroutine stopped" client_id=StashfinID error="Client-AcraServer:EOF" interrupt_side=AcraServer-Database session_id=1584
time="2024-02-13T03:29:08Z" level=info msg="Finished processing client's connection" client_id=StashfinID interrupt_side=AcraServer-Database session_id=1584

Main issue seems db connection leaks.

Infra details:
RDS: Aurora cluster (t4g.medium)
Acra server: 2 (one as reader and another one as writer) in t3.small and t2.small
OS: Ubuntu 20.04, acra installed using package manager in Ubuntu
Applications: 3 PHP applications (PHP 7.2 and CodeIgniter 3), 6 Python applications (using FastApi and Sqlalchemy 2), 4 golang applications.

Python and golang applications use connection pool. PHP applications does not use connection pool. They create connection for every query.

Screenshot from 2024-02-13 09-03-13
Acra was introduced around 15:00 hours. Till midnight, everything was fine. However, after midnight, there is spike in number of connections.

Acra server is running with following options:

-client_id ${ACRA_CLIENT_ID} -db_host $DB_HOST -db_port 3306 -d --incoming_connection_close_timeout=10 --http_api_enable=true -mysql_enable --v -keys_dir keystore/stashfin -encryptor_config_file encryptor_config.yml

To reproduce, you can write sample 2-3 PHP applications using codeigniter with DB configuration as follows:

$db['db_write']['hostname'] = '<acra_host>';
$db['db_write']['username'] = '<user>';
$db['db_write']['port'] = 9393;
$db['db_write']['password'] = 'password';
$db['db_write']['database'] = 'db_name';
$db['db_write']['dbdriver'] = 'mysqli';
$db['db_write']['dbprefix'] = '';
$db['db_write']['pconnect'] = false;
$db['db_write']['db_debug'] = true;
$db['db_write']['db_debug_exception'] = true;
$db['db_write']['cache_on'] = false;
$db['db_write']['cachedir'] = '';
$db['db_write']['char_set'] = 'utf8';
$db['db_write']['dbcollat'] = 'utf8_general_ci';
$db['db_write']['swap_pre'] = '';
$db['db_write']['autoinit'] = true;
$db['db_write']['stricton'] = false;

Sample query code:

$this->db->select("concat(first_name,' ',coalesce(middle_name,''),' ',coalesce(last_name,'')) as customer_name, 
                            email,phone,gender,dob,pan_number,
                            aadhar_number,
                            coalesce(ovd_id, '') as ovd_id,
                            IF(ovd_id IS NULL, 
                                aadhar_number,
                                IF(ovd_id = 1, ovd_number, ovd_number)
                            ) AS ovd_number,
                            coalesce(se.is_active,'0') as stashfin_employee");
        $this->db->from('customer_detail as cd');
        $this->db->join('employee as e', 'e.customer_id=cd.id', 'left');
        $this->db->where('cd.id', $customer_id);
        $data = $this->db->get()->row_array();
        ```
You can do many queries. Create load on these APIs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@Lagovas Lagovas

Labels
question
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@devendermishra @Lagovas @Zhaars