From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!.POSTED.blaine.gmane.org!not-for-mail From: Daniel Pittman Newsgroups: gmane.emacs.devel Subject: TRAMP VC optimization: also breaks process filters -_- Date: Wed, 1 May 2019 14:13:47 -0400 Message-ID: Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="000000000000bc26cc0587d77c8f" Injection-Info: blaine.gmane.org; posting-host="blaine.gmane.org:195.159.176.226"; logging-data="197750"; mail-complaints-to="usenet@blaine.gmane.org" To: emacs-devel , Michael Albinus Original-X-From: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Wed May 01 20:14:39 2019 Return-path: Envelope-to: ged-emacs-devel@m.gmane.org Original-Received: from lists.gnu.org ([209.51.188.17]) by blaine.gmane.org with esmtps (TLS1.0:RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1hLtkc-000pFq-17 for ged-emacs-devel@m.gmane.org; Wed, 01 May 2019 20:14:38 +0200 Original-Received: from localhost ([127.0.0.1]:37971 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1hLtka-0007Jz-Qc for ged-emacs-devel@m.gmane.org; Wed, 01 May 2019 14:14:36 -0400 Original-Received: from eggs.gnu.org ([209.51.188.92]:45491) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1hLtkS-0007Jt-Hw for emacs-devel@gnu.org; Wed, 01 May 2019 14:14:31 -0400 Original-Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1hLtkQ-0002U0-W8 for emacs-devel@gnu.org; Wed, 01 May 2019 14:14:28 -0400 Original-Received: from mail-io1-xd2c.google.com ([2607:f8b0:4864:20::d2c]:37585) by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_128_CBC_SHA1:16) (Exim 4.71) (envelope-from ) id 1hLtkQ-0002TK-Mi for emacs-devel@gnu.org; Wed, 01 May 2019 14:14:26 -0400 Original-Received: by mail-io1-xd2c.google.com with SMTP id a23so15520408iot.4 for ; Wed, 01 May 2019 11:14:25 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20161025; h=mime-version:from:date:message-id:subject:to; bh=VHsN2zK/pwXxaxonQvraGwd+nRegujVhqSBl7UPv18g=; b=GAqb2Z5+x4a1UUxteyuBTBLrsUtz6GpcNAHAAq3QZMoRvW1vMZPu3Ij3NE13qxEhB9 0ap+bzPD9gd7UxfQRl5Kf90qyfYXK2orp3oyMczJ9I3kPqGNEWGlCR4vL1DNtGgvRBpH FPOkq2l+ixmEhroSi6LRZ/fwDnV64vzmN+PbIXTKQeEm/YwapBZWVVx5PHL1aIniNa82 +uFf3H952/B6YGID+3B7X2bEa6bRyEu6VJA8LEpb0AY91beDtqD/P3MK5FebOKt102Ts +72umfsz7jWBOnfCwSOOz/atMBH2RM+NwZHVzVuwmw09ZSgO+fZxF0GVHh0ItsRQMXCv fxkw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:from:date:message-id:subject:to; bh=VHsN2zK/pwXxaxonQvraGwd+nRegujVhqSBl7UPv18g=; b=HmYi0N4xLk4ZzFV/lXYPXKLxfXviLRmzJyJBrtCuUUKAa6+AFHvg8beaGUqHOCIGZx WmIq97zZ/oGcgYtIpyCAY931r9KewL0d8OwUo7s0hIci3ANL9sn/McChInw/L7gJKFe1 AspfmAcgUgaTM/10YzvFhTH+6ae/4hpwoOLjUBYajbzgc8w//J0v5SBgg7Xdx0UcgeAU EhGCpmLsIEwxluZNCs1N3w5NAWzA2kABkiSdh66J0+IfgAkQ73bQM8TBQerIAvnAfBZO Pc785llUYs27gzmCvo1K994O7/Kt4CFcKHk04ALLdh1n4Tw4gFvxeWNqEZnYdt68Zl+8 z2NA== X-Gm-Message-State: APjAAAVd31yUUKz2Kg4h7YZ0cqf8x10KfmDAks6QF9ds+17vOTLN+rHu JYxuNinnS4EWcMWT/gcQIszzofQrUV5tFQ+KD2heuNuuG4idoA== X-Google-Smtp-Source: APXvYqxdrTK8jL103zwxqUA02twuaDb1wGKe32He+9y0hh4jGH6hm8/w6rLzxJyDnCAl7pTz0nfzkiD+NTpqEv1+0RI= X-Received: by 2002:a6b:7c4a:: with SMTP id b10mr5704825ioq.35.1556734463925; Wed, 01 May 2019 11:14:23 -0700 (PDT) X-detected-operating-system: by eggs.gnu.org: Genre and OS details not recognized. X-Received-From: 2607:f8b0:4864:20::d2c X-BeenThere: emacs-devel@gnu.org X-Mailman-Version: 2.1.21 Precedence: list List-Id: "Emacs development discussions." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Original-Sender: "Emacs-devel" Xref: news.gmane.org gmane.emacs.devel:236096 Archived-At: --000000000000bc26cc0587d77c8f Content-Type: multipart/alternative; boundary="000000000000bc26c90587d77c8d" --000000000000bc26c90587d77c8d Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable G'day Michael. I'm sad to report that blocking timers in TRAMP is not sufficient to avoid it breaking other operations: process filters can also run while TRAMP is sending, and waiting for the result of, a command. I have attached a backtrace showing this, which happens during startup: I trigger an async ELPA package refresh at the start of my init file, which is what causes the HTTPS connection, and in the process filter invokes the NSM library to verify the cert =E2=80=93 and that tries to access a local p= ath for the database of ... something related to handling certificates. (I think user supplied policy decisions around them or something, but I don't know the detail.) That call to NSM from `url-https-proxy-after-change-function` in `url-http.el`, ultimately called from `url-http-generic-filter` with `funcall`, which is set as the process filter for the network connection in `url-http`, the entry point to fetching the content. I found this when I set down to discover why my package refresh was breaking during startup; if it is still running when the desktop.el library triggers restoring state, and that state includes TRAMP files (which it always does, for me) then it can happen at the same time as the refresh. A reproducible case should be possible by way of running this code in a TRAMP backed buffer: (progn (package-refresh-contents t) (revert-buffer)) ;; the first bit starts an async package refresh It is, though, a race condition, so if it doesn't trigger you may want to loop reverting or something. The backtrace is fairly clear, however. In theory it could also be triggered by any other process filter that triggers a file operation on a local file. Notes on the backtrace: `tramp-user-error@backtrace-on-bad-file-name-handling` is my advice to capture the backtrace, and consists of calling (debug) at the appropriate moment. I censored some names in the source for work related reasons, which are a) fairly obvious, and b) only in strings, and c) not relevant to the bug itself. The `gssh` method is a copy of the `ssh` method with a trivial modification; while I don't think it is strictly relevant, the performance of it may be related to how easy the race is for me to hit. The modification consist of pointing at the "correct" ssh binary for my environment, by absolute path, rather than the default one. (I think I fixed the problem causing it to come into being by adjusting how I handle the executable-path in init.el too, but I'm too lazy to remove the configuration now.) --000000000000bc26c90587d77c8d Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
G'day Michael.

I'm sad to report that = blocking timers in TRAMP is not sufficient to avoid it breaking other opera= tions: process filters can also run while TRAMP is sending, and waiting for= the result of, a command.

I have attached a backt= race showing this, which happens during startup: I trigger an async ELPA pa= ckage refresh at the start of my init file, which is what causes the HTTPS = connection, and in the process filter invokes the NSM library to verify the= cert =E2=80=93 and that tries to access a local path for the database of .= .. something related to handling certificates.=C2=A0 (I think user supplied= policy decisions around them or something, but I don't know the detail= .)

That call to NSM from `url-https-proxy-after-ch= ange-function` in `url-http.el`, ultimately called from `url-http-generic-f= ilter` with `funcall`, which is set as the process filter for the network c= onnection in `url-http`, the entry point to fetching the content.

I found this when I set down to discover why my package ref= resh was breaking during startup; if it is still running when the desktop.e= l library triggers restoring state, and that state includes TRAMP files (wh= ich it always does, for me) then it can happen at the same time as the refr= esh.

A reproducible case should be possible by way= of running this code in a TRAMP backed buffer:
(progn (package-r= efresh-contents t) (revert-buffer))=C2=A0 ;; the first bit starts an async = package refresh

It is, though, a race condition, s= o if it doesn't trigger you may want to loop reverting or something.=C2= =A0 The backtrace is fairly clear, however.=C2=A0 In theory it could also b= e triggered by any other process filter that triggers a file operation on a= local file.


Notes on the backtrace= :

`tramp-user-error@backtrace-on-bad-file-name-han= dling` is my advice to capture the backtrace, and consists of calling (debu= g) at the appropriate moment.

I censored some name= s in the source for work related reasons, which are a) fairly obvious, and = b) only in strings, and c) not relevant to the bug itself.

