Opened 11 months ago

Closed 11 months ago

Last modified 11 months ago

#29562 closed defect (fixed)

APPCRASH of tor.exe on Windows when PT bootstrap is cancelled

Reported by: dcf Owned by: ahf
Priority: High Milestone: Tor: 0.4.0.x-final
Component: Core Tor/Tor Version: Tor: 0.4.0.1-alpha
Severity: Normal Keywords: regression 040-must crash nickm-merge
Cc: ahf, gk Actual Points: 0.3
Parent ID: Points: 0.3
Reviewer: dgoulet Sponsor: Sponsor19

Description (last modified by dcf)

Start Tor Browser, click Configure, then select a pluggable transport (I tried both obfs4 and meek-azure). While bootstrapping is in progress, click Cancel. tor.exe crashes with the log:

[ERR] tor_assertion_failed_(): Bug: process.c:522: process_get_win32_process: Assertion process->win32_process failed; aborting. (on Tor 0.4.0.1-alpha 81f1b89efc94723f)
[ERR] Bug: Assertion process->win32_process failed in process_get_win32_process at process.c:522. (Stack trace not available) (on Tor 0.4.0.1-alpha 81f1b89efc94723f)

These dialogs appear in succession. Sometimes, the "application has requested the Runtime to terminate it in an unusual way" would not appear, and instead the "tor.exe has stopped working" would appear twice.




The "View problem details" expander shows:

Problem signature:
  Problem Event Name:	APPCRASH
  Application Name:	tor.exe
  Application Version:	0.0.0.0
  Application Timestamp:	a640a628
  Fault Module Name:	tor.exe
  Fault Module Version:	0.0.0.0
  Fault Module Timestamp:	a640a628
  Exception Code:	40000015
  Exception Offset:	00000000002c6a44
  OS Version:	6.1.7601.2.1.0.256.48
  Locale ID:	1033
  Additional Information 1:	869c
  Additional Information 2:	869c6822c6babdacb5663a19facccafb
  Additional Information 3:	607b
  Additional Information 4:	607bd60f513aeecf36fa5e247b547f57

Here are tor logs from different runs. One of them mentions a clock skew, but that seems to be a problem with the remote system. I checked and the time on the local Windows host was correct.

