[axel-devel] [axel-Bugs][313564] An order violation which may cause a dead loop(sometimes crash)

axel-bugs at alioth.debian.org axel-bugs at alioth.debian.org
Fri Mar 9 10:23:15 UTC 2012 

Bugs item #313564, was opened at 2012-03-09 18:23 by Mingxing Zhang
You can respond by visiting: 
https://alioth.debian.org/tracker/?func=detail&atid=413085&aid=313564&group_id=100070

Status: Open
Priority: 3
Submitted By: Mingxing Zhang (zhangmx-guest)
Assigned to: Nobody (None)
Summary: An order violation which may cause a dead loop(sometimes crash) 


Initial Comment:
Hi, axel developers:
  This bug is trigger by a pintool tailored for detecting concurrency bug, so it may hardly to be exposed in realworld. (fotunatly it's easy to reproduce).
  The main cause of this bug is that the function axel.c:setup_thread is excuted in a new thread created by axel.c:axel_start. Although it's rarely happended, if this thread excute untolerately slow /*excute line 538 conn->last_transfer = gettime(); and line 539 conn->state = 0;  later than line 389 if( !axel->conn[i].enabled &&...) and line 417 if( gettime() > axel->conn[i].last_transfer + axel->conf->reconnect_delay )*/, it will be restarted by axel.c:axel_do(line 419). So if setup_thread always excute slowly there will be a dead loop.(sometimes there will be a crash)

How to reproduce:
	add sleep(50); before axel.c:538 conn->last_transfer = gettime();  (axel-2.4)

But I have no idea about why it may crash, maybe the following error message will help.
--error message when crash--
mingxingzhang:bin$./axel -n 4 http://10.0.1.113:8087/mysql.tar.gz
Initializing download: http://10.0.1.113:8087/mysql.tar.gz
tcp_connect( 10.0.1.113, 8087 ) = 33793
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=1-
User-Agent: Axel 2.4 (Linux)
--- End of request ---
--- Reply headers ---
HTTP/1.1 206 Partial Content
Date: Fri, 09 Mar 2012 08:19:54 GMT
Server: Apache/2.4.1 (Unix) PHP/5.4.0
Last-Modified: Thu, 08 Mar 2012 03:04:18 GMT
ETag: "67d51-4bab288265080"
Accept-Ranges: bytes
Content-Length: 425296
Content-Range: bytes 1-425296/425297
Connection: close
Content-Type: application/x-gzip
--- End of headers ---
File size: 425297 bytes
Downloading 0-106323 using conn. 0
Downloading 106324-212648 using conn. 1
Downloading 212649-318973 using conn. 2
Downloading 318974-425296 using conn. 3
Opening output file mysql.tar.gz.1
State file found: 0 bytes downloaded, 425297 to go.
Starting download
tcp_connect( 10.0.1.113, 8087 ) = tcp_connect( 10.0.1.113, 8087 ) = tcp_connect( 10.0.1.113, 8087 ) = tcp_connect( 10.0.1.113, 8087 ) = 33794
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=318974-425296
User-Agent: Axel 2.4 (Linux)
--- End of request ---
33795
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=212649-318973
User-Agent: Axel 2.4 (Linux)
--- End of request ---
33796
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=106324-212648
User-Agent: Axel 2.4 (Linux)
--- End of request ---
33797
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
User-Agent: Axel 2.4 (Linux)
--- End of request ---
--- Reply headers ---
HTTP/1.1 206 Partial Content
Date: Fri, 09 Mar 2012 08:19:54 GMT
Server: Apache/2.4.1 (Unix) PHP/5.4.0
Last-Modified: Thu, 08 Mar 2012 03:04:18 GMT
ETag: "67d51-4bab288265080"
Accept-Ranges: bytes
Content-Length: 106323
Content-Range: bytes 318974-425296/425297
Connection: close
Content-Type: application/x-gzip
--- End of headers ---
--- Reply headers ---
HTTP/1.1 206 Partial Content
Date: Fri, 09 Mar 2012 08:19:54 GMT
Server: Apache/2.4.1 (Unix) PHP/5.4.0
Last-Modified: Thu, 08 Mar 2012 03:04:18 GMT
ETag: "67d51-4bab288265080"
Accept-Ranges: bytes
Content-Length: 106325
Content-Range: bytes 212649-318973/425297
Connection: close
Content-Type: application/x-gzip
--- End of headers ---
--- Reply headers ---
HTTP/1.1 206 Partial Content
Date: Fri, 09 Mar 2012 08:19:54 GMT
Server: Apache/2.4.1 (Unix) PHP/5.4.0
Last-Modified: Thu, 08 Mar 2012 03:04:18 GMT
ETag: "67d51-4bab288265080"
Accept-Ranges: bytes
Content-Length: 106325
Content-Range: bytes 106324-212648/425297
Connection: close
Content-Type: application/x-gzip
--- End of headers ---
--- Reply headers ---
HTTP/1.1 200 OK
Date: Fri, 09 Mar 2012 08:19:54 GMT
Server: Apache/2.4.1 (Unix) PHP/5.4.0
Last-Modified: Thu, 08 Mar 2012 03:04:18 GMT
ETag: "67d51-4bab288265080"
Accept-Ranges: bytes
Content-Length: 425297
Connection: close
Content-Type: application/x-gzip
--- End of headers ---
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=318974-425296
User-Agent: Axel 2.4 (Linux)
--- End of request ---
*** buffer overflow detected ***: ./axel terminated
======= Backtrace: =========
/lib/i386-linux-gnu/libc.so.6(__fortify_fail+0x45)[0x34d8d5]
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=212649-318973
User-Agent: Axel 2.4 (Linux)
--- End of request ---
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
Range: bytes=106324-212648
User-Agent: Axel 2.4 (Linux)
--- End of request ---
--- Sending request ---
GET /mysql.tar.gz HTTP/1.0
Host: 10.0.1.113
User-Agent: Axel 2.4 (Linux)
--- End of request ---
/lib/i386-linux-gnu/libc.so.6(+0xe66d7)[0x34c6d7]
/lib/i386-linux-gnu/libc.so.6(+0xe5b3f)[0x34bb3f]
./axel[0x804da8e]
./axel[0x804c6d4]
./axel[0x804b497]
/lib/i386-linux-gnu/libpthread.so.0(+0x6d31)[0xd61d31]
/lib/i386-linux-gnu/libc.so.6(clone+0x5e)[0x3380ce]
======= Memory map: ========
00265000-00266000 r-xp 00000000 00:00 0          [vdso]
00266000-003dc000 r-xp 00000000 08:01 5243813    /lib/i386-linux-gnu/libc-2.13.so
003dc000-003de000 r--p 00176000 08:01 5243813    /lib/i386-linux-gnu/libc-2.13.so
003de000-003df000 rw-p 00178000 08:01 5243813    /lib/i386-linux-gnu/libc-2.13.so
003df000-003e2000 rw-p 00000000 00:00 0 
004bc000-004da000 r-xp 00000000 08:01 5243800    /lib/i386-linux-gnu/ld-2.13.so
004da000-004db000 r--p 0001d000 08:01 5243800    /lib/i386-linux-gnu/ld-2.13.so
004db000-004dc000 rw-p 0001e000 08:01 5243800    /lib/i386-linux-gnu/ld-2.13.so
00549000-00565000 r-xp 00000000 08:01 5243834    /lib/i386-linux-gnu/libgcc_s.so.1
00565000-00566000 r--p 0001b000 08:01 5243834    /lib/i386-linux-gnu/libgcc_s.so.1
00566000-00567000 rw-p 0001c000 08:01 5243834    /lib/i386-linux-gnu/libgcc_s.so.1
00d5b000-00d72000 r-xp 00000000 08:01 5243873    /lib/i386-linux-gnu/libpthread-2.13.so
00d72000-00d73000 r--p 00016000 08:01 5243873    /lib/i386-linux-gnu/libpthread-2.13.so
00d73000-00d74000 rw-p 00017000 08:01 5243873    /lib/i386-linux-gnu/libpthread-2.13.so
00d74000-00d76000 rw-p 00000000 00:00 0 
08048000-08053000 r-xp 00000000 08:01 2105096    /home/mingxingzhang/axel-2.4/bin/bin/axel
08053000-08054000 r--p 0000a000 08:01 2105096    /home/mingxingzhang/axel-2.4/bin/bin/axel
08054000-08055000 rw-p 0000b000 08:01 2105096    /home/mingxingzhang/axel-2.4/bin/bin/axel
090c8000-090e9000 rw-p 00000000 00:00 0          [heap]
b565d000-b565e000 ---p 00000000 00:00 0 
b565e000-b5e5e000 rw-p 00000000 00:00 0 
b5e5e000-b5e5f000 ---p 00000000 00:00 0 
b5e5f000-b665f000 rw-p 00000000 00:00 0 
b665f000-b6660000 ---p 00000000 00:00 0 
b6660000-b6e60000 rw-p 00000000 00:00 0 
b6e60000-b6e61000 ---p 00000000 00:00 0 
b6e61000-b7662000 rw-p 00000000 00:00 0 
b7662000-b7663000 r--p 0043a000 08:01 7084893    /usr/lib/locale/locale-archive
b7663000-b76a3000 r--p 002bd000 08:01 7084893    /usr/lib/locale/locale-archive
b76a3000-b78a3000 r--p 00000000 08:01 7084893    /usr/lib/locale/locale-archive
b78a3000-b78a5000 rw-p 00000000 00:00 0 
b78b4000-b78b6000 rw-p 00000000 00:00 0 
bf8ce000-bf8ef000 rw-p 00000000 00:00 0          [stack]
Aborted


----------------------------------------------------------------------

You can respond by visiting: 
https://alioth.debian.org/tracker/?func=detail&atid=413085&aid=313564&group_id=100070

More information about the axel-devel mailing list