Hi again Michal,

I have more information to share.
I think I can confirm that the patches are actually fixing the credentials problem and they are passed along.
This is the content of test.log with libvirt-php output:

[2016-09-05 22:06:05 libvirt-php/core ]: libvirt_connect: credentials index 2
[2016-09-05 22:06:05 libvirt-php/core ]: libvirt_connect: credentials index 5
[2016-09-05 22:06:05 libvirt-php/core ]: libvirt_connect: Found 2 elements for credentials
[2016-09-05 22:06:05 libvirt-php/core ]: libvirt_virConnectAuthCallback: cred 0, type 5, prompt Enter Administrator's password for 192.168.7.2 challenge 192.168.7.2
 [2016-09-05 22:06:05 libvirt-php/core ]: libvirt_virConnectAuthCallback: result somepass (16)

Of course then the process is crashing and the connection is aborted so I believe that the patches work fine (they fix the connection credentials not passed along issue) but once this is fixed the other problem is uncovered.

I also took a trace of virsh to compare the behavior and I found that right after trying to open the file "/etc/openwsman/openwsman_client.conf" which doesn't exist, the network connection to the Hyper-V host starts:

open("/etc/openwsman/openwsman_client.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
gettimeofday({1473108181, 503801}, NULL) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 6
ioctl(6, SIOCGIFCONF, {80, {{"lo", {AF_INET, inet_addr("127.0.0.1")}}, {"eth0", {AF_INET, inet_addr("192.168.0.24")}}}}) = 0
ioctl(6, SIOCGIFFLAGS, {ifr_name="lo", ifr_flags=IFF_UP|IFF_LOOPBACK|IFF_RUNNING}) = 0
ioctl(6, SIOCGIFFLAGS, {ifr_name="eth0", ifr_flags=IFF_UP|IFF_BROADCAST|IFF_RUNNING|IFF_MULTICAST}) = 0
ioctl(6, SIOCGIFHWADDR, {ifr_name="eth0", ifr_hwaddr=00:15:5d:07:32:03}) = 0
close(6) = 0
futex(0x7fa9b602fd48, FUTEX_WAKE_PRIVATE, 2147483647) = 0
open("/etc/openwsman/openwsman_client.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
brk(0) = 0x7fa9b881f000
brk(0x7fa9b8840000) = 0x7fa9b8840000
clock_gettime(CLOCK_MONOTONIC, {1530071, 524608469}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524644770}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524680171}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524715271}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524753172}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524791573}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524823274}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524875775}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 524976977}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 525034178}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 525103179}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 525135580}) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 525176581}) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 6
fcntl(6, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
clock_gettime(CLOCK_MONOTONIC, {1530071, 525334084}) = 0
connect(6, {sa_family=AF_INET, sin_port=htons(5985), sin_addr=inet_addr("192.168.0.2")}, 16) = -1 EINPROGRESS (Operation now in progress)
clock_gettime(CLOCK_MONOTONIC, {1530071, 525458286}) = 0

While in the case of libvirt-php, it will crash and abort the connection. If you want me to send you the full virsh trace, just let me know.
Also, not sure if it worth mention it and I guess you are aware that libvirt depends on openwsman to connect to a Hyper-V host.

Thanks in advance for your help.

Fer

On lun, sep 5, 2016 at 9:38 , Fernando Casas Schössow <casasfernando@hotmail.com> wrote:
Thanks for your reply Michal.

Actually you don't need a Hyper-V server to reproduce the problem since the connection to the server is never initiated because the process crash before that stage (got wireshark on the network to confirm this).
So you should be able to reproduce the problem without a Hyper-V server, just using the same PHP code I'm using (or any other hyperv URI for that matter).

==============================================================================================================

Following your advice I attached strace to the PHP processes and reproduced the issue. This is the trace result:

Process 34978 attached
Process 34979 attached
Process 34981 attached
Process 34983 attached
Process 34984 attached
Process 34986 attached
Process 34987 attached
Process 34989 attached
[pid 34989] accept(0, <unfinished ...>
[pid 34987] wait4(-1, <unfinished ...>
[pid 34986] accept(0, <unfinished ...>
[pid 34981] accept(0, <unfinished ...>
[pid 34979] wait4(-1, <unfinished ...>
[pid 34978] wait4(-1, <unfinished ...>
[pid 34984] wait4(-1, <unfinished ...>
[pid 34983] accept(0, 
 <unfinished ...>
[pid 34989] <... accept resumed> {sa_family=AF_LOCAL, NULL}, [2]) = 4
[pid 34989] poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
[pid 34989] read(4, "\1\1\0\1\0\10\0\0", 8) = 8
[pid 34989] read(4, "\0\1\0\0\0\0\0\0", 8) = 8
[pid 34989] read(4, "\1\4\0\1\2\351\0\0", 8) = 8
[pid 34989] read(4, "\17\10SERVER_SOFTWARElighttpd\v\fSERVE"..., 745) = 745
[pid 34989] read(4, "\1\4\0\1\0\0\0\0", 8) = 8
[pid 34989] lstat("/storage/lighttpd/wwwroot/libvirt.php", {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 34989] lstat("/storage/lighttpd/wwwroot", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 34989] lstat("/storage/lighttpd", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 34989] lstat("/storage", {st_mode=S_IFDIR|0755, st_size=31, ...}) = 0
[pid 34989] gettimeofday({1473102621, 318809}, NULL) = 0
[pid 34989] stat("/storage/lighttpd/wwwroot/.user.ini", 0x7ffc541fcbe0) = -1 ENOENT (No such file or directory)
[pid 34989] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
[pid 34989] rt_sigaction(SIGPROF, {0x7f9772bbb970, [PROF], SA_RESTORER|SA_RESTART, 0x7f976f07b670}, {SIG_DFL, [], 0}, 8) = 0
[pid 34989] rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
[pid 34989] open("/storage/lighttpd/wwwroot/libvirt.php", O_RDONLY) = 5
[pid 34989] fstat(5, {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 34989] fstat(5, {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 34989] fstat(5, {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 34989] mmap(NULL, 633, PROT_READ, MAP_SHARED, 5, 0) = 0x7f9772959000
[pid 34989] getcwd("/usr/bin", 4095) = 9
[pid 34989] chdir("/storage/lighttpd/wwwroot") = 0
[pid 34989] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={14400, 0}}, NULL) = 0
[pid 34989] munmap(0x7f9772959000, 633) = 0
[pid 34989] close(5) = 0
[pid 34989] unlink("test.log") = 0
[pid 34989] access("test.log", F_OK) = -1 ENOENT (No such file or directory)
[pid 34989] open("test.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 5
[pid 34989] lseek(5, 0, SEEK_END) = 0
[pid 34989] dup3(5, 2, 0) = 2
[pid 34989] close(5) = 0
[pid 34989] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 34989] fstat(2, {st_mode=S_IFREG|0755, st_size=0, ...}) = 0
[pid 34989] mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9772956000
[pid 34989] write(2, "[2016-09-05 21:10:21 libvirt-php"..., 80) = 80
[pid 34989] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 34989] write(2, "[2016-09-05 21:10:21 libvirt-php"..., 80) = 80
[pid 34989] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 34989] write(2, "[2016-09-05 21:10:21 libvirt-php"..., 93) = 93
[pid 34989] futex(0x7f976ae3cb18, FUTEX_WAKE_PRIVATE, 2147483647) = 0
[pid 34989] futex(0x7f976ae3d078, FUTEX_WAKE_PRIVATE, 2147483647) = 0
[pid 34989] geteuid() = 997
[pid 34989] geteuid() = 997
[pid 34989] socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 5
[pid 34989] connect(5, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
[pid 34989] close(5) = 0
[pid 34989] socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 5
[pid 34989] connect(5, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
[pid 34989] close(5) = 0
[pid 34989] open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 5
[pid 34989] fstat(5, {st_mode=S_IFREG|0644, st_size=1998, ...}) = 0
[pid 34989] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9772955000
[pid 34989] read(5, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1998
[pid 34989] close(5) = 0
[pid 34989] munmap(0x7f9772955000, 4096) = 0
[pid 34989] access("/var/www/lighttpd/.config/libvirt/libvirt.conf", F_OK) = -1 ENOENT (No such file or directory)
[pid 34989] geteuid() = 997
[pid 34989] open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 5
[pid 34989] fstat(5, {st_mode=S_IFREG|0644, st_size=1998, ...}) = 0
[pid 34989] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9772955000
[pid 34989] read(5, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1998
[pid 34989] close(5) = 0
[pid 34989] munmap(0x7f9772955000, 4096) = 0
[pid 34989] access("/var/www/lighttpd/.config/libvirt/auth.conf", R_OK) = -1 ENOENT (No such file or directory)
[pid 34989] access("/etc/libvirt/auth.conf", R_OK) = -1 EACCES (Permission denied)
[pid 34989] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 34989] write(2, "[2016-09-05 21:10:21 libvirt-php"..., 168) = 168
[pid 34989] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 34989] write(2, "[2016-09-05 21:10:21 libvirt-php"..., 104) = 104
[pid 34989] open("/etc/openwsman/openwsman_client.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
[pid 34989] --- SIGSEGV {si_signo=SIGSEGV, si_code=SI_KERNEL, si_addr=0} ---
[pid 34989] +++ killed by SIGSEGV +++
[pid 34987] <... wait4 resumed> [{WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV}], 0, NULL) = 34989
[pid 34987] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=34989, si_status=SIGSEGV, si_utime=0, si_stime=0} ---
[pid 34987] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f9772942b10) = 35616
[pid 34987] wait4(-1,


==============================================================================================================

I also got a trace *without* the patches applied in which case there is no crash but the connection doesn't work either (I think the credentials are not passed along). The output is slightly different:

{sa_family=AF_LOCAL, NULL}, [2]) = 2
[pid 49430] poll([{fd=2, events=POLLIN}], 1, 5000) = 1 ([{fd=2, revents=POLLIN}])
[pid 49430] read(2, "\1\1\0\1\0\10\0\0", 8) = 8
[pid 49430] read(2, "\0\1\0\0\0\0\0\0", 8) = 8
[pid 49430] read(2, "\1\4\0\1\2\351\0\0", 8) = 8
[pid 49430] read(2, "\17\10SERVER_SOFTWARElighttpd\v\fSERVE"..., 745) = 745
[pid 49430] read(2, "\1\4\0\1\0\0\0\0", 8) = 8
[pid 49430] lstat("/storage/lighttpd/wwwroot/libvirt.php", {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 49430] lstat("/storage/lighttpd/wwwroot", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid 49430] lstat("/storage/lighttpd", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 49430] lstat("/storage", {st_mode=S_IFDIR|0755, st_size=31, ...}) = 0
[pid 49430] gettimeofday({1473102046, 10224}, NULL) = 0
[pid 49430] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
[pid 49430] rt_sigaction(SIGPROF, {0x7f1014f4c970, [PROF], SA_RESTORER|SA_RESTART, 0x7f101140c670}, {0x7f1014f4c970, [PROF], SA_RESTORER|SA_RESTART, 0x7f101140c670}, 8) = 0
[pid 49430] rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
[pid 49430] open("/storage/lighttpd/wwwroot/libvirt.php", O_RDONLY) = 4
[pid 49430] fstat(4, {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 49430] fstat(4, {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 49430] fstat(4, {st_mode=S_IFREG|0755, st_size=633, ...}) = 0
[pid 49430] mmap(NULL, 633, PROT_READ, MAP_SHARED, 4, 0) = 0x7f1014cea000
[pid 49430] getcwd("/usr/bin", 4095) = 9
[pid 49430] chdir("/storage/lighttpd/wwwroot") = 0
[pid 49430] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={14400, 0}}, NULL) = 0
[pid 49430] munmap(0x7f1014cea000, 633) = 0
[pid 49430] close(4) = 0
[pid 49430] unlink("test.log") = -1 ENOENT (No such file or directory)
[pid 49430] access("test.log", F_OK) = -1 ENOENT (No such file or directory)
[pid 49430] open("test.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 4
[pid 49430] lseek(4, 0, SEEK_END) = 0
[pid 49430] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 49430] fstat(4, {st_mode=S_IFREG|0755, st_size=0, ...}) = 0
[pid 49430] mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1014ce7000
[pid 49430] write(4, "[2016-09-05 21:00:46 libvirt-php"..., 93) = 93
[pid 49430] geteuid() = 997
[pid 49430] geteuid() = 997
[pid 49430] open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 5
[pid 49430] fstat(5, {st_mode=S_IFREG|0644, st_size=1998, ...}) = 0
[pid 49430] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1014ce6000
[pid 49430] read(5, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1998
[pid 49430] close(5) = 0
[pid 49430] munmap(0x7f1014ce6000, 4096) = 0
[pid 49430] access("/var/www/lighttpd/.config/libvirt/libvirt.conf", F_OK) = -1 ENOENT (No such file or directory)
[pid 49430] geteuid() = 997
[pid 49430] open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 5
[pid 49430] fstat(5, {st_mode=S_IFREG|0644, st_size=1998, ...}) = 0
[pid 49430] mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1014ce6000
[pid 49430] read(5, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 1998
[pid 49430] close(5) = 0
[pid 49430] munmap(0x7f1014ce6000, 4096) = 0
[pid 49430] access("/var/www/lighttpd/.config/libvirt/auth.conf", R_OK) = -1 ENOENT (No such file or directory)
[pid 49430] access("/etc/libvirt/auth.conf", R_OK) = -1 EACCES (Permission denied)
[pid 49430] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 49430] write(4, "[2016-09-05 21:00:46 libvirt-php"..., 168) = 168
[pid 49430] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 49430] write(4, "[2016-09-05 21:00:46 libvirt-php"..., 93) = 93
[pid 49430] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2593, ...}) = 0
[pid 49430] write(4, "[2016-09-05 21:00:46 libvirt-php"..., 142) = 142
[pid 49430] getcwd("/storage/lighttpd/wwwroot", 4096) = 26
[pid 49430] lstat("/storage/lighttpd/wwwroot/test.log", {st_mode=S_IFREG|0755, st_size=496, ...}) = 0
[pid 49430] open("/storage/lighttpd/wwwroot/test.log", O_RDONLY) = 5
[pid 49430] fstat(5, {st_mode=S_IFREG|0755, st_size=496, ...}) = 0
[pid 49430] lseek(5, 0, SEEK_CUR) = 0
[pid 49430] stat("test.log", {st_mode=S_IFREG|0755, st_size=496, ...}) = 0
[pid 49430] read(5, "[2016-09-05 21:00:46 libvirt-php"..., 8192) = 496
[pid 49430] close(5) = 0
[pid 49430] chdir("/usr/bin") = 0
[pid 49430] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
[pid 49430] write(2, "\1\7\0\1\0\361\7\0PHP Warning: unlink(tes"..., 928) = 928
[pid 49430] shutdown(2, SHUT_WR) = 0
[pid 49430] recvfrom(2, "\1\5\0\1\0\0\0\0", 8, 0, NULL, NULL) = 8
[pid 49430] close(2) = 0
[pid 49430] setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
[pid 49430] accept(0, 


==============================================================================================================

I'm not an expert debugger but I suspect that the patches are actually working, the credentials are passed along and the connection attempt is moving forward but crashing in the next stage before any actual connection attempt to the remote server is attempted.

I still need to try with the git HEAD code tough.
Not sure if it worth mention this again but the same connection is working without any problems using virsh.

Thanks for looking into this.

Cheers.

Fer

On lun, sep 5, 2016 at 9:33 , Michal Privoznik <mprivozn@redhat.com> wrote:
On 02.09.2016 11:11, Fernando Casas Schössow wrote:
I'm running libvirt-php 0.5.2 on CentOS 7 with libvirt 2.1.0. Using virsh I'm able to connect to hyper-v hosts correctly but using libvirt-php it fails during authentication since it seems that the credentials are not being passed along. This is the php code I'm using: <?php $logfile = 'test.log'; unlink($logfile); if (!libvirt_logfile_set($logfile)) die('Cannot set the log file'); $connstr = 'hyperv://user@hyperv-host/?transport=http'; $credentials = array(VIR_CRED_AUTHNAME=>'Administrator',VIR_CRED_PASSPHRASE=>'somepass'); $conn = libvirt_connect($connstr, false, $credentials); echo libvirt_get_last_error(); unset($conn); $fp = fopen($logfile, 'r'); $str = fread($fp, filesize($logfile)); fclose($fp); echo '<pre>'; echo $str; print_r($credentials); echo '</pre>'; ?>
Unfortunately, I don't have a hyperv instance to try this out, but for other connection URIs (like qemu:///system) this works for me.
And this is the output: authentication failed: Password request failed [2016-09-02 11:10:02 libvirt-php/core ]: libvirt_connect: Found 0 elements for credentials [2016-09-02 11:10:02 libvirt-php/core ]: libvirt_virConnectAuthCallback: cred 0, type 5, prompt Enter Administrator's password for hyperv-host challenge hyperv-host [2016-09-02 11:10:02 libvirt-php/core ]: libvirt_virConnectAuthCallback: result (null) (0) [2016-09-02 11:10:02 libvirt-php/core ]: libvirt_connect: Cannot establish connection to hyperv://Administrator@hyperv-host/?transport=http Array ( [2] => Administrator [5] => somepass ) Note the "Found 0 elements for credentials". After doing some googling I found an email thread "[libvirt] [libvirt-php PATCH 0/3] Fix PHP5 compatibilty issues." that I think is related to my problem, especially patch 2/3. I also checked github project and saw that those patches are already merged in the code so I went ahead and apply them to 0.5.2 source code and rebuild: use VIRT_FOREACH macros everywhere - Commit: f4b760d libvirt_connect: use loop macros to read cred info - Commit: d704106 Define macros for looping php hash tables - Commit: 673a0bf The build went fine but now when I'm trying to connect to the hyper-v host using libvirt-php I get an internal server error (500) so it seems PHP is crashing. From the system log I see: kernel: traps: php-cgi[43452] general protection ip:7f63907f74a0 sp:7fff12d61f68 error:0 in libvirt.so.0.2001.0[7f6390735000+385000]
If you could attach a debugger and get a stack trace where this is happening that'd be great.
Is there any other patch that I'm missing?
Doesn't look like it, but if you could try the current git HEAD that would help. I mean, if you see the error even with that the bug is still there.
Any ideas on how to fix the libvirt_connect credentials issue without applying the patches above?
I should probably do a release soon. Not that there was a much movement since the last one though. Michal