2/23/19, 08:42:06.326 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:42:09.765 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:42:09.765 [NOTICE] Switching to guard context "default" (was using "bridges") 
2/23/19, 08:42:09.765 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:42:09.765 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:42:09.765 [NOTICE] Opening Socks listener on 127.0.0.1:9150 
2/23/19, 08:42:09.765 [NOTICE] Opened Socks listener on 127.0.0.1:9150 
2/23/19, 08:42:10.224 [WARN] Managed proxy at 'TorBrowser\Tor\PluggableTransports\terminateprocess-buffer.exe' reported: 2019/02/23 08:42:09 running firefox command ["C:\\Users\\david\\Desktop\\Tor Browser\\Browser\\firefox.exe" "--invisible" "-no-remote" "-profile" "C:\\Users\\david\\Desktop\\Tor Browser\\Browser\\TorBrowser\\Data\\Browser\\profile.meek-http-helper"] 
2/23/19, 08:42:10.224 [WARN] Managed proxy at 'TorBrowser\Tor\PluggableTransports\terminateprocess-buffer.exe' reported: 2019/02/23 08:42:09 firefox started with pid 3552 
2/23/19, 08:42:10.224 [NOTICE] Bootstrapped 5% (conn): Connecting to a relay 
2/23/19, 08:42:10.564 [WARN] Managed proxy at 'TorBrowser\Tor\PluggableTransports\terminateprocess-buffer.exe' reported: 2019/02/23 08:42:10 running meek-client command ["TorBrowser\\Tor\\PluggableTransports\\meek-client.exe" "--helper" "127.0.0.1:1468"] 
2/23/19, 08:42:10.565 [WARN] Managed proxy at 'TorBrowser\Tor\PluggableTransports\terminateprocess-buffer.exe' reported: 2019/02/23 08:42:10 meek-client started with pid 4004 
2/23/19, 08:42:10.565 [WARN] Managed proxy at 'TorBrowser\Tor\PluggableTransports\terminateprocess-buffer.exe' reported: 2019/02/23 08:42:10 using helper on 127.0.0.1:1468 
2/23/19, 08:42:10.565 [WARN] Managed proxy at 'TorBrowser\Tor\PluggableTransports\terminateprocess-buffer.exe' reported: 2019/02/23 08:42:10 listening on 127.0.0.1:1469 
2/23/19, 08:42:10.566 [NOTICE] Bootstrapped 10% (conn_done): Connected to a relay 
2/23/19, 08:42:10.892 [NOTICE] Bootstrapped 14% (handshake): Handshaking with a relay 
2/23/19, 08:42:11.490 [NOTICE] Bootstrapped 15% (handshake_done): Handshake with a relay done 
2/23/19, 08:42:11.500 [NOTICE] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection 
2/23/19, 08:42:11.252 [NOTICE] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus 
2/23/19, 08:42:11.441 [NOTICE] Bootstrapped 30% (loading_status): Loading networkstatus consensus 
2/23/19, 08:42:11.610 [WARN] Received NETINFO cell with skewed time (OR:128.31.0.39:9101): It seems that our clock is ahead by 7 hours, 59 minutes, or that theirs is behind. Tor requires an accurate clock to work: please check your time, timezone, and date settings. 
2/23/19, 08:42:11.610 [WARN] Problem bootstrapping. Stuck at 30% (loading_status): Loading networkstatus consensus. (Clock skew 28796 in NETINFO cell from OR; CLOCK_SKEW; count 1; recommendation warn; host 9695DFC35FFEB861329B9F1AB04C46397020CE31 at 128.31.0.39:9101) 
2/23/19, 08:42:11.632 [NOTICE] Closing no-longer-configured Socks listener on 127.0.0.1:9150 
2/23/19, 08:42:11.632 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:42:11.633 [NOTICE] Delaying directory fetches: DisableNetwork is set. 
2/23/19, 08:42:11.633 [ERR] tor_assertion_failed_(): Bug: process.c:522: process_get_win32_process: Assertion process->win32_process failed; aborting. (on Tor 0.4.0.1-alpha 81f1b89efc94723f) 
2/23/19, 08:42:11.634 [ERR] Bug: Assertion process->win32_process failed in process_get_win32_process at process.c:522. (Stack trace not available) (on Tor 0.4.0.1-alpha 81f1b89efc94723f) 
2/23/19, 08:47:29.840 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:47:29.840 [NOTICE] Opening Socks listener on 127.0.0.1:9150 
2/23/19, 08:47:29.850 [NOTICE] Opened Socks listener on 127.0.0.1:9150 
2/23/19, 08:47:30.850 [NOTICE] Bootstrapped 3% (conn_proxy): Connecting to proxy 
2/23/19, 08:47:30.870 [NOTICE] Bootstrapped 4% (conn_done_proxy): Connected to proxy 
2/23/19, 08:47:31.866 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:33.867 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:35.896 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:38.945 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:41.963 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:45.550 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:49.530 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:47:51.134 [WARN] Proxy Client: unable to connect to 154.35.22.9:443 ("general SOCKS server failure") 
2/23/19, 08:47:51.136 [WARN] Proxy Client: unable to connect to 192.99.11.54:443 ("general SOCKS server failure") 
2/23/19, 08:47:51.139 [WARN] Proxy Client: unable to connect to 154.35.22.11:443 ("general SOCKS server failure") 
2/23/19, 08:47:51.141 [WARN] Proxy Client: unable to connect to 154.35.22.10:15937 ("general SOCKS server failure") 
2/23/19, 08:47:51.142 [WARN] Proxy Client: unable to connect to 154.35.22.13:16815 ("general SOCKS server failure") 
2/23/19, 08:47:51.143 [WARN] Proxy Client: unable to connect to 2001:470:b381:bfff:216:3eff:fe23:d6c3:443 ("general SOCKS server failure") 
2/23/19, 08:47:51.144 [WARN] Proxy Client: unable to connect to 154.35.22.12:4304 ("general SOCKS server failure") 
2/23/19, 08:47:57.239 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:48:04.848 [NOTICE] Closing no-longer-configured Socks listener on 127.0.0.1:9150 
2/23/19, 08:48:04.848 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:48:04.849 [ERR] tor_assertion_failed_(): Bug: process.c:522: process_get_win32_process: Assertion process->win32_process failed; aborting. (on Tor 0.4.0.1-alpha 81f1b89efc94723f) 
2/23/19, 08:48:04.849 [ERR] Bug: Assertion process->win32_process failed in process_get_win32_process at process.c:522. (Stack trace not available) (on Tor 0.4.0.1-alpha 81f1b89efc94723f) 
2/23/19, 08:52:16.607 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:52:23.234 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:52:23.234 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:52:23.235 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:52:23.235 [NOTICE] Opening Socks listener on 127.0.0.1:9150 
2/23/19, 08:52:23.235 [NOTICE] Opened Socks listener on 127.0.0.1:9150 
2/23/19, 08:52:24.231 [NOTICE] Bootstrapped 3% (conn_proxy): Connecting to proxy 
2/23/19, 08:52:24.235 [NOTICE] Bootstrapped 4% (conn_done_proxy): Connected to proxy 
2/23/19, 08:52:26.212 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:52:28.800 [WARN] Proxy Client: unable to connect to 37.218.240.34:40035 ("general SOCKS server failure") 
2/23/19, 08:52:28.810 [NOTICE] Closing no-longer-configured Socks listener on 127.0.0.1:9150 
2/23/19, 08:52:28.820 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. 
2/23/19, 08:52:28.820 [ERR] tor_assertion_failed_(): Bug: process.c:522: process_get_win32_process: Assertion process->win32_process failed; aborting. (on Tor 0.4.0.1-alpha 81f1b89efc94723f) 
2/23/19, 08:52:28.820 [ERR] Bug: Assertion process->win32_process failed in process_get_win32_process at process.c:522. (Stack trace not available) (on Tor 0.4.0.1-alpha 81f1b89efc94723f) 

