[PATCH] depmod: ignore related modules in depmod_report_cycles

Only print actual cyclic dependencies. Don't print count of all the
modules as it includes other modules which have dependencies but not
necessarily cyclic.

Printing related modules causes buffer overflow as m->modnamesz is not
included in buffer size calculations (loop == m is never true).
This buffer overflow causes kmod to crash.

Reported-by: Andreas Färber <afaerber@suse.de>
Signed-off-by: Mian Yousaf Kaukab <redacted>
---
As count of modules in cyclic dependency chain is not known at the
start of this function, so it is not printed anymore. The output
when cyclic dependency is detected is changed as following:

Old:
depmod: ERROR: Found 8 modules in dependency cycles!

New:
depmod: ERROR: Modules found in dependency cycles!

I hope it wouldn't be a problem.

 tools/depmod.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/tools/depmod.c b/tools/depmod.c
index ad01f66..2813ef1 100644
--- a/tools/depmod.c
+++ b/tools/depmod.c

@@ -1456,7 +1456,7 @@ static void depmod_report_cycles(struct depmod *depmod, uint16_t n_mods,
 {
 	const char sep[] = " -> ";
 	int ir = 0;
-	ERR("Found %u modules in dependency cycles!\n", n_roots);
+	ERR("Modules found in dependency cycles!\n");
 
 	while (n_roots > 0) {
 		int is, ie;

@@ -1491,6 +1491,7 @@ static void depmod_report_cycles(struct depmod *depmod, uint16_t n_mods,
 			if (m->visited) {
 				int i, n = 0, sz = 0;
 				char *buf;
+				bool is_cyclic = false;
 
 				for (i = ie - 1; i >= 0; i--) {
 					struct mod *loop = depmod->modules.array[edges[i]];

@@ -1498,9 +1499,15 @@ static void depmod_report_cycles(struct depmod *depmod, uint16_t n_mods,
 					n++;
 					if (loop == m) {
 						sz += loop->modnamesz - 1;
+						is_cyclic = true;
 						break;
 					}
 				}
+				/* Current module not found in dependency list.
+				 * Must be a related module. Ignore it.
+				 */
+				if (!is_cyclic)
+					continue;
 
 				buf = malloc(sz + n * strlen(sep) + 1);
 				sz = 0;

-- 
2.7.4

Hi,

On Fri, Nov 4, 2016 at 7:33 AM, Mian Yousaf Kaukab
[off-list ref] wrote:

Only print actual cyclic dependencies. Don't print count of all the
modules as it includes other modules which have dependencies but not
necessarily cyclic.

Printing related modules causes buffer overflow as m->modnamesz is not
included in buffer size calculations (loop =3D=3D m is never true).
This buffer overflow causes kmod to crash.

Reported-by: Andreas F=C3=A4rber <afaerber@suse.de>
Signed-off-by: Mian Yousaf Kaukab <redacted>
---
As count of modules in cyclic dependency chain is not known at the
start of this function, so it is not printed anymore. The output
when cyclic dependency is detected is changed as following:

Old:
depmod: ERROR: Found 8 modules in dependency cycles!

New:
depmod: ERROR: Modules found in dependency cycles!

I think it would be good to fix this problem, but retaining the behavior.

My first reaction to this is "how do I reproduce the issue?". This
number so far does tell us how many modules are involved in loops. So,
for example:

A -> B -> D -> A
B -> C -> B

This line should point to 4 modules. We don't know which module is
wrong. But there are 4 modules involved in the loops. D could be the
culprit.

The function should show what are the loops present (in "first found
order" - it could very well report as "B -> D -> A -> B" the line
above).

We have a testsuite to check if the loop detection is working in
depmod. See testsuite/test-depmod.c:depmod_detect_loop().
Would it be possible to add your use case there? If you tell me what
are your dependency chain and cycle I can take a look.

If I misunderstood the issue with the total number, then at least the
testsuite needs to be fixed, because right now it expects that number
to be in the output (see
testsuite/rootfs-pristine/test-depmod/detect-loop/correct.txt)


thanks
Lucas De Marchi

On Sat, 2016-11-05 at 21:50 -0200, Lucas De Marchi wrote:

Hi,

On Fri, Nov 4, 2016 at 7:33 AM, Mian Yousaf Kaukab
[off-list ref] wrote:

quoted

Only print actual cyclic dependencies. Don't print count of all the
modules as it includes other modules which have dependencies but
not
necessarily cyclic.

Printing related modules causes buffer overflow as m->modnamesz is
not
included in buffer size calculations (loop == m is never true).
This buffer overflow causes kmod to crash.

Reported-by: Andreas Färber <afaerber@suse.de>
Signed-off-by: Mian Yousaf Kaukab <redacted>
---
As count of modules in cyclic dependency chain is not known at the
start of this function, so it is not printed anymore. The output
when cyclic dependency is detected is changed as following:

Old:
depmod: ERROR: Found 8 modules in dependency cycles!

New:
depmod: ERROR: Modules found in dependency cycles!

I think it would be good to fix this problem, but retaining the
behavior.

Would it be OK if the modules names are printed first and count is
printed afterward. Something like following: 

DEPMOD  4.9.0-rc4-default
depmod: ERROR: Cycle detected: qcom_wcnss_iris -> qcom_wcnss ->
qcom_wcnss_iris
depmod: ERROR: Found 2 modules in dependency cycles!
Makefile:1227: recipe for target '_modinst_post' failed

In this way modules names can still be printed in the loop and then the
exact count of modules involved in cyclic dependency is printed at the
end of the depmod_report_cycles().

My first reaction to this is "how do I reproduce the issue?". This
number so far does tell us how many modules are involved in loops. 

There is more info at the following link:
https://bugzilla.opensuse.org/show_bug.cgi?id=1008186

You can reproduce the issue by enabling CONFIG_QCOM_WCNSS_PIL as module
in v4.9-rc4 for arm64. 
+CONFIG_REMOTEPROC=m
+CONFIG_QCOM_MDT_LOADER=m
-# CONFIG_QCOM_WCNSS_PIL is not set
+CONFIG_QCOM_WCNSS_IRIS=m
+CONFIG_QCOM_WCNSS_PIL=m

Issue will reproduce when depmod is run at the end of modules_install.

So,
for example:

A -> B -> D -> A
B -> C -> B

C -> X
C -> Y
C -> Z
In this case count becomes 7. Which is misleading.

This line should point to 4 modules. We don't know which module is
wrong. But there are 4 modules involved in the loops. D could be the
culprit.

The function should show what are the loops present (in "first found
order" - it could very well report as "B -> D -> A -> B" the line
above).

We have a testsuite to check if the loop detection is working in
depmod. See testsuite/test-depmod.c:depmod_detect_loop().
Would it be possible to add your use case there? [...]

Yes I can take a look.

[...] If you tell me what
are your dependency chain and cycle I can take a look.

If I misunderstood the issue with the total number, then at least the
testsuite needs to be fixed, because right now it expects that number
to be in the output (see
testsuite/rootfs-pristine/test-depmod/detect-loop/correct.txt)


thanks
Lucas De Marchi

BR,
Yousaf

On Mon 07 Nov 09:27 PST 2016, Mian Yousaf Kaukab wrote:

On Sat, 2016-11-05 at 21:50 -0200, Lucas De Marchi wrote:

quoted

Hi,

On Fri, Nov 4, 2016 at 7:33 AM, Mian Yousaf Kaukab
[off-list ref] wrote:

quoted

Only print actual cyclic dependencies. Don't print count of all the
modules as it includes other modules which have dependencies but
not
necessarily cyclic.

Printing related modules causes buffer overflow as m->modnamesz is
not
included in buffer size calculations (loop == m is never true).
This buffer overflow causes kmod to crash.

Reported-by: Andreas F�rber <afaerber@suse.de>
Signed-off-by: Mian Yousaf Kaukab <redacted>
---
As count of modules in cyclic dependency chain is not known at the
start of this function, so it is not printed anymore. The output
when cyclic dependency is detected is changed as following:

Old:
depmod: ERROR: Found 8 modules in dependency cycles!

New:
depmod: ERROR: Modules found in dependency cycles!

I think it would be good to fix this problem, but retaining the
behavior.

Would it be OK if the modules names are printed first and count is
printed afterward. Something like following:�

DEPMOD��4.9.0-rc4-default
depmod: ERROR: Cycle detected: qcom_wcnss_iris -> qcom_wcnss ->
qcom_wcnss_iris
depmod: ERROR: Found 2 modules in dependency cycles!
Makefile:1227: recipe for target '_modinst_post' failed

In this way modules names can still be printed in the loop and then the
exact count of modules involved in cyclic dependency is printed at the
end of the depmod_report_cycles().

quoted

My first reaction to this is "how do I reproduce the issue?". This
number so far does tell us how many modules are involved in loops. 

There is more info at the following link:
https://bugzilla.opensuse.org/show_bug.cgi?id=1008186

You can reproduce the issue by enabling�CONFIG_QCOM_WCNSS_PIL as module
in v4.9-rc4 for arm64.�
+CONFIG_REMOTEPROC=m
+CONFIG_QCOM_MDT_LOADER=m
-# CONFIG_QCOM_WCNSS_PIL is not set
+CONFIG_QCOM_WCNSS_IRIS=m
+CONFIG_QCOM_WCNSS_PIL=m

I added some debugging prints to track the stack management in
depmod_report_cycles().

remoteproc, mdt_loader, wcnss_iris and wcnss_pil are all roots and we
have dependencies like this.

       /---(rproc)
       |     ^
       |     |
(pil) -+-> (mdt)
  ^    |
  |    v
  +- (iris)

1) We pick rproc as first root, mark that as visited and see that we're
   done.

2) We pick mdt_loader as second root, we push remoteproc to the stack
   and find that it's already visited, so we found a loop!

     mdt_loader -> remoteproc

3) We pick iris as third root, we push wcnss which pushes remoteproc,
   mdt_loader and iris. All three have already been visited from root #1
   and #2, so we find that there's a loop in:

     iris -> wcnss -> iris
     iris -> wcnss -> mdt
     iris -> wcnss -> remoteproc

Only one of these cases are actually a cycle, but as we don't reset
visited between the searches we can't tell. Further more, if there was a
dependency from iris -> remoteproc that would have shown up earlier and
marked iris->visited and when we get to step #3 we would just have
bailed directly - completely missing the cycle.

So I think we need to reset the visited list on each run of the DFS from
each root.

Regards,
Bjorn

On Mon, 2016-11-07 at 12:23 -0800, Bjorn Andersson wrote:

On Mon 07 Nov 09:27 PST 2016, Mian Yousaf Kaukab wrote:

quoted

On Sat, 2016-11-05 at 21:50 -0200, Lucas De Marchi wrote:

quoted

Hi,

On Fri, Nov 4, 2016 at 7:33 AM, Mian Yousaf Kaukab
[off-list ref] wrote:

quoted

Only print actual cyclic dependencies. Don't print count of all
the
modules as it includes other modules which have dependencies
but
not
necessarily cyclic.

Printing related modules causes buffer overflow as m->modnamesz 
is
not
included in buffer size calculations (loop == m is never true).
This buffer overflow causes kmod to crash.

Reported-by: Andreas Färber <afaerber@suse.de>
Signed-off-by: Mian Yousaf Kaukab <redacted>
---
As count of modules in cyclic dependency chain is not known at
the
start of this function, so it is not printed anymore. The
output
when cyclic dependency is detected is changed as following:

Old:
depmod: ERROR: Found 8 modules in dependency cycles!

New:
depmod: ERROR: Modules found in dependency cycles!

I think it would be good to fix this problem, but retaining the
behavior.

Would it be OK if the modules names are printed first and count is
printed afterward. Something like following: 

DEPMOD  4.9.0-rc4-default
depmod: ERROR: Cycle detected: qcom_wcnss_iris -> qcom_wcnss ->
qcom_wcnss_iris
depmod: ERROR: Found 2 modules in dependency cycles!
Makefile:1227: recipe for target '_modinst_post' failed

In this way modules names can still be printed in the loop and then
the
exact count of modules involved in cyclic dependency is printed at
the
end of the depmod_report_cycles().

quoted

My first reaction to this is "how do I reproduce the issue?".
This
number so far does tell us how many modules are involved in
loops. 

There is more info at the following link:
https://bugzilla.opensuse.org/show_bug.cgi?id=1008186

You can reproduce the issue by enabling CONFIG_QCOM_WCNSS_PIL as
module
in v4.9-rc4 for arm64. 
+CONFIG_REMOTEPROC=m
+CONFIG_QCOM_MDT_LOADER=m
-# CONFIG_QCOM_WCNSS_PIL is not set
+CONFIG_QCOM_WCNSS_IRIS=m
+CONFIG_QCOM_WCNSS_PIL=m

I added some debugging prints to track the stack management in
depmod_report_cycles().

remoteproc, mdt_loader, wcnss_iris and wcnss_pil are all roots and we
have dependencies like this.

       /---(rproc)
       |     ^
       |     |
(pil) -+-> (mdt)
  ^    |
  |    v
  +- (iris)

AFAICT this is not correct. Dependencies are like following:

pil -> rproc
pil -> mtd -> rproc
pil -> iris -> pil

1) We pick rproc as first root, mark that as visited and see that
we're
   done.

2) We pick mdt_loader as second root, we push remoteproc to the stack
   and find that it's already visited, so we found a loop!

     mdt_loader -> remoteproc

This is not cyclic.

3) We pick iris as third root, we push wcnss which pushes remoteproc,
   mdt_loader and iris. All three have already been visited from root
