{"action":"created","issue":{"url":"https://api.github.com/repos/erlio/vernemq/issues/893","repository_url":"https://api.github.com/repos/erlio/vernemq","labels_url":"https://api.github.com/repos/erlio/vernemq/issues/893/labels{/name}","comments_url":"https://api.github.com/repos/erlio/vernemq/issues/893/comments","events_url":"https://api.github.com/repos/erlio/vernemq/issues/893/events","html_url":"https://github.com/erlio/vernemq/issues/893","id":369364075,"node_id":"MDU6SXNzdWUzNjkzNjQwNzU=","number":893,"title":"Stuck session is preventing client re-connect","user":{"login":"chriswue","id":903928,"node_id":"MDQ6VXNlcjkwMzkyOA==","avatar_url":"https://avatars3.githubusercontent.com/u/903928?v=4","gravatar_id":"","url":"https://api.github.com/users/chriswue","html_url":"https://github.com/chriswue","followers_url":"https://api.github.com/users/chriswue/followers","following_url":"https://api.github.com/users/chriswue/following{/other_user}","gists_url":"https://api.github.com/users/chriswue/gists{/gist_id}","starred_url":"https://api.github.com/users/chriswue/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/chriswue/subscriptions","organizations_url":"https://api.github.com/users/chriswue/orgs","repos_url":"https://api.github.com/users/chriswue/repos","events_url":"https://api.github.com/users/chriswue/events{/privacy}","received_events_url":"https://api.github.com/users/chriswue/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":5,"created_at":"2018-10-12T01:24:02Z","updated_at":"2018-10-19T08:52:54Z","closed_at":null,"author_association":"NONE","body":"### Environment\r\n\r\n- VerneMQ Version: 1.5.0\r\n- OS: official docker image running on Ubuntu 18.04\r\n\r\nOn one of our brokers we've observed a stuck client session. The client publishes ~5,500 messages/sec on an ongoing basis. After around 60h of continuous running the client got disconnected by the broker and hasn't been able to reconnect.\r\n\r\nWhen that particular client tries to connect, this is what gets logged:\r\n\r\n    [warning] can't register client {[],<<\"the-client-id\">>} due to reason action_timeout\r\n\r\nOther clients can still connect fine - it's just this particular client id.\r\n\r\nBefore the timeout was hit the following message was logged regularly as well:\r\n\r\n    [info] monitor busy_port <0.515.0> [{initial_call,{vmq_ranch,init,5}},{almost_current_function,{erts_internal,port_command,3}},{message_queue_len,1}] #Port<0.11015>\r\n\r\nwith the `message_queue_len` varying between 0 and 2\r\n\r\nThat client doesn't appear in the `vmq-admin session show` command.\r\n`vmq-admin trace client` output:\r\n\r\n    Starting trace for 1 existing sessions for client \"the-client-id\" with PIDs\r\n    [<7251.14618.0>]\r\n    New session with PID <7251.20870.2> found for client \"the-client-id\"\r\n    <7251.20870.2> MQTT RECV: CID: \"the-client-id\" CONNECT(c: the-client-id, v: 4, u: undefined, p: undefined, cs: 0, ka: 60)\r\n    New session with PID <7251.20880.2> found for client \"the-client-idr\"\r\n    <7251.20880.2> MQTT RECV: CID: \"the-client-id\" CONNECT(c: the-client-id, v: 4, u: undefined, p: undefined, cs: 0, ka: 60)\r\n\r\nI can run `vmq-admin session disconnect` on the client which reports Ok but it doesn't change anything or create any log entries.\r\n\r\nVerneMQ is currently using around 2GB RAM - the online message queue size is 10,000. LevelDB backend is disabled\r\n\r\nIs there anything else I can do to debug this?"},"comment":{"url":"https://api.github.com/repos/erlio/vernemq/issues/comments/431293289","html_url":"https://github.com/erlio/vernemq/issues/893#issuecomment-431293289","issue_url":"https://api.github.com/repos/erlio/vernemq/issues/893","id":431293289,"node_id":"MDEyOklzc3VlQ29tbWVudDQzMTI5MzI4OQ==","user":{"login":"ioolkos","id":282359,"node_id":"MDQ6VXNlcjI4MjM1OQ==","avatar_url":"https://avatars0.githubusercontent.com/u/282359?v=4","gravatar_id":"","url":"https://api.github.com/users/ioolkos","html_url":"https://github.com/ioolkos","followers_url":"https://api.github.com/users/ioolkos/followers","following_url":"https://api.github.com/users/ioolkos/following{/other_user}","gists_url":"https://api.github.com/users/ioolkos/gists{/gist_id}","starred_url":"https://api.github.com/users/ioolkos/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/ioolkos/subscriptions","organizations_url":"https://api.github.com/users/ioolkos/orgs","repos_url":"https://api.github.com/users/ioolkos/repos","events_url":"https://api.github.com/users/ioolkos/events{/privacy}","received_events_url":"https://api.github.com/users/ioolkos/received_events","type":"User","site_admin":false},"created_at":"2018-10-19T08:52:54Z","updated_at":"2018-10-19T08:52:54Z","author_association":"CONTRIBUTOR","body":"Ok, let's suppose we fill up a queue with 1Million offline messages. Those go into LevelDB too. Then we restart the broker. Then we reconnect the consumer for those messages (clean session = false, so it will resume it's session).\r\n\r\n@dergraf, @larshesel the delay can't be caused by the merkle tree build-up, can't it? (because we only have a few session). But spawning the queue, and then filling it up with 1Million messages (copying from LevelDB to RAM), that could take some time, right? Then we might have a session trying to attach to a somewhat blocked queue, or something like that."}}
{"actor":{"display_login":"ioolkos"}}