Child Tickets

Attachments (6)

terminate.png (6.5 KB) - added by dcf 11 months ago.
stoppedworking.png (12.9 KB) - added by dcf 11 months ago.
exited.png (10.2 KB) - added by dcf 11 months ago.
win8-exited.png (14.2 KB) - added by dcf 11 months ago.
win8-stoppedworking.png (19.4 KB) - added by dcf 11 months ago.
win8-terminate.png (9.8 KB) - added by dcf 11 months ago.

Download all attachments as: .zip

Change History (19)

Changed 11 months ago by dcf

Attachment: terminate.png added

Changed 11 months ago by dcf

Attachment: stoppedworking.png added

Changed 11 months ago by dcf

Attachment: exited.png added

comment:1 Changed 11 months ago by dcf

Summary: APPCRASH of tor.exe on Windows 7 when PT bootstrap is cancelledAPPCRASH of tor.exe on Windows when PT bootstrap is cancelled

I got it to happen on Windows 8 too.




Changed 11 months ago by dcf

Attachment: win8-exited.png added

Changed 11 months ago by dcf

Attachment: win8-stoppedworking.png added

Changed 11 months ago by dcf

Attachment: win8-terminate.png added

comment:2 Changed 11 months ago by nickm

Cc: ahf added
Keywords: regression 040-must crash added
Milestone: Tor: 0.4.0.x-final
Priority: MediumHigh

comment:3 Changed 11 months ago by gk

Cc: gk added

comment:4 Changed 11 months ago by ahf

Owner: set to ahf
Status: newassigned

comment:5 Changed 11 months ago by ahf

I can reproduce this on Windows 10 as well. Looking into it.

comment:6 Changed 11 months ago by ahf

Just clearing up some confusion here: the Git revision for the Tor version is 81f1b89efc94723f. Small typo in the first report.

comment:8 Changed 11 months ago by ahf

Actual Points: 0.3
Points: 0.3
Status: assignedneeds_review

Looks like CI was happy with this.

PR against maint-0.4.0 can be found at: https://github.com/torproject/tor/pull/728

comment:9 Changed 11 months ago by dgoulet

Keywords: nickm-merge added
Reviewer: dgoulet

lgtm!

comment:10 Changed 11 months ago by dgoulet

Status: needs_reviewmerge_ready

comment:11 Changed 11 months ago by nickm

Resolution: fixed
Status: merge_readyclosed

Merged to 0.4.0 and forward. Thanks!

comment:12 in reply to:  6 Changed 11 months ago by dcf

Description: modified (diff)

Replying to ahf:

Just clearing up some confusion here: the Git revision for the Tor version is 81f1b89efc94723f. Small typo in the first report.

Updated the description for this.

comment:13 Changed 11 months ago by ahf

Sponsor: Sponsor19
Note: See TracTickets for help on using tickets.