Opened 5 months ago

Last modified 5 weeks ago

#31036 assigned defect

Logfile grow upto 2GB tor fails and refuse to start

Reported by: cypherpunks Owned by: ahf
Priority: Medium Milestone: Tor: 0.4.2.x-final
Component: Core Tor/Tor Version:
Severity: Normal Keywords: 035-backport, 040-backport, 041-backport, 042-should
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

i have enabled logging to file by log-level warning. there showed up repeatedly messages. once logfilesize >2GByte tor crash and cannot start again with logging enabled to this file.

Child Tickets

Change History (11)

comment:1 Changed 5 months ago by nickm

What version of tor? What kind of messages? Does deleting the log file help?

comment:2 Changed 5 months ago by nickm

Oh, also: what operating system are you using?

comment:3 in reply to:  2 Changed 5 months ago by cypherpunks

Seems the startup fails, while not able to appending to logfile because some magic size limits. (looks like INT_MAX bytes here? 2 GByte)
Also possible solution for startup fail should be the non default setting i found:

# TruncateLogFile TruncateLogFile 0|1
#     If 1, Tor will overwrite logs at startup and in response to a HUP signal,
#     instead of appending to them. (Default: 0)

But this will not help for running tor trying for writing above the filelimits.

Replying to nickm:

Does deleting the log file help?

Yes, of course Sorry. rm the log file helped.
Replying to nickm:

What version of tor?

Tor 0.4.0.5
Replying to nickm:

What kind of messages?

repeated messages:
Jun 26 07:01:30.000 [warn] {BUG} tor_bug_occurred_(): Bug: buffers_tls.c:73: buf_read_from_tls: Non-fatal assertion !(buf->datalen >= INT
#_MAX - at_most) failed. (on Tor 0.4.0.5 )

Replying to nickm:

Oh, also: what operating system are you using?

excuse me for not mentioning in reports this details. win10 - mingw-64

comment:4 Changed 5 months ago by nickm

Keywords: 035-backport 040-backport 041-backport added
Milestone: Tor: 0.4.2.x-final

Okay, it looks like at least two bugs here: failure to start when the logs are over 2GB, and the underlying warning message that is filling up the logs. We should fix both of these.

The warning message means that we are trying to fill a buffer attached to an incoming TLS connection to over 2GB in size, which is not something we should ever do; we should investigate why.

I'm guessing that you are running as a relay; is that right? Would you be okay with posting as much of your configuration here as you are comfortable with?

comment:5 Changed 4 months ago by cypherpunks

i can reproduce the tor startup fail, with any logfile >2147483646 bytes

Jul 05 04:36:11.043 [notice] Tor 0.4.0.5 running on Windows 10 [or later] with Libevent 2.1.8-stable, OpenSSL 1.1.1, Zlib 1.2.11, Liblzma 5.2.4, and Libzstd 1.3.8.
Jul 05 04:36:11.043 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jul 05 04:36:11.077 [notice] Your ContactInfo config option is not set. Please consider setting it, so we can contact you if your server is misco
nfigured or something else goes wrong.
Jul 05 04:36:11.044 [notice] Read configuration file "C:\tools\msys64\home\tor\usr\share\tor\platform\torrc-windows".
Jul 05 04:36:11.044 [notice] Read configuration file "C:\tools\msys64\home\tor\etc\tor\instances\node02\torrc".
Jul 05 04:36:11.049 [notice] Included configuration file or directory at recursion level 1: "C:\tools\msys64\home\tor\usr\share\tor\tor-service-defaults-torrc".
Jul 05 04:36:11.093 [notice] Opening Socks listener on [::1]:9050
Jul 05 04:36:11.095 [notice] Opened Socks listener on [::1]:9050
Jul 05 04:36:11.000 [debug] tor_open_cloexec(): Opening C:\tools\msys64\home\tor\var\log\tor\debug.log with flags 109
Jul 05 04:36:11.000 [warn] Couldn't open file for 'Log debug file C:\tools\msys64\home\tor\var\log\tor\debug.log': No error
Jul 05 04:36:11.000 [warn] Couldn't open file for 'Log debug file C:\tools\msys64\home\tor\var\log\tor\debug.log': No error
Jul 05 04:36:11.000 [notice] Closing partially-constructed Socks listener on ::1:9050
Jul 05 04:36:11.000 [warn] Failed to parse/validate config: Failed to init Log options. See logs for details.
Jul 05 04:36:11.000 [err] Reading config failed--see warnings above.

The Start fix is to set switch non default value

TruncateLogFile 1 

and tor starts happily with this big files

Jul 05 04:49:36.000 [debug] tor_open_cloexec(): Opening C:\tools\msys64\home\tor\var\log\tor\debug.log with flags 301
Jul 05 04:49:36.000 [warn] {GENERAL} Your log may contain sensitive information - you disabled SafeLogging, and you're logging more than "notice". Don't log unless it serves an important reason. Overwrite the log afterwards.

This works for me.

For reproduce error steps, may something like this helps creating big file.

dd if=/dev/zero of=debug.log bs=1 count=0 seek=2G
Last edited 4 months ago by cypherpunks (previous) (diff)

comment:6 Changed 4 months ago by nickm

I'm trying the reproduction steps, and I don't see this bug. Possibly this is windows only.

comment:7 Changed 3 months ago by cypherpunks

Sorry, can be platform specific. but i could have this again reproduced and it just happened randomly again.
warning log file filled over 7GB within one hour.
all messages are the same:

Aug 26 09:47:20.000 [warn] {BUG} tor_bug_occurred_(): Bug: buffers_tls.c:73: buf_read_from_tls: Non-fatal assertion !(buf->datalen >= INT_MAX - at_most) failed. (on Tor 0.4.0.5 )

tor process does not start afterwards. without setting

TruncateLogFile 1

error:

Aug 27 07:03:46.000 [warn] Couldn't open file for 'Log warn file C:\tools\msys64\home\tor\var\log\tor\warn.log': Invalid argument
Aug 27 07:03:46.000 [warn] Failed to parse/validate config: Failed to init Log options. See logs for details.
Aug 27 07:03:46.000 [err] Reading config failed--see warnings above.

comment:8 Changed 2 months ago by nickm

Keywords: 042-should added

comment:9 Changed 7 weeks ago by ahf

Owner: set to catalyst
Status: newassigned

Distributing 0.4.2 tickets between network team members.

comment:10 Changed 6 weeks ago by ahf

Owner: changed from catalyst to ahf

Taking over this one per discussion in network team meeting.

comment:11 Changed 5 weeks ago by catalyst

#32022 is the ticket for the underlying assertion failure that causes the log spam.

Note: See TracTickets for help on using tickets.