The `gssh` method is a copy of the `ssh` method with a trivial mod= ification; while I don't think it is strictly relevant, the performance= of it may be related to how easy the race is for me to hit.=C2=A0=C2=A0

The modification consist of pointing at the "co= rrect" ssh binary for my environment, by absolute path, rather than th= e default one.=C2=A0 (I think I fixed the problem causing it to come into b= eing by adjusting how I handle the executable-path in init.el too, but I= 9;m too lazy to remove the configuration now.)

--000000000000bc26c90587d77c8d-- --000000000000bc26cc0587d77c8f Content-Type: text/plain; charset="US-ASCII"; name="tramp-vc-filename-handling-2.text" Content-Disposition: attachment; filename="tramp-vc-filename-handling-2.text" Content-Transfer-Encoding: base64 Content-ID: X-Attachment-Id: f_jv5j4nw90 ICB0cmFtcC11c2VyLWVycm9yQGJhY2t0cmFjZS1vbi1iYWQtZmlsZS1uYW1lLWhhbmRsaW5nKCNm KGNvbXBpbGVkLWZ1bmN0aW9uICh2ZWMtb3ItcHJvYyBmbXQtc3RyaW5nICZyZXN0IGFyZ3VtZW50 cykgIlNpZ25hbCBhIHBpbG90IGVycm9yLiIgIzxieXRlY29kZSAweDFmZjU2ZDYxYWRhZD4pIG5p bCAiTm90IGEgVHJhbXAgZmlsZSBuYW1lOiBcIiVzXCIiICIvVXNlcnMvc2xpcHB5Y2hlZXplLy5l bWFjcy5kL25ldHdvcmstc2VjdXJpdHkuZGF0YSIpCiAgYXBwbHkodHJhbXAtdXNlci1lcnJvckBi YWNrdHJhY2Utb24tYmFkLWZpbGUtbmFtZS1oYW5kbGluZyAjZihjb21waWxlZC1mdW5jdGlvbiAo dmVjLW9yLXByb2MgZm10LXN0cmluZyAmcmVzdCBhcmd1bWVudHMpICJTaWduYWwgYSBwaWxvdCBl cnJvci4iICM8Ynl0ZWNvZGUgMHgxZmY1NmQ2MWFkYWQ+KSAobmlsICJOb3QgYSBUcmFtcCBmaWxl IG5hbWU6IFwiJXNcIiIgIi9Vc2Vycy9zbGlwcHljaGVlemUvLmVtYWNzLmQvbmV0d29yay1zZWN1 cml0eS5kYXRhIikpCiAgdHJhbXAtdXNlci1lcnJvcihuaWwgIk5vdCBhIFRyYW1wIGZpbGUgbmFt ZTogXCIlc1wiIiAiL1VzZXJzL3NsaXBweWNoZWV6ZS8uZW1hY3MuZC9uZXR3b3JrLXNlY3VyaXR5 LmRhdGEiKQogIHRyYW1wLWRpc3NlY3QtZmlsZS1uYW1lKCIvVXNlcnMvc2xpcHB5Y2hlZXplLy5l bWFjcy5kL25ldHdvcmstc2VjdXJpdHkuZGF0YSIpCiAgdHJhbXAtdmMtZmlsZS1uYW1lLWhhbmRs ZXIoZXhwYW5kLWZpbGUtbmFtZSAiL1VzZXJzL3NsaXBweWNoZWV6ZS8uZW1hY3MuZC9uZXR3b3Jr LXNlY3VyaXR5LmRhdGEiICIvZ3NzaDpzbGlwcHljaGVlemUuWC5YWFhYWFhYWC5YWFg6IikKICBm aWxlLWV4aXN0cy1wKCIvVXNlcnMvc2xpcHB5Y2hlZXplLy5lbWFjcy5kL25ldHdvcmstc2VjdXJp dHkuZGF0YSIpCiAgbnNtLWhvc3Qtc2V0dGluZ3MoInNoYTE6NmQ0ZWI5NTgzOTA1OTkyNDNiYTlm NTAzNWNiNjcxZmE4ZGQ2YTkzYSIpCiAgbnNtLXZlcmlmeS1jb25uZWN0aW9uKCM8cHJvY2VzcyBl bHBhLmdudS5vcmc+ICJlbHBhLmdudS5vcmciIDQ0MykKICBwcm9jZXNzLXNlbmQtc3RyaW5nKCM8 cHJvY2VzcyAqdHJhbXAvZ3NzaCBzbGlwcHljaGVlemUuWC5YWFhYWFhYWC5YWFgqPiAidHJhbXBf dmNfcmVnaXN0ZXJlZF9yZWFkX2ZpbGVfbmFtZXMgPDwnNDhhNDkyMDc0YzguLi4iKQogIHRyYW1w LXNlbmQtc3RyaW5nKCh0cmFtcC1maWxlLW5hbWUgImdzc2giIG5pbCBuaWwgInNsaXBweWNoZWV6 ZS5YLlhYWFhYWFhYLlhYWCIgbmlsICIvWFhYWFhYL1hYWFhYWC9YWFhYWFguLi4iIG5pbCkgInRy YW1wX3ZjX3JlZ2lzdGVyZWRfcmVhZF9maWxlX25hbWVzIDw8JzQ4YTQ5MjA3NGM4Li4uIikKICB0 cmFtcC1zZW5kLWNvbW1hbmQoKHRyYW1wLWZpbGUtbmFtZSAiZ3NzaCIgbmlsIG5pbCAic2xpcHB5 Y2hlZXplLlguWFhYWFhYWFguWFhYIiBuaWwgIi9YWFhYWFgvWFhYWFhYL1hYWFhYWC4uLiIgbmls KSAidHJhbXBfdmNfcmVnaXN0ZXJlZF9yZWFkX2ZpbGVfbmFtZXMgPDwnNDhhNDkyMDc0YzguLi4i KQogIHRyYW1wLXNoLWhhbmRsZS12Yy1yZWdpc3RlcmVkKCIvZ3NzaDpzbGlwcHljaGVlemUuWC5Y WFhYWFhYWC5YWFg6L1hYWFhYWC9YWFhYWFgvWFhYWFhYLi4uIikKICBhcHBseSh0cmFtcC1zaC1o YW5kbGUtdmMtcmVnaXN0ZXJlZCAiL2dzc2g6c2xpcHB5Y2hlZXplLlguWFhYWFhYWFguWFhYOi9Y WFhYWFgvWFhYWFhYL1hYWFhYWC4uLiIpCiAgdHJhbXAtc2gtZmlsZS1uYW1lLWhhbmRsZXIodmMt cmVnaXN0ZXJlZCAiL2dzc2g6c2xpcHB5Y2hlZXplLlguWFhYWFhYWFguWFhYOi9YWFhYWFgvWFhY WFhYL1hYWFhYWC4uLiIpCiAgYXBwbHkodHJhbXAtc2gtZmlsZS1uYW1lLWhhbmRsZXIgdmMtcmVn aXN0ZXJlZCAiL2dzc2g6c2xpcHB5Y2hlZXplLlguWFhYWFhYWFguWFhYOi9YWFhYWFgvWFhYWFhY L1hYWFhYWC4uLiIpCiAgdHJhbXAtZmlsZS1uYW1lLWhhbmRsZXIodmMtcmVnaXN0ZXJlZCAiL2dz c2g6c2xpcHB5Y2hlZXplLlguWFhYWFhYWFguWFhYOi9YWFhYWFgvWFhYWFhYL1hYWFhYWC4uLiIp CiAgdmMtcmVnaXN0ZXJlZCgiL2dzc2g6c2xpcHB5Y2hlZXplLlguWFhYWFhYWFguWFhYOi9YWFhY WFgvWFhYWFhYL1hYWFhYWC4uLiIpCiAgdmMtYmFja2VuZCgiL2dzc2g6c2xpcHB5Y2hlZXplLlgu WFhYWFhYWFguWFhYOi9YWFhYWFgvWFhYWFhYL1hYWFhYWC4uLiIpCiAgdmMtcmVmcmVzaC1zdGF0 ZSgpCiAgcnVuLWhvb2tzKGZpbmQtZmlsZS1ob29rKQogIGFmdGVyLWZpbmQtZmlsZShuaWwgbmls KQogIGZpbmQtZmlsZS1ub3NlbGVjdC0xKCM8YnVmZmVyIFhYWFhYWC5YWFhYWFg+ICIvZ3NzaDpz bGlwcHljaGVlemUuWC5YWFhYWFhYWC5YWFg6L1hYWFhYWC9YWFhYWFgvWFhYWFhYLi4uIiA6bm93 YXJuIG5pbCAiL2dzc2g6c2xpcHB5Y2hlZXplLlguWFhYWFhYWFguWFhYOi9YWFhYWFgvWFhYWFhY L1hYWFhYWC4uLiIgKDQ4OTM5MyAoLTEgLiAxKSkpCiAgZmluZC1maWxlLW5vc2VsZWN0KCIvZ3Nz aDpzbGlwcHljaGVlemUuWC5YWFhYWFhYWC5YWFg6L1hYWFhYWC9YWFhYWFgvWFhYWFhYLi4uIiA6 bm93YXJuKQogIGRlc2t0b3AtcmVzdG9yZS1maWxlLWJ1ZmZlcigiL2dzc2g6c2xpcHB5Y2hlZXpl LlguWFhYWFhYWFguWFhYOi9YWFhYWFgvWFhYWFhYL1hYWFhYWC4uLiIgIlhYWFhYWC5YWFhYWFgi IG5pbCkKICBkZXNrdG9wLWNyZWF0ZS1idWZmZXIoMjA4ICIvZ3NzaDpzbGlwcHljaGVlemUuWC5Y WFhYWFhYWC5YWFg6L1hYWFhYWC9YWFhYWFgvWFhYWFhYLi4uIiAiWFhYWFhYLlhYWFhYWCIgcHJv dG9idWZmZXItbW9kZSAob3ZlcnJpZGUtZ2xvYmFsLW1vZGUgZ29vZ2xlbWVudS1tb2RlIHN1cGVy LXNhdmUtbW9kZSBiZWdpbmVuZC1wcm9nLW1vZGUgYmVnaW5lbmQtZ2xvYmFsLW1vZGUgZ2xvYmFs LWF1dG8tcmV2ZXJ0LW1vZGUgd3MtYnV0bGVyLW1vZGUgdHlwby1tb2RlIHJhaW5ib3ctZGVsaW1p dGVycy1tb2RlIHdoaWNoLWtleS1tb2RlKSAyIChuaWwgbmlsKSBuaWwgbmlsICgodGFiLXdpZHRo IC4gMikgKGluZGVudC10YWJzLW1vZGUpIChidWZmZXItZGlzcGxheS10aW1lIDIzNzUwIDY1MTgz IDc1OTUyOSAwKSAoYnVmZmVyLWZpbGUtY29kaW5nLXN5c3RlbSAuIHV0Zi04LXVuaXgpKSAoKG1h cmstcmluZyBuaWwpKSkKICBldmFsLWJ1ZmZlcigjPGJ1ZmZlciAgKmxvYWQqPiBuaWwgIi9Vc2Vy cy9zbGlwcHljaGVlemUvLmVtYWNzLmQvZW1hY3Muc2xpcHB5Y2hlZXplLmRlLi4uIiBuaWwgdCkg IDsgUmVhZGluZyBhdCBidWZmZXIgcG9zaXRpb24gNzYxODQxCiAgbG9hZC13aXRoLWNvZGUtY29u dmVyc2lvbigiL1VzZXJzL3NsaXBweWNoZWV6ZS8uZW1hY3MuZC9lbWFjcy5zbGlwcHljaGVlemUu ZGUuLi4iICIvVXNlcnMvc2xpcHB5Y2hlZXplLy5lbWFjcy5kL2VtYWNzLnNsaXBweWNoZWV6ZS5k ZS4uLiIgdCB0KQogIGxvYWQoIi9Vc2Vycy9zbGlwcHljaGVlemUvLmVtYWNzLmQvZW1hY3Muc2xp cHB5Y2hlZXplLmRlLi4uIiB0IHQgdCkKICBkZXNrdG9wLXJlYWQoKQogICNmKGNvbXBpbGVkLWZ1 bmN0aW9uICgpICM8Ynl0ZWNvZGUgMHgxZmY1NmNhZjZjYzE+KSgpCiAgcnVuLWhvb2tzKGFmdGVy LWluaXQtaG9vayBkZWxheWVkLXdhcm5pbmdzLWhvb2spCiAgY29tbWFuZC1saW5lKCkKICBub3Jt YWwtdG9wLWxldmVsKCkK --000000000000bc26cc0587d77c8f--