Hello,
I am getting tons of messages in syslog, syslog > 100Mo, most messages are like :
Nov 11 17:17:27 mail rabbitmq-server[621]: #033[38;5;160m2024-11-11 17:17:27.921843+01:00 [error] <0.460492.0> Error running Consul health check: "{failed_connect,[{to_address,{\"127.0.0.1\",8500}},{inet,[inet],econnrefused}]}"#033[0m
Nov 11 17:17:28 mail carbonio-prometheus-consul-exporter[625]: ts=2024-11-11T16:17:28.643Z caller=consul_exporter.go:370 level=error msg="Failed to query for services" err="Get \"http://localhost:8500/v1/catalog/services?stale=\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 11 17:17:28 mail carbonio-prometheus-consul-exporter[625]: ts=2024-11-11T16:17:28.646Z caller=consul_exporter.go:259 level=error msg="Can't query consul" err="Get \"http://localhost:8500/v1/status/peers\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 11 17:17:28 mail carbonio-prometheus-consul-exporter[625]: ts=2024-11-11T16:17:28.649Z caller=consul_exporter.go:271 level=error msg="Can't query consul" err="Get \"http://localhost:8500/v1/status/leader\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 11 17:17:28 mail carbonio-prometheus-consul-exporter[625]: ts=2024-11-11T16:17:28.652Z caller=consul_exporter.go:289 level=error msg="Failed to query catalog for nodes" err="Get \"http://localhost:8500/v1/catalog/nodes?stale=\": dial tcp 127.0.0.1:8500: connect: connection refused"
Nov 11 17:17:28 mail carbonio-prometheus-consul-exporter[625]: ts=2024-11-11T16:17:28.655Z caller=consul_exporter.go:301 level=error msg="Failed to query member info" err="Get \"http://localhost:8500/v1/agent/members\": dial tcp 127.0.0.1:8500: connect: connection refused"
No updates sera made except installation of new Letsencrypt SSL cert.
Regards
JP P
Hello,
I get other messages in mail.log :
Nov 12 18:10:51 mail postfix/postscreen[4398]: CONNECT from [127.0.0.1]:54306 to [127.0.0.1]:25
Nov 12 18:10:51 mail postfix/postscreen[4398]: ALLOWLISTED [127.0.0.1]:54306
Nov 12 18:10:51 mail postfix/smtpd[28727]: connect from localhost[127.0.0.1]:54306
Nov 12 18:10:51 mail postfix/smtpd[28727]: lost connection after CONNECT from localhost[127.0.0.1]:54306
Nov 12 18:10:51 mail postfix/smtpd[28727]: disconnect from localhost[127.0.0.1]:54306 commands=0/0
Every ten seconds the same message block .
In syslog :
Nov 12 18:13:27 mail service-discoverd[2622]: 2024-11-12T18:13:27.463+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=1cad39b1-9f75-b590-5080-664bae23190a from=127.0.0.1:40574 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
every second approx
Regards
JP P
Tha mail system is working and sends and receive mails ...
Nov 12 18:13:27 mail service-discoverd[2622]: 2024-11-12T18:13:27.463+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=1cad39b1-9f75-b590-5080-664bae23190a from=127.0.0.1:40574 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
this could help you:
Regards,
Sharif
Hello,
OK, token is invalid, but how to "make" a new token ?
Regards
JP P
I try (as root) :
carbonio-message-broker setup
I get now bunch of messages like :
Nov 14 14:59:45 mail service-discoverd[2622]: 2024-11-14T14:59:45.509+0100 [ERROR] agent.http: Request error: method=GET url=/v1/agent/self from=127.0.0.1:57478 error="Permission denied: token with AccessorID '51d6f289-7a3c-a682-ec76-93fac18dc8aa' lacks permission 'agent:read' on \"mail-jpp-fr\""
WIll try to reboot ... after reboot ...
From mail.log every 10 seconds :
Nov 14 15:38:39 mail postfix/postscreen[4070]: CONNECT from [127.0.0.1]:60292 to [127.0.0.1]:25
Nov 14 15:38:39 mail postfix/postscreen[4070]: ALLOWLISTED [127.0.0.1]:60292
Nov 14 15:38:39 mail postfix/smtpd[20592]: connect from localhost[127.0.0.1]:60292
Nov 14 15:38:39 mail postfix/smtpd[20592]: lost connection after CONNECT from localhost[127.0.0.1]:60292
Nov 14 15:38:39 mail postfix/smtpd[20592]: disconnect from localhost[127.0.0.1]:60292 commands=0/0
Nov 14 15:38:40 mail postfix/postscreen[4070]: CONNECT from [127.0.0.1]:60296 to [127.0.0.1]:25
Same log in carbonio.log
From syslog :
Every 5 seconds :
Nov 14 15:41:31 mail carbonio-preview-start.sh[1171]: "[2024-11-14 15:41:31,004] INFO [uvicorn.access.send:476] 127.0.0.1:38658 - "GET /health/ready/ HTTP/1.1" 200"
EVery 15 seconds :
Nov 14 15:43:00 mail prometheus[624]: ts=2024-11-14T14:43:00.536Z caller=consul.go:285 level=error component="discovery manager scrape" discovery=consul config=ldap msg="Error retrieving datacenter name" err="Unexpected response code: 403 (Permission denied: token with AccessorID '51d6f289-7a3c-a682-ec76-93fac18dc8aa' lacks permission 'agent:read' on \"mail-jpp-fr\")"
Regards
JP P
I have also a same problem, Thank you for sharing this information...
Hello,
No news since 3 weeks ? Is it normal ?
Regards
JPPO
It's a new year and I get always tons of log messages ...
Hello,
The core version is : 24.12.3.
The biggest part seems to be in "syslog", here are the 24 last lines :
---------------------------------------------------------------------------------
Jan 13 12:59:05 mail service-discoverd[2126]: 2025-01-13T12:59:05.459+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=6c3eb230-6567-408b-fa8c-23e9791b4a81 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:05 mail service-discoverd[2126]: 2025-01-13T12:59:05.719+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=2ecd73ca-6d67-39d6-1248-643e85e47c0a from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:05 mail service-discoverd[2126]: 2025-01-13T12:59:05.907+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=61bcc1c0-f499-ee60-09c1-cb5c2389135f from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:05 mail service-discoverd[2126]: 2025-01-13T12:59:05.986+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=b5f6e4d6-3c22-a515-d209-a58dacd36280 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:06 mail service-discoverd[2126]: 2025-01-13T12:59:06.103+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=691fdf01-50fc-cbed-0974-d39892f71f69 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:06 mail rabbitmq-server[632]: #033[38;5;160m2025-01-13 12:59:06.103695+01:00 [error] <0.763517.0> Internal error in Consul while updating health check. Cannot obtain list of nodes registered in Consul either: "Error while acquiring lock, reason: 403"#033[0m
Jan 13 12:59:06 mail service-discoverd[2126]: 2025-01-13T12:59:06.474+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=0f94ad91-b911-0fc3-b20e-8e1e40f663f5 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:06 mail carbonio-preview-start.sh[1209]: "[2025-01-13 12:59:06,540] INFO [uvicorn.access.send:476] 127.0.0.1:40298 - "GET /health/live/ HTTP/1.1" 200"
Jan 13 12:59:06 mail service-discoverd[2126]: 2025-01-13T12:59:06.728+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=88400bcf-1c54-91c8-8cce-9ed4041b181b from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:06 mail service-discoverd[2126]: 2025-01-13T12:59:06.915+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=fb151196-1ad9-325b-9d54-eb30d7223926 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:06 mail service-discoverd[2126]: 2025-01-13T12:59:06.994+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=61048c2a-122f-4aed-6cb5-a198ad3f99a7 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:07 mail service-discoverd[2126]: 2025-01-13T12:59:07.490+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=9a7e8cd0-c13d-1b14-c0fe-50da9c5b3fe8 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:07 mail service-discoverd[2126]: 2025-01-13T12:59:07.737+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=47c3eb43-2ae4-1b4b-a3be-81106f117af4 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:07 mail service-discoverd[2126]: 2025-01-13T12:59:07.924+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=053cac81-d324-e595-8df1-1b1b1ef18b59 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:08 mail service-discoverd[2126]: 2025-01-13T12:59:08.003+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=ed58a761-fa17-ca8d-472c-9d260ffdd324 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:08 mail service-discoverd[2126]: 2025-01-13T12:59:08.518+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=cb3556a6-cb1f-6efd-13c0-726c8e4a4a18 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:08 mail service-discoverd[2126]: 2025-01-13T12:59:08.746+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=9bbc8689-f22d-94d8-a31e-c58651e157d1 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:08 mail service-discoverd[2126]: 2025-01-13T12:59:08.941+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=2e521925-6237-1d91-7556-407428827176 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:09 mail service-discoverd[2126]: 2025-01-13T12:59:09.013+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=a6c9dccb-50aa-1edf-316c-b15d78453687 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:09 mail service-discoverd[2126]: 2025-01-13T12:59:09.542+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=304956fb-82ec-3ab5-c40e-06c1106712c9 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:09 mail service-discoverd[2126]: 2025-01-13T12:59:09.755+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=0955afb1-90b4-e6a9-5fa1-af92e0efb78b from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:09 mail service-discoverd[2126]: 2025-01-13T12:59:09.949+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=0ac24b88-3c74-5d46-2816-146c9dcc909e from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:10 mail service-discoverd[2126]: 2025-01-13T12:59:10.021+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=624e45cb-7ec5-e648-4953-6d2e998218e4 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
Jan 13 12:59:10 mail service-discoverd[2126]: 2025-01-13T12:59:10.550+0100 [ERROR] agent.http: Request error: method=PUT url=/v1/kv/rabbitmq/default/startup_lock?acquire=93a0bf01-6575-98a1-eabd-f22d31cd4071 from=127.0.0.1:50682 error="Permission denied: token with AccessorID 'b2855e10-0026-33f3-e8b0-906713faf4a3' lacks permission 'key:write' on \"rabbitmq/default/startup_lock\""
---------------------------------------------------------------------------------------------------------
That file is 81Mo since 13/01/2025 at 00:00.
Th file /opt/zextras/log/mailbox.log is full of suche groups od messages :
----------------------------------------------------------------------------------------------------------
2025-01-13 00:14:20,222 WARN [qtp1040093935-13066] [] extensions - unable to find handler for extension: system failure: Extension HTTP handler not found at /metrics/powerstore
2025-01-13 00:14:20,890 ERROR [pool-8457-thread-1] [] ServiceDiscoverHttpClient - Service discover didn't respond with 200 when requesting a config (received 403)
2025-01-13 00:14:20,890 ERROR [pool-8457-thread-1] [] ServiceDiscoverHttpClient - Service discover didn't respond with 200 when requesting a config (received 403)
2025-01-13 00:14:50,893 ERROR [pool-8460-thread-1] [] ServiceDiscoverHttpClient - Service discover didn't respond with 200 when requesting a config (received 403)
2025-01-13 00:14:50,893 ERROR [pool-8460-thread-1] [] ServiceDiscoverHttpClient - Service discover didn't respond with 200 when requesting a config (received 403)
2025-01-13 00:14:52,688 WARN [qtp1040093935-13063] [] extensions - unable to find handler for extension: system failure: Extension HTTP handler not found at /metrics/auth
2025-01-13 00:14:55,222 WARN [qtp1040093935-13075] [] extensions - unable to find handler for extension: system failure: Extension HTTP handler not found at /metrics/powerstore
2025-01-13 00:15:17,903 INFO [MailboxPurge] [name=galsync@mail.jpp.fr;mid=15;] purge - Purging messages.
------------------------------------------------------------------------------------------------------------------------------------
Another problem :
I try to upgrade the system from 20.4 to 22.4 following the instructions,
- Postgresql is upgraded to version 16 (OK), all seems to be working
- when I try "apt dist-upgrade" the upgrade went to end without any problem, but Carbonio was not working, only 13 processes for zextras.
So I revert to the backup taken after migrating Postgresql.
Regards
JP P
Hi,
In some occasion, Carbonio Mesh can not correctly communicate with rabbitmq due to an invalid token.
have you tried this:
https://docs.zextras.com/carbonio-ce/html/troubleshooting/wsc.html#wsc
regards,
Hello,
The upgrade is partially OK, only the migration to Postgresql16 is done and works/
I had some problems whith the command "do-release-upgrade" which wants to install Postgresql-14, I had to add 3 files in /etc/apt/preferences.d to circumvent it :
Package: postgresql-14
Pin: release *
Pin-Priority: -1
Idem for postgresql-client-14 et postgressql-14-doc
After that problem was solved the upgrade went to end, but when I restart Carbonio was noot usable with only 13 "zextras" processes visible.
I had to revert to the last backup.
Regards
Ah yes. Because Ubuntu 22 ships with PostgreSQL version 14. That's why Carbonio-CE installation instruction for Ubuntu 22.04LTS specifies about adding repo for PostgreSL-16 and related packages. Therefore, I am not sure what other package could have this kind of issues.
Upgrading a version itself is critical and sensitive, IMO, if possible have a clean version of CE on Ubuntu 22.04 and migrate data from Ubuntu 20.04 to Ubuntu 22.04. But this is completely my opinion.
Regards,
Hello,
Postgresql 16 is OK, and I "block" the i,stallation of version 14 in preferences.d, but when I try to upgrade to 22.04 the upgrade went at end and the system seems to be OK, but >Carbonio does not start...>
Will have a new try and save the logs.
Regards
JP P