#1
   and #2, so we find that there's a loop in:

     iris -> wcnss -> iris
     iris -> wcnss -> mdt
     iris -> wcnss -> remoteproc

Only one of these cases are actually a cycle, but as we don't reset
visited between the searches we can't tell. Further more, if there
was a
dependency from iris -> remoteproc that would have shown up earlier
and
marked iris->visited and when we get to step #3 we would just have
bailed directly - completely missing the cycle.

In case we have more than one cyclic dependencies around same modules?
May be we should add a testcase for such a scenario so that its easy to
understand and reproduce.

So I think we need to reset the visited list on each run of the DFS
from
each root.

Regards,
Bjorn

BR,
Yousaf

On Tue 08 Nov 01:36 PST 2016, Mian Yousaf Kaukab wrote:

On Mon, 2016-11-07 at 12:23 -0800, Bjorn Andersson wrote:

quoted

On Mon 07 Nov 09:27 PST 2016, Mian Yousaf Kaukab wrote:

[..]

quoted

I added some debugging prints to track the stack management in
depmod_report_cycles().

remoteproc, mdt_loader, wcnss_iris and wcnss_pil are all roots and we
have dependencies like this.

�������/---(rproc)
�������|�����^
�������|�����|
(pil) -+-> (mdt)
� ^����|
� |����v
� +- (iris)

