{"action":"created","issue":{"url":"https://api.github.com/repos/xcat2/xcat-core/issues/3698","repository_url":"https://api.github.com/repos/xcat2/xcat-core","labels_url":"https://api.github.com/repos/xcat2/xcat-core/issues/3698/labels{/name}","comments_url":"https://api.github.com/repos/xcat2/xcat-core/issues/3698/comments","events_url":"https://api.github.com/repos/xcat2/xcat-core/issues/3698/events","html_url":"https://github.com/xcat2/xcat-core/issues/3698","id":250561651,"number":3698,"title":"[DEV}Callback message may hang at xcatd side","user":{"login":"chenglch","id":7165199,"avatar_url":"https://avatars1.githubusercontent.com/u/7165199?v=4","gravatar_id":"","url":"https://api.github.com/users/chenglch","html_url":"https://github.com/chenglch","followers_url":"https://api.github.com/users/chenglch/followers","following_url":"https://api.github.com/users/chenglch/following{/other_user}","gists_url":"https://api.github.com/users/chenglch/gists{/gist_id}","starred_url":"https://api.github.com/users/chenglch/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/chenglch/subscriptions","organizations_url":"https://api.github.com/users/chenglch/orgs","repos_url":"https://api.github.com/users/chenglch/repos","events_url":"https://api.github.com/users/chenglch/events{/privacy}","received_events_url":"https://api.github.com/users/chenglch/received_events","type":"User","site_admin":false},"labels":[{"id":310577086,"url":"https://api.github.com/repos/xcat2/xcat-core/labels/component:xcatd","name":"component:xcatd","color":"fbca04","default":false},{"id":551182344,"url":"https://api.github.com/repos/xcat2/xcat-core/labels/sprint1","name":"sprint1","color":"bfd4f2","default":false}],"state":"open","locked":false,"assignee":{"login":"chenglch","id":7165199,"avatar_url":"https://avatars1.githubusercontent.com/u/7165199?v=4","gravatar_id":"","url":"https://api.github.com/users/chenglch","html_url":"https://github.com/chenglch","followers_url":"https://api.github.com/users/chenglch/followers","following_url":"https://api.github.com/users/chenglch/following{/other_user}","gists_url":"https://api.github.com/users/chenglch/gists{/gist_id}","starred_url":"https://api.github.com/users/chenglch/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/chenglch/subscriptions","organizations_url":"https://api.github.com/users/chenglch/orgs","repos_url":"https://api.github.com/users/chenglch/repos","events_url":"https://api.github.com/users/chenglch/events{/privacy}","received_events_url":"https://api.github.com/users/chenglch/received_events","type":"User","site_admin":false},"assignees":[{"login":"chenglch","id":7165199,"avatar_url":"https://avatars1.githubusercontent.com/u/7165199?v=4","gravatar_id":"","url":"https://api.github.com/users/chenglch","html_url":"https://github.com/chenglch","followers_url":"https://api.github.com/users/chenglch/followers","following_url":"https://api.github.com/users/chenglch/following{/other_user}","gists_url":"https://api.github.com/users/chenglch/gists{/gist_id}","starred_url":"https://api.github.com/users/chenglch/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/chenglch/subscriptions","organizations_url":"https://api.github.com/users/chenglch/orgs","repos_url":"https://api.github.com/users/chenglch/repos","events_url":"https://api.github.com/users/chenglch/events{/privacy}","received_events_url":"https://api.github.com/users/chenglch/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/xcat2/xcat-core/milestones/30","html_url":"https://github.com/xcat2/xcat-core/milestone/30","labels_url":"https://api.github.com/repos/xcat2/xcat-core/milestones/30/labels","id":2381926,"number":30,"title":"2.13.7","description":"","creator":{"login":"whowutwut","id":10049070,"avatar_url":"https://avatars0.githubusercontent.com/u/10049070?v=4","gravatar_id":"","url":"https://api.github.com/users/whowutwut","html_url":"https://github.com/whowutwut","followers_url":"https://api.github.com/users/whowutwut/followers","following_url":"https://api.github.com/users/whowutwut/following{/other_user}","gists_url":"https://api.github.com/users/whowutwut/gists{/gist_id}","starred_url":"https://api.github.com/users/whowutwut/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/whowutwut/subscriptions","organizations_url":"https://api.github.com/users/whowutwut/orgs","repos_url":"https://api.github.com/users/whowutwut/repos","events_url":"https://api.github.com/users/whowutwut/events{/privacy}","received_events_url":"https://api.github.com/users/whowutwut/received_events","type":"User","site_admin":false},"open_issues":74,"closed_issues":24,"state":"open","created_at":"2017-03-13T13:27:28Z","updated_at":"2017-08-17T07:06:23Z","due_on":"2017-09-22T07:00:00Z","closed_at":null},"comments":0,"created_at":"2017-08-16T09:17:35Z","updated_at":"2017-08-17T07:51:59Z","closed_at":null,"body":"We encountered this problem while running bmc discovery for a large cluster (more than 2 thousand nodes). The child processes may hang at the end if  `xCAT::MsgUtils->message(\"I\" , ...` is called. This is a general error of xcatd while redirecting the message from pipe to the client."},"comment":{"url":"https://api.github.com/repos/xcat2/xcat-core/issues/comments/322996127","html_url":"https://github.com/xcat2/xcat-core/issues/3698#issuecomment-322996127","issue_url":"https://api.github.com/repos/xcat2/xcat-core/issues/3698","id":322996127,"user":{"login":"chenglch","id":7165199,"avatar_url":"https://avatars1.githubusercontent.com/u/7165199?v=4","gravatar_id":"","url":"https://api.github.com/users/chenglch","html_url":"https://github.com/chenglch","followers_url":"https://api.github.com/users/chenglch/followers","following_url":"https://api.github.com/users/chenglch/following{/other_user}","gists_url":"https://api.github.com/users/chenglch/gists{/gist_id}","starred_url":"https://api.github.com/users/chenglch/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/chenglch/subscriptions","organizations_url":"https://api.github.com/users/chenglch/orgs","repos_url":"https://api.github.com/users/chenglch/repos","events_url":"https://api.github.com/users/chenglch/events{/privacy}","received_events_url":"https://api.github.com/users/chenglch/received_events","type":"User","site_admin":false},"created_at":"2017-08-17T07:51:59Z","updated_at":"2017-08-17T07:51:59Z","body":"After running some self scripts, the root cause is from the code logic of xcatd while handling communication between the socket pairs if multiple child processes exist.\r\n\r\nBelow is the code block that has race condition if child processes send the message back to the client at the same time. `relay_fds` is running in `immidiate` process and `convey_response` is running in child plugin processes.\r\n```\r\nsub relay_fds { # Relays file descriptors from pipes to children to the SSL socket\r\n    my $fds        = shift;\r\n    my $replyqueue = shift;\r\n    my $goneclient = 0;\r\n    my $collate    = (scalar @_ > 0 ? shift : 0);\r\n    my @readyset   = $fds->can_read(1);\r\n    my $rfh;\r\n    my $rc = @readyset;\r\n    my $text;\r\n\r\n    # A PIPE signal might be received when run fd_retrieve from the plugin sub processors\r\n    # This mostly happens when there are multiple plugins are called for certain command\r\n    # So spkit the pipe error handle\r\n    $pipeexpected = 1;\r\n    foreach $rfh (@readyset) { # go through each child, extract a complete, atomic message\r\n        my $line;\r\n        my $resp;\r\n        eval {\r\n            $resp = fd_retrieve($rfh);\r\n        };\r\n        if ($@ and $@ =~ /^Magic number checking on storable file/) { # this most likely means we ran over the end of available input\r\n            $fds->remove($rfh);\r\n            close($rfh);\r\n        } else {\r\n            push @$replyqueue, $resp;\r\n            print $rfh \"nfin\\n\";\r\n        }\r\n    }\r\n   ....\r\n```\r\n\r\n```\r\nsub convey_response {\r\n    my $resp = shift;\r\n\r\n    # TODO: This is where the following will/may happen:\r\n    # -Track transaction id\r\n    # -Save output for deferred commands\r\n    unless ($parent_fd) {\r\n        build_response($resp);\r\n        return;\r\n    }\r\n    unless ($resp) { return; }\r\n    $pipeexpected = 1;\r\n\r\n    #$resp = XMLout($resp,KeyAttr=>[], NoAttr=>1,RootName=>'xcatresponse');\r\n    # sanitize the response, to avoid being killed by non-printable bytes\r\n    #$resp =~ tr/\\011-\\177/?/c;\r\n    # seeing if using utf-8 offloads potential issues to client terminal, it didn't\r\n    store_fd($resp, $parent_fd);\r\n    yield; # parent must get timeslice anyway before an ack could possibly return\r\n    my $parsel = new IO::Select;\r\n    $parsel->add($parent_fd);\r\n    my $selbits = $parsel->bits;\r\n    my $rsp;\r\n    while ($selbits && ($rsp = select($selbits, undef, undef, 5))) { # block up to five seconds\r\n\r\n        if ($quit) {    # Obey quit flag\r\n            xexit 0;\r\n        }\r\n        if ($rsp == 0) {    # This means the filedescriptor was removed\r\n            last;\r\n        }\r\n        if ($rsp < 0) {     # A signal caused select to skip out, do-over\r\n            next;\r\n        }\r\n\r\n        # At this point, the only possibility is a positive return, meaning parent_fd requires attention of some sort\r\n        $rsp = <$parent_fd>;\r\n        if ($rsp) { # If data actually came in, last, otherwise, remove it from the IO::Select, but both should amount to the same thing\r\n            last;\r\n        } else {\r\n            $parsel->remove($parent_fd);\r\n            last;\r\n        }\r\n    }\r\n    yield; # If still around, it means a peer process still hasn't gotten to us, so might as well yield\r\n    $selbits = $parsel->bits;\r\n}\r\n```\r\nBelow is my guess.\r\n\r\nI focus on the `convey_response` at first, after sending the response to `immidiate` process though `store_fd($resp, $parent_fd);`, it use a select to wait for the response and then read it `$rsp = <$parent_fd>;`. My test script always hangs here as the race condition of multiple child processes call the `read system call` and blocks.  When the write event from `print $rfh \"nfin\\n\";` of `relay_fds` comes, one of the blocked read `system call` will be waked up. Unfortunately, in a multi-processes environment, `immidate` process may call the `print` multiple times and then the cpu switch to the child processes. Only one of the child processes may be waked up, so some of the wake up event made by writing pipe  is missing. ( I can't find detail document to explain why only one of blocked read `system call` is waked up but the other blocked read `system calls` are still waiting even though there are buffer to read from the pipe, **if anyone knows, could tell me if the guess is right or not**).\r\n\r\nTo handle this, previous xcat code use a select to check is it the right time to read from the $parent_fd pipe, it only decrease the probability but can not avoid it. Imaging that there are two child processes passed the select check , one call the read and then the pipe is empty, the other  child process is waiting for the write event. But if the write event is missing like the situation described above, there are always child processes waiting for the write event, then hangs.\r\n\r\n\r\n"}}
{"actor":{"display_login":"chenglch"}}