[SR-6555] Regression: Reusing an URLSession on Swift 4.x causes constant CPU time

[swift-ci]

Previous ID	SR-6555
Radar	None
Original Reporter	graemer957 (JIRA User)
Type	Bug

Attachment: Download

Environment

Swift version 4.0 (swift-4.0-RELEASE)

Swift version 4.0.2 (swift-4.0.2-RELEASE)

Swift version 4.0.3 (swift-4.0.3-RELEASE)

Swift version 4.1 (swift-4.1-RELEASE)

Swift version 4.1.1 (swift-4.1.1-RELEASE)

Swift version 4.1.2 (swift-4.1.2-RELEASE)

Swift version 4.2-dev (LLVM 70f121e1f0, Clang 4c555650a6, Swift bb9532c588)

Additional Detail from JIRA

Votes	1
Component/s	Foundation
Labels	Bug
Assignee	@pushkarnk
Priority	Medium

md5: 0ccd93cd881b11aece0f0343f75c7fb7

Issue Description:

Steps to reproduce

Using the attached project with Swift 4.0.3 under Ubuntu 14.04.5 LTS:

1. Leave top running in one session
2. In a new session swift build
3. swift run
4. Observe after first HTTP response CPU time drops back to zero
5. However, after second HTTP response CPU is using constant time

Expected behaviour

CPU time is not constantly used.

Workaround

Recreate URLSession for each dataTask(with: ), by commenting out line 4 and uncommenting line 7.

Swift versions affected

• Swift version 4.0 (swift-4.0-RELEASE)

• Swift version 4.0.2 (swift-4.0.2-RELEASE)

• Swift version 4.0.3 (swift-4.0.3-RELEASE)

• Swift version 4.1 (swift-4.1-RELEASE)

• Swift version 4.1.1 (swift-4.1.1-RELEASE)

• Swift version 4.1.2 (swift-4.1.2-RELEASE)

• Swift version 4.2-dev (LLVM 70f121e1f0, Clang 4c555650a6, Swift bb9532c588)

Swift versions unaffected

• Swift version 3.1.1 (swift-3.1.1-RELEASE)

Misc

• Target is x86_64-unknown-linux-gnu

• Have tried Ubuntu 16.04, but it exhibits the same behaviour

• If the attachment is unavailable, it can be found on GitLab

[swift-ci]

Comment by Natchanon Luangsomboon (JIRA)

Using gdb on the thread that cause the high usage results in this:

Thread 1 "URLSessionRegre" received signal SIGINT, Interrupt.
0x00007ffff5b92811 in __GI_ppoll (fds=0x7fffffffe128, nfds=1, timeout=<optimized out>, sigmask=0x0) at ../sysdeps/unix/sysv/linux/ppoll.c:50
50 in ../sysdeps/unix/sysv/linux/ppoll.c
(gdb) thread 3
[Switching to thread 3 (Thread 0x7ffff7edc700 (LWP 4138))]
#0 0x00007ffff5b9ea13 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
84 ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) bt
#0 0x00007ffff5b9ea13 in epoll_wait () at ../sysdeps/unix/syscall-template.S:84
#1 0x00007ffff7f45275 in _dispatch_event_loop_drain () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#2 0x00007ffff7f40de8 in _dispatch_mgr_invoke () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#3 0x00007ffff7f40d1e in _dispatch_mgr_thread () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#4 0x00007ffff7f3cdf8 in _dispatch_worker_thread () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#5 0x00007ffff6b106ba in start_thread (arg=0x7ffff7edc700) at pthread_create.c:333
#6 0x00007ffff5b9e41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
(gdb) thread 6
[Switching to thread 6 (Thread 0x7fffed68e700 (LWP 4141))]
#0 0x00007ffff6b18a15 in futex_abstimed_wait_cancelable (private=0, abstime=0x7fffed68dd88, expected=0,
futex_word=0x7ffff7f85898 <_dispatch_pthread_root_queue_contexts+1352>) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
205 ../sysdeps/unix/sysv/linux/futex-internal.h: No such file or directory.
(gdb) bt
#0 0x00007ffff6b18a15 in futex_abstimed_wait_cancelable (private=0, abstime=0x7fffed68dd88, expected=0,
futex_word=0x7ffff7f85898 <_dispatch_pthread_root_queue_contexts+1352>) at ../sysdeps/unix/sysv/linux/futex-internal.h:205
#1 do_futex_wait (sem=sem@entry=0x7ffff7f85898 <_dispatch_pthread_root_queue_contexts+1352>, abstime=abstime@entry=0x7fffed68dd88) at sem_waitcommon.c:111
#2 0x00007ffff6b18adf in __new_sem_wait_slow (sem=0x7ffff7f85898 <_dispatch_pthread_root_queue_contexts+1352>, abstime=0x7fffed68dd88) at sem_waitcommon.c:181
#3 0x00007ffff6b18b92 in sem_timedwait (sem=<optimized out>, abstime=<optimized out>) at sem_timedwait.c:36
#4 0x00007ffff7f45755 in _dispatch_sema4_timedwait () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#5 0x00007ffff7f3dd1e in _dispatch_semaphore_wait_slow () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#6 0x00007ffff7f3cfbd in _dispatch_worker_thread () from /home/lantua/.local/swift/usr/lib/swift/linux/libdispatch.so
#7 0x00007ffff6b106ba in start_thread (arg=0x7fffed68e700) at pthread_create.c:333
#8 0x00007ffff5b9e41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
(gdb)

This behaviour is quite similar to https://bugs.swift.org/browse/SR-4567.
Maybe there's some commonality between the two.

[swift-ci]

Comment by Graeme Read (JIRA)

Validated issue with recent Swift versions and updated `Environment` and `Description` accordingly.

Interestingly in Swift v4.2-dev (2018-06-12-a) the constant CPU time is ~4% less than Swiftv 4.0 through 4.1.2.