AFAICT this is not correct. Dependencies are like following:

pil -> rproc
pil -> mtd -> rproc
pil -> iris -> pil

All dependencies are:

pil -> rproc
pil -> mdt
mdt -> rproc
pil -> iris
iris -> pil

The last two forming a cyclic subgraph in a dependency graph including
all of them.

quoted

1) We pick rproc as first root, mark that as visited and see that
we're
���done.

2) We pick mdt_loader as second root, we push remoteproc to the stack
���and find that it's already visited, so we found a loop!

�����mdt_loader -> remoteproc

This is not cyclic.

Exactly my point. But the DFS will find this cycle, as we don't reset
"visited" between the iterations in the loop.

quoted

3) We pick iris as third root, we push wcnss which pushes remoteproc,
���mdt_loader and iris. All three have already been visited from root
#1
���and #2, so we find that there's a loop in:

�����iris -> wcnss -> iris
�����iris -> wcnss -> mdt
�����iris -> wcnss -> remoteproc

Only one of these cases are actually a cycle, but as we don't reset
visited between the searches we can't tell. Further more, if there
was a
dependency from iris -> remoteproc that would have shown up earlier
and
marked iris->visited and when we get to step #3 we would just have
bailed directly - completely missing the cycle.

In case we have more than one cyclic dependencies around same modules?

Well in this case we have a mixture of cyclic and non-cyclic subgraphs
that the DFS hits due to the "visited" issue above, the non-cyclic ones
are what triggers the buffer overflow.

May be we should add a testcase for such a scenario so that its easy to
understand and reproduce.

+1

Thanks for looking at this!

Regards,
